2012-06-27

Slony-I: duplicate key value violates unique constraint "sl_nodelock-pkey", part 2


Slony-I(slon)が起動しなくなることがある。ログには、

2012-05-16 14:08:46.60711 FATAL  localListenThread: "select "_slony1".cleanupNodelock(); insert into "_slony1".sl_nodelock values (    1, 0, "pg_catalog".pg_backend_pid()); " - ERROR:  duplicate key value violates unique constraint "sl_nodelock-pkey"

こうなった時の復旧方法は、以前のエントリーを参照。


以前から年に一回くらい起こっていたが、サーバー再起動で復旧した後はパッタリ起こらなくなるため、そのうち(Slony-I 側で)直るだろうと気楽に考えていた。しかしいくら待っても一向に直る気配が無く、もういい加減に我慢ならなくなったので、ようやく重い腰を上げて調べることにした。

結果から先に言うと、Apache, PostgreSQL での already running 現象と原因は同じ。これらの詳細については以前のエントリーを参照。


ソースコードでは次の部分。(Slony-I 2.0.7 以降は使ってないので知らない)

slony1-2.0.6/src/backend/slony1_funcs.sql:

create or replace function @NAMESPACE@.cleanupNodelock ()
returns int4
as $$
declare
    v_row        record;
begin
    for v_row in select nl_nodeid, nl_conncnt, nl_backendpid
            from @NAMESPACE@.sl_nodelock
            for update
    loop
        if @NAMESPACE@.killBackend(v_row.nl_backendpid, 'NULL') < 0 then
            raise notice 'Slony-I: cleanup stale sl_nodelock entry for pid=%',
                    v_row.nl_backendpid;
            delete from @NAMESPACE@.sl_nodelock where
                    nl_nodeid = v_row.nl_nodeid and
                    nl_conncnt = v_row.nl_conncnt;
        end if;
    end loop;

    return 0;
end;
$$ language plpgsql;

killBackend(v_row.nl_backendpid, 'NULL') の結果が負になればロックが削除される。killBackend の実装は C で書かれていて、

slony1-2.0.6/src/backend/slony1_funcs.c:

Datum
_Slony_I_killBackend(PG_FUNCTION_ARGS)
{
    int32        pid;
    int32        signo;
    text       *signame;

    if (!superuser())
        elog(ERROR, "Slony-I: insufficient privilege for killBackend");

    pid = PG_GETARG_INT32(0);
    signame = PG_GETARG_TEXT_P(1);

    if (VARSIZE(signame) == VARHDRSZ + 4 &&
        memcmp(VARDATA(signame), "NULL", 0) == 0)
    {
        signo = 0;
    }
    else if (VARSIZE(signame) == VARHDRSZ + 4 &&
             memcmp(VARDATA(signame), "TERM", 0) == 0)
    {
        signo = SIGTERM;
    }
    else
    {
        signo = 0;
        elog(ERROR, "Slony-I: unsupported signal");
    }

    if (kill(pid, signo) < 0)
        PG_RETURN_INT32(-1);

    PG_RETURN_INT32(0);
}

第二引数が "NULL" だと kill -0 が実行される。よってこの関数の返値は、プロセスが存在すれば 0、存在しなければ -1 となる。結果として、プロセスが存在すれば二重起動と見なされてロックは残り、存在しなければロックは削除される。そのプロセスが slon であるかは関係ない

これは Apache と同じロジックだ。その結果も同じく、slon が起動しなくなる。しかし、slon は Apache よりも重大な問題を抱えている。

  1. slon は正常終了時であってもロックを削除しない
  2. ロックは DB 中にあるため、サーバー再起動では削除されない。

この合わせ技はかなり凶悪だ。想像してみよう。サーバーを再起動したとする。slon は正常終了するがロックは残ったままだ。次回 slon 起動時、ロック(sl_nodelock)に残っている PID を持つプロセスが存在しなければ slon は起動する。

怖すぎる。いくらサーバー起動時のプロセス起動順は滅多に変わらないと言っても、これでは「起動する方が運が良い」と言った方が合っている。今まで知らずに slon を普通に起動していたかと思うと、背筋が寒くなる。

まさか Slony-I がこんなお粗末な二重起動チェックを行っているとは思わなかった。信じてたのに。せめてエラーログがもっと分かり易ければ早くに気付けたが、duplicate error でそれに気付けというのは難度が高過ぎだろう。

ということで、やはり起動スクリプトでロックを削除することになる。ロックの削除は、例えばこんな感じ。

DBHOST=localhost
DBUSER=postgres
DBNAME=testdb
CLUSTER=slony1

cleanup_local_nodelock() {
    echo 'cleanup sl_nodelock entry for local node'
    psql -h $DBHOST -U $DBUSER -d $DBNAME <<EOF
DELETE FROM _$CLUSTER.sl_nodelock
 WHERE nl_nodeid = (SELECT _$CLUSTER.getLocalNodeId('_$CLUSTER'))
   AND nl_conncnt = 0;
EOF
}

当然、ロックを削除する前には自力で二重起動をチェックする必要がある。この辺は起動スクリプトの内容に依存するため、各自で頑張って実装して欲しい。私の知る限りでは Slony-I には 2 つの起動スクリプト(redhat/slony1.init, tools/start_slon.sh)が同梱されているし、他の起動スクリプトを使っていることも多いだろう。私の場合は、例によって runit なので(略)。

さて、今回までの一連(Apache, PostgreSQL, Slony-I)から得られた教訓は、

標準の二重起動チェックを信用するな。

PID ファイルを使って二重起動チェックを行うものは多いが、もし重要なサービスがあるなら、起動中のプロセスの PID を使って PID ファイルを偽造してみて、サービスが起動するかどうか確認してみることをお勧めする。(今回の Slony-I の事例には役に立たないが)

2012-06-15

PostgreSQL: lock file "postmaster.pid" already exists


PostgreSQL が起動しなくなることがある。ログには、

2012-06-15 09:52:59 GMT  [6133]: FATAL:  lock file "postmaster.pid" already exists
2012-06-15 09:52:59 GMT  [6133]: HINT:  Is another postmaster (PID 2225) running in data directory "/var/lib/pgsql/data"?

原因は Apache のときと同じ。


ソースコードでは次の部分。(PostgreSQL 9.0 以降は使ってないので知らない)

postgresql-8.4.11/src/backend/utils/init/miscinit.c:

static void
CreateLockFile(const char *filename, bool amPostmaster,
               bool isDDLock, const char *refName)
{

    /* snip... */

        /*
         * Check to see if the other process still exists
         *
         * If the PID in the lockfile is our own PID or our parent's PID, then
         * the file must be stale (probably left over from a previous system
         * boot cycle).  We need this test because of the likelihood that a
         * reboot will assign exactly the same PID as we had in the previous
         * reboot.    Also, if there is just one more process launch in this
         * reboot than in the previous one, the lockfile might mention our
         * parent's PID.  We can reject that since we'd never be launched
         * directly by a competing postmaster.    We can't detect grandparent
         * processes unfortunately, but if the init script is written
         * carefully then all but the immediate parent shell will be
         * root-owned processes and so the kill test will fail with EPERM.
         *
         * We can treat the EPERM-error case as okay because that error
         * implies that the existing process has a different userid than we
         * do, which means it cannot be a competing postmaster.  A postmaster
         * cannot successfully attach to a data directory owned by a userid
         * other than its own.    (This is now checked directly in
         * checkDataDir(), but has been true for a long time because of the
         * restriction that the data directory isn't group- or
         * world-accessible.)  Also, since we create the lockfiles mode 600,
         * we'd have failed above if the lockfile belonged to another userid
         * --- which means that whatever process kill() is reporting about
         * isn't the one that made the lockfile.  (NOTE: this last
         * consideration is the only one that keeps us from blowing away a
         * Unix socket file belonging to an instance of Postgres being run by
         * someone else, at least on machines where /tmp hasn't got a
         * stickybit.)
         *
         * Windows hasn't got getppid(), but doesn't need it since it's not
         * using real kill() either...
         *
         * Normally kill() will fail with ESRCH if the given PID doesn't
         * exist.
         */
        if (other_pid != my_pid
#ifndef WIN32
            && other_pid != getppid()
#endif
            )
        {
            if (kill(other_pid, 0) == 0 ||
                (errno != ESRCH && errno != EPERM))
            {
                /* lockfile belongs to a live process */
                ereport(FATAL,
                        (errcode(ERRCODE_LOCK_FILE_EXISTS),
                         errmsg("lock file \"%s\" already exists",
                                filename),
                         isDDLock ?
                         (encoded_pid < 0 ?
                          errhint("Is another postgres (PID %d) running in data directory \"%s\"?",
                                  (int) other_pid, refName) :
                          errhint("Is another postmaster (PID %d) running in data directory \"%s\"?",
                                  (int) other_pid, refName)) :
                         (encoded_pid < 0 ?
                          errhint("Is another postgres (PID %d) using socket file \"%s\"?",
                                  (int) other_pid, refName) :
                          errhint("Is another postmaster (PID %d) using socket file \"%s\"?",
                                  (int) other_pid, refName))));
            }
        }

ちょっと長いが、全てはコメント部に書いてある。やはり PID ファイルにあるプロセスの存在をチェックしているが、Apache との違いはプロセスの所有者まで見ていること。プロセスの所有者が異なれば、二重起動とは見なさない。

PostgreSQL が postgres ユーザーで起動するようになっている場合、postgres ユーザーで起動するプロセスは基本的に PostgreSQL しか無いはず。故に PostgreSQL を複数起動しているのでもない限り、この現象に遭遇することはまず無い。私の場合、PostgreSQL を起動している runit の logger プロセス(svlogd)とバッティングしたため、運良く:-)この現象に遭遇した。

PostgreSQL を複数起動させたり、postgres ユーザーで他にもプロセスを起動させているのであれば、Apache の時と同じく起動スクリプトで PID ファイルを削除するようにした方が良いだろう。

その場合、やはり二重起動チェックを自力で行うことになるが、pg_ctl status はその用途には役に立たない(たぶん上記のコードを通るのだと思われる)。その代わり PostgreSQL は $PGDATA が一意となるので、プロセスのコマンドラインや環境変数を見る(/proc/<PID>/{cmdline,environ})と良いかも知れない。

例によって私は runit を使っていて二重起動チェックとは無縁なので、実際に動くコードは載せられない。

2012-06-11

Apache: httpd (pid ####) already running


Apache が起動しなくなることがある。

# /usr/local/apache2/bin/httpd -k start
httpd (pid 2369) already running

大抵はサーバー再起動で復旧するが、運が悪いと何度再起動しても復旧しなくなる。

ソースコードでは次の部分。(Apache 2.4 は使ってないので知らない)

httpd-2.2.22/server/mpm_common.c:

int ap_signal_server(int *exit_status, apr_pool_t *pconf)
{
    apr_status_t rv;
    pid_t otherpid;
    int running = 0;
    const char *status;

    *exit_status = 0;

    rv = ap_read_pid(pconf, ap_pid_fname, &otherpid);
    if (rv != APR_SUCCESS) {
        if (rv != APR_ENOENT) {
            ap_log_error(APLOG_MARK, APLOG_STARTUP, rv, NULL,
                         "Error retrieving pid file %s", ap_pid_fname);
            ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
                         "Remove it before continuing if it is corrupted.");
            *exit_status = 1;
            return 1;
        }
        status = "httpd (no pid file) not running";
    }
    else {
        if (kill(otherpid, 0) == 0) {
            running = 1;
            status = apr_psprintf(pconf,
                                  "httpd (pid %" APR_PID_T_FMT ") already "
                                  "running", otherpid);
        }
        else {
            status = apr_psprintf(pconf,
                                  "httpd (pid %" APR_PID_T_FMT "?) not running",
                                  otherpid);
        }
    }

PID ファイルに書かれている PID へ kill -0 が成功すれば、つまりプロセスが存在すれば、already running となる。該当プロセスが Apache であるかは関係ない。通常、PID ファイルは Apache 停止時に削除されるが、SIGKILL やサーバーリセットなどで Apache が死ぬと PID ファイルが残る。

ソースからビルドしている場合、PID ファイルの場所を /var/run 下などに変更していない限り、サーバーを再起動しても PID ファイルは消えない。故に、運が悪いと何度サーバーを再起動しても復旧しなくなる。サーバー起動時のプロセス起動順なんて、そうそう変わらないからだ。(尤も、Upstart や Systemd で殆んどのプロセスが並列起動するようになっていれば、この限りではないかも知れない)

要は PID ファイルを消しさえすれば復旧するのだが、システムが客先にあってコマンドを叩ける人が居ない場合など、サーバー再起動で復旧しないのは致命的だ。

これがパッケージインストールした Apache の場合だと少し違って、例えば RHEL6 だと、

# service httpd start
Starting httpd:

起動スクリプト中で処理が止められるため already running とは出ないが、やはり起動に失敗する。但し、こちらはサーバーを再起動すれば確実に復旧する。パッケージインストールした Apache の PID ファイルは、例えば RHEL6 なら /var/run/httpd/httpd.pid になるが、/var/run 下はサーバー起動時に必ず削除されるからだ。

最悪はサーバー再起動で復旧しさえすれば何とかなるが、欲を言えば Apache の再起動だけで復旧して欲しい。つまり、Apache の起動前に PID ファイルを削除するようにすれば良い。具体的には、Apache の起動スクリプトでゴニョゴニョすることになるだろう。

気を付けるとすれば、この挙動(already running)自体が二重起動を防止する機構なので、PID ファイルを消す前に自力で二重起動をチェックする必要がある。RHEL なら /etc/init.d/function 中の status 関数、更に言えばその中の __pids_pidof 関数が使えそうだが、Apache なら単純にポート 80 が LISTEN されているか調べる方が簡単かも知れない。但し、いずれの場合も実際に私はやったことが無いので、コードは載せられない。

私自身は runit を使っているため、二重起動のチェックはそれこそ runit の仕事。runit が起動スクリプト(run)を実行する時点で二重起動でないことが保証されるので、単に起動スクリプトの先頭で rm -f pidfile すれば良いだけ。今まで runit には苦労させられてきたから、こんな時くらい楽させて貰わないと :-)。

2012-06-01

Apache: not `reload' but `graceful' when logrotate


RHEL で Apache をパッケージインストールすると、logrotate 設定は次のようになる。

RHEL6.2: /etc/logrotate.d/httpd:

/var/log/httpd/*log {
    missingok
    notifempty
    sharedscripts
    delaycompress
    postrotate
        /sbin/service httpd reload > /dev/null 2>/dev/null || true
    endscript
}

これで負荷試験を行うと、logrotate 時に接続が切れてクライアント側でエラーになる。Apache 起動スクリプトの実装を見てみると、

RHEL6.2: /etc/init.d/httpd:

reload() {
    echo -n $"Reloading $prog: "
    if ! LANG=$HTTPD_LANG $httpd $OPTIONS -t >&/dev/null; then
        RETVAL=6
        echo $"not reloading due to configuration syntax error"
        failure $"not reloading $httpd due to configuration syntax error"
    else
        # Force LSB behaviour from killproc
        LSB=1 killproc -p ${pidfile} $httpd -HUP
        RETVAL=$?
        if [ $RETVAL -eq 7 ]; then
            failure $"httpd shutdown"
        fi
    fi
    echo
}

普通に HUP を送っている。HUP を受けると Apache は即座に子プロセスを再起動するので、クライアントの接続が切れるのは当たり前。少なくとも、logrotate 時は graceful reload するべきだろう。

    postrotate
        /sbin/service httpd graceful > /dev/null 2>/dev/null || true
    endscript

参考までに Ubuntu 12.04 を見ると、RHEL と同様に logrotate では reload しているが、起動スクリプトの reload の実装が graceful を呼ぶようになっているので問題ない。

RHEL と言えども過信は禁物。