readproctitle service errors: ...multilog: fatal: unable to lock directory /var/log/qmail/smtpd: temporary failure?multilog: fatal: unable to lock directory /var/log/qmail: temporary failure?multilog: fatal: unable to lock directory /var/log/qmail/smtpd: temporary failure?multilog: fatal: unable to lock directory /var/log/qmail: temporary failure?multilog: fatal: unable to lock directory /var/log/qmail/smtpd: temporary failure?
문서들을 검색해 보면 대부분 qmail을 프로세스 하나 남김 없이 깨끗이 종료 처리하고 qmail log가 쌓이고 있는 디렉토리 안의 lock 파일을 삭제해 주면 된다고 하는데 내 경우는 전혀 해결되지 않았다. 심지어는 시스템을 거듭 리부팅해봐도 안되는 것이었다.
완벽한 해결책이라고 자신할 수 있는 방법을 찾아냈다.
daemontools에는 multilog라는 바이너리가 있는데 알고 보니 이게 로그 파일을 적절히 쪼개어 순환해 주는 logrotate와 같은 기능을 하는 바이너리이다.
multilog의 순환 대상 로그 파일엔 한 개의 multilog 프로세스만 붙여야 한다.
올바르게 운영되고 있는 qmail + vpopmail 서버의 multilog 관련 프로세스 현황이다.
[root@localhost ~]# ps auxww | grep multilog
qmaill 16135 0.0 0.0 1624 304 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/vpop
qmaill 16142 0.0 0.0 1624 300 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-smtpd
qmaill 16143 0.0 0.0 1624 296 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-send
root 24261 0.0 0.0 5128 708 pts/3 D+ 00:18 0:00 grep --color=auto multilog
[root@localhost ~]#
qmaill 16135 0.0 0.0 1624 304 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/vpop
qmaill 16142 0.0 0.0 1624 300 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-smtpd
qmaill 16143 0.0 0.0 1624 296 ? S Apr05 0:00 /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-send
root 24261 0.0 0.0 5128 708 pts/3 D+ 00:18 0:00 grep --color=auto multilog
[root@localhost ~]#
qmail-send, vpop, qmail-smtpd log가 각각 따로 저장되고 있으며 각 로그마다 multilog에 의해 따로 관리되고 있다. 이게 올바른 세팅 상태이다.
중요한 점이 log 파일들이 multilog에 의해 올바르게 관리되려면 서로 대등한 서브 경로에 위치하고 있어야 한다는 것이다. 만약 qmail-send 프로세스의 log를 /var/log/qmail/current에 위치 시키고 qmail-smtpd의 log를 /var/log/qmail의 서브 경로인 /var/log/qmail/smtpd/current 에 위치시키는 구조를 취한다면 이는 잘못되었다는 것이다(qmail 설치 문서들 중에 이런 경우들이 적잖음). 이유는 본 포스트 하단의 readproctitle service errors 캡쳐 이미지의 설명에서 밝힌다.
http://qmail.kldp.net/faq/admin.html
그리고 정말 중요한 것 하나 더...
multolog에 의해 순환될 qmail 각 프로세스별 log(파일명 current)가 들어 있는 디렉토리 명은 반드시 /var/qmail/supervise 하위의 디렉토리 명과 일치해야 한다.
스크립트 파일을 직접 보는 것이 이해가 빠를 것이다.
[root@localhost ~]# cat /var/qmail/supervise/qmail-send/log/run
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-send
[root@localhost ~]# ls -l /var/log/qmail | grep qmail-send
drwxr-xr-x 2 qmaill root 4096 4월 5 20:03 qmail-send
[root@localhost ~]#
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-send
[root@localhost ~]# ls -l /var/log/qmail | grep qmail-send
drwxr-xr-x 2 qmaill root 4096 4월 5 20:03 qmail-send
[root@localhost ~]#
[root@localhost ~]# cat /var/qmail/supervise/qmail-smtpd/log/run
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-smtpd
[root@localhost ~]# ls -l /var/log/qmail | grep qmail-smtpd
drwxr-xr-x 2 qmaill root 4096 4월 5 17:08 qmail-smtpd
[root@localhost ~]#
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/qmail-smtpd
[root@localhost ~]# ls -l /var/log/qmail | grep qmail-smtpd
drwxr-xr-x 2 qmaill root 4096 4월 5 17:08 qmail-smtpd
[root@localhost ~]#
[root@localhost ~]# cat /var/qmail/supervise/vpop/log/run
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/vpop
[root@localhost ~]# ls -l /var/log/qmail | grep vpop
drwxr-xr-x 2 qmaill root 4096 4월 5 11:08 vpop
[root@localhost ~]#
#!/bin/sh
exec /usr/local/bin/setuidgid qmaill /usr/local/bin/multilog t s1000000 n20 /var/log/qmail/vpop
[root@localhost ~]# ls -l /var/log/qmail | grep vpop
drwxr-xr-x 2 qmaill root 4096 4월 5 11:08 vpop
[root@localhost ~]#
[root@localhost ~]# ls -lh /var/qmail/supervise
합계 16K
drwxr-xr-t 4 root root 4.0K 4월 4 13:54 qmail-send
drwxr-xr-t 4 root root 4.0K 4월 5 14:47 qmail-smtpd
drwxr-xr-t 4 root root 4.0K 4월 5 23:45 vpop
[root@localhost ~]# ls -lh /var/log/qmail
합계 16K
drwxr-xr-x 2 qmaill root 4.0K 4월 5 20:03 qmail-send
drwxr-xr-x 2 qmaill root 4.0K 4월 5 17:08 qmail-smtpd
drwxr-xr-x 2 qmaill root 4.0K 4월 5 11:08 vpop
[root@localhost ~]#
합계 16K
drwxr-xr-t 4 root root 4.0K 4월 4 13:54 qmail-send
drwxr-xr-t 4 root root 4.0K 4월 5 14:47 qmail-smtpd
drwxr-xr-t 4 root root 4.0K 4월 5 23:45 vpop
[root@localhost ~]# ls -lh /var/log/qmail
합계 16K
drwxr-xr-x 2 qmaill root 4.0K 4월 5 20:03 qmail-send
drwxr-xr-x 2 qmaill root 4.0K 4월 5 17:08 qmail-smtpd
drwxr-xr-x 2 qmaill root 4.0K 4월 5 11:08 vpop
[root@localhost ~]#
위처럼 세팅을 잘 해 두었다면 ps로 확인했을 때 아래와 같이 readproctitle service errors: 부분이 점선만으로 출력된다. readproctitle service errors 메시지는 그 자체가 에러메시지는 아니고 readproctitle service errors가 실제 발생하고 있을 경우 점선 부분에 해당 문제의 사유가 출력된다. 대부분 multilog의 unable to lock directory 문제인 경우가 많을 것이다.

그렇다면 포스트 상단에 최초 언급하였던 multilog: fatal: unable to lock directory /var/log/qmail/smtpd: temporary failure 요 에러메시지는 무엇을 의미하느냐?
두 가지 중 하나로 추측되는데 하나는 이렇다. multilog는 프로세스당 한 개의 로그만 컨트롤해야 하는데 두 개 이상의 프로세스가 한 개의 로그 파일(/var/log/qmail/smtpd/currrent)에 액세스하다 보니 이미 먼저 잡은 프로세스가 다른 프로세스의 액세스를 막기 위해 로그가 들어있는 디렉토리를 lock을 건 상태에서 두 번째로 액세스하려는 프로세스는 디렉토리를 lock하지 못한다는 의미인 것 같다. 접근이 막혔으니 당연한 결과이다.
MySQL을 dump해 보았으면 알겠지만 mysqldump를 시도하면 일단 dump 대상 테이블에 table lock(TABLE LOCK 권한이 있어야 함)을 건 다음에 dump를 한다. dump를 하는 동안 db의 무결성을 유지하기 위해 lock을 걸어 쓰기를 일시적으로 막는 것이다. multilog에서 unable to lock directory 현상이 일어나는 것도 같은 맥락으로 이해하면 될 것이다.
다른 하나는 multolog에 의해 순환될 log(파일명 current)가 들어 있는 디렉토리 명은 반드시 /var/qmail/supervise 하위의 디렉토리 명과 일치해야 하는데 그렇지 못해 발생한 듯 싶다. 내 경우 /var/supervice/qmail-smtp의 구조를 갖고 있어 로그 파일 디렉토리 경로는 /var/log/qmail/qmail-smtpd 여야 정상인데 /var/log/qmail/smtpd 였던 게 문제였다.
참고로 이 문제를 겪는 동안 메일이 발신만 안 되고 프로세스 종료하고 lock 파일 삭제하고 큐메일 재구동하면서 쓰다가 랜덤하게 다시 발신이 안 되는 문제를 간헐적으로 겪다가 이 문제 해결 후 발신이 안 되던 문제를 깨끗이 해결할 수 있었다.
예전에 포스팅했던 qmail 기술문서가 일부 잘못된 셈이다. ^^;;
http://digimoon.net/blog/323
http://digimoon.net/blog/354