Apcupsd doesn't timely updates the measurements (for APC UPSs) since 19.07

I have apcupsd running on 22.03.3 monitoring an APC Back-UPS ES 550.
Apparently works fine, except I'm noticing the "Utility Voltage" is not updated every couple of seconds as the browser tab/screen does, but on a way longer basis (hours or events, I'm not sure which one).

I noticing this either on multimon.cgi, or upstatus.cgi, or apcaccess.

How often is supposed the Utility Voltage to be updated?

Unless your local utility is dirty, you won't see very much variance from the nominal baseline AC Voltage. Your best bet would be to add luci statistics/collectd-mod-apcups to see the variance over time. Depending on time of day/demand, on the NA grid I run from 123.5V to 126.0V.

It is being constantly monitored by the UPS firmware. Apcupsd is just recording what the UPS is telling it. When you refer to the Tab update this is a screen refresh. No change, nothing to see. Here's a visual example:



2 Likes

Good idea! Now I will assess the variance over time, because the voltage here goes up and down often (nominal=117V).

I suppose that, but the thing is the voltage reflected by apcupsd doesn't match what I'm measuring with a voltmeter. For instance yesterday we had a brownout, and the UPS kept reporting 109V for long time, while the utility was "normal" again. That's why I ask whether it could be some kind of configuration issue, or a bug, or just a 843.K1 firmware and/or hardware limitation (sampling periodically and/or by event, and/or sample resolution).

i.e. after collecting the stats for a couple of hours, the measured voltage have been between 127V and 120V, but apcupsd reported 127V all the time.


Anyways, I'll let it run for a while.

During this 23h running, I measured the line several times with two voltmeters: max 128V, min 120V, and several values in between. But the monitoring showed only 1 sudden change (exactly at 2pm?).

Time ago I had the same UPS directly connected to a linux machine, and the gapcmon plot made more sense to me:
imagen
(IIRC, green was line Voltage, and yellow was battery charging after a blackout).

Just looking at Recent Events log and Power failure messages.

Run apcaccess. What values do you show for SENSE, LOTRANSFER, and HITRANSFER.

root@SVdP2:~# apcaccess |grep SENSE
SENSE    : Medium
root@SVdP2:~# apcaccess |grep TRANS
LOTRANS  : 92.0 Volts
HITRANS  : 139.0 Volts
root@SVdP2:/# apcaccess |grep START
STARTTIME: 2023-03-21 16:11:55 -0400
root@SVdP2:~# apcaccess |grep XFERS
NUMXFERS : 2
root@SVdP2:~# apcaccess |grep LAST
LASTXFER : Low line voltage

The last time it was 109V, and kept reporting the same value for hours, that's how I realized the updates are not working properly.

Side note regarding the configuration: it draws my attention the config file I'm using states "for apcupsd release 3.14.1" (2007) when we're using 3.14.14 (2016). And as suggested, I let DEVICE followed by a blank, when other people had commented that line.

Have you looked at the changelog for 3.14.14?

Did you mean this:

The only configuration file change needed versus MODBUS serial is to change UPSCABLE to usb and use an empty DEVICE setting. See the MODBUS section of the apcupsd manual for more details.

Got it, and that's how I have it. So it should be something else.

In the meantime, it has only recorded two changes for 1d+:

I've been logging at 10 second intervals for almost two years, here's the last 10 days or so, which are pretty representative of the whole log. SoCal, with dirty power and frequent drops, so read what you will from it.

But has been that gathered through apcupsd / OpenWrt?

Regardless, what I want to diagnose first is whether my particular firmware/hardware isn't working properly, or is something more general.

I'm more interested on getting an envelope and/or trend for short term forecast and activate protection/countermeasures. But first, the measurement process/ecosystem needs to be providing the proper info.

Yes, it's from an APU2e4 running OpenWrt 22.03.3, with the APC Back-UPS Pro 1500 management cable plugged into one of its USB ports. I also have apcupsd running on one of my Ubuntu servers, same model UPS and same config (different NAME and IP). It shows virtually identical data -- the voltages sometimes differ by a volt for a few samples, but normally the same.

rtr00$ egrep -v '^(#|$)' /etc/apcupsd/apcupsd.conf
UPSNAME APC-1500-2
UPSCABLE usb
UPSTYPE usb
LOCKFILE /var/lock
SCRIPTDIR /etc/apcupsd
PWRFAILDIR /etc
NOLOGINDIR /etc
BATTERYLEVEL 5
MINUTES 3
TIMEOUT 0
ANNOY 300
ANNOYDELAY 60
NOLOGON disable
KILLDELAY 0
NETSERVER on
NISIP 10.1.1.1
NISPORT 3551
EVENTSFILE /var/log/apcupsd.events
EVENTSFILEMAX 10
UPSCLASS standalone
UPSMODE disable
STATTIME 0
STATFILE /var/log/apcupsd.status
LOGSTATS off
DATATIME 0

rtr00$ apcaccess
APC      : 001,038,0963
DATE     : 2023-03-17 14:12:15 -0700
HOSTNAME : rtr00
VERSION  : 3.14.14 (31 May 2016) unknown
UPSNAME  : APC-1500-2
CABLE    : USB Cable
DRIVER   : USB UPS Driver
UPSMODE  : Stand Alone
STARTTIME: 2023-02-13 06:46:33 -0800
MODEL    : Back-UPS RS 1500MS
STATUS   : ONLINE
LINEV    : 119.0 Volts
LOADPCT  : 3.0 Percent
BCHARGE  : 100.0 Percent
TIMELEFT : 180.0 Minutes
MBATTCHG : 5 Percent
MINTIMEL : 3 Minutes
MAXTIME  : 0 Seconds
SENSE    : Medium
LOTRANS  : 88.0 Volts
HITRANS  : 144.0 Volts
ALARMDEL : No alarm
BATTV    : 26.9 Volts
LASTXFER : Low line voltage
NUMXFERS : 11
XONBATT  : 2023-03-17 14:12:12 -0700
TONBATT  : 0 Seconds
CUMONBATT: 820 Seconds
XOFFBATT : 2023-03-17 14:12:14 -0700
LASTSTEST: 2023-02-14 03:27:03 -0800
SELFTEST : NO
STATFLAG : 0x05000008
SERIALNO : 3B999X999
BATTDATE : 2019-03-24
NOMINV   : 120 Volts
NOMBATTV : 24.0 Volts
NOMPOWER : 900 Watts
FIRMWARE : 952.e3 .D USB FW:e3
END APC  : 2023-03-30 12:34:25 -0700

I have almost the same configuration, but for some reason mine seldom updates values.

UPSNAME Back-UPS
UPSCABLE usb
UPSTYPE usb
DEVICE 
LOCKFILE /var/lock
SCRIPTDIR /etc/apcupsd
PWRFAILDIR /etc
NOLOGINDIR /etc
BATTERYLEVEL 5
MINUTES 3
TIMEOUT 0
ANNOY 300
ANNOYDELAY 60
NOLOGON disable
KILLDELAY 0
NETSERVER on
NISIP 0.0.0.0
NISPORT 3551
EVENTSFILE /var/log/apcupsd.events
EVENTSFILEMAX 10
UPSCLASS standalone
UPSMODE disable
STATTIME 0
STATFILE /var/log/apcupsd.status
LOGSTATS off
DATATIME 0

FWIW, I don't see any USB errors:

root@SVdP2:~# dmesg |grep usb
[   17.640355] usbcore: registered new interface driver usbfs
[   17.646119] usbcore: registered new interface driver hub
[   17.651602] usbcore: registered new device driver usb
[   18.026626] phy phy-10120000.usbphy.0: remote usb device wakeup disabled
[   18.033452] phy phy-10120000.usbphy.0: UTMI 16bit 30MHz
[   18.581226] usb 1-1: new low-speed USB device number 2 using ohci-platform
[   18.787052] usbcore: registered new interface driver usbhid
[   18.792718] usbhid: USB HID core driver
[   19.327390] hid-generic 0003:051D:0002.0001: hiddev96,hidraw0: USB HID v1.10 Device [APC Back-UPS ES 550 FW:843.K1 .D USB FW:K1 ] on usb-101c1000.ohci-1/input0
root@SVdP2:~# dmesg |tail
[495080.029241] rt3050-esw 10110000.esw: port 2 link down
[495082.624184] rt3050-esw 10110000.esw: port 2 link up

And apcaccess report looks ok (except the lack of updated data).

root@SVdP2:~# apcaccess
APC      : 001,035,0880
DATE     : 2023-03-30 12:36:00 -0400
HOSTNAME : SVdP2
VERSION  : 3.14.14 (31 May 2016) unknown
UPSNAME  : Back-UPS
CABLE    : USB Cable
DRIVER   : USB UPS Driver
UPSMODE  : Stand Alone
STARTTIME: 2023-03-21 16:11:55 -0400
MODEL    : Back-UPS ES 550
STATUS   : ONLINE
LINEV    : 119.0 Volts
LOADPCT  : 8.0 Percent
BCHARGE  : 100.0 Percent
TIMELEFT : 29.2 Minutes
MBATTCHG : 5 Percent
MINTIMEL : 3 Minutes
MAXTIME  : 0 Seconds
SENSE    : Medium
LOTRANS  : 92.0 Volts
HITRANS  : 139.0 Volts
ALARMDEL : No alarm
BATTV    : 13.5 Volts
LASTXFER : Low line voltage
NUMXFERS : 2
XONBATT  : 2023-03-28 23:09:53 -0400
TONBATT  : 0 Seconds
CUMONBATT: 4 Seconds
XOFFBATT : 2023-03-28 23:09:55 -0400
STATFLAG : 0x05000008
SERIALNO : 3B1805X62100
BATTDATE : 2020-10-27
NOMINV   : 115 Volts
NOMBATTV : 12.0 Volts
FIRMWARE : 843.K1 .D USB FW:K1
END APC  : 2023-03-30 16:09:53 -0400

Note: I also realized there's a several minutes delay between updating the databases:


As someone else mentioned, maybe you just have very stable power? In our location, the power is fairly dirty, plus I have a solar array on the roof to confound things even further. You can clearly see when the sun came out today at about 1100 and then clouds rolled back in at about 1300.

Along those lines, but a caveat from the v3.14.14-3 apcupsd.conf also says a UPSTYPE must be defined. Did not know if that exists in the 3.14.1 .conf.

FWIW, I’ve had my meter probes plugged into a spare receptacle on the UPS the last 9 hrs. and it has mimicked the reported line voltage from both apcaccess, and https://10.10.1.1/cgi-bin/apcupsd/upsstats.cgi.

My apcaccess - identical unit to your’s:

APC      : 001,034,0849
DATE     : 2023-03-30 13:53:02 -0400  
HOSTNAME : RuralRoots
VERSION  : 3.14.14 (31 May 2016) unknown
UPSNAME  : RuralRoots ES 550 UPS
CABLE    : USB Cable
DRIVER   : USB UPS Driver
UPSMODE  : Stand Alone
STARTTIME: 2023-03-30 13:53:01 -0400  
MODEL    : Back-UPS ES 550 
STATUS   : ONLINE 
LINEV    : 125.0 Volts
LOADPCT  : 23.0 Percent
BCHARGE  : 100.0 Percent
TIMELEFT : 7.4 Minutes
MBATTCHG : 5 Percent
MINTIMEL : 3 Minutes
MAXTIME  : 0 Seconds
SENSE    : Low
LOTRANS  : 88.0 Volts
HITRANS  : 142.0 Volts
ALARMDEL : 30 Seconds
BATTV    : 13.5 Volts
LASTXFER : Automatic or explicit self test
NUMXFERS : 0
TONBATT  : 0 Seconds
CUMONBATT: 0 Seconds
XOFFBATT : N/A
STATFLAG : 0x05000008
SERIALNO : 3B1106X22237  
BATTDATE : 2011-02-03
NOMINV   : 120 Volts
NOMBATTV : 12.0 Volts
FIRMWARE : 843.K2 .D USB FW:K2
END APC  : 2023-03-30 16:42:41 -0400 

How I would wish that. On the contrary, it's unstable and eventful, specially during the tropic's dry season (thankfully this year's "la niña" has easen the things a little bit for us so far).

Here I was measuring 121V back and forth to 124V, when the UPS was reporting 127V yesterday.


Me neither. But I got courious why the included apcupsd.conf refers to 3.14.1.


Anyways, the three of us are running the same config, I think.

Thanks for that. So if yours follows the line variations but mine doesn't, and we are running the same configuration, and there's no software errors, and time ago it worked fine when I had it connected to a linux PC with apcupsd/gapcmon. I don't know where else to look.

Maybe I will have to recreate that environment to discard a hardware failure.

For the sake of time and pinpointing the issue, I replicated the configuration on one vendor's OpenWrt implementation (over 18.06+propietary drivers). Now the things make more sense:


Therefore I pointed the official OpenWrt box to pull information from the other one:

Hence the issue is only when the UPS is connected to the original 22.03.3 router. But I haven't seen any USB errors or "UPS communication lost" errors, so it doesn't seems to be USB or hardware related. It has to be some library or installation/configuration issue.

I guess I'll begin by comparing libraries installed or not, and versions, but I'm not an OpenWrt/apcupsd/collectd expert.

Nice! I am still on 21.02.5 (mvebu broke on 23.03). I’ll build a new Snapshot tomorrow and let you know how it compares.

Thanks for taking the time for that. I'll continue investigating myself after some other stuff to take care of.

In the meantime, it's evident the difference when collectd of the original 22.03.3 router was gathering info from the local USB port (left), the time there was no UPS connected (no communication/data, center), and when gathering samples from the unofficial 18.06 fork (right, and credits to gl.iNet for getting this working):

I think the issue is at apcupsd level or lower. To rule-out collectd and statistics, I wrote an apcaccess datalogger script to follow the line Voltage (and variations):
/19:59, new value: 124 ----------------------------------------------------------------------------/21:18, new value: 125 ----------------------------
where "-", "/", or "\" represent the continuity or change for the last period (minute). During this run, it only recorded 1 variation for the ongoing 100minutes or so.

Because the release image for my mt76x8 didn't include USB drivers, I installed it guided by wiki and tutorials. i.e.

root@SVdP2:~# opkg list-installed | grep usb
kmod-usb-core - 5.10.161-1
kmod-usb-hid - 5.10.161-1
kmod-usb-ohci - 5.10.161-1
libusb-1.0-0 - 1.0.24-5
libusb-compat4 - 0.1.7-2
usbutils - 014-1
root@SVdP2:~# opkg list-installed | grep ups
apcupsd - 3.14.14-3
apcupsd-cgi - 3.14.14-3
collectd-mod-apcups - 5.12.0-33

Which as we know stablish the connection:

root@SVdP2:~#  ls -l /dev/usb
crw-------    1 root     root      180,  96 Mar 31 11:47 hiddev0
root@SVdP2:~# dmesg |grep usb
[   17.664485] usbcore: registered new interface driver usbfs
[   17.670153] usbcore: registered new interface driver hub
[   17.675741] usbcore: registered new device driver usb
[   18.054068] phy phy-10120000.usbphy.0: remote usb device wakeup disabled
[   18.060877] phy phy-10120000.usbphy.0: UTMI 16bit 30MHz
[   18.611262] usb 1-1: new low-speed USB device number 2 using ohci-platform
[   18.807087] usbcore: registered new interface driver usbhid
[   18.812754] usbhid: USB HID core driver
[   19.356641] hid-generic 0003:051D:0002.0001: hiddev96,hidraw0: USB HID v1.10 Device [APC Back-UPS ES 550 FW:843.K1 .D USB FW:K1 ] on usb-101c1000.ohci-1/input0
root@SVdP2:~# lsusb
Bus 001 Device 002: ID 051d:0002 APC Back-UPS ES 550 FW:843.K1 .D USB FW:K1
Bus 001 Device 001: ID 1d6b:0001 Linux 5.10.161 ohci_hcd Generic Platform OHCI controller
root@SVdP2:~# lsusb -t
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
    |__ Port 1: Dev 2, If 0, Class=, Driver=usbhid, 1.5M
root@SVdP2:/# cat /sys/kernel/debug/usb/devices

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=12   MxCh= 1
B:  Alloc= 13/900 us ( 1%), #Int=  1, #Iso=  0
D:  Ver= 1.10 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0001 Rev= 5.10
S:  Manufacturer=Linux 5.10.161 ohci_hcd
S:  Product=Generic Platform OHCI controller
S:  SerialNumber=101c1000.ohci
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   2 Ivl=255ms

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=1.5  MxCh= 0
D:  Ver= 1.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs=  1
P:  Vendor=051d ProdID=0002 Rev= 1.06
S:  Manufacturer=APC
S:  Product=Back-UPS ES 550 FW:843.K1 .D USB FW:K1
S:  SerialNumber=3B1805X62100
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  2mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=03(HID  ) Sub=00 Prot=00 Driver=usbhid
E:  Ad=81(I) Atr=03(Int.) MxPS=   6 Ivl=10ms
root@SVdP2:~# /etc/init.d/apcupsd stop
root@SVdP2:~# apctest


2023-03-31 21:02:41 apctest 3.14.14 (31 May 2016) unknown
Checking configuration ...
sharenet.type = Network & ShareUPS Disabled
cable.type = USB Cable
mode.type = USB UPS Driver
Setting up the port ...
Doing prep_device() ...

You are using a USB cable type, so I'm entering USB test mode
Hello, this is the apcupsd Cable Test program.
This part of apctest is for testing USB UPSes.

Getting UPS capabilities...SUCCESS

Please select the function you want to perform.

1)  Test kill UPS power
2)  Perform self-test
3)  Read last self-test result
4)  View/Change battery date
5)  View manufacturing date
6)  View/Change alarm behavior
7)  View/Change sensitivity
8)  View/Change low transfer voltage
9)  View/Change high transfer voltage
10) Perform battery calibration
11) Test alarm
12) View/Change self-test interval
 Q) Quit

Select function number: q

2023-03-31 21:03:40 End apctest.
root@SVdP2:~# /etc/init.d/apcupsd start

Just in case, I forced the DEVICE to /dev/usb/hiddev0, but it doesn't make difference.

As expected, if I unplug and plug the USB cable, the values are updated, but then seldom changes, unless there is an event, for which the UPS push the update.

I took the same USB-modded router with 22.03.3 and UPS, and tried nut instead of apcupsd. After some improvements made on rrtdtool's nut.js, got it working.

Therefore it's not hardware related. It's something about recent apcupsd and/or this UPS set of features combination, and therefore I kindly ask for the developers to take a look at the previous discussion.