none
Windows Timeサービスの動作について RRS feed

  • 質問

  • いつもお世話になっております。
    現在、WindowsTimeサービスにてWorkGroup環境で時刻同期を行っております。
    設定としてはSpecialPollIntervalを86400(1日)に設定しているのですが、予期せぬタイミングで時刻が数秒進んだり、戻ったりする現象が発生しております。

    デバッグログを出力したところ、1日1回のポーリング以外に別のポーリングが動作しているようで
    特にNTPサーバから時刻を取得していないのに
    07:07:54 から07:05:01に*SET*TIME*していることが分かりました。
    この原因と回避策が分かりましたらご教授願えますでしょうか?
    端末はWindows10 LTSB 2016です。

    152823 07:04:54.9598095s - W32TmServiceMain: timeout
    152823 07:04:54.9600200s - Sample Prepared at 132039326949600011 for peer XXX.XXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->172.18.10.254:123)
    152823 07:04:54.9600730s - Sorted endpoints for intersection algorithm:
    152823 07:04:54.9600861s -     -03.6474400s  -1
    152823 07:04:54.9601038s -     +00.3307773s  0
    152823 07:04:54.9601197s -     +04.3089946s  1
    152823 07:04:54.9601357s - Intersection successful over range: -03.6474400s - +04.3089946s
    152823 07:04:54.9601585s -   SyncDist:39782173 SelectJitter:0 PeerJitter:3014167 CorrectedOffset:3307773
    152823 07:04:54.9601722s -  MaxSelectJitter: 0 MinPeerJitter: 3014167
    152823 07:04:54.9601882s - New NTP sample not available.
    152823 07:04:54.9602030s - NtpClient returned 1 samples.
    152823 07:04:54.9602155s - Sample 0 offset:-00.9910904s delay:+00.0009655s dispersion:03.9940347s
    152823 07:04:54.9602378s - Intersection successful with 0 dropped samples.
    152823 07:04:54.9602520s -   0: Sample:0 SyncDist:359945174 SelectDisp:0
    152823 07:04:54.9602686s - Sample 0 chosen. Select Dispersion:00.0000000s STC:93206053
    152823 07:04:54.9603193s - ClockDispln Update: LastUTC:93206053 SO:3308299 KPhO:88714 PhO:3219585 uT:0
    152823 07:04:54.9603581s -  sysPollTicks:2.09715e+006 FllDown:65536 PllUp:0 PllDown:1.67772e+007 FllRA:12.2817 PllRA:0
     RA:12 CR:156262 DecRA:0.30407 nT:5390261 RAPhO:66322151 SD:39940347 LI:0 S:3 RDl:9655 RDs:40040347 TSF:0x0 Sync
    152823 07:05:01.9229515s - ClockDispln Discipline: *SET*TIME* - KPho:69630450
    152823 07:05:01.9230119s - W32TmServiceMain: ********** Time Slip Notification **********
    152823 07:05:01.9230136s - TimeProvCommand([NtpClient], TPC_TimeJumped) called.
    152823 07:05:01.9230734s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9231008s - PeerPollingThread: waiting 2171.149s
    152823 07:05:01.9230883s - ClockDispln TimeSlip:TimeSlip LastUTC:98596314 [Poll: 15->10] SetUnsync: LI:3 S:0 RDl:9655 RDs:40040347 TSF:0x0 ReleaseClock2CMOS
    152823 07:05:01.9220575s - TimeProvCommand([NtpClient], TPC_TimeJumped) called.
    152823 07:05:01.9220809s - TimeProvCommand([NtpClient], TPC_PollIntervalChanged) called.
    152823 07:05:01.9220912s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9220963s - Peer poll: Max:86400.0000000s (special) Cur:2171.1485819s
    152823 07:05:01.9221220s - W32TmServiceMain: waiting i16.000s (1024.000s)
    2019年6月3日 9:10

すべての返信

  • チャブーンです。

    この件ですが、w32timeデバッグログの一部しかないため(前後の経緯がわからない)、確かなことは分かりません。「ClockDispln Discipline: *SET*TIME*」は厳密には「NTP時刻をWindowsシステム時刻にStep反映」したことを示すだけなので、ログのリクツ上はあっています(Syncの後のSETなので)。ワークグループの場合Slewの上限は1秒なので、1秒以上ということでStep反映したのでしょう。

    サンプル値が時刻がばらばらなのも問題と思いますが、原因元がNTPサーバーなのかクライアントなのかわからないので、切り分けも含め、「SpecialPollInterval」の利用自体をやめる、ことをお奨めします。この値の使用は、NTPの作法には全く則らない動作なので、(ここではわかりませんが)以下の問題が起こる可能性があるためです。

    https://blogs.technet.microsoft.com/jpntsblog/2013/04/14/spike/
    https://support.microsoft.com/en-us/help/2638243/when-specialpollinterval-is-used-as-a-polling-interval-the-windows-tim

    できれば最初からMinPollInterval/MaxPollIntervalを使うことをお奨めします。それと当然のことですが、「Windows Time」サービスは常時起動していますよね?もしもタスクスケジューラーで「1日1回しか起動しない」ような動作になっている場合、それを解除する必要があります。


    フォーラムは有償サポートとは異なる「コミュニティ」です。フォーラムでご質問頂くにあたっての注意点 をご一読のうえ、お楽しみください。

    2019年6月4日 2:59
  • ありがとうございます。

    経緯として毎日7:41頃にSpecialPollIntervalで時刻同期する設定となっております。(実際には0x9設定)
    ログから毎日7:41にはNTPサーバから時刻を受け取って同期実行しているようなのですが、それ以外のポーリングで7:04:54にいきなり7秒進んだ7:51:01時刻に更新される動作となっているようです。
    これが0x9設定時の0x8(Min,Maxのポーリング)動作が影響しているかが知りたいところです。
    そして、このポーリングは何をしているのかをご教授いただきたいです。(特にNTPサーバから時間を貰っているようには見えないため)

    現状、グループポリシ側の設定を0x8にして、Min,Maxで動作させて様子を見ております。
    また、windows timeサービスは現象発生時は手動起動で、トリガー起動に失敗することがあるため常時起動にして様子を見ております。

    前日の7:41からのログを再度添付させていただきます。
    お手数をおかけしますが、ご確認の程よろしくお願い致します。

    ★★前日の7:41★★
    152822 07:41:13.0713485s - PeerPollingThread: WaitTimeout
    152822 07:41:13.0715532s - Polling peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152822 07:41:13.0716793s - Peer poll: Max:86400.0000000s (special) Cur:00.0000000s
    152822 07:41:13.0717021s - PeerPollingThread: waiting 86400.000s
    152822 07:41:13.0719775s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    152822 07:41:13.0720089s - ListeningThread -- response heard from XXX.XXXX.XXX.XXX:123 <- XXX.XXXX.XXX.XXX:123
    152822 07:41:13.0720328s - /-- NTP Packet:
    152822 07:41:13.0720368s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 4 - Server;  LiVnMode: 0x1C
    152822 07:41:13.0720454s - | Stratum: 2 - secondary reference (syncd by (S)NTP)
    152822 07:41:13.0720511s - | Poll Interval: 10 - 1024s;  Precision: -22 - 238.419ns per tick
    152822 07:41:13.0720636s - | RootDelay: 0x0000.0025s - 0.000564575s;  RootDispersion: 0x0000.3B97s - 0.232773s
    152822 07:41:13.0720784s - | ReferenceClockIdentifier: 0xAC1206EF - source IP: XXX.XXXX.XXX.XXX
    152822 07:41:13.0720876s - | ReferenceTimestamp:   0xE09CA793D70BB2F2 - 13203847699840022300ns - 152822 07:28:19.8400223s
    152822 07:41:13.0721012s - | OriginateTimestamp:   0xE09CAA991253E483 - 13203848473071592600ns - 152822 07:41:13.0715926s
    152822 07:41:13.0721149s - | ReceiveTimestamp:     0xE09CAA9814A8ED43 - 13203848472080702600ns - 152822 07:41:12.0807026s
    152822 07:41:13.0721292s - | TransmitTimestamp:    0xE09CAA9814A9AC13 - 13203848472080714000ns - 152822 07:41:12.0807140s
    152822 07:41:13.0721434s - >-- Non-packet info:
    152822 07:41:13.0721503s - | DestinationTimestamp: 152822 07:41:13.0721560s - 0xE09CAA99126EE9C2152822 07:41:13.0721617s -  - 13203848473072004900ns152822 07:41:13.0721674s -  - 152822 07:41:13.0720049s
    152822 07:41:13.0721748s - | RoundtripDelay: 400900ns (0s)
    152822 07:41:13.0721851s - | LocalClockOffset: -991090400ns - 0:00.991090400s
    152822 07:41:13.0721982s - \--
    152822 07:41:13.0722193s - ListeningThread STC:93206052
    152822 07:41:13.0722364s - Peer poll: Max:86400.0000000s (special) Cur:86399.9994417s
    152822 07:41:13.0722569s - Response from peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123), ofs: -00.9910904s
    152822 07:41:13.0722786s - 5 Age:5 Ofs:+00.0000000s COfs:-00.4705778s Dly:+00.0000000s RDly:+00.0000000s Dsp:18.0000100s RDsp:00.0000000s Pnt:08.0000400s Dst:16.0000000s FDsp:00.2812501s Jitter:00.0000000s AgeTime:+13203848473.0722729s
    152822 07:41:13.0723173s - 4 Age:4 Ofs:+00.0000000s COfs:-00.4705778s Dly:+00.0000000s RDly:+00.0000000s Dsp:18.0000100s RDsp:00.0000000s Pnt:08.0000400s Dst:16.0000000s FDsp:00.8437504s Jitter:00.0000000s AgeTime:+13203848473.0722729s
    152822 07:41:13.0723538s - 3 Age:3 Ofs:+00.0000000s COfs:-00.4705778s Dly:+00.0000000s RDly:+00.0000000s Dsp:18.0000100s RDsp:00.0000000s Pnt:08.0000400s Dst:16.0000000s FDsp:01.9687510s Jitter:00.0000000s AgeTime:+13203848473.0722729s
    152822 07:41:13.0723903s - 2 Age:2 Ofs:-00.1013876s COfs:-00.5719654s Dly:+00.0004580s RDly:+00.0005951s Dsp:02.0000103s RDsp:00.2375031s Pnt:08.0000400s Dst:02.0004683s FDsp:02.2187522s Jitter:00.0000000s AgeTime:+172800.8734307s
    152822 07:41:13.0724285s - 1 Age:1 Ofs:-00.1207919s COfs:-00.6896737s Dly:+00.0004245s RDly:+00.0005493s Dsp:01.0000103s RDsp:00.2264404s Pnt:04.0000400s Dst:01.0004348s FDsp:02.4687547s Jitter:908520.2703889s AgeTime:+86400.8728305s
    152822 07:41:13.0724667s - 0 Age:0 Ofs:-00.9910904s COfs:-00.9910904s Dly:+00.0004009s RDly:+00.0005646s Dsp:00.0000003s RDsp:00.2327728s Pnt:00.0000000s Dst:00.0004009s FDsp:02.4687548s Jitter:908520.2703889s AgeTime:+00.0002680s
    152822 07:41:13.0725032s - Peer jitter: 00.3014167s Filter Dispersion: 02.4687548s
    152822 07:41:13.0725574s - W32TmServiceMain: resync req, irreg now pending.
    152822 07:41:13.0725916s - W32TmServiceMain: waiting i0.000s (18686.829s)
    152822 07:41:13.0733267s - W32TmServiceMain: timeout
    152822 07:41:13.0733997s - Sample Prepared at 132038484730733746 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152822 07:41:13.0734442s - Sorted endpoints for intersection algorithm:
    152822 07:41:13.0734727s -     -03.9945174s  -1
    152822 07:41:13.0735115s -     -00.9910904s  0
    152822 07:41:13.0735474s -     +02.0123366s  1
    152822 07:41:13.0735828s - Intersection successful over range: -03.9945174s - +02.0123366s
    152822 07:41:13.0736330s -   SyncDist:30034270 SelectJitter:0 PeerJitter:3014167 CorrectedOffset:-9910904
    152822 07:41:13.0736638s -  MaxSelectJitter: 0 MinPeerJitter: 3014167
    152822 07:41:13.0737111s - NTP Sample 4262073004 chosen. Dispersion: 39940347 SystemJitter: 4.26268e+006 STC:93206053 SystemOffset: -9910904 Delay: 9655
    152822 07:41:13.0737561s - NtpClient returned 1 samples.
    152822 07:41:13.0737858s - Sample 0 offset:-00.9910904s delay:+00.0009655s dispersion:03.9940347s
    152822 07:41:13.0738337s - Intersection successful with 0 dropped samples.
    152822 07:41:13.0738656s -   0: Sample:0 SyncDist:359945174 SelectDisp:0
    152822 07:41:13.0738947s - Sample 0 chosen. Select Dispersion:00.0000000s STC:93206053
    152822 07:41:13.0739945s - ClockDispln Update: LastUTC:93206053 SO:-10565134 KPhO:1167260 PhO:-11732394 uT:5529607
    152822 07:41:13.0740812s -  sysPollTicks:2.09713e+006 FllDown:5.52961e+006 PllUp:2.09713e+006 PllDown:1.6777e+007 FllRA:-0.530435 PllRA:-0.0787173
     RA:-1 CR:156251 DecRA:0.274454 nT:0 RAPhO:0 SD:45332939 (i) LI:0 S:3 RDl:9655 RDs:40040347 TSF:0x0 Sync
    152822 07:41:13.0743508s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-20 CR:156251 UI:360000 phcT:209932 KPhO:-10565134
    152822 07:41:13.0743902s - W32TmServiceMain: waiting 18686.828s
    152822 08:41:12.6373729s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-11 CR:156251 UI:360000 phcT:230400 KPhO:-5893901
    152822 09:41:12.4076582s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-6 CR:156251 UI:360000 phcT:230400 KPhO:-3296267
    152822 10:41:12.2929118s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-3 CR:156251 UI:360000 phcT:230400 KPhO:-1850633
    152822 11:41:12.2479021s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-2 CR:156251 UI:360000 phcT:230400 KPhO:-1096199
    152822 12:41:12.2254930s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156251 UI:360000 phcT:230400 KPhO:-572164

    ★★★★別のポーリング動作が動いているように見えます★★★★
    152822 12:52:39.0531416s - W32TmServiceMain: timeout
    152822 12:52:39.0532169s - Sample Prepared at 132038671590531935 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152822 12:52:39.0532608s - Sorted endpoints for intersection algorithm:
    152822 12:52:39.0532898s -     -03.2769163s  -1
    152822 12:52:39.0533280s -     -00.0572164s  0
    152822 12:52:39.0533645s -     +03.1624835s  1
    152822 12:52:39.0534005s - Intersection successful over range: -03.2769163s - +03.1624835s
    152822 12:52:39.0534506s -   SyncDist:32196999 SelectJitter:0 PeerJitter:3014167 CorrectedOffset:-572164
    152822 12:52:39.0534809s -  MaxSelectJitter: 0 MinPeerJitter: 3014167
    152822 12:52:39.0535157s - New NTP sample not available.
    152822 12:52:39.0535487s - NtpClient returned 1 samples.
    152822 12:52:39.0535772s - Sample 0 offset:-00.9910904s delay:+00.0009655s dispersion:03.9940347s
    152822 12:52:39.0536337s - Intersection successful with 0 dropped samples.
    152822 12:52:39.0536730s -   0: Sample:0 SyncDist:359945174 SelectDisp:0
    152822 12:52:39.0536861s - Sample 0 chosen. Select Dispersion:00.0000000s STC:93206053
    152822 12:52:39.0537358s - ClockDispln Update: LastUTC:93206053 SO:-516143 KPhO:-516143 PhO:0 uT:0
    152822 12:52:39.0537797s -  sysPollTicks:2.09713e+006 FllDown:65535.5 PllUp:0 PllDown:1.67771e+007 FllRA:0 PllRA:-0
     RA:0 CR:156251 DecRA:0.274454 nT:1195957 RAPhO:328235 SD:43609563 LI:0 S:3 RDl:9655 RDs:40040347 TSF:0x0 Sync
    152822 12:52:39.0539279s - W32TmServiceMain: waiting 32768.000s
    152822 14:52:39.0781644s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:1 CR:156251 UI:360000 phcT:230400 KPhO:168960
    152822 17:52:39.1752207s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:1 CR:156251 UI:360000 phcT:230400 KPhO:128263
    152822 21:52:39.2970564s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:1 CR:156251 UI:360000 phcT:230400 KPhO:150800

    152822 21:58:47.3005627s - W32TmServiceMain: timeout
    152822 21:58:47.3006346s - Sample Prepared at 132038999273006192 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152822 21:58:47.3006785s - Sorted endpoints for intersection algorithm:
    152822 21:58:47.3007070s -     -03.6167055s  -1
    152822 21:58:47.3007452s -     -00.0177435s  0
    152822 21:58:47.3007794s -     +03.5812185s  1
    152822 21:58:47.3008148s - Intersection successful over range: -03.6167055s - +03.5812185s
    152822 21:58:47.3008632s -   SyncDist:35989620 SelectJitter:0 PeerJitter:3014167 CorrectedOffset:-177435
    152822 21:58:47.3008940s -  MaxSelectJitter: 0 MinPeerJitter: 3014167
    152822 21:58:47.3009288s - New NTP sample not available.
    152822 21:58:47.3009721s - NtpClient returned 1 samples.
    152822 21:58:47.3009847s - Sample 0 offset:-00.9910904s delay:+00.0009655s dispersion:03.9940347s
    152822 21:58:47.3010069s - Intersection successful with 0 dropped samples.
    152822 21:58:47.3010206s -   0: Sample:0 SyncDist:359945174 SelectDisp:0
    152822 21:58:47.3010389s - Sample 0 chosen. Select Dispersion:00.0000000s STC:93206053
    152822 21:58:47.3010947s - ClockDispln Update: LastUTC:93206053 SO:-194523 KPhO:133712 PhO:-328235 uT:0
    152822 21:58:47.3011409s -  sysPollTicks:2.09713e+006 FllDown:65535.5 PllUp:0 PllDown:1.67771e+007 FllRA:-1.25213 PllRA:-0
     RA:-1 CR:156250 DecRA:0.0223266 nT:3293109 RAPhO:-3219585 SD:41815220 LI:0 S:3 RDl:9655 RDs:40040347 TSF:0x0 Sync
    152822 21:58:47.3012938s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-6 CR:156250 UI:360000 phcT:23552 KPhO:-3414108
    152822 21:58:47.3013325s - W32TmServiceMain: waiting 32768.000s
    152822 22:58:47.1632137s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-3 CR:156250 UI:360000 phcT:230400 KPhO:-2026564
    152822 23:58:47.0956665s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-2 CR:156250 UI:360000 phcT:230400 KPhO:-1330220
    152823 00:58:47.0506864s - ClockDispln Discipline: *SKEW*TIME* - PhCRR:-1 CR:156250 UI:360000 phcT:230400 KPhO:-864276

    ★★★★別のポーリング動作が動いているように見えます★★★★
    152823 07:04:54.9598095s - W32TmServiceMain: timeout
    152823 07:04:54.9600200s - Sample Prepared at 132039326949600011 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152823 07:04:54.9600730s - Sorted endpoints for intersection algorithm:
    152823 07:04:54.9600861s -     -03.6474400s  -1
    152823 07:04:54.9601038s -     +00.3307773s  0
    152823 07:04:54.9601197s -     +04.3089946s  1
    152823 07:04:54.9601357s - Intersection successful over range: -03.6474400s - +04.3089946s
    152823 07:04:54.9601585s -   SyncDist:39782173 SelectJitter:0 PeerJitter:3014167 CorrectedOffset:3307773
    152823 07:04:54.9601722s -  MaxSelectJitter: 0 MinPeerJitter: 3014167
    152823 07:04:54.9601882s - New NTP sample not available.
    152823 07:04:54.9602030s - NtpClient returned 1 samples.
    152823 07:04:54.9602155s - Sample 0 offset:-00.9910904s delay:+00.0009655s dispersion:03.9940347s
    152823 07:04:54.9602378s - Intersection successful with 0 dropped samples.
    152823 07:04:54.9602520s -   0: Sample:0 SyncDist:359945174 SelectDisp:0
    152823 07:04:54.9602686s - Sample 0 chosen. Select Dispersion:00.0000000s STC:93206053
    152823 07:04:54.9603193s - ClockDispln Update: LastUTC:93206053 SO:3308299 KPhO:88714 PhO:3219585 uT:0
    152823 07:04:54.9603581s -  sysPollTicks:2.09715e+006 FllDown:65536 PllUp:0 PllDown:1.67772e+007 FllRA:12.2817 PllRA:0
     RA:12 CR:156262 DecRA:0.30407 nT:5390261 RAPhO:66322151 SD:39940347 LI:0 S:3 RDl:9655 RDs:40040347 TSF:0x0 Sync

    ★★★★ここで7秒進んだ時刻にSETされる★★★★
    152823 07:05:01.9229515s - ClockDispln Discipline: *SET*TIME* - KPho:69630450
    152823 07:05:01.9230119s - W32TmServiceMain: ********** Time Slip Notification **********
    152823 07:05:01.9230136s - TimeProvCommand([NtpClient], TPC_TimeJumped) called.
    152823 07:05:01.9230734s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9231008s - PeerPollingThread: waiting 2171.149s
    152823 07:05:01.9230883s - ClockDispln TimeSlip:TimeSlip LastUTC:98596314 [Poll: 15->10] SetUnsync: LI:3 S:0 RDl:9655 RDs:40040347 TSF:0x0 ReleaseClock2CMOS
    152823 07:05:01.9220575s - TimeProvCommand([NtpClient], TPC_TimeJumped) called.
    152823 07:05:01.9220809s - TimeProvCommand([NtpClient], TPC_PollIntervalChanged) called.
    152823 07:05:01.9220912s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9220963s - Peer poll: Max:86400.0000000s (special) Cur:2171.1485819s
    152823 07:05:01.9221220s - W32TmServiceMain: waiting i16.000s (1024.000s)
    152823 07:05:01.9221237s - PeerPollingThread: waiting 2171.149s
    152823 07:05:01.9221459s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9221556s - TimeProvCommand([NtpClient], TPC_PollIntervalChanged) called.
    152823 07:05:01.9221698s - PeerPollingThread: waiting 2171.149s
    152823 07:05:01.9221875s - Peer poll: Max:86400.0000000s (special) Cur:2171.1484906s
    152823 07:05:01.9222138s - W32TmServiceMain: waiting 1024.000s
    152823 07:05:01.9222263s - PeerPollingThread: PeerListUpdated
    152823 07:05:01.9222542s - PeerPollingThread: waiting 2171.149s


    152823 07:22:05.9220239s - W32TmServiceMain: timeout
    152823 07:22:05.9220923s - Sample Prepared at 132039337259220775 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152823 07:22:05.9221351s - ** NTP sample vector is empty.
    152823 07:22:05.9221716s - No new NTP sample is available.
    152823 07:22:05.9222087s - W32TmServiceMain: waiting 1024.000s
    152823 07:39:09.9223785s - W32TmServiceMain: timeout
    152823 07:39:09.9225656s - Sample Prepared at 132039347499225411 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152823 07:39:09.9226078s - ** NTP sample vector is empty.
    152823 07:39:09.9226380s - No new NTP sample is available.
    152823 07:39:09.9226762s - W32TmServiceMain: waiting 1024.000s

    ★★★★1日1回の時刻同期で7秒戻って、時刻が合った★★★★
    152823 07:41:13.0713039s - PeerPollingThread: WaitTimeout
    152823 07:41:13.0713678s - Polling peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152823 07:41:13.0715389s - Peer poll: Max:86400.0000000s (special) Cur:00.0000000s
    152823 07:41:13.0715959s - PeerPollingThread: waiting 86400.000s
    152823 07:41:13.0718308s - ListeningThread -- DataAvailEvent set for socket 1 (0.0.0.0:123)
    152823 07:41:13.0718605s - ListeningThread -- response heard from XXX.XXXX.XXX.XXX <- XXX.XXXX.XXX.XXX:123
    152823 07:41:13.0718838s - /-- NTP Packet:
    152823 07:41:13.0718884s - | LeapIndicator: 0 - no warning;  VersionNumber: 3;  Mode: 4 - Server;  LiVnMode: 0x1C
    152823 07:41:13.0718970s - | Stratum: 2 - secondary reference (syncd by (S)NTP)
    152823 07:41:13.0719027s - | Poll Interval: 10 - 1024s;  Precision: -22 - 238.419ns per tick
    152823 07:41:13.0719146s - | RootDelay: 0x0000.0025s - 0.000564575s;  RootDispersion: 0x0000.3AEDs - 0.230179s
    152823 07:41:13.0719295s - | ReferenceClockIdentifier: 0xAC1206EF - source IP: XXX.XXXX.XXX.XXX
    152823 07:41:13.0719386s - | ReferenceTimestamp:   0xE09DF9DF71B344F3 - 13203934303444141700ns - 152823 07:31:43.4441417s
    152823 07:41:13.0719517s - | OriginateTimestamp:   0xE09DFC191246D82B - 13203934873071393500ns - 152823 07:41:13.0713935s
    152823 07:41:13.0719654s - | ReceiveTimestamp:     0xE09DFC11F4E16C4D - 13203934865956564700ns - 152823 07:41:05.9565647s
    152823 07:41:13.0719796s - | TransmitTimestamp:    0xE09DFC11F4E2572E - 13203934865956578700ns - 152823 07:41:05.9565787s
    152823 07:41:13.0719945s - >-- Non-packet info:
    152823 07:41:13.0720013s - | DestinationTimestamp: 152823 07:41:13.0720064s - 0xE09DFC1912653005152823 07:41:13.0720121s -  - 13203934873071856500ns152823 07:41:13.0720184s -  - 152823 07:41:13.0718565s
    152823 07:41:13.0720258s - | RoundtripDelay: 449000ns (0s)
    152823 07:41:13.0720355s - | LocalClockOffset: -7115053300ns - 0:07.115053300s
    152823 07:41:13.0720492s - \--
    152823 07:41:13.0720715s - ListeningThread STC:98735267
    152823 07:41:13.0720886s - Peer poll: Max:86400.0000000s (special) Cur:86399.9994441s
    152823 07:41:13.0721062s - Response from peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123), ofs: -07.1150533s
    152823 07:41:13.0721296s - Logging warning: Time Provider NtpClient: The time sample received from peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123) differs from the local time by -7 seconds.  The transmission delay from the server was 0 milliseconds. 
    152823 07:41:13.0721530s - 5 Age:5 Ofs:+00.0000000s COfs:-06.1117025s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0251290s RDsp:00.0000000s Pnt:04.1005560s Dst:16.0000000s FDsp:00.2503926s Jitter:00.0000000s AgeTime:+172800.8727049s
    152823 07:41:13.0721912s - 4 Age:4 Ofs:+00.0000000s COfs:-06.1117025s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0251290s RDsp:00.0000000s Pnt:00.1005160s Dst:16.0000000s FDsp:00.7511778s Jitter:00.0000000s AgeTime:+86400.0001424s
    152823 07:41:13.0722448s - 3 Age:3 Ofs:+00.0000000s COfs:-06.1117025s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0251290s RDsp:00.0000000s Pnt:08.1005560s Dst:16.0000000s FDsp:01.7527483s Jitter:00.0000000s AgeTime:+13203934873.0721473s
    152823 07:41:13.0722830s - 2 Age:2 Ofs:+00.0000000s COfs:-06.1117025s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0251290s RDsp:00.0000000s Pnt:08.1005560s Dst:16.0000000s FDsp:03.7558894s Jitter:00.0000000s AgeTime:+13203934873.0721473s
    152823 07:41:13.0723184s - 1 Age:1 Ofs:+00.0000000s COfs:-06.1117025s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0251290s RDsp:00.0000000s Pnt:08.1005560s Dst:16.0000000s FDsp:07.7621716s Jitter:00.0000000s AgeTime:+13203934873.0721473s
    152823 07:41:13.0723566s - 0 Age:0 Ofs:-07.1150533s COfs:-07.1150533s Dly:+00.0004490s RDly:+00.0005646s Dsp:00.0000003s RDsp:00.2301788s Pnt:00.0000000s Dst:00.0004490s FDsp:07.7621717s Jitter:00.0000000s AgeTime:+00.0002908s
    152823 07:41:13.0723931s - Peer jitter: 00.0000000s Filter Dispersion: 07.7621717s
    152823 07:41:13.0724330s - W32TmServiceMain: resync req, irreg now pending.
    152823 07:41:13.0724632s - W32TmServiceMain: waiting i0.000s (900.850s)
    152823 07:41:13.0732963s - W32TmServiceMain: timeout
    152823 07:41:13.0733590s - Sample Prepared at 132039348730733436 for peer XXX.XXXX.XXX.XXX,0x9 (ntp.m|0x9|0.0.0.0:123->XXX.XXXX.XXX.XXX:123)
    152823 07:41:13.0734024s - Sorted endpoints for intersection algorithm:
    152823 07:41:13.0734309s -     -15.1079106s  -1
    152823 07:41:13.0734702s -     -07.1150533s  0
    152823 07:41:13.0735061s -     +00.8778040s  1
    152823 07:41:13.0735426s - Intersection successful over range: -15.1079106s - +00.8778040s
    152823 07:41:13.0735934s -   SyncDist:79928573 SelectJitter:0 PeerJitter:0 CorrectedOffset:-71150533
    152823 07:41:13.0736242s -  MaxSelectJitter: 0 MinPeerJitter: 0
    152823 07:41:13.0736670s - NTP Sample 4262073004 chosen. Dispersion: 151074038 SystemJitter: 0 STC:98735267 SystemOffset: -71150533 Delay: 10136
    152823 07:41:13.0737120s - NtpClient returned 1 samples.
    152823 07:41:13.0737417s - Sample 0 offset:-07.1150533s delay:+00.0010136s dispersion:15.1074038s
    152823 07:41:13.0737907s - Intersection successful with 0 dropped samples.
    152823 07:41:13.0738221s -   0: Sample:0 SyncDist:471079106 SelectDisp:0
    152823 07:41:13.0738511s - Sample 0 chosen. Select Dispersion:00.0000000s STC:98735267
    152823 07:41:13.0739458s - ClockDispln Update: LastUTC:98735267 SO:-71108282 KPhO:42251 *PhO:-71150533 uT:138953
     SD:83079869 LI:0 S:3 RDl:10136 RDs:151174038 TSF:0x0 Unset->Hold

    2019年6月4日 4:56
  • こんにちは

    チャブーンの意見を賛成します。

    SpecialPollIntervalがポーリング間隔として使用されると、Windowsタイムサービスは、サービスがスパイク状態になった場合に時刻を修正しません。

    SpecialPollIntervalの代わりにMinPollInterval/MaxPollIntervalを使用してまた状況をチェックすることをお願いします。

    どうぞよろしくお願いいたします

    Fan



    Please remember to mark the replies as an answers if they help. If you have feedback for TechNet Subscriber Support, contact tnmff@microsoft.com

    2019年6月4日 7:36
    モデレータ
  • こんにちは

    今の状況を確認させていただきます

    お役に立つところがありましたら,遠慮なくてご連絡ください

    Fan


    Please remember to mark the replies as an answers if they help. If you have feedback for TechNet Subscriber Support, contact tnmff@microsoft.com

    2019年6月6日 8:22
    モデレータ
  • チャブーンです。

    この件ですが、いただいたログだと「過去に得た時刻サンプル(この状況で都合7秒間時刻がずれている)を再評価して時刻同期をしている」部分しか見えず、どの動作が正しいのか、わからないというのが本当のところかと思います。

    こちらが知りたかったのは、

    また、windows timeサービスは現象発生時は手動起動で、トリガー起動に失敗することがあるため常時起動にして様子を見ております。

    ということらしいので、実際のWindows Timeがどのように起動・終了しているのか、また起動時に必ず記録されるw32time各種レジストリ情報の確認が必要かと思いました。これはログの全編を見ないとわからないです。

    また、「7秒ずれている」はNTPサーバー側では可能性が少ないと思いますので、クライアント側が勝手にずれているように見えます。クライアントは仮想環境の「仮想ゲスト」マシンではありませんか?

    上記の場合、Windows Timeに不具合があるようなので、したのKBを確認してみてください。仮に該当しなくても、最近のWindowsは前提として「不具合がある」が既定なので、公開された更新プログラムはすべて適用することをお奨めします。

    https://support.microsoft.com/en-us/help/4457127/windows-10-update-kb4457127

    更新プログラムをすべて適用したうえで、したの方法で「Windows Timeのトリガー」をはずし、かつSpecialPollRemainingレジストリ値を「空欄(値を空にする)」に設定してWindows Timeを再起動すると、SpecialPollInterval設定でのクリーンな環境が実現できると思います(同期時刻は7:41ではなくなるので注意してください)

    https://support.microsoft.com/ja-jp/help/2385818/windows-time-service-doesn-t-start-automatically-on-a-workgroup-comput

    ただうえの話しは、「なにがなんでも今の設定は変えたくない」という前提で、私はお奨めしません。


    フォーラムは有償サポートとは異なる「コミュニティ」です。フォーラムでご質問頂くにあたっての注意点 をご一読のうえ、お楽しみください。

    2019年6月6日 10:49