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"

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

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

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

Slony-I は、ファイルではなくデータベース(sl_nodelock テーブル)に PID を保存する。そして、slon 起動時にその cleanup 処理を行っている。ソースコードでは次の部分。(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') の結果が負になれば、行が delete される。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);
}

第 2 引数が "NULL" だと kill -0 が実行される。よってこの関数の返値は、プロセスが存在すれば 0、存在しなければ -1 となる。そのプロセスが slon であるかは関係ない。その結果、プロセスが存在すると sl_nodelock に行が残り、その後 slon が自身の PID を insert する際に duplicate error が発生することになる。

これは Apache httpd と同じロジックだ。しかし、Slony-I は httpd よりも 重大な問題 を抱えている。

  • slon は、例え正常終了であっても、終了時にロックを削除しない。
  • ロックはデータベース内にあるため、サーバー再起動では決して削除されない。

この合わせ技はかなり凶悪だ。想像してみよう。サーバーを再起動したとする。slon は正常終了するがロックは残ったままだ。次回 slon 起動時、ロックに残っている 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 httpd, PostgreSQL, Slony-I)から得られた教訓は、

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

PID ファイルを使って二重起動チェックを行うものは多いが、もし重要なサービスがあるなら、存在するプロセスの PID で PID ファイルを偽造してみて、サービスが起動するかどうか確認してみることをお勧めする。

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 httpd の時と同じ。

ソースコードでは次の部分。(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 ファイルにあるプロセスの存在をチェックしているが、httpd との違いはプロセスの所有者まで見ていること。プロセスの所有者が異なれば、二重起動とは見なさない。

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

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

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

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

2012-06-11

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

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

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

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

ソースコードでは次の部分。(httpd 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 となる。そのプロセスが httpd であるかは関係ない。通常、PID ファイルは httpd 停止時に削除されるが、SIGKILL やサーバーリセットなどで httpd が死ぬと、PID ファイルは残ったままになる。

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

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

これがビルドではなくパッケージインストールした httpd の場合だと現象が違って、例えば RHEL6 だと、

# service httpd start
Starting httpd:

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

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

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

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

2012-06-01

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

RHEL で Apache httpd パッケージをインストールすると、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 時に接続が切れてクライアント側でエラーになる。httpd 起動スクリプトの実装を見てみると、

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 を受けると httpd は即座に子プロセスを再起動するので、クライアントの接続が切れるのは当たり前。少なくとも、logrotate 時は graceful reload するべきだろう。

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

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

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