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

[nikolaysu]

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

• last test time - LASTSTEST in apcaccess
• battery life - TIMELEFT in apcaccess

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]

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

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

[nikolaysu]

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]

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]

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]

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]

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]

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]

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]

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:

• Does the output of the SUCCESS command /bin/upscmd matter or does it only mean that the command is complete?
• does the -w parameter have an effect on the usbhid-ups driver?

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]

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]

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]

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)