Mārtiņš Puķītis
2013-Jun-10 17:05 UTC
[Nut-upsuser] several problems with Powercom BNT-500AP
I took the log. Here's what happened. Broadcast Message from nut at rasp (somewhere) at 16:18 ... UPS BNT500AP at localhost battery needs to be replaced occurred when for the first time value "1" was read as "UPS.PowerSummary.PresentStatus.NeedReplacement", on this line: 6409.240690 Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Input, ReportID: 0x0a, Offset: 6, Size: 1, Value: 1 It happened for 9 times, but the message appeared only on first. Broadcast Message from nut at rasp (somewhere) at 17:33 ... UPS BNT500AP at localhost on battery occurred when UPS.PowerSummary.PresentStatus.ACPresent turned to 0 on this line: 10921.069403 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 Broadcast Message from nut at rasp (somewhere) at 17:33 ... UPS BNT500AP at localhost on line power There were 3 more "on battery" events at 2:31: 43194.030619 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 Here I also see a suspisious frequency value 70. How is this possible? 43194.046966 Path: UPS.Input.Frequency, Type: Feature, ReportID: 0x1e, Offset: 0, Size: 8, Value: 70 At 2:58: 44790.984549 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 Here all voltages and frequencies are OK, so I don't understand why ACPresent is 0. 44790.374516 Path: UPS.Input.Voltage, Type: Feature, ReportID: 0x1d, Offset: 0, Size: 16, Value: 232 44790.375512 Path: UPS.Input.Frequency, Type: Feature, ReportID: 0x1e, Offset: 0, Size: 8, Value: 50 44790.376535 Path: UPS.Output.Voltage, Type: Feature, ReportID: 0x21, Offset: 0, Size: 16, Value: 232 44790.377511 Path: UPS.Output.Frequency, Type: Feature, ReportID: 0x22, Offset: 0, Size: 8, Value: 50 and at 6:15: 56597.541128 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 At 6:15 I also got "Low battery" event that triggered Raspberry pi shutdown, but I don't see a reason for that in the driver log. When it happened, the UPS started beeping every 2 seconds and I could silence it by pressing the power button, as written in user manual. I was only able to silence it by shutting down completely. By the way, the first time it happened also at about the same time. I'm not able to post the log, because even compressed it is more than 1 MB. -----Original Message----- From: Charles Lepple [mailto:clepple at gmail.com] Sent: Saturday, June 08, 2013 10:49 PM To: M?rti?? Pu??tis Cc: 'nut-upsuser lists.alioth.debian.org' Subject: Re: [Nut-upsuser] several problems with Powercom BNT-500AP On Jun 8, 2013, at 12:57 PM, M?rti?? Pu??tis wrote:> I'll take a longer driver log. This page (http://www.networkupstools.org/support.html) says that to take a driver log NUT should be stopped, so I won't be able to tell when these events occurred within a driver log.Hmm, I didn't realize it said that, but I think that's to prevent having two copies of the same driver running at the same time. (That's even more difficult to decipher from one log alone.) You can either just restart the driver, or restart upsd after stopping everything. In either case, I was thinking that it would be useful to know where *in the longer log* the events occur. Then we can look to see if the UPS is returning bad information, or if the driver is experiencing an error condition. -- Charles Lepple clepple at gmail
Charles Lepple
2013-Jun-11 13:27 UTC
[Nut-upsuser] several problems with Powercom BNT-500AP
[I am CC'ing Alexey from Powercom in case he has seen any of these issues with the Raspberry Pi hardware.] On Jun 10, 2013, at 1:05 PM, M?rti?? Pu??tis wrote:> I took the log. Here's what happened. > Broadcast Message from nut at rasp > (somewhere) at 16:18 ... > UPS BNT500AP at localhost battery needs to be replaced > > occurred when for the first time value "1" was read as "UPS.PowerSummary.PresentStatus.NeedReplacement", on this line: > 6409.240690 Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Input, ReportID: 0x0a, Offset: 6, Size: 1, Value: 1 > It happened for 9 times, but the message appeared only on first.Correct, upsmon throttles the REPLBATT event: http://www.networkupstools.org/docs/man/upsmon.conf.html (search for RBWARNTIME)> Broadcast Message from nut at rasp > (somewhere) at 17:33 ... > > UPS BNT500AP at localhost on battery > occurred when UPS.PowerSummary.PresentStatus.ACPresent turned to 0 on this line: > 10921.069403 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0If you turn up the debugging level from 2 to 3, the driver will do a hex dump of the report buffer. Offset and size are bits, so if the ACPresent bit is 0, that's what the driver reports.> Here I also see a suspisious frequency value 70. How is this possible? > 43194.046966 Path: UPS.Input.Frequency, Type: Feature, ReportID: 0x1e, Offset: 0, Size: 8, Value: 70Similar situation to ACPresent - if those are the bits coming in, that's what the driver reports. Granted, there are cases where usbhid-ups might be misinterpreting those bits, but as you can imagine, it is hard to test all of the corner cases. We should be getting an error message from usbhid-ups if the USB reply is not long enough.> At 2:58: > 44790.984549 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 > Here all voltages and frequencies are OK, so I don't understand why ACPresent is 0.usbhid-ups does not look at voltage and frequency to determine whether AC is present. Voltage and frequency values can be averages over time (with the averaging being performed in the UPS microprocessor), so the driver simply trusts the ACPresent bit returned by the UPS. I'm starting to wonder if the USB controller or driver in the Raspberry Pi is flaky. We have seen odd issues with other ARM/Linux boards, and none of the symptoms are the same as on x86 PCs. Do you have a desktop or laptop Linux system where you can test this? -- Charles Lepple clepple at gmail
Mārtiņš Puķītis
2013-Nov-27 20:19 UTC
[Nut-upsuser] several problems with Powercom BNT-500AP
Hello. It's been a while since I started this topic. I've finally tested it on Linux desktop PC. Nut version 2.6.4-2.3 Basically the behavior is the same as on raspberry pi. It reports "battery needs to be replaced" regularly and I got "on battery" message 114107.780504 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 (on line nr. 1044540 in log) after ~ 31 hours of testing along with immediate "low battery (critical)" not sure, but probably because of 114107.780620 Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Input, ReportID: 0x0a, Offset: 4, Size: 1, Value: 1 (on line nr. 1044544 in log) message. Full zipped log (5,8 MB) with -DDD driver debug level available at http://wikisend.com/download/396966/upsdebug.zip As before, no power failure was present at the time this happened. The UPS at the time I bought it (in June) was capable of supplying backup power for PC for more than 15 minutes. Martins Pukitis. -----Original Message----- From: Charles Lepple [mailto:clepple at gmail.com] Sent: Tuesday, June 11, 2013 4:27 PM To: M?rti?? Pu??tis Cc: nut-upsuser lists.alioth.debian.org; morozov at pcm.ru Subject: Re: [Nut-upsuser] several problems with Powercom BNT-500AP [I am CC'ing Alexey from Powercom in case he has seen any of these issues with the Raspberry Pi hardware.] On Jun 10, 2013, at 1:05 PM, M?rti?? Pu??tis wrote:> I took the log. Here's what happened. > Broadcast Message from nut at rasp > (somewhere) at 16:18 ... > UPS BNT500AP at localhost battery needs to be replaced > > occurred when for the first time value "1" was read as "UPS.PowerSummary.PresentStatus.NeedReplacement", on this line: > 6409.240690 Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Input, ReportID: 0x0a, Offset: 6, Size: 1, Value: 1 > It happened for 9 times, but the message appeared only on first.Correct, upsmon throttles the REPLBATT event: http://www.networkupstools.org/docs/man/upsmon.conf.html (search for RBWARNTIME)> Broadcast Message from nut at rasp > (somewhere) at 17:33 ... > > UPS BNT500AP at localhost on battery > occurred when UPS.PowerSummary.PresentStatus.ACPresent turned to 0 on this line: > 10921.069403 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0If you turn up the debugging level from 2 to 3, the driver will do a hex dump of the report buffer. Offset and size are bits, so if the ACPresent bit is 0, that's what the driver reports.> Here I also see a suspisious frequency value 70. How is this possible? > 43194.046966 Path: UPS.Input.Frequency, Type: Feature, ReportID: 0x1e, Offset: 0, Size: 8, Value: 70Similar situation to ACPresent - if those are the bits coming in, that's what the driver reports. Granted, there are cases where usbhid-ups might be misinterpreting those bits, but as you can imagine, it is hard to test all of the corner cases. We should be getting an error message from usbhid-ups if the USB reply is not long enough.> At 2:58: > 44790.984549 Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x0a, Offset: 2, Size: 1, Value: 0 > Here all voltages and frequencies are OK, so I don't understand why ACPresent is 0.usbhid-ups does not look at voltage and frequency to determine whether AC is present. Voltage and frequency values can be averages over time (with the averaging being performed in the UPS microprocessor), so the driver simply trusts the ACPresent bit returned by the UPS. I'm starting to wonder if the USB controller or driver in the Raspberry Pi is flaky. We have seen odd issues with other ARM/Linux boards, and none of the symptoms are the same as on x86 PCs. Do you have a desktop or laptop Linux system where you can test this? -- Charles Lepple clepple at gmail