search

networkupstools / nut

The Network UPS Tools repository. UPS management protocol Informational RFC 9271 published by IETF at https://www.rfc-editor.org/info/rfc9271 Please star NUT on GitHub, this helps with sponsorships!
https://networkupstools.org/
Other
2.12k stars 354 forks source link

APC Smart-UPS 1000 USB - ups.test.result: No test initiated and missing TIMELEFT #2441

Open nikolaysu opened 6 months ago

nikolaysu commented 6 months ago

APC Smart-UPS 1000 when connected via USB, two very important parameters are missing:

root@cell06:~/nut# lsusb
Bus 001 Device 003: ID 051d:0002 American Power Conversion Uninterruptible Power Supply
upsc UPS_CELL06@127.0.0.1 ``` Init SSL without certificate database battery.charge: 100 battery.charge.low: 10 battery.charge.warning: 50 battery.mfr.date: 2020/03/01 battery.runtime: 1380 battery.runtime.low: 120 battery.temperature: 27.4 battery.type: PbAc battery.voltage: 27.5 battery.voltage.nominal: 24.0 device.mfr: American Power Conversion device.model: Smart-UPS 1000 device.serial: AS0451230660 device.type: ups driver.name: usbhid-ups driver.parameter.pollfreq: 30 driver.parameter.pollinterval: 2 driver.parameter.port: auto driver.parameter.productid: 0002 driver.parameter.synchronous: no driver.parameter.vendorid: 051d driver.version: 2.7.4 driver.version.data: APC HID 0.96 driver.version.internal: 0.41 input.sensitivity: medium input.transfer.high: 253 input.transfer.low: 204 input.voltage: 226.0 output.frequency: 50.0 output.voltage: 226.0 output.voltage.nominal: 230.0 ups.beeper.status: enabled ups.delay.shutdown: 20 ups.delay.start: 30 ups.firmware: 600.3.I ups.firmware.aux: 1.5 ups.load: 35.7 ups.mfr: American Power Conversion ups.mfr.date: 2004/12/14 ups.model: Smart-UPS 1000 ups.productid: 0002 ups.serial: AS0451230660 ups.status: OL ups.test.result: No test initiated ups.timer.reboot: -1 ups.timer.shutdown: -1 ups.timer.start: -1 ups.vendorid: 051d ```
usbhid-ups -a UPS_CELL06 -DDDDDD ``` 0.000000 debug level is '6' 0.000732 upsdrv_initups... 0.252814 Checking device (174C/3074) (002/002) 0.380304 - VendorID: 174c 0.380321 - ProductID: 3074 0.380323 - Manufacturer: unknown 0.380324 - Product: unknown 0.380325 - Serial Number: unknown 0.380326 - Bus: 002 0.380327 - Device release number: 0200 0.380328 Trying to match device 0.380332 Device does not match - skipping 0.380339 Checking device (1D6B/0003) (002/001) 0.380352 - VendorID: 1d6b 0.380354 - ProductID: 0003 0.380355 - Manufacturer: unknown 0.380356 - Product: unknown 0.380357 - Serial Number: unknown 0.380358 - Bus: 002 0.380359 - Device release number: 0504 0.380360 Trying to match device 0.380361 Device does not match - skipping 0.380364 Checking device (26CE/01A2) (001/004) 0.380369 - VendorID: 26ce 0.380371 - ProductID: 01a2 0.380372 - Manufacturer: unknown 0.380373 - Product: unknown 0.380374 - Serial Number: unknown 0.380375 - Bus: 001 0.380376 - Device release number: 0000 0.380377 Trying to match device 0.380378 Device does not match - skipping 0.380380 Checking device (051D/0002) (001/003) 0.389355 - VendorID: 051d 0.389364 - ProductID: 0002 0.389365 - Manufacturer: American Power Conversion 0.389366 - Product: Smart-UPS 1000 FW:600.3.I USB FW:1.5 0.389367 - Serial Number: AS0451230660 0.389368 - Bus: 001 0.389369 - Device release number: 0006 0.389370 Trying to match device 0.389390 Device matches 0.389393 failed to claim USB device: could not claim interface 0: Device or resource busy 0.389415 detached kernel driver from USB device... 0.389421 nut_usb_set_altinterface: skipped usb_set_altinterface(udev, 0) 0.390300 HID descriptor, method 1: (9 bytes) => 09 21 10 01 21 01 22 f3 f1 0.390306 HID descriptor length (method 1) 61939 0.390309 i=0, extra[i]=09, extra[i+1]=21 0.390312 HID descriptor, method 2: (9 bytes) => 09 21 10 01 21 01 22 10 04 0.390313 HID descriptor length (method 2) 1040 0.390315 Warning: two different HID descriptors retrieved (Reportlen = 61939 vs. 1040) 0.390317 HID descriptor length 1040 0.466932 Report Descriptor size = 1040 0.466953 Report Descriptor: (1040 bytes) => 05 84 09 04 a1 01 09 24 a1 02 85 01 09 0.466955 fe 79 01 75 08 95 01 15 00 26 ff 00 b1 22 85 02 09 ff 79 02 b1 22 85 03 09 0.466958 fd 79 03 b1 22 05 85 85 04 09 8f 79 03 b1 22 85 05 09 89 79 04 b1 22 85 06 0.466960 09 8b b1 22 09 2c b1 22 85 0e 09 83 25 64 b1 22 09 67 b1 22 85 0c 09 66 81 0.466963 22 09 66 b1 a2 85 10 09 8d b1 22 09 8e b1 22 85 0f 09 8c b1 22 85 11 09 29 0.466965 b1 a2 85 09 09 85 75 10 27 ff ff 00 00 b1 a2 85 0d 09 68 27 ff ff 00 00 66 0.466967 01 10 55 00 81 a2 09 68 b1 a2 05 84 85 12 09 57 16 ff ff 26 ff 7f b1 a2 85 0.466970 13 09 55 75 18 17 ff ff ff ff 27 18 c5 13 00 b1 a2 05 85 85 08 09 2a 27 64 0.466972 05 00 00 16 78 00 81 22 09 2a b1 a2 05 84 85 0a 09 40 75 10 15 00 27 ff ff 0.466974 00 00 67 21 d1 f0 00 55 05 b1 22 85 0b 09 30 b1 a2 85 14 09 5a 75 08 15 01 0.466977 25 03 65 00 55 00 81 22 09 5a b1 a2 09 02 a1 02 85 07 05 85 09 44 75 01 15 0.466979 00 25 01 81 a2 09 44 b1 a2 09 45 81 a2 09 45 b1 a2 09 d0 81 a2 09 d0 b1 a2 0.466982 09 d1 81 a2 09 d1 b1 a2 09 42 81 a2 09 42 b1 a2 05 84 09 68 81 a2 09 68 b1 0.466984 a2 09 69 81 a2 09 69 b1 a2 05 85 09 43 81 a2 09 43 b1 a2 05 84 09 73 81 a2 0.466986 09 73 b1 a2 05 85 09 4b 81 a2 09 4b b1 a2 05 84 09 65 81 a2 09 65 b1 a2 05 0.466989 85 09 db 81 a2 09 db b1 a2 06 86 ff 09 80 81 a2 09 80 b1 a2 95 03 81 01 b1 0.466991 01 c0 c0 05 84 09 12 a1 00 85 16 09 58 75 08 95 01 25 06 81 a2 09 58 b1 a2 0.466993 06 86 ff 85 17 09 19 25 5a 81 22 09 19 b1 a2 85 1b 09 1a 25 03 81 22 09 1a 0.466996 b1 a2 85 1c 09 1b 26 ff 00 81 a2 09 1b b1 a2 05 85 85 15 09 85 75 10 27 ff 0.466998 ff 00 00 81 22 09 85 b1 a2 85 18 09 66 55 0f b1 a2 85 1a 09 2a 27 64 05 00 0.467000 00 16 78 00 66 01 10 55 00 81 22 09 2a b1 a2 85 19 27 ff ff 00 00 15 00 09 0.467003 68 b1 a2 05 84 85 1e 09 36 67 01 00 01 00 55 0f b1 a2 85 1f 09 40 67 21 d1 0.467015 f0 00 55 05 b1 22 85 1d 09 30 b1 a2 c0 09 1a a1 00 85 20 09 30 55 06 b1 a2 0.467017 06 86 ff 85 21 09 52 75 08 25 0a 65 00 55 00 81 22 09 52 b1 a2 85 22 09 61 0.467020 25 02 81 a2 09 61 b1 a2 c0 05 84 09 1c a1 00 85 2c 09 35 75 10 27 ff ff 00 0.467022 00 55 0f b1 a2 85 2a 09 32 66 01 f0 55 0e b1 a2 85 2b 09 30 67 21 d1 f0 00 0.467025 55 06 b1 a2 85 2d 09 40 16 dc 00 26 f0 00 55 07 81 22 09 40 b1 a2 85 23 09 0.467027 54 16 fd 00 26 09 01 81 22 09 54 b1 a2 85 24 09 53 16 c4 00 26 d0 00 81 22 0.467029 09 53 b1 a2 06 86 ff 85 25 09 7e 15 00 27 a4 01 00 00 66 01 10 55 00 81 22 0.467032 09 7e b1 a2 85 26 09 76 27 76 02 00 00 81 22 09 76 b1 a2 05 84 85 27 09 57 0.467034 16 ff ff 26 ff 7f b1 a2 85 28 09 56 b1 a2 85 29 09 55 75 18 17 ff ff ff ff 0.467036 27 18 c5 13 00 b1 a2 c0 85 2e 09 fe 79 05 75 08 15 00 26 ff 00 65 00 b1 22 0.467039 85 2f 09 ff 79 02 b1 22 85 30 09 fd 79 03 b1 22 85 31 09 01 79 06 b1 a2 06 0.467041 86 ff 85 34 09 42 79 07 b1 22 06 86 ff 85 37 09 79 79 08 b1 22 85 32 09 72 0.467043 25 01 b1 22 05 85 85 35 09 85 75 10 27 ff ff 00 00 b1 22 06 86 ff 85 3e 09 0.467046 27 75 20 15 00 27 ff ff ff 7f b1 a2 85 3f 09 28 b1 a2 05 84 85 36 09 5a 75 0.467048 08 15 01 25 03 81 22 09 5a b1 a2 09 02 a1 02 85 33 05 85 09 44 75 01 15 00 0.467050 25 01 81 a2 09 44 b1 a2 09 45 81 a2 09 45 b1 a2 09 d0 81 a2 09 d0 b1 a2 09 0.467053 d1 81 a2 09 d1 b1 a2 09 42 81 a2 09 42 b1 a2 05 84 09 68 81 a2 09 68 b1 a2 0.467055 09 69 81 a2 09 69 b1 a2 05 85 09 43 81 a2 09 43 b1 a2 05 84 09 73 81 a2 09 0.467057 73 b1 a2 05 85 09 4b 81 a2 09 4b b1 a2 05 84 09 65 81 a2 09 65 b1 a2 05 85 0.467060 09 db 81 a2 09 db b1 a2 06 86 ff 09 80 81 a2 09 80 b1 a2 95 03 81 01 b1 01 0.467061 c0 c0 0.467104 Using subdriver: APC HID 0.96 0.467106 128 HID objects found 0.467107 Entering libusb_get_report 0.467672 Report[get]: (2 bytes) => 01 01 0.467677 PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 0.467678 Unit = 00000000, UnitExp = 0 0.467680 Exponent = 0 0.467682 hid_lookup_path: 00840004 -> UPS 0.467683 hid_lookup_path: 00840024 -> PowerSummary 0.467685 hid_lookup_path: 008400fe -> iProduct 0.467687 Path: UPS.PowerSummary.iProduct, Type: Feature, ReportID: 0x01, Offset: 0, Size: 8, Value: 1 0.467688 Entering libusb_get_report 0.468274 Report[get]: (2 bytes) => 02 02 0.468281 PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 0.468283 Unit = 00000000, UnitExp = 0 0.468284 Exponent = 0 0.468286 hid_lookup_path: 00840004 -> UPS 0.468287 hid_lookup_path: 00840024 -> PowerSummary 0.468288 hid_lookup_path: 008400ff -> iSerialNumber 0.468290 Path: UPS.PowerSummary.iSerialNumber, Type: Feature, ReportID: 0x02, Offset: 0, Size: 8, Value: 2 0.468291 Entering libusb_get_report 0.468887 Report[get]: (2 bytes) => 03 03 0.468891 PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 0.468893 Unit = 00000000, UnitExp = 0 0.468894 Exponent = 0 0.468895 hid_lookup_path: 00840004 -> UPS 0.468897 hid_lookup_path: 00840024 -> PowerSummary 0.468898 hid_lookup_path: 008400fd -> iManufacturer 0.468900 Path: UPS.PowerSummary.iManufacturer, Type: Feature, ReportID: 0x03, Offset: 0, Size: 8, Value: 3 0.468901 Entering libusb_get_report 0.469414 Report[get]: (2 bytes) => 04 03 0.469419 PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 0.469421 Unit = 00000000, UnitExp = 0 0.469422 Exponent = 0 0.469423 hid_lookup_path: 00840004 -> UPS 0.469425 hid_lookup_path: 00840024 -> PowerSummary 0.469426 hid_lookup_path: 0085008f -> iOEMInformation 0.469428 Path: UPS.PowerSummary.iOEMInformation, Type: Feature, ReportID: 0x04, Offset: 0, Size: 8, Value: 3 0.469429 Entering libusb_get_report 0.470051 Report[get]: (2 bytes) => 05 04 0.470056 PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 0.470057 Unit = 00000000, UnitExp = 0 --skip-- 1.530192 Exponent = 0 1.530193 Path: UPS.Output.DelayBeforeStartup, Type: Feature, ReportID: 0x28, Offset: 0, Size: 16, Value: -1 1.530195 send_to_all: SETINFO ups.timer.start "-1" 1.530196 hid_lookup_usage: UPS -> 00840004 1.530198 hid_lookup_usage: Output -> 0084001c 1.530200 hid_lookup_usage: DelayBeforeShutdown -> 00840057 1.530201 string_to_path: depth = 3 1.530202 hid_lookup_usage: UPS -> 00840004 1.530204 hid_lookup_usage: Output -> 0084001c 1.530205 hid_lookup_usage: DelayBeforeReboot -> 00840055 1.530206 string_to_path: depth = 3 1.530208 hid_lookup_usage: UPS -> 00840004 1.530209 hid_lookup_usage: APCGeneralCollection -> ff860005 1.530211 hid_lookup_usage: APCDelayBeforeStartup -> ff86007e 1.530212 string_to_path: depth = 3 1.530213 hid_lookup_usage: UPS -> 00840004 1.530214 hid_lookup_usage: APCGeneralCollection -> ff860005 1.530216 hid_lookup_usage: APCDelayBeforeShutdown -> ff86007d 1.530217 string_to_path: depth = 3 1.530218 hid_lookup_usage: UPS -> 00840004 1.530219 hid_lookup_usage: APCGeneralCollection -> ff860005 1.530221 hid_lookup_usage: APCDelayBeforeStartup -> ff86007e 1.530222 string_to_path: depth = 3 1.530223 hid_lookup_usage: UPS -> 00840004 1.530225 hid_lookup_usage: APCGeneralCollection -> ff860005 1.530227 hid_lookup_usage: APCDelayBeforeShutdown -> ff86007d 1.530228 string_to_path: depth = 3 1.530229 hid_lookup_usage: UPS -> 00840004 1.530231 hid_lookup_usage: APCGeneralCollection -> ff860005 1.530232 hid_lookup_usage: APCDelayBeforeReboot -> ff86007c 1.530233 string_to_path: depth = 3 1.530235 hid_lookup_usage: UPS -> 00840004 1.530236 hid_lookup_usage: Battery -> 00840012 1.530238 hid_lookup_usage: Test -> 00840058 1.530239 string_to_path: depth = 3 1.530241 Report[buf]: (2 bytes) => 16 06 1.530242 PhyMax = 0, PhyMin = 0, LogMax = 6, LogMin = 0 1.530243 Unit = 00000000, UnitExp = 0 1.530244 Exponent = 0 1.530246 Path: UPS.Battery.Test, Type: Feature, ReportID: 0x16, Offset: 0, Size: 8, Value: 6 1.530247 hu_find_infoval: found No test initiated (value: 6) 1.530249 send_to_all: SETINFO ups.test.result "No test initiated" 1.530250 hid_lookup_usage: UPS -> 00840004 1.530252 hid_lookup_usage: PowerSummary -> 00840024 1.530253 hid_lookup_usage: AudibleAlarmControl -> 0084005a 1.530255 string_to_path: depth = 3 1.530256 Report[buf]: (2 bytes) => 14 02 1.530257 PhyMax = 0, PhyMin = 0, LogMax = 3, LogMin = 1 1.530259 Unit = 00000000, UnitExp = 0 1.530260 Exponent = 0 1.530261 Path: UPS.PowerSummary.AudibleAlarmControl, Type: Feature, ReportID: 0x14, Offset: 0, Size: 8, Value: 2 1.530262 hu_find_infoval: found enabled (value: 2) 1.530264 send_to_all: SETINFO ups.beeper.status "enabled" 1.530265 hid_lookup_usage: UPS -> 00840004 1.530268 hid_lookup_usage: ManufacturerDate -> 00850085 1.530269 string_to_path: depth = 2 1.530271 Report[buf]: (3 bytes) => 35 8e 31 1.530273 PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 1.530274 Unit = 00000000, UnitExp = 0 1.530275 Exponent = 0 1.530276 Path: UPS.ManufacturerDate, Type: Feature, ReportID: 0x35, Offset: 0, Size: 16, Value: 12686 1.530278 send_to_all: SETINFO ups.mfr.date "2004/12/14" 1.530280 hid_lookup_usage: UPS -> 00840004 1.530281 hid_lookup_usage: PowerSummary -> 00840024 1.530283 hid_lookup_usage: ManufacturerDate -> 00850085 1.530285 string_to_path: depth = 3 1.530286 hid_lookup_usage: UPS -> 00840004 1.530287 hid_lookup_usage: PowerConverter -> 00840016 1.530289 hid_lookup_usage: ConfigActivePower -> 00840044 1.530290 string_to_path: depth = 3 1.530292 hid_lookup_usage: UPS -> 00840004 1.530293 hid_lookup_usage: Output -> 0084001c 1.530295 hid_lookup_usage: ConfigActivePower -> 00840044 1.530296 string_to_path: depth = 3 1.530298 hid_lookup_usage: UPS -> 00840004 1.530299 hid_lookup_usage: PowerSummary -> 00840024 1.530300 hid_lookup_usage: PresentStatus -> 00840002 1.530303 hid_lookup_usage: ACPresent -> 008500d0 1.530304 string_to_path: depth = 4 1.530306 Report[buf]: (3 bytes) => 07 0c 00 1.530307 PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 1.530308 Unit = 00000000, UnitExp = 0 --skip-- 1.639027 Exponent = 0 1.639029 Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x07, Offset: 4, Size: 1, Value: 0 1.639030 hu_find_infoval: found !lowbatt (value: 0) 1.639031 process_boolean_info: !lowbatt 3.575744 upsdrv_updateinfo... 3.575805 libusb_get_interrupt: error submitting URB: Device or resource busy 3.575808 Got disconnected by another driver: Device or resource busy 5.577754 upsdrv_updateinfo... 5.577778 Got to reconnect! 5.577780 ================================================== 5.577781 = device has been disconnected, try to reconnect = 5.577782 ================================================== 5.824706 Checking device (174C/3074) (002/002) 5.952378 - VendorID: 174c 5.952396 - ProductID: 3074 5.952397 - Manufacturer: unknown 5.952398 - Product: unknown 5.952399 - Serial Number: unknown 5.952401 - Bus: 002 5.952402 - Device release number: 0200 ...... ```
apcaccess status ``` root@cell06:~# apcaccess status APC : 001,045,1117 CABLE : USB Cable DRIVER : USB UPS Driver MODEL : Smart-UPS 1000 --skip-- TIMELEFT : 22.0 Minutes LASTSTEST: 2024-04-25 02:51:11 +0300 FIRMWARE : 600.3.I USB FW:1.5 END APC : 2024-04-27 13:22:34 +0300 ```

I built the latest version from the master branch, but the result was exactly the same

git clone https://github.com/networkupstools/nut.git
./configure --with-user=nut --with-group=nut --with-usb
make
jimklimov commented 6 months ago

For the initial test, NUT is v2.7.4 or older, right?

As for missing values, CC @aquette @clepple @desertwitch : any ideas?

nikolaysu commented 6 months ago

For the initial test, NUT is v2.7.4 or older, right?


root@cell06:/usr/lib/nut# upsc -V
Network UPS Tools upscmd 2.7.4

root@cell06:/usr/lib/nut# /usr/lib/nut/usbhid-ups -V Network UPS Tools - Generic HID driver 0.41 (2.7.4) USB communication driver 0.33

desertwitch commented 6 months ago

apcupsd TIMELEFT : 22.0 Minutes => NUT battery.runtime: 1380 (seconds = 23 minutes) Not sure about last test, will take a look...

Can you provide us with the upsc output from the latest master build (or release 2.8.2) in the meantime? Version 2.7.4 is extremely old at this point, just to be sure we're not missing something... 😄

nikolaysu commented 6 months ago 
root@cell06:~/nut/clients# ./upsc -V
Network UPS Tools upsc 2.8.2-215-gc342e63a2
upsc UPS_CELL06@127.0.0.1 ``` root@cell06:~/nut/clients# ./upsc UPS_CELL06@127.0.0.1 battery.charge: 100 battery.charge.low: 10 battery.charge.warning: 50 battery.mfr.date: 2020/03/01 battery.runtime: 1500 battery.runtime.low: 120 battery.temperature: 27.9 battery.type: PbAc battery.voltage: 27.5 battery.voltage.nominal: 24.0 device.mfr: American Power Conversion device.model: Smart-UPS 1000 device.serial: AS0451230660 device.type: ups driver.name: usbhid-ups driver.parameter.pollfreq: 30 driver.parameter.pollinterval: 2 driver.parameter.port: auto driver.parameter.productid: 0002 driver.parameter.synchronous: no driver.parameter.vendorid: 051d driver.version: 2.7.4 driver.version.data: APC HID 0.96 driver.version.internal: 0.41 input.sensitivity: medium input.transfer.high: 253 input.transfer.low: 204 input.voltage: 226.0 output.frequency: 50.0 output.voltage: 226.0 output.voltage.nominal: 230.0 ups.beeper.status: enabled ups.delay.shutdown: 20 ups.delay.start: 30 ups.firmware: 600.3.I ups.firmware.aux: 1.5 ups.load: 39.0 ups.mfr: American Power Conversion ups.mfr.date: 2004/12/14 ups.model: Smart-UPS 1000 ups.productid: 0002 ups.serial: AS0451230660 ups.status: OL ups.test.result: No test initiated ups.timer.reboot: -1 ups.timer.shutdown: -1 ups.timer.start: -1 ups.vendorid: 051d root@cell06:~/nut/clients# ```
desertwitch commented 6 months ago

driver.version: 2.7.4

You're still on NUT 2.7.4. on the machine where the UPS is physically connected. It would be great if you could try it with NUT 2.8.2 or the current master (both driver + upsc for output). 😉

nikolaysu commented 6 months ago

i need

driver.version: 2.7.4

You're still on NUT 2.7.4. on the machine where the UPS is physically connected. It would be great if you could try it with NUT 2.8.2 or the current master (both driver + upsc for output). 😉

I need 10-15 minutes

nikolaysu commented 6 months ago

completely removed the NUT that I installed from the packages installed from master branch

upsc UPS_CELL06@127.0.0.1 ``` root@cell06:/usr/local/ups/bin# /usr/local/ups/bin/upsc UPS_CELL06@127.0.0.1 battery.charge: 100 battery.charge.low: 10 battery.charge.warning: 50 battery.mfr.date: 2020/03/01 battery.runtime: 1320 battery.runtime.low: 120 battery.temperature: 27.9 battery.type: PbAc battery.voltage: 27.5 battery.voltage.nominal: 24.0 device.mfr: American Power Conversion device.model: Smart-UPS 1000 device.serial: AS0451230660 device.type: ups driver.debug: 0 driver.flag.allow_killpower: 0 driver.name: usbhid-ups driver.parameter.pollfreq: 30 driver.parameter.pollinterval: 2 driver.parameter.port: auto driver.parameter.productid: 0002 driver.parameter.synchronous: auto driver.parameter.vendorid: 051d driver.state: quiet driver.version: 2.8.2-215-gc342e63a2 driver.version.data: APC HID 0.100 driver.version.internal: 0.53 driver.version.usb: libusb-1.0.22 (API: 0x1000106) input.sensitivity: medium input.transfer.high: 253 input.transfer.low: 204 input.voltage: 226.0 output.frequency: 50.0 output.voltage: 224.6 output.voltage.nominal: 230.0 ups.beeper.status: enabled ups.delay.shutdown: 20 ups.delay.start: 30 ups.firmware: 600.3.I ups.firmware.aux: 1.5 ups.load: 37.7 ups.mfr: American Power Conversion ups.mfr.date: 2004/12/14 ups.model: Smart-UPS 1000 ups.productid: 0002 ups.serial: AS0451230660 ups.status: OL ups.test.result: No test initiated ups.timer.reboot: -1 ups.timer.shutdown: -1 ups.timer.start: -1 ups.vendorid: 051d ```
desertwitch commented 6 months ago

I've just looked into this and LASTSTEST is not a value actually reported through the HID (and read from the UPS), but rather a date/time variable that apcupsd calculates and stores itself. So there is some programmatic logic behind it, rather than being read "as is" from the UPS. It seems that when apcupsd sees the UPS in or exiting a self-testing state (although that detection does seem a bit fuzzy in the code), it stores that date in a variable and displays it as LASTSTEST. Not sure what NUT's stance on such (pseudo-)variables is, as opposed to actual readable/reported variables, and if that would be something worth looking into. On the one hand I could see it being a useful metric, but then again a hit-and-miss CAL detection (reporting a successful self test when there was in fact maybe none) may also lead users into a false sense of security... so not sure, @jimklimov ?

In any case, the runtime variable is there as it should be, it just has a different name in NUT. 😎 So this is more of a feature request now than missing readings after further investigations...

nikolaysu commented 6 months ago

First, thanks for the clarification about battery.runtime, this already in my Zabbix 👍 Second, i was experimenting with yesterday ups.test.result If send command to test /bin/upscmd -u admin -p admin UPS_CELL06@127.0.0.1 test.battery.start.quick return SUCCESS And in the variable ups.test.result there was a value Done and passed which lasted for several minutes, then again became No test initiated After the battery is charged, about 10 minutes. I repeated the experiment, but ups.test.result was No test initiated and did not change. I repeated the experiment today(10 hour left) and again ups.test.result was No test initiated from the beginning. I also tried running Self-test with the -w parameter /bin/upscmd -t 60 -w -u admin -p admin UPS_CELL06@127.0.0.1 test.battery.start.quick The result is the same

There may be a reason in the self test period - in apcaccess parameter STESTI: 7 days.

I still don’t understand how I can get the result of a self-test:

There is complete confusion with ups.test.result, but I will check it again after a week

I understand that this is apparently not the work of NUT. But maybe this will help someone in the future

jimklimov commented 6 months ago

I believe upscmd and upsrw by default send a command and return success quickly (if there were no NUT protocol errors). Since NUT v2.8.0 "tracking" is available (the -w flag) so these commands send a random-ish cookie and can wait for a driver-dictated result attached to that cookie - and discern that reply to their specific request from whatever other traffic passes on the bus.

Using -w -t NUM with a short timeout value (default 10) can be counter-productive if the device interaction takes long. Not sure OTOH what happens for calibration with this driver and hardware, but if theoretically the driver accepts the request, passes it to the device, and returns a verdict only when the device is done - the needed upscmd timeout may be in hours range to receive the ultimate answer to that original request to run a self-test.

Now that you've dug into the logic and comparisons for all of this, and have a device to test with, you may be in fact better positioned than myself to iterate with a custom driver - see https://github.com/networkupstools/nut/wiki/Building-NUT-for-in%E2%80%90place-upgrades-or-non%E2%80%90disruptive-tests

For starters, try adding different diagnostic print-outs into the driver with upsdebugx() to make sense of where it sets or clears the calibration verdict (per your "Done and passed" example that was seen for a while). Maybe it is the driver forgetting it after some loops (e.g. a major vs. minor update... or is that only in snmp-ups?..) or the device itself clearing that status in its reports e.g. after some time has passed or after the battery charge or other internal state has changed and the calibration verdict is no longer deemed trustworthy for whatever reasons the vendor thought of.

Regarding the other question, with synthetic variables - they have their place (e.g. when we do not know the battery charge from the device itself, but "guesstimate" it from known voltage and assumed high/low limits and some assumption about the discharge function over time). I don't think the NUT protocol (see docs/net-protocol.txt) has a way to discern synthetic values from those reported by the device (I certainly never saw any use of that in driver/client code even if it existed); at best there is a higher-level TYPE to tell apart numbers, strings, enums, etc. So as long as there is a suitable name for the concept in docs/nut-names.txt (or one gets negotiated on ups-dev mailing list to appear in the document), feel free to populate it meaningfully.

nikolaysu commented 6 months ago

Thanks for the detailed answer

For now, I hope that it is the UPS that is preventing this value from being obtained due to the fact that the test occurs too often. I'll wait a week and check it out. Debugging the driver looks quite difficult to me and will probably take a lot of time. But I will try to do this if the information is not collected in a week.

nikolaysu commented 6 months ago

I would like to continue this discussion

At the moment I keep getting a value No test initiated

The first thing I noticed was when running the driver in debug mode I compare with powercom(works via usbhid) connected on different host,

   0.013145 [D3] HID descriptor, method 1: (9 bytes) => 09 21 10 01 21 01 22 f3 f1
   0.013147 [D3] HID descriptor length (method 1) 61939
   0.013148 [D4] i=0, extra[i]=09, extra[i+1]=21
   0.013149 [D3] HID descriptor, method 2: (9 bytes) => 09 21 10 01 21 01 22 10 04
   0.013151 [D3] HID descriptor length (method 2) 1040
   0.013152 [D2] Warning: two different HID descriptors retrieved (Reportlen = 61939 vs. 1040)

Perhaps this is some kind of problem?

If you need to do some fine debugging of the code, I’m ready to do it, but I still don’t understand why I need to add a diagnostic output. For now, if I look at the code, I see that the function receives the value 

void upsdrv_updateinfo(void)
....

        if (HIDGetDataValue(udev, event[i], &value, poll_interval) != 1)
            continue;

HIDGetDataValue(libhid.c)-> get_item_buffered(libhid.c)->GetValue(hidparser.c)