タイムサーバーの時刻がおかしい？

システム設定 > 一般 > 日付と時刻

「自動的に設定」は有効、「タイムサーバー」は Apple (time.apple.com.) だけど、「時刻がずれる」症状に遭遇した方が少なくないようです。ネットワーク通信に問題ないならば「タイムサーバーの時刻が狂ってる」と判断するのは仕方ないでしょう。

しかし、タイムサーバーから時刻が取れない状況が続くと、Macの内蔵時計のままになっています。設定上はタイムサーバーの時刻ですが、実態はMacの内蔵時計かもしれないのです。内蔵時計も実用的な精度で時間が進むので、気付くまでに日数を要するでしょう。

このとき、「内蔵時計の時刻」を「タイムサーバーの時刻」と誤認して「タイムサーバーの時刻が狂ってる」と判断しても、他所と状況が違うので混乱することになります。

時刻が取れない状況が続く？

time.apple.com は IP アドレスに変換すると下の表になります。IP アドレスに対する色分けが取得の可否です。

IPv6 通信ができない環境では、タイムサーバーへの接続が IPv4 で時刻が取れます。使われる IP アドレスは青色です。

IPv6 通信ができる環境では、使われる IP アドレスは赤か黄(暗)です。青(IPv4)は使用されません。ホスト名 jptyo5-ntp-* (赤)はすべて応答がありません。唯一、応答があるのはホスト名 krsel6-ntp-* ですが

　　Mac → [中継] → krsel6-ntp-*

　　Mac ← [中継] ← krsel6-ntp-*

の通信が約1秒で終わらないとタイムアウト(エラー)になります。タイムアウトになるかならないかは [中継] 次第です。ホスト名から jptyo5-* は日本･東京で、krsel6-* は韓国ソウルでしょう。krsel6-* は jptyo5-* よりネットワーク的に条件が厳しくなります。(特に最初の通信)

krsel6-* から時刻を取れるかどうかは運次第となって

の何れかの状況になりますが、どの状況になるのか確定しないので、とても厄介です。

通信が IPv4 なのか IPv6 なのか？

Google の IPv6 通信テストがあるので、チェックしてみてください。

以前 Mac OS X が不安定だと思っていたが、その原因は ESET Cyber Security Pro だった。

コンソール アプリケーションで .crash ファイルを確認すると、

と、こんな感じでクラッシュが多発していた。

ESET プロセスのクラッシュ直後に

などの症状に遭遇している。まるで Mac OS X が不安定な感じだが、ECSP がカーネルに悪影響を及ぼす（カーネル拡張処理中に異常終了する）ので様々な症状が出ていたようだ。

クラッシュ時の診断ファイルを見つつ分析して、動作が不安定となるバグを特定した。このバグは初期バージョンから V6.3 まで含まれていて V6.4 で修正された。数日に一回発生していた ESET プロセスのクラッシュは、半年で数回に激減した。V6.5 になってから一度も遭遇していない。

■多発するクラッシュの技術的な詳細

沢山ある .crash ファイルを眺めていると、バックトレース中の RefObje::Unref() が目に付いた。その先には参照が終わったであろうオブジェクトのデストラクタ[Object::~Object()形式の関数]がある。そこからメモリ解放に失敗するなど、メモリ内容の破壊が原因となっているようだった。

デストラクタの処理中なので、同じオブジェクトが別のスレッドで既に破棄されていた場合が考えられる。これを仮定してバックトレースを見ると、呼び出し元である RefObj::Unref() がスレッド セーフではない可能性に気付いた。

RefObj::Unref() はオブジェクトの参照カウントをデクリメントして０ならデストラクタを呼び出す、短くて簡単なプログラムだと名前から推定できる。ライセンス違反（その旨はサポートにも話をしてある）だが逆アセンブルして調査する事にした。プログラムを見ていくと、やっぱりスレッドセーフになっていなかった。

RefObj::Unref() での参照カウントのデクリメントと結果判定は

こんな風になっていてマルチスレッド プログラミングにおけるバグの典型

になっている。 C++ による記述だろうから、アトミック操作と判定処理で別々のメモリアクセスになっているのだろう。アトミック操作により参照カウントは RefObj::Unref() を呼び出した回数に応じた値で更新されるが、判定時に他のスレッドを同じ値と判断する可能性がある。運が悪いと、二つのスレッドから同じオブジェクトのデストラクタが各々呼び出されてしまう。クラッシュする場合はプログラムが異常終了するが、クラッシュしない場合は、メモリ内容を破壊したまま動作するので何が起きるか分からない。

V6.1 はコンパイル時の最適化オプションが入っておらずシンボルも残っていた。どうやらデバッグ版でビルドしたバイナリをリリースしていたようだ。お陰で RefObj::Unref() という名前の関数にあるバグを特定できた。

■クラッシュログ

サポートからの最初の回答は「正常に動作しています」だった。問い合わせ内容にクラッシュログを引用し、customer_info ログにクラッシュ ログが含まれていたのに「正常動作」と判断している。クラッシュログを見ていないことが分かった。サポートの技術担当の知識不足もあるだろうけど、クラッシュログ確認を指示されていないことも分かる。本来は ESET社からクラッシュログの収集指示が出ていないといけないが、不具合調査におけるクラッシュログの重要性を知らない技術担当でいいのか？と、基本的なことから問い合わせしないといけなかった。

不具合の状況について提出した資料では、動作と症状の詳細解説と修正方法を示しておいた。サポートの技術担当は理解したという返事が早々にあったが、そこからESET社が「内容が正しいようだ」と回答されるまで約三ヶ月かかっている。動作を理解できたのか非常に怪しいが修正された。経緯から ESET Cyber Security のプログラム担当はスキル不足と判断するしかないので、スキルアップをお願いしておいた。

原因調査ではクラッシュログは重要な情報だから、OSでは「○○が予期しない理由で終了しました」でレポートするときの送信内容になっている。

■ Mission Control の挙動

選択するウインドウの位置は

(1) Mission Control を起動した状態

(2) デスクトップを選択可能にした状態

の二段階で移動します。

■ 問題１：ウインドウ選択の枠がズレた場所に出る

二段階で移動した後、選択の枠が一段階目の位置に出ることがあります。

再現手順は

　　1. Magic Trackpad を使う

　　2. マウス カーソルを画面上端の中央付近へ

　　3. Mission Control をジェスチャー (３本指で上) で起動する

　　　※スッっと一瞬だけ触れて起動します

　　4. Mission Control 開始から約 0.5 秒以内にマウス カーソルを移動する

　　　※デスクトップを選択可能な状態にします

　　5. ウインドウを選択する

とします。

■ 問題２：選択したウインドウが固定される

選択の枠がズレた状態でウインドウを選択すると、そのウインドウが画面上に固定され移動もサイズ変更も出来なくなることがあります。

再現させるには選択の枠がズレた状態を作りますが、最初の配置も重要です。ここでは Mission Control を開始する前の配置は[デスクトップ1]のような位置・サイズで開始しました。

左のターミナルをクリックして選択したら、元の位置に戻らずウインドウが固定されました。こうなると、ウインドウを移動しようと操作しても移動しません。サイズを変更しようとすると、

となって、変更できません。代わりに中の表示が拡大されています。サイズ変更操作を続けて、もう一度 Mission Control を実行してみると、

となっていて、[デスクトップ1] では左側のターミナルが小さくなっています。これが本来の位置とサイズのようです。さらに、この Mission Control 中に左側のターミナルをドラッグして少し移動すると、正常な位置・サイズに戻ってウインドウの固定は終了しました。

■ アップデート待ち

Apple サポートの窓口の方が再現確認しています。誰でも再現可能なので修正されるのは時間の問題でしょう。あとはアップデートを待つだけです。