Runtime Messages

INFO Level Messages

The logger displays INFO level messages at each SOAP Service endpoint to indicate that the Service Health Check has been 'initiated', 'in progress' or 'response received'.

The following are representative log entries:

08 Apr 2015 16:01:31,443 [httpConnector_2] [INFO ] [] com.tibco.amx.healthcheck - Health check "{http://www.example.org/echoString/}checkHealth" initiated on SOAP Endpoint URI "http://0.0.0.0:9895/s1/" . (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Promoted Service: "S1", Binding: "S1ServiceBinding", PortType: "EchoString" Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This INFO log entry is emitted at Runtime time to record the fact that Service Health Check request has been received by the SOAP Endpoint on the URI http://0.0.0.0:9895/s1/, which is the first hop for this invocation. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,562 [httpConnector_5] [INFO ] [] com.tibco.amx.healthcheck - Health check "{http://www.example.org/echoString/}checkHealth" in progress on SOAP Endpoint URI "http://localhost:9895/echoString/" . (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Promoted Service: "S5", Binding: "S5ServiceBinding", PortType: "EchoString" Application: "Soap1Java1_2", Status: Covered "2" of "2" hops).

This INFO log entry is emitted at Runtime time to record the fact that Service Health Check execution request has reached the SOAP Endpoint on the URI http://localhost:9895/echoString/, which is the second hop for this Invocation. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,610 [httpConnector_2] [INFO ] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check response received for SOAP Endpoint URI "/s1/". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Promoted Service: "S1", Binding: "S1ServiceBinding", PortType: "EchoString" Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This INFO log entry is emitted at Runtime time to record the fact that Service Health Check execution response has been received on the return path at the SOAP Endpoint on the URI /s1/. CorrelationID and other details specific to this Invocation are also recorded.

08 Jun 2015 19:17:49,683 [HealthCheckCachingThread] [INFO ] [jv.helloworld2.soa]
stdout - HealthCheckCachingThread Start. Time = Mon Jun 08 19:17:49 IST 2015

This INFO log entry is emitted at Runtime time to mark the start time of a HealthCheckCachingThread.

08 Jun 2015 19:17:49,684 [HealthCheckCachingThread] [INFO ] [jv.helloworld2.soa]
stdout - Deleting following entry from cache: endpointURI: http://0.0.0.0:9895/helloWorldPT/ hops: 1

This INFO log entry is emitted at Runtime time to record the fact that Service Health Check cached entry for SOAP Endpoint "helloWorldPT" and hops =1 is being deleted from the cache.

08 Jun 2015 19:17:49,684 [HealthCheckCachingThread] [INFO ] [jv.helloworld2.soa]
stdout - HealthCheckCachingThread End. Time = Mon Jun 08 19:17:49 IST 2015

This INFO log entry is emitted at Runtime time to mark the end time of a HealthCheckCachingThread.

08 Jun 2015 19:25:40,765 [hello2Connector_5] [INFO ] [] com.tibco.amx.healthcheck -
A Cached Health Check Response is being returned for hops: "1" for SOAP Endpoint
URI "/helloWorldPT/". (Promoted Service: "HelloWorldPT", Binding:
"HelloWorld2SOAP", PortType: "HelloWorldPT", Application: "jv.helloworld2.soa").

This INFO log entry is emitted at Runtime time to record the fact that a cached Service Health Check response is returned for SOAP Endpoint "helloWorldPT" and hops=1.

18 Nov 2015 19:44:00,678 [AMX JCA Thread_1] [INFO ] [SOAPJMS] com.tibco.amx.healthcheck - Health Check response received for SOAP/JMS Endpoint on destination "Queue[soapjms.queue]". 
(CorrelationID: "dc3b5819-3dfc-4800-b5a4-8b7fb75a927b", Promoted Service: "Greetings", Binding: "SOAPService_Binding1", PortType: "Greetings", Application: "SOAPJMS", Status: Covered 1 of 1 hops).

This INFO log entry is emitted at Runtime time to record the fact that Service Health Check execution response has been received on the return path at the SOAP Endpoint on the destination Queue[soapjms. queue]. CorrelationID and other details specific to this Invocation are also recorded.

TRACE Level Messages

The logger displays TRACE level message at runtime. These messages indicate the Component-level progress of the Service Health Check operation.

These messages show the following:

  • The SOAP endpoint URI on which the request was initiated
  • The progress or status of Service Health Check at each Component/Service level

The following are representative log entries:

08 Apr 2015 16:01:31,468 [httpConnector_2] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check requested on Component "J1". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This TRACE log entry is emitted at Runtime time to record the fact that Service Health Check execution is in progress on Component J1 of hop 1. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,471 [HealthCheckExecutionThread] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check requested for Service "echoString" of Component "J1". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).
This TRACE log entry is emitted at Runtime time to record the fact that the service echoString of Component J1 is called. CorrelationID and other details specific to this invocation are also recorded.
08 Apr 2015 16:01:31,549 [HealthCheckExecutionThread] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check has resulted in the following error: "404 NOT_FOUND". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This TRACE log entry is emitted at Runtime time to record the fact that an error 404 NOT_FOUND has occurred because the requested service is not available. There could be other error messages for different failure scenarios. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,550 [HealthCheckExecutionThread] [ERROR] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check has resulted in an error. (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops, Cause: "SOAPException [code=com.tibco.amf.platform.runtime.extension.exception.SOAPCode@483df376, detail=com.tibco.amf.platform.runtime.extension.exception.SOAPDetail@5b3aed07, node=null, reason=[404 NOT_FOUND], role=null]

This ERROR log entry is emitted at Runtime time to record that an error has occurred and a detailed cause of the error is also provided. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,603 [HealthCheckExecutionThread] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check requested for Shared Resource Property "JDBC2" of Component "J1". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This TRACE log entry is emitted at Runtime time to record the fact that Service Health Check execution is in progress on Shared Resource JDBC2 of Component J1. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,606 [HealthCheckExecutionThread] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check has resulted in the following error: "Access is denied". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This TRACE log entry is emitted at Runtime time to record the fact that an error Access is denied has occurred because the user is not authorized to use the resource. CorrelationID and other details specific to this Invocation are also recorded.

08 Apr 2015 16:01:31,607 [httpConnector_2] [TRACE] [Soap1Java123JDBC12Soap12] com.tibco.amx.healthcheck - Health Check response received for Component "J1". (CorrelationID: "b568adde-dc74-4364-a7e6-9a767b1099d3", Application: "Soap1Java123JDBC12Soap12", Status: Covered "1" of "2" hops).

This TRACE log entry is emitted at Runtime time to record the fact that a Service Health Check response has reached Component J1. CorrelationID and other details specific to this Invocation are also recorded.

08 Jun 2015 19:17:37,643 [hello2Connector_2] [TRACE] [] com.tibco.amx.healthcheck -
Cached Health Check Response for hops: "1" is not available for SOAP Endpoint URI "/
helloWorldPT/". (Promoted Service: "HelloWorldPT", Binding: "HelloWorld2SOAP",
PortType: "HelloWorldPT", Application: "jv.helloworld2.soa").

This TRACE log entry is emitted at Runtime time to record the fact that no cached Service Health Check response was available for SOAP Endpoint "helloWorldPT" and hops=1.

08 Jun 2015 19:17:37,682 [hello2Connector_2] [TRACE] [jv.helloworld2.soa]
com.tibco.amx.healthcheck - The cache is being updated with a Health Check Response
for hops: "1" for SOAP Endpoint URI "/helloWorldPT/". (Promoted Service:
"HelloWorldPT", Binding: "HelloWorld2SOAP", PortType: "HelloWorldPT", Application:
"jv.helloworld2.soa") valid for "12" seconds.

This TRACE log entry is emitted at Runtime time to record the fact that the cache is being updated with the Service Health Check response for SOAP Endpoint "helloWorldPT" for "12" seconds.

08 Jun 2015 19:25:40,764 [hello2Connector_5] [TRACE] [] com.tibco.amx.healthcheck -
Cached Health Check Response for hops: "1" is available for SOAP Endpoint URI "/
helloWorldPT/". (Promoted Service: "HelloWorldPT", Binding: "HelloWorld2SOAP",
PortType: "HelloWorldPT", Application: "jv.helloworld2.soa").

This TRACE log entry is emitted at Runtime time to record the fact that a cached Service Health Check response is available for SOAP Endpoint "helloWorldPT" and hops=1.

08 Jun 2015 19:26:18,249 [hello2Connector_8] [TRACE] [jv.helloworld2.soa]
com.tibco.amx.healthcheck - Health Check Response for hops: "1" for SOAP Endpoint
URI "/helloWorldPT/". (Promoted Service: "HelloWorldPT", Binding:
"HelloWorld2SOAP", PortType: "HelloWorldPT", Application: "jv.helloworld2.soa") is
being flushed from the cache as validityDurationInSecs was specified as zero.

This TRACE log entry is emitted at Runtime time to record the fact that a cached Service Health Check response is being deleted for SOAP Endpoint "helloWorldPT" with hops=1 since validityDurationInSecs was specified as zero.

 08 Jun 2015 19:27:08,864 [hello2Connector_10] [TRACE] [jv.helloworld2.soa]
com.tibco.amx.healthcheck - Health Check Response for hops: "1" for SOAP Endpoint
URI "/helloWorldPT/". (Promoted Service: "HelloWorldPT", Binding:
"HelloWorld2SOAP", PortType: "HelloWorldPT", Application: "jv.helloworld2.soa") is
not cached as refreshCache was specified as false.

This TRACE log entry is emitted at Runtime time to record the fact that the cache will not be updated for SOAP Endpoint "helloWorldPT" with hops=1 as refreshCache was specified as false.

WARN Level Messages

*09 Jun 2015 17:45:39,264 [hello2Connector_4] [WARN ] [] 
com.tibco.amx.healthcheck - Since hops was specified as zero, caching attributes for 
SOAP Endpoint URI "/sayhello/". (Promoted Service: "HelloWorldPT", Binding: "SOAPService_Binding1", 
PortType: "HelloWorldPT", Application: "jv.helloworld2.soa") will be ignored.*

This WARN message is emitted to record the fact that the caching attributes specified in the current request are ignored as hops was specified as zero.

Service Health Check Invocation Messages from Administrator

Health Check UI activity is recorded in SytemNode.log file at TRACE and INFO level as shown in the following sample SystemNode logs:

08 Oct 2018 13:50:03,637 [amxAdminDefaultHttpConnector_10] [INFO ] [] com.tibco.amx.healthcheck - about to call getServiceUrlForBinding service mbean
08 Oct 2018 13:50:03,637 [amxAdminDefaultHttpConnector_9] [INFO ] [] com.tibco.amx.healthcheck - about to call getServiceUrlForBinding service mbean
08 Oct 2018 13:50:03,638 [amxAdminDefaultHttpConnector_9] [INFO ] [] com.tibco.amx.healthcheck -  calling Endpoint mbean
08 Oct 2018 13:50:03,638 [amxAdminDefaultHttpConnector_10] [INFO ] [] com.tibco.amx.healthcheck -  calling Endpoint mbean
08 Oct 2018 13:50:03,801 [amxAdminDefaultHttpConnector_10] [TRACE] [] com.tibco.amx.healthcheck - *** machine name is "Win2k8R2x64S3"... ***
08 Oct 2018 13:50:04,103 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** URL for Binding {"location":"http://0.0.0.0:9896/test"}... ***
08 Oct 2018 13:50:04,104 [amxAdminDefaultHttpConnector_9] [INFO ] [] com.tibco.amx.healthcheck - getServiceUrlForBinding service mbean call complete
08 Oct 2018 13:50:04,306 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** SOAP Version is 1.1... ***
08 Oct 2018 13:50:04,306 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** policytype applied on binding null... ***
08 Oct 2018 13:50:04,306 [amxAdminDefaultHttpConnector_9] [INFO ] [] com.tibco.amx.healthcheck - about to generate Health Check Request for SOAP
08 Oct 2018 13:50:04,306 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** looking for HttpClient... ***
08 Oct 2018 13:50:04,306 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** healthcheck request is... ***<?xml version='1.0'?><SOAP-ENV:Envelope xmlns:SOAP-ENV='http://schemas.xmlsoap.org/soap/envelope/' xmlns:heal='http://www.tibco.com/healthcheck/'>  <SOAP-ENV:Body>
    <heal:HealthCheckRequest>  <hops>-1</hops>/><suppressStackTrace>True</suppressStackTrace><timeout>300</timeout></heal:HealthCheckRequest></SOAP-ENV:Body></SOAP-ENV:Envelope>
08 Oct 2018 13:50:04,322 [amxAdminDefaultHttpConnector_9] [TRACE] [] com.tibco.amx.healthcheck - *** healthcheck response is... ***<?xml version="1.0" encoding="UTF-8"?>
<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body><ns2:HealthCheckResponse applicationName="com.tibco.restbt.sample.bookstore" correlationID="0bcec135-1df8-47df-ba54-025618986ea8" status="Passed" xmlns:ns2="http://www.tibco.com/healthcheck/"><Service bindingName="soap" bindingType="SOAP" endTime="08 Oct 2018 13:50:04,322" endpointURI="/test" environmentName="DevEnvironment" hostName="SystemHost" ipAddress="10.97.105.238" isSSLEnabled="false" machineName="Win2k8R2x64S3" name="BookStoreResource" nodeName="DevNode" portTypeName="BookStoreResource" responseTime="0" soapVersion="1.1" startTime="08 Oct 2018 13:50:04,322" status="Passed" transportType="HTTP"><Component componentType="TIBCO-IT-JAVA" endTime="08 Oct 2018 13:50:04,322" environmentName="DevEnvironment" hostName="SystemHost" name="BookStoreResource" nodeName="DevNode" responseTime="0" startTime="08 Oct 2018 13:50:04,322" status="Passed" version="1.0.0.v2014-12-31-1101"/></Service></ns2:HealthCheckResponse></SOAP-ENV:Body></SOAP-ENV:Envelope>