Logging and Monitoring

The following sections cover logging the time, report, and leap state and monitoring the current state of the TimeMonitor application.

Logging

Logging is configured in conf/log4j.properties (given that the wrapper scripts in bin/ are used to run the application).

By default, events at INFO level are logged to a local file called signserver-timemonitor.log.

It is recommended to use syslog or similar mechanisms to send the logs to a remote server where they can be inspected when the time is detected to be out of sync.

The TimeMonitor maintains three types of states: Time state, Report state, and Leap state.

Time State

Time State for time synchronization describes the status of the time source and can be:

• INSYNC: The time is in sync as it was detected to be within the configured range.
• SOON_OUT_OF_SYNC: The time is in sync but was detected to be within the configured range to give a warning.
• OUT_OF_SYNC: The time was detected to be out of sync.
• UNKNOWN: The status of the time is unknown as the time server has not yet been contacted, it could not be contacted, or some other error occurred preventing the TimeMonitor from getting the status.

Report State

Report State describes the status of the publishing of the results to SignServer and can be:

• REPORTED: The results were successfully published to SignServer.
• REPORTED_BUT_EXPIRE_TIME_SHORT: The results were successfully published to SignServer but the time it took to perform the measurements and publish it was longer than the time configured as timemonitor.warnRunTime. The log gives more information about the actual run time and how much time was spent during the query and publishing when the state changes to this state.
• FAILED_TO_REPORT: The results could not be published to SignServer. An error message could be available in the log when the state changes to this state.

Leap State

Leap State is reported to SignServer with the following values: 

• NONE: No leap second is scheduled at the next possible leap second occurrence. 

• POSITIVE: A positive (inserted) leap second is scheduled at the next possible leap second occurrence. 

• NEGATIVE: A negative (removed) leap second is scheduled at the next possible leap second occurrence. 

• UNKNOWN: Leapsecond state was unknown when querying the time server (for Builtin SNTP) or the NTP daemon (for Local NTP Commands).

For more information on StatusReportingLocalComputerTimeSource and setting up leap second handling, see Time Sources in SignServer.

Examples

Each time any of the states change, the new Time, Report, and Leap states are logged at INFO level:

14:56:01,983  INFO TimeMonitorRunnable:60 - Started
14:56:02,491 ERROR TimeMonitorRunnable:214 - Command failed (1): 31 Oct 14:56:02
 ntpdate[26321]: no server suitable for synchronization found
14:56:02,511 ERROR TimeMonitorRunnable:268 - Failed to update status property: Connection
 refused
14:56:02,515  INFO TimeMonitorRunnable:91 - State changed to: UNKNOWN,FAILED_TO_REPORT,NONE
14:58:11,152  INFO TimeMonitorRunnable:91 - State changed to: UNKNOWN,REPORTED,NONE
15:01:23,310  INFO TimeMonitorRunnable:91 - State changed to: INSYNC,REPORTED,NONE

 When the state changes from INSYNC or SOON_OUT_OF_SYNC to either OUT_OF_SYNC or UNKNOWN, an additional log entry outputs the last time determined to be in sync:

15:32:05,990 INFO  [TimeMonitorRunnable] State changed to: INSYNC,REPORTED,NONE
15:32:06,492 INFO  [TimeMonitorRunnable] State changed to: OUT_OF_SYNC,REPORTED,NONE
15:32:06,492 INFO  [TimeMonitorRunnable] Last trusted time was: 2012-11-27 15:32:05,990

Monitoring

The current state of the TimeMonitor application can also be monitored from an external service if the state-showing web (health check) server is enabled.

Example of getting the current state from the state web page:

$ curl http://tsaserver:8980/state
 1409050686281,INSYNC,REPORTED,NONE,1ccdf46b,0,508,8,6 

It is also possible to use the TimeMonitorStatusReportWorker to monitor the TimeMonitor application. In this case, the external system sends a request to the worker.

Example of getting the current state from the TimeMonitorStatusReportWorker:

$ curl http://tsaserver:8080/signserver/process -d workerName=TimeMonitorStatusReport -d data=
 1409050686281,INSYNC,REPORTED,NONE,1ccdf46b,0,508,8,6 

The current state is returned as a comma-separated list of values:

1. Update time: The current time when the expiration time to set was calculated
2. Time state: See states in the Logging section.
3. Report state: See states in the Logging section.
4. Leap state: See states in the Logging section.
5. Config version: Identifier for the last configuration received.
6. Time offset: The measured difference in time with the time server.
7. Time server query time: The time it took to query the time server.
8. NTP daemon query time: The time it took to query the leap state.
9. Report time: The time it took to report the status to SignServer.

Rate-limiting

If an NTP server responds with a rate-limiting "kiss of death" response, the time monitor will log an error and stop querying and the state will be set to UNKNOWN. The time monitor will resume querying on the next configuration update (i.e. setting another NTP server host).