Linuxの起動を29万2612回も繰り返し、1000回に1回発生するバグの原因を特定 109
ストーリー by nagazou
地獄 部門より
地獄 部門より
Red Hat Linux開発者のリチャード・M・W・ジョーンズ氏は、Linux v6.4の起動時にハングアップするバグを発見し、原因特定のため29万2612回もLinuxを再起動して検証を実施したそうだ。彼はバグの原因を特定するためにさまざまな試行を実施したが、その結果、1000回に1回の割合で起動時にハングアップが生じることが判明したという（WM Jones、GIGAZINE）。
調査の結果、起動時の問題を引き起こしていたのは、カーネルコンソールにタイムスタンプを表示する「printk time」の変更だったとしている。同氏によるとLinux v6.0とv6.4-rc6を比較することで、ブート時のハングアップの原因を絞り込むことができたと述べている。なお、この起動バグはAMD製CPUよりもIntel製CPUのマシン環境のほうが発生頻度が低かったとしている。
あるAnonymous Coward 曰く、
調査の結果、起動時の問題を引き起こしていたのは、カーネルコンソールにタイムスタンプを表示する「printk time」の変更だったとしている。同氏によるとLinux v6.0とv6.4-rc6を比較することで、ブート時のハングアップの原因を絞り込むことができたと述べている。なお、この起動バグはAMD製CPUよりもIntel製CPUのマシン環境のほうが発生頻度が低かったとしている。
あるAnonymous Coward 曰く、
再現しにくいバグや、再現はするものの原因を特定するのが困難なバグを調べたことがあれば、話せる範囲で語ってもらえませんか？
どのように再現させたか、どういう風に原因を特定したのか、またはバグの解決に付随するトンデモエピソードがあれば、ぜひとも聞いてみたい。
現在劇場公開のアメコミ映画を2連チャンで観た後に、この記事タイトルを見た感想 (スコア:5, おもしろおかしい)
うん、知ってる、知ってる。
最近流行りのタイムループとかマルチバースってヤツでしょ？
Re: (スコア:0)
ヤンマガの「何度繰り返しても本能寺が燃えるんじゃが」でも
信長が上杉攻めを80万回だか繰り返したばかりだな
自動電源オンオフ (スコア:3, 興味深い)
組込やってると、たまに起動失敗するなんて日常茶飯事だから、自動で電源オンオフできるコンセントは常備してるよね。
0.1%の割合で失敗するならかなり高確率だ。週末回しておけばかなりの回数のログが取れるから、追跡も楽なほう。
Re:自動電源オンオフ (スコア:2, 参考になる)
とある組込プロセッサ・ボードで起動時にソフトウェア・ループによる時間待ちを使ったプログラムを書いたところ、時間待ちのところでLEDをパカパカ点滅させたら初期化に失敗するというトラブルに遭遇したことがある
やたらLEDの駆動電流が大きい回路定数になっていて、LED点滅によって発生した電源ラインのノイズが悪さをしていたらしい（LEDパカパカを止めたら直った）
＃秋月のキットでLEDの駆動電流がやたら大きいのは眩しくってかなわんので、もっと電流制限抵抗を大きくして欲しい
Re:自動電源オンオフ (スコア:1)
メモリの初期化忘れとかリセット回路etcのタイミングマージン辺りとか
# 展示会に間に合わないから起動時マニュアルリセット一回やってください
# なんて小細工をしたことがあるのはナイショ
殿堂入りネタ (スコア:3, 参考になる)
オカルトにだって頼っちゃうよ！ (スコア:3, おもしろおかしい)
by textoyx (29735)on 2006年02月09日 17時10分 (#880549) ホームページ 日記
バグの発見方法
* ソースリストプリントアウト
* 髪の毛にクリップを結びつける
* １ページずつ髪の毛の先にぶら下げたクリップをかざす
* 反応したページを抽出
* 一行ずつクリップをかざす
* 反応した行に注目
ええ、もちろん最終手段ですよ。もう、なにがなんだかワカラン！いっそ殺してくれ！オレを殺してくれ！ってなマトモじゃない精神状態ですよ。一回だけですよ！もうしませんよ！許してください…。
でも解決したよ(笑)
Re:殿堂入りネタ (スコア:1)
髪がない人はどうすればいいですか？ (´・ω・｀)
Re: (スコア:0)
髪がない人はどうすればいいですか？ (´・ω・｀)
新井智慧「髪はタヒんだ」
Re: (スコア:0)
そのために髪を一本抜いたのか、生えたままの貴重な髪の先にクリップつけて頭をソースリストに近づけたのか
Re: (スコア:0)
最初から「バグ退散」シールを貼っておけばそんなことしなくても良かったのに
モデの理由は (スコア:0)
参考になりました
バグの原因がわからない時は
試してみますってこと？
発生頻度低いとたいへん (スコア:2, 参考になる)
同じく linux カーネルで 5000台のサーバで、1週間に1回くらいのペースで起こるバグを調査したことあるけど、すごい大変だった。
Re: (スコア:0)
おれだったら宇宙線のせいにするかそういうもんだと諦めて運用でカバーする方法を探る
Re: (スコア:0)
何の徴候もなく死んでくれれば、ハード故障とか宇宙線とかのせいにもできたんだけどねー。
毎回場所が違うけど、どれも明らかにカーネルのバグっぽい死亡メッセージ出してから死ぬ。
当然ながらディストリビュータは「再現できない」で終わり。
運用スタッフでは対応できないので、詳しいやつ呼び出せってなって、深夜や休日でも週1のペースで呼び出される。
めんどうなやつ。
Re: (スコア:0)
むかーし昔、Linuxをインストールしたサーバを製造している場所で仕事をしていましたが、
保守契約があるお客様からそういう話があったら、dump がどこそこに出てるので提供してください。
bug があったので修正版カーネルを提供いたします。って個別にビルドして提供してたけど、最近は品質下がったのかなぁ
Re: (スコア:0)
自分も諦めそうなバグだなあ。
解決したような感じなのでどうやって糸口を見つけたのか聞いてみたい。
Re:発生頻度低いとたいへん (スコア:4, 興味深い)
1. 発生か所はバラついてるんだけど、発生か所や運用状況に基いて関係しそうなところ全部にログ出力や情報追加などを仕込んだ特殊カーネルを準備して全台を入れ換えて発生を待つ （ライブマイグレーションでタスクを一時的に別のサーバに逃がしてその間に再起動）
2. 発生したら、その時出力された情報を元にさらに場所を絞り込んで、カーネルを修正して入れ換えという地味な作業を繰り返す
3. 原因っぽいものが特定できたら、対策（したつもりの）カーネルを準備して半分だけ入れ換えて発生頻度を見る
4. 次に対策した半分を元に戻し、対策してなかった半分を対策したものに入れ換えて発生頻度を見る （ハードや実行タスクの影響の可能性を排除するため）
5. 対策版と未対策版に発生頻度に違いがあれば原因に近い何かであることが確定
（この時のはロックのレース・コンディションだった。ロックの場所じゃなくて、ずっと先のリソースのアクセス中でこけるので特定がやっかいなやつ。それも似たようなのが2個所あって、1か所の対策では頻度が減るだけで直らなかった）
まさに今戦ってるところ (スコア:1)
毎朝8時半～9時前後頃に、UNEXPECTED STORE EXCEPTIONでBSoDになる現象が発生中で
一体何が悪さをしているのかを特定してみたくて、格闘中。
UNEXPECTED STORE EXCEPTIONという事は、おそらくSSDの劣化が原因だとは思う。
サーマルスロットリング機能のついてない安物で、熱でやられっぱなしだったし。
もう新しいSSDも用意してある。
でもなぜ毎朝繰り返し発生するのか、なぜ昼や夕方や夜は何も起こらないのかを特定したくて
あえてこのまま運用中。
この時にどんなタスクが走っているのか、新しいSSDにした時は何に気を付けてやろうかと
知見を貯めたくて。
Re:まさに今戦ってるところ (スコア:1)
自分だったら温度計ひっ付けてログ取るけどなぁ。
あとは別なマシンにつけてみるとか。
切り分け大事。
Re: (スコア:0)
起動時間から何時間で死ぬかをチェック。
SSDのファームウェアのバグで電源投入から一定時間経過で死亡は稀にある。
近隣の工場の始業に伴う電源電圧の低下がトリガーの可能性とかもあるのでUPSの電源電圧ログを確認。
SATAなら電波も疑うかな。
Re: (スコア:0)
コンセントの電圧を調べてみては？
Re:まさに今戦ってるところ (スコア:1)
その時、掃除のおばちゃんが…
Re:まさに今戦ってるところ (スコア:1)
逆の例を聞いたことがあるな。
休日に工場の機器の多くが停止するので、電圧が上がって、UPS設定の上限電圧に引っかかってシャットダウンされる。
その後、上限電圧設定をイジって解消したらしい。
Re: (スコア:0)
Windowsが原因とは考えてないの？
奇妙な不具合はOSのインストールし直しで治る場合がある。
Re: (スコア:0)
起動時にアンチウイルスがフルスキャンしてて、熱で死亡って事？
解決した事例とかではないけど (スコア:1)
旅客機の整備やってると、
各座席の機内エンタメのモニターが毎日電源入れた時に起動失敗、
飛行中に宇宙線含め何らかの原因でハングアップ、
到着後に次の便の設定に切り替える時に失敗などなど
1機で300～400席近いモニターが50機とか、再起動で治るようなソフトエラーがあたかも頻発してるような件数で起きるから本当に困る
#再起動して駄目なら予備品と入れ替えてメーカー送りだから特に原因は気にしない
Re: (スコア:0)
それ、一斉起動による電圧低下が原因じゃないかな。
新品のうちはある程度の電圧低下に対応できるけど、電圧低下環境でのコンデンサー劣化が進行しまくって起動不能ってパターンじゃないかな。
Apacheが稀に落ちるバグ (スコア:1)
https://qiita.com/rana_kualu/items/c40fe2fb25a043a5dd12 [qiita.com]
Apache2.4.26より前のauth_digest_moduleにあるバグのせいで、稀にApacheが落ちる。
稀っていうかこれまで一回しか遭ったことないけど。
原因まで調べた日本人は私しかいないと思われる。
一番ありそうなのは (スコア:0)
メモリー不良ですかね
散々ぱら調べて特定できずにまさか、、、とメモテスかけたら真っ赤かでorzみたいな
で，具体的な原因は書いてくれないのね (スコア:0)
printk timeのリグレッション(デグレ)とはあるけど。
デグレの内容が欠落してるのは和田となのかねぇ
Re:で，具体的な原因は書いてくれないのね (スコア:2, 参考になる)
printk("これを入れるとなぜか動く") を取り除いたのが原因。
マジレスすると、ひとつ前のcommitに戻すと動くけど、理由はわからんとのこと。
https://lkml.org/lkml/2023/6/13/733 [lkml.org]
Re:で，具体的な原因は書いてくれないのね (スコア:1)
tick カウンタ関係で、jiffies を初期化する時に TICK_NSEC の整数倍に調整してなかったから、と読んだけど。
なんでレアケースなのかまでは判らんかった。
Re: (スコア:0)
割り込み関係の待ち合わせ的な何かなんですかね。
別クロックで駆動している何かの割り込みとかだと
決定論的に動かないから厄介ですよね。
# クロックが逆相になっててマージン不足で時々こけるってのは
# あった。ブートロムのバグで後でエラッタが出た。
Re:で，具体的な原因は書いてくれないのね (スコア:2, 興味深い)
雑に言うと
・カーネル起動後しばらくはタイマ関連はピリオディック・モードで動いている
・このモードでは定期的にイベントが呼び出されるのだけど
・何が作業した時に、次のイベントまでの残り時間が短か過ぎると
・経過時間を差し引くと残り時間がマイナスになって、永久に戻って来なくなる
・起動後しばらく経つとワン・ショットモードに移行するので、この問題は起きなくなる
Re: (スコア:0)
にゃるほど。ベアメタルだと起動時のCPUリソースは安定してるので出にくそうではあるね。
Re: (スコア:0)
スラドは、技術系サイトではないからね。
クラウド業者ならよくあるのでは？ (スコア:0)
1000回に1回も失敗するなら、クラウド業者や、大量サーバ運用者は、かなりの頻度でぶつかるのでは？
Re:クラウド業者ならよくあるのでは？ (スコア:4, おもしろおかしい)
もちろん定期的にエラーログをメーカーに上げては再現性無しで送り返されてくるまでが様式美だぞ。
ある一定の条件と環境が揃わない限りは発生しないから「稀に良くある」「判明する頃にはもう使ってない」となる。
Re:クラウド業者ならよくあるのでは？ (スコア:1)
ああ耳が痛いw
レッツ自動化 (スコア:0)
社内でRPAソフトのライセンスが余ってたので使わせてもらって、ひたすら試験をやらせた。
RPAソフトのメモリリークと、セキュリティソフトのメモリリークが観測できた。
問題の事象は数万回のテストで2回か3回しか再現せず、「発生はするけど原因わかんね」で終わった。
# 前者は修正され、後者は絶賛放置中
すべてがFになる系 (スコア:0)
カウンタが一巡して起動から一定期間後にハングする不具合
カウンタがもうすぐ一巡するぐらいから始めて、いい感じで特定操作を行って再現確認
とかしてたなぁ……
Re: (スコア:0)
カウンタあふれは大抵鬼門ですね。
WindowsNTや2000や7を497日以上連続稼動したときや
Windows95や10を49.7日以上連続稼動したときに問題が出てました。
Re: (スコア:0)
あれ？弊社のルータのカードが１４００日くらいでハングするバグがあってメーカは対処しないことにしたんじゃなかったかな。そろそろ前回のハングアップから同じくらい経っていそう。明日出社したら確認してみるかな。ｓｈｕｔ→ｎｏ ｓｈｕｔで済むんだったかなーとかドキュメント探しから始めないと……
ソフトウェアのバグと認識できるのがすごい (スコア:0)
一度遭遇してから次に遭遇するのが1000回後のブート失敗なんて、さっき何か悪い事したかなぐらいでスルーしちゃうな。
そう動くにはそう動く原因があるのは確かだけどさ…
# 今使ってるPCは今まで何回ブートしただろう
原因はわからなかったが (スコア:0)
ガラケー時代に某社の端末がアプリ実行中に二百数十回通信を行うと以降通信を行わなくなる現象に遭遇。
何故か現地で死ぬ (スコア:0)
クラッシュダンプを取得できるので、再現性はそこまで悪くないから相応しくないかも。
ここの人ならよく遭遇してる事例として、テストして問題ないとしてリリースしたはずなのに現場でクラッシュ。
原因は、
ダンブ取得して逆アセンブルを追っかけたらコンパイラのバグが原因で稀に死ぬ。
CPUのエラッタで稀に死ぬ。
アンチウイルスが原因ハンドルやメモリや通信内容が稀に破壊される。
稀なおま環で、HDDの不良セクターが原因でAPIコールに失敗して止まる。
メモリ不良(宇宙線の可能性あり)で死ぬ。
ストレステストを1日走らせて出るか出ないかのバグ (スコア:0)
カーネルクラッシュしたメモリダンプを調べてみたところ意図しないメモリが破壊されてクラッシュがおきていたが、誰がメモリを壊していたのかわからず悩みまくった。結局は別の人が手掛けていたディスクドライバが原因で脱力。
トンデモエピソード？ (スコア:0)
過去に自分が担当していた所でのバグが発生したと言われ、現場での緊急対応が必要だからと特殊な開発環境を大きな段ボール箱につめ二人がかりで運び半日かけて移動したことがあります。先行調査していた人たちと深夜近くに合流して伝えられたのは原因はハードウェア臭いというオチ。
初めて遭遇したPCのCPU不具合 (スコア:0)
数年前、なんかPCの動作が重いなぁと思ってパフォーマンスモニターで調べたら、ほぼアイドリング状態なのに割り込みが10万回/秒もあって驚いたことがあった。再起動してみると数千回/秒に戻るんだけど、その後もたまに割り込み頻度が増えたりしていたので、何がきっかけで割り込みが増えるのかを調べたことがあった。
調べた結果、CPU直経由のUSBに取り付けた外付け光学ドライブの電源スイッチを入れた時に発生することが分かった（チップセット経由のUSBでは起こらなかった。）のだけれども、たどり着くのにちょっと苦労した。
パフォーマンスモニターのデータコレクターセットとタスクスケジューラ、PowerShellスクリプトを組み合わせて、割り込み頻度が閾値を超えたらトースト通知するような仕組みを作って様子見してた。（データコレクタセットの使い方とかPowerShellスクリプトでWindowsのAPIを使う方法とか色々と勉強になった。）
何週間か経過して、あまり使わなくなっていた光学ドライブの電源スイッチを入れた後、視線をディスプレイに戻すと通知が出ていて、思わず「出たー！」と声を出してしまったw。
Windows Performance Analyzerとやらを使って調べてみたが、ACPI.sysが割り込みを発生させていることが分かったくらい。プラグアンドプレイ周りのデバイスの検知や電源状態遷移に問題があったのかな？
その後、光学ドライブはチップセット経由のUSBの方に接続してやり過ごしたけれど、元々CPUの調子が悪くて（月一くらいでBSoDしてた）、1年と何か月かでCPUを新しいのに換えた。（使ってたのはSEGV問題とかあった初代Zen。たまたま某タイムセールで見付けたZen+世代にしたら安寧を得られた。）
リセマラ (スコア:0)
29万回もやる根気があれば、どんなゲームでも目当てのアイテムを手に入れられる？