13 Replies Latest reply on Jun 18, 2018 7:50 AM by Andreas Mitterdorfer

    AR Email Engine 9.1.04/18.05 - CreatorModule Hangs.

    Jakub Komorski

      Hi All,

      we've recently changed our environment - Server from Windows 2008 to 2016, DB from MSSQL2008 to 2016 and AR System from 8.1 to 9.1.04.

      On fresh server I've installed 9.1.04 and connected it to existing DB (backup from 2008 and restore on 2016).

       

      After that, we've started encountering issues with outgoing emails not being processed.

      In logs there not much about it - the only thing we can see is that CreatorModule tries to process email and then hangs. We've waited few hours but this provider is never enabled again.

       

      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:303> /* on jun. 13 2018 10:06:41.226 */ Entering
      <EML> <TID: 37> <FINEST > <LoggingModule> <CreatorModule.java:347> /* on jun. 13 2018 10:06:41.226 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]] DoMessageQ Begin 
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:671> /* on jun. 13 2018 10:06:41.226 */ Entering
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.227 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Querying the AR System Server for new outgoing emails. MailBox Name = outgoing/AREmail_ServiceDeskSystem
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.885 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Total number of emails to send are: 7, MailBox Name = outgoing/AREmail_ServiceDeskSystem
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:778> /* on jun. 13 2018 10:06:41.885 */ Exiting
      <EML> <TID: 37> <FINEST > <LoggingModule> <CreatorModule.java:350> /* on jun. 13 2018 10:06:41.885 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]] DoMessageQ fetched : 7records 
      
      
      <EML> <TID: 37> <FINEST > <LoggingModule> <CreatorModule.java:352> /* on jun. 13 2018 10:06:41.885 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]] DoMessageQ End 
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:303> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <FINEST > <LoggingModule> <CreatorModule.java:495> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]] Started createMessage for 000000009401092
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:884> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Retreiving the Entry from the AR System Server for email: 1
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Successfully loaded entry for email: 1
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Creating contents for email: 1
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:1022> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:157> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:228> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:77> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:144> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:242> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <ValidateAddress.java:391> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:1230> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:3145> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:791> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Querying the AR System Server for attachment associations for email: 1
      <EML> <TID: 37> <FINE > <LoggingModule> /* on jun. 13 2018 10:06:41.888 */ [Thread[AGHAA5V0FPKL1AN372K3BCXAAJG9DP,5,Creator Module]]Total number of associations are: 0
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:808> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:3171> /* on jun. 13 2018 10:06:41.888 */ Exiting
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:1386> /* on jun. 13 2018 10:06:41.888 */ Entering
      <EML> <TID: 37> <INFO > <LoggingModule> <CreatorModule.java:2429> /* on jun. 13 2018 10:06:41.904 */ Entering
      <EML> <TID: 34> <INFO > <LoggingModule> <CreatorModule.java:303> /* on jun. 13 2018 10:07:30.415 */ Entering
      

       

      We've investigated those blocked emails and all of them were send as reply to emails received from Outlook.

      Then further investigation told us that 98% of those can be processed (after email engine restart) when we remove <IMG> tag which has "cid:" in it, for example:

       

      <img border="0" width="400" height="93" id="_x0000_i1032" title="Attachment Image: image001.png" src="cid:image001.png" arqual="&apos;1&apos;=&quot;000000003269483&quot;" arentryid="000000003269483" arschema="AR System Email Attachments" arattid="18004" alt="18026DK_MAIL_SIGNETURE_ROADTOUR_0418.">
      

       

      We've tried updating Email Engine with patch 002 and also using the one from version 18.05.

      Nothing helps.

       

      Other providers: incoming mails, outgoing mails with plain text work all the time even if the above provider hangs.

       

      During investigation we've tried numerous parameters in EmailDeamon.properties but whithout any luck so far.

       

      Thanks for your help and Best Regards,

      Jakub