locked
Time Skew Problem RRS feed

  • Question

  • Hi,

    We are getting time skew alert. I have checked the below. This is on a PDC.

    There is no kernel general event for last 7 days.

    w32tm /resync /rediscover is working perfectly fine.

    w32tm /stripchart /computer:<ntp server name> /samples:3 /dataonly
    Tracking ######.com [#####:123].
    Collecting 3 samples.
    The current time is 12/29/2015 1:49:54 PM.
    13:49:54, -00.0014021s
    13:49:56, -00.0046351s
    13:49:58, -00.0051172s

    w32tm /query /status 
    Leap Indicator: 0(no warning)
    Stratum: 4 (secondary reference - syncd by (S)NTP)
    Precision: -6 (15.625ms per tick)
    Root Delay: 0.0721893s
    Root Dispersion: 0.0972451s
    ReferenceId: 0x0A831AFA (source IP:  10.131.26.250)
    Last Successful Sync Time: 12/29/2015 4:05:53 PM
    Source: #####.com,0x8
    Poll Interval: 10 (1024s)

    So I have enabled w32time debug logging. Please find a portion of the log below.

    151572 17:01:26.0769480s - ListeningThread -- response heard from 10.60.4.64:123 <- 172.18.16.33:123
    151572 17:01:26.0769480s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->10.60.4.64:123
    151572 17:01:26.5604798s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    151572 17:01:26.5604798s - ListeningThread -- response heard from 172.18.17.161:123 <- 172.18.16.33:123
    151572 17:01:26.5604798s - Computing server digest: OLD:FALSE, RID:00243C9B
    151572 17:01:26.5760776s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->172.18.17.161:123
    ckDispln Discipline: *SKEW*TIME* - PhCRR:2 CR:156001 PhCR:2 UI:100 phcT:65 KPhO:2029

    Not able to understand the debug log. What is PhCRR,PhCR,phcT,KPhO. Please let me know what should I look in the w32time debug log.

     Thanks,

    Arindam


    Tuesday, December 29, 2015 9:23 PM

Answers

All replies

  • Hi Arindam,

    I wasn’t able to find official document regarding PhCRR,PhCR,PhCT,KPhO.

    I suggest you to run the command line below to check the synchronize source of PDC, and post the result.

    W32tm /Query /Source

    Best Regards,

    Jay


    Please remember to mark the replies as answers if they help and un-mark them if they provide no help. If you have feedback for TechNet Subscriber Support, contact tnmff@microsoft.com.

    Wednesday, December 30, 2015 9:09 AM
  • Hi,

    That is already pointing to ntp (ntp.###.com). 

    w32tm /query /source
    ntp.<domain name>.com,0x8

    it is taking the time data from the above time source which is ntp.<domain name>.com

    Thanks,

    Arindam

    Wednesday, December 30, 2015 5:40 PM
  • If the PDC is your NTP server as well it can not be its own time source (system log will give you a time source error). Go to the registry "hklm\system\currentcontroset\services\w32tm\parameters" Ensure that the the "NTPServer" key is correctly stated as an external time source, if you are using a DNS name and not IP ensure DNS static record is correct. Look at the "type" registry key ensure the PDC has it set for NTP and not NT5DS.

    On the other DC's make sure that you run the following:

    Net stop w32time

    net start w32time

    w32tm /config /syncfromflags:domhier /update

    w32tm /query /status

    Ensure your other DC's state that their time source is the PDCE/ NTP server.

    Wednesday, December 30, 2015 6:34 PM
  • Hi Jedi,

    I have done that. My PDC is pointing to external time souce (ntp.###.com). The time is synced. But I am getting time skew error.

    Other DCs are NT5DS. They are pointing to the PDC. 

    Everything should working as expected but I am getting time skew error in the debug log.

    So I have enabled w32time debug logging. Please find a portion of the log below.

    151572 17:01:26.0769480s - ListeningThread -- response heard from 10.60.4.64:123 <- 172.18.16.33:123
    151572 17:01:26.0769480s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->10.60.4.64:123
    151572 17:01:26.5604798s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    151572 17:01:26.5604798s - ListeningThread -- response heard from 172.18.17.161:123 <- 172.18.16.33:123
    151572 17:01:26.5604798s - Computing server digest: OLD:FALSE, RID:00243C9B
    151572 17:01:26.5760776s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->172.18.17.161:123
    ckDispln Discipline: *SKEW*TIME* - PhCRR:2 CR:156001 PhCR:2 UI:100 phcT:65 KPhO:2029

    I am not able to understand the debug log. What is PhCRR,PhCR,phcT,KPhO. Please let me know what should I look in the w32time debug log.

    Thanks

    Arindam


    Wednesday, December 30, 2015 7:47 PM
  • Use NSLookup, what does "ntp.###.com" resolve to IP wise? I ask because I look at your time source (0x0A831AFA source IP:  10.131.26.250) which should match the Source: field. Yet I look at the debug log and I see a different 10.X ip address.

    When did you change the time source? Did something happen right before this started happening?

    Wednesday, December 30, 2015 8:45 PM
  • On the PDCE make sure the registry key:

    HKLM\system\currentcontrolset\w32tm\config\announcementflag is set to 5

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\TimeProviders\NtpServer\enabled is set to 1

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\TimeProviders\NtpClient\SpecialPollInterval

    make sure it is set to the proper time sequence.

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config\MaxPosPhaseCorrection

    &

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config\MaxNegPhaseCorrection

    TimeInSeconds is a placeholder for a reasonable value, such as 1 hour (3600) or 30 minutes (1800). The value that you select will depend on the poll interval, network condition, and external time source.
    The default value of MaxNegPhaseCorrection is 48 hours in Windows Server 2008 R2 or later.

    https://support.microsoft.com/en-us/kb/816042

    https://technet.microsoft.com/en-us/library/cc784553(v=ws.10).aspx

    Wednesday, December 30, 2015 9:15 PM
  • Time Service skew: The Windows W32Time service is not as accurate or reliable as one thinks

    Yes, this is true, and this statement is according to Microsoft (KB939322). The reason is the Windows time service is not reliable to synch time down to 1 or 2 seconds and such tolerances are beyond the design of the Windows time service. . It was primarily designed for loose synchronization to support Active Directory’s use of the Kerberos v5 protocol for authentication, which uses and relies on a maximum time skew of 5 minutes for it authentication ‘salt.’ However the Windows Time services is sufficient for this reason, however if you have apps that require sensitive transactional processing with timing down to the second (possibly SEC, banking, or other reasons), it is suggested to use a third party time service.

    The Windows 2000 and 2003 time service skew and algorithm is pretty much the same.

    Regarding high accuracy, the following Microsoft’s position on this was quoted from:

    Support boundary to configure the Windows Time service for high accuracy environments:
    http://support.microsoft.com/kb/939322:

    “We do not guarantee and we do not support the accuracy of the W32Time service between nodes on a network. The W32Time service is not a full-featured NTP solution that meets time-sensitive application needs. The W32Time service is primarily designed to do the following:
    ◾Make the Kerberos version 5 authentication protocol work.
    ◾Provide loose sync time for client computers.

    ◾The W32Time service cannot reliably maintain sync time to the range of 1 to 2 seconds. Such tolerances are outside the design specification of the W32Time service.”

    “When the local clock offset has been determined, the following algorithm is used to adjust the time:  
    ◾If the local clock time of the client is behind the current time received from the server, W32Time will change the local clock time immediately.
    ◾If the local clock time of the client is more than three minutes ahead of the time on the server, W32Time will change the local clock time immediately.
    ◾If the local clock time of the client is less than three minutes ahead of the time on the server, W32Time will quarter or halve the clock frequency for long enough to bring the clocks into sync. If the client is less that 15 seconds ahead, it will halve the frequency; otherwise, it will quarter the frequency. The amount of time the clock spends running at an unusual frequency depends on the size of the offset that is being corrected. “

    High Accuracy W32time Requirements
    http://blogs.technet.com/b/askds/archive/2007/10/23/high-accuracy-w32time-requirements.aspx

    “This entry specifies the largest interval, in log2 seconds, allowed for the system polling interval. Note that while a system must poll according to the scheduled interval, a provider can refuse to produce samples when requested to do so. The default value for domain controllers is 10. The default value for domain members is 15. The default value for stand-alone clients and servers is 15. “

    Based on the article below, “If you change the MaxPollInterval and MinPollInterval local polling values for the Microsoft Windows Time service (W32time), the values are ignored. The service always polls at 17-minute intervals.”

    Settings for minimizing periodic WAN traffic
    http://support.microsoft.com/kb/819108

    Configuring the MaxPollInterval

    The passage below was quoted from:

    Config\MaxPollInterval
    http://technet.microsoft.com/en-us/library/cc739293(WS.10).aspx

    “Specifies the longest interval (in units of 2n seconds, where n is the value of this entry) that is allowed for system polling. While the system does not request samples less frequently than this, a provider may refuse to produce samples when requested to do so.”

    “Note: The time service itself is considered unsynchronized after 1.5 times the number of seconds specified by this entry have elapsed. The Network Time Protocol specifies that the maximum clock age is 86,400 seconds, so if the value of this entry is greater than 15, then peers will eventually ignore this server.”

    So if changing it from the default of 15 to 14, the longest time interval is changed from 32,768 seconds (546.13 hours or 22.75 days), to 16,384 seconds (273 hours or 11.37 days).

    http://blogs.msmvps.com/acefekay/2009/09/18/configuring-the-windows-time-service-for-windows-server/

    • Proposed as answer by Jay Gu Thursday, December 31, 2015 2:54 AM
    Wednesday, December 30, 2015 9:19 PM
  • Hi Jedi,

    Thanks for reply. Do you know how to read data in debug log for time service. What I should look for in debug.log.

    And How to read "ckDispln Discipline: *SKEW*TIME* - PhCRR:2 CR:156001 PhCR:2 UI:100 phcT:65 KPhO:2029"

    Thanks,

    Arindam

    Wednesday, December 30, 2015 11:24 PM
  • the debug log read as is, it goes to get the time, it comes back, time is skewed... You need to look at the MaxPollInterval interval and MaxNegPhaseCorrection/ MaxposPhaseCorrection.

    Wireshark or netmon packet captures will tell you a lot more with a point-to-point capture on the NTP port

    Thursday, December 31, 2015 2:33 AM
  • as I also previously stated your debug log shows a different 10.X.X.X IP than the IP listed as your time source. Please make sure to verify your source: "w32tm /query /source" & "w32tm /query /configuration"

    If you registered a www.ntpsource.com name then make sure DNS is resolving the right IP?

    Your authorized time source is not the one being used in the debug log

    Thursday, December 31, 2015 3:00 AM
  • Hi Jedi,

    Thanks for your reply.

    Can you please also let me know how to check date and time in debug log on time.

    151578 07:57:27.2866913s - Computing server digest: OLD:FALSE, RID:003E67A8
    151578 07:57:27.3022915s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->172.18.18.90:123
    151578 07:57:27.3958927s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    151578 07:57:27.3958927s - ListeningThread -- response heard from 10.44.60.101:123 <- 172.18.16.33:123
    151578 07:57:27.3958927s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->10.44.60.101:123
    151578 07:57:27.8794989s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156004 PhCR:1 UI:100 phcT:65 KPhO:-1147
    151578 07:57:28.8935119s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156004 PhCR:1 UI:100 phcT:65 KPhO:-1082
    151578 07:57:29.9075249s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156004 PhCR:1 UI:100 phcT:65 KPhO:-1017
    151578 07:57:30.3911311s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)

    Like form the below log 

    151578 07:57:27.8794989s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156004 PhCR:1 UI:100 phcT:65 KPhO:-1147

    I can get the time as 07:57:27.8794989s but how can I get the date from 151578

    Thanks

    Arindam


    • Edited by Ari18Das Monday, January 4, 2016 11:55 AM
    Monday, January 4, 2016 11:53 AM
  • The "07:57:27" is the time for which the record entry is created. I do not see the date in the record, you may need to use the date of the file as it may role over daily, hourly, etc... depending on how you have it set.
    Monday, January 4, 2016 2:32 PM
  • Hi,

    I have enabled the debug log as per below.

    w32tm /debug /enable /file:c:\W32Time\w32time.log /size:10000000 /entries:0-116

    Also I have configured the registry settings as per below.

    https://support.microsoft.com/en-us/kb/816042

    https://technet.microsoft.com/en-us/library/cc784553(v=ws.10).aspx

    Still I am getting skew time error on debug log.

    151578 13:51:32.4945528s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:186 CR:156001 PhCR:186 UI:100 phcT:65 KPhO:130473

    151578 13:51:33.5097618s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:169 CR:156001 PhCR:169 UI:100 phcT:65 KPhO:118383

    Thanks

    Arindam



    • Edited by Ari18Das Monday, January 4, 2016 3:23 PM
    Monday, January 4, 2016 3:17 PM
  • The debug log just tells you the time skew issue. Have you done any of the actions suggested to fix your time skew issue?

    Remember your time source in the debug log is different from what you are saying it should be... What this means is you are syncing to another time source. Example:

    151578 07:57:27.3958927s - TransmitResponse: sent 0.0.0.0:123(172.18.16.33:123)->10.44.60.101:123
    151578 07:57:27.8794989s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156004 PhCR:1

    source IP:  10.131.26.250

    Notice how the reference source IP is different from the one in the debug log?

    Monday, January 4, 2016 3:22 PM
  • Hi Jedi,

    I have done the following things

    On the PDCE make sure the registry key:

    HKLM\system\currentcontrolset\w32tm\config\announcementflag is set to 10

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\TimeProviders\NtpServer\enabled is set to 1

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\TimeProviders\NtpClient\SpecialPollInterval has been set to 900

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config\MaxPosPhaseCorrection has been set to 3600.

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config\MaxNegPhaseCorrection has been set to 3600

    Thanks,

    Arindam


    Monday, January 4, 2016 5:08 PM
  • Run the command on the NTP server: w32tm /query /status

    Does the "source:X.X.X.X" match what it should be?

    Look at your debug log, does the log show the same IP in the query/status results?

    Monday, January 4, 2016 5:19 PM
  • Hi Jedi,

    The IP Address is coming as per the source. Please find a full debug log where it is polling data from the source.

    151578 14:08:33.4183333s - Polling peer ntp.XXX.com,0x8 (ntp.m|0x8|0.0.0.0:123->10.131.26.250:123)
    151578 14:08:33.4183333s - Peer poll: Max:1024.0000000s Cur:00.0000000s
    151578 14:08:33.4183333s - PeerPollingThread: waiting 1024.000s
    151578 14:08:33.4495333s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    151578 14:08:33.4495333s - ListeningThread -- response heard from 10.131.26.250:123 <- 172.18.16.33:123
    151578 14:08:33.4495333s - /-- NTP Packet:
    151578 14:08:33.4495333s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 4 - Server;  LiVnMode: 0x1C
    151578 14:08:33.4495333s - | Stratum: 3 - secondary reference (syncd by (S)NTP)
    151578 14:08:33.4495333s - | Poll Interval: 10 - 1024s;  Precision: -10 - 976.563æs per tick
    151578 14:08:33.4495333s - | RootDelay: 0x0000.0A0Ds - 0.0392609s;  RootDispersion: 0x0000.172Cs - 0.0905151s
    151578 14:08:33.4495333s - | ReferenceClockIdentifier: 0x0A89FA0B - source IP: 10.137.250.11
    151578 14:08:33.4495333s - | ReferenceTimestamp:   0xDA34F90171EB8658 - 13096389505445000100ns - 151578 13:58:25.4450001s
    151578 14:08:33.4495333s - | OriginateTimestamp:   0xDA34FB616B17E422 - 13096390113418333300ns - 151578 14:08:33.4183333s
    151578 14:08:33.4495333s - | ReceiveTimestamp:     0xDA34FB6172F1AB38 - 13096390113449000100ns - 151578 14:08:33.4490001s
    151578 14:08:33.4495333s - | TransmitTimestamp:    0xDA34FB6172F1AB38 - 13096390113449000100ns - 151578 14:08:33.4490001s
    151578 14:08:33.4495333s - >-- Non-packet info:
    151578 14:08:33.4495333s - | DestinationTimestamp: 151578 14:08:33.4495333s - 0xDA34FB6173149D45151578 14:08:33.4495333s -  - 13096390113449533300ns151578 14:08:33.4495333s -  - 151578 14:08:33.4495333s
    151578 14:08:33.4495333s - | RoundtripDelay: 31200000ns (0s)
    151578 14:08:33.4495333s - | LocalClockOffset: 15066800ns - 0:00.015066800s
    151578 14:08:33.4495333s - \--
    151578 14:08:33.4495333s - Peer poll: Max:1024.0000000s Cur:1023.9688000s
    151578 14:08:33.4495333s - Response from peer ntp.xxx.com,0x8 (ntp.m|0x8|0.0.0.0:123->10.131.26.250:123), ofs: +00.0150668s
    151578 14:08:33.4495333s - 5 Age:5 Ofs:+00.0064663s Dly:+00.0312500s RDly:+00.0393219s Dsp:00.0580584s RDsp:00.0680695s Pnt:00.1659260s Dst:00.2396094s FDsp:00.0043002s
    151578 14:08:33.4495333s - 4 Age:4 Ofs:+00.0084638s Dly:+00.0312500s RDly:+00.0393219s Dsp:00.0521324s RDsp:00.0757599s Pnt:00.1422220s Dst:00.2099794s FDsp:00.0054516s
    151578 14:08:33.4495333s - 3 Age:3 Ofs:+00.0110658s Dly:+00.0312500s RDly:+00.0392914s Dsp:00.0462065s RDsp:00.0829010s Pnt:00.1185184s Dst:00.1803499s FDsp:00.0047263s
    151578 14:08:33.4495333s - 2 Age:2 Ofs:+00.0070678s Dly:+00.0312500s RDly:+00.0392914s Dsp:00.0402806s RDsp:00.0905762s Pnt:00.0948148s Dst:00.1507204s FDsp:00.0063626s
    151578 14:08:33.4495333s - 1 Age:1 Ofs:+00.0174673s Dly:+00.0312500s RDly:+00.0392761s Dsp:00.0284287s RDsp:00.0776062s Pnt:00.0474072s Dst:00.0914609s FDsp:00.0043815s
    151578 14:08:33.4495333s - 0 Age:0 Ofs:+00.0150668s Dly:+00.0312500s RDly:+00.0392609s Dsp:00.0165769s RDsp:00.0905151s Pnt:00.0000000s Dst:00.0322019s FDsp:00.0021907s
    151578 14:08:33.4495333s - W32TmServiceMain: resync req, reg too soon.
    151578 14:08:33.4495333s - W32TmServiceMain: waiting 0.029s
    151578 14:08:33.4807333s - W32TmServiceMain: timeout
    151578 14:08:33.4807333s - Sample Prepared at 130963901134807333 for peer ntp.xxx.com,0x8 (ntp.m|0x8|0.0.0.0:123->10.131.26.250:123)
    151578 14:08:33.4807333s - NtpClient returned 1 samples.
    151578 14:08:33.4807333s - Sample 0 offset:+00.0150668s delay:+00.0705109s dispersion:00.1092830s
    151578 14:08:33.4807333s - Intersection successful with 0 dropped samples.
    151578 14:08:33.4807333s -   0: Sample:0 SyncDist:481445384 SelectDisp:0
    151578 14:08:33.4807333s - Sample 0 chosen. Select Dispersion:00.0000000s STC:226293265
    151578 14:08:33.4807333s - ClockDispln Update: SO:150668 KPhO:668 PhO:150000 uT:65639 FllPPE:150000 PllPPE:150000 FllPPrE:132076 PllPPrE:132076 sysPollTicks:65640 FllDown:65640 PllUp:65639 PllDown:525120 FllRA:0 PllRA:0 RA:0 CR:156001 nT:2 RAPhO:0 SD:1044410 LI:0 S:4 RDl:705109 RDs:1192830 TSF:0x0 Sync
    151578 14:08:33.4807333s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:215 CR:156001 PhCR:215 UI:100 phcT:56 KPhO:150668
    151578 14:08:33.4807333s - W32TmServiceMain: waiting 1024.000s
    151578 14:08:34.4961308s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:195 CR:156001 PhCR:195 UI:100 phcT:65 KPhO:136693
    151578 14:08:35.5113983s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:177 CR:156001 PhCR:177 UI:100 phcT:65 KPhO:124018

    Thanks,

    Arindam

    Monday, January 4, 2016 5:29 PM
  • Your announcement flag on the NTP server should be set to 5

    HKLM\system\currentcontrolset\w32tm\config\announcementflag is set to 10

    Try moving the special interval to 3600 (default)... 3600 is 60 minutes while 900 is 15 minutes.

    For max pos and max neg settings try the below

    Here is an example of a registry entry that you can merge on-demand to apply a 48 hour limit to the phase correction:

    [HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config]
    "MaxNegPhaseCorrection"=dword:0002a300
    "MaxPosPhaseCorrection"=dword:0002a300

    Monday, January 4, 2016 6:30 PM
  • Hi Arindam,

    Here is an article about best practice and troubleshooting steps of time synchronize for your reference.

    Windows Time and the W32TM service

    http://blogs.technet.com/b/industry_insiders/archive/2006/08/29/w32-tm-service.aspx

    Best Regards,

    Jay


    Please remember to mark the replies as answers if they help and un-mark them if they provide no help. If you have feedback for TechNet Subscriber Support, contact tnmff@microsoft.com.

    Tuesday, January 5, 2016 5:31 AM
  • Hi All,

    I was using ntp.<domain name>.com,0x8 as NTP server.

    But by using ntp.<domain name>.com,0x9 resolved the issue I think. I am not getting any time skew alert as of now. 

    Please find the below link for more details.

    http://blogs.technet.com/b/askds/archive/2007/11/01/configuring-your-pdce-with-alternate-time-sources.aspx

    Thanks,

    Arindam

    • Marked as answer by Ari18Das Thursday, January 7, 2016 5:14 PM
    Thursday, January 7, 2016 5:14 PM