piu lentoの日々 (piu lento days)

少し前に、Spotifyアプリがメモリを消費し過ぎることの弊害を緩和できないかと思って、それまで無効にしていたスワップを有効にしてみた。ところが、その後くらいから、Thunderbirdが2日くらいでハングし、Thunderbirdのプロセスをkillすることもできず、OSをrebootしようとしてもエラーでハングしてしまってリセットするしかなくなる問題が多発した。その時、dmesgやreboot時のコンソールには、以下で始まるエラーが出ていた。

[149418.786180] BUG: unable to handle kernel NULL pointer 
dereference at 0000000000000010

どういう訳かは分からないが、スワップを有効にしたのが悪かったように感じたので、無効にして試しているのだが、一週間経っても問題が起こっていないので、やはり、スワップが原因だったようだ。

ただ、Linuxでスワップが良くないことは信じられない。考えられるのは、スワップ領域を初期化せずに有効にしたためかと思う。その他には、起動時のdmesgに、以下のような警告があったのが気になっている。

[ 11.107687] nct6775: Found NCT6776D/F or compatible chip at 
0x2e:0x290
[ 11.107694] ACPI Warning: SystemIO range 0x0000000000000295-
0x0000000000000296 conflicts with OpRegion 0x0000000000000290-
0x0000000000000299 (\_GPE.HWRE) (20150930/utaddress-254)
[ 11.107699] ACPI: This conflict may cause random problems and 
system instability
[ 11.107701] ACPI: If an ACPI driver is available for this device, 
you should use it instead of the native driver

これは以前からもあったのだが、スワップが有効だと問題が起こるのかも知れない。警告から、センサーチップNCT6776Dとグラフィック(Intel内蔵)のアドレスが重複していると思われるので、次回問題が起こったら、BIOS設定でグラフィックのアドレスを狭められれば、試してみたい。無理なら、検索して見つかった対処の、カーネルの起動パラメタにprocessor.nocst=1を追加することを試してみたい(ただ、それで別の問題が起こらないかという心配はある)。

いずれにしても、今のところ問題は起こっていないので、このまま行けそうな気がする。もしスワップを有効にする時は、このことを思い出したい。

↓

(11/16 3:47) 昨日、再びThunderbirdがハングした。今度は約12日間動作していた。スワップをonにすると問題が起こりやすくなるようだが、直接的な原因でなさそうだ。そこで、上記の対処を試そうとしたのだが、Intel内蔵グラフィックのアドレスは変更できず、カーネルの起動パラメタprocessor.nocst=1も設定しても同じACPIの警告が出たので、効果がなかった。

それで、ACPIのアドレス重複を解消できるかと、別のカーネル起動パラメタacpi_enforce_resources=laxを止め、センサのドライバnct6775も止めてみたのだが、アドレス重複は解決できなかった。そもそも、acpi_enforce_resources=laxとnct6775ドライバは1年以上前から使っていて、近頃まで問題がなかったので、今回の原因ではなさそうだ。また、別のセンサのドライバasus_atk0110を試したが、うまく動かなかった(センサの値が取得できなかった)。

更にログを調べたところ、Thunderbirdのハングの直前のスリープからの復帰の数分後に、snap関連のメッセージの直後にカーネルのエラーが起こっていた。以下に、その時のログを示す。

Nov 15 23:57:33 localhost snapd[1285]: storehelpers.go:398: 
cannot refresh snap "core": snap has no updates available
(略)
Nov 15 23:57:40 localhost systemd[1]: Mounting Mount unit for 
spotify, revision 26...
Nov 15 23:57:40 localhost kernel: [758674.540346] BUG: unable 
to handle kernel NULL pointer dereference at 0000000000000010

snapdは、Spotifyアプリをsnap版にするために使っているのだが、snapとカーネルの相性が悪いことが考えられる。それで、今度はSpotifyアプリをsnapでない版に戻して様子を見ることにした。また、問題を起こりやすくするため、スワップをonにしてみる。

↓

(11/27 19:19) その後はThunderbirdのハングやカーネルのBUGは起こらず、Spotifyアプリを後の投稿に書いたように、snapから取り出した版にし、snapの機能・サービスを使わずに使っていた(関係なさそうなので、スワップはoffに戻した)。それでも問題が起こらなかったので、現象はsnapとスリープに関係しているようだ。今推測しているのは、以下のようなことである。

1. スリープ(サスペンド)からの復帰時、少しの間、LANが正常に動作しない時間(1-2分)がある。
2. その時にsnapがマウント処理(上のログの23:57:40、2行目)を行うと、カーネルのBUG(同3行目)が発生する。
3. そうなると、どういう訳かThunderbirdもハングする。

その推測に基づき、1番の問題に対処するため、スリープからの復帰時にLAN IFを一時停止する処理を追加して、再度snap版のSpotifyアプリを使うことにした。LANの一時停止処理の間はスリープからの復帰処理が終わらないので、snapのマウント処理も行われないはずである。以下に、LANの一時停止処理の流れを示す。この処理は、スリープなどの前後に実行されるスクリプト(/etc/pm/sleep.d/89name)に格納している。

• スリープや休止からの復帰時(resumeまたはthaw)に以下を実行する。
  1. LAN IFを停止(nmcli device disconnect IF名)する。
  2. 少し(1秒)待つ。
  3. LAN IFを起動(nmcli device connect IF名)する。
  4. 少し(1秒)待つ。

この処理は、以前別の問題(NW通信不調)が起こったために追加したのだが、近頃は問題が起こらなくなったようなので無効にしていた。別のルータを使っていた時は起こらなかったので、ルータとNICやドライバやOSの相性が悪いようだ。

(11/28 15:33追記) シャットダウン時にハングアップした時にコンソールに出たカーネルのエラーメッセージの最後辺りの文字列("propagate_one+0xbe/0x1c0")で検索したところ、これはカーネルの既知の問題(2016-04-19)のようだ。問題が起こる契機は異なるが、メッセージは同じだ。

シャットダウン時にハングした時のカーネルのエラーメッセージ

また、メッセージ中に"do_mount"とあるので、昨日の推測どおりsnapのマウント処理が契機になって発生すると考えられる。

修正版を探したところ、カーネル4.4.0-23.41で修正されているのだが、使っているLinux Mint(正確にはUbuntu)のパッケージはなかった。ベースはUbuntuのLTSのため、対応する問題が限られているのではないかと推測する。この問題を修正するには、おそらく最新のLinux Mint 19にするしかなさそうだが、来年に予定しているので、それまでは昨日記した対処(スリープからの復帰時にLAN IFを一時停止する)で様子を見ることにする。

↓

(11/29 2:40) アップデートマネージャの設定を見直し、"Always show kernel updates"をonにしたら、更新版カーネル(4.4.0-139.165)のパッケージが表示され、その履歴に本問題の修正も含まれていたので適用した。おそらくこの問題は解消すると思われるが、元々ルータとNICやドライバやOSの相性から、以前に起こっていた問題は起こりそうなので、スリープからの復帰時にLAN IFを一時停止する処理は有効にし続ける。

(11/16 3:47 題を若干変更)

(仕事ブログより転載・一部表記を修正、題を若干変更: 元の投稿日時: 2018/11/10 17:39)