9 Replies Latest reply on May 21, 2009 3:11 PM by ips

    StackOverflowError in ResourceContainer

    sanjoa

      Our jopr agent logs contain a lot of stack overflow errors, any clues how to avoid this?

      agent.log-2009-05-18 18:03:02,064 INFO [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Starting configuration update check
      agent.log-2009-05-18 18:03:11,779 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      --
      agent.log-2009-05-18 19:03:04,349 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
      agent.log-2009-05-18 19:03:12,240 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      --
      agent.log-2009-05-18 20:03:08,093 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
      agent.log-2009-05-18 20:03:14,430 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      --
      agent.log-2009-05-18 21:03:12,250 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
      agent.log-2009-05-18 21:03:12,410 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      --
      agent.log-2009-05-18 23:03:02,065 INFO [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Starting configuration update check
      agent.log-2009-05-18 23:03:15,554 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      --
      agent.log-2009-05-19 00:03:02,064 INFO [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Starting configuration update check
      agent.log-2009-05-19 00:03:15,929 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      agent.log:java.lang.Exception: java.lang.StackOverflowError
      --
      agent.log- at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      agent.log- at java.lang.Thread.run(Unknown Source)
      agent.log:Caused by: java.lang.StackOverflowError
      ..
      


      2009-05-18 17:02:32,040 INFO [MeasurementManager.sender-1] (rhq.core.pc.measurement.MeasurementCollectorRunner)- Measurement collection for [8] metrics took 2ms - sending report to Server...
      2009-05-18 17:02:55,401 INFO [InventoryManager.availability-1] (rhq.core.pc.inventory.InventoryManager)- Sending availability report to Server...
      2009-05-18 17:03:02,058 INFO [ResourceContainer.invoker.daemon-106] (rhq.plugins.www.snmp.SNMPClient)- Initialized SNMP session for agent at /127.0.0.1:1610
      2009-05-18 17:03:02,065 INFO [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Starting configuration update check
      2009-05-18 17:03:16,504 WARN [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- Unable to check for updated configuration
      java.lang.Exception: java.lang.StackOverflowError
       at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocationThread.call(ResourceContainer.java:488)
       at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
       at java.util.concurrent.FutureTask.run(Unknown Source)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
       at java.lang.Thread.run(Unknown Source)
      Caused by: java.lang.StackOverflowError
       at java.security.AccessController.doPrivileged(Native Method)
       at sun.rmi.server.MarshalOutputStream.<init>(Unknown Source)
       at sun.rmi.server.MarshalOutputStream.<init>(Unknown Source)
       at sun.rmi.transport.ConnectionOutputStream.<init>(Unknown Source)
       at sun.rmi.transport.StreamRemoteCall.getOutputStream(Unknown Source)
       at sun.rmi.transport.StreamRemoteCall.getOutputStream(Unknown Source)
       at sun.rmi.transport.StreamRemoteCall.<init>(Unknown Source)
       at sun.rmi.server.UnicastRef.invoke(Unknown Source)
       at com.sun.jmx.remote.internal.PRef.invoke(Unknown Source)
       at javax.management.remote.rmi.RMIConnectionImpl_Stub.invoke(Unknown Source)
       at javax.management.remote.rmi.RMIConnector$RemoteMBeanServerConnection.invoke(Unknown Source)
       at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
       at java.lang.reflect.Method.invoke(Unknown Source)
       at org.mc4j.ems.impl.jmx.connection.support.providers.proxy.JMXRemotingMBeanServerProxy.invoke(JMXRemotingMBeanServerProxy.java:61)
       at $Proxy40.invoke(Unknown Source)
       at com.sun.jmx.mbeanserver.MXBeanProxy$InvokeHandler.invoke(Unknown Source)
       at com.sun.jmx.mbeanserver.MXBeanProxy.invoke(Unknown Source)
       at javax.management.MBeanServerInvocationHandler.invoke(Unknown Source)
       at $Proxy52.getLoggerLevel(Unknown Source)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:71)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
       at org.rhq.plugins.jmx.JavaUtilLoggingResourceComponent.getLoggerLevel(JavaUtilLoggingResourceComponent.java:74)
      ..
      


        • 1. Re: StackOverflowError in ResourceContainer
          ips

          Hi, it looks like the infinite recursion was happening in the unusual case where the root logger had no explicit level. We haven't come across this before. What OS and JDK version is the JDK used by the managed server?

          In any case, I've added a check that will prevent the infinite recursion from happening (see http://jira.rhq-project.org/browse/RHQ-2096 ).

          • 2. Re: StackOverflowError in ResourceContainer
            sanjoa

            We're using sun jdk 1.6 u13 and ubuntu 9.04

            • 3. Re: StackOverflowError in ResourceContainer
              ips

              Hmm, that's a very recent JDK update. I was thinking you were possibly using some very early update like u01.

              Can you post the logging.properties file that was being used by the managed server's JVM?

              • 4. Re: StackOverflowError in ResourceContainer
                sanjoa

                rhq-agent-env.sh

                RHQ_AGENT_DEBUG=true
                RHQ_AGENT_SIGAR_DEBUG=true
                


                I've only adjusted some of the logging levels, root category is unchanged.
                <?xml version="1.0" encoding="UTF-8"?>
                <!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
                
                <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
                
                 <!-- ============================== -->
                 <!-- Append messages to the console -->
                 <!-- ============================== -->
                
                 <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
                 <param name="Threshold" value="DEBUG"/>
                 <param name="Target" value="System.out"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <!-- The default pattern: Date Priority [Category] Message\n -->
                 <param name="ConversionPattern" value="%d{ISO8601} %-5p [%t] (%c{5}) - %m%n"/>
                 </layout>
                 </appender>
                
                 <!-- ================================= -->
                 <!-- Append messages to a rolling file -->
                 <!-- ================================= -->
                 <appender name="FILE" class="org.apache.log4j.RollingFileAppender">
                
                 <param name="Threshold" value="DEBUG"/>
                 <param name="File" value="logs/agent.log"/>
                 <param name="MaxBackupIndex" value="2"/>
                 <param name="MaxFileSize" value="5000KB"/>
                 <param name="Append" value="true"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d{ISO8601} %-5p [%t] (%c{5})- %m%n"/>
                 </layout>
                
                 </appender>
                
                 <!-- ====================================== -->
                 <!-- Append command trace to a rolling file -->
                 <!-- ====================================== -->
                 <appender name="COMMANDTRACE" class="org.apache.log4j.RollingFileAppender">
                
                 <param name="Threshold" value="TRACE"/>
                 <param name="File" value="logs/command-trace.log"/>
                 <param name="MaxBackupIndex" value="9"/>
                 <param name="MaxFileSize" value="10MB"/>
                 <param name="Append" value="true"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d{ISO8601} %-5p %m%n"/>
                 </layout>
                
                 </appender>
                 <!-- ================ -->
                 <!-- Limit categories -->
                 <!-- ================ -->
                
                 <!-- RHQ -->
                 <category name="org.rhq">
                 <priority value="DEBUG"/>
                 </category>
                
                 <!-- RHQ outgoing command tracing - set to TRACE to trace commands sent by the agent -->
                 <category name="org.rhq.enterprise.communications.command.client.OutgoingCommandTrace">
                 <priority value="DEBUG"/>
                 <appender-ref ref="COMMANDTRACE"/>
                 </category>
                
                 <!-- RHQ incoming command tracing - set to TRACE to trace commands coming in from the Server -->
                 <category name="org.rhq.enterprise.communications.command.server.IncomingCommandTrace">
                 <priority value="NONE"/>
                 <appender-ref ref="COMMANDTRACE"/>
                 </category>
                
                 <!-- JBoss/Remoting - for low level communications layer tracing -->
                 <!--
                 <category name="org.jboss.remoting">
                 <priority value="TRACE" class="org.jboss.logging.XLevel"/>
                 </category>
                 -->
                
                 <!-- EMS can be noisy with its WARN messages - uncomment the below to suppress them. -->
                 <!--
                 <category name="org.mc4j.ems">
                 <priority value="ERROR"/>
                 </category>
                 -->
                
                 <!-- ======================= -->
                 <!-- Setup the Root category -->
                 <!-- ======================= -->
                
                 <root>
                 <priority value="INFO"/>
                 <appender-ref ref="FILE"/>
                 <!-- <appender-ref ref="CONSOLE"/> -->
                 </root>
                
                </log4j:configuration>
                


                • 5. Re: StackOverflowError in ResourceContainer
                  mazz

                  That's the log4j log configuration - that's not where the problem was. The problem occurred in the java.util.logging (aka JDK logging) configuration.

                  • 6. Re: StackOverflowError in ResourceContainer
                    sanjoa

                    Sorry, I didn't notice that in the error message.

                    /usr/lib/jvm/jre1.6.0_13/lib/logging.properties

                    ############################################################
                    # Default Logging Configuration File
                    #
                    # You can use a different file by specifying a filename
                    # with the java.util.logging.config.file system property.
                    # For example java -Djava.util.logging.config.file=myfile
                    ############################################################
                    
                    ############################################################
                    # Global properties
                    ############################################################
                    
                    # "handlers" specifies a comma separated list of log Handler
                    # classes. These handlers will be installed during VM startup.
                    # Note that these classes must be on the system classpath.
                    # By default we only configure a ConsoleHandler, which will only
                    # show messages at the INFO and above levels.
                    handlers= java.util.logging.ConsoleHandler
                    
                    # To also add the FileHandler, use the following line instead.
                    #handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler
                    
                    # Default global logging level.
                    # This specifies which kinds of events are logged across
                    # all loggers. For any given facility this global level
                    # can be overriden by a facility specific level
                    # Note that the ConsoleHandler also has a separate level
                    # setting to limit messages printed to the console.
                    .level= INFO
                    
                    ############################################################
                    # Handler specific properties.
                    # Describes specific configuration info for Handlers.
                    ############################################################
                    
                    # default file output is in user's home directory.
                    java.util.logging.FileHandler.pattern = %h/java%u.log
                    java.util.logging.FileHandler.limit = 50000
                    java.util.logging.FileHandler.count = 1
                    java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter
                    
                    # Limit the message that are printed on the console to INFO and above.
                    java.util.logging.ConsoleHandler.level = INFO
                    java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
                    
                    
                    ############################################################
                    # Facility specific properties.
                    # Provides extra control for each logger.
                    ############################################################
                    
                    # For example, set the com.xyz.foo logger to only log SEVERE
                    # messages:
                    com.xyz.foo.level = SEVERE
                    


                    • 7. Re: StackOverflowError in ResourceContainer
                      ips

                      Actually, from your log, it's not clear which managed server the logging config exception occurred on. I have the feeling the logging.properties for whichever server it was either contained:

                      .level=


                      or did not contain a .level=LEVEL line at all.

                      Are you able to update to Jopr trunk so you can get the fix I checked in?



                      • 8. Re: StackOverflowError in ResourceContainer
                        sanjoa

                        The error message above and the logging.properties file are both from the same jopr agent. I may have time to try the trunk version, tomorrow friday.

                        • 9. Re: StackOverflowError in ResourceContainer
                          ips

                          Right. But the error is referring to the JDK logging config for some Java-based server process the Agent is monitoring (e.g. a JBoss AS Server instance), not necessarily the Agent JVM itself. And we don't know which server process the error was occurring for.