Hide Forgot
Description of problem: Agent is throwing Error while JON server executing Operations(start/shutdown/restart) on JBoss server. ****************************** 2016-03-07 13:50:28,371 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.jbossas7.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: }, additionalProperties={name=release-version}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@7fe7140f; line: 1, column: 2] 2016-03-07 13:50:29,412 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.jbossas7.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: }, additionalProperties={name=release-version}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@43403c93; line: 1, column: 2] ****************************** Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. Navigate to Standalone server 2. Click on Operations 3. Schedule Operation (shutdown/start/restart/reload) 4. check JON agent log (agent.log) Actual results: Error: ******************************* 2016-03-07 13:50:28,371 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.jbossas7.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: }, additionalProperties={name=release-version}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@7fe7140f; line: 1, column: 2] 2016-03-07 13:50:29,412 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.jbossas7.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: }, additionalProperties={name=release-version}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@43403c93; line: 1, column: 2] ******************************* Expected results: Agent should not have any error while executing any operation Additional info:
That error is coming from the EAP7 server, which doesn't seem to be in alright shape (error 503). That error message should be there as agent can't execute the operation when EAP can't (and it's not even returning correct JSON response). NOTABUG.
[17:07:45] <@pilhuhn> so we just said on the call, that this is indeed more a cosmetic thing, but [17:08:39] <@pilhuhn> as this shows up as ERROR in the log, customers are very likely to call support because they are confused. So we need to detect if the server returns a 503 code and just log "server {id} is currently unavailable"
commit e8ca78a0747c61359f01d6008be0f187e754f117 Merge: 449d6b1 63257bf Author: Michael Burman <yak> Date: Thu Mar 17 11:28:47 2016 +0200 Merge pull request #218 from josejulio/bugs/1315466 Bug 1315466 - Agent is throwing Error while JON server executing Oper… commit 63257bfe3fa2a4c718752a581152dd9a4f4bf77f Author: Josejulio Martínez <jmartine> Date: Mon Mar 14 19:19:45 2016 -0600 Bug 1315466 - Agent is throwing Error while JON server executing Operations on JBoss server. Detects if error code is 503 and returns a failure operation result with "server not available" message.
This bug was accidentally moved from POST to MODIFIED via an error in automation, please see mmccune with any questions
Bug repeated with EAP-plugin-update04-ER01: 2016-04-13 12:13:00,448 ERROR [ResourceContainer.invoker.nonDaemon-4] (rhq.modules.plugins.wildfly10.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: }, additionalProperties={name=release-version}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@428f9128; line: 1, column: 2] 2016-04-13 12:13:00,486 ERROR [ResourceContainer.invoker.nonDaemon-4] (rhq.modules.plugins.wildfly10.ASConnection)- Failed to deserialize response to Operation{operation='read-attribute', address=Address{path: core-service=server-environment}, additionalProperties={name=config-file}} to JsonNode - response status was 503 Service Unavailable, and body was [<html><head><title>Error</title></head><body>503 - Service Unavailable</body></html>]: org.codehaus.jackson.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: java.io.StringReader@46b00da1; line: 1, column: 2]
Cannot be verified so far.
Bug reproduced for operation 'Restart'.
Could you please elaborate more the way to reproduce it? I tried on that build and I'm getting: 2016-04-13 11:59:11,706 ERROR [ResourceContainer.invoker.nonDaemon-8] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable]
Tested on configuration: EAP7 instance built from http://download.devel.redhat.com/devel/candidates/JBEAP/JBEAP-7.0.0.CR1/jboss-eap-7.0.0.CR1.zip JON Plugin pack - http://web.bc.jonqe.lab.eng.bos.redhat.com/jon-plugin-pack-eap-3.3.0.GA-update-04.zip JON - of 'JON/Server/JON 3.3.0/CR4_CR01' hostgroup. -- Will recreate instance from scratch and recheck it!
Results: On operations 'Start' and 'Restart' in agent log: ----------------------- 2016-04-13 17:03:43,945 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-13 17:03:43,951 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-13 17:03:45,318 INFO [ResourceContainer.invoker.nonDaemon-3] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Exit code from process execution: null 2016-04-13 17:03:45,318 INFO [ResourceContainer.invoker.nonDaemon-3] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Output from process execution: ----------------------- ----------------------- 2016-04-13 17:03:52,534 ERROR [ResourceContainer.invoker.nonDaemon-3] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-13 17:03:53,705 INFO [MeasurementManager.collector-1] (rhq.core.pc.measurement.MeasurementCollectorRunner)- [PERF] Collection of measurements for [Resource[id=15623, uuid=c74ccf97-7108-45ce-a27d-39cf0ea152d1, type={EAP7}EAP7 Standalone Server, key=hostConfig: /home/hudson/jboss-eap7-standalone/standalone/configuration/standalone-full-changed.xml, name=EAP 7 (0.0.0.0:10090), parent=vso-eap7-2.bc.jonqe.lab.eng.bos.redhat.com, version=EAP 7.0.0.GA]] (component=[org.rhq.modules.plugins.wildfly10.StandaloneASComponent@373e5240]) took [2438]ms
Rechecked: Original error message fixed. BUT: Other message 'ERROR' still present. It worth consider, is such message acceptable in log file after user scheduled operation 'Restart': --------------------------------------------------- 2016-04-14 09:50:24,168 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-14 09:50:24,195 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-14 09:50:25,689 INFO [ResourceContainer.invoker.nonDaemon-1] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Exit code from process execution: null 2016-04-14 09:50:25,689 INFO [ResourceContainer.invoker.nonDaemon-1] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Output from process execution: ----------------------- ----------------------- 2016-04-14 09:50:33,842 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-14 09:50:34,898 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable]
Are you talking about these: 2016-04-14 09:50:25,689 INFO [ResourceContainer.invoker.nonDaemon-1] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Exit code from process execution: null 2016-04-14 09:50:25,689 INFO [ResourceContainer.invoker.nonDaemon-1] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Output from process execution: ? The other messages are meant to be there as per comment #2
Not. I meant such like these ones: 2016-04-14 09:50:33,842 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-04-14 09:50:34,898 ERROR [ResourceContainer.invoker.nonDaemon-1] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] -- It were repeated - because I rechecked issue this newly updated plugins, and issue was repeated.
According to Comment #1 the original error message was being show because EAP7 wasn't in a good shape, so it was agreed ( Comment #2 ) to show the message in a less verbose mode.
Could we just replace the logging level ERROR with INFO/WARN for not to confuse customer?
Sure, I'll replace the logging level with WARN.
commit 2a0a15ea5e7d437bd08677a542c0d3d3baad9d84 Author: Josejulio Martínez <jmartine> Date: Mon Apr 18 12:07:56 2016 -0500 Bug 1315466 - Changes logging level from ERROR to WARN.
Execution steps: For operation 'Restart' got: ----------------------- 2016-05-01 11:00:57,546 WARN [ResourceContainer.invoker.nonDaemon-2] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-05-01 11:00:57,553 WARN [ResourceContainer.invoker.nonDaemon-2] (rhq.modules.plugins.wildfly10.ASConnection)- Server not available [503 Service Unavailable] 2016-05-01 11:00:58,736 INFO [ResourceContainer.invoker.nonDaemon-2] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Exit code from process execution: null 2016-05-01 11:00:58,736 INFO [ResourceContainer.invoker.nonDaemon-2] (modules.plugins.wildfly10.util.ProcessExecutionLogger)- Output from process execution: -----------------------