Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.1_b43
    • Fix Version/s: 3.1.1_b01
    • Component/s: logging
    • Labels:
      None
    • Environment:

      solaris sparc

      Description

      I'm trying to start a standalone instance but the action hangs from both Admin Console and CLI. After trying with --verbose, with Joe's advice, here is what I see:

      tuppy(j2eetest):/export/home/j2eetest/v3.1/glassfish3/glassfish# a start-local-instance --verbose in1
      CLI801 Instance is already synchronized
      Mar 4, 2011 5:52:23 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
      INFO: JVM invocation command line:
      /export/home/j2eetest/jdk/bin/java
      -cp
      /export/home/j2eetest/v3.1/glassfish3/glassfish/modules/glassfish.jar
      -XX:+UnlockDiagnosticVMOptions
      -XX:MaxPermSize=192m
      -XX:NewRatio=2
      -Xmx512m
      -javaagent:/export/home/j2eetest/v3.1/glassfish3/glassfish/lib/monitor/btrace-agent.jar=unsafe=true,noServer=true
      -server
      -Dosgi.shell.telnet.maxconn=1
      -Dfelix.fileinstall.disableConfigSave=false
      -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver
      -Dfelix.fileinstall.dir=/export/home/j2eetest/v3.1/glassfish3/glassfish/modules/autostart/
      -Djavax.net.ssl.keyStore=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/keystore.jks
      -Dosgi.shell.telnet.port=26666
      -Djava.security.policy=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/server.policy
      -Dfelix.fileinstall.log.level=3
      -Dfelix.fileinstall.poll=5000
      -Dcom.sun.aas.instanceRoot=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1
      -Dosgi.shell.telnet.ip=127.0.0.1
      -Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory
      -Djava.endorsed.dirs=/export/home/j2eetest/v3.1/glassfish3/glassfish/modules/endorsed:/export/home/j2eetest/v3.1/glassfish3/glassfish/lib/endorsed
      -Dcom.sun.aas.installRoot=/export/home/j2eetest/v3.1/glassfish3/glassfish
      -Dfelix.fileinstall.bundles.startTransient=true
      -Djava.ext.dirs=/export/home/j2eetest/jdk/lib/ext:/export/home/j2eetest/jdk/jre/lib/ext:/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/lib/ext
      -Dfelix.fileinstall.bundles.new.start=true
      -Djavax.net.ssl.trustStore=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/cacerts.jks
      -Dorg.glassfish.additionalOSGiBundlesToStart=org.apache.felix.shell,org.apache.felix.gogo.runtime,org.apache.felix.gogo.shell,org.apache.felix.gogo.command
      -Dcom.sun.enterprise.security.httpsOutboundKeyAlias=s1as
      -Djava.security.auth.login.config=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/login.conf
      -DANTLR_USE_DIRECT_CLASS_LOADING=true
      Dgosh.args=-noshutdown -c noop=true
      -Djava.library.path=/export/home/j2eetest/v3.1/glassfish3/glassfish/lib:/export/home/j2eetest/jdk/jre/lib/sparc/server:/export/home/j2eetest/jdk/jre/lib/sparc:/export/home/j2eetest/jdk/lib/sparc:/usr/jdk/packages/lib/sparc:/lib:/usr/lib
      com.sun.enterprise.glassfish.bootstrap.ASMain
      -asadmin-args
      -host,,,localhost,,,port,,,4848,,,secure=false,,,terse=false,,,echo=false,,,interactive=false,,,start-local-instance,,,verbose=true,,,-debug=false,,,in1
      -instancename
      in1
      -verbose
      true
      -debug
      false
      -asadmin-classpath
      /export/home/j2eetest/v3.1/glassfish3/glassfish/modules/admin-cli.jar
      -asadmin-classname
      com.sun.enterprise.admin.cli.AsadminMain
      -upgrade
      false
      -type
      INSTANCE
      -instancedir
      /export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1
      -read-stdin
      true
      Mar 4, 2011 5:52:23 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
      INFO: Successfully launched in 100 msec.
      Launching GlassFish on Felix platform
      Exception in thread "main" java.lang.reflect.InvocationTargetException
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at com.sun.enterprise.glassfish.bootstrap.GlassFishMain.main(GlassFishMain.java:97)
      at com.sun.enterprise.glassfish.bootstrap.ASMain.main(ASMain.java:55)
      Caused by: java.lang.NullPointerException
      at com.sun.enterprise.server.logging.SyslogHandler.postConstruct(SyslogHandler.java:88)
      at com.sun.hk2.component.AbstractCreatorImpl.inject(AbstractCreatorImpl.java:131)
      at com.sun.hk2.component.ConstructorCreator.initialize(ConstructorCreator.java:91)
      at com.sun.hk2.component.AbstractCreatorImpl.get(AbstractCreatorImpl.java:82)
      at com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:67)
      at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
      at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
      at org.jvnet.hk2.component.Habitat$5.get(Habitat.java:701)
      at java.util.AbstractList$Itr.next(AbstractList.java:345)
      at com.sun.enterprise.server.logging.LogManagerService.postConstruct(LogManagerService.java:263)
      at com.sun.hk2.component.AbstractCreatorImpl.inject(AbstractCreatorImpl.java:131)
      at com.sun.hk2.component.ConstructorCreator.initialize(ConstructorCreator.java:91)
      at com.sun.hk2.component.AbstractCreatorImpl.get(AbstractCreatorImpl.java:82)
      at com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:67)
      at com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
      at com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
      at com.sun.enterprise.v3.server.AppServerStartup.run(AppServerStartup.java:219)
      at com.sun.enterprise.v3.server.AppServerStartup.start(AppServerStartup.java:135)
      at com.sun.enterprise.glassfish.bootstrap.GlassFishImpl.start(GlassFishImpl.java:79)
      at com.sun.enterprise.glassfish.bootstrap.GlassFishMain$Launcher.launch(GlassFishMain.java:117)
      ... 6 more

      The exception seems to come from logging, hence I'm logging this bug under this module.

      A little background: I've been using this solaris system for verifying 3.1 bugs for the past week or so. I encountered this issue yesterday. The last thing I did was undeploy a hello.war application from this instance while it was stopped (didn't actually mean to do this). When I went to the standalone instance's page and clicked on Start button. The "processing, please wait" message was displayed and never went away. I checked CLI and it reported this instance as stopped but with odd status:

      tuppy(j2eetest):/export/home/j2eetest/v3.1/glassfish3/glassfish/domains/domain1/logs# a list-instances
      in1 not running [pending config changes are: _get-runtime-info; _get-runtime-info; ]
      c1in1 running
      in2 not running
      Command list-instances executed successfully.

      After reloading Admin Console, the instance was reported as stopped there too.

      I checked jps -v and it looked like there were two in1 processes running:

      tuppy(j2eetest):/export/home/j2eetest/v3.1/glassfish3/glassfish/domains/domain1/logs# jps -v
      8743 ASMain -XX:+UnlockDiagnosticVMOptions -XX:MaxPermSize=192m -XX:NewRatio=2 -Xmx512m -javaagent:/export/home/j2eetest/v3.1/glassfish3/glassfish/lib/monitor/btrace-agent.jar=unsafe=true,noServer=true -Dosgi.shell.telnet.maxconn=1 -Dfelix.fileinstall.disableConfigSave=false -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver -Dfelix.fileinstall.dir=/export/home/j2eetest/v3.1/glassfish3/glassfish/modules/autostart/ -Djavax.net.ssl.keyStore=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/keystore.jks -Dosgi.shell.telnet.port=26666 -Djava.security.policy=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/server.policy -Dfelix.fileinstall.log.level=3 -Dfelix.fileinstall.poll=5000 -Dcom.sun.aas.instanceRoot=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1 -Dosgi.shell.telnet.ip=127.0.0.1 -Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory -Djava.endorsed.
      ...
      8691 ASMain -XX:+UnlockDiagnosticVMOptions -XX:MaxPermSize=192m -XX:NewRatio=2 -Xmx512m -javaagent:/export/home/j2eetest/v3.1/glassfish3/glassfish/lib/monitor/btrace-agent.jar=unsafe=true,noServer=true -Dosgi.shell.telnet.maxconn=1 -Dfelix.fileinstall.disableConfigSave=false -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver -Dfelix.fileinstall.dir=/export/home/j2eetest/v3.1/glassfish3/glassfish/modules/autostart/ -Djavax.net.ssl.keyStore=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/keystore.jks -Dosgi.shell.telnet.port=26666 -Djava.security.policy=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1/config/server.policy -Dfelix.fileinstall.log.level=3 -Dfelix.fileinstall.poll=5000 -Dcom.sun.aas.instanceRoot=/export/home/j2eetest/v3.1/glassfish3/glassfish/nodes/localhost-domain1/in1 -Dosgi.shell.telnet.ip=127.0.0.1 -Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory -Djava.endorsed.

      At this point I asked Joe for help and he confirmed that indeed there were two in1 processes on the system. I'm attaching thread dump for both of them. I also checked instance's server.log and it looks like the shutdown from that day was not clean. Here is the output of the shutdown from a couple days earlier on the same instance that completed:

      [#|2011-02-23T19:04:20.327-0800|INFO|oracle-glassfish3.1|javax.enterprise.system
      .tools.admin.org.glassfish.server|_ThreadID=79;_ThreadName=Thread-2;|JMXStartupS
      ervice: Stopped JMXConnectorServer: null|#]

      [#|2011-02-23T19:04:20.329-0800|INFO|oracle-glassfish3.1|javax.enterprise.system
      .tools.admin.org.glassfish.server|_ThreadID=79;_ThreadName=Thread-2;|JMXStartupS
      ervice and JMXConnectors have been shut down.|#]

      [#|2011-02-23T19:04:20.330-0800|INFO|oracle-glassfish3.1|javax.enterprise.system
      .core.com.sun.enterprise.v3.server|_ThreadID=79;_ThreadName=Thread-2;|Shutdown p
      rocedure finished|#]

      Feb 25, 2011 12:13:58 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
      INFO: JVM invocation command line:
      /export/home/j2eetest/jdk/bin/java

      While the latest shutdown is missing the "Shutdown procedure finished" line:

      [#|2011-03-03T15:49:31.811-0800|INFO|oracle-glassfish3.1|javax.enterprise.system
      .tools.admin.org.glassfish.server|_ThreadID=1120;_ThreadName=Thread-2;|JMXStartu
      pService: Stopped JMXConnectorServer: null|#]

      [#|2011-03-03T15:49:31.813-0800|INFO|oracle-glassfish3.1|javax.enterprise.system
      .tools.admin.org.glassfish.server|_ThreadID=1120;_ThreadName=Thread-2;|JMXStartu
      pService and JMXConnectors have been shut down.|#]

      Mar 3, 2011 3:51:25 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
      INFO: JVM invocation command line:
      /export/home/j2eetest/jdk/bin/java

      At this point, I killed both processes and tried to start the instance again - it would still hang and the output of the verbose option is listed at the top (hence we came the full circle). I'm attaching server.log from the start of testing till the initial startup hang and thread dumps of both processes that belonged to the instance. The machine is still available for debugging.

      1. 8691
        5 kB
        lidiam
      2. 8743
        5 kB
        lidiam
      3. server.log.started-notrunning
        60 kB
        lidiam

        Activity

          People

          • Assignee:
            naman_mehta
            Reporter:
            lidiam
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: