radQueueSend: write failed on fd 9: Broken pipe

[bgrattan]

I know this problem has been discussed before but I can't seem to find
out why things aren't working. I'm running wview 5.4.0p1 Simulator on
Debian lenny. I have followed Joe's script and things seem to be
working but the html images stop after the first set is created and I
continue to get the radQueueSend error. Archives are written on time
but the index.html page is not updated. I feel like maybe something
is not in the correct place.

here are some logs, etc.:

Apr 17 18:02:11 wxserver htmlgend[4074]: <1240005731000> : doing
initial html generation now...
Apr 17 18:02:46 wxserver radmrouted[3063]: <1240005766820> :
radQueueSend: write failed on fd 9: Broken pipe
Apr 17 18:02:53 wxserver htmlgend[4080]: <1240005773161> : radlib:
htmlgend started as a daemon ...
........................................
root 4136 1 0 18:12 ? 00:00:17 /usr/local/bin/
htmlgend
root 4137 4136 0 18:12 ? 00:00:00 /usr/local/bin/
htmlgend
................................
root 4126 1 0 18:12 ? 00:00:00 /usr/local/bin/
radmrouted 1 /usr/local/var/wview
root 4127 4126 0 18:12 ? 00:00:00 /usr/local/bin/
radmrouted 1 /usr/local/var/wview
root 4130 1 0 18:12 ? 00:00:01 /usr/local/bin/
wviewd_sim
root 4131 4130 0 18:12 ? 00:00:00 /usr/local/bin/
wviewd_sim
...................................
Apr 17 18:13:07 wxserver htmlgend[4136]: <1240006387667> : ARCREC:
saving ALL daily archive reports ...
Apr 17 18:13:08 wxserver htmlgend[4136]: <1240006388366> : ARCREC: 1
daily archive reports available
Apr 17 18:13:09 wxserver htmlgend[4136]: <1240006389000> : starting
html generation in 2 mins 1 secs
Apr 17 18:13:09 wxserver htmlgend[4136]: <1240006389013> : doing
initial html generation now...
Apr 17 18:15:04 wxserver wviewd[4130]: <1240006504253> : storing
record for 2009-04-17 18:15
Apr 17 18:15:04 wxserver htmlgend[4136]: <1240006504267> : Adding 5
minute sample for 2009-04-17 18:15...
Apr 17 18:20:04 wxserver wviewd[4130]: <1240006804266> : storing
record for 2009-04-17 18:20
Apr 17 18:20:04 wxserver htmlgend[4136]: <1240006804279> : Adding 5
minute sample for 2009-04-17 18:20...
....................................
I can send more.
Thanks in advance for any help.

Bob

[Mark S. Teel]

Send full boot logs - htmlgend restarting doesn't look right but I don't
see the process monitor wvpmond running, so...

Mark

[bgrattan]

Thanks, Mark, here's the log after a stop/start:


Apr 17 22:35:12 wxserver wvpmond[4159]: <1240022112091> : exiting
normally...
Apr 17 22:35:12 wxserver htmlgend[4136]: <1240022112094> : exiting
normally...
Apr 17 22:35:12 wxserver wviewd[4130]: <1240022112098> : exiting
normally...
Apr 17 22:35:13 wxserver radmrouted[4126]: <1240022113104> : exiting
normally...
Apr 17 22:36:10 wxserver radmrouted[5213]: <1240022170852> : radlib:
radmrouted started as a daemon ...
Apr 17 22:36:10 wxserver radmrouted[5213]: <1240022170853> : started
on radlib system 1, workdir /usr/local/var/wview
Apr 17 22:36:10 wxserver radmrouted[5213]: <1240022170853> :
running...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171858> : radlib:
wviewd started as a daemon ...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171858> : wview 5.4.0p1
starting ...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171861> : station
interface: serial ...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171862> : Rain Season
Start Month set to 1
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171862> : Rain Storm
Start Trigger set to 0.05 in/hr
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171862> : Rain Storm
Stop Time set to 12 hours
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171862> : Rain YTD
preset set to 0.00 inches
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171862> : ET YTD preset
set to 0.000 inches
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171863> : bad rain/ET
YTD Year given, disabling...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171863> : station
polling interval set to 30 seconds
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171892> : HILOW:
database OK
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171892> : HILOW:
beginning normal LOOP operation
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171892> : -- Station
Init Start --
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : station
archive interval: 5 minutes
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : Simulator
station opened: 720 minute data generation period...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : running...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : station
location: elevation: 210 feet
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : station
location: latitude: 37.8 N longitude: 77.5 W
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171894> : initializing
computed data values...
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171897> :
computeDataAllTime: 200904
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171903> :
computeDataYear: 200904
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171910> :
computeDataMonth: 200904
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171921> :
computeDataDay: 20090417
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171997> : -- Station
Init Complete --
Apr 17 22:36:11 wxserver wviewd[5217]: <1240022171998> : newest
archive record: 2009-04-17 22:35
Apr 17 22:36:12 wxserver htmlgend[5223]: <1240022172864> : radlib:

htmlgend started as a daemon ...

Apr 17 22:36:12 wxserver wvalarmd[5227]: <1240022172868> : radlib:
wvalarmd started as a daemon ...
Apr 17 22:36:12 wxserver htmlgend[5223]: <1240022172873> : generating
to /usr/local/var/wview/img
Apr 17 22:36:12 wxserver htmlgend[5223]: <1240022172873> : templates
at /usr/local/etc/wview/html
Apr 17 22:36:12 wxserver htmlgend[5223]: <1240022172874> : !! Dual
units will be displayed !!
Apr 17 22:36:12 wxserver htmlgend[5223]: <1240022172874> : Tag Search
red-black tree: max black node tree height: 7
Apr 17 22:36:12 wxserver wvcwopd[5231]: <1240022172876> : radlib:
wvcwopd started as a daemon ...
Apr 17 22:36:12 wxserver wviewftpd[5236]: <1240022172882> : radlib:
wviewftpd started as a daemon ...
Apr 17 22:36:12 wxserver wviewsshd[5241]: <1240022172888> : radlib:
wviewsshd started as a daemon ...
Apr 17 22:36:12 wxserver wviewftpd[5236]: <1240022172893> : ftp daemon
disabled - exiting...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172894> : radlib:
wvpmond started as a daemon ...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172971> : PMON:
wviewd: 0
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172971> : PMON: wviewd
process monitoring is disabled
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172971> : PMON:
htmlgend: 5
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172971> : PMON:
wvalarmd: 120
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON: pid
file /usr/local/var/wview/wvalarmd.pid not present, disable
monitoring...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON:
wvcwopd: 120
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON: pid
file /usr/local/var/wview/wvcwopd.pid not present, disable
monitoring...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON:
wvhttpd: 120
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON: pid
file /usr/local/var/wview/wvhttpd.pid not present, disable
monitoring...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON:
wviewsqld: 600
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : PMON: pid
file /usr/local/var/wview/wviewsqld.pid not present, disable
monitoring...
Apr 17 22:36:12 wxserver wvpmond[5246]: <1240022172972> : running...
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173401> : running...
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173401> : received
station info from wviewd: 20090417 22:35:00
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173402> :
htmlmgrInit: 66 built-in image definitions added
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173402> :
htmlmgrInit: 0 user image definitions added
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173402> :
htmlmgrInit: 14 templates added
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173402> :
htmlmgrInit: forecast html tags are disabled - /usr/local/etc/wview/
forecast.conf not found...
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173404> :
initializing barometric pressure trend
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173404> :
initializing historical stores (this may take some time...)
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173405> :
htmlHistoryInit: DAY: samples=0
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173415> :
htmlHistoryInit: DAY: samples=50
...................snip.........................................
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173947> :
htmlHistoryInit: YEAR: samples=350
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173957> :
htmlHistoryInit: YEAR: samples=365
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173958> : HILOW: OK
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173958> : NOAA DB: OK
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173958> : NOAA:
initilizing reports (this may take some time...)
Apr 17 22:36:13 wxserver htmlgend[5223]: <1240022173959> : NOAA DB:
syncing 19700101 => 20090416
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190333> : NOAA DB:
done: 0 HILOW records => 0 NOAA records
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190333> : NOAA
Generate: creating monthly NOAA reports starting 200904
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190333> : NOAA
Generate: creating yearly NOAA reports starting 2009
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190334> : ARCREC:
initializing archive browser files (this may take some time...)
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190334> : ARCREC:
using header file /usr/local/etc/wview/arcrec-header.conf ...
Apr 17 22:36:30 wxserver htmlgend[5223]: <1240022190334> : ARCREC:

saving ALL daily archive reports ...

Apr 17 22:36:31 wxserver htmlgend[5223]: <1240022191047> : ARCREC: 1
daily archive reports available
Apr 17 22:36:32 wxserver htmlgend[5223]: <1240022192000> : starting
html generation in 3 mins 38 secs
Apr 17 22:36:32 wxserver htmlgend[5223]: <1240022192000> : doing
initial html generation now...
Apr 17 22:40:04 wxserver wviewd[5217]: <1240022404997> : storing
record for 2009-04-17 22:40
Apr 17 22:40:05 wxserver htmlgend[5223]: <1240022405010> : Adding 5
minute sample for 2009-04-17 22:40...

[Mark S. Teel]

That boot log looks gorgeous. htmlgend didn't die or restart. What was
the problem after this boot?

[bgrattan]

Mark,

Here is a shot from an earlier system reboot where I think the
problem is occuring. wview seems to be running but it's not updating
the html pages. I've restarted wview several times after this but the
web pages don't update. The "Generated: 248 ms: 66 images, 14 template
files" appears here but doesn't show up in the boot log I sent
earlier. I made a cange from classic to chrome to test whether the
page was changing and the format did change but then stuck again and
never updated after the initial change to chrome. The "broken pipe"
error must have something to do with the problem. Thanks.


Apr 17 17:24:05 wxserver htmlgend[3078]: <1240003445236> : ARCREC: 1
daily archive reports available
Apr 17 17:24:06 wxserver htmlgend[3078]: <1240003446000> : starting
html generation in 1 mins 4 secs
Apr 17 17:24:06 wxserver htmlgend[3078]: <1240003446000> : doing
initial html generation now...
Apr 17 17:24:06 wxserver htmlgend[3078]: <1240003446248> : Generated:
248 ms: 66 images, 14 template files
Apr 17 17:25:04 wxserver wviewd[3072]: <1240003504862> : storing
record for 2009-04-17 17:25
Apr 17 17:25:04 wxserver htmlgend[3078]: <1240003504875> : Adding 5
minute sample for 2009-04-17 17:25...
Apr 17 17:25:10 wxserver htmlgend[3078]: <1240003510314> : Generated:
64 ms: 31 images, 14 template files
Apr 17 17:26:46 wxserver radmrouted[3063]: <1240003606815> :

radQueueSend: write failed on fd 9: Broken pipe

Apr 17 17:26:52 wxserver htmlgend[3306]: <1240003612828> : radlib:

htmlgend started as a daemon ...

Apr 17 17:26:52 wxserver htmlgend[3306]: <1240003612830> : generating
to /usr/local/var/wview/img
Apr 17 17:26:52 wxserver htmlgend[3306]: <1240003612831> : templates
at /usr/local/etc/wview/html

[bgrattan]

Mark,

I rebuilt everything a couple of times and then rebuilt with wview
5.4.0 and got the same problem as mentioned above. When wiew starts
it runs fine for 15 minutes or so and updates the html pages. After
it experiences the "write failed on fd 9: Broken pipe " then it stops
updating the html pages although it's running and adding archives.
I've followed Joe's script (manually) using the rev. 2 but I get the
same problem. The reboot seems to make a difference buth then I've
been rebuilding and stopping/starting several times. Thanks for any
insight.

Bob

[Mark S. Teel]

I suspect something is not right with your HTML templates or other
htmlgend setup. htmlgend is apparently the one that is dying - still
couldn't really tell based on the partial logs you sent.

You should be able to find the log entries when it dies - right before
the first broken pipe log...

Mark

[bgrattan]

This is what I show in the logs:

Apr 18 17:48:08 wxserver htmlgend[3492]: <1240091288000> : starting
html generation in 2 mins 2 secs
Apr 18 17:48:08 wxserver htmlgend[3492]: <1240091288000> : doing
initial html generation now...
Apr 18 17:48:43 wxserver radmrouted[3099]: <1240091323831> :
radQueueSend: write failed on fd 9: Broken pipe
Apr 18 17:48:50 wxserver htmlgend[3497]: <1240091330039> : radlib:

htmlgend started as a daemon ...

Apr 18 17:48:50 wxserver htmlgend[3497]: <1240091330041> : generating
to /usr/local/var/wview/img

After a couple of these it doesn't appear again and the html pages
stop updating.

Htmlgend seems to be running (restarted as above) but no updates to
html pages:

root 3497 1 0 17:48 ? 00:00:17 /usr/local/bin/
htmlgend
root 3498 3497 0 17:48 ? 00:00:00 /usr/local/bin/
htmlgend

Is there anything else I can send that might give you a clue as to
what is going on? Thanks.

Bob

[Mark S. Teel]

OK, so what in the crap is restarting htmlgend? Do you have something
else monitoring processes and restarting them?

[bgrattan]

I have nothing that I know of that would be restarting htmlgend. This
is a brand new install of lenny and vwiew is the only app I have
running, other than the stuff that debian uses.

It looks as if the htmlmgrInit process isn't rerunning after the first
several times when the broken pipe error occurrs. I do have to reboot
the computer to get wview to start correctly--simply wview stop/start
without a reboot only continues the error state. After the reboot,
everything seems to start up correctly and run for about 15 minmutes
and then the broken pipe from radQueueSend. After that, no html page
updates.

I ran the script you setup for 5.4.0 (it ran fine, by the way) but am
back at the same error. Is there any other debugging I can turn on to
follow what is happening? Thanks.


Apr 19 11:11:49 wxserver htmlgend[3653]: <1240153909670> :

htmlmgrInit: 66 built-in image definitions added

Apr 19 11:11:49 wxserver htmlgend[3653]: <1240153909670> :

htmlmgrInit: 0 user image definitions added

Apr 19 11:11:49 wxserver htmlgend[3653]: <1240153909670> :
htmlmgrInit: 14 templates added
Apr 19 11:11:49 wxserver htmlgend[3653]: <1240153909670> :

htmlmgrInit: forecast html tags are disabled - /usr/local/etc

Apr 19 11:17:07 wxserver htmlgend[3684]: <1240154227000> : starting
html generation in 3 mins 3 secs
Apr 19 11:17:07 wxserver htmlgend[3684]: <1240154227000> : doing
initial html generation now...
Apr 19 11:17:42 wxserver radmrouted[3358]: <1240154262938> :

radQueueSend: write failed on fd 9: Broken pipe

Apr 19 11:17:49 wxserver htmlgend[3692]: <1240154269167> : radlib:

htmlgend started as a daemon ...

Apr 19 11:17:49 wxserver htmlgend[3692]: <1240154269169> : generating
to /usr/local/var/wview/img
Apr 19 11:17:49 wxserver htmlgend[3692]: <1240154269169> : templates
at /usr/local/etc/wview/html

[Mark S. Teel]

Turn on verbose logging for the process monitor (wvpmond) and of course
htmlgend. Apparently the process monitor is enabled for htmlgend
(default behavior).

If we see process monitor logs, the restart mystery will be solved.

The real problem has to do with htmlgend dying during the initial
generation cycle. I've only seen this when the html-templates.conf file
has bad entries (no corresponding template file), or the html templates
themselves have a problem, or a goofy value in the configuration
database. I have tried to add better logging in these scenarios, but
perhaps some failure scenario is not well logged.

Mark

[bgrattan]

Here is something I found in the syslog. Maybe it will help.

Apr 19 11:18:07 wxserver htmlgend[3692]: <1240154287000> : doing
initial html generation now...
Apr 19 11:18:07 wxserver htmlgend[3692]: <1240154287112> : htmlgend:
recv sig 11: shutting down!
Apr 19 11:18:07 wxserver htmlgend[3692]: <1240154287112> : htmlgend:
recv sig 6: exiting!
Apr 19 11:18:42 wxserver radmrouted[3358]: <1240154322938> :

radQueueSend: write failed on fd 9: Broken pipe

Apr 19 11:18:42 wxserver radmrouted[3358]: <1240154322938> :
sendToConsumer: htmlgend: radProcessQueueSend failed!
Apr 19 11:18:42 wxserver radmrouted[3358]: <1240154322938> :
msgHandler: htmlgend: sendToConsumer failed!
Apr 19 11:18:47 wxserver wvpmond[3396]: <1240154327166> :
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 19 11:18:47 wxserver wvpmond[3396]: <1240154327167> : PMON >>>> /
usr/local/bin/htmlgend did not respond to poll!
Apr 19 11:18:47 wxserver wvpmond[3396]: <1240154327167> : PMON >>>>
OLDPID: 3692
Apr 19 11:18:47 wxserver wvpmond[3396]: <1240154327167> : PMON >>>>
SIGTERM: /usr/local/bin/htmlgend
Apr 19 11:18:47 wxserver wvpmond[3396]: <1240154327167> : PMON >>>>
waiting for /usr/local/bin/htmlgend to exit
Apr 19 11:18:49 wxserver wvpmond[3396]: <1240154329167> : PMON >>>>
SIGKILL: /usr/local/bin/htmlgend
Apr 19 11:18:49 wxserver wvpmond[3396]: <1240154329167> : PMON >>>>
deleting: /usr/local/var/wview/htmlgend.pid
Apr 19 11:18:49 wxserver wvpmond[3396]: <1240154329167> : PMON >>>>
starting: /usr/local/bin/htmlgend
Apr 19 11:18:49 wxserver htmlgend[3704]: <1240154329170> : radlib:

[Mark S. Teel]

Ya think!

OK, so the restart mystery is just wvpmond doing its job. Good.

SIG 11 is SEGV (segmentation fault). This is the exact scenario I
described earlier. Have you customized anything? Have you tried a plain
vanilla install?

If you are doing a plain vanilla install, then I would start looking at
my prerequisites, in particular our friend SQLite3. Is it a recent
version? Is there an older installed copy that is being dynamically
loaded first?

Mark

[Mark S. Teel]

Copy the attached file to $distro/htmlgenerator and execute "make
install". Then re-run wview and send me the logs, all of them please.

This will generate a bunch of logs with each generation, so you will
want to replace this file once we figure out the problem.

Mark

[Deborah]

I got signal 11 on htmlgend too, as of today, just like Bob. The
syslog output is much the same.

I couldn't finger what thing has changed; in the last week almost
everything has changed in my setup.

I am getting odd values in the NOAA daily records. Observe:
http://futzle-home.no-ip.org/weather/Archive/ARC-2009-04-20.txt,
starting around 7 pm. Is that just a result of wview being down for
that time, and not able to populate the fields after being restarted?

I'll also compile and run htmlMgr.c and post my findings.

[Deborah]

> The real problem has to do with htmlgend dying during the initial
> generation cycle.

Probably unrelated: I managed to kill htmlgend the very first time I
ran wview post-5.0.0, when it had to generate almost a year of
historical NOAA pages. It took so long that wvpmond thought it had
failed to run, so wvpmond killed it. It only happened the one time.

[Deborah]

> SIG 11 is SEGV (segmentation fault). This is the exact scenario I
> described earlier. Have you customized anything? Have you tried a plain
> vanilla install?

I know you weren't asking me, but since I have the same crash...

My only customization is the vpconfig customizations new to 5.4.0.
I've made no changes to htmlgenerator, and the only changes I made to
the HTML templates was to remove the background image reference on the
body of the index.htm page.

I wonder if the bug I just raised on the Mantis server (http://
www.wviewweather.com/mantis/view.php?id=64) is related. Segfaults
happen with out-of-bounds array accesses, among other things, so you
never know...

> If you are doing a plain vanilla install, then I would start looking at
> my prerequisites, in particular our friend SQLite3. Is it a recent
> version? Is there an older installed copy that is being dynamically
> loaded first?

On my machine, a brand new Debian lenny install, the only version of
sqlite that was ever installed is the current one, 3.5.9-6. The dev
version which radlib and wview were built against is the same.

[Mark S. Teel]

The more the merrier...

Deborah wrote:
>> SIG 11 is SEGV (segmentation fault). This is the exact scenario I
>> described earlier. Have you customized anything? Have you tried a plain
>> vanilla install?
>>
>
> I know you weren't asking me, but since I have the same crash...
>
> My only customization is the vpconfig customizations new to 5.4.0.
> I've made no changes to htmlgenerator, and the only changes I made to
> the HTML templates was to remove the background image reference on the
> body of the index.htm page.
>
> I wonder if the bug I just raised on the Mantis server (http://
> www.wviewweather.com/mantis/view.php?id=64) is related. Segfaults
> happen with out-of-bounds array accesses, among other things, so you
> never know...
>

I doubt it - the sensor values are array values, not indices, for the
graphs. I'm more interested in what was happening when you were getting
NULL values in you ARC browser file for today. Does the archive database
records match that or is it a browser file anamoly? Any feedback on the
generation debugs yet?

[bgrattan]

Mark et al.,

I decided to reinstall sqlite3 and something in the system got hosed
(by me, I'm sure). I'm going to reinstall lenny and wview on another
machine (MSI Wind PC) since that was to be the final destination
anyway. I think your software is great and I appreciate all the
help. I'm not a linux whiz so frequently I have to redo things. My
wview 4.0.1 is running solid on the RedHat ES5 so now I'm trying to
learn a new distro (debian). I'll get back to you in a few with the
results.
Thanks again for the help.

Bob

[Deborah]

Hi Mark,

> I'm more interested in what was happening when you were getting
> NULL values in you ARC browser file for today. Does the archive database
> records match that or is it a browser file anamoly? Any feedback on the
> generation debugs yet?

I used the Firefox sqlite add-on to look at the *.sdb file itself.
They are also NULL.

I checked the log, thinking that wviewd wasn't fetching archive
records, and that the NULL records were populated after I restarted
wviewd. That doesn't seem to be the case, though. wviewd is still
reporting "Adding 5 minute sample for..." every five minutes during
the period in question.

The null values in the database are for the fields: wind speed, wind
direction*, wind gust direction*, dewpoint, windchill, heat index.
The other values appear to be correct. Even the hourly ET
accumulation comes through OK. The NOAA pages are accurately
reflecting what is in the database.

The generation hasn't failed since I added your debug statements. I
will report when it does.

* Of course, this is also null when the wind speed is zero, but this
is in addition to those cases.

[Mark S. Teel]

Greetings,

Thanks for your succinct descriptions.

Deborah wrote:
> Hi Mark,
>
>
>> I'm more interested in what was happening when you were getting
>> NULL values in you ARC browser file for today. Does the archive database
>> records match that or is it a browser file anamoly? Any feedback on the
>> generation debugs yet?
>>
>
> I used the Firefox sqlite add-on to look at the *.sdb file itself.
> They are also NULL.
>
> I checked the log, thinking that wviewd wasn't fetching archive
> records, and that the NULL records were populated after I restarted
> wviewd. That doesn't seem to be the case, though. wviewd is still
> reporting "Adding 5 minute sample for..." every five minutes during
> the period in question.
>
> The null values in the database are for the fields: wind speed, wind
> direction*, wind gust direction*, dewpoint, windchill, heat index.
> The other values appear to be correct. Even the hourly ET
> accumulation comes through OK. The NOAA pages are accurately
> reflecting what is in the database.
>

Just as a point of minutia, the ARC record browser is not NOAA related,
strictly speaking.

> The generation hasn't failed since I added your debug statements. I
> will report when it does.
>

I think it is totally related to the NULL values and won't happen again
until that phenomenon does.
When I ask "what was happening" during those NULL records, I mean:
Were you in the middle of a long NOAA or ARC browser generation during init?
Did those records arrive from the envoy while htmlgend was still
initializing?
Etc.

Further, you could wipe all of your archive records since midnight of
the day those NULLs occurred, wipe your HILOW and NOAA databases and do
it again with the debug code. All the while observing what process is
doing what as those records are retrieved. A bit of a pain for a general
debug result, totally up to you.

[Deborah]

Hi Mark,

> I think it is totally related to the NULL values and won't happen again
> until that phenomenon does.

I do get one-off instances of the NULL values every so often. Take a
look at http://futzle-home.no-ip.org/weather/Archive/ARC-2009-04-21.txt
at 9.20 am, for instance. That will correspond to NULL in the archive
database for that record.

> When I ask "what was happening" during those NULL records, I mean:
> Were you in the middle of a long NOAA or ARC browser generation during init?
> Did those records arrive from the envoy while htmlgend was still
> initializing?
> Etc.

wview was running unattended. Looking at the logs, there was nothing
special around the times of those NULL values. The times don't seem
to coincide with the htmlgend segfaults either, so I'm wondering if
they are unrelated and I have hijacked this thread. When I am home
again I will look at the logs and see if there is a correlation
between NULL entries and htmlgend crashes.

> Further, you could wipe all of your archive records since midnight of
> the day those NULLs occurred, wipe your HILOW and NOAA databases and do
> it again with the debug code. All the while observing what process is
> doing what as those records are retrieved. A bit of a pain for a general
> debug result, totally up to you.

That's true; the envoy will still have that data in its datalogger.
It would be instructive to see if the blackouts occur at the same
time. In fact, now that I look through the archive, I notice that the
blackouts only started happening since I replaced the VP2 console with
the envoy. Interesting...

[Mark S. Teel]

Howdy,

Deborah wrote:
> Hi Mark,
>
>
>> I think it is totally related to the NULL values and won't happen again
>> until that phenomenon does.
>>
>
> I do get one-off instances of the NULL values every so often. Take a
> look at http://futzle-home.no-ip.org/weather/Archive/ARC-2009-04-21.txt
> at 9.20 am, for instance. That will correspond to NULL in the archive
> database for that record.
>
>
>> When I ask "what was happening" during those NULL records, I mean:
>> Were you in the middle of a long NOAA or ARC browser generation during init?
>> Did those records arrive from the envoy while htmlgend was still
>> initializing?
>> Etc.
>>
>
> wview was running unattended. Looking at the logs, there was nothing
> special around the times of those NULL values. The times don't seem
> to coincide with the htmlgend segfaults either, so I'm wondering if
> they are unrelated and I have hijacked this thread.

I don't think you hijacked the thread - you had the htmlgend crash too.
Maybe they are unrelated...

> When I am home
> again I will look at the logs and see if there is a correlation
> between NULL entries and htmlgend crashes.
>
>
>> Further, you could wipe all of your archive records since midnight of
>> the day those NULLs occurred, wipe your HILOW and NOAA databases and do
>> it again with the debug code. All the while observing what process is
>> doing what as those records are retrieved. A bit of a pain for a general
>> debug result, totally up to you.
>>
>
> That's true; the envoy will still have that data in its datalogger.
> It would be instructive to see if the blackouts occur at the same
> time. In fact, now that I look through the archive, I notice that the
> blackouts only started happening since I replaced the VP2 console with
> the envoy. Interesting...
>

And I seem to vaguely remember that the envoy liked to send more "0xFF"
values for sensors than the VP console does. If you do decide to try
this, it might be good to dump the raw envoy data as it is received to
the log file too.
> >
>

[Deborah]

> >> Further, you could wipe all of your archive records

> > That's true; the envoy will still have that data in its datalogger.
> > It would be instructive to see if the blackouts occur at the same
> > time.

> And I seem to vaguely remember that the envoy liked to send more "0xFF"
> values for sensors than the VP console does.

I can confirm that. I deleted today's archive records and let wviewd
repopulate them from the Envoy. I got the same NULL value for wind
speed at 9.20 am. That means my NULLs are "real" and that wviewd
isn't miscommunicating with the Envoy. Good.

[bgrattan]

Mark,

I have moved to another computer (Intel Atom 230 MSI Wind PC), another
OS (Ubuntu 9.04 -i386), and a complete install of wview 5.4.0 and
radlib 2.8.2. I went through the script you posted manually as I
wanted to be certain that I saw all of the messages resulting from the
downloads, etc. All prerequisites you listed are present and
installed--no build errors were noticed. I am using the extra-logging
file you sent htmlMgr.c.

I'm still getting the Broken pipe error and the system stops updating
the html screens. In the file, only one archive record appears which
was stored at 12:45. According to the messages, others were stored but
I only see one (12:45) in ARC-2009-04-26.txt.

Since the logs are somewhat long, I am sending them to you direct.

Thanks.

Bob

>  htmlMgr.c
> 32KViewDownload- Hide quoted text -
>
> - Show quoted text -

[bgrattan]

Mark,

More info from another part of the log after I restarted wview:

Apr 26 16:01:10 wx htmlgend[5175]: <1240776070251> : GENERATE: images
Apr 26 16:01:10 wx htmlgend[5175]: <1240776070331> : htmlgend: recv
sig 11: shutting down!
Apr 26 16:01:10 wx htmlgend[5175]: <1240776070331> : htmlgend: recv
sig 6: exiting!
Apr 26 16:01:54 wx radmrouted[5166]: <1240776114175> : radQueueSend:

write failed on fd 9: Broken pipe

Apr 26 16:01:54 wx radmrouted[5166]: <1240776114175> : sendToConsumer:
htmlgend: radProcessQueueSend failed!
Apr 26 16:01:54 wx radmrouted[5166]: <1240776114175> : msgHandler:
htmlgend: sendToConsumer failed!
Apr 26 16:01:58 wx wvpmond[5193]: <1240776118254> :
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Apr 26 16:01:58 wx wvpmond[5193]: <1240776118254> : PMON >>>> /usr/

local/bin/htmlgend did not respond to poll!

Apr 26 16:01:58 wx wvpmond[5193]: <1240776118254> : PMON >>>> OLDPID:
5175
Apr 26 16:01:58 wx wvpmond[5193]: <1240776118254> : PMON >>>>
SIGTERM: /usr/local/bin/htmlgend
Apr 26 16:01:58 wx wvpmond[5193]: <1240776118254> : PMON >>>> waiting
for /usr/local/bin/htmlgend to exit
Apr 26 16:02:00 wx wvpmond[5193]: <1240776120254> : PMON >>>>
SIGKILL: /usr/local/bin/htmlgend
Apr 26 16:02:00 wx wvpmond[5193]: <1240776120254> : PMON >>>>
deleting: /usr/local/var/wview/htmlgend.pid
Apr 26 16:02:00 wx wvpmond[5193]: <1240776120255> : PMON >>>>
starting: /usr/local/bin/htmlgend
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : PMON: failed to
OPEN /usr/local/var/wview/htmlgend.pid!
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : PMON >>>> GETPID /
usr/local/bin/htmlgend failed: No such file or directory
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : PMON >>>> Process
Monitor shutting down:
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : PMON >>>> Please
report this incident to wview Forums
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : radProcessWait:
exit flag is set!
Apr 26 16:02:02 wx wvpmond[5193]: <1240776122255> : exiting
normally...

> > - Show quoted text -- Hide quoted text -

[Mark S. Teel]

So my guess is that you have some NULL values in your archive data. Look
at the data using sqlite3 and if there are NULLs for important data
(outTemp, outHumidity, etc.) please provide excerpts from an execution
of "select * from archive..." within sqlite3 (the command line utility).

Mark