The PTV xServer use the log4j2-Framework for logging purposes. There are two separate logging configuration files to control the logging behaviour:
server-logging.properties
xserver.logdirectory
as placeholder for the default logging directory and xserver
as placeholder for the actual service name (xmap, xroute, ...). Both system properties are set in the wrapper.conf.module-logging.properties
xserver.logdirectory
and xserver
(see above) and xserver.moduleid
in your configuration. The latter variable contains the instance id of the module.Logging Interval: The logging configuration can be changed at runtime. These changes are checked and applied every 60 seconds. To change this interval adjust the value of the property monitorInterval.
By default, PTV xServer module log billing summaries into files located in the logs
folder using the module name with prefix -server.log
. Per request one row is written with semicolon-separated values (CSV).
Header name | Content |
---|---|
timestamp |
The arrival time of a request. Example: |
loglevel |
The log level (degree of severity), ranging from |
RequestTimes |
The string |
id |
A server-provided ID for this request. Example: |
client host |
The IP of the client of this request. Example: |
user |
The username when using http authentication. Default: |
port |
The port of the service used. Example: |
clusterId |
An id for the server that can be assigned in |
service |
The classname and operation used in this request. Example: |
success |
Boolean value indication the successfulness of this request. Example: |
log1 |
User logging slot, configurable with the caller context object. Useful to distinguish tenants or offices, test requests and so on. |
log2 |
User logging slot. |
log3 |
User logging slot. |
profile |
Profile name from the caller context. |
pool instance |
An id for the concrete instance in the process pool. Example: |
deserialisation |
Time for the parsing of the request, in ms. |
input trafo |
Time for the transformation of input coordinates, in ms. |
module queueing |
Time that the request had to wait for a free backend module, in ms. |
module time |
Time spent in the backend module, the net computation time, in ms. |
output trafo |
Time for the transformation of output coordinates, in ms. |
serialisation |
Time for the assembling of the response, in ms. |
total inner |
Total time without parsing/assembling, in ms. |
total outer |
Total time for the request handling, in ms. |
transaction |
User-defined transactionId from the caller context. Can be used to associate responses to requests. |
use-cases |
Special use information, depending on service. Example: |
ref-coord 1 |
First address of the response, or first station of a route, or center of a rendered map. Intended for country-specific billing. |
ref-coord 2 |
Second address of the response, or last station of a route, or center of a rendered map. Intended for country-specific billing. |
dynamic provider |
Content from |
dimensions |
Number of addresses, number of waypoints, for bulk routing also the number of routes (comma-separated), width,height of the image. |
additionalInfo |
Intended for future use. Currently not used. |
errorType |
Engine error type, if applicable and available. |
errorCode |
Engine error type, if applicable and available. |
errorMsg |
Engine error type, if applicable and available. |
There are two ways of analysing performance. The first one is to have a look at the module specific access statistics. The statistics can be reset online to monitor a certain period of time.
The second way is to monitor the request time stamps in the log files. The management console comes with a function for exporting request time stamps into CSV format. That function requires adequate log settings:
file logging must be used
the log level for the RequestTimes category must be set to INFO
There are different types of restarts. The log file contains information on each type which is necessary to see which was the reason of the restart.
When restarting all modules from the management console the following lines occur in the log file.
2014-01-22 16:10:54,463;INFO;com.ptvgroup.xserver.framework.Dispatcher$RollingRestarter; Rolling restart of all 1 module instances initiated. 2014-01-22 16:10:54,464;INFO;com.ptvgroup.xserver.framework.Dispatcher$RollingRestarter; Rolling restart of module instance m0001 2014-01-22 16:10:54,464;INFO;com.ptvgroup.xserver.framework.ModuleAgent; Restarting module m0001 due to rolling restart 2014-01-22 16:10:54,477;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 shutting down with exit code 1 2014-01-22 16:10:54,480;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Starting module instance m0001 in external process... 2014-01-22 16:10:55,308;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 is up and running. 2014-01-22 16:10:55,808;INFO;com.ptvgroup.xserver.framework.Dispatcher$RollingRestarter; Successful rolling restart of module instance m0001 2014-01-22 16:10:55,808;INFO;com.ptvgroup.xserver.framework.Dispatcher$RollingRestarter; Rolling restart finished
When restarting the complete server by shutting down and starting again the following lines occur in the log file. The exit code is 1.
2014-01-22 16:15:27,427;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 shutting down with exit code 1. 2014-01-22 16:15:42,864;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Starting module instance m0001 in external process... 2014-01-22 16:15:43,778;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 is up and running.
When the module crashes the billing line RequestTimes
shows the service method called, indicates non-success with false
, and says Error communicating with backend module
. The exit code is arbitrary, very often the logs folder contains a file hs_err_pid<pid>.log
.
2014-01-22 16:10:03,389;INFO;RequestTimes;0082a76b-f048-47dc-958f-160eea5939f3; 0:0:0:0:0:0:0:1;unknown-http;59990;unknown-cluster;XCrash.doubleFree;false;;;;null; m0001;3;0;0;3879;0;1;3879;3884;NO-TXN;;;;;;;com.ptvag.xserver.common.XServiceException; null;Error communicating with backend module. 2014-01-22 16:10:03,398;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 shutting down with exit code -1073740940. 2014-01-22 16:10:04,391;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Pinging instance m0001 ended with exception java.rmi.ConnectException after 1003 milliseconds. 2014-01-22 16:10:04,391;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Exception message: Connection refused to host: 172.23.73.30; nested exception is: java.net.ConnectException: Connection refused: connect 2014-01-22 16:10:04,391;INFO;com.ptvgroup.xserver.framework.ModuleAgent; Restarting module m0001. Module is not responding. 2014-01-22 16:10:05,395;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Starting module instance m0001 in external process... 2014-01-22 16:10:06,227;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 is up and running.
If a module does not respond to server pings for more than 5 seconds (can be configured with backendPingTimeout
in xserver.properties
) the framework assumes that the module hangs and tries to destroy the process. Here is what the log prints in this case:
2014-01-23 16:06:36,876;ERROR;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 did not answer ping for 5001 milliseconds. 2014-01-23 16:06:36,876;INFO;com.ptvgroup.xserver.framework.XServer1Dispatcher; Agent m0001 seems to be broken. Destroying process.
When a request exceeds the module timeout while it is running (see key moduleTimeout
in the corresponding <xmodule>.properties
) the framework logs that the request is expired and that it tries to delete the request. In addition the billing line RequestTimes
shows the service method called, indicates non-success with false and does not contain an error message. The exit code is 0.
2014-01-23 15:53:45,069;INFO;com.ptvgroup.xserver.framework.ModuleAgent; Request is expired, trying to delete request. 2014-01-23 15:53:45,069;INFO;com.ptvgroup.xserver.framework.ModuleAgent; Delete requested: 8e7c2b5e-ec28-4ee2-ad5a-85dcae382b99, status = DeleteRequestedByTimeout 2014-01-23 15:53:50,070;INFO;ErrorLog;8e7c2b5e-ec28-4ee2-ad5a-85dcae382b99;0:0:0:0:0:0:0:1; unknown-http;59990;unknown-cluster;XCrash.loopInfinite;false;;;;null; m0001;1;0;0;0;0;0;0;35278;NO-TXN;;;;;;;;;- 2014-01-23 15:53:50,070;INFO;RequestTimes;8e7c2b5e-ec28-4ee2-ad5a-85dcae382b99;0:0:0:0:0:0:0:1; unknown-http;59990;unknown-cluster;XCrash.loopInfinite;false;;;;null;m0001;1;0;0;0;0;0;0;35278; NO-TXN;;;;;;;;;- 2014-01-23 15:53:50,390;INFO;com.ptvgroup.xserver.framework.ModuleInstanceProcessWrapper; Module instance m0001 shutting down with exit code 0.
Copyright © 2024 PTV Logistics GmbH All rights reserved. | Imprint