午後の診療開始直後,受付から処方箋,領収書,診療明細が印刷されなくなったという連絡あり。orca サーバを再起動してみたが症状は変わらず。処方箋を印刷しようとすると syslog にわけの分からない dump が出てくる。患者さんが結構待っていたのでかなり焦ったが,ここは冷静に頭を医者モードからコンピュータ管理者モードに切り替えてトラブルシューティングを開始した。
まずは orca の cups にブラウザでアクセス,プリンタにテストプリントを送ってみたところ正常にプリントされた。当院では,処方箋等は cups のバックエンドに送って,バックアップマシンにカーボンコピーを残しつつプリンタに送る様に設定している。そこで,orca のプリント出力先を,ダイレクトにプリンタに送るようにしてみたところ,プリントされるようになった。とりあえずこれで診療を乗り切った。
患者さんが切れてから cups のログを見てみた。
E [14:06:50 +0900] Unable to fork /usr/lib/cups/filter/foomatic-rip - Cannot allocate memory.
E [14:06:50 +0900] [Job 224056] Unable to start filter "foomatic-rip" - Success.
E [14:06:50 +0900] [Job 224056] Stopping job because the scheduler could not execute a filter.
E [14:06:51 +0900] Unable to fork /usr/lib/cups/backend/socket - Cannot allocate memory.
E [14:06:51 +0900] [Job 224059] Stopping job because the sheduler could not execute the backend.
E [14:06:52 +0900] Unable to fork /usr/lib/cups/backend/pdf - Cannot allocate memory.
E [14:06:52 +0900] [Job 224058] Stopping job because the sheduler could not execute the backend.
cups がメモリ不足で止まっていたようだった。そこで,メモリを調べてみると。
$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 911564 23084 13584 165496 17 106 124 134 77 67 1 0 99 0 0
$ free -t
total used free shared buffers cached
Mem: 1013348 991528 21820 39876 13628 166520
-/+ buffers/cache: 811380 201968
Swap: 1048572 911536 137036
Total: 2061920 1903064 158856
血の気が引いた。慌てて最新 orca の必要メモリを調べてみたら,4GB 以上,最低 2GB となっていた。以前から orca には 1GB しか割り当てていなかったため,スワップ領域を食い尽くして,ギリギリの状態で動いていたようだ。
緊急に容量を工面して,orca のために 3GB 用意した。これでプリンタ出力先をバックエンドに戻しても問題なく印刷されるようになり,その後の業務も問題なく終了。
$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 404244 124896 528624 0 0 23 23 63 56 1 0 99 0 0
$ free -t
total used free shared buffers cached
Mem: 3069452 2665032 404420 64548 124904 528628
-/+ buffers/cache: 2011500 1057952
Swap: 1048572 0 1048572
Total: 4118024 2665032 1452992
業務終了後,メモリを買ってきて造設 (DDR3メモリずいぶん安くなってた)。余裕をもってトータル 16G にして,orca には推奨の 4GB を割り当てた。メモリ増設後の1日業務終了後,かなりの余裕。
$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
1 0 0 1148244 147516 679468 0 0 4 21 77 68 1 0 99 0 0
$ free -t
total used free shared buffers cached
Mem: 4097504 2949632 1147872 141864 147524 679532
-/+ buffers/cache: 2122576 1974928
Swap: 1048572 0 1048572
Total: 5146076 2949632 2196444
2010年には 4GB で湯水のようにメモリが使えると喜んでいたのに,今や orca だけで 4GB である。