<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body>
<p>Hello,</p>
<p>Using xymon 4.3.28 ( on a Raspberry Pi 3B running Raspbian
GNU/Linux 10 (buster) (32 bit) ) file /var/log/syslog is scanned
for various error messages. The syslog is checked on two Raspberry
Pi 0W devices, called rpi01 and rpi02, which both run the
aforementioned version of Raspbian (raspberry OS) too. On rpi01
and rpi02 a proxy xymon is running, which forward all messages to
the xymon server at the Raspberry Pi 3B, called rpi30.</p>
<p>The relevant part of analysis.cfg on hosts rpi01 and rpi02 is:</p>
<p><font face="monospace">HOST=*<br>
PROC /usr/sbin/sshd 1 1<br>
LOG /var/log/syslog %(?-i)Under-voltage<br>
LOG /var/log/syslog %disabled\sby\shub\.+re-enabling<br>
LOG /var/log/syslog %wlan0:\scarrier\slost
EXTIME=*:0650:0745<br>
LOG /var/log/syslog %wlan0:\scarrier\sacquired
EXTIME=*:0650:0745 COLOR=yellow</font><br>
</p>
<p>The associated part of analysis.cfg on host rpi30 is:</p>
<p><font face="monospace">HOST=rpi01<br>
PROC /usr/sbin/sshd 1<br>
LOG /var/log/syslog %(?-i)Under-voltage<br>
LOG /var/log/syslog %I\/O\serror<br>
LOG /var/log/syslog %EXT4-fs\serror<br>
LOG /var/log/syslog %disabled\sby\shub\.+re-enabling<br>
LOG /var/log/syslog %wlan0:\scarrier\slost
EXTIME=*:0650:0745<br>
LOG /var/log/syslog %wlan0:\scarrier\sacquired
COLOR=yellow EXTIME=*:0650:0745<br>
<br>
HOST=rpi02<br>
PROC /usr/sbin/sshd 1<br>
LOG /var/log/syslog %(?-i)Under-voltage<br>
LOG /var/log/syslog %I\/O\serror<br>
LOG /var/log/syslog %EXT4-fs\serror<br>
LOG /var/log/syslog %disabled\sby\shub\.+re-enabling<br>
LOG /var/log/syslog %wlan0:\scarrier\slost
EXTIME=*:0650:0745<br>
LOG /var/log/syslog %wlan0:\scarrier\sacquired
COLOR=yellow EXTIME=*:0650:0745</font><br>
</p>
<p>The alerts resulting from this configuration are all sent by
e-mail, which contain the content of variable BBALPHAMSG at the
time the script to sent the e-mail is invoked.</p>
<p><br>
</p>
<p>The problem seems to be twofold. (A) The 'carrier acquired'
message is sometimes displayed with a red status indicator, but
once entered in the history, and viewed via the history page, this
problem is gone. (B) the page of test 'msgs' might show something
different from BBALPHAMSG.</p>
<p><br>
</p>
<p>An example of the error (B) is found at host rpi01. The relevant
part of the HTML source of the page showing test msgs, taken from
the history page, is:</p>
<p><font face="monospace"><CENTER><TABLE ALIGN=CENTER
BORDER=0 SUMMARY="Detail Status"><br>
<TR><TD ALIGN=LEFT><H3> Mon Apr 18 19:08:38
CEST 2022 - System logs NOT ok</H3><br>
<PRE><br>
<br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Critical entries in <a
href="/cgi-bin/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Apr 18 19:08:39 rpi01 dhcpcd[413]:
wlan0: carrier lost<br>
<IMG SRC="/xymon/gifs/static/yellow.gif" ALT="yellow"
HEIGHT="16" WIDTH="16" BORDER=0> Apr 18 19:08:40 rpi01
dhcpcd[413]: wlan0: carrier acquired<br>
<br>
<br>
Full log <a
href="/cgi-bin/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: bits received from HRNG
source: 28360064<br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: bits sent to kernel
pool: 28299456<br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: entropy added to kernel
pool: 28299456</font><br>
</p>
<p>The associated message in the e-mail contains:</p>
<p><font face="monospace">rpi01:msgs red [56896]<br>
red Mon Apr 18 19:08:38 CEST 2022 - System logs NOT ok<br>
<br>
&red Critical entries in /var/log/syslog<br>
&red Apr 18 19:08:39 rpi01 dhcpcd[413]: wlan0: carrier lost<br>
&red Apr 18 19:08:40 rpi01 dhcpcd[413]: wlan0: carrier
acquired<br>
<br>
<br>
Full log /var/log/syslog<br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: bits received from HRNG
source: 28360064<br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: bits sent to kernel
pool: 28299456<br>
Apr 18 18:53:31 rpi01 rngd[269]: stats: entropy added to kernel
pool: 28299456</font><br>
</p>
<p>Thus BBALPHAMSG shows the wrong status (colour) for the line
'wlan0: carrier acquired'.</p>
<p><br>
</p>
<p>This problem is not always reproducible, as shown by the
following example at host rpi02. The relevant part of the HTML
source of the page showing test msgs, taken from the history page,
is:</p>
<pre id="line1"><span><<span class="start-tag">CENTER</span>></span><span></span><span><<span class="start-tag">TABLE</span> <span class="attribute-name">ALIGN</span>=<a class="attribute-value">CENTER</a> <span class="attribute-name">BORDER</span>=<a class="attribute-value">0</a> <span class="attribute-name">SUMMARY</span>="<a class="attribute-value">Detail Status</a>"></span><span>
<span id="line86"></span></span><span><<span class="start-tag">TR</span>></span><span></span><span><<span class="start-tag">TD</span> <span class="attribute-name">ALIGN</span>=<a class="attribute-value">LEFT</a>></span><span></span><span><<span class="start-tag">H3</span>></span><span> Mon Apr 18 19:11:29 CEST 2022 - System logs NOT ok</span><span></<span class="end-tag">H3</span>></span><span>
<span id="line87"></span></span><span><<span class="start-tag">PRE</span>></span><span>
<span id="line88"></span>
<span id="line89"></span></span><span><<span class="start-tag">IMG</span> <span class="attribute-name">SRC</span>="<a class="attribute-value">/xymon/gifs/static/red.gif</a>" <span class="attribute-name">ALT</span>="<a class="attribute-value">red</a>" <span class="attribute-name">HEIGHT</span>="<a class="attribute-value">16</a>" <span class="attribute-name">WIDTH</span>="<a class="attribute-value">16</a>" <span class="attribute-name">BORDER</span>=<a class="attribute-value">0</a>></span><span> Critical entries in </span><span><<span class="start-tag">a</span> <span class="attribute-name">href</span>="<a class="attribute-value">/cgi-bin/svcstatus.sh?CLIENT=rpi02<span class="entity"><span>&</span>amp;</span>SECTION=msgs:/var/log/syslog</a>"></span><span>/var/log/syslog</span><span></<span class="end-tag">a</span>></span><span>
<span id="line90"></span></span><span><<span class="start-tag">IMG</span> <span class="attribute-name">SRC</span>="<a class="attribute-value">/xymon/gifs/static/red.gif</a>" <span class="attribute-name">ALT</span>="<a class="attribute-value">red</a>" <span class="attribute-name">HEIGHT</span>="<a class="attribute-value">16</a>" <span class="attribute-name">WIDTH</span>="<a class="attribute-value">16</a>" <span class="attribute-name">BORDER</span>=<a class="attribute-value">0</a>></span><span> Apr 18 19:08:41 rpi02 dhcpcd[395]: wlan0: carrier lost
<span id="line91"></span></span><span><<span class="start-tag">IMG</span> <span class="attribute-name">SRC</span>="<a class="attribute-value">/xymon/gifs/static/yellow.gif</a>" <span class="attribute-name">ALT</span>="<a class="attribute-value">yellow</a>" <span class="attribute-name">HEIGHT</span>="<a class="attribute-value">16</a>" <span class="attribute-name">WIDTH</span>="<a class="attribute-value">16</a>" <span class="attribute-name">BORDER</span>=<a class="attribute-value">0</a>></span><span> Apr 18 19:08:42 rpi02 dhcpcd[395]: wlan0: carrier acquired
<span id="line92"></span>
<span id="line93"></span>
<span id="line94"></span>Full log </span><span><<span class="start-tag">a</span> <span class="attribute-name">href</span>="<a class="attribute-value">/cgi-bin/svcstatus.sh?CLIENT=rpi02<span class="entity"><span>&</span>amp;</span>SECTION=msgs:/var/log/syslog</a>"></span><span>/var/log/syslog</span><span></<span class="end-tag">a</span>></span><span>
<span id="line95"></span>Apr 18 18:45:23 rpi02 rngd[273]: stats: bits received from HRNG source: 28700064
<span id="line96"></span>Apr 18 18:45:23 rpi02 rngd[273]: stats: bits sent to kernel pool: 28653824
<span id="line97"></span>Apr 18 18:45:23 rpi02 rngd[273]: stats: entropy added to kernel pool: 28653824</span></pre>
<p>The associated message in the e-mail contains:</p>
<pre>rpi02:msgs red [574766]
red Mon Apr 18 19:11:29 CEST 2022 - System logs NOT ok
&red Critical entries in <a>/var/log/syslog</a>
&red Apr 18 19:08:41 rpi02 dhcpcd[395]: wlan0: carrier lost
&yellow Apr 18 19:08:42 rpi02 dhcpcd[395]: wlan0: carrier acquired
Full log <a>/var/log/syslog</a>
Apr 18 18:45:23 rpi02 rngd[273]: stats: bits received from HRNG source: 28700064
Apr 18 18:45:23 rpi02 rngd[273]: stats: bits sent to kernel pool: 28653824
Apr 18 18:45:23 rpi02 rngd[273]: stats: entropy added to kernel pool: 28653824</pre>
<p>In this case the two reports on the same alert show the same
status information.</p>
<p><br>
</p>
<p>The following extractions of messages show both problems. The
first extraction is taken from the message as displayed on website
a few minutes after detection of the error condition:</p>
<p><font face="monospace"><TR><TD ALIGN=LEFT><H3>
Sat Apr 23 19:10:09 CEST 2022 - System logs NOT ok</H3><br>
<PRE><br>
<br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Critical entries in <a
href="/xymon-cgi/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Apr 23 19:07:12 rpi01 dhcpcd[413]:
wlan0: carrier lost<br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Apr 23 19:07:12 rpi01 dhcpcd[413]:
wlan0: carrier acquired<br>
<br>
<br>
Full log <a
href="/xymon-cgi/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits received from HRNG
source: 31960064<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits sent to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: entropy added to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: FIPS 140-2 successes:
1597<br>
</font></p>
<p>The corresponding alert via e-mail contains:</p>
<p><font face="monospace">rpi01:msgs red [515388]<br>
red Sat Apr 23 19:10:09 CEST 2022 - System logs NOT ok<br>
<br>
&red Critical entries in /var/log/syslog<br>
&red Apr 23 19:07:12 rpi01 dhcpcd[413]: wlan0: carrier lost<br>
&yellow Apr 23 19:07:12 rpi01 dhcpcd[413]: wlan0: carrier
acquired<br>
<br>
<br>
Full log /var/log/syslog<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits received from HRNG
source: 31960064<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits sent to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: entropy added to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: FIPS 140-2 successes:
1597</font><br>
</p>
<p>The same message retrieved some time later from the historical
status:</p>
<p><font face="monospace"><TR><TD ALIGN=LEFT><H3>
Sat Apr 23 19:10:09 CEST 2022 - System logs NOT ok</H3><br>
<PRE><br>
<br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Critical entries in <a
href="/cgi-bin/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
<IMG SRC="/xymon/gifs/static/red.gif" ALT="red" HEIGHT="16"
WIDTH="16" BORDER=0> Apr 23 19:07:12 rpi01 dhcpcd[413]:
wlan0: carrier lost<br>
<IMG SRC="/xymon/gifs/static/yellow.gif" ALT="yellow"
HEIGHT="16" WIDTH="16" BORDER=0> Apr 23 19:07:12 rpi01
dhcpcd[413]: wlan0: carrier acquired<br>
<br>
<br>
Full log <a
href="/cgi-bin/svcstatus.sh?CLIENT=rpi01&SECTION=msgs:/var/log/syslog">/var/log/syslog</a><br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits received from HRNG
source: 31960064<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: bits sent to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: entropy added to kernel
pool: 31895872<br>
Apr 23 18:53:32 rpi01 rngd[269]: stats: FIPS 140-2 successes:
1597</font><br>
</p>
<p><br>
</p>
<p>Thus sometimes the currently shown message contains the wrong
colour for the 'carrier acquired' message (but not the same page
in the history) and sometimes the message as passed in BBALPHAMSG
contains the wrong colour. <br>
</p>
<p><br>
</p>
<p>Regards,</p>
<p> Wim Nelis.<br>
</p>
</body>
</html>