loggerコマンドの使用例

syslogフォーマットでログを送信することのできるloggerコマンドの使用例。

loggerコマンドの使用例

shell> logger -h host.l2tp.org -p local0.info -t hoge
hogehoge ^D

-hでホストを指定

-pはプライオリティを指定。 ドット区切りでログファシリティとログレベルを指定

-tはタグ指定。プログラム名とも呼ばれる。

RT58iで接続がうまくいかないトラブルが発生

RT58iで接続がうまくいかないトラブルが発生

外部からはもちろん、内部からもうまくpingが届かない。

wanを切断しても効果なし。いったい何が起こったの・・・・。

64 bytes from 192.168.84.253: icmp_seq=1077 ttl=255 time=1063.397 ms
64 bytes from 192.168.84.253: icmp_seq=1078 ttl=255 time=74.789 ms
64 bytes from 192.168.84.253: icmp_seq=1079 ttl=255 time=226.006 ms
64 bytes from 192.168.84.253: icmp_seq=1080 ttl=255 time=0.472 ms
64 bytes from 192.168.84.253: icmp_seq=1081 ttl=255 time=0.657 ms
64 bytes from 192.168.84.253: icmp_seq=1082 ttl=255 time=1.128 ms
64 bytes from 192.168.84.253: icmp_seq=1083 ttl=255 time=0.842 ms
64 bytes from 192.168.84.253: icmp_seq=1084 ttl=255 time=1.336 ms
64 bytes from 192.168.84.253: icmp_seq=1085 ttl=255 time=2903.965 ms
64 bytes from 192.168.84.253: icmp_seq=1086 ttl=255 time=1916.236 ms
64 bytes from 192.168.84.253: icmp_seq=1087 ttl=255 time=924.898 ms
64 bytes from 192.168.84.253: icmp_seq=1088 ttl=255 time=0.956 ms
64 bytes from 192.168.84.253: icmp_seq=1089 ttl=255 time=0.621 ms
64 bytes from 192.168.84.253: icmp_seq=1090 ttl=255 time=2540.378 ms
64 bytes from 192.168.84.253: icmp_seq=1091 ttl=255 time=1552.851 ms
64 bytes from 192.168.84.253: icmp_seq=1092 ttl=255 time=561.524 ms
64 bytes from 192.168.84.253: icmp_seq=1093 ttl=255 time=2112.758 ms
64 bytes from 192.168.84.253: icmp_seq=1094 ttl=255 time=1124.880 ms
64 bytes from 192.168.84.253: icmp_seq=1095 ttl=255 time=136.290 ms
64 bytes from 192.168.84.253: icmp_seq=1096 ttl=255 time=269.743 ms
64 bytes from 192.168.84.253: icmp_seq=1097 ttl=255 time=421.978 ms
64 bytes from 192.168.84.253: icmp_seq=1098 ttl=255 time=651.552 ms
64 bytes from 192.168.84.253: icmp_seq=1099 ttl=255 time=815.570 ms
64 bytes from 192.168.84.253: icmp_seq=1100 ttl=255 time=0.794 ms
64 bytes from 192.168.84.253: icmp_seq=1101 ttl=255 time=0.572 ms
64 bytes from 192.168.84.253: icmp_seq=1102 ttl=255 time=2350.312 ms
64 bytes from 192.168.84.253: icmp_seq=1103 ttl=255 time=1358.987 ms
64 bytes from 192.168.84.253: icmp_seq=1104 ttl=255 time=368.046 ms
64 bytes from 192.168.84.253: icmp_seq=1105 ttl=255 time=1068.143 ms
64 bytes from 192.168.84.253: icmp_seq=1106 ttl=255 time=78.687 ms
64 bytes from 192.168.84.253: icmp_seq=1107 ttl=255 time=0.567 ms
64 bytes from 192.168.84.253: icmp_seq=1108 ttl=255 time=0.466 ms
64 bytes from 192.168.84.253: icmp_seq=1109 ttl=255 time=2172.697 ms
64 bytes from 192.168.84.253: icmp_seq=1110 ttl=255 time=1188.188 ms
64 bytes from 192.168.84.253: icmp_seq=1111 ttl=255 time=202.031 ms
64

PHPのエラーで500 Internal Server Errorが返される

PHPのエラーで500 Internal Server Errorが返される。

今回の問題は単純でいて難しい問題だった。ここ二週間ほど、かなりの時間を使ってしまった。

まず最初に問題が起こった。

あるリクエストに対して500 Internal Server Errorが返ってくるようになった。

それなりにコードのアップデートを行ったあとだったのでこの辺が原因だろうという予測はついたのだが、状況が複雑だった。

リクエストごとに200の正常な返答と、500のエラーとが混在して返ってきていたのだ。

というのもこのとき、二つのサーバを負荷分散のためmod_proxyで振り分けしていたのだが、このうちの一方のみから500が返答されるようになっていた。

NFSを通して一つのファイルを利用しているため、エラーのコードが片方にのみ混ざっていることはない。

ホスト phpのバージョン
エラーのあるホスト php5-5.3.3_2        PHP Scripting Language
正常に動くホスト php52-5.2.14        PHP Scripting Language
テストのホスト(エラー) php5-5.3.3_2        PHP Scripting Language

どうやらPHPの5.3系列でエラーになっているような雰囲気ではあるんだけど、実は応答によっては200でレスポンスヘッダ、レスポンスボディが全く空のものが返ってきたりして何ともテストしにくい状況に。

テスト環境でも試していたけれど500が返ってくることに。printデバッグもうまくいかない。

php_errorにもエラーログが残らず、サッパリ訳がわからない状態になってしまった。

と、ひょんなことでdisplay_errosがoffになっていることに気づく。じつはテスト環境では本番環境への前テストとしてdisplay_errorsをoffにして運用していたのだ。

これをonにするとエラーが出てきた。

これにて一件落着っぽい。

ちなみに5.3へ建前上は移行したんだけれど、5.3独特のエラーを見つけるためというかなんというか、ってことで両方の環境を残している。今回はこれはよかったのか、わるかったのか・・・。

FreeBSDでportsからのインストールとかができなくなる

FreeBSDでportsからのインストールとかができなくなる。

エラーの内容は下記


%sudo make
"/usr/ports/Mk/bsd.port.mk", line 2523: Could not find /usr/ports/Mk/bsd.licenses.mk
"/usr/ports/Mk/bsd.port.mk", line 2526: Could not find /usr/ports/Mk/bsd.sites.mk
make: fatal errors encountered -- cannot continue

原因不明だけれど、これらのファイルがなくなってしまっている様子。

portsnapを使ってアップデートすると復活する模様。


> sudo portsnap fetch && sudo portsnap update
Looking up portsnap.FreeBSD.org mirrors... 5 mirrors found.
Fetching snapshot tag from portsnap6.FreeBSD.org... done.
Fetching snapshot metadata... done.
Updating from Sun Mar 13 01:52:19 JST 2011 to Fri Mar 18 10:00:20 JST 2011.
Fetching 3 metadata patches.. done.
Applying metadata patches... done.
Fetching 0 metadata files... done.
Fetching 860 patches.....10....20....30....40....50....60....70....80....90....100....110....120....130....140....150....160....170....180....190....200....210....220....230....240....250....260....270....280....290....300....310....320....330....340....350....360....370....380....390....400....410....420....430....440....450....460....470....480....490....500....510....520....530....540....550....560....570....580....590....600....610....620....630....640....650....660....670....680....690....700....710....720....730....740....750....760....770....780....790....800....810....820....830....840....850....860 done.
Applying patches... done.
Fetching 24 new ports or files... done.
Removing old files and directories... done.
Extracting new files:
/usr/ports/MOVED
/usr/ports/Mk/bsd.gnustep.mk
/usr/ports/Mk/bsd.licenses.db.mk
/usr/ports/Mk/bsd.licenses.mk
/usr/ports/Mk/bsd.octave.mk
/usr/ports/Mk/bsd.sites.mk
/usr/ports/UPDATING
...
(中略)
...
/usr/ports/x11/metisse/
/usr/ports/x11/nvidia-driver/
/usr/ports/x11/xtset/
Building new INDEX files... done.

原因は不明。しかもここ最近何度か見かけるようになってしまった。

自分のところの環境は複数のホストから一つのportsディレクトリを共有しているが、そこのホストのどれかが原因でこの問題が起きているのではないかと予測。うーんむ。

NAS/SANの構築を直すと同時に、共有されているディレクトリを二つのグループに分け、二分探索の様相で問題ホストを特定する、とか。

あとはmaproot?を許可しない、とか。distfilesの置き場とかって環境変数で変えることができそうなのでその辺と組み合わせて書き込みされないように防いでみる、とか、とかとか。

FreeBSDのsyslogがうまく動いていない

FreeBSDのsyslogがうまく動いていない。

現在syslogの集約サーバを立てているがそこへログが届かなくなっていた。

最初はサーバ側のエラーを疑っていたりしたが(実際サーバ側にも問題があった)、それでも複数のホストからログが届かない。

ログが届かないホストで調べてみた。


%/etc/rc.d/syslogd status
syslogd is not running.

なるほど、止まってる。


%sudo /etc/rc.d/syslogd start
Starting syslogd.
syslogd: child pid 390 exited with return code 1
/etc/rc.d/syslogd: WARNING: failed to start syslogd

起動させようとしても起動しない。

PIDファイルを調べると


%ls -lat /var/run/syslog*
-rw-r--r--  1 root  wheel  0 Feb 25 15:50 /var/run/syslogd.sockets

socketファイルは存在する。


%sockstat | grep syslog
root     syslogd    719   4  dgram  /var/run/log
root     syslogd    719   5  dgram  /var/run/logpriv
root     syslogd    719   6  udp6   *:514                 *:*
root     syslogd    719   7  udp4   *:514                 *:*

socketは利用されているらしい。


%ps auxww | grep 719
root     719  0.0  0.0  7024  1652  ??  Ss   25Feb11   0:14.45 /usr/sbin/syslogd -s
yousan   432  0.0  0.0  9092  1744   0  S+    9:19AM   0:00.00 grep 719

syslogdが走ってる。

/var/run/syslogd.pidファイルが存在しないけどsyslogdが走ってる状況に。なぜだろう。

手動でkillしてやる。


# sudo killall  syslogd
% ps auxww | grep syslogd
yousan   525  0.0  0.0  9092  1744   0  S+    9:21AM   0:00.00 grep syslogd

ちゃんと終了した。

で、再起動


%sudo /etc/rc.d/syslogd start
Starting syslogd.

どうやらうまくいったみたい。

FreeNASで一つのNICに二つ以上のIP addressを付与する

FreeNASで一つのNICに二つ以上のIP addressを付与する。

現在あるホストに192.168.52.214というアドレスを割り振っているが、(物理的に)同じセグメントにおいてあるマシンとのやりとりは、デフォルトゲートウェイを介さなければならない。

これは、一つのスイッチングハブに複数のL2のセグメント、例えばあるホストは192.168.0.1のアドレスであり、あるホストは192.168.1.1、ということだ。

普通はこんなことにしない。L2スイッチでつながれるのはブロードキャストドメインであるはずであり、各ブロードキャストドメインをつなぐのがルータの役割だからだ。

でもなんかなんとなく、こんな構成にしている。

でもここで問題がある。先述のホスト、192.168.0.1(ホストA)と192.168.1.1(ホストB)が通信するときにすべてお互いのデフォルトゲートウェイとなっているルータを介して通信してしまっていることだ。

これは実はルータを介さず直接通信することができるはず、である。

そのための手段は、

  1. デフォルトゲートウェイがICMPリダイレクトを送信して、それぞれのホストが直接macアドレスをホストA、ホストB宛てにしてやりとりする
  2. ルータからルーティング情報を広告する、もしくは各ホストにスタティックルートを書く。これでデフォルトゲーウェイに投げることなくarp解決を各自のホストで行ってもらう。
  3. arpプロキシでもいけるのかも・・・、しれない。いややっぱり無理っぽい

でもそれぞれには問題がある

  1. デフォルトゲートウェイにあるルータ(RT58i)がICMPリダイレクトを投げてくれない。またデフォルトではICMPリダイレクトを受け取らない(拒否する)ホストがある。
  2. ルーティング情報を設定するのが面倒。ルータから管理セグメント宛ての広告にしても、各ホストでRIPなどの待ち受け(例えばwindowsならRIPリスナ)の設定がたくさんひつようで面倒。静的ルーティングは構成変更とかあると大変そう、というか絶対漏れて通信できなくなってましたっていうホストがでてくる。

といったところでいろいろと躊躇していた。

ところで最近いろいろとホストが増えてきて、セグメント間のネットワーク利用率も高まり、いよいよ通信はルータがボトルネックになってきた。でもこれらのセグメントにはちょっとした特性があった。それは帯域を利用するホストがごく少数に限られていること、だ。

それぞれのセグメントにはそれぞれのデフォルトゲートウェイをおいて、ネットワークを司るサーバ(DNSとかnisとかメールとかwebとか。 dhcpはl2だったので統合されてしまった)がいるんだけど、そいつらへのアクセスが多い。ココで言う多いとはもう一方のセグメントからの通信、すなわちルータの帯域を使う通信が多い、ってことだ。

でも実は、多いといえども帯域的にはそこまで使ってなかった。だから今までそこまで問題視してなかった。所詮はDNSの問い合わせとかypとか、キャッシュされやすい項目だしまぁ許容範囲内だった。でもあるときから状況が変わってしまった。それはNAS/SANの導入だ

NASを導入したんだけどこれって結構お金がかかる。HDDとかマシン代とか。ついでに運営コストも結構こまめに設定いれると面倒だ。だから一元化してしまいたい、してしまった。これによりこのホストには同じ(論理)セグメントからの通信はもちろん、もう一方のセグメントからの通信量も増えてしまった。さてさてここでルータがいよいよ本格的にボトルネックになってしまった。

いよいよ上述の三つのうち、そろそろどれかを解決して直接通信させる必要がでてきたんだけど、ここでyubirdたんからアドバイスが。

「NIC二枚さして別のIP持たせればいいんじゃない?」

なるほど、頭いいです。それをやれば確かに現在の問題は解決する。万事オッケー。でもこれこれには投資が必要だ。

そこで横着な案を思いついた。一つのNICに複数のIPアドレスを設定すればよいのではないか・・・、と。

ところでこのNASはFreeBSDをベースとしたFreeNASで構築されている。中身はまぁFreeBSDだ。ということはFreeBSDでNICへ複数のIPアドレスを持たせてやれ(どうやらこれはエイリアスと呼ばれるらしい)ばよい。FreeBSDとなると情報源も一挙に広がるので対処しやすい。

さてそこでさっくりググって情報を漁る。さっくり見つかる。

rc.conf

ifconfig_lnc0=”inet 192.168.140.129 netmask 255.255.255.0″
ifconfig_lnc0_alias0=”inet 192.168.254.100 netmask 255.255.255.0″
ifconfig_lnc0_alias1=”inet 172.17.10.100 netmask 255.255.0.0″

設定終了後サーバの再起動等を行って設定を反映させます。
FreeBSD-複数IPアドレス設定(alias) — server-memo.net

なるほど、これなら自分にもできそうだ、ということで早速試してみる。とここで問題が。

FreeNASのrc.confってどうやら再起動ごとに書き換わってしまうみたい。ということで手動で(ifconfigをたたいて)できないか試すことになった。

まずは実験前の状態


# ifconfig
em0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
options=9b<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM>
ether 00:50:xx:xx:xx:xx
inet 192.168.0.1netmask 0xffffff00 broadcast 192.168.52.255
media: Ethernet autoselect (1000baseT <full-duplex>)
status: active

# ping 192.168.1.1
PING 192.168.1.1 (192.168.1.2): 56 data bytes
64 bytes from 192.168.1.2: icmp_seq=0 ttl=63 time=0.822 ms
64 bytes from 192.168.1.2: icmp_seq=1 ttl=63 time=0.568 ms

ここでTTLが63になっている。ちなみにICMPリダイレクトがくると二発目ぐらいから64とかになったりする。今回は見てても全然減らない。

tracerouteしてみると


# traceroute 192.168.1.1
traceroute to host002.l3tp.org (192.168.84.2), 64 hops max, 52 byte packets
1  192.168.0.254 (192.168.0.254)  0.703 ms  0.439 ms  0.407 ms
2  192.168.1.2 (192.168.1.2)  0.790 ms  0.470 ms  0.470 ms

やっぱりルータ経由みたい。

さてテキトウにmanみてaliasを与える。


# ifconfig em0 alias 192.168.1.1/24
# ifconfig
em0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
options=9b<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM>
ether 00:50:xx:xx:xx
inet 192.168.0.1 netmask 0xffffff00 broadcast 192.168.52.255
inet 192.168.1.1 netmask 0xffffff00 broadcast 192.168.84.255
media: Ethernet autoselect (1000baseT <full-duplex>)
status: active

なんか二行になったwwwうぇっうぇっ。こんなの始めてww。

aliasの後はinetをつけずにIPアドレスを記述。サブネットマスクはnetmask 255.255.255.0でもいいしCIDRでもいいらしい。

pingしてみる


# ping 192.168.1.2
PING 192.168.1.2 (192.168.1.2): 56 data bytes
64 bytes from 192.168.1.2: icmp_seq=0 ttl=64 time=0.870 ms
64 bytes from 192.168.1.2: icmp_seq=1 ttl=64 time=0.401 ms
64 bytes from 192.168.1.2: icmp_seq=2 ttl=64 time=0.308 ms

ちゃんとTTLが64のままだ。


# traceroute 192.168.1.2
traceroute to 192.168.1.2 (192.168.84.2), 64 hops max, 52 byte packets
1 192.168.1.2 (192.168.1.2)  2.449 ms  2.087 ms  0.701 ms

ばっちり。

さてここでaliasの解除してみる。解除のためには-aliasをつけるらしい。


# ifconfig em0 -alias 192.168.1.1

後ろのIPアドレスを指定しないとすべての関連づけ?されているIPアドレスがなくなってしまうので注意。DHCPで配られたアドレスすらなくしてしまった。

ひとまずこれで一つのNICに複数のIPアドレスをつけることができた。

方法は二つ、

  • rc.confにifconfig_em0_alias0=”inet 192.168.1.1″の形で書くこと
  • ifconfigのaliasオプションで設定してやること

これを使ってFreeNASに複数のIPアドレスを付与してみる。

中略

手動で与えて、他のホストからnetperfをかけてみる。


freenas%./netserver
Starting netserver at port 12865
Starting netserver at hostname 0.0.0.0 port 12865 and family AF_UNSPEC

client% netperf -H 192.168.0.1
TCP STREAM TEST from 0.0.0.0 (0.0.0.0) port 0 AF_INET to 192.168.0.1 (192.168.0.1) port 0 AF_INET
Recv   Send    Send
Socket Socket  Message  Elapsed
Size   Size    Size     Time     Throughput
bytes  bytes   bytes    secs.    10^6bits/sec

65536  32768  32768    9.93       91.26
client% netperf -H 192.168.1.1
TCP STREAM TEST from 0.0.0.0 (0.0.0.0) port 0 AF_INET to 192.168.1.1(192.168.1.1) port 0 AF_INET
Recv   Send    Send
Socket Socket  Message  Elapsed
Size   Size    Size     Time     Throughput
bytes  bytes   bytes    secs.    10^6bits/sec

65536  32768  32768    9.90      847.86

別セグメントからはおよそ91Mbp、同じセグメントからは850Mbps出た。

別セグメントだとルータを通過するのでそこのスループットで頭打ちになっているけど、同じセグメント扱いのときはワイヤスピード?にちかい850Mbpsが出た。ばっちりだ!

VMWareESXiのブート画面でESCキーが押せない

VMWareESXiのブート画面でESCキーが押せない。

これはどういうことかというと、VMWareで一度OSなどをインストールするとブートシーケンスがHDDになっちゃう。

一度OSを入れ直した後、CDからブートしてOSを入れ直したいよ~、とか、アップデートでOSから起動する必要があるねん、といった状況がある。

ESXiの仮想マシンはほぼ完全なマシンを仮想化してるのでちゃんとBIOSもあるしその上でブートシーケンスも決まる。CDからブートするためにはBIOS画面に入ってブートシーケンスのCDの優先度を上げてやる必要があるのだ。

でBIOSへの入り方なんだけど、VMWareのロゴが出ているときにESCを押すらしい。でもこれがめっちゃ早い。とても手では無理でした。

そこで仮想マシンの設定画面を開き、そこから次回起動時にBIOS画面に強制的に入らせるためのチェックボックスがある。

ココをonにすると次回めでたくBIOS画面へ入ることができる。

強制的にBIOS設定画面に入らせるモードのチェック
強制的にBIOS設定画面に入らせるモードのチェック

このやり方で今回はめでたくCDから仮装マシンをブートすることができた。

 

ちなみに同じ設定画面には起動するときの遅延時間をmsで指定でき、この間にBIOSへ入ることもできる。

頻繁にBIOS画面を見る必要があるならばそちらのオプションを利用する、というのもいいのかもしれない。

(でもCDブートだったらブートシーケンスを変えておいてCDのイジェクトで対応するってほうがいいのかも、しれない)

 

osc tokyo sprint 2011に参加しています

osc tokyo sprint 2011に参加しています。

PHPでDTraceしようってのに参加しています。

  • OpenSolarisいいよね
  • デーモン監視とかあるし
  • メモリダンプ?やりやすいし

phpの利用方法について

  • mod_php
  • fcgi
  • 独自でfork…

apacheのpreforkについて

メモリを徐々に食い尽くすよね

  • topしたときのSIZEってforkで共通の部分あるよね(ライトオンメモリーだっけ?コピーオンライト)
  • 個別にメモリについて見るコマンドがあるよ~
  • RSSが共通の領域?
  1. 10MBのファイルをphpで読むコードを書いておく
  2. それをapacheでアクセスしてみる
  3. topで見ている -> うひょー

キープアライブがあるので同じchildrenが同じクライアントを担当しそうね

memory_limitが数Mならいいけど、数十Mだとやばいよね

shrink(一定時間経過したらメモリをきれいにしてくれたりするけど、意外にapacheはきれいにしてくれない)

いろんな理由でどこが遅いか分からないコードってあるよね

dtoolkit使ってみよう

inclusive elassped timeと exclusive elassped timeについて

inclusiveは外が絶対でかい、exclusiveはその関数だけ、でかかった時間

php_malloc, php_syscall

pfexecとPIDを指定するとsyscallの数を調べることができる

php_who