Szalay Attila wrote:
Hi!
On Wed, 2007-06-06 at 11:34 +0100, Chris Taylor wrote:
When trying to reproduce it manually, sending kill -HUP causes syslog-ng
to die shortly after it gets a new PID.
I am able to consistently reproduce this.
No data is written to the new logfile until I manually restart syslog-ng
Could you do it again and in the same time strace-ing the syslog-ng?
(strace -fo output -s 512 -p `pidof syslog-ng`) And after it please send
the output to me.
Thanks.
Sorry about the delay, things have been pretty busy.
Attached is the strace output.
Below is the process I used:
d350-berlin:~# cat /var/run/syslog-ng.pid; echo
24507
d350-berlin:~# kill -HUP `cat /var/run/syslog-ng.pid`
d350-berlin:~# cat /var/run/syslog-ng.pid; echo
24507
d350-berlin:~# ps ax | grep syslog-ng
24551 pts/2 S+ 0:00 grep syslog-ng
d350-berlin:~# tail -f /var/log/messages
Jun 20 19:52:22 10.37.0.72 ports: port 10 is now off-line
Jun 20 19:55:15 10.37.0.71 00077 ports: port 17 is now off-line
Jun 20 20:16:52 10.37.0.71 00331 FFI: port 24-High collision or drop
rate. See help.
Jun 20 20:40:25 10.37.0.72 SNTP: updated time by -4 seconds
Jun 20 21:09:53 10.37.0.71 00331 FFI: port 24-High collision or drop
rate. See help.
Jun 20 21:18:15 10.37.0.71 00331 FFI: port 24-High collision or drop
rate. See help.
Jun 20 21:23:50 10.37.0.71 00331 FFI: port 24-High collision or drop
rate. See help.
Jun 20 23:06:49 10.37.0.74 SNTP: updated time by -4 seconds
Jun 21 00:49:56 10.37.0.64 SNTP: updated time by -4 seconds
Jun 21 10:40:41 d350-berlin syslog-ng[24507]: syslog-ng starting up;
version='2.0.0'
As you can see, -HUP is causing syslog-ng to die (in fact the strace
says it's segfaulting.. always fun), thus leaving us without any logging
of any kind.
Let me know if you need any more information.
Thanks,
Chris
24507 gettimeofday({1182418884, 445078}, NULL) = 0
24507 gettimeofday({1182418884, 445188}, NULL) = 0
24507 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN, revents=POLLIN},
{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 4, 137026) = 1
24507 gettimeofday({1182418898, 162028}, NULL) = 0
24507 accept(4, {sa_family=AF_FILE, [EMAIL PROTECTED], [2]) = 11
24507 fcntl64(11, F_GETFL) = 0x2 (flags O_RDWR)
24507 fcntl64(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0
24507 fcntl64(11, F_GETFD) = 0
24507 fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
24507 gettimeofday({1182418898, 162615}, NULL) = 0
24507 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=11, events=POLLIN, revents=POLLIN|POLLHUP}, {fd=4,
events=POLLIN}], 5, 123309) = 1
24507 gettimeofday({1182418898, 162780}, NULL) = 0
24507 read(11, "<38>Jun 21 10:41:38 sshd[24538]: Accepted password for root
from 193.203.82.100 port 22449 ssh2\0", 8192) = 96
24507 gettimeofday({1182418898, 162996}, NULL) = 0
24507 time(NULL) = 1182418898
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 gettimeofday({1182418898, 163355}, NULL) = 0
24507 time(NULL) = 1182418898
24507 open("/var/log/auth.log",
O_WRONLY|O_NONBLOCK|O_APPEND|O_CREAT|O_NOCTTY|O_LARGEFILE, 0640) = 12
24507 fcntl64(12, F_GETFD) = 0
24507 fcntl64(12, F_SETFD, FD_CLOEXEC) = 0
24507 fchown32(12, 0, -1) = 0
24507 fchown32(12, -1, 4) = 0
24507 fchmod(12, 0640) = 0
24507 time(NULL) = 1182418898
24507 time(NULL) = 1182418898
24507 read(11, "", 8192) = 0
24507 close(11) = 0
24507 gettimeofday({1182418898, 164271}, NULL) = 0
24507 poll([{fd=7, events=POLLOUT, revents=POLLOUT}, {fd=10, events=POLLOUT,
revents=POLLOUT}, {fd=12, events=POLLOUT, revents=POLLOUT}, {fd=3,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=4,
events=POLLIN}], 7, 123307) = 3
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(7, "<38>Jun 21 10:41:38 d350-berlin sshd[24538]: Accepted password
for root from 193.203.82.100 port 22449 ssh2\n", 108) = 108
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(10, "Jun 21 10:41:38 d350-berlin sshd[24538]: Accepted password for
root from 193.203.82.100 port 22449 ssh2\n", 104) = 104
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(12, "Jun 21 10:41:38 d350-berlin sshd[24538]: Accepted password for
root from 193.203.82.100 port 22449 ssh2\n", 104) = 104
24507 gettimeofday({1182418898, 165322}, NULL) = 0
24507 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=4, events=POLLIN, revents=POLLIN}], 4, 123306) = 1
24507 gettimeofday({1182418898, 242930}, NULL) = 0
24507 accept(4, {sa_family=AF_FILE, [EMAIL PROTECTED], [2]) = 11
24507 fcntl64(11, F_GETFL) = 0x2 (flags O_RDWR)
24507 fcntl64(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0
24507 fcntl64(11, F_GETFD) = 0
24507 fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
24507 gettimeofday({1182418898, 243470}, NULL) = 0
24507 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=11, events=POLLIN, revents=POLLIN|POLLHUP}, {fd=4,
events=POLLIN}], 5, 123228) = 1
24507 gettimeofday({1182418898, 243636}, NULL) = 0
24507 read(11, "<38>Jun 21 10:41:38 sshd[24540]: (pam_unix) session opened for
user root by root(uid=0)\0", 8192) = 88
24507 gettimeofday({1182418898, 243819}, NULL) = 0
24507 time(NULL) = 1182418898
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 gettimeofday({1182418898, 244159}, NULL) = 0
24507 time(NULL) = 1182418898
24507 time(NULL) = 1182418898
24507 read(11, "", 8192) = 0
24507 close(11) = 0
24507 gettimeofday({1182418898, 244550}, NULL) = 0
24507 poll([{fd=7, events=POLLOUT, revents=POLLOUT}, {fd=10, events=POLLOUT,
revents=POLLOUT}, {fd=12, events=POLLOUT, revents=POLLOUT}, {fd=3,
events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=4,
events=POLLIN}], 7, 123227) = 3
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(7, "<38>Jun 21 10:41:38 d350-berlin sshd[24540]: (pam_unix) session
opened for user root by root(uid=0)\n", 100) = 100
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(10, "Jun 21 10:41:38 d350-berlin sshd[24540]: (pam_unix) session
opened for user root by root(uid=0)\n", 96) = 96
24507 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
24507 write(12, "Jun 21 10:41:38 d350-berlin sshd[24540]: (pam_unix) session
opened for user root by root(uid=0)\n", 96) = 96
24507 gettimeofday({1182418898, 245701}, NULL) = 0
24507 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=4, events=POLLIN}], 4, 123226) = -1 EINTR (Interrupted
system call)
24507 --- SIGHUP (Hangup) @ 0 (0) ---
24507 sigreturn() = ? (mask now [])
24507 gettimeofday({1182418932, 82675}, NULL) = 0
24507 time([1182418932]) = 1182418932
24507 gettimeofday({1182418932, 82842}, NULL) = 0
24507 time(NULL) = 1182418932
24507 open("/etc/syslog-ng/syslog-ng.conf", O_RDONLY) = 11
24507 ioctl(11, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfb51538) = -1 ENOTTY
(Inappropriate ioctl for device)
24507 fstat64(11, {st_mode=S_IFREG|0644, st_size=9803, ...}) = 0
24507 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0xb7f63000
24507 read(11, "#\n# Configuration file for syslog-ng under Debian\n#\n#
attempts at reproducing default syslog behavior\n\n# the standard syslog levels
are (in descending order of priority):\n# emerg alert crit err warning notice
info debug\n# the aliases \"error\", \"panic\", and \"warn\" are deprecated\n#
the \"none\" priority found in the original syslogd configuration is\n# only
used in internal messages created by syslogd\n\n\n######\n# options\n\noptions
{\n # disable the chained hostname format in logs\n # (default is
enabled"..., 8192) = 8192
24507 open("/etc/group", O_RDONLY) = 13
24507 fcntl64(13, F_GETFD) = 0
24507 fcntl64(13, F_SETFD, FD_CLOEXEC) = 0
24507 _llseek(13, 0, [0], SEEK_CUR) = 0
24507 fstat64(13, {st_mode=S_IFREG|0644, st_size=546, ...}) = 0
24507 mmap2(NULL, 546, PROT_READ, MAP_SHARED, 13, 0) = 0xb7f62000
24507 _llseek(13, 546, [546], SEEK_SET) = 0
24507 munmap(0xb7f62000, 546) = 0
24507 close(13) = 0
24507 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 13
24507 connect(13, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
24507 getsockname(13, {sa_family=AF_INET, sin_port=htons(3204),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
24507 close(13) = 0
24507 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 13
24507 connect(13, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
24507 getsockname(13, {sa_family=AF_INET, sin_port=htons(3204),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
24507 close(13) = 0
24507 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 13
24507 connect(13, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("193.203.88.22")}, 16) = 0
24507 getsockname(13, {sa_family=AF_INET, sin_port=htons(3204),
sin_addr=inet_addr("192.168.100.89")}, [16]) = 0
24507 close(13) = 0
24507 open("/etc/passwd", O_RDONLY) = 13
24507 fcntl64(13, F_GETFD) = 0
24507 fcntl64(13, F_SETFD, FD_CLOEXEC) = 0
24507 _llseek(13, 0, [0], SEEK_CUR) = 0
24507 fstat64(13, {st_mode=S_IFREG|0644, st_size=1020, ...}) = 0
24507 mmap2(NULL, 1020, PROT_READ, MAP_SHARED, 13, 0) = 0xb7f62000
24507 _llseek(13, 1020, [1020], SEEK_SET) = 0
24507 munmap(0xb7f62000, 1020) = 0
24507 close(13) = 0
24507 open("/etc/passwd", O_RDONLY) = 13
24507 fcntl64(13, F_GETFD) = 0
24507 fcntl64(13, F_SETFD, FD_CLOEXEC) = 0
24507 _llseek(13, 0, [0], SEEK_CUR) = 0
24507 fstat64(13, {st_mode=S_IFREG|0644, st_size=1020, ...}) = 0
24507 mmap2(NULL, 1020, PROT_READ, MAP_SHARED, 13, 0) = 0xb7f62000
24507 _llseek(13, 1020, [1020], SEEK_SET) = 0
24507 munmap(0xb7f62000, 1020) = 0
24507 close(13) = 0
24507 open("/etc/passwd", O_RDONLY) = 13
24507 fcntl64(13, F_GETFD) = 0
24507 fcntl64(13, F_SETFD, FD_CLOEXEC) = 0
24507 _llseek(13, 0, [0], SEEK_CUR) = 0
24507 fstat64(13, {st_mode=S_IFREG|0644, st_size=1020, ...}) = 0
24507 mmap2(NULL, 1020, PROT_READ, MAP_SHARED, 13, 0) = 0xb7f62000
24507 _llseek(13, 1020, [1020], SEEK_SET) = 0
24507 munmap(0xb7f62000, 1020) = 0
24507 close(13) = 0
24507 read(11, "rr\nlog {\n source(s_all);\n filter(f_mail);\n
filter(f_at_least_err);\n destination(df_facility_dot_err);\n};\n\n#
news.crit /var/log/news/news.crit\nlog {\n
source(s_all);\n filter(f_news);\n filter(f_at_least_crit);\n
destination(df_news_dot_crit);\n};\n\n# news.err
/var/log/news/news.err\nlog {\n source(s_all);\n
filter(f_news);\n filter(f_at_least_err);\n
destination(df_news_dot_err);\n};\n\n# news."..., 8192) = 1611
24507 read(11, "", 4096) = 0
24507 read(11, "", 8192) = 0
24507 ioctl(11, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfb50fe8) = -1 ENOTTY
(Inappropriate ioctl for device)
24507 close(11) = 0
24507 munmap(0xb7f63000, 4096) = 0
24507 close(5) = 0
24507 time([1182418932]) = 1182418932
24507 gettimeofday({1182418932, 90239}, NULL) = 0
24507 time(NULL) = 1182418932
24507 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
24507 kill(24507, SIGSEGV) = 0
24507 sigreturn() = ? (mask now [])
24507 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
