Tuesday 30 June 2020

help with excessive WSAECONNRESET causing instability - msgType



Okay, this is for the next time I forget message types.

Client is getting 100's of 
        10054-Error from Host=<145 .47.230.206=""> in recv returned 10054 (WSAECONNRESET): Connection was reset by peer

in the logs, sometimes I care, most times I do not.  I care when the message is important.

So in looking at the 10054's you might get a bunch of these:
3120/7552 Wed Jun 24 07:05:48.441000 netflow.c1686

3120 (pid) in routeOutgoingQueue(), unable to send message: sd=-1, msgId=2989, msgHost=172.30.72.6, msgPort=6091, sendingHost=172.30.72.4, msgType=15501, msgRange=28, krnlName=APP SERVER KERNEL, reqNet=0, resNet=0, reqKrnl=9860, resKrnl=0, msgFlags=0.

What can you tell about the msgType?  This is the important part of this message, because really - this tells you if you can ignore the message or not.

This is defined in jdenet.h - here is some help so 15501 is RTE - don't really care...  let's move on!

See how easy it is...   Remember that anything in /* */ is comments, so that is really a guide.  I think that the internal #defs of all these are in a file that we do not have access to as a client, so thanks for the comments JDE!


   JDEMSGSTARTWFPROC=WORK_FLOW_RANGE_START,  /* 4001 : Start process on server                     */
   JDEMSGCOMPLETEWFACT,                      /* 4002 : Complete activity on server                 */
   JDEMSGWFINTEROP,                          /* 4003 : Workflow Runtime Interop, inbound           */
   JDEMSGWFMONITORING,                       /* 4004 : Extract monitoring info for the jas server  */
   JDEMSGWFMONITORINGACTIONS,                /* 4005 : Monitoring actions from the jas server      */
   JDEMSGWFDESIGN,                           /* 4006 : Extract Graphical Info for the jas server   */
   JDEMSGWFDRILLDOWN,                        /* 4007 : Resolve Local sub proc task --> proc name   */
   JDEMSGWF_XML_SYSTEM_FUNCTION,             /* 4008 : Message System Function                     */
   JDEMSGWFFREEENV                           /* 4009 : Free Environment                            */
/* XMLTransaction - kernel type 15, Range 5001 - 5256 */
  XML_TRANSACTION_MSG = XML_TRANSACTION_RANGE_START,   /* 5001 */
  XML_TRANSACTION_LAST_MSG = XML_TRANSACTION_RANGE_END /* 5256 */
/* XMLList - kernel type 16, Range 5257 - 5512 */
  XML_LIST_MESSAGE = XML_LIST_RANGE_START, /* 5257 :     */
  XML_LIST_LAST_MSG = XML_LIST_RANGE_END   /* 5512 :     */
/* EVN - kernel type 19, Range 12001 - 13000 */
   IE_MSG_SUBSCRIBE=EVN_RANGE_START,   /* 12001 :                           */
   IE_MSG_EVENT,                       /* 12002 :                           */
   IE_MSG_SUBSCRIBE_INTERNAL,          /* 12003 :                           */
   IE_MSG_EVENTLIST,                   /* 12004 :                           */
   IE_MSG_EVENTTEMPLATE,               /* 12005 :                           */
   IE_MSG_EVENTOUT,                    /* 12006 :                           */
   IE_MSG_RELIABLE_EVENT,              /* 12007 :                           */
   IE_MSG_RELIABLE_REPLY_TO_SENDER,    /* 12008 :                           */
   IE_SD_IEO,                          /* 12009 :                           */
   IE_SD_ZEVG,                         /* 12010 :                           */
   IE_SD_SUBSCRIBE,                    /* 12011 :                           */
   IE_MSG_REQUEST_SUBSCRIPTION_INFO,   /* 12012 :                           */
   IE_MSG_DIRECT_ROUTING,              /* 12013 :                           */
   IE_MSG_START_KERNEL,                /* 12014 :                           */
   IE_MSG_LAST     = EVN_RANGE_END     /* 13000 : reserve the final message */
/* IEO - kernel type 20, Range 13001-13256 */
   IEO_MSG_EVENT_INIT = IEO_RANGE_START, /* 13001 :                        */
   IEO_MSG_EVENT_ADD,          /* 13002 :                                  */
   IEO_MSG_EVENT_FINALIZE,     /* 13003 :                                  */
   IEO_MSG_EVENT_INTROSPECT,   /* 13004 : create XML template for an event */
   IEO_MSG_EVENT_GET_TYPES,    /* 13005 : provide list of events           */
   IEO_MSG_RELIABLE_EVENT,     /* 13006 : reliable IEO event               */
   IEO_MSG_RELIABLE_REPLY_TO_SENDER,     /* 13007 : reply to sender of reliable event*/
   IEO_SD_EVG,                           /* 13008 : SDTool connectivity event        */
   IEO_MSG_DIRECT_ROUTING,               /* 13009 : Direct routing                   */
   IEO_MSG_EVENT_LAST = IEO_RANGE_END  /* 13256 : reserve the final message        */
/* XMLDispatch Kernel - kernel type 22, Range 13513-14000.    */
  XMLDispatchMessageType = XMLDISPATCH_RANGE_START,
  eNetProcessXMLDoc = XMLDISPATCH_RANGE_START + 2,
  eNetNotifyTransport,
  eNetResponseTransport,
  eNetSubscribeXMLDoc,
  IE_MSG_RELIABLE_OUT,                /* 13519 :                           */
  XMLDispatchLastMsgType = XMLDISPATCH_RANGE_END
/* XTSKrnl - kernel type 23, Range 14001-14250 */
   XTS_MSG_GET_PROXY_INFO = XTS_RANGE_START,  /* 14001 :           */
   XTS_ENGINE_TRANSFORM,            /* 14002 : used by XTS to JVM          */
   XTS_MGR_TRANSFORM,               /* 14003 : used by XTS to JVM          */
   XTS_COMP_PROCESS_CREATE,         /* 14004 : used by XTS to JVM          */
   XTS_COMP_PROCESS_TRANSFORM,      /* 14005 : used by XTS to JVM          */
   XTS_COMP_PROCESS_DESTROY,        /* 14006 : used by XTS to JVM          */
   XTS_MSG_EVENT_LAST = XTS_RANGE_END /* 14250 : reserve the final message */
/* XMLService - kernel type 24, Range 14251-14500 */
   XMLSERVICE_CALLMETHOD = XMLSERVICE_RANGE_START,        /* 14251 */
   XMLSERVICE_LOADDOCUMENT,                               /* 14252 */
   XMLSERVICE_DELETEDOCUMENT,                             /* 14253 */
   XMLSERVICE_LAST = XMLSERVICE_RANGE_END                 /* 14500 */
/* Client Kernel mesg, type 27, Range 15001 - 15250 */
   CLIENT_MSG_EVENT_NOTIFY  =  CLIENT_KERNEL_RANGE_START, /* 15001 */
   CLIENT_MSG_FORM_INTERCON                               /* 15002 */
/* Ranges for the java kernel */
   JAVA_MSG_TRIGGER = JAVA_APP_SERVER_RANGE_START,
   JAVA_MSG_EVENT_CACHE_CLEAR,
   Java_MSG_SUBSCRIBER_CACHE_CLEAR,
   JAVA_MSG_EVENT_LAST = JAVA_APP_SERVER_RANGE_END /* 15750 : reserve the final message */
/** Metadata - kernel type 30, Range 15751 - 15900 */
   METADATA_XML_TO_BINARY = METADATA_RANGE_START,        /**< 15751 - to convert a metadata XML doc into a platform dep. c-structure.*/
   METADATA_BINARY_TO_XML,                               /**< 15752 - to convert a platform dep. metadata c-structure into an XML doc.*/
   METADATA_PREPARE_UBE_CACHE,                           /**< 15753 - to prepare the persistent UBE cache. */
   METADATA_QUERY_TEST_STATUS = METADATA_RANGE_END - 3,  /**< 15897 - for querying the state of the MD kernel. */
   METADATA_START_TEST_MODE = METADATA_RANGE_END - 2,    /**< 15898 - start test mode to support mdtest test driver. */
   METADATA_END_TEST_MODE = METADATA_RANGE_END - 1,      /**< 15899 - to end test mode. */
   METADATA_LAST = METADATA_RANGE_END                    /**< 15900 */
/* XMLPublisher - kernel type 31, Range 15901 - 16150 */
   XMLP_EXECUTE_REPORT = XMLPUBLISHER_RANGE_START,       /* 15901 Phase 1 publish */
   XMLP_PUBLISH_REPORTDEF,                               /* 15902 Phase 2 publish */
   XMLP_PUBLISH_REPORTDEF_FROM_UBE,                      /* 15903 Phase 2 publish */
   XMLP_NEW_BIP_ENTRY,                                   /* BIP - hardening */
   XMLP_LAST = XMLPUBLISHER_RANGE_END                    /* 16150 */
/* Management Kernel type 32, Range 16151 - 16199 */
   MANAGEMENT_PROCLIST_REFRESH = MANAGEMENT_RANGE_START,        /* 16151 */
   MANAGEMENT_CLEAR_CACHE,                                      /* 16152 Clear Table Cache */
   MANAGEMENT_LAST = MANAGEMENT_RANGE_END                       /* 16199 */
/* Message Ranges for SBF JAVA KERNEL type 33, Range 16201 - 16450 */
/* TEXTSEARCH- kernel type 34, Range 16451 - 16600 */
   TEXT_START_INDEXING = TEXTSEARCH_RANGE_START,
   TEXT_CLEAR_INDEXING,
   TEXT_VERIFY_SES,
   TEXT_VERIFY_FTP,
   TEXT_LAST = TEXTSEARCH_RANGE_END


6604/10708       Wed Jun 10 10:43:33.957000                    xmlrequest.cpp1398
              ICU0000017 - ICU CodePage for 1252 is ibm-1252.

6604/10708       Wed Jun 10 10:55:33.002000                    callsbfmsg.c330
              Did not receive response from BSSV Server. JDENET Error = eTimeOut


Back to my problem now, I see that that UBE is trying to call a BSSV.  This eventually times out (after 12 minutes - yes that's right!!!  Don't ask - honestly) and I can see that the UBE passes the request to the jdesnet kernel, yet this kernel gets the following (immediately after the call).  I think that JDE needs to do some better error handling - because this is NEVER passed back to the UBE - it just times out... haha.

152/8584        Wed Jun 10 10:43:44.282000              netrcv.c486

        10054-Error from Host=<145 .47.230.206=""> in recv returned 10054 (WSAECONNRESET): Connection was reset by peer

So, this is what I'm trying to solve.  I know that this can come up a lot on windows.   I can see that it took 11 seconds between the last known message in the UBE log to this network error - but the UBE generally takes a little while to run.

I know that this error means that the BSSV server forcibly terminated the connection at it's end, and this is picked up by jdesnet with the error above.

What I'm trying to work out is why?  Note that this is not a "cannot connect" - it's connection reset...   My thoughts are that it's trying to use a previously opened connection and this has been swept up by the firewall (every 6 hours of unused connections are removed).

it's very difficult to prove... but I'm getting there.  Perhaps nettrace is next?  If this was AWS, I'd be able to use cloudwatch and solve it quickly.

Anyway, this was a quick helper on msgType and what you can ignore.

No comments: