Plan 9とGo言語のブログ

主にPlan 9やGo言語の日々気づいたことを書きます。

I/O errorでユーザーにログインできなくなった

Linux

普段使っているユーザーでLinuxデスクトップにログインできなくなった。正しいパスワードを入力すると画面が1秒程度切り変わるけど、すぐディスプレイマネージャのログイン画面に戻ってしまう状態だった。

エラーの内容を調べる

rootではログインできたので、Ctl+Alt+F4などでディスプレイマネージャからコンソールに切り替えて、ログインできなくなった原因を調べる。問題のユーザーはsystemd-homedでLUKSイメージを使った環境だったので、activateしてみるとI/Oエラーが出力された。

# homectl activate lufia
[  152.810994] loop0: detected capacity change from 0 to 764010613
[  152.812280] blk_update_request: I/O error, dev loop0, sector 764010608 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[  152.812446] blk_update_request: I/O error, dev loop0, sector 764010608 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[  152.812554] Buffer I/O error on dev loop0, logical block 95501326, async page read
[  152.813969] blk_update_request: I/O error, dev loop0, sector 764010608 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[  152.814210] Buffer I/O error on dev loop0, logical block 95501326, async page read
[  152.815182] blk_update_request: I/O error, dev loop0, sector 764010608 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[  152.815344] Buffer I/O error on dev loop0, logical block 95501326, async page read
[  153.564587] device-mapper: table: 254:0: len=763977845 not aligned to h/w logical block size 4096 of loop0
[  153.564591] device-mapper: core: Cannot calculate initial queue limits
[  153.564716] device-mapper: ioctl: unable to set up device queue for new table.
[  153.568854] blk_update_request: I/O error, dev loop0, sector 764010608 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[  153.569169] Buffer I/O error on dev loop0, logical block 95501326, async page read

ここで

blk_update_request: I/O error, dev loop0, sector xxx

という嫌なエラーがみえる。また、homectl inspectやhomectl listなどで現在の状態を調べると、dirtyという状態になっていることがわかる。systemd-homedはdeactivateせず終了したとき、dirty状態になるらしい*1。

# homectl list
NAME  UID   GID   STATE REALNAME HOME        SHELL
lufia 60331 60331 dirty lufia    /home/lufia /bin/bash

1 home areas listed.

このフラグは、/home/[user].homeにあるLUKSイメージにhome-dirty=1として属性が付けられている。属性を消せばinactive状態に戻る。

# attr -l /home/lufia.home
Attribute "home-dirty" has a 1 byte value for /home/lufia.home

# attr -r /home/lufia.home home-dirty

systemd-homedのLUKSストレージ構造

systemd-homedはディレクトリやCIFSサーバなどにストレージを切り替えられるようになっていて、LUKS+Btrfsなファイルシステムイメージがデフォルトとして使われる。この場合、以下の要素が使われる。

LUKSストレージでユーザーが作られると、ユーザーのホームディレクトリは/home/[user].homeという名前のイメージファイルで管理されるようになる。イメージファイルはそのままではマウントできないので、device-mapperでイメージをloopデバイスにする。このデバイスは、LUKSで暗号化したうえでBtrfsファイルシステムとしてフォーマットされる。こうして作られたファイルシステムはログインするとsystemd-homedによって/home/[user]へマウントされるので、ユーザーのデータは最終的に[user].homeのイメージファイルへ書かれることになる。

データを取り出す

ローカルには紛失すると困るものはないはずだが、作業中のソースコードなどは救出したいので必要なデータを取り出した。systemd-homed - ArchWikiにレスキューコマンドがあったのでそのまま使う。

# losetup -fP lufia.home
# cryptsetup open /dev/loop0p1 rescue
# mount /dev/mapper/rescue /mnt/

これで/mnt/[user]からファイルを参照できるようになるので、あとはtarなどで必要なファイルをコピーする。それが終わったら新しくユーザーを作って、逃がしておいたファイルを戻せばよい。ここでは、新しいユーザーはLUKSイメージを使わないストレージにした。

# userctl create --storage=directory --uid=60331 --member-of=wheel lufia

暗号化はディスク全体でやればいいし、Btrfsディスクイメージの利点もあまり感じていなかった。

コマンドとsystemd-homedの違い(未解決)

レスキュー用のコマンドではマウントできるのに、systemd-homedではactivateできないところが不思議だったのでjournalctlでログを読む。

# journalctl -u systemd-homed --since=today
Jan 03 10:49:54 plage systemd-homed[359]: lufia: changing state inactive → activating
Jan 03 10:49:54 plage systemd-homework[506]: Provided password unlocks user record.
Jan 03 10:49:54 plage systemd-homework[506]: Successfully locked image file '/home/lufia.home'.
Jan 03 10:49:54 plage systemd-homework[506]: Backing file is fully allocated already.
Jan 03 10:49:54 plage systemd-homework[506]: Setting up loopback device /dev/loop0 completed.
Jan 03 10:49:55 plage systemd-homework[506]: device-mapper: reload ioctl on home-lufia (254:0) failed: Invalid argument
Jan 03 10:49:55 plage systemd-homework[506]: Failed to unlock LUKS superblock: No such device
Jan 03 10:49:55 plage systemd-homed[359]: block device /sys/devices/virtual/block/loop0 has been removed.
Jan 03 10:49:55 plage systemd-homed[359]: Activation failed: No such device
Jan 03 10:49:55 plage systemd-homed[359]: lufia: changing state activating → inactive

ここで、

block device /sys/devices/virtual/block/loop0 has been removed.
Activation failed: No such device

とあるのは、systemd-homedの処理途中でエラーが発生した場合にloopデバイスが残らないように削除しているだけなので問題ではない。なのでおそらく

device-mapper: reload ioctl on home-lufia (254:0) failed: Invalid argument

が、レスキュー用のコマンドとの差異だろう。次の行に出力されたログから、

のどこかでioctlがエラーになっているのだと思うが、簡単には追えそうになかったので諦めた。

参考情報

調べているときに参考になった記事。

*1:systemd-prerelease 247-rc2を読んだ

Gitで9legacyのパッチを管理する

Plan 9

9legacyは「ベル研Plan 9最終版からのパッチ集」という位置付けです。更新がある場合、基本的には新しいパッチが追加されていきますが、パッチにバグがあった場合などはパッチ自体が更新されることもあります。そのため、手元の環境にパッチを適用したあと、次の更新を手元に適用するためには、過去に適用したパッチを元に戻してから再適用するなどの仕草が必要です。そのため現在は、直接パッチを手元の環境に適用するのではなく、9legacyが配布しているCDイメージを使って replica/pull する方法が推奨されています。

とはいえ自分自身でもPlan 9に手を入れているので、replica/pull で書き戻ってしまうと都合が悪いなどの事情があって、今はGitで差分を管理しています。この記事では、そのための手順をまとめます。

前提

事前に、以下2つのQEMUディスクイメージを用意しておきます。

disk1.raw はベル研Plan 9を9legacyの安定版にアップデートするで、

インストールが終わったら、あとで使うためにインストール直後のdisk0.rawをバックアップしておきましょう。ここでは disk0-orig.raw とします。

と書いているところでバックアップしたディスクイメージです。この記事では説明の都合上 disk1.raw と呼称します。このディスクイメージは何度もインストール直後へ戻すことになるので、バックアップは残しておきましょう。

必要なツールのインストール

disk0.raw で起動して、Gitをインストールします。

$ ./start.bash -v
qemu-system-x86_64 -m 1G -smp 2 \
    -device virtio-scsi-pci,id=scsi \
    -device scsi-hd,drive=hd0 \
    -drive file=disk0.raw,format=raw,cache=writethrough,id=hd0,if=none,index=0 \
    -device virtio-net-pci,netdev=ether0 \
    -netdev user,id=ether0,net=10.0.2.0/24 \
    -machine type=pc,accel=hvf

386環境で使えるGitのバイナリは以下からダウンロードできるので、$home/bin/386 以下などに展開しておきましょう。

  • lufia.org/git-386.tgz

また、パッチの管理を簡単にするため、9legacy-toolもインストールしておくと便利だと思います。

9legacyの差分をGitリポジトリに書き出す

準備ができたら、disk0.raw と disk1.raw を接続した状態で仮想マシンを起動します。

$ ./start.bash -v -a disk1.raw 
qemu-system-x86_64 -m 1G -smp 2 \
    -device virtio-scsi-pci,id=scsi \
    -device scsi-hd,drive=hd0 \
    -drive file=disk0.raw,format=raw,cache=writethrough,id=hd0,if=none,index=0 \
    -device scsi-hd,drive=hd1 \
    -drive file=disk1.raw,format=raw,cache=writethrough,id=hd1,if=none,index=1 \
    -device virtio-net-pci,netdev=ether0 \
    -netdev user,id=ether0,net=10.0.2.0/24 \
    -machine type=pc,accel=hvf

起動直後は disk1.raw をマウントしていないので、disk1.raw を /n/other にマウントします。

% con -l /srv/fscons
prompt: fsys other config /dev/sd01/fossil # virtioが無効な場合はsd01をsdC1に読み替える
prompt: fsys other open -AWPV
prompt: srv fossil
prompt: (ctl+\)
>>> q

% mount -n -c /srv/fossil /n/other other/active

これでインストール直後のPlan 9ファイルツリーを /n/other でアクセスできるようになります。以降は、このファイルツリーにパッチを適用していきます。

Gitリポジトリの準備(最初だけ)

ここで用意するもの

まずリポジトリを作成します。Gitのワーキングツリーは /n/other をそのまま使うので、Gitディレクトリ(ベアリポジトリ)だけ必要です。

% cd $home/lib
% mkdir dist.git
% git -C dist.git init --bare

# 必要なら
% git remote add origin https://github.com/xxx/xxx

dist.gitignore を準備します。ファイルの内容はgithub.com/lufia/plan9:.gitignoreです。/n/other は9legacyの更新があるたびにリセットするので、ここではまだ/n/other/.gitignore には置きません。

9legacyパッチの適用

9legacyのパッチを、/n/other 以下のファイルツリーに適用します。

% mkdir /tmp/20211208 # 作業用ディレクトリなので、どこでもいい
% cd /tmp/20211208
% 9legacy/init -r `{pwd}
% bind -c /n/other plan9
% 9legacy/update -r `{pwd}
% 9legacy/stable -r `{pwd} >o
% 9legacy/installall -n -r `{pwd} o
% cp $home/lib/dist.gitignore plan9/.gitignore

# libmemdraw-9kはalloc.cが1つのパッチで2回更新されるので、patchのテストが落ちる
# そのためテストを無視して適用する
% 9legacy/install -n -r `{pwd} -f libmemdraw-9k

# 残りのパッチを適用
% 9legacy/installall -n -r `{pwd} o

次に9kカーネルのパッチを当てます。

% 9legacy/9k -r `{pwd} >o
% 9legacy/installall -n -r `{pwd} o

必要なら、9legacyのページでOptionalとされているパッチを当てます。

% 9legacy/install -n -r `{pwd} libmux
% 9legacy/install -n -r `{pwd} libworker

ここまで終われば、/tmp/20211208 の作業ディレクトリは不要なので消しても問題ありません。

% unmount plan9 # unmountせずrmするとdisk1.rawのファイルツリーが消えてしまうので注意

差分をリポジトリにコミット

Gitディレクトリ(ベアリポジトリ)とワークツリーを分けた関係で、--git-dir と --work-tree オプションを与えてあげる必要があります。何度も入力するのは面倒なのでシェル関数を作っておきます。

% fn x { git --git-dir $home/lib/dist.git --work-tree /n/other $* }

オプションの代わりに環境変数でも代用できます。

GIT_DIR=$home/lib/dist.git
GIT_WORK_TREE=/n/other

これで、前回のリポジトリ状態と /n/other の差分を扱えるようになるので、必要な変更をGitリポジトリに追加しましょう。

% cd /n/other
% x status
% x add path/to/file # 内容をみてgit addする
% x commit -m '2021-12-08'

# 必要なら
% x push

全部終わったら片付け。

% unmount /n/other

次回以降、9legacyのパッチが更新されたときは、disk1.raw をインストール直後のディスクイメージに戻して上記の手順を繰り返すと、差分だけをGitで管理できます。以下リポジトリの stable ブランチに、9legacyの変更をpushしているので必要なら使ってください。

github.com

リポジトリの内容をPlan 9へ反映する

これで、9legacyのパッチを戻さなくても必要な差分を扱えるようになったので、次にGitリポジトリを使って手元の環境を更新する手順を紹介します。ここでは、アップデートしたいPlan 9のディスクを disk2.raw とします。

disk2.raw を起動ディスクとしてブートした後、上記で作成したリポジトリをcloneします。当然ですがGitコマンドが必要なので、disk1.raw の時と同様にインストールしておいてください。

//memo: rc; rfork ne; bind -a /usr/lufia/bin/386 /bin

% cd $home/lib
% git clone -b stable https://github.com/lufia/plan9.git

2回目以降はpullで更新します。

% cd $home/lib/plan9
% git pull origin stable

次に、Plan 9のルートディレクトリには、実行中にしか存在しない仮想的なファイル*1が含まれるので、それらを除いた disk2.raw の実態を /n/boot から参照できるようにします。

% echo 'srv -AWP replica' >>/srv/fscons # -Vオプションは不要

# 少し待ってからマウントする
% mount -c /srv/replica /n/boot

これで以下の準備ができました。

  • $home/lib/plan9
    • 最新の9legacyパッチを適用したリポジトリ(上の手順で作ったもの)
  • /n/boot
    • disk2.raw に保存されている素のファイルツリー

あとは git を使って、変更のあるファイルをリポジトリの状態にリストアしていけば、最終的には最新の9legacyファイルツリーへ更新できます。

% fn x { git --git-dir $home/lib/plan9/.git --work-tree /n/boot $* }
% cd /n/boot
% x status
% x restore .gitignore
% x restore path/to/file # 必要なだけ繰り返す

最後に片付けして終わり。

% unmount /n/boot
% rm /srv/replica

新しいソースコードでリビルド

あとは以下の記事と同じです。「ソースコードのリビルド」から先を参照してください。

blog.lufia.org

気になる人のためのメモ

Gitでリストアしたファイルのオーナーやグループは、リストアしたユーザーのものに切り替わります。一般的に、/sys 以下のオーナーは sys ユーザーなので、この差が気になる人は chgrp -u などで個別に変更するといいです。

うまくいかない場合

2021年末の時点で、Plan 9に移植したGitコマンドは(特にpull/pushでハングするなど)やや不安定です。そういった場合、以下の環境変数をセットしておくとトレースログとそれぞれの実行にかかった時間などを表示するので原因の調査に役立ちます。

*1:/mnt や /dev など

Goの型や関数定義を検索するコマンド

Plan 9 Go Bash

9fansを見ていると、Rob Pike氏が、Goの型定義や関数定義を検索するコマンドを紹介していた。

実装

上記によるとコマンドは4つ。

bin/f

カレントディレクトリにあるソースコードから関数定義をgrepする。

#!/bin/sh

9 grep -i -n '^func (\([^)]+\) )?'$1'\(' *.go /dev/null

bin/t

f と似ているけど、こちらは型定義をgrepする。

#!/bin/sh

9 grep -i -n '^type '$1' ' *.go /dev/null

bin/cf

codesearch インデックスからGoの関数定義をgrepする。

#!/bin/sh

csearch -n -f '\.go$' '^func (\([^)]+\) )?'$1'\('

bin/ct

同様に、こちらは型定義。

#!/bin/sh

csearch -n -f '\.go$' '^type '$1

使い方

上記の f または t には、plan9portのgrep*1が使われている。Plan 9のgrepは+や|が使える実装なので、インストールしたうえでPATHの末尾に追加しておく必要がある。plan9portのインストールについてはPlan 9 from User Space(plan9port)を使うで書いた。または、試していないけど大体は同じなので、grep -Eで代用できるかもしれない。

出力例はこんな雰囲気。全て filename.go:line 形式で結果を出力するので、Acmeエディタを使っていれば右クリックするだけで該当行にジャンプできるようになっている。

% f String
pickle.go:28: func (op Operator) String() string {
pickle.go:65: func (e *Expr) String() string {
pickle.go:79: func (r *Rule) String() string {
pickle.go:110: func (m *Metric) String() string {
pickle_test.go:336: func (p *InvalidData) String() string {

% t Metric
pickle.go:103: type Metric struct {

cf または ct では csearch コマンドが使われている。これはgoogle/codesearchで公開されているコマンドで、事前にインデックスを作成しておき、インデックスを正規表現で検索する。

# cgrep, cindex, csearchをインストール
% go install github.com/google/codesearch/cmd/...

# インデックス化したいディレクトリを列挙する
% cindex $GOPATH/src ...

これでcsearchすると、インデックスを検索できるようになる。作成したインデックスは、デフォルトでは$HOME/.csearchindexに作られるが、CSEARCHINDEX環境変数で変更できる。技術的な詳細は、Russ Cox氏が以下に書いているが、難しいので読めていない。

*1:9 grepの部分がそれ

labstack/echoのv4.6でRequestLoggerWithConfigを使う

Go

labstack/echoには、以前から middleware.LoggerWithConfig が存在していて、リクエストログのカスタマイズがある程度は可能でした。公式のLogger Middlewareドキュメントより引用します。

e.Use(middleware.LoggerWithConfig(middleware.LoggerConfig{
    Format: "method=${method}, uri=${uri}, status=${status}\n",
}))

この Format は fasttemplate で処理されます。テンプレートの変数はレイテンシやリクエストサイズ、IPアドレスなどミドルウェア側で用意されている値を選択することはできますが、アプリケーション側で用意した任意の値を出力させることができませんでした。また、 io.Writer で出力先の変更はできますが、io.Writer インターフェイスを満たさない任意のロガーを使うことはできませんでした。なので任意の値を追加するためには、独自のミドルウェアを実装して、LoggerWithConfigが行っている処理と同じようにリクエストログで必要な値を echo.Context から計算する必要がありました。

RequestLoggerWithConfig

echoのv4.6で middleware.RequestLoggerWithConfig が追加されて、リクエストログのカスタマイズが少しだけ簡単になりました。以下に例を示します。

package main

import (
    "log"

    "github.com/go-logr/stdr"
    "github.com/labstack/echo/v4"
    "github.com/labstack/echo/v4/middleware"
)

var logger = stdr.New(log.Default())

func writeRequestLog(c echo.Context, v middleware.RequestLoggerValues) error {
    logger.Info("finished",
        "method", v.Method,
        "path", v.URIPath,
        "remote_ip", v.RemoteIP,
        "user_agent", v.UserAgent,
        "protocol", v.Protocol,
        "status", v.Status,
        "latency", v.Latency,
        "content_length", v.ContentLength, // ContentLengthの型はstringで、GETの場合は空文字列
        "response_size", v.ResponseSize,
    )
    return nil
}

func requestLogger() echo.MiddlewareFunc {
    return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
        LogValuesFunc:    writeRequestLog,
        LogMethod:        true,
        LogURIPath:       true,
        LogRemoteIP:      true,
        LogUserAgent:     true,
        LogProtocol:      true,
        LogStatus:        true,
        LogLatency:       true,
        LogContentLength: true,
        LogResponseSize:  true,
    })
}

func main() {
    e := echo.New()
    e.Use(requestLogger())
    e.GET("/", func(c echo.Context) error {
        return c.String(http.StatusOK, "hello")
    })
    e.Start(":8080")
}

これで、任意のロガーを通してアクセスログを出力できるようになりました。middleware.RequestLoggerValues で必要な値に対応する middleware.RequestLoggerConfig のフラグを true にセットしておかないとゼロ値になってしまうので、値がおかしい場合は見直してみましょう。

echo.Context.Logger

ところで echo.Context にはリクエストログとは別に

type Context interface {
    Logger() echo.Logger
}

が用意されていて、アプリケーションで自由に使うことができます。この echo.Logger の実態はデフォルトだと gommon.Logger になっていて echo.Context.SetLogger で変更が可能です。ただし、echo.Logger インターフェイスは

type Logger interface {
    Output() io.Writer
    SetOutput(w io.Writer)
    Prefix() string
    SetPrefix(p string)
    Level() log.Lvl
    SetLevel(v log.Lvl)
    SetHeader(h string)
    Print(i ...interface{})
    Printf(format string, args ...interface{})
    Printj(j log.JSON)
    Debug(i ...interface{})
    Debugf(format string, args ...interface{})
    Debugj(j log.JSON)
    Info(i ...interface{})
    ... この後もログレベルごとに3つメソッドが定義されている...

のようにとても大きくて、JSONログが必要なだけでも全部満たす必要があるのは不毛なので、もう少しこれもどうにかならないかなと思っています。

NodeJS+TypeScriptのchild_processモジュールで非同期にコマンドをパイプする

TypeScript NodeJS

さいきん業務ではReactを使っていて、フロントに対する苦手意識も減ってきたので、いろいろ実験するための環境として自サイトをNextJSのSSGで生成するようにしたのですが、このとき、もともとはPlan 9のmkfileでリソースを管理していた事情もあって、NodeJS+TypeScriptで複数の外部コマンドを扱う必要がありました。

NodeJSで非同期実行する場合、単純なコマンドならchild_processモジュールのspawnを使えばいいだけなのですが、

  • コマンドにファイル名を渡す以外の方法で標準入力にデータを流したい
  • コマンドの標準出力を、別コマンドの入力にしたい

などの場合に、どうすればいいのか分からなかったので調べました。ただ、最後にも書いているけどchild_processモジュールだけで実装するのは意外と大変なので、execaのようなライブラリを使ったほうがいいだろうと思います。

ファイルを指定して単一のコマンドを実行する

child_processモジュールにはコマンドを実行するための関数が複数ありますが、非同期で実行する場合はspawnを使います。コマンドの実行結果はStreamになっているので、以下のように書くと標準出力の内容を取得できます。

import { spawn } from "child_process";

async function main() {
    const p = await spawn("ls", ["-al"], {
        stdio: ["pipe", "pipe", "inherit"],
    });
    for await (const s of p.stdout){
        console.log(`${s}`);
    }
    const status = await new Promise((resolve, reject) => {
        p.on("close", resolve);
    });
    console.log("Status:", status);
}

main();

spawnのstdioオプションは[(stdin), (stdout), (stderr)]の順になっていて、ここでpipeを与えるとプログラムから読み書きできるようになり、inheritの場合は親プロセスのファイルディスクリプタを共有します。上記コード例の場合は、stdinとstdoutがpipeなのでプログラムから読み書きできる状態でプロセスを実行しますし、stderrのところがinheritなので、コマンドのエラーは標準エラー出力にそのまま流れます。ただし、ここで実行しているlsコマンドは標準入力を読まないので、stdinがpipeになっている意味はありません。

標準エラー出力を読む場合は、stdioオプションをpipeに設定して、p.stdoutの代わりにp.stderrを読めば得られます。

任意のストリームをコマンドに渡したい

コマンドの扱う入力がファイルで足りる場合はspawnだけで良いのですが、コマンドに流したいデータは必ずしもファイル名で与えられるとは限りません。例えばHTTPで取得したレスポンスかもしれないし、別のコマンドを実行した結果かもしれません。具体的には、

createReadStream("file").pipe(spawn("sed", ...)).pipe(spawn("wc", ...))

のようにStreamを繋げたい場合は、意外と素直に書くことができませんでした。spawnのstdioオプションはStreamを受け取れるので、

import { spawn } from "child_process";
import { createReadStream } from "fs";

async function main() {
    const fin = createReadStream("package.json", "utf-8");
    const p = await spawn("wc", ["-l"], {
        stdio: [fin, "pipe", "inherit"],
    });
    ...
}

とすれば実現できるかというと、このコードはERR_INVALID_ARG_VALUEで失敗します。

$ npx ts-node main.ts 
TypeError [ERR_INVALID_ARG_VALUE]: The argument 'stdio' is invalid. Received ReadStream {
  path: 'package.json',
  flags: 'r',
  mode: 438,
  fd: null,
  start: undefined,
  end: Infinity,
  pos: undefine...
    at new NodeError (node:internal/errors:371:5)
    at node:internal/child_process:1042:13
    at Array.reduce (<anonymous>)
    at getValidStdio (node:internal/child_process:967:11)
    at ChildProcess.spawn (node:internal/child_process:354:11)
    at Object.spawn (node:child_process:698:9)
    at main (/home/lufia/Downloads/x/main.ts:6:18)
    at Object.<anonymous> (/home/lufia/Downloads/x/main.ts:18:1)
    at Module._compile (node:internal/modules/cjs/loader:1101:14)
    at Module.m._compile (/home/lufia/Downloads/x/node_modules/ts-node/src/index.ts:1311:23) {
  code: 'ERR_INVALID_ARG_VALUE'
}

どうやらcreateReadStreamしただけではfinが内部に持っているファイルディスクリプタがまだnullのようです。fin.on("data", ...)すればファイルディスクリプタがセットされそうでしたが、それだと本当はコマンドに流したいデータがコールバック関数に流れてしまうので、意図していた動作にはなりません。

Transformを実装してパイプする

Stramには、読み込み用のReadableや書き込み用のWritable以外にも、ストリームを流れるデータを加工して流すためのTransformが用意されています。上でやりたかったコマンドのパイプも、このTransformを実装すると実現できます。Transformの実装方法は、コンストラクタに変換するための関数を渡す方法と、クラスとして実装する方法の2種類ありますが、ここでは前者で実装しました。

import { ChildProcess, spawn } from "child_process";
import { createReadStream } from "fs";
import { Transform } from "stream";

function createTransform(p: ChildProcess): Transform {
    const data: string[] = [];
    p.stdout?.on("data", s => {
        data.push(s); // 実行したコマンドの標準出力を貯めておく
    });

    const t = new Transform({
        // 定期的に呼ばれるので貯めていたデータを流す
        transform: (s, encoding, callback): void => {
            // 前プロセスから届いたデータをコマンドに流す
            p.stdin?.write(s);

            // コマンドの結果を次のストリームに渡す
            while(data.length > 0)
                t.push(data.shift());
            callback();
        },
        final: async (callback): Promise<void> => {
            // コマンドが終わるのを待つ
            p.stdin?.end();
            const status = await new Promise((resolve, reject) => {
                p.on("close", resolve);
            });
            if(status !== 0)
                throw new Error(`${p.spawnfile}: exit with ${status}`);

            // p.stdin.end()の後で貯まったデータを次のストリームへ全部流す
            while(data.length > 0)
                t.push(data.shift());
            callback();
        },
    });
    return t;
}

// 使用例
async function main() {
    const fin = createReadStream("package.json", "utf-8");
    const p = spawn("grep", ["ts"], {
        stdio: ["pipe", "pipe", "inherit"],
    });
    const t = createTransform(p);
    const stream = fin.pipe(t);
    try {
        for await (const s of stream){
            console.log(`${s}`);
        }
    } catch(e) {
        console.error(e.message)
    }
}

pipeではなくpipelineを使う

ところで、pipeでストリームを接続した場合、ストリームのうちどれか1つでもエラーが発生すると、残りのプロセスが回収されない問題があります。イベントを監視して適切な対応をすればいいのですが、接続するプロセスが多くなると面倒なので、今はpipelineを使うとよいそうです。

ただし、pipeと異なりpipelineは戻り値がPromise<void>になっているため、これまでのようにfor...ofを使った出力結果の取得ができません。代わりにpipelineでは、最後の引数にWritableなストリームを受け取るようになっていて、例えばファイルに書き出す場合はここへcreateWriteStreamで生成したストリームを渡します。

とはいえ、ここではコマンドの実行結果をプログラムから扱いたいだけなので、ファイルに書き出す必要はありません。流れてきたデータをメモリ上で保持するためのWritableなストリームを探したのですが見つからなかった*1ので、以下のようにWritableMemoryStreamを用意して対応しました。

import { ChildProcess, spawn } from "child_process";
import { createReadStream } from "fs";
import { Transform, Writable } from "stream";
import { pipeline } from "stream/promises";

async function main() {
    const fin = createReadStream("package.json", "utf-8");
    const grep = spawn("grep", ["ts"], {
        stdio: ["pipe", "pipe", "inherit"],
    });
    const wc = spawn("wc", ["-l"], {
        stdio: ["pipe", "pipe", "inherit"],
    });
    const w = new WritableMemoryStream();
    try {
        await pipeline(fin, createTransform(grep), createTransform(wc), w);
    } catch(e) {
        console.error(e.message)
    }
    console.log(w.toString());
}

function createTransform(p: ChildProcess): Transform {
    const data: string[] = [];
    p.stdout?.on("data", s => {
        data.push(s);
    });

    const t = new Transform({
        transform: (s, encoding, callback): void => {
            p.stdin?.write(s);
            while(data.length > 0)
                t.push(data.shift());
            callback();
        },
        final: async (callback): Promise<void> => {
            p.stdin?.end();
            const status = await new Promise((resolve, reject) => {
                p.on("close", resolve);
            });
            if(status !== 0)
                throw new Error(`${p.spawnfile}: exit with ${status}`);
            while(data.length > 0)
                t.push(data.shift());
            callback();
        },
    });
    return t;
}

class WritableMemoryStream extends Writable {
    private data: string[];

    constructor() {
        super();
        this.data = [];
    }

    _write(data: any, encoding: BufferEncoding, callback: (error?: Error | null) => void) {
        this.data.push(data);
        callback();
    }

    toString(): string {
        return this.data.join("");
    }
}

Transformと同じように、Writableのコンストラクタを使ってもよかったけれど、toStringで最終的な結果を取得する方が自然に思えたのでクラスとして実装しています。

感想

パイプの実装なんてCで何度も書いたことがあるし、spawnのインターフェイスがやりたいことを満たしてそうだったのもあって、油断してchild_processだけで対応してしまったけれど、やってみると意外と大変でした。もっとうまい実装方法はあるかなとは思いつつ、個人的には、次に同じ処理が必要ならexecaのようなライブラリを使うと思います。

*1:npmにmemorystreamはあるけどメンテナンスされてなさそうだった

Plan 9 CのARGBEGIN、ARGENDマクロ

Plan 9 C

Plan 9のCは独自のライブラリを持っていて、stdio.hのようなANSIライブラリもAPE(ANSI/POSIX Environment)として存在してはいるが、基本的にはPlan 9独自のライブラリを使う方が好まれる。ANSI Cとの違いは挙げればいくつもあるのでPlan 9 Cを知らない人には伝わりづらいけれども、Goの標準ライブラリにもPlan 9のCライブラリの面影が部分的に残っているので、Goの基礎的なパッケージ(bufio, utf8, strconv, stringsなど)に似ているといえば伝わるかもしれない。いくつか挙げると、Plan 9 Cではバッファリングを行うライブラリはlibbioにまとまっているが、libbioの

#include <bio.h>

int Binit(Biobuf *bp, int fd, int mode);
int Brdline(Biobufhdr *bp, int delim);

は、ほとんどGoの

package bufio

func NewReader(rd io.Reader) *Reader
func (b *Reader) ReadBytes(delim byte) ([]byte, error)

と同じ使用感になっているし、

#include <libc.h>

int tokenize(char *str, char **args, int maxargs);

も、言語の違いこそあるものの、Goのstrings.Fieldsとだいたい同じように使える。また、UTF-8はPlan 9から出てきたものなので当然といえば当然だけど、Plan 9 CはGoと同様に、Unicode文字を扱う場合はRune型*1を使う。他にも探せば似たものはいくつもあるけれど、詳細には取り挙げない。

コマンドラインパーサ

Plan 9独自のCライブラリには、コマンドラインオプションを解析するARGBEGINマクロとARGENDマクロがある。これらはコマンドラインオプションを扱うときに使用するマクロで、典型的にはEARGFなどと組み合わせて以下のように使う。

#include <u.h>
#include <libc.h>

int debug;
char *file;

void
usage(void)
{
    fprint(2, "usage: %s [-f file] [-v] [arg ...]\n", argv0);
    exits("usage");
}

void
main(int argc, char **argv)
{
    int i;

    ARGBEGIN {
    case 'f':
        file = EARGF(usage());
        break;
    case 'v':
        debug++;
        break;
    default:
        usage();
    } ARGEND

    print("debug: %d\n", debug);
    print("file: %s\n", file);
    for(i = 0; i < argc; i++)
        print("argv[%d]: %s\n", i, argv[i]);
    exits(nil);
}

特筆すべきところは、ARGENDを抜けた後のargv[0]は、コマンド名ではなくオプションを除いた最初の引数を参照している。上記コードを実行結果は以下のようになる。

% opts -f file -v a b c
debug: 1
file: file
argv[0]: a
argv[1]: b
argv[2]: c

% opts -f # 引数が足りない場合
usage: opts [-f file] [-v] [arg ...]

ロングオプションは対応していないけれど、Plan 9のコマンドはオプションがあまりないので、これで充分なんだろうと思う。cat(1)はオプションが無いし、cp(1)は3個、ls(1)でも12個しかない。

usage: ls [-dlmnpqrstuFQ] [file ...]

usage: cp [-gux] fromfile tofile

サブコマンド

Plan 9の標準シェルであるrc(1)は、$path配下のディレクトリも検索対象となるので、

% fossil/conf -w file /dev/sd01/fossil
% auth/factotum
% upas/fs

のように関連するコマンドをディレクトリでまとめることが普通となっていて、サブコマンドが使われることはほとんどない*2が、ARGBEGINマクロを使ってサブコマンドを実装できるので参考程度に書いておく。単純に、サブコマンド関数の引数がargcとargvになっていればARGBEGINマクロを利用できる。

#include <u.h>
#include <libc.h>

void cmdinit(int, char **);
void cmdprint(int, char **);

struct {
    char *name;
    void (*cmd)(int, char **);
} cmds[] = {
    { "init", cmdinit },
    { "print", cmdprint },
};

int debug;
char *file;

void
usage(void)
{
    fprint(2, "usage:\t%s init [-y]\n", argv0);
    fprint(2, "\t%s print\n", argv0);
    exits("usage");
}

void
main(int argc, char **argv)
{
    int i;

    ARGBEGIN {
    case 'f':
        file = EARGF(usage());
        break;
    case 'v':
        debug++;
        break;
    default:
        usage();
    } ARGEND
    if(argc == 0)
        usage();

    for(i = 0; i < nelem(cmds); i++)
        if(strcmp(cmds[i].name, argv[0]) == 0){
            cmds[i].cmd(argc, argv);
            exits(nil);
        }
    usage();
}

void
cmdinit(int argc, char **argv)
{
    int yes;

    yes = 0;
    ARGBEGIN {
    case 'y':
        yes++;
        break;
    default:
        usage();
    } ARGEND
    print("init: debug=%d yes=%d\n", debug, yes);
}

void
cmdprint(int argc, char **argv)
{
    ARGBEGIN {
    default:
        usage();
    } ARGEND
    print("print: file=%s\n", file);
}

*1:以前は16bitだったけど今は22bitのはず

*2:OS標準のコマンドでは全く見た記憶がない

systemd-logindにSuspend key pressedと記録されてサスペンドする問題とthermal-conf.xmlの書き方

Linux

12インチMacBookにLinuxをインストールして使っていたが、負荷が上がったときにMacBookがサスペンドする問題に困っていた。サスペンドが発生した時刻には、systemd-logindのログに

systemd-logind[299]: Suspend key pressed.

のようなイベントが記録されていた。このログは、LinuxカーネルでKEY_SLEEPと定義されたキーが押されたときにsystemd-logindのbutton_dispatch関数が記録しているものだった。button_dispatchの主な処理を引用する。

static int button_dispatch(sd_event_source *s, int fd, uint32_t revents, void *userdata)
{
    Button *b = userdata;
    struct input_event ev;
    ssize_t l;

    l = read(b->fd, &ev, sizeof ev);
    switch(ev.code){
    case KEY_SLEEP:
        log_struct(LOG_INFO, "Suspend key pressed.", ...);
        manager_handle_action(b->manager,
            INHIBIT_HANDLE_SUSPEND_KEY,
            b->manager->handle_suspend_key,
            b->manager->suspend_key_ignore_inhibited,
            true);
        break;
    case KEY_SUSPEND:
        log_struct(LOG_INFO, "Hibernate key pressed.", ...);
        ...
    }
}

KEY_SLEEP定数はLinuxのヘッダファイルで定義されたもので、カーネルとsystemdではSuspendが意味するものが異なっているところは少し難しいが、とにかくスリープのようなキーが押されたことを意味する。

#define KEY_SLEEP 142 /* SC System Sleep */
#define KEY_SUSPEND 205

上のコードを読む限りでは、button_dispatchはキーイベントをread(2)しているだけなので、少なくともなんらかのハードウェアが原因だろうと思ったが、MacBookには電源ボタンはあるけれど押していないし、なんならリッドクローズドで使っている時は電源ボタンもないキーボードを使っているので、誤って物理キーを押したわけではない。

systemd-logindでサスペンドを無効化してみる

systemd-logindはサスペンドキーが押されたときの動作を/etc/systemd/logind.confで変更できる。例えば以下のようにignoreを設定するとキーイベントを無視できる。

-#HandleSuspendKey=suspend
+HandleSuspendKey=ignore

これは実際に、systemd-logindのmanager_handle_actionで、HANDLE_IGNOREの場合はすぐに関数を抜けているところからもイベントを無視している様子が読み取れる。

 /* If the key handling is turned off, don't do anything */
if (handle == HANDLE_IGNORE) {
    log_debug("Handling of %s (%s) is disabled, taking no action.",
        inhibit_key == 0 ? "idle timeout" : inhibit_what_to_string(inhibit_key),
        is_edge ? "edge" : "level");
    return 0;
}

しかし試したけれど残念ながら、状況は改善されなかった。負荷をかけるとすぐにサスペンドしてしまった。

デスクトップ環境でサスペンドを無効にする

GNOMEやKDEなどのデスクトップ環境は独自の電源管理を行っているので、これを無効化してみる。GNOMEの場合は、関連する設定は以下の通り。

$ gsettings get org.gnome.settings-daemon.plugins.power power-button-action
'suspend'
$ gsettings get  org.gnome.settings-daemon.plugins.power sleep-inactive-battery-type
'suspend'
$ gsettings get org.gnome.settings-daemon.plugins.power sleep-inactive-ac-type
'suspend'
$ gsettings get org.gnome.settings-daemon.plugins.power sleep-inactive-battery-timeout
200
$ gsettings get org.gnome.settings-daemon.plugins.power sleep-inactive-ac-timeout
1200

これらの設定を無効にする。

$ gsettings set org.gnome.settings-daemon.plugins.power power-button-action nothing
$ gsettings set  org.gnome.settings-daemon.plugins.power sleep-inactive-battery-type nothing
$ gsettings set org.gnome.settings-daemon.plugins.power sleep-inactive-ac-type nothing

これも、設定したあとで負荷をかけて様子をみたが、再発してしまったので関係がなかった。

CPU周波数を落とす

12インチMacBookはファンレスなので、熱の問題だろうと当たりをつけて対策する。このハードウェアのデフォルトはintel_pstateドライバのpowersaveガバナー(Governor)だった。

$ grep . /sys/devices/system/cpu/cpu?/cpufreq/scaling_driver
/sys/devices/system/cpu/cpu0/cpufreq/scaling_driver:intel_pstate
/sys/devices/system/cpu/cpu1/cpufreq/scaling_driver:intel_pstate
/sys/devices/system/cpu/cpu2/cpufreq/scaling_driver:intel_pstate
/sys/devices/system/cpu/cpu3/cpufreq/scaling_driver:intel_pstate

$ grep . /sys/devices/system/cpu/cpu?/cpufreq/scaling_governor
/sys/devices/system/cpu/cpu0/cpufreq/scaling_governor:powersave
/sys/devices/system/cpu/cpu1/cpufreq/scaling_governor:powersave
/sys/devices/system/cpu/cpu2/cpufreq/scaling_governor:powersave
/sys/devices/system/cpu/cpu3/cpufreq/scaling_governor:powersave

Intel Turbo Boostを無効にする

Turbo Boostは使っていないコアの電源を落とす替わりに、特定コアのクロックを上げる仕様らしい。

Turbo Boostはno_turboファイルに1を書き込むことで無効にできる。

$ echo 1 | sudo tee /sys/devices/system/cpu/intel_pstate/no_turbo

TurboBoostを無効にすると、突然サスペンドすることはなくなったが、クロックが最大1.4GHzまで落ちてしまうので普段使いするには少々厳しい性能になってしまった。

cpuの最大クロック数を制限する

cpupowerを使ってクロックを落とす方法。

$ sudo pacman -S cpupower
$ sudo cpupower frequency-set -u '2.2GHz'

これで全てのコアが最大2.2GHzに制限される。ただしこの設定は再起動すると消えるので、永続化したい場合はsystemdで実行する。cpupowerをインストールしていれば、/etc/default/cpupowerに設定ファイルがあるので利用するといい。

-#max_freq="3GHz"
+max_freq="2.2GHz"

その後、systemctlでサービスを有効にする。

$ systemctl enable cpupower.service

クロックを変更して実験した結果、2.2GHzまで落とさなければサスペンドが発生していた。実験したときは5月だけど、夏はもっと下げなければだめかもしれない。もっと下げると、TurboBoost無効時の1.4GHzとそれほど変らず、性能の劣化が気になる。

Thermaldで冷却する

一般的にはインストールして起動するだけで適切な動作をする。Ask Ubuntuの回答によると、このモードはZero Configuration Modeといって、DTS温度測定センサーやIntel P-stateを使って適切な調整をする。

coretempドライバのドキュメントは以下のURLにあった。

だけれども、MacBookの場合はZero Configuration Modeでは冷却されている様子がなかったので、/etc/thermald/thermal-conf.xmlで設定することにした。この方法は、上記Ask Ubuntuの回答によるとUser defined configuration modeにあたる。Thermaldに関係するマニュアルは以下の2つ。

thermal-conf.xml(5)には設定例もあるので、読めばだいたい雰囲気で分かるのだけど、難しかったところを少しまとめる。thermal-conf.xmlは大きく分けて3つの要素で構成される。

  • ThermalSensor
  • CoolingDevice
  • TripPoint

ThermalSensor

センサーは温度を計測する場所のことで、たとえばCPUコアなどがそれに該当する。センサーを扱うためには/sys以下のファイルなどを<ThermalSensor>要素で設定が必要になるが、/sys/class/thermal以下のデバイスはデフォルトで組み込まれているので、特に設定を追加せずとも利用できる。12インチMacBookの場合は以下の通り。

$ grep . /sys/class/thermal/thermal_zone*/type
/sys/class/thermal/thermal_zone0/type:BAT0
/sys/class/thermal/thermal_zone1/type:x86_pkg_temp

BAT0はバッテリーで、x86_pkg_tempはCPUパッケージかな。/sys/class/thermal以下のファイル郡はACPI由来のもので、マニュアルではThermal sysfsと呼ばれている。/sys/class/thermalのカーネルドキュメントは以下のURLにある。

Thermal sysfs以外にも、MacBookには/sys/devices/platform/coretemp.0/subsystem/devices/applesmc.768などのセンサーがある。これらThermal sysfs以外のセンサーを参照して温度管理をする場合は、<ThermalSensor>要素を使った設定が必要になる。sensorsコマンドを実行すると、他にどのようなセンサーがあるのか調べられる。

$ sensors
BAT0-acpi-0
Adapter: ACPI interface
in0:           8.58 V  
temp:         +32.8°C  
curr1:         0.00 A  (avg =  +0.00 A)

coretemp-isa-0000
Adapter: ISA adapter
Package id 0:  +44.0°C  (high = +100.0°C, crit = +100.0°C)
Core 0:        +43.0°C  (high = +100.0°C, crit = +100.0°C)
Core 1:        +43.0°C  (high = +100.0°C, crit = +100.0°C)

applesmc-isa-0300
Adapter: ISA adapter
TA0V:         +29.0°C  
TB0T:         +32.5°C  
TB1T:         +32.0°C  
TB2T:         +32.5°C  
TBXT:         +32.5°C  
TC0E:         +43.8°C  
TC0F:         +46.0°C  
TC0P:         +39.5°C  
TC1C:         +43.0°C  
TC2C:         +43.0°C  
TCGC:         +43.0°C  
TCHP:         +37.0°C  
TCSA:         +44.0°C  
TCXC:         +43.5°C  
TH0A:         +37.2°C  
TH0B:        -127.0°C  
TH0C:        -127.0°C  
TH0F:         -47.8°C  
TH0R:         -47.8°C  
TKBV:         +36.8°C  
TM0P:         +38.8°C  
TPCD:         +39.0°C  
TPMV:         +31.8°C  
TW0P:         +37.2°C  
Th0N:         +36.2°C  
Th0R:         +31.8°C  
Ts0P:         +32.2°C  
Ts0S:         +36.0°C  
Ts1P:         +30.5°C  
TsCH:         +47.5°C  
TsFD:         +60.0°C  
TsFS:         +53.0°C  
TsHS:          +2.0°C  
TsTH:          +3.0°C  
TsTP:         +50.0°C  
TsWS:         +49.0°C  

BAT0-virtual-0
Adapter: Virtual device
temp1:        +32.8°C  

nvme-pci-0100
Adapter: PCI adapter
Composite:    +39.9°C

sensorsコマンドで出力された結果の意味は、以下の記事が参考になると思う。

CoolingDevice

冷却デバイスは温度を下げるための機構またはハードウェアのこと。空冷ファンは当然だけど、CPUのクロックを落とすしくみのような機構もCoolingDeviceに該当する。これもセンサーと同様に、/sys/class/thermal以下のデバイスは何も書かなくても利用できる。12インチMacBookの場合は以下の通り。

$ grep . /sys/class/thermal/cooling_device*/type
/sys/class/thermal/cooling_device0/type:Processor
/sys/class/thermal/cooling_device1/type:Processor
/sys/class/thermal/cooling_device2/type:Processor
/sys/class/thermal/cooling_device3/type:Processor
/sys/class/thermal/cooling_device4/type:intel_powerclamp
/sys/class/thermal/cooling_device5/type:LCD

また、マニュアルによると、以下のデバイスもCoolingDeviceとして使えるらしい。

  • rapl_controller
  • intel_pstate (CPU周波数ドライバ)
  • cpufreq
  • LCD (モニターのバックライトを薄暗くする)

それぞれがどんな動作をするのかは、ArchWikiのCPU 周波数スケーリングが詳しい。

TripPoint

この要素で、センサーと冷却デバイスをまとめて温度管理を行う。例えば以下のような設定になる。

<TripPoint>
    <SensorType>x86_pkg_temp</SensorType>
    <Temperature>75000</Temperature>
    <type>passive</type>
    <ControlType>PARALLEL</ControlType>
    <CoolingDevice>
      <index>1</index>
      <type>rapl_controller</type>
      <influence>50</influence>
      <SamplingPeriod>1</SamplingPeriod>
    </CoolingDevice>
</TripPoint>

<Temperature>は冷却を開始するセンサーの温度を設定する。75000の場合は75℃以上になったら開始する。<type>は以下の3種類。

  • active
  • passive
  • max

activeは、空冷ファンなどコストのかかる(追加の電源やノイズなどが発生する)を使う。passiveならパフォーマンスを落として温度を下げる。maxについてはよくわからない。

<SamplingPeriod>を設定すると、前回の変化から設定した秒が経過するまでは温度の変化を検出しなくなる。未設定または0なら常に検出する。

設定例

現在設定している/etc/thermald/thermal-conf.xmlを貼っておく。だいたい期待どおりに動いているが、長時間の負荷を与えたときはまだ稀にサスペンドする場合があるので、もう少し調整は必要だと思う。

<?xml version="1.0"?>
<ThermalConfiguration>
  <Platform>
    <Name>Macbook 2017</Name>
    <ProductName>*</ProductName>
    <Preference>QUIET</Preference>   <!-- 空冷ファンなどactiveなデバイスを使わず冷却する -->
    <ThermalZones>
      <ThermalZone>
        <Type>x86_pkg_temp</Type>
        <TripPoints>
          <TripPoint>
            <SensorType>x86_pkg_temp</SensorType>
            <Temperature>75000</Temperature>
            <type>passive</type>
            <ControlType>PARALLEL</ControlType>
            <CoolingDevice>
              <index>1</index>
              <type>rapl_controller</type>
              <influence>50</influence>
            </CoolingDevice>
            <CoolingDevice>
              <index>2</index>
              <type>intel_pstate</type>
              <influence>40</influence>
            </CoolingDevice>
            <CoolingDevice>
              <index>3</index>
              <type>intel_powerclamp</type>
              <influence>30</influence>
            </CoolingDevice>
            <CoolingDevice>
              <index>4</index>
              <type>cpufreq</type>
              <influence>20</influence>
            </CoolingDevice>
            <CoolingDevice>
              <index>5</index>
              <type>Processor</type>
              <influence>10</influence>
            </CoolingDevice>
          </TripPoint>
        </TripPoints>
      </ThermalZone>
    </ThermalZones>
  </Platform>
</ThermalConfiguration>

以下のURLにも設定例が書かれているので、参考になる。