Attachment 946554 Details for Bug 1145327 – dying agent with debugging on

dying agent with debugging on

agent_debug.log (text/plain), 34.42 KB, created by Viet Nguyen on 2014-10-13 19:13:00 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Viet Nguyen

Created: 2014-10-13 19:13:00 UTC

Size: 34.42 KB

patch

obsolete

>2014-10-13 18:52:37,657 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.java-logging-start}Reconfiguring Java Logging...
>2014-10-13 18:52:37,670 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.java-logging-done}Done reconfiguring Java Logging.
>2014-10-13 18:52:37,674 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.creating-agent}Agent being created now
>2014-10-13 18:52:37,733 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.preferences-already-exist}Found preferences already loaded in persisted store; using those for the configuration
>2014-10-13 18:52:37,744 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.preferences-schema}Preferences configuration schema: [9]
>2014-10-13 18:52:37,744 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.preferences-node-path}Preferences node path where configuration is persisted: [/rhq-agent/default]
>2014-10-13 18:52:37,846 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.configuration}Agent configuration: /rhq-agent/default[rhq.agent.agent-update.enabled=false,rhq.agent.client.command-preprocessors=org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor:org.rhq.enterprise.agent.ExternalizableStrategyCommandPreprocessor,rhq.agent.client.command-spool-file.compressed=true,rhq.agent.client.command-spool-file.name=command-spool.dat,rhq.agent.client.command-spool-file.params=10000000:75,rhq.agent.client.command-timeout-msecs=600000,rhq.agent.client.max-concurrent=5,rhq.agent.client.max-retries=10,rhq.agent.client.queue-size=50000,rhq.agent.client.queue-throttling=200:2000,rhq.agent.client.retry-interval-msecs=15000,rhq.agent.client.send-throttling=100:1000,rhq.agent.client.server-polling-interval-msecs=60000,rhq.agent.configuration-schema-version=9,rhq.agent.configuration-setup-flag=true,rhq.agent.data-directory=data,rhq.agent.disable-native-system=false,rhq.agent.plugins.directory=plugins,rhq.agent.primary-server-switchover-check-interval-msecs=3600000,rhq.agent.register-with-server-at-startup=true,rhq.agent.server-auto-detection=false,rhq.agent.server.alias=rhqserver,rhq.agent.server.bind-address=0.0.0.0,rhq.agent.server.bind-port=7080,rhq.agent.server.transport=servlet,rhq.agent.server.transport-params=/jboss-remoting-servlet-invoker/ServerInvokerServlet,rhq.agent.test-failover-list-at-startup=true,rhq.agent.update-plugins-at-startup=true,rhq.agent.vm-health-check.interval-msecs=5000,rhq.agent.vm-health-check.low-heap-mem-threshold=0.90,rhq.agent.vm-health-check.low-nonheap-mem-threshold=0.90,rhq.agent.wait-for-server-at-startup-msecs=60000,rhq.communications.command-authenticator=org.rhq.enterprise.agent.SecurityTokenCommandAuthenticator,rhq.communications.command-service-directory.allow-dynamic-discovery=true,rhq.communications.command-services=org.rhq.enterprise.communications.command.impl.echo.server.EchoCommandService, org.rhq.enterprise.communications.command.impl.identify.server.IdentifyCommandService,rhq.communications.configuration-schema-version=1,rhq.communications.connector.bind-port=16163,rhq.communications.connector.rhqtype=agent,rhq.communications.connector.transport=socket,rhq.communications.data-directory=data,rhq.communications.global-concurrency-limit=-1,rhq.communications.multicast-detector.bind-address=0.0.0.0,rhq.communications.multicast-detector.default-time-delay=5000,rhq.communications.multicast-detector.enabled=false,rhq.communications.multicast-detector.heartbeat-time-delay=1000,rhq.communications.multicast-detector.multicast-address=224.16.16.16,rhq.communications.multicast-detector.port=16162,rhq.communications.remote-pojos=org.rhq.enterprise.communications.PingImpl:org.rhq.enterprise.communications.Ping,rhq.communications.remote-stream-max-idle-time-msecs=300000]
>2014-10-13 18:52:37,865 DEBUG [main] (enterprise.communications.util.prefs.PreferencesUpgrade)- {PreferencesUpgrade.already-uptodate}The preferences configuration [rhq.agent.configuration-schema-version] is up-to-date at version [9]
>2014-10-13 18:52:37,865 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.args-processed}Agent container has processed its command line arguments: [--daemon]
>2014-10-13 18:52:38,037 INFO  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.identify-version}Version=[RHQ 4.12.0.JON330ER03], Build Number=[44e33a4], Build Date=[Sep 16, 2014 6:23 PM]
>2014-10-13 18:52:38,056 INFO  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.agent-name-auto-generated}The name of this agent was not predefined so it was auto-generated. The agent name is now [643c10624b09]
>2014-10-13 18:52:38,059 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentConfiguration.cert-file-location}Explicitly setting file location [rhq.communications.connector.security.keystore.file] to [/opt/rhq-agent/conf/keystore.dat]
>2014-10-13 18:52:38,059 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentConfiguration.cert-file-location}Explicitly setting file location [rhq.communications.connector.security.truststore.file] to [/opt/rhq-agent/conf/truststore.dat]
>2014-10-13 18:52:38,060 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentConfiguration.cert-file-location}Explicitly setting file location [rhq.agent.client.security.keystore.file] to [/opt/rhq-agent/conf/keystore.dat]
>2014-10-13 18:52:38,060 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentConfiguration.cert-file-location}Explicitly setting file location [rhq.agent.client.security.truststore.file] to [/opt/rhq-agent/conf/truststore.dat]
>2014-10-13 18:52:38,108 DEBUG [main] (org.jboss.logging)- Logging Provider: org.jboss.logging.Log4jLoggerProvider
>2014-10-13 18:52:38,111 DEBUG [main] (org.jboss.remoting)- Remoting version: 2.5.4.SP5 (Flounder)
>2014-10-13 18:52:38,123 DEBUG [main] (enterprise.communications.command.client.CommandQueue)- {CommandQueue.configured}Queue throttling is configured for [200] max commands in burst periods of [2,000] milliseconds.  These will take effect when queue throttling is enabled.
>2014-10-13 18:52:38,129 DEBUG [main] (enterprise.communications.command.client.CommandQueue)- {CommandQueue.enabled}Command Queue is now throttling - a maximum of [200] commands are allowed to be dequeued every [2,000] milliseconds
>2014-10-13 18:52:38,131 DEBUG [main] (enterprise.communications.command.client.SendThrottle)- {SendThrottle.configured}Send throttling is configured for [100] max commands and quiet periods of [1,000] milliseconds. These will take effect while send throttling is enabled.
>2014-10-13 18:52:38,133 DEBUG [main] (enterprise.communications.command.client.SendThrottle)- {SendThrottle.enabled}Send throttling is now enabled - a maximum of [100] commands are allowed to be sent in between quiet periods of [1,000] milliseconds.
>2014-10-13 18:52:38,159 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$CommandListenerStateListener@6e0be922]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:52:38,161 DEBUG [main] (enterprise.communications.util.prefs.PreferencesUpgrade)- {PreferencesUpgrade.already-uptodate}The preferences configuration [rhq.communications.configuration-schema-version] is up-to-date at version [1]
>2014-10-13 18:52:38,163 INFO  [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.global-concurrency-limit-disabled}Global concurrency limit has been disabled - there is no limit to the number of incoming commands allowed
>2014-10-13 18:52:38,256 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.using-existing-mbs}Found an existing MBeanServer [DefaultDomain] - will use that
>2014-10-13 18:52:38,315 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.registry-created}Network registry has been created [rhq.remoting:type=networkregistry]
>2014-10-13 18:52:38,315 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.multicast-detector-disabled}Multicast detector has not been enabled in configuration - it will not be started and auto-discovery will not be supported
>2014-10-13 18:52:38,319 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.added-command-service}Added command service [org.rhq.enterprise.communications.command.impl.echo.server.EchoCommandService] with an id of [1]
>2014-10-13 18:52:38,326 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.added-command-service}Added command service [org.rhq.enterprise.communications.command.impl.identify.server.IdentifyCommandService] with an id of [2]
>2014-10-13 18:52:38,329 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.added-command-service}Added command service [org.rhq.enterprise.communications.command.impl.remotepojo.server.RemotePojoInvocationCommandService] with an id of [3]
>2014-10-13 18:52:38,329 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.added-remote-pojo}Added remote POJO of type [org.rhq.enterprise.communications.PingImpl] with a remote interface of [org.rhq.enterprise.communications.Ping]
>2014-10-13 18:52:38,336 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.dynamic-discovery-allowed}Command Service Directory has been allowed to perform dynamic discovery
>2014-10-13 18:52:38,383 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.new-supported-command}Command [echo] is now supported by [rhq.remoting:type=command,subsystem=RHQ,id=1]
>2014-10-13 18:52:38,384 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.new-supported-command}Command [identify] is now supported by [rhq.remoting:type=command,subsystem=RHQ,id=2]
>2014-10-13 18:52:38,386 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.new-supported-command}Command [remotepojo] is now supported by [rhq.remoting:type=command,subsystem=RHQ,id=3]
>2014-10-13 18:52:38,397 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.directory-created}Command service directory has been created [rhq.remoting:type=directory]
>2014-10-13 18:52:38,398 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.connector-uri}Connector is using locator URI of [InvokerLocator [socket://172.17.0.216:16163/?backlog=200&clientMaxPoolSize=304&enableTcpNoDelay=true&maxPoolSize=303&numAcceptThreads=1&rhq.communications.connector.rhqtype=agent&socketTimeout=60000]]
>2014-10-13 18:52:38,406 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.connector-lease-period}The connector lease period is [-1]
>2014-10-13 18:52:38,496 DEBUG [main] (org.jboss.remoting.ServerInvoker)- SocketServerInvoker[172.17.0.216:16163] did not find server socket factory configuration as mbean service or classname. Creating default server socket factory.
>2014-10-13 18:52:38,496 DEBUG [main] (org.jboss.remoting.ServerInvoker)- SocketServerInvoker[172.17.0.216:16163] created server socket factory javax.net.DefaultServerSocketFactory@79b36031
>2014-10-13 18:52:38,515 DEBUG [main] (enterprise.communications.command.server.CommandProcessor)- {CommandProcessor.authenticator-set}Command processor assigned an authenticator for command security checks: [org.rhq.enterprise.agent.SecurityTokenCommandAuthenticator@7339f51a]
>2014-10-13 18:52:38,515 DEBUG [main] (org.jboss.remoting.ServerInvoker)- SocketServerInvoker[172.17.0.216:16163] added org.rhq.enterprise.communications.command.server.CommandProcessor@10198cc for subsystem 'RHQ'
>2014-10-13 18:52:38,515 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] starting
>2014-10-13 18:52:38,522 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] created ServerSocket[addr=/172.17.0.216,localport=16163]
>2014-10-13 18:52:38,525 DEBUG [main] (org.jboss.remoting.ServerInvoker)- SocketServerInvoker[172.17.0.216:16163] started for locator InvokerLocator [socket://172.17.0.216:16163/?backlog=200&clientMaxPoolSize=304&enableTcpNoDelay=true&maxPoolSize=303&numAcceptThreads=1&rhq.communications.connector.rhqtype=agent&socketTimeout=60000]
>2014-10-13 18:52:38,525 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] started
>2014-10-13 18:52:38,525 DEBUG [main] (org.jboss.remoting.transport.Connector)- org.jboss.remoting.transport.Connector@78861c2d started
>2014-10-13 18:52:38,527 DEBUG [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.processor-ready}Command processor is now ready to begin accepting commands from clients
>2014-10-13 18:52:38,527 INFO  [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.started}Service container started - ready to accept incoming commands
>2014-10-13 18:52:38,527 INFO  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.no-auto-detect}Server auto-detection is not enabled - starting the poller immediately
>2014-10-13 18:52:38,529 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ServerPollingThread)- {ServerPollingThread.started}Server polling thread has started and will poll for server status every [60,000] milliseconds
>2014-10-13 18:52:38,529 DEBUG [RHQ Server Polling Thread] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:52:38,536 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:52:38,544 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$RegisterStateListener@2e97bb80]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:52:38,544 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$PluginContainerConditionalRestartListener@6944da12]; sender is sending=[false]; notify listener immediately=[false]
>2014-10-13 18:52:38,545 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.waiting-for-server}The agent is waiting for the server - will sleep for [60,000] milliseconds
>2014-10-13 18:52:38,546 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@365bc793]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:52:38,552 DEBUG [RHQ Server Polling Thread] (org.jboss.remoting.Client)- Client[1305878981:4sh060-qcp4gt-i186hh2x-1-i186hh5k-3].connect(null)
>2014-10-13 18:52:38,566 DEBUG [RHQ Server Polling Thread] (org.jboss.remoting.MicroRemoteClientInvoker)- org.jboss.remoting.transport.http.HTTPClientInvoker@389c6ad9 connecting
>2014-10-13 18:52:38,566 DEBUG [RHQ Server Polling Thread] (org.jboss.remoting.MicroRemoteClientInvoker)- org.jboss.remoting.transport.http.HTTPClientInvoker@389c6ad9 connected
>2014-10-13 18:52:38,568 DEBUG [RHQ Server Polling Thread] (org.jboss.remoting.Client)- Client[1305878981:4sh060-qcp4gt-i186hh2x-1-i186hh5k-3] connected to InvokerLocator [servlet://0.0.0.0:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet]
>2014-10-13 18:52:38,568 DEBUG [RHQ Server Polling Thread] (org.jboss.remoting.Client)- Client[1305878981:4sh060-qcp4gt-i186hh2x-1-i186hh5k-3] is connected
>2014-10-13 18:52:38,782 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ServerPollingThread)- {ServerPollingThread.server-poll-failure}Failed to successfully poll the server. This is normally due to the server not being up yet. You can usually ignore this message since it will be tried again later, however, you should ensure this failure was not really caused by a misconfiguration. Cause: org.jboss.remoting.transport.http.WebServerError:<html><head><title>JBoss Web/7.4.8.Final-redhat-4 - JBWEB000064: Error report</title><style></style> </head><body><h1>JBWEB000065: HTTP Status 404 - /jboss-remoting-servlet-invoker/ServerInvokerServlet</h1><HR size="1" noshade="noshade"><p><b>JBWEB000309: type</b> JBWEB000067: Status report</p><p><b>JBWEB000068: message</b> <u>/jboss-remoting-servlet-invoker/ServerInvokerServlet</u></p><p><b>JBWEB000069: description</b> <u>JBWEB000124: The requested resource is not available.</u></p><HR size="1" noshade="noshade"><h3>JBoss Web/7.4.8.Final-redhat-4</h3></body></html>
>2014-10-13 18:53:38,548 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@365bc793]
>2014-10-13 18:53:38,549 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.waiting-for-server}The agent is waiting for the server - will sleep for [60,000] milliseconds
>2014-10-13 18:53:38,549 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@220787d0]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:53:38,783 DEBUG [RHQ Server Polling Thread] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:53:38,783 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:54:38,549 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@220787d0]
>2014-10-13 18:54:38,593 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.waiting-for-server}The agent is waiting for the server - will sleep for [60,000] milliseconds
>2014-10-13 18:54:38,593 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@75dcb2b9]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:54:38,808 DEBUG [RHQ Server Polling Thread] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:54:38,808 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:55:38,593 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@75dcb2b9]
>2014-10-13 18:55:38,594 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.waiting-for-server}The agent is waiting for the server - will sleep for [60,000] milliseconds
>2014-10-13 18:55:38,594 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@3609075a]; sender is sending=[false]; notify listener immediately=[true]
>2014-10-13 18:55:38,817 DEBUG [RHQ Server Polling Thread] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:55:38,817 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:55:38,905 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.loading-command-spool}Loading [0] commands from the spool file and queueing them up to be sent to [remoting endpoint [servlet://0.0.0.0:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet]]
>2014-10-13 18:55:38,906 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.unspooled}[0] commands were unspooled and will be resent to [remoting endpoint [servlet://0.0.0.0:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet]]
>2014-10-13 18:55:38,906 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.sending}Client is now going to actively send commands
>2014-10-13 18:55:38,906 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.notifying-state-listeners}Notifying command client sender state listeners of a state change - sender is sending=[true]
>2014-10-13 18:55:39,925 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.agent-registration-attempt}Agent will now attempt to register with the server [AgentRegistrationRequest: [name=[643c10624b09]; address=[172.17.0.216]; port=[16163]; remote-endpoint=[socket://172.17.0.216:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200]; regenerate-token=[false]; original-token=[<was null>]; agent-version=[4.12.0.JON330ER03(44e33a4)]; install-id=[null]; install-location=[/opt/rhq-agent]]
>2014-10-13 18:55:39,928 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:55:39,932 DEBUG [ClientCommandSenderTask Timer Thread #0] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:55:40,191 DEBUG [WorkerThread#0[172.17.0.216:49893]] (enterprise.communications.command.server.CommandProcessor)- {CommandProcessor.executing}Executing command [Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.send-throttle=true, rhq.timeout=10000}]; params=[{targetInterfaceName=org.rhq.enterprise.communications.Ping, invocation=NameBasedInvocation[ping]}]]
>2014-10-13 18:55:40,194 DEBUG [WorkerThread#0[172.17.0.216:49893]] (enterprise.communications.command.server.CommandProcessor)- {CommandProcessor.executed}Executed command - response is [Command Response: isSuccessful=[true]; command=[null]; results=[]; exception=[>> exception was null <<]]
>2014-10-13 18:55:40,203 DEBUG [WorkerThread#0[172.17.0.216:49893]] (jboss.remoting.transport.socket.ServerThread)- WorkerThread#0[172.17.0.216:49893] closed socketWrapper: ServerSocketWrapper[Socket[addr=/172.17.0.216,port=49893,localport=16163].65bab443]
>2014-10-13 18:56:38,594 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@3609075a]
>2014-10-13 18:56:38,595 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.waiting-for-server}The agent is waiting for the server - will sleep for [60,000] milliseconds
>2014-10-13 18:56:38,595 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.added-state-listener}Added the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@39a83e27]; sender is sending=[true]; notify listener immediately=[true]
>2014-10-13 18:56:38,595 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$2@39a83e27]
>2014-10-13 18:56:38,596 FATAL [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.startup-error}The agent encountered an error during startup and must abort
>org.rhq.core.clientapi.server.core.AgentRegistrationException: The agent cannot register with the server. Admin intervention needed!
>	at org.rhq.enterprise.agent.AgentMain.start(AgentMain.java:720)
>	at org.rhq.enterprise.agent.AgentMain.main(AgentMain.java:448)
>2014-10-13 18:56:38,598 INFO  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.shutting-down}Agent is being shut down...
>2014-10-13 18:56:38,610 INFO  [main] (org.rhq.core.pc.PluginContainer)- Plugin container is already shut down.
>2014-10-13 18:56:38,612 WARN  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.failed-to-shutdown-component}Agent failed to shutdown component [Plugin Container]. Cause: java.lang.NullPointerException:null
>2014-10-13 18:56:38,612 DEBUG [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.notifying-server-of-shutdown}Agent is notifying the server that it is shutting down.
>2014-10-13 18:56:38,612 DEBUG [main] (org.rhq.enterprise.agent.SecurityTokenCommandPreprocessor)- {SecurityTokenCommandPreprocessor.no-security-token-yet}There is no security token yet - the server will not accept commands from this agent until the agent is registered.
>2014-10-13 18:56:38,613 DEBUG [ClientCommandSenderTask Timer Thread #1] (enterprise.communications.command.client.JBossRemotingRemoteCommunicator)- {JBossRemotingRemoteCommunicator.init-callback-done}The initialize callback has finished. Callback to be invoked again? [true]
>2014-10-13 18:56:38,629 DEBUG [main] (enterprise.communications.command.client.ClientRemotePojoFactory)- {ClientRemotePojoFactory.execution-failure}Failed to execute remote POJO method [agentIsShuttingDown]. Cause: org.rhq.enterprise.communications.command.server.AuthenticationException:Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=643c10624b09, rhq.externalizable-strategy=AGENT, rhq.timeout=10000}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.core.CoreServerService, invocation=NameBasedInvocation[agentIsShuttingDown]}]
>2014-10-13 18:56:38,629 WARN  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.server-shutdown-notification-failure}Agent failed to notify the server of the pending shutdown. Cause: org.rhq.enterprise.communications.command.server.AuthenticationException:Command failed to be authenticated!  This command will be ignored and not processed: Command: type=[remotepojo]; cmd-in-response=[false]; config=[{rhq.agent-name=643c10624b09, rhq.externalizable-strategy=AGENT, rhq.timeout=10000}]; params=[{targetInterfaceName=org.rhq.core.clientapi.server.core.CoreServerService, invocation=NameBasedInvocation[agentIsShuttingDown]}]
>2014-10-13 18:56:38,630 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.removed-state-listener}Removed the command client sender state listener [org.rhq.enterprise.agent.AgentMain$RegisterStateListener@2e97bb80]
>2014-10-13 18:56:38,630 INFO  [RHQ Server Polling Thread] (enterprise.communications.command.client.ServerPollingThread)- {ServerPollingThread.server-online}The server has come back online; client has been told to start sending commands again
>2014-10-13 18:56:38,630 DEBUG [RHQ Server Polling Thread] (enterprise.communications.command.client.ServerPollingThread)- {ServerPollingThread.stopped}Server polling thread has been stopped
>2014-10-13 18:56:46,444 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.test-failover-list-entry}Testing failover connectivity to server [10.16.23.108:7080]
>2014-10-13 18:56:46,446 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.test-failover-list-entry}Testing failover connectivity to server [10.16.23.108:7443]
>2014-10-13 18:56:46,446 WARN  [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.failover-list-unreachable-host}Failover list has an unreachable host [10.16.23.108] (tested ports [7080] and [7443]). Cause: java.net.ConnectException:Connection refused
>2014-10-13 18:56:46,446 DEBUG [main] (org.jboss.remoting.InvokerRegistry)- removed org.jboss.remoting.transport.http.HTTPClientInvoker@389c6ad9 from registry
>2014-10-13 18:56:46,447 DEBUG [main] (org.jboss.remoting.Client)- Client[1305878981:4sh060-qcp4gt-i186hh2x-1-i186hh5k-3] is disconnected
>2014-10-13 18:56:46,447 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.spooling}Persisting commands with guaranteed delivery to the spool file
>2014-10-13 18:56:46,447 WARN  [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.failover-list-check-failed}!!! There are [1] servers that are potentially unreachable by this agent.
>Please double check all public endpoints of your servers and ensure
>they are all reachable by this agent. The failed server endpoints are:
>[10.16.23.108:7080/7443]
>See the Administration (Topology) > Servers in the server GUI
>to change the public endpoint of a server.
>THIS AGENT WILL WAIT UNTIL ONE OF ITS SERVERS BECOMES REACHABLE!
>2014-10-13 18:56:46,447 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.spool-done}Persisted [0] commands to the spool file for later delivery to [remoting endpoint [servlet://0.0.0.0:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet]]; [0] volatile commands remain in the queue and will be lost if the sender does not start again
>2014-10-13 18:56:46,447 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.no-longer-sending}Client is no longer actively sending commands to [remoting endpoint [servlet://0.0.0.0:7080/jboss-remoting-servlet-invoker/ServerInvokerServlet]]
>2014-10-13 18:56:46,447 DEBUG [main] (enterprise.communications.command.client.ClientCommandSender)- {ClientCommandSender.notifying-state-listeners}Notifying command client sender state listeners of a state change - sender is sending=[false]
>2014-10-13 18:56:46,448 DEBUG [main] (enterprise.communications.command.client.CommandQueue)- {CommandQueue.disabled}Command Queue is not throttling - commands will be dequeued as fast as possible
>2014-10-13 18:56:46,448 DEBUG [main] (enterprise.communications.command.client.SendThrottle)- {SendThrottle.disabled}Send throttling is disabled - commands will be sent as fast as possible
>2014-10-13 18:56:46,448 INFO  [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.shutting-down}Service container shutting down...
>2014-10-13 18:56:46,448 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] stopped threads in clientpool
>2014-10-13 18:56:46,448 DEBUG [ServerSocketRefresh] (jboss.remoting.transport.socket.SocketServerInvoker)- ServerSocketRefresh shutting down
>2014-10-13 18:56:46,449 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] stopped threads in threadpool
>2014-10-13 18:56:46,449 DEBUG [main] (jboss.remoting.transport.socket.SocketServerInvoker)- SocketServerInvoker[172.17.0.216:16163] exiting
>2014-10-13 18:56:46,452 DEBUG [main] (org.jboss.remoting.ServerInvoker)- SocketServerInvoker[172.17.0.216:16163] stopped
>2014-10-13 18:56:46,453 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.removed-command-support}Command [echo] is no longer supported; removed [rhq.remoting:type=command,subsystem=RHQ,id=1]
>2014-10-13 18:56:46,454 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.removed-command-support}Command [identify] is no longer supported; removed [rhq.remoting:type=command,subsystem=RHQ,id=2]
>2014-10-13 18:56:46,454 DEBUG [main] (enterprise.communications.command.server.CommandServiceDirectory)- {CommandServiceDirectory.removed-command-support}Command [remotepojo] is no longer supported; removed [rhq.remoting:type=command,subsystem=RHQ,id=3]
>2014-10-13 18:56:46,454 INFO  [main] (org.rhq.enterprise.communications.ServiceContainer)- {ServiceContainer.shutdown}Service container shut down - no longer accepting incoming commands
>2014-10-13 18:56:46,454 INFO  [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.shut-down}Agent has been shut down
>2014-10-13 18:56:46,455 FATAL [main] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.start-failure}Failed to start the agent
>org.rhq.core.clientapi.server.core.AgentRegistrationException: The agent cannot register with the server. Admin intervention needed!
>	at org.rhq.enterprise.agent.AgentMain.start(AgentMain.java:720)
>	at org.rhq.enterprise.agent.AgentMain.main(AgentMain.java:448)
>2014-10-13 18:56:46,455 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {SecurityTokenCommandPreprocessor.new-security-token}A new security token has been persisted: /iOBxVMb3yXH068hghdbNHCR/9ojlGqBt3FvLYkfIhVEA0dwYW6nCFt7snjFCytM700=
>2014-10-13 18:56:46,455 DEBUG [RHQ Agent Registration Thread] (org.rhq.enterprise.agent.AgentMain)- {AgentMain.agent-registration-aborted}Aborting the server registration attempt.

Actions: View

Attachments on bug 1145327: 940172 | 946554