<html><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; "><div><div>Hi,</div><div><br></div><div>I have a configuration where several nodes send all log messages to a central server. The </div><div>applications on remote nodes send their logs locally either via UDP or a unix socket. The</div><div>syslog-ng running on remote nodes simply pick up all log messages from all sources, i.e. TCP, UDP, </div><div>/proc/kmsg, /dev/log and internal, and transmit all messages to the central server uisng TCP. The </div><div>remote node's config file follows.</div><div><br></div><div>We've been having intermittent problems where the central server would suddenly stop logging messages </div><div>from certain nodes. We noticed that very often restarting syslog-ng on the central server would fix</div><div>the condition and logging would carry on.</div><div><br></div><div>Howver I discovered a new rare case where restarting the central syslog-ng didn't work. I found out </div><div>by doing a tcpdump that the remote syslog-ng was not sending the log messages. I have done an strace </div><div>on the remote syslog-ng and it shows that nothing happens after a message has been "recvfrom()" or </div><div>"read()". Then I have restarted syslog-ng and things went back to normal. In the 2nd strace we can see </div><div>that there is a "write()" after the "read()".</div><div><br></div><div>I'm using syslog-ng 2.0.9.</div><div><br></div><div>*********************</div><div>Remote node's Config file:</div><div>*********************</div><div>options {</div><div> chain_hostnames(no);</div><div> log_msg_size(8192);</div><div> log_fifo_size(50000);</div><div> log_iw_size(250);</div><div> log_fetch_limit(25);</div><div> flush_lines(10);</div><div> flush_timeout(10);</div><div>};</div><div><br></div><div>source local {</div><div> pipe("/proc/kmsg");</div><div> unix-stream("/dev/log" max-connections(50));</div><div> internal();</div><div>};</div><div><br></div><div>source network {</div><div> udp(localport(514));</div><div> tcp(localport(514));</div><div>};</div><div><br></div><div>destination spotxdeoam {</div><div> tcp("spotxdeoam" destport(514));</div><div>};</div><div><br></div><div>destination local {</div><div> tcp("localhost" destport(514));</div><div>};</div><div><br></div><div># To change the local log path for modules, change the following statement.</div><div>destination local_Modules {</div><div> file("/opt/spotxde/software/var/SPOTxdeServer/logs/$HOST/$PROGRAM/messages"</div><div> create_dirs(yes)</div><div> template("$FULLDATE, $HOST, $MSG\n")</div><div> template_escape(no));</div><div>};</div><div><br></div><div># To change the local log path for node, change the following statement.</div><div>destination local_Nodes {</div><div> file("/opt/spotxde/software/var/SPOTxdeServer/logs/$HOST/messages"</div><div> create_dirs(yes)</div><div> template("$FULLDATE, $HOST, $MSG\n")</div><div> template_escape(no));</div><div>};</div><div><br></div><div>filter Modules {</div><div> program("^OAM") or</div><div> program("^TRX") or</div><div> program("^VA1") or</div><div>[root@c15 Rich]# more /opt/spotxde/software/etc/syslog_ng/syslog-ng_trx.conf </div><div>options {</div><div> chain_hostnames(no);</div><div> log_msg_size(8192);</div><div> log_fifo_size(50000);</div><div> log_iw_size(250);</div><div> log_fetch_limit(25);</div><div> flush_lines(10);</div><div> flush_timeout(10);</div><div>};</div><div><br></div><div>source local {</div><div> pipe("/proc/kmsg");</div><div> unix-stream("/dev/log" max-connections(50));</div><div> internal();</div><div>};</div><div><br></div><div>source network {</div><div> udp(localport(514));</div><div> tcp(localport(514));</div><div>};</div><div><br></div><div>destination spotxdeoam {</div><div> tcp("spotxdeoam" destport(514));</div><div>};</div><div><br></div><div>destination local {</div><div> tcp("localhost" destport(514));</div><div>};</div><div><br></div><div># To change the local log path for modules, change the following statement.</div><div>destination local_Modules {</div><div> file("/opt/spotxde/software/var/SPOTxdeServer/logs/$HOST/$PROGRAM/messages"</div><div> create_dirs(yes)</div><div> template("$FULLDATE, $HOST, $MSG\n")</div><div> template_escape(no));</div><div>};</div><div><br></div><div># To change the local log path for node, change the following statement.</div><div>destination local_Nodes {</div><div> file("/opt/spotxde/software/var/SPOTxdeServer/logs/$HOST/messages"</div><div> create_dirs(yes)</div><div> template("$FULLDATE, $HOST, $MSG\n")</div><div> template_escape(no));</div><div>};</div><div><br></div><div>filter Modules {</div><div> program("^OAM") or</div><div> program("^TRX") or</div><div> program("^VA1") or</div><div> program("^VA2") or</div><div> program("^VA3") or</div><div> program("^VA4") or</div><div> program("^MM1") or</div><div> program("^MM3") or</div><div> program("^MM4") or</div><div> program("^MM7") or</div><div> program("^WAP") or</div><div> program("^STI") or</div><div> program("^HCA") or</div><div> program("^RPT") or</div><div> program("^PRF") or</div><div> program("^SVW") or</div><div> program("^MNG") or</div><div> program("^CDR") or</div><div> program("^EAIF") or</div><div> program("^TEST") or</div><div> program("^MMSC") or</div><div> program("^SSMA") or</div><div> program("^SMTP") or</div><div> program("^ICAP") or</div><div> program("^BIDA") or</div><div> program("^SMPP") or</div><div> program("^LTRX") or</div><div> program("^MCDN") or</div><div> program("^RMSS") or</div><div> program("^EPGS");</div><div>};</div><div><br></div><div>log {</div><div> source(local);</div><div> source(network);</div><div> filter(Modules);</div><div> destination(spotxdeoam);</div><div># Remove the comment on the next statement to log locally on the TRX nodes the Modules related logs</div><div># destination(local_Modules);</div><div> flags(final);</div><div>};</div><div><br></div><div>log {</div><div> source(local);</div><div> source(network);</div><div> destination(spotxdeoam);</div><div># Remove the comment on the next statement to log locally on the TRX nodes the Node relatedlogs</div><div># destination(local_Nodes);</div><div> flags(fallback);</div><div>};</div><div><br></div><div>*********************</div><div><br></div><div>*********************</div><div>Following is an strace of syslog-ng that doesn't work.</div><div>There were 2 attemps in this one: one using UDP and on using Unix socket.</div><div>*********************</div><div><br></div><div>[root@c15 Rich]# strace -p 8259</div><div>Process 8259 attached - interrupt to quit</div><div>gettimeofday({1213891616, 539195}, NULL) = 0</div><div>gettimeofday({1213891616, 539246}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 22650) = 0</div><div>gettimeofday({1213891639, 190435}, NULL) = 0</div><div>time(NULL) = 1213891639</div><div>time(NULL) = 1213891639</div><div>gettimeofday({1213891639, 190507}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891669, 191715}, NULL) = 0</div><div>time(NULL) = 1213891669</div><div>time(NULL) = 1213891669</div><div>gettimeofday({1213891669, 191778}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN, revents=POLLIN}], 8, 30000) = 1</div><div>gettimeofday({1213891676, 326051}, NULL) = 0</div><div>recvfrom(3, "<30>Jun 19 12:07:56 RMSS: /syslo"..., 8192, 0, {sa_family=AF_INET, sin_port=htons(39166), sin_addr=inet_addr("127.0.0.1")}, [16]) = 100</div><div>gettimeofday({1213891676, 326294}, NULL) = 0</div><div>time(NULL) = 1213891676</div><div>stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1252, ...}) = 0</div><div>time(NULL) = 1213891676</div><div>gettimeofday({1213891676, 326621}, NULL) = 0</div><div>recvfrom(3, 0x8131ef8, 8192, 0, 0xffffd560, 0xffffd55c) = -1 EAGAIN (Resource temporarily unavailable)</div><div>gettimeofday({1213891676, 326794}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 22865) = 0</div><div>gettimeofday({1213891699, 193074}, NULL) = 0</div><div>time(NULL) = 1213891699</div><div>time(NULL) = 1213891699</div><div>gettimeofday({1213891699, 193277}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891729, 195368}, NULL) = 0</div><div>time(NULL) = 1213891729</div><div>time(NULL) = 1213891729</div><div>gettimeofday({1213891729, 195569}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891759, 196643}, NULL) = 0</div><div>time(NULL) = 1213891759</div><div>time(NULL) = 1213891759</div><div>gettimeofday({1213891759, 196842}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891789, 197931}, NULL) = 0</div><div>time(NULL) = 1213891789</div><div>time(NULL) = 1213891789</div><div>gettimeofday({1213891789, 198129}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891819, 199219}, NULL) = 0</div><div>time(NULL) = 1213891819</div><div>time(NULL) = 1213891819</div><div>gettimeofday({1213891819, 199421}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891849, 200510}, NULL) = 0</div><div>time(NULL) = 1213891849</div><div>time(NULL) = 1213891849</div><div>gettimeofday({1213891849, 200707}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN, revents=POLLIN}, {fd=3, events=POLLIN}], 8, 30000) = 1</div><div>gettimeofday({1213891867, 753947}, NULL) = 0</div><div>accept(6, {sa_family=AF_FILE, path="??????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????"}, [2]) = 11</div><div>setsockopt(11, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0</div><div>fcntl64(11, F_GETFL) = 0x2 (flags O_RDWR)</div><div>fcntl64(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0</div><div>fcntl64(11, F_GETFD) = 0</div><div>fcntl64(11, F_SETFD, FD_CLOEXEC) = 0</div><div>brk(0) = 0x8ae1000</div><div>brk(0x8b02000) = 0x8b02000</div><div>gettimeofday({1213891867, 754658}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=11, events=POLLIN, revents=POLLIN|POLLHUP}, {fd=6, events=POLLIN}], 9, 11446) = 1</div><div>gettimeofday({1213891867, 754830}, NULL) = 0</div><div>read(11, "<30>Jun 19 12:11:07 RMSS: /syslo"..., 8192) = 100</div><div>gettimeofday({1213891867, 755001}, NULL) = 0</div><div>time(NULL) = 1213891867</div><div>stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1252, ...}) = 0</div><div>gettimeofday({1213891867, 755271}, NULL) = 0</div><div>read(11, "", 8192) = 0</div><div>close(11) = 0</div><div>gettimeofday({1213891867, 755520}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6, events=POLLIN}], 8, 11445) = 0</div><div>gettimeofday({1213891879, 201791}, NULL) = 0</div><div>time(NULL) = 1213891879</div><div>time(NULL) = 1213891879</div><div>gettimeofday({1213891879, 201987}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891909, 203098}, NULL) = 0</div><div>time(NULL) = 1213891909</div><div>time(NULL) = 1213891909</div><div>gettimeofday({1213891909, 203299}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN|POLLOUT}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6, events=POLLIN}], 8, 30000) = 0</div><div>gettimeofday({1213891939, 205377}, NULL) = 0</div><div>time(NULL) = 1213891939</div><div>time(NULL) = 1213891939</div><div>gettimeofday({1213891939, 205580}, NULL) = 0</div><div>poll(</div><div><br></div><div><br></div><div>*******************</div><div>And now the strace sequence when it works:</div><div>We can see that after the read there is a write to transmit the message to the central log server.</div><div>*******************</div><div><br></div><div>[root@c15 Rich]# strace -p 15310</div><div>Process 15310 attached - interrupt to quit</div><div>gettimeofday({1213900598, 12321}, NULL) = 0</div><div>gettimeofday({1213900598, 12361}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=5, events=POLLIN}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=6, events=POLLIN}, {fd=3, events=POLLIN}], 7, 2069) = 0</div><div>gettimeofday({1213900600, 83036}, NULL) = 0</div><div>time(NULL) = 1213900600</div><div>time(NULL) = 1213900600</div><div>gettimeofday({1213900600, 83101}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=5, events=POLLIN}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=6, events=POLLIN, revents=POLLIN}, {fd=3, events=POLLIN}], 7, 30000) = 1</div><div>gettimeofday({1213900610, 338336}, NULL) = 0</div><div>accept(6, {sa_family=AF_FILE, path=@}, [2]) = 10</div><div>setsockopt(10, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0</div><div>fcntl64(10, F_GETFL) = 0x2 (flags O_RDWR)</div><div>fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0</div><div>fcntl64(10, F_GETFD) = 0</div><div>fcntl64(10, F_SETFD, FD_CLOEXEC) = 0</div><div>gettimeofday({1213900610, 338937}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=5, events=POLLIN}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=10, events=POLLIN, revents=POLLIN|POLLHUP}, {fd=6, events=POLLIN}], 8, 19745) = 1</div><div>gettimeofday({1213900610, 339123}, NULL) = 0</div><div>read(10, "<30>Jun 19 14:36:50 RMSS: /syslo"..., 8192) = 100</div><div>gettimeofday({1213900610, 339320}, NULL) = 0</div><div>time(NULL) = 1213900610</div><div>stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1252, ...}) = 0</div><div>gettimeofday({1213900610, 339627}, NULL) = 0</div><div>read(10, "", 8192) = 0</div><div>close(10) = 0</div><div>gettimeofday({1213900610, 339888}, NULL) = 0</div><div>poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=5, events=POLLIN}, {fd=9, events=POLLIN}, {fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6, events=POLLIN}], 7, 10) = 0</div><div>gettimeofday({1213900610, 351199}, NULL) = 0</div><div>stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1252, ...}) = 0</div><div>write(8, "<30>Jun 19 14:36:50 c15 RMSS: /s"..., 103) = 103</div><div>gettimeofday({1213900610, 351494}, NULL) = 0</div><div>poll( <unfinished ...></div><div>Process 15310 detached</div><div><br></div></div><div apple-content-edited="true"> <span class="Apple-style-span" style="border-collapse: separate; color: rgb(0, 0, 0); font-family: Helvetica; font-size: 12px; font-style: normal; font-variant: normal; font-weight: normal; letter-spacing: normal; line-height: normal; orphans: 2; text-align: auto; text-indent: 0px; text-transform: none; white-space: normal; widows: 2; word-spacing: 0px; -webkit-border-horizontal-spacing: 0px; -webkit-border-vertical-spacing: 0px; -webkit-text-decorations-in-effect: none; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0; "><div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; "><div><div style="margin-top: 0cm; margin-bottom: 0.0001pt; margin-right: 0cm; margin-left: 0cm; font-size: 12pt; font-family: 'Times New Roman'; "><strong><b><font size="2" color="#3e841c" face="Verdana"><span style="font-size: 10pt; font-family: Verdana; color: rgb(62, 132, 28); ">Richard Vigeant</span></font></b></strong><o:p></o:p></div><div style="margin-top: 0cm; margin-bottom: 0.0001pt; margin-right: 0cm; margin-left: 0cm; font-size: 12pt; font-family: 'Times New Roman'; "><span class="Apple-style-span" style="color: rgb(76, 86, 96); font-family: Verdana; font-size: 12px; font-weight: bold; "><a href="http://www.vantrix.com/" style="color: blue; text-decoration: underline; ">www.vantrix.com</a></span></div><div><font class="Apple-style-span" color="#4C5660" face="Verdana"><b><br></b></font></div></div></div></span><br class="Apple-interchange-newline"> </div><br></body></html>