Email generated from Workflows stuck in queue

[michaeli5972889]

Hi,

I have an AEM system which we've recently upgraded from 6.0 to 6.2.  While testing the environment post upgrade we've noticed that email notifications that are triggered as part of workflows are not being sent out.  To simplify testing I created a workflow with just one step, to send an email to one user.  I also confirmed that this user has a valid email address.  When I execute this workflow it is stuck in RUNNING state and no email is sent out.  I added logging around workflows and email and see the following.

01.02.2017 14:25:05.657 *DEBUG* [CQWorkflowStatisticsService-Processor] com.day.cq.workflow.impl.statistics.CQWorkflowStatisticsService Workflow Statistics processor. Processing com/day/cq/workflow/event type: WorkflowStarted 
01.02.2017 14:25:05.657 *INFO* [Thread-12] com.day.cq.workflow.impl.statistics.CQWorkflowStatisticsService handleEvent: put event [WorkflowStarted] in queue, size now [0]
01.02.2017 14:25:05.657 *DEBUG* [Thread-12] com.day.cq.workflow.impl.email.EMailNotificationService handleEvent: put event [WorkflowStarted] in queue, size now [46]
01.02.2017 14:25:05.657 *DEBUG* [CQWorkflowStatisticsService-Processor] com.day.cq.workflow.impl.CQWorkflowService Creating GRANITE workflow session wrapper for user: workflow-service
01.02.2017 14:25:05.657 *DEBUG* [sling-threadpool-99082294-dc9c-498c-af22-0ccbd56c7bf1-(com.day.cq.wcm.workflow.impl.wcmworkflowserviceimpl)-88] com.day.cq.workflow.impl.CQWorkflowService Creating GRANITE workflow session wrapper for user: wcm-workflow-service
01.02.2017 14:25:05.688 *INFO* [Thread-16] com.day.cq.workflow.impl.statistics.CQWorkflowStatisticsService handleEvent: put event [NodeTransition] in queue, size now [1]
01.02.2017 14:25:05.688 *DEBUG* [Thread-16] com.day.cq.workflow.impl.email.EMailNotificationService handleEvent: put event [NodeTransition] in queue, size now [47]
01.02.2017 14:25:05.688 *DEBUG* [CQWorkflowStatisticsService-Processor] com.day.cq.workflow.impl.statistics.CQWorkflowStatisticsService Workflow Statistics processor. Processing com/day/cq/workflow/event type: NodeTransition 
01.02.2017 14:25:05.688 *DEBUG* [sling-threadpool-99082294-dc9c-498c-af22-0ccbd56c7bf1-(com.day.cq.wcm.workflow.impl.wcmworkflowserviceimpl)-89] com.day.cq.workflow.impl.CQWorkflowService Creating GRANITE workflow session wrapper for user: wcm-workflow-service
01.02.2017 14:25:05.688 *DEBUG* [CQWorkflowStatisticsService-Processor] com.day.cq.workflow.impl.CQWorkflowService Creating GRANITE workflow session wrapper for user: workflow-service
01.02.2017 14:25:05.751 *DEBUG* [10.11.19.14 [1485977105751] GET /libs/cq/workflow/content/console/instances.json HTTP/1.1] com.day.cq.workflow.impl.CQWorkflowService Creating GRANITE workflow session wrapper for user: admin
01.02.2017 14:25:05.860 *DEBUG* [10.11.19.14 [1485977105751] GET /libs/cq/workflow/content/console/instances.json HTTP/1.1] com.day.cq.workflow.util.WorkflowUtil WORKFLOW JOBS: 0

So I can see that it is getting added to some queue, but I have no idea where this queue is or what is in it.  

It should also be noted that the SMTP server being used is setup and working.  This worked before the AEM upgrade and no changes were made to it.  Also, emails generated by other parts of the application (like feedback forms on the publish site) generate an email as expected.  

One theroy is that there may be something wrong with the workflow service accounts.  But since these are all auto-generated I'm not sure how to check this.  Has anyone run into similar issues and resolved it?  Any advice would be appreciated.  

Thanks  

[smacdonald2008]

Issues seem to occur on upgraded instances as opposed to fresh 6,2 instances. Please file a ticket so support and Eng can be made aware of this. 

[michaeli5972889]

 

I have some additional information.  It appears the issue may be with the "Day CQ Workflow Email Notification" package.  This is not writing to the logs even though it is added to the logger.  In addition when I look at the bundle I see the following:

                                 

Symbolic Name	com.day.cq.workflow.cq-workflow-impl
Version	6.0.26
Bundle Location	jcrinstall:/libs/cq/platform/install/cq-workflow-impl-5.7.8.jar
Last Modification	Tue Aug 09 14:38:44 EDT 2016
Bundle Documentation	http://www.adobe.com/
Vendor	Adobe Systems Incorporated
Description	The Workflow Engine Implementation bundle
Start Level	20

The version does not match the bundle location.  Also, when I navigate to the bundle location this file does not seem to exist (in CRX DE Lite).  

On a vanilla 6.2 environment the version of the bundle does not match the one in the upgraded environment.  I have a screenshot of a fresh install 6.2 below.  So it appears that because we did an upgrade something was broken with this bundle.  

     

283

Day Communique 5 Workflow Implementationcom.day.cq.workflow.cq-workflow-impl                                       Symbolic Name com.day.cq.workflow.cq-workflow-impl Version 6.0.26 Bundle Location launchpad:resources/install/0/cq-workflow-impl-6.0.26.jar Last Modification Fri Dec 02 11:06:58 EST 2016 Bundle Documentation http://www.adobe.com/ Vendor Adobe Systems Incorporated Description The Workflow Engine Implementation bundle Start Level 20 Exported Packages com.day.cq.workflow.compatibility,version=5.7.0 com.day.cq.workflow.serialization,version=5.7.0 com.day.cq.workflow.util,version=6.0.0

It seems that this is likely the cause, but I am now looking into how to fix this.  Also how can identify if this same issue occurred with other bundles?  Any advice would be appreciated.  

Thanks

[puniths34934369]

Hi

We had recently upgraded from 6.0 to 6.2 and it appears to have similar problem. Stuck in Queue.

By any chance were you able to solve this issue?

    

2017-05-11 10:08:26.722 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowStarted] in queue, size now [7950]
2017-05-11 10:08:26.791 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7951]
2017-05-11 10:08:50.259 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowStarted] in queue, size now [7952]
2017-05-11 10:08:50.307 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7953]
2017-05-11 10:08:59.798 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7954]
2017-05-11 10:08:59.872 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7955]
2017-05-11 10:09:03.612 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7956]
2017-05-11 10:09:06.868 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7957]
2017-05-11 10:09:12.205 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7958]
2017-05-11 10:09:12.460 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowCompleted] in queue, size now [7959]

[puniths34934369]

Hi

We had recently upgraded from 6.0 to 6.2 and it appears to have similar problem. Stuck in Queue.

By any chance were you able to solve this issue?

    

2017-05-11 10:08:26.722 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowStarted] in queue, size now [7950]
2017-05-11 10:08:26.791 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7951]
2017-05-11 10:08:50.259 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowStarted] in queue, size now [7952]
2017-05-11 10:08:50.307 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7953]
2017-05-11 10:08:59.798 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7954]
2017-05-11 10:08:59.872 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7955]
2017-05-11 10:09:03.612 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7956]
2017-05-11 10:09:06.868 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7957]
2017-05-11 10:09:12.205 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [NodeTransition] in queue, size now [7958]
2017-05-11 10:09:12.460 DEBUG [com.day.cq.workflow.impl.email.EMailNotificationService] handleEvent: put event [WorkflowCompleted] in queue, size now [7959]

[michaeli5972889]

If I recall I created a ticket with Adobe and they provided me a patch.  This was a known issue with the upgrade.  

[shubha_kirani]

We recently upgraded from 6.0 to 6.3 and seeing this issue.