Author Archive

    はてなブックマーク - PostgreSQLのログをデバッグに活用しよう
    このエントリーをはてなブックマークに追加

    はじめての人もそうでない人もはじめまして。河野と申します。

    Advent Calendar も中頃、私は3回目に突入しました。

    さて、本日は「PostgreSQLのログをデバッグに活用しよう」というお話を皆様にしたいと思います。

    ログを見る前に

    さっそくログを見ていきたいところですが、まずはログの出力が行われているか確認します。
    ログの出力先はOSやサーバによって違うかと思いますが、今回は以下のように設定されているものとします。

    postgresql.conf

    
    #log_destination = 'stderr'
    redirect_stderr = on
    log_directory = 'pg_log'
    log_filename = 'postgresql-%a.log'
    log_truncate_on_rotation = on
    log_rotation_age = 1440
    log_rotation_size = 0
    
    

    ざっくり言うと…

    標準出力にログを吐き出し、吐き出されたログは pg_log 以下の postgresql-曜日.log へ保存。
    ログは 1日ごとにローテーションするという設定です。

    ざっくりすぎま…せんよね?

    ちなみに「log_destination」を syslog に設定することで syslog を利用する事が可能ですが、メッセージの一部が syslog では出力されない可能性があるため信頼性は高くありません。

    Linux であれば基本的に「log_destination」を stderr に。
    「redirect_stderr」を on に設定して PostgreSQL にログローテーションまで任せましょう。

    何を出力するか

    さっそくログを見ていきたいところですが、まずは何を出力するか設定します。
    デバッグに役立つ設定値をかいつまんで、紹介差し上げたいと思います。

    ● エラーのSQLを記録

    SQLにエラーが発生した場合、エラーとなったSQLをログに出力したい時、以下の設定を error に設定することでログに保存できます。
    開発中やテスト時には error に設定を変更する事をおすすめします。

    私のサーバではデフォルトで panic となっていました。
    これはエラー時もログを出力しない設定となります。

    
    #log_min_error_statement = panic
    
    

    ● 時間のかかるSQLを記録

    複雑なSQLやインデックスの貼り忘れ、テーブルの結合など、色々な条件が原因でレスポンスがなかなか帰って来ないことがあります。
    その原因となったSQLを知りたい場合は「log_min_duration_statement」の設定をしましょう。

    デフォルトでは -1 無効となっています。
    ここの設定値はミリ秒単位ですので30秒ならば 30000 と設定しましょう。

    
    #log_min_duration_statement = -1
    
    

    データが少ない開発時より、運用されてからこの設定が生きてくることもあるかと思います。

    ● クライアントからの接続・切断を記録

    ひとつのデータベースを複数のアプリケーションで参照する場合、以下の設定を行っておくと接続元のIPが記録されるため、どこからの接続が多いかがログから判断できます。

    デフォルトでは off となっています。
    有効にする場合は on に設定してください。

    
    #log_connections = off
    #log_disconnections = off
    
    

    もし PostgreSQL の最大接続数に達するほど接続数が増えている場合は、安易に max_connections を増やさずにログを見てから判断しましょう。

    ● すべてのSQLを記録する

    とにかく全てのSQLを記録したい。
    レガシーなプログラムのデバッグでは有用になってくるかもしれない設定です。

    そのようなプログラムのデバッグをせねばならない状況…お察しします。
    この設定値で頑張ってください!

    デフォルトでは none となっています。
    全て出力したい場合は all と設定してください。

    
    #log_statement = 'none'
    
    

    PostgreSQLのログをデバッグに活用しよう

    いかがでしたでしょうか?
    データベース設計や運用・保守はメインではない(とお考えの)開発者ですとデータベースのログを見ることはあまり無いのではと思います。
    とくに最近のフレームワークはいい具合にSQLのログなどを出力してくれる為、開発中は見なかったなんて方もいるかも…。

    ログは運用されてから発生してくる問題の原因究明にこそ役立ちます(だから開発中見なかったはダメw)

    さて、ログの設定は終わりましたか?
    では、さっそくログを見ていきましょう!

      はてなブックマーク - サービスは止まっていないのにネットワークエラーが・・・なぜ?
      このエントリーをはてなブックマークに追加

      奥さまの名前は CentOS、旦那さまの名前はしんちゃん。
      ごく普通のサーバに、ごく普通にインストールし、ごく普通の納品をしました。
      でも、ただひとつ違っていたのは、ifconfig を叩くと………エラーが発生していたのです!

      *・゜゚・*:.。..。.:*・゜゚・*:.。. (n‘∀‘)η

      はじめての人もそうでない人もはじめまして。 河野と申します。

      Advent Calendar はスタートの火蓋が切られたばかりにも関わらず、私だけが二週目に突入しました。
      マッハ号もかくやといったところです。

      さて、本日は「サービスは止まっていないのにネットワークエラーが増え続ける」という奇妙な問題を解決した際のお話を皆様にしたいと思います。

      尚、サーバはCentOS となります。

      エラーの増加

      サンプルに偏りがあるのを承知で言いますが「サービスは止まっていないのにネットワークエラーが増え続ける」。
      そういった事象はあまり無いのではないかと思われます。
      ネットワークにエラーがある場合は、サービスどころかネットワーク自体が疎通出来なくなる事が多いのではないでしょうか?

      ところが今回のエラーは以下のような特徴を持っていました。

      • リモートからサーバへのアクセスが可能
      • ローカルから外部へのアクセスが可能
      • パケットのエラーが増え続ける

      エラー発生当初、サービスに支障が出ていないので、今後の経過を見るという判断になりました。

      このサーバには Munin というサーバ動作ログを視覚的に閲覧することの出来るソフトウェアをインストールしていたのですが、見るたびにサーバのエラーは増えていきました。

      # ifconfig
      eth0      Link encap:Ethernet  HWaddr 00:03:0D:34:8F:AD
                inet addr:10.1.0.1  Bcast:10.255.255.255  Mask:255.0.0.0
                inet6 addr: fe80::203:dff:fe34:8fad/64 Scope:Link
                UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
                RX packets:5505120 errors:869 dropped:0 overruns:0 frame:869
                TX packets:563000 errors:0 dropped:0 overruns:0 carrier:0
                collisions:30 txqueuelen:1000
                RX bytes:900322789 (858.6 MiB)  TX bytes:102707436 (97.9 MiB)
                Interrupt:209 Base address:0xd800

      ※ ↑は執筆時に仮想サーバにてエラーを発生させてみたものです

      問題の調査

      色々と調査した結果、Auto-Negotiation 機能に問題があるのではないかという結論に至りました。

      ethtool コマンドで eth0 を調査した結果 half-duplex(半二重)になっていたからです。

      # ethtool eth0
      Settings for eth0:
              Supported ports: [ TP MII ]
              Supported link modes:   10baseT/Half 10baseT/Full
                                      100baseT/Half 100baseT/Full
              Supports auto-negotiation: Yes
              Advertised link modes:  10baseT/Half 10baseT/Full
                                      100baseT/Half 100baseT/Full
              Advertised auto-negotiation: No
              Speed: 100Mb/s
              Duplex: Half
              Port: MII
              PHYAD: 1
              Transceiver: internal
              Auto-negotiation: off
              Supports Wake-on: pg
              Wake-on: d
              Current message level: 0x000000c5 (197)
              Link detected: yes

      このサーバの eth1 はバックアップ装置と直繋ぎしておりこちらの通信モードは full-duplex(全二重)に設定されています。

      この結果から eth0 と繋がれているスイッチが full-duplex 固定に設定されており Auto-Negotiation 設定時に通信モードを返さなかった為、デフォルトの半2重設定を行ったと考えられました。

      問題の解決

      そうと分かればサーバ側の eth0 の設定を full-duplex 固定にしてしまえばいいだけの話です。

      ローカル環境で確認後、本番で行なった変更は ifcfg-eth0 の最後に以下の一文を加えるだけ。

      # vim /etc/sysconfig/network-scripts/ifcfg-eth0
      ETHTOOL_OPTS="autoneg off speed 100 duplex full"

      但し、ネットワークリスタートする必要があります。

      ちなみに eth-tool コマンドでも設定可能です。

      ● eth0 の autonegotiation を off

      # ethtool -s eth0 autoneg off

      ● eth0 の duplex を full にする

      # ethtool -s eth0 duplex full

      こちらは再起動を行なうと設定が消えますので、再起動後も設定を反映する場合は上記のようにデバイスの設定ファイルに設定を記述してください。

      最後に

      今回一番困ったのは「利用者からは問題がないように見える」点です。
      無視するわけにもいかないが、無視できる範囲のエラーなので、システムを停止することが難しいサーバや、社内システムだと止めるほどでも無いかもしれません。

      今回のエラーはサーバを設置してすぐだったため、トラフィックが増えてエラーが無視できなくなってくる前に対応する事にしました。

      どういったエラーでも対応すべきか、無視できるかは熟慮・検討する必要があるかと思いますが、今回のエラーは判断に迷う内容でした。

      結論からするとエラーは対応すべきものと私は思います。 が、技術的視点以外からの判断が加わってくると対応しないという結論もあるかもしれませんね。

        はてなブックマーク - PostgreSQL の VACUUM をなんとなくでするのはやめよう
        このエントリーをはてなブックマークに追加

        はじめての人もそうでない人もはじめまして。 河野と申します。

        いきなりすいません・・・。

        私の名前をさっそく覚えていただいた方には申し訳ないのですが、
        弊社にはもう一人河野というものがおり、そっちとは違う方と覚えて頂けると溜飲が下がります…。

        さて、今回 Fusic Advent Calendar の一番槍として最初に寄稿させて頂くことになりました。

        本日はお題の通り PostgreSQL の VACUUM をなんとなくでするのはやめようという提案を、全国 4,000万の VACUUM ファンの皆様にしたいと思います。

        尚、PostgreSQLの対応バージョンは 8.3 以降となります。

        PostgreSQL のメンテナンスと VACUUM

        データベースに PostgreSQL を採用している会社はどのくらいあるのでしょう?
        オープンソースのデータベースでは MySQL が多く採用されているイメージがありますが、弊社では以前より PostgreSQL を使用しシステム開発を行なっています。

        そんなこんなで PostgreSQL のメンテナンス業務などで VACUUM を実行する場面が私は何度かあるのですが、同じようにメンテナンスをされてる皆様は漫然と VACUUM を実行していませんでしょうか?

        VACUUM とは不要になった領域の回収を行うコマンドです。
        PostgreSQL は追記型のデータベースのためレコードの削除時はもちろん、更新時にも不要な領域が溜まっていきます。
        不要な領域が溜まっていくと、データベースのパフォーマンスが落ちていきます。
        そうなる前に PostgreSQL 好きの皆さんは VACUUM を実行してパフォーマンスをあげたいなと思いますよね?

        でも、ちょっと待って!
        あなたが VACUUM を実行するその時、それが VACUUM のタイミングなのでしょうか?

        VACUUM 前にチェック! 不要領域はどれぐらいあるの?

        PostgreSQL 8.3 からは、不要になった領域をSQLで確認することが可能となりました。
        ここでは pgAdmin を使って不要な領域、デッドタプルを確認したいと思います。

        データベースに接続して…テーブルを選んで…統計情報タブを選択する…以上。

        簡単ですね。 これで不要な行がどの程度あるのか確認することが可能です。
        23699行のデッドタプルがあることが分かりました。

        このテーブルの有効タプルが 454340行 そのうち 23699 行が不要なデッドタプルです。
        有効タプルに対して大体 5% が不要な領域として使用されている事がわかります。

        ちなみにSQLではこのように…。

        
        SELECT
            relname, n_live_tup, n_dead_tup, round(n_dead_tup*100/n_live_tup,2) AS ratio
        FROM
            pg_stat_user_tables WHERE relname = 'テーブル名';
        
         relname | n_live_tup | n_dead_tup | ratio
        ------------+------------+------------+-------
         テーブル名 |     454340 |      23699 |  5.00
        

        実際に確認してみますと、更新の多いテーブルほど n_dead_tup デッドタプルが多いことが分かるかと思います。
        そのデッドタプルが多く有効なレコードに対する割合の多いテーブルほど VACUUM すべきなのです!

        VACUUM を行ないましょう

        5%程でしたら VACUUM を実行するほどではないかもしれませんw
        (統計情報の更新や btree インデックスの不要領域の回収も行なうため実行した方がよいです。)
        むしろこのエントリーの本題は先ほどの”確認する”という部分なので、後はおまけみたいなものなのですが…
        VACUUM を実行してすっきりしたテーブルを見て心までまですっきりするために VACUUM を行なってみましょう。

        ここでも pgAdmin を利用して VACUUM を実行してみましょう。

        テーブルを右クリックしてメンテナンスを選択…VACUUMにラジオのチェックが入っているのを確認したらOKボタン…以上。

        SQLでは以下のようになります。

        VACUUM テーブル名;

        簡単ですね?
        デッドタプルが無くなり不要領域が回収されています。

        VACUUM をなんとなくでするのはやめよう

        如何でしたでしょうか?
        不要領域を回収するから、パフォーマンスが回復するからという理由で漫然と行なってきた VACUUM。

        これからは VACUUM を実行する前に、デッドタプルがあるか確認してください。
        そしてデッドタプルが多く、有効なレコードに対するデッドタプルの割合の多いテーブルに VACUUM をするようにしてみてください。

        このようなデータベースの状況の確認・把握するのは管理・メンテナンスを行なう者にとって重要なことです。
        なんとなく行なってきた VACUUM が明日からは ハッキリ とした理由で行なうことができます。

        VACUUM ファンの皆様なら分かってくれますよね?