28 August 2014

ADMU3007E: Exception com.ibm.websphere.management.exception.AdminException: ADMU3027E: An instance of the server may already be running

So, I didn't went very far away from WebSphere in this one. Just yesterday one of my colleagues asked me for help while attempting to start nawely installed WAS on newly installed Linux OS.

He was getting standard "specified port busy" message and exceptions in the logs:

[8/27/14 13:17:48:979 CEST] 00000001 AdminTool     A   ADMU3028I: Conflict detected on port 8879.  Likely causes: a) An instance of the server dmgr is already running  b) some other process is using port 8879
[8/27/14 13:17:48:980 CEST] 00000001 AdminTool     A   ADMU3029I: Conflict detected on port 8879 for endpoint SOAP_CONNECTOR_ADDRESS of the server dmgr 
[8/27/14 13:17:48:980 CEST] 00000001 AdminTool     A   ADMU3027E: An instance of the server may already be running: dmgr
[8/27/14 13:17:48:981 CEST] 00000001 WsServerLaunc E   ADMU3002E: Exception attempting to process server dmgr
[8/27/14 13:17:48:981 CEST] 00000001 WsServerLaunc E   ADMU3007E: Exception com.ibm.websphere.management.exception.AdminException: ADMU3027E: An instance of the server may already be running: dmgr
at com.ibm.ws.management.tools.WsServerLauncher.runTool(WsServerLauncher.java:318)
at com.ibm.ws.management.tools.AdminTool.executeUtility(AdminTool.java:269)
at com.ibm.ws.management.tools.WsServerLauncher.main(WsServerLauncher.java:134)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.ibm.ws.bootstrap.WSLauncher.main(WSLauncher.java:277)

Usual (for the case) check of netstat -an | grep 8879 and ps -ef | grep dmgr didn't show any rogue or orphaned processes running in the system, so initially the cause was not apparent. But, I tried to start the server with -trace flag which gives you (sometimes) a lot of additional information on server startup process and.....we found the culprit:

[27.08.14 15:11:36:362 CEST] 00000001 ConnectorHelp >  getOpenConnectorPorts: false Entry
[27.08.14 15:11:36:362 CEST] 00000001 ConnectorHelp 3   testing host: fully_qualified_hostname, port: 8879
[27.08.14 15:11:36:362 CEST] 00000001 ConnectorHelp 3   trying host: fully_qualified_hostname, port: 8879
[27.08.14 15:11:36:366 CEST] 00000001 ConnectorHelp 3   determined host: fully_qualified_hostname, port: 8879  in use
[27.08.14 15:11:36:366 CEST] 00000001 AdminTool     A   ADMU3028I: Wykryto konflikt na porcie 8879.  Możliwe przyczyny: a) Instancja serwera dmgr została już uruchomiona.  b) Port 8879 jest używany przez inny proces.
[27.08.14 15:11:36:366 CEST] 00000001 AdminTool     A   ADMU3029I: Wykryto konflikt na porcie 8879 dla punktu końcowego SOAP_CONNECTOR_ADDRESS serwera dmgr
[27.08.14 15:11:36:367 CEST] 00000001 AdminTool     A   ADMU3027E: Możliwe, że działa już instancja tego serwera: dmgr
[27.08.14 15:11:36:367 CEST] 00000001 WsServerLaunc E   ADMU3002E: Wyjątek podczas próby przetworzenia serwera dmgr
[27.08.14 15:11:36:368 CEST] 00000001 WsServerLaunc E   ADMU3007E: Wyjątek com.ibm.websphere.management.exception.AdminException: ADMU3027E: Możliwe, że działa już instancja tego serwera: dmgr

so, only after using -trace those two key log lines appear, telling you what exactly host your jvm is trying to use to open sockets. Being sure no process occupies port 8879, I checked /etc/hosts and found there only:

127.0.0.1 localhost

entry. So there was no way WAS could resolve port 8879 on fully_qualified_hostname! I simply added:

127.0.0.1 fully_qualified_hostname 

there, saved, and the very next attempt to start the server was successful:

[27.08.14 15:11:36:371 CEST] 00000001 AdminTool     A   ADMU0111E: Program zakończył pracę z błędem: com.ibm.websphere.management.exception.AdminException: ADMU3027E: Możliwe, że działa już instancja tego serwera: dmgr
at com.ibm.ws.management.tools.WsServerLauncher.runTool(WsServerLauncher.java:318)
at com.ibm.ws.management.tools.AdminTool.executeUtility(AdminTool.java:269)
at com.ibm.ws.management.tools.WsServerLauncher.main(WsServerLauncher.java:134)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.ibm.ws.bootstrap.WSLauncher.main(WSLauncher.java:277)

[27.08.14 15:11:36:372 CEST] 00000001 AdminTool     3   Returning from auxiliary method issueMessage with return code: 111
[27.08.14 15:11:36:372 CEST] 00000001 AdminTool     A   ADMU0211I: Szczegóły dotyczące błędu można znaleźć w pliku: /opt/IBM/WebSphere/AppServer/profiles/Dmgr01/logs/dmgr/startServer.log
[27.08.14 15:11:36:372 CEST] 00000001 AdminTool     3   Returning from auxiliary method issueMessage with return code: 211
[27.08.14 15:11:36:373 CEST] 00000001 AdminTool     3   Returning from executeUtility method with return code: -1
************ Start Display Current Environment ************
Host Operating System is Linux, version 3.10.0-123.el7.x86_64
Java version = 1.6.0, Java Compiler = j9jit26, Java VM name = IBM J9 VM
was.install.root = /opt/IBM/WebSphere/AppServer
user.install.root = /opt/IBM/WebSphere/AppServer/profiles/Dmgr01
Java Home = /opt/IBM/WebSphere/AppServer/java/jre
ws.ext.dirs = /opt/IBM/WebSphere/AppServer/java/lib:/opt/IBM/WebSphere/AppServer/classes:/opt/IBM/WebSphere/AppServer/lib:/opt/IBM/WebSphere/AppServer/installedChannels:/opt/IBM/WebSphere/AppServer/lib/ext:/opt/IBM/WebSphere/AppServer/web/help:/opt/IBM/WebSphere/AppServer/deploytool/itp/plugins/com.ibm.etools.ejbdeploy/runtime
Classpath = /opt/IBM/WebSphere/AppServer/profiles/Dmgr01/properties:/opt/IBM/WebSphere/AppServer/properties:/opt/IBM/WebSphere/AppServer/lib/startup.jar:/opt/IBM/WebSphere/AppServer/lib/bootstrap.jar:/opt/IBM/WebSphere/AppServer/java/lib/tools.jar:/opt/IBM/WebSphere/AppServer/lib/lmproxy.jar:/opt/IBM/WebSphere/AppServer/lib/urlprotocols.jar
Java Library path = /opt/IBM/WebSphere/AppServer/java/jre/lib/amd64/compressedrefs:/opt/IBM/WebSphere/AppServer/java/jre/lib/amd64:/opt/IBM/WebSphere/AppServer/lib/native/linux/x86_64/:/opt/IBM/WebSphere/AppServer/bin::/usr/lib
Orb Version = IBM Java ORB build orb626-20130112.01
Current trace specification = *=info
************* End Display Current Environment *************
[27.08.14 15:14:17:349 CEST] 00000001 ManagerAdmin  I   TRAS0017I: Początkowy stan śledzenia: *=info.
[27.08.14 15:14:17:402 CEST] 00000001 AdminTool     A   ADMU0128I: Uruchamianie narzędzia w oparciu o profil Dmgr01
[27.08.14 15:14:17:406 CEST] 00000001 AdminTool     A   ADMU3100I: Odczyt konfiguracji serwera: dmgr
[27.08.14 15:14:17:416 CEST] 00000001 ImplFactory   W   WSVR0072W: Niezadeklarowane przesłonięcie interfejsu com.ibm.websphere.cluster.topography.DescriptionManager implementacją com.ibm.ws.cluster.propagation.bulletinboard.BBDescriptionManager jest ignorowane
[27.08.14 15:14:17:563 CEST] 00000001 ModelMgr      I   WSVR0801I: Inicjowanie wszystkich modeli konfiguracji serwera
[27.08.14 15:14:19:761 CEST] 00000001 WorkSpaceMana A   WKSP0500I: Funkcja sprawdzania spójności konfiguracji obszaru roboczego: wyłączone.
[27.08.14 15:14:19:914 CEST] 00000001 AdminTool     A   ADMU3200I: Serwer został uruchomiony. Oczekiwanie na status inicjowania.
[27.08.14 15:14:41:275 CEST] 00000001 AdminTool     A   ADMU3000I: Serwer dmgr został otwarty dla e-biznesu. Identyfikator procesu to 29871


Hope this helps! Good luck!