NTP Problems from the publisher

mmedwid · ‎10-07-2011

I keep being sent that there is a problem with NTP from the publisher. But when I run utils ntp status at the command prompt it says synchronised to NTP server within 128ms - which is close enough. Can someone shed light into what the complaint it exactly and how to approach this?

"At Fri Oct 07 14:00:15 PDT 2011 on node hrk-cucmpub, the following SyslogSeverityMatchFound events generated: SeverityMatch - Critical ntpRunningStatus.sh: The local NTP client is off by more than the acceptable threshold of 3 seconds from its remote NTP system peer. The normal remedy is for NTP Watch Dog to automatically restart NTP. However, an unusual number of automatic NTP restarts have already occurred on this node. No additional automatic NTP restarts will be done until NTP time synchronization stabilizes. Check NTP status via CLI 'utils ntp status' and ensure good network connectivity to the remote NTP server(s). After rectifying the problem, restart NTP on this node and any dependent nodes via CLI 'utils ntp restart'. If all else fails, schedule a reboot of this server. :

admin:utils ntp status

ntpd (pid 15437 15435) is running...

remote refid st t when poll reach delay offset jitter

==============================================================================

127.127.1.0 LOCAL(0) 10 l 28 64 1 0.000 0.000 0.004

*10.10.10.139 204.123.2.72 2 u 13 64 1 0.288 -14.115 9.004

10.10.10.140 10.10.10.139 3 u 12 64 1 0.313 -648.34 7.431

synchronised to NTP server (10.10.10.139) at stratum 3

time correct to within 128 ms

polling server every 64 s

Current time in UTC is : Fri Oct 7 21:03:38 UTC 2011

Current time in America/Los_Angeles is : Fri Oct 7 14:03:38 PDT 2011

Aaron Harrison · ‎10-08-2011

Hi

Sounds like your NTP server may not be very stable - try removing the current one (139?) and see if it running against the other (140) is more stable...

Aaron

Aaron Please remember to rate helpful posts to identify useful responses, and mark 'Answered' if appropriate!

mmedwid · ‎10-08-2011

I did exactly that. Changed from 139 to 140. For a couple hours it resulted in these "heartbeat" warnnings (server, tftp and attendant console - the latter of which I don't even use.) Then I started getting "NTP is not synchronizing with any of the external NTP servers". This despite the fact that running "utils ntp status" from ssh command line shows it synchronized. The time displaying at the end of the command is accurate. Perhaps I could point to an externap

NTP source. Not sure how to guage the stability of ntp servers. They are pretty well resourced VMs/Domain Controllers.

admin:utils ntp status

ntpd (pid 10995) is running...

remote refid st t when poll reach delay offset jitter

==============================================================================

*127.127.1.0 LOCAL(0) 10 l 62 64 377 0.000 0.000 0.002

10.10.10.140 0.0.0.0 16 u 959 1024 0 0.000 0.000 4000.00

synchronised to local net at stratum 11

time correct to within 12 ms

polling server every 64 s

Current time in UTC is : Sat Oct 8 15:14:32 UTC 2011

Current time in America/Los_Angeles is : Sat Oct 8 08:14:32 PDT 2011

hrk-cucmpub, the following SyslogSeverityMatchFound events generated: SeverityMatch - Critical ntpRunningStatus.sh: NTP is not synchronizing with any of the external NTP servers. Verify the network connectivity to the external NTP servers, that they're NTPv4 and are running. Use CLI 'utils ntp status' to verify their operational status.

HRS · ‎06-01-2016

What was the fix for your issue?

I am running into the same kind of issue.. It looks like it drops the connection for very few seconds..

CUCM Version 10.5.2.13900-12

Jun 1 15:15:34 CCPUB local7 2 : 126015: CCPUB: Jun 01 2016 08:15:34 PM.354 UTC : %UC_RTMT-2-RTMT_ALERT: %[AlertName=SyslogSeverityMatchFound][AlertDetail= At Wed Jun 01 15:15:34 CDT 2016 on node 10.10.0.4, the following SyslogSeverityMatchFound events generated: #012SeverityMatch : Critical#012MatchedEvent : Jun 1 15:15:05 CCPUB user 2 platform: NTP is not synchronizing with any of the external NTP servers. Verify the network connectivity to the external NTP servers, that they're NTPv4 and are running. Use CLI 'utils ntp status' to verify their operational status.#012AppID : Cisco Syslog Agent#012ClusterID : #012NodeID : CCPUB#012 TimeStamp : Wed Jun 01 15:15:05 CDT 2016][AppID=Cisco AMC Service][ClusterID=][NodeID=CCPUB]: RTMT Alert

Leszek Wojnarski · ‎06-07-2016

Hi HRS,

I don't know what was the fix of this issue in the subject, but the errors you are getting are often cause by wrong NTP version, connectivity issue etc.

Can you please sen the result of the following commands from Pub:

utils diagnose module ntp_reachability
utils diagnose module ntp_clock_drift
utils diagnose module ntp_stratum

And then run this command for couple minutes and attach results as well:

utils network capture port 123

Leszek

HRS · ‎06-07-2016

Hi Leszek,

Thank you your response,

admin:utils ntp status
ntpd (pid 27245) is running...

remote refid st t when poll reach delay offset jitter
==============================================================================
*66.220.9.122 .CDMA. 1 u 84 1024 377 54.063 0.086 0.204

synchronised to NTP server (66.220.9.122) at stratum 2
time correct to within 60 ms
polling server every 1024 s

Current time in UTC is : Tue Jun 7 13:56:26 UTC 2016
Current time in America/Chicago is : Tue Jun 7 08:56:26 CDT 2016

All these were passed.. Here are my outputs..

admin:utils diagnose module ntp_reachability

Log file: platform/log/diag4.log

Starting diagnostic test(s)
===========================
test - ntp_reachability : Passed

Diagnostics Completed

The final output will be in Log file: platform/log/diag4.log

Please use 'file view activelog platform/log/diag4.log' command to see the output
admin:
admin:utils diagnose module ntp_clock_drift

Log file: platform/log/diag5.log

Starting diagnostic test(s)
===========================
test - ntp_clock_drift : Passed

Diagnostics Completed

The final output will be in Log file: platform/log/diag5.log

Please use 'file view activelog platform/log/diag5.log' command to see the output
admin:
admin:
admin:utils diagnose module ntp_stratum

Log file: platform/log/diag1.log

Starting diagnostic test(s)
===========================
test - ntp_stratum : Passed

Diagnostics Completed

The final output will be in Log file: platform/log/diag1.log
Please use 'file view activelog platform/log/diag1.log' command to see the output

admin:
admin:

admin:utils network capture port 123
Executing command with options:
size=128 count=1000 interface=eth0
src= dest= port=123
ip=
08:45:01.898795 IP SUB.hort.com.49602 > CCPUB.ntp: NTPv4, Client, length 48
08:45:01.899219 IP CCPUB.ntp > SUB.hort.com.49602: NTPv4, Server, length 48
08:45:01.907811 IP SUB.hort.com.49602 > CCPUB.ntp: NTPv4, Client, length 48
08:45:01.908869 IP CCPUB.ntp > SUB.hort.com.49602: NTPv4, Server, length 48
08:45:01.917608 IP SUB.hort.com.49602 > CCPUB.ntp: NTPv4, Client, length 48
08:45:01.917684 IP CCPUB.ntp > SUB.hort.com.49602: NTPv4, Server, length 48
08:45:01.925807 IP SUB.hort.com.49602 > CCPUB.ntp: NTPv4, Client, length 48
08:45:01.925859 IP CCPUB.ntp > SUB.hort.com.49602: NTPv4, Server, length 48
08:45:02.117091 IP SUB.hort.com.49657 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.117503 IP CCPUB.ntp > SUB.hort.com.49657: NTPv4, Server, length 48
08:45:02.125635 IP SUB.hort.com.49657 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.126012 IP CCPUB.ntp > SUB.hort.com.49657: NTPv4, Server, length 48
08:45:02.134180 IP SUB.hort.com.49657 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.134366 IP CCPUB.ntp > SUB.hort.com.49657: NTPv4, Server, length 48
08:45:02.142536 IP SUB.hort.com.49657 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.142584 IP CCPUB.ntp > SUB.hort.com.49657: NTPv4, Server, length 48
08:45:02.372313 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:02.399061 IP CUPS.hort.com.46403 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.399129 IP CCPUB.ntp > CUPS.hort.com.46403: NTPv4, Server, length 48
08:45:02.399305 IP CUPS.hort.com.46403 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.399369 IP CCPUB.ntp > CUPS.hort.com.46403: NTPv4, Server, length 48
08:45:02.399555 IP CUPS.hort.com.46403 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.399591 IP CCPUB.ntp > CUPS.hort.com.46403: NTPv4, Server, length 48
08:45:02.399757 IP CUPS.hort.com.46403 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.399791 IP CCPUB.ntp > CUPS.hort.com.46403: NTPv4, Server, length 48
08:45:02.582399 IP CUPS.hort.com.39937 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.582489 IP CCPUB.ntp > CUPS.hort.com.39937: NTPv4, Server, length 48
08:45:02.582628 IP CUPS.hort.com.39937 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.582664 IP CCPUB.ntp > CUPS.hort.com.39937: NTPv4, Server, length 48
08:45:02.582769 IP CUPS.hort.com.39937 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.582794 IP CCPUB.ntp > CUPS.hort.com.39937: NTPv4, Server, length 48
08:45:02.582915 IP CUPS.hort.com.39937 > CCPUB.ntp: NTPv4, Client, length 48
08:45:02.582940 IP CCPUB.ntp > CUPS.hort.com.39937: NTPv4, Server, length 48
08:45:03.372308 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:03.427066 IP 66.220.9.122.ntp > CCPUB.39447: NTPv4, Server, length 48
08:45:03.427149 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:03.482172 IP 66.220.9.122.ntp > CCPUB.39447: NTPv4, Server, length 48
08:45:03.482233 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:03.536902 IP 66.220.9.122.ntp > CCPUB.39447: NTPv4, Server, length 48
08:45:03.730392 IP CCPUB.57133 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:03.784825 IP 66.220.9.122.ntp > CCPUB.57133: NTPv4, Server, length 48
08:45:03.784893 IP CCPUB.57133 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:04.730395 IP CCPUB.57133 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:45:04.784842 IP 66.220.9.122.ntp > CCPUB.57133: NTPv4, Server, length 48
08:45:04.784929 IP CCPUB.57133 > 66.220.9.122.ntp: NTPv4, Client, length 48
08:46:01.537841 IP SUB.hort.com.48328 > CCPUB.ntp: NTPv4, Client, length 48
08:46:01.538619 IP CCPUB.ntp > SUB.hort.com.48328: NTPv4, Server, length 48
08:46:01.546784 IP SUB.hort.com.48328 > CCPUB.ntp: NTPv4, Client, length 48

Thanks,

HRS

Leszek Wojnarski · ‎06-07-2016

If I were you I'd switch to some local NTP server instead of this Public server.

The reason is that from the logs I can see that some requests that are send from Publisher are not being responded by the server, which might cause such issue.

# Sample requests from Pub that were not responded by the server

08:45:02.372313 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48

08:45:03.372308 IP CCPUB.39447 > 66.220.9.122.ntp: NTPv4, Client, length 48

So you can just setup some NTP on the router that is close to you CUCM and is should to the trick.

Leszek

Aman Soi · ‎06-07-2016

[+5] to Leszek.

HRS,you can refer the troubleshooting DOC on NTP

http://www.cisco.com/c/en/us/support/docs/unified-communications/unified-communications-manager-callmanager/118718-technote-cucm-00.html

regds,

aman

HRS · ‎06-08-2016

Thank you Leszek and Aman,

I switched to some local NTP server instead of this Public server and there are no more errors.. but our Unity Connection is pulling the information from Same Public NTP Server.. there are no errors... and that is the reason I didn't went on that route but anyways the issue is resolved..

HRS · ‎06-07-2016

Atleast every 10 - 15 seconds this syslog alert is getting generated but the NTP shows as Synchronised

Jun 1 15:15:34 CCPUB local7 2 : 126015: CCPUB: Jun 01 2016 08:15:34 PM.354 UTC : %UC_RTMT-2-RTMT_ALERT: %[AlertName=SyslogSeverityMatchFound][AlertDetail= At Wed Jun 01 15:15:34 CDT 2016 on node 10.10.0.4, the following SyslogSeverityMatchFound events generated: #012SeverityMatch : Critical#012MatchedEvent : Jun 1 15:15:05 CCPUB user 2 platform: NTP is not synchronizing with any of the external NTP servers. Verify the network connectivity to the external NTP servers, that they're NTPv4 and are running. Use CLI 'utils ntp status' to verify their operational status.#012AppID : Cisco Syslog Agent#012ClusterID : #012NodeID : CCPUB#012 TimeStamp : Wed Jun 01 15:15:05 CDT 2016][AppID=Cisco AMC Service][ClusterID=][NodeID=CCPUB]: RTMT Alert

mmedwid · ‎10-08-2011

While the CUCM complains of NTP not being available (will post screen shot in separate message as it blew up my last post) - running w32tm from a Win 7 laptop seems to show it is ok. The CUCM and NTP source are on the same LAN, gig attached, no errors. Also the utils command shows synchronized which is out of step with the CUCM GUI display.

C:\Users\mmedwid>w32tm /stripchart /computer:10.10.10.139

Tracking 10.10.10.139 [10.10.10.139:123].

The current time is 10/8/2011 9:30:01 AM.

09:30:01 d:+00.0260000s o:+05.8135206s [ |

* ]

09:30:03 d:+00.0260000s o:+05.8185004s [ |

* ]

09:30:05 d:+00.0260000s o:+05.8188544s [ |

* ]

09:30:07 d:+00.0310000s o:+05.8087084s [ |

* ]

09:30:09 d:+00.0300000s o:+05.8101882s [ |

* ]

09:30:11 d:+00.0280000s o:+05.8091680s [ |

* ]

09:30:13 d:+00.0280000s o:+05.8111478s [ |

admin:utils ntp status

ntpd (pid 4047) is running...

remote refid st t when poll reach delay offset jitter

==============================================================================

*127.127.1.0 LOCAL(0) 10 l 20 64 377 0.000 0.000 0.002

10.10.10.140 0.0.0.0 16 u 664 1024 0 0.000 0.000 4000.00

10.10.10.139 204.123.2.72 2 u 70 512 0 0.000 0.000 4000.00

synchronised to local net at stratum 11

time correct to within 12 ms

polling server every 1024 s

Current time in UTC is : Sat Oct 8 16:34:57 UTC 2011

Current time in America/Los_Angeles is : Sat Oct 8 09:34:57 PDT 2011

mmedwid · ‎10-08-2011

Note how in the CUCM GUI the publisher is saying NTP service not accessible. But again the utils ntp says synchronized:

admin:utils ntp status

ntpd (pid 4047) is running...

remote refid st t when poll reach delay offset jitter

==============================================================================

*127.127.1.0 LOCAL(0) 10 l 4 64 377 0.000 0.000 0.002

10.10.10.140 0.0.0.0 16 u 842 1024 0 0.000 0.000 4000.00

10.10.10.139 204.123.2.72 2 u 248 512 0 0.000 0.000 4000.00

synchronised to local net at stratum 11

time correct to within 11 ms

polling server every 1024 s

Current time in UTC is : Sat Oct 8 16:37:55 UTC 2011

Current time in America/Los_Angeles is : Sat Oct 8 09:37:55 PDT 2011

RTMT is sending alerts. Not sure which to believe. All is well or all is not so well.

Rob Huffman · ‎10-08-2011

Have a look at the great info from Michael in this thread and his

attached blog

https://supportforums.cisco.com/message/3289490#3289490

Cheers!

Rob

dave.yeskey · ‎10-28-2011

What version of CUCM?

mmedwid · ‎10-28-2011

7.1.5.31900-3