Nut upsuser - Dec 2010 - Belkin Regulator Pro dropping connection and halting

I've a Belkin Regulator Pro (F6C1400-EUR) connected via serial to a 
FreeBSD machine using NUT v.2.4.3

Sometimes I get a series of logged messages saying that the data is 
switching between stale and valid, this in itself isn't an issue, 
however occasionally when the communication is re-established, upsmon 
gets a "On battery" message followed quickly by "Battery
low" message,
and calls on the system to halt. I know for a fact that the battery 
isn't low at any stage, as other UPSs have not reported a loss of power. 
This behaviour has only started occurring since using NUT rather than 
Belkin Bulldog (not supported on FreeBSD x64).

Dec  1 08:02:46 rack upsd[941]: UPS [belkinreg] data is no longer stale
Dec  1 08:02:47 rack upsmon[957]: Communications with UPS 
belkinreg at localhost established
Dec  1 08:02:48 rack upsd[941]: Data for UPS [belkinreg] is stale - 
check driver
Dec  1 08:02:52 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
Dec  1 08:02:52 rack upsmon[957]: Communications with UPS 
belkinreg at localhost lost
Dec  1 08:02:57 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
Dec  1 08:02:59 rack upsd[941]: UPS [belkinreg] data is no longer stale
Dec  1 08:03:00 rack upsd[941]: Data for UPS [belkinreg] is stale - 
check driver
Dec  1 08:03:02 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
Dec  1 08:03:27 rack last message repeated 5 times
Dec  1 08:03:32 rack upsd[941]: UPS [belkinreg] data is no longer stale
Dec  1 08:03:32 rack upsmon[957]: Communications with UPS 
belkinreg at localhost established
Dec  1 08:03:34 rack upsd[941]: Data for UPS [belkinreg] is stale - 
check driver
Dec  1 08:03:37 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
Dec  1 08:03:37 rack upsmon[957]: Communications with UPS 
belkinreg at localhost lost
Dec  1 08:03:42 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
...
Dec  1 08:03:52 rack upsmon[957]: Poll UPS [belkinreg at localhost] failed 
- Data stale
Dec  1 08:03:52 rack upsmon[957]: Communications with UPS 
belkinreg at localhost lost
Dec  1 08:03:57 rack upsd[941]: UPS [belkinreg] data is no longer stale
Dec  1 08:03:57 rack upsmon[957]: Communications with UPS 
belkinreg at localhost established
Dec  1 08:03:57 rack upsmon[957]: UPS belkinreg at localhost on battery
Dec  1 08:03:57 rack upsmon[957]: UPS belkinreg at localhost battery is low
Dec  1 08:03:57 rack upsmon[957]: Executing automatic power-fail shutdown
Dec  1 08:03:57 rack upsmon[957]: Auto logout and shutdown proceeding

I can see no reason why the NUT is seeing a battery low message. 
Unfortunately there is only a 5 minute resolution for the ups log:

20101201 072111 100 238.7 022 [OL] 012 50.1
20101201 072611 NA NA NA [NA] NA NA
20101201 073111 NA NA NA [NA] NA NA
20101201 073611 000 000.0 2400 [OL] 000 0.0
20101201 074111 NA NA NA [NA] NA NA
20101201 074611 NA NA NA [NA] NA NA
20101201 075111 NA NA NA [NA] NA NA
20101201 075611 NA NA NA [NA] NA NA
20101201 080111 NA NA NA [NA] NA NA
20101201 090322 NA NA NA [WAIT] NA NA
20101201 090822 100 234.5 024 [OL] 017 49.9
20101201 091348 NA NA NA [WAIT] NA NA
20101201 091848 100 236.7 022 [OL] 017 50.0
20101201 092348 100 235.7 022 [OL] 017 49.9

Has anyone got any suggestions?

John

On Dec 1, 2010, at 7:42 AM, John Bayly wrote:
> I've a Belkin Regulator Pro (F6C1400-EUR) connected via serial to a  
> FreeBSD machine using NUT v.2.4.3
>
> Sometimes I get a series of logged messages saying that the data is  
> switching between stale and valid, this in itself isn't an issue,  
> however occasionally when the communication is re-established,  
> upsmon gets a "On battery" message followed quickly by
"Battery low"
> message, and calls on the system to halt. I know for a fact that the  
> battery isn't low at any stage, as other UPSs have not reported a  
> loss of power. This behaviour has only started occurring since using  
> NUT rather than Belkin Bulldog (not supported on FreeBSD x64).
I would suggest temporarily disabling the automated shutdown (maybe  
replacing it with some sort of notification), and running the driver  
with debugging enabled; however, there don't seem to be many  
upsdebugx() calls in the code.

The get_belkin_reply() function looks fragile to me. Three seconds  
should be enough to fill the buffer, but if you put a few upsdebugx()  
calls around ser_get_buf_len(), it should be evident whether the read  
is timing out, or if there is a problem with the format of the response.

-- 
Charles Lepple