読者です 読者をやめる 読者になる 読者になる

コーディング練習: holeを意識したコピー

昨日に引き続きプログラミングの練習。網羅性とサイズの大きさで有名な次の本の演習のひとつを扱いました。

作るのはファイルをコピーするだけのプログラムです。もとのファイルにholeがあれば、コピー先ファイルにもholeを作る必要があります(ヌルバイトの連続によってストレージ領域を消費してはいけない)。

web上には次のような回答例がありました。

github.com

目的のプログラムを作る場合には通常lseek()のwhence引数にSEEK_HOLEとSEEK_DATAを指定することによってholeのありかを検出します(ここには書きませんがioctl()でも同様のことができます)。しかし、上記プログラムの作者の環境はこれらが使えないカーネルバージョンだったらしく、この方法を使わない単純な実装になっていました。連続するヌル文字を見つけたら、それらをただ書き込むのではなく、lseek()によって飛ばしてしまおうというものです。これは一見うまくいきそうですが、次のような問題があります。

  • もともとわざとヌル文字で埋めていたブロックもholeになってしまう
  • hole部分をフルスキャンする必要があるため、コピー所要時間が長くなる
  • ファイル末尾に連続するNULL文字あるいはholeがあった場合は、その部分がコピーされない。それら領域をlseek()によって飛ばした後に0バイトwrite()する(つまり実質何もしない)だけでファイルサイズを正しいものに更新しないため、ファイルサイズがコピー元ファイルより短くなってしまう

実際、次に示す簡単なテスト(ファイル内の色々な箇所にholeが空いているファイルをコピー)のほとんどに失敗しました。

github.com

その一方で、私の実装は次の通りです(上記プログラムは見ずに作ってます)。

github.com

このプログラムは、次のような特徴があります。

  • lseek()におけるSEEK_HOLEとSEEK_DATAを使っている。データ領域をコピーする処理と、その後に続くholeを飛ばす処理の繰り返しです。
  • エラー処理のためにgotoを用いている。gotoを見るのも嫌というかたがたもいると思いますが、こういうケースではgotoを使わないほうがむしろコードが見にくくなると私は考えています

こちらは前述のテストをすべてパスしました。ほかの観点でテストをしたらまだバグは潜んでいると思いますが、ひとまずは合格です。

コーディング練習: 人の書いたプログラムを自分の方法で書き直す

web上で、とある凄腕エンジニアのかたが実装した簡単なプログラミング言語の実装と、その様子を紹介したビデオを見つけました。

gist.github.com

www.youtube.com

思うところあって、プログラムの仕様をできるだけ変えないまま、自分なりに書き直す練習をしたかったので、ちょうどいい小さな規模のこのプログラムで実践してみました。

gist.github.com

仕様を変えないまま…とは言っても仕様が文書なりで明確化されていたわけではないので、ソースから著者の意図を推測しただけです。一から書き直すという方法もありますが、今回は既存のソースを改編するという方法をとりました。

変更点は次の通り。

  • 仕様っぽいもの(すごく柔らかい、お金を取るプロダクトの仕様書として出したら殴られるレベルのもの。ここではこれでいいんです)をソース冒頭に書いた
  • 関数名、変数名(とくにグローバル変数)は何をしているものなのかをわかりやすくした
  • エラーチェックの追加: 引数の数、バッファオーバーランなど
  • print機能(P()関数)による出力と、トップレベルの文を評価した際の出力を区別できるようにした
  • 雑多なバグ修正

もう少しこだわると、コードへのポインタはグローバル変数ではなく関数引数にしたかったんですが、無用にややこしくするだけになる恐れがあったので、やめました。

可読性においては初級者には見やすくなっていると思います。その一方で、上級者にとっては冗長に見えるかと思います。それらはオリジナルソースの作者と私の好みの違い、および、ソースをどれだけ気合を入れて書いたかの違いでしょう。「俺だったらここはこうするね」という意見も多々あろうかと思います。色々な人が同じことをした場合のソースを並べて見てみたいものです。

この試みはけっこう面白かったので、他のソースでもやってみようかと思います。オレオレプログラムを書く場合とは異なる脳の部位を使っている気がします。

ノートPCに仕込まれていたキーロガーを削除した

三日前にこんなニュースが飛び込んできました。

thehackernews.com

で、私が最近買ったPCはHP製品です。

satoru-takeuchi.hatenablog.com

該当PCの一覧にもありました。あーあ。

https://www.modzero.ch/advisories/MZ-17-01-Conexant-Keylogger.txt

こんなのを仕込まれていてはたまらないので、問題となる実行ファイルを削除しました。ログファイル(c:/Users/Public/MicTray.log)にパスワードを含む打鍵履歴が山盛り記録されていて肝を冷やしたかったのですが、残念ながら当該ファイルは空であり、かつ、変更日時はOSインストール時とおもわしきものでした。私のPCにインストールされているバージョンのドライバではロギングしていないのか、あるいはログファイルはスーパーハカーの手によって変更履歴が改竄されているのかは知らないです。

ただこの話は、迷惑かついい気分がしないのは確かなんですが、

  • ログを".log"というわかりやすい拡張子のファイルに保存している
  • ドライバ自身からはネットワーク転送していないらしい
  • 全ユーザにファイルが読める

という隠す気ゼロのしょっぱい作りなあたり、わざとでなく本当に「やっちゃった」だけなのでは?というのは感じます(後付けで何を言っても真意は作者にしかわかりませんが…)。

5/14に落ちてきたWindows Update “Conexant - MEDIA - 5/14/2017 12:00:00 AM - 9.0.134.1"によって、問題のログファイルは消され、かつそれを作っていると思わしき実行ファイルは更新されていたので、これが修正なのでしょう。こういうのは黙って直すだけではなく、HPからなんらかのアナウンスが欲しいところです。がっかり。

Ryzen上でlinuxカーネルをテストしようとしたら問題が出た(未解決)

最近Ryzenを積んだデスクトップマシンを買いました。その上でカーネルビルド&テストをしようとしたんですが、2点問題が発生しました。先代のCore i5を積んだマシンでは起きなかった現象です。

NOTE: このエントリはメモがてら、随時更新していきます。落ち着いたらどこかにまとめるかも。

問題1: linux カーネルのビルドには成功するが、ビルドしたカーネルをguest上でブートしたら起動中に死ぬ(原因判明、修正待ち)

ブート時のカーネルのログはこんなかんじ。

...
[    0.227720] raid6: sse2x1   gen()  7985 MB/s
[    0.295709] raid6: sse2x1   xor()  8181 MB/s
[    0.363706] raid6: sse2x2   gen() 17531 MB/s
[    0.431699] raid6: sse2x2   xor() 11098 MB/s
[    0.499693] raid6: sse2x4   gen() 18509 MB/s
[    0.567688] raid6: sse2x4   xor() 10177 MB/s
[    0.571692] invalid opcode: 0000 [#1] SMP
[    0.572312] Modules linked in:
[    0.572822] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.11.0-rc8-ktest #1
[    0.573734] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014
[    0.575040] task: ffff8f791e1c0000 task.stack: ffff9c72c00d0000
[    0.575865] RIP: 0010:raid6_avx21_gen_syndrome+0x3d/0x120
[    0.576634] RSP: 0018:ffff9c72c00d3d70 EFLAGS: 00010246
[    0.577376] RAX: 0000000000000000 RBX: ffff9c72c00d3dc0 RCX: 00000000fffedb97
[    0.578327] RDX: 0000000000000000 RSI: 0000000000001000 RDI: 0000000000000012
[    0.579283] RBP: ffff9c72c00d3da0 R08: 0000000000000000 R09: 00000000000000cd
[    0.580243] R10: 00000000fffedb86 R11: ffffffffa617008d R12: 0000000000001000
[    0.581211] R13: ffff8f791e39e000 R14: ffff8f791e39f000 R15: 0000000000000012
[    0.582163] FS:  0000000000000000(0000) GS:ffff8f791fc00000(0000) knlGS:0000000000000000
[    0.583324] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    0.584128] CR2: 0000000000000000 CR3: 000000001be09000 CR4: 00000000003006f0
[    0.585078] Call Trace:
[    0.594952]  raid6_select_algo+0x116/0x30b
[    0.595592]  ? libcrc32c_mod_init+0x2b/0x2b
[    0.596240]  do_one_initcall+0x53/0x1a0
[    0.596843]  ? parse_args+0x2cf/0x490
[    0.597421]  kernel_init_freeable+0x182/0x21c
[    0.598077]  ? rest_init+0x80/0x80
[    0.598626]  kernel_init+0xe/0x100
[    0.599175]  ret_from_fork+0x2c/0x40
[    0.599741] Code: 55 41 54 53 48 89 d3 48 8d 14 c5 00 00 00 00 41 89 ff 49 89 f4 48 83 ec 08 4c 8b 2c c3 4c 8b 74 13 08 48 89 55 d0 e8 53 ed a9 ff <c5> fd 6f 05 2b 2d 4e 00 c5 e5 ef db 4d 85 e4 48 8b 55 d0 0f 84
[    0.602215] RIP: raid6_avx21_gen_syndrome+0x3d/0x120 RSP: ffff9c72c00d3d70
[    0.603154] ---[ end trace 17ee01f86b8fc548 ]---
[    0.603850] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[    0.603850]
[    0.605276] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
...

AVX2命令の実行中に不正な命令を発行したとしてパニックしています。RyzenではAVX2命令が使えるはずだし、AMDのマニュアルを見ると仮想化環境では使えないとか書いてないように見えるし(隅から隅まで読んだわけではないので間違ってるかも)、なんかおかしい。次のようなダーティハックでとりあえずブートできるようにはなった。as-instrが何をするものなのかは知りません。

]diff --git a/arch/x86/Makefile b/arch/x86/Makefile
index 2d44933..b589097 100644
--- a/arch/x86/Makefile
+++ b/arch/x86/Makefile
@@ -162,7 +162,7 @@ asinstr := $(call as-instr,fxsaveq (%rax),-DCONFIG_AS_FXSAVEQ=1)
 asinstr += $(call as-instr,pshufb %xmm0$(comma)%xmm0,-DCONFIG_AS_SSSE3=1)
 asinstr += $(call as-instr,crc32l %eax$(comma)%eax,-DCONFIG_AS_CRC32=1)
 avx_instr := $(call as-instr,vxorps %ymm0$(comma)%ymm1$(comma)%ymm2,-DCONFIG_AS_AVX=1)
-avx2_instr :=$(call as-instr,vpbroadcastb %xmm0$(comma)%ymm1,-DCONFIG_AS_AVX2=1)
+#avx2_instr :=$(call as-instr,vpbroadcastb %xmm0$(comma)%ymm1,-DCONFIG_AS_AVX2=1)
 avx512_instr :=$(call as-instr,vpmovm2b %k1$(comma)%zmm5,-DCONFIG_AS_AVX512=1)
 sha1_ni_instr :=$(call as-instr,sha1msg1 %xmm0$(comma)%xmm1,-DCONFIG_AS_SHA1_NI=1)
 sha256_ni_instr :=$(call as-instr,sha256msg1 %xmm0$(comma)%xmm1,-DCONFIG_AS_SHA256_NI=1)

とりえあずは問題を整理してバグ報告しました。

LKML: Satoru Takeuchi: [BUG] x86: failed to boot a kernel on a Ryzen machine

幸いにもBorislav Petkovさん(linuxカーネルのいろんなコンポのメンテナ)からレスをいただき、彼のの環境で再現もできました。かつ、AMDRyzen Engineering Teamにも転送されたようです。

その後Masami Hiramatsuさん(kprobesのメンテナ)から、VMに見えているCPUのモデルと機能フラグの組み合わせの問題では、という指摘を受けました。

www.spinics.net

自分の環境ではlibvirtを使ってVMを管理しています。CPUのモデルはhostと同じもの(host-model)になるよう設定しているのですが、今のlibvirtではそれが実際には古いOpteron_G3に設定されます。これを、CPUのモデルをOpteron_G5にして、かつ、Ryzenがサポートしない機能(fma4, tbm, およびXOP)のフラグを落としたところ、無事上記カーネルで起動成功しました。

その後さらにPaolo Bonziniさん(KVMのメンテナかつqemu開発者)に、新しいCPUではこういうことがよくあること、およびmodeを"host-passthrough"にするように言われ、その通りにするとパニックしなくなりました。これでqemuのCPU modelにRyzen(あるいはZen)を追加してもらえれば完了なはずです。

問題2: linuxカーネルのビルド中に gcc が SEGV で死ぬ(原因不明、調査中)

/home/sat/src/elkdat/linux/block/partition-generic.c: In function 'part_alignment_offset_show':
/home/sat/src/elkdat/linux/block/partition-generic.c:103:1: internal compiler error: Segmentation fault
 }
 ^
Please submit a full bug report,
with preprocessed source if appropriate.
See <file:///usr/share/doc/gcc-5/README.Bugs> for instructions.
/home/sat/src/elkdat/linux/scripts/Makefile.build:294: recipe for target 'block/partition-generic.o' failed
make[2]: *** [block/partition-generic.o] Error 1

カーネルを10回連続でビルドしたら、7回成功して3回はsegmentation faultで死にました。死んだ場所はそれぞれ全然違うところです。このため、gccに関する問題というよりも、CPUやメモリなどのハードの問題に見えます。Gentoo Forumでも類似の報告がありました。

Gentoo Forums :: View topic - Segfaults during compilation on AMD Ryzen.

とりあえず自分の環境でも再現したことを同フォーラムに報告しましたが、Ubuntuの話をしたことが気にくわなかったらしい人に怒られて、投稿が削除されてしまいました。とりあえずGentoo Forumは今後ROMるだけにすると決めました。

最新カーネル(4.12-rc1)にアップデートした上で再現テストをすると、問題は依然残っていることがわかりました。この他に、こうすれば直った/回避できたという情報が錯綜していますが、私の環境ではどれも効果無しでした。

現在はAMDのサポートに問題を報告した上で、やりとり中です。当初はプライベートなサポートチケットを発行したのですが、応答が極端に鈍くてまともに調査してるか、そもそも問題として認識しているのかどうかもわからないような状況だったので困っていました。再度web上を調査したところ、問題認識当初は無かった、同じ問題についての報告する次のようなスレッドがサポートフォーラムにできていることがわかりました。

community.amd.com

ここで「AMDはこの問題をハンドルしてるのか、および、できれば進捗を教えてほしい。できれば公開で」と言うと、公式から「調査中である。進捗があったらここで報告する」という回答を得ました。どうやら問題そのものが無視/黙殺されている最悪のケースは回避できたようなので安心しました。

オフライン状態においてWSLでemacsやsudoが起動中に固まる(解決済)

結論

WSLを使うときは次のように/etc/hostsにマシンのホスト名を書くべし。

127.0.0.1 localhost puffy         # puffyは私のwindowsマシン名

そうしないとemacs, sudoなどの、実行時にホスト名を解決しようとするソフトが固まる

問題の認識

数日前に買ったノートPCでWSLをしばらく快適に使っていたのですが、emacsが起動中に固まって動かなくなる問題がさきほど発生しました。その後sudoにも同じ問題が起きることがわかりました。つい数十分前には正しく使えており、かつ、その後Windows Updateはしていないし、設定変更もしていないので、これはおかしいです。

トラブルシューティング

最後に問題が発生していなかった時点(今朝9時ごろ)と問題発生を確認した時点(9時30分ごろ)の差分をしばらく考えてみたところ、前者はオンライン環境であり、後者はオフライン環境だったことを思い出しました。ネットワーク環境に関係あるのかを確認するために、オンラインにしてから同じ操作をすると、問題は発生しませんでした。ここで一つ「ネットワーク関係の疑いが強い」という切り分けに成功。

デバッグのためにstrace -o emacs.log emacsを実行すると、次のように/etc/resolv.confをopen(2)したり、uname(2)コマンドでホスト名を取ったりした後に発行した複数回のsenddmsg()にそれぞれ10秒前後時間がかかっていることがわかりました。

emacs.log

...
1492485708.123190 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=189, ...}) = 0
1492485708.123497 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 3
1492485708.123952 fstat(3, {st_mode=S_IFREG|0644, st_size=189, ...}) = 0
1492485708.124115 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa4fe940000
1492485708.124295 read(3, "# This file was automatically ge"..., 4096) = 189
1492485708.124478 read(3, "", 4096)     = 0
1492485708.124648 close(3)              = 0
1492485708.124820 munmap(0x7fa4fe940000, 4096) = 0
1492485708.124986 uname({sys="Linux", node="puffy", ...}) = 0
1492485708.125249 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3
1492485708.125475 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.43.1")}, 16) = 0
1492485708.125710 gettimeofday({1492485708, 125750}, NULL) = 0
1492485708.125859 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
1492485708.126111 sendmmsg(3, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2
3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2
1492485714.097840 poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout)
1492485719.099159 socket(PF_INET6, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4
1492485719.099929 connect(4, {sa_family=AF_INET6, sin6_port=htons(53), inet_pton(AF_INET6, "fec0:0:0:ffff::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
1492485719.100742 gettimeofday({1492485719, 100932}, NULL) = 0
1492485719.101843 poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
1492485719.103170 sendmmsg(4, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2
3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2
1492485731.096900 poll([{fd=4, events=POLLIN}], 1, 3000) = 0 (Timeout)
1492485734.098345 socket(PF_INET6, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 5
1492485734.099193 connect(5, {sa_family=AF_INET6, sin6_port=htons(53), inet_pton(AF_INET6, "fec0:0:0:ffff::2", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
1492485734.099969 gettimeofday({1492485734, 100273}, NULL) = 0
1492485734.101202 poll([{fd=5, events=POLLOUT}], 1, 0) = 1 ([{fd=5, revents=POLLOUT}])
1492485734.102447 sendmmsg(5, {{{msg_name(0)=NULL, msg_iov(1)=[{"t\246\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\1\0\1", 23}], msg_controllen=0, msg_flags=0}, 23}, {{msg_name(0)=NULL, msg_iov(1)=[{"_\200\1\0\0\1\0\0\0\0\0\0\5puffy\0\0\34\0\1", 2
3}], msg_controllen=0, msg_flags=0}, 23}}, 2, MSG_NOSIGNAL) = 2
1492485746.097900 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
1492485746.098406 rt_sigaction(SIGINT, {SIG_DFL, [INT], SA_RESTORER|SA_RESTART, 0x7fa4fc946cb0}, {0x4a6200, ~[RTMIN RT_1], SA_RESTORER, 0x7fa4fd000330}, 8) = 0
1492485746.099849 getpgrp()             = 139
1492485746.100944 ioctl(0, TIOCGPGRP, [139]) = 0
1492485746.102129 rt_sigprocmask(SIG_BLOCK, [WINCH IO], NULL, 8) = 0
1492485746.103238 rt_sigaction(SIGIO, {SIG_IGN, [IO], SA_RESTORER|SA_RESTART, 0x7fa4fc946cb0}, {SIG_DFL, [], SA_RESTORER, 0x7f161b466cb0}, 8) = 0
1492485746.104837 exit_group(2)         = ?
1492485746.105671 +++ exited with 2 +++

resolv.confの読み出しもuname(2)の発行もホスト名に関するものであり、かつ、sendmmsg()によって送信したメッセージの中にもホスト名を示す文字列(“puffy”)が入っていたので、問題はホスト名の解決に関するものかなと推測しました。

hostnameコマンドは一瞬で"puffy"を返すので問題ないとして、/etc/hostsはどうなっているかを見ると、127.0.0.1puffyは結び付けられていませんでした。

/etc/hosts

...
127.0.0.1 localhost
...

これを次のように変更したらオフラインでもうまく動くようになりました。

/etc/hosts

...
127.0.0.1 localhost puffy
...

Windows 10 Creators Updateを適用したらmoshが動くようになった

2, 3日前にWSL上でmoshを動かしたところ、ログインした瞬間にプロセスが終了してしまうという問題が発生しました。ぐぐったところ、既知の問題でした。

github.com

上記Issueを追ってみると、Creators Updateを適用すると直るとのことなので早速適用してみると、うまく動きました。やったぜ。

Windows UpdateによってSIMの通信規制された&対策をとった

最近、数年ぶりにWindows PCを買いました。モバイルノートなので、どれくらいバッテリが持つものなのかを試すために、外出先でテザリングによって通信しながらバッテリが切れるまで作業しました。すると、ある時点から通信が極端に遅くなってしまいました。なぜかと思ってスマホの通信量を確認すると、案の定、一日あたりの通信規制にひっかかる通信量を超えていました。あーあ。

きっとWindows Updateの自動ダウンロードの仕業だろうと思って、Windows Updateの設定から自動ダウンロードを無効化しようとするも、そういう設定はありませんでした。但し書きを見たところ、

利用可能な更新プログラムが自動的にダウンロードされ、インストールされます。従量制課金接続(料金が発生する場合があります)では実行されません。

と書いてありましたが、どうやって従量制課金接続かどうかを判定しているのかは不明でした。

調べた結果、wifiの設定の中でアクセスポイントごとに従量制課金接続かどうかを設定できるようです。具体的には次の設定項目です。

設定 → ネットワークとインターネット → wifi → <AP名> → 従量課金制接続として設定する

これを設定したら通信量の急激な増加が収まったので、おそらくWindows Updateが原因という仮説も正しかったのでしょう。