Unable to process message MessageListenerException on portal startup

• Type: Regression Bug
• Status: Closed
• Resolution: Fixed
• Affects Version/s: 7.0.0 M5
• Fix Version/s: 7.0.0 M5
• Component/s: Core Infrastructure
• Labels:
  • QA-AUTOMATION
  • team_marketplace
• Fix Priority: 5
• Git Pull Request: https://github.com/brianchandotcom/liferay-portal/pull/26330

Steps to reproduce:

1. Startup portal (Sometimes, it won't happen on the first startup, but shutting down and then restarting portal will reproduce the error.

Expected result:
No console errors.

Actual result:
The following console error is thrown (naming marketplace and polls plugins as problematic):

17:48:04,829 ERROR [liferay/hot_deploy-1][SerialDestination:61] Unable to process message {destinationName=liferay/hot_deploy, response=null, responseDestinationName=null, responseId=null, payload=null, values={defaultLocale=en_US, groupId=0, command=deploy, companyId=20152, servletContextName=marketplace-web}}
com.liferay.portal.kernel.messaging.MessageListenerException: java.lang.NullPointerException
        at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:32)
        at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
        at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
        at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:756)
        at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:667)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
        at com.liferay.marketplace.service.AppLocalServiceUtil.clearInstalledAppsCache(AppLocalServiceUtil.java:58)
        at com.liferay.marketplace.web.messaging.HotDeployMessageListener.doReceive(HotDeployMessageListener.java:28)
        at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
        ... 5 more
17:48:04,881 INFO  [localhost-startStop-1][HotDeployImpl:217] Deploying polls-web from queue
17:48:04,881 INFO  [localhost-startStop-1][PluginPackageUtil:1006] Reading plugin package for polls-web
Loading bundleresource://154.fwk1713761390/portlet.properties
Loading bundleresource://154.fwk1713761390/portlet.properties
Apr 28, 2015 5:48:04 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
17:48:04,987 INFO  [localhost-startStop-1][PortletHotDeployListener:237] Registering portlets for polls-web
Loading bundleresource://132.fwk1713761390/portlet.properties
Loading bundleresource://154.fwk1713761390/portlet.properties
17:48:05,110 INFO  [localhost-startStop-1][PortletHotDeployListener:382] 2 portlets for polls-web are available for use
17:48:05,111 ERROR [liferay/hot_deploy-1][SerialDestination:61] Unable to process message {destinationName=liferay/hot_deploy, response=null, responseDestinationName=null, responseId=null, payload=null, values={defaultLocale=en_US, groupId=0, command=deploy, companyId=20152, servletContextName=polls-web}}
com.liferay.portal.kernel.messaging.MessageListenerException: java.lang.NullPointerException
        at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:32)
        at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
        at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
        at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:756)
        at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:667)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
        at com.liferay.marketplace.service.AppLocalServiceUtil.clearInstalledAppsCache(AppLocalServiceUtil.java:58)
        at com.liferay.marketplace.web.messaging.HotDeployMessageListener.doReceive(HotDeployMessageListener.java:28)
        at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
        ... 5 more

In our latest Jenkins master run, we see wiki-web and bookmarks-web getting thrown under the bus:

    [exec] 14:12:13,325 INFO  [localhost-startStop-1][PortletHotDeployListener:382] 3 portlets for marketplace-web are available for use
     [exec] 14:12:13,329 ERROR [liferay/hot_deploy-1][SerialDestination:61] Unable to process message {destinationName=liferay/hot_deploy, response=null, responseDestinationName=null, responseId=null, payload=null, values={defaultLocale=en_US, groupId=0, command=deploy, companyId=20152, servletContextName=marketplace-web}}
     [exec] com.liferay.portal.kernel.messaging.MessageListenerException: java.lang.NullPointerException
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:32)
     [exec] 	at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
     [exec] 	at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:756)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:667)
     [exec] 	at java.lang.Thread.run(Thread.java:744)
     [exec] Caused by: java.lang.NullPointerException
     [exec] 	at com.liferay.marketplace.service.AppLocalServiceUtil.clearInstalledAppsCache(AppLocalServiceUtil.java:58)
     [exec] 	at com.liferay.marketplace.web.messaging.HotDeployMessageListener.doReceive(HotDeployMessageListener.java:28)
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
     [exec] 	... 5 more
     [exec] 14:12:13,413 INFO  [localhost-startStop-1][HotDeployImpl:217] Deploying bookmarks-web from queue
     [exec] 14:12:13,414 INFO  [localhost-startStop-1][PluginPackageUtil:1006] Reading plugin package for bookmarks-web
     [exec] Apr 28, 2015 2:12:13 PM org.apache.catalina.core.ApplicationContext log
     [exec] INFO: Initializing Spring root WebApplicationContext
     [exec] Loading bundleresource://85.fwk731664706/portlet.properties
     [exec] Loading bundleresource://85.fwk731664706/portlet.properties
     [exec] 14:12:13,455 INFO  [localhost-startStop-1][PortletHotDeployListener:237] Registering portlets for bookmarks-web
     [exec] Loading bundleresource://85.fwk731664706/portlet.properties
     [exec] Loading bundleresource://85.fwk731664706/portlet.properties
     [exec] 14:12:13,983 INFO  [localhost-startStop-1][PortletHotDeployListener:382] 2 portlets for bookmarks-web are available for use
     [exec] 14:12:13,983 INFO  [localhost-startStop-1][SocialHotDeployListener:88] Registering social for bookmarks-web
     [exec] 14:12:13,985 INFO  [localhost-startStop-1][SocialHotDeployListener:97] Social for bookmarks-web is available for use
     [exec] 14:12:13,986 ERROR [liferay/hot_deploy-1][SerialDestination:61] Unable to process message {destinationName=liferay/hot_deploy, response=null, responseDestinationName=null, responseId=null, payload=null, values={defaultLocale=en_US, groupId=0, command=deploy, companyId=20152, servletContextName=bookmarks-web}}
     [exec] com.liferay.portal.kernel.messaging.MessageListenerException: java.lang.NullPointerException
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:32)
     [exec] 	at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
     [exec] 	at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:756)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:667)
     [exec] 	at java.lang.Thread.run(Thread.java:744)
     [exec] Caused by: java.lang.NullPointerException
     [exec] 	at com.liferay.marketplace.service.AppLocalServiceUtil.clearInstalledAppsCache(AppLocalServiceUtil.java:58)
     [exec] 	at com.liferay.marketplace.web.messaging.HotDeployMessageListener.doReceive(HotDeployMessageListener.java:28)
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
     [exec] 	... 5 more
     [exec] 14:12:14,036 INFO  [localhost-startStop-1][HotDeployImpl:217] Deploying wiki-web from queue
     [exec] 14:12:14,036 INFO  [localhost-startStop-1][PluginPackageUtil:1006] Reading plugin package for wiki-web
     [exec] Apr 28, 2015 2:12:14 PM org.apache.catalina.core.ApplicationContext log
     [exec] INFO: Initializing Spring root WebApplicationContext
     [exec] Loading bundleresource://102.fwk731664706/portlet.properties
     [exec] Loading bundleresource://102.fwk731664706/portlet.properties
     [exec] 14:12:14,093 INFO  [localhost-startStop-1][PortletHotDeployListener:237] Registering portlets for wiki-web
     [exec] Loading bundleresource://102.fwk731664706/portlet.properties
     [exec] Loading bundleresource://102.fwk731664706/portlet.properties
     [exec] 14:12:14,684 INFO  [localhost-startStop-1][PortletHotDeployListener:382] 3 portlets for wiki-web are available for use
     [exec] 14:12:14,685 INFO  [localhost-startStop-1][SocialHotDeployListener:88] Registering social for wiki-web
     [exec] 14:12:14,687 INFO  [localhost-startStop-1][SocialHotDeployListener:97] Social for wiki-web is available for use
     [exec] 14:12:14,688 ERROR [liferay/hot_deploy-1][SerialDestination:61] Unable to process message {destinationName=liferay/hot_deploy, response=null, responseDestinationName=null, responseId=null, payload=null, values={defaultLocale=en_US, groupId=0, command=deploy, companyId=20152, servletContextName=wiki-web}}
     [exec] com.liferay.portal.kernel.messaging.MessageListenerException: java.lang.NullPointerException
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:32)
     [exec] 	at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
     [exec] 	at com.liferay.portal.kernel.messaging.SerialDestination$1.run(SerialDestination.java:58)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:756)
     [exec] 	at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:667)
     [exec] 	at java.lang.Thread.run(Thread.java:744)
     [exec] Caused by: java.lang.NullPointerException
     [exec] 	at com.liferay.marketplace.service.AppLocalServiceUtil.clearInstalledAppsCache(AppLocalServiceUtil.java:58)
     [exec] 	at com.liferay.marketplace.web.messaging.HotDeployMessageListener.doReceive(HotDeployMessageListener.java:28)
     [exec] 	at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:26)
     [exec] 	... 5 more

Note: The error doesn't always throw right away - sometimes it throws after a few minutes.