RHEL6.3: rsyslog no longer supports `reload'

自作インストーラーが RHEL6.3 から動かなくなった。調べると、rsyslog reload が失敗している。

[rhel63]# service rsyslog reload ; echo $?
3

• Red Hat Bugzilla - Bug 718403: rsyslog-5.8.2-1.fc15.i686 init script fails reload

上記には、「rsyslog は reload をサポートしなくなったから代わりに restart を使ってね」とあるが、それだけ言われても釈然としない。しかし実は、以前から身近なところに答えはあった。

[rhel62]# man rsyslogd

SIGNALS
       <...snip...>

       HUP    This  lets rsyslogd perform close all open files.  Also, in v3 a
              full restart will be done in order to read changed configuration
              files.   Note  that  this means a full rsyslogd restart is done.
              This has, among others, the consequence that TCP and other  con-
              nections  are  torn down. Also, if any queues are not running in
              disk assisted mode or are not set to persist data  on  shutdown,
              queue  data  is  lost. HUPing rsyslogd is an extremely expensive
              operation and should only be done when actually necessary. Actu-
              ally,  it  is a rsyslgod stop immediately followed by a restart.
              Future versions will remove this restart  functionality  of  HUP
              (it  will  go  away in v5). So it is advised to use HUP only for
              closing files, and a  "real  restart"  (e.g.  /etc/rc.d/rsyslogd
              restart) to activate configuration changes.

何か未来を予見してたような manpage 出た。「HUP で設定を再読み込みする機能は v5 から無くなるんだからね!」とのこと。どうやらこれは今更の話ではなく、rsyslog かねてよりの固い意志だったらしい。HUP 時に設定を再読み込みする $HUPisRestart という設定項目も、v5 になって消えたようだ。

• rsyslog.com: Compatibility Notes for rsyslog v5: HUP processing

The $HUPisRestart directive is supported by some early v5 versions, but has been removed in 5.1.3 and above.

ちなみに RHEL6.2 → RHEL6.3 でパッケージバージョンを比べると、

[rhel62]# rpm -q rsyslog
rsyslog-4.6.2-12.el6.x86_64

[rhel63]# rpm -q rsyslog
rsyslog-5.8.10-2.el6.x86_64

同じ RHEL6 中でパッケージのメジャーバージョンが上がるのって反則じゃね? 全ての元凶はここにある気がするのだが。

ともかく、ここに至ってようやく前述の Bugzilla での議論が理解できる。

• Fedora Project Wiki: Packaging: SysVInitScript: Required Actions

reload: reload the configuration of the service without actually stopping and restarting the service (if the service does not support this, do nothing)

reload の定義は、「サービスを再起動することなく設定を再読み込みする」となっている。つまり、もはや rsyslog v5 の initscript には reload を実装する術がない。reload をサポートしなくなったというより、サポートできなくなったのだ。だから reload は未実装となり、これまでの流れを考えると、恐らく今後も復活することはないだろう。

結論として、rsyslog に関しては(どんなに不満でも)以下を受け入れるしかない。

• ファイルハンドルを閉じたいなら HUP シグナル。(kill -HUP <PID>)
• 設定を再読み込みさせたいなら再起動。(service rsyslog restart)

Emacs 24: Gnus: `smtpmail-auth-credentials' was removed

いつの間にか Emacs 24 がリリースされていたので、好奇心で使い始めた。Emacs 23 での設定をそのまま引き継いだが、問題なく動く。楽勝じゃん! て調子で仕事してたら、その日の終わりにメールが送れなくなってることに気が付いた。orz

具体的には、Gnus でメール送信時に「SMTP user name for <HOSTNAME>:」って聞かれる。何でこんな基本的なところが動かなくなるんだよ、と恨めしく思いながら調べると、これだ。

• Emacs NEWS 24.1

** SMTPmail

*** SMTPmail now uses encrypted connections (via STARTTLS) by default
if the mail server supports them.  This uses either built-in GnuTLS
support, or the starttls.el library.  Customize `smtpmail-stream-type'
to change this.

*** The variable `smtpmail-auth-credentials' has been removed.
By default, the information is now stored in the file ~/.authinfo.
This was the default value of smtpmail-auth-credentials.  If you had
customized smtpmail-auth-credentials to a list of user names and
passwords, those settings are not used.  During your first connection
to the smtp server, Emacs will prompt for the user name and password,
and offer to save them to ~/.authinfo.  Or you can manually copy the
credentials to ~/.authinfo.  For example, if you had

  (setq smtpmail-auth-credentials
        '(("mail.example.org" 25 "jim" "s!cret")))

then the equivalent line in ~/.authinfo would be

  machine mail.example.org port 25 login jim password s!cret

See the auth-source manual for more information, e.g. on encrypting
the credentials file.

*** The variable `smtpmail-starttls-credentials' has been removed.
If you had that set, you need to put

  machine smtp.whatever.foo port 25 key "~/.my_smtp_tls.key" cert "~/.my_smtp_tls.cert"

in your ~/.authinfo file instead.

smtpmail-{auth,starttls}-credentials は無くなったので代わりに ~/.authinfo を使え、と。しかもデフォルトで TLS にまで対応してくれちゃうらしい。TLS は使ってないので知らないが、~/.authinfo の方は作ったらサクッと動いた。

しかしこれ、みんな知ってるんかな? 検索しても目ぼしいものが出てこないけど。まあ、Gnus 使ってる人はこれくらい自己解決してるのが当たり前、ということなんだろう。

Upstart + runit: stop: Job failed while stopping

Upstart で管理している runit を終了させると、エラーが発生。

# stop runsvdir ; echo $?
stop: Job failed while stopping
1

/var/log/messages には、

Jul 17 12:13:38 rhel6 init: runsvdir post-stop process (3686) terminated with status 1

どうやら post-stop 処理がエラーになった模様。runsvdir の Upstart 設定は次の通り。

/etc/init/runsvdir.conf:

# for runit - manage /sbin/runsvdir-start
start on runlevel [2345]
stop on runlevel [016]
respawn
exec /sbin/runsvdir-start
post-stop exec pkill -x runsv

実際、pkill はプロセスが見つからない場合に 1 を返す。どうせここで pkill が失敗したところでどうしようもないし、post-stop を次のように変更して対処した。

post-stop script
	pkill -x runsv || true
end script

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"

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

• piyolian: Slony-I: duplicate key value violates unique constraint "sl_nodelock-pkey", part 1

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

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

• piyolian: Apache: httpd (pid ####) already running
• piyolian: PostgreSQL: lock file "postmaster.pid" already exists

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 ファイルを偽造してみて、サービスが起動するかどうか確認してみることをお勧めする。

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

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

ソースコードでは次の部分。(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 を使っていて二重起動チェックとは無縁なので、実際に動くコードは載せられない。

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 には散々苦労させられてきたから、こんな時くらい楽させて貰わないと。:-)

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 と言えども過信は禁物。