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
1.99k stars 349 forks source link

Unable to connect to UPS (ETA-1600 SINUS) #1077

Open dmilith opened 3 years ago

dmilith commented 3 years ago

I have configured UPS named "eta":

[eta]
        driver = blazer_usb
        port = auto

This driver worked well with this UPS on Linux… but on FreeBSD 13.0:

This is what I get:

./blazer_usb -DDDDDDD -a eta
Network UPS Tools - Megatec/Q1 protocol USB driver 0.12 (2.7.4)
   0.000000     send_to_all: SETINFO driver.parameter.port "auto"
   0.000245     debug level is '7'
   0.035863     Checking device (0001/0000) (/dev/usb//dev/ugen1.2)
   0.053452     - VendorID: 0001
   0.053512     - ProductID: 0000
   0.053542     - Manufacturer: MEC
   0.053566     - Product: MEC0003
   0.053590     - Serial Number: unknown
   0.053615     - Bus: /dev/usb
   0.053638     - Device release number: 0100
   0.053662     Trying to match device
   0.053694     Device matches
   0.053731     nut_usb_set_altinterface: skipped usb_set_altinterface(udev, 0)
   0.053790     send_to_all: SETINFO ups.vendorid "0001"
   0.053831     send_to_all: SETINFO ups.productid "0000"
   0.053891     send_to_all: SETINFO device.type "ups"
   0.053932     send_to_all: SETINFO driver.version "2.7.4"
   0.053973     send_to_all: SETINFO driver.version.internal "0.12"
   0.054011     send_to_all: SETINFO driver.name "blazer_usb"
   0.054049     Trying megatec protocol...
   0.054077     send: Q1
   0.406719     read: Unknown error
   0.406980     Permissions problem: Input/output error

What am I doing wrong?

aquette commented 3 years ago

If it's not already the case, I'd run as root. Then, I can't say how much freebsd USB stack is mature. I helped the early Sun and Linux implementation, back 2 decades ago, but never found time to look at other friends... export USB_DEBUG=3 Iirc, may help to get more visibility too

dmilith commented 3 years ago

That's the thing… I'm running it as root. Tried with all kind of debug messages… listening on the bus with usbdump…

17:53:30.284901 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.286915 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.287242 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.288895 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.289203 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 01 03 09 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.290893 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  08 03 4D 00 -- -- -- --  -- -- -- -- -- -- -- --  |..M.            |
17:53:30.291200 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 01 03 09 00 08 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 8 bytes
17:53:30.292893 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 8 bytes
 0000  08 03 4D 00 45 00 43 00  -- -- -- -- -- -- -- --  |..M.E.C.        |
17:53:30.293207 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.294895 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.295209 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.296901 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.297211 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 02 03 09 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.298900 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  10 03 4D 00 -- -- -- --  -- -- -- -- -- -- -- --  |..M.            |
17:53:30.299210 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 02 03 09 00 10 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 16 bytes
17:53:30.301900 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=16,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 16 bytes
 0000  10 03 4D 00 45 00 43 00  30 00 30 00 30 00 33 00  |..M.E.C.0.0.0.3.|
17:53:30.314104 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.315898 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.316208 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 00 03 00 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.317893 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=4,IVAL=0,ERR=0
 frame[0] WRITE 8 bytes
 frame[1] READ 4 bytes
 0000  04 03 09 00 -- -- -- --  -- -- -- -- -- -- -- --  |....            |
17:53:30.318297 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 03 03 09 00 04 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 4 bytes
17:53:30.532895 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=0,IVAL=0,ERR=IOERROR
 frame[0] WRITE 8 bytes
 frame[1] READ 0 bytes
17:53:30.599562 usbus3.2 SUBM-CTRL-EP=00000080,SPD=LOW,NFR=2,SLEN=8,IVAL=0
 frame[0] WRITE 8 bytes
 0000  80 06 03 03 09 00 FF 00  -- -- -- -- -- -- -- --  |........        |
 frame[1] READ 255 bytes
17:53:30.600912 usbus3.2 DONE-CTRL-EP=00000080,SPD=LOW,NFR=1,SLEN=0,IVAL=0,ERR=IOERROR
 frame[0] WRITE 0 bytes

No sign of anything wrong. Even from truss side it's cryptic:

…
write(2,"send_to_all: SETINFO ups.vendori"...,41) = 41 (0x29)
   0.033457     write(2,"   0.033457\t",12)                      = 12 (0xc)
send_to_all: SETINFO ups.productid "0000"
write(2,"send_to_all: SETINFO ups.product"...,42) = 42 (0x2a)
   0.033669     write(2,"   0.033669\t",12)                      = 12 (0xc)
send_to_all: SETINFO device.type "ups"
write(2,"send_to_all: SETINFO device.type"...,39) = 39 (0x27)
   0.033874     write(2,"   0.033874\t",12)                      = 12 (0xc)
send_to_all: SETINFO driver.version "2.7.4"
write(2,"send_to_all: SETINFO driver.vers"...,44) = 44 (0x2c)
   0.034079     write(2,"   0.034079\t",12)                      = 12 (0xc)
send_to_all: SETINFO driver.version.internal "0.12"
write(2,"send_to_all: SETINFO driver.vers"...,52) = 52 (0x34)
   0.034284     write(2,"   0.034284\t",12)                      = 12 (0xc)
send_to_all: SETINFO driver.name "blazer_usb"
write(2,"send_to_all: SETINFO driver.name"...,46) = 46 (0x2e)
   0.034488     write(2,"   0.034488\t",12)                      = 12 (0xc)
Trying megatec protocol...
write(2,"Trying megatec protocol...\n",27)       = 27 (0x1b)
   0.034713     write(2,"   0.034713\t",12)                      = 12 (0xc)
send: Q1
write(2,"send: Q1\n",9)                          = 9 (0x9)
ioctl(4,USB_DO_REQUEST,0xffffffffd350)           = 0 (0x0)
ioctl(4,USB_DO_REQUEST,0xffffffffd350)           = 0 (0x0)
ioctl(4,USB_DO_REQUEST,0xffffffffd350)           ERR#5 'Input/output error'
ioctl(4,USB_DO_REQUEST,0xffffffffd350)           ERR#5 'Input/output error'
   0.388584     write(2,"   0.388584\t",12)                      = 12 (0xc)
read: Unknown error
write(2,"read: Unknown error\n",20)              = 20 (0x14)
fstatat(AT_FDCWD,"/usr/share/nls/C/libc.cat",0xffffffffce10,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/share/nls/libc/C",0xffffffffce10,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/local/share/nls/C/libc.cat",0xffffffffce10,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/local/share/nls/libc/C",0xffffffffce10,0x0) ERR#2 'No such file or directory'
   0.389152     write(2,"   0.389152\t",12)                      = 12 (0xc)
Permissions problem: Input/output error
write(2,"Permissions problem: Input/outpu"...,40) = 40 (0x28)
ioctl(5,USB_FS_UNINIT,0xffffffffd2e0)            = 0 (0x0)
close(5)                                         = 0 (0x0)
close(4)                                         = 0 (0x0)
exit(0x1)
process exit, rval = 1
dmilith commented 3 years ago

The weirdest part is that ioctl to 0xffffffffd350… Done 4 times… 2 times it was just fine… next 2… I/O errors… -_-

dmilith commented 3 years ago

Ok… When I recompiled with TESTING=1… It just works… sad it's just all testing values:

[1629479523] vks1:/Software/Nut/bin λ upsd
Network UPS Tools upsd 2.7.4-2486-gaa0b3d1d
fopen /var/state/ups/upsd.pid: No such file or directory
/Services/Nut/etc/upsd.conf is world readable
listening on 127.0.0.1 port 3493
listening on ::1 port 3493
/var/state/ups is world readable
Connected to UPS [eta]: blazer_usb-eta
/Services/Nut/etc/upsd.users is world readable
[1629479544] vks1:/Software/Nut/bin λ upsc eta
battery.charge: 100
battery.voltage: 27.24
battery.voltage.high: 26.00
battery.voltage.low: 20.80
battery.voltage.nominal: 24.0
device.mfr: -------------
device.model: ------
device.type: ups
driver.name: blazer_usb
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.parameter.synchronous: yes
driver.parameter.usb_set_altinterface: 0
driver.version: 2.7.4-2486-gaa0b3d1d
driver.version.internal: 0.12
input.current.nominal: 0.0
input.frequency: 49.0
input.frequency.nominal: 50
input.voltage: 215.0
input.voltage.fault: 195.0
input.voltage.nominal: 230
output.voltage: 230.0
ups.beeper.status: disabled
ups.delay.shutdown: 30
ups.delay.start: 180
ups.firmware: VT12046Q
ups.load: 14
ups.mfr: -------------
ups.model: ------
ups.status: OL BOOST
ups.temperature: 30.0
ups.type: offline / line interactive

which means that issue is with this command: https://github.com/networkupstools/nut/blob/9ea2aa279ed9b68994c1675701eff21e6fdde34f/drivers/blazer_usb.c#L434 which returns EPERM cause of some weird reason?

aquette commented 3 years ago

Thanks for the feedback. I forgot to mention that you should prefer nutdrv-qx too

dmilith commented 3 years ago

After a minute of hacking with nutdrv_qx with conf:

[eta]
        driver = nutdrv_qx
        vendor = MEC
        port = auto

Output:

Network UPS Tools - Generic Q* USB/Serial driver 0.30 (2.7.4-2486-gaa0b3d1d)
USB communication driver 0.33
   0.000000     [D1] debug level is '5'
   0.001199     [D5] send_to_all: SETINFO device.type "ups"
   0.001237     [D1] upsdrv_initups...
   0.002925     [D3] usb_busses=0x403b5a30
   0.002964     [D2] Checking device (0001/0000) (/dev/usb//dev/ugen1.2)
   0.019638     [D2] - VendorID: 0001
   0.019666     [D2] - ProductID: 0000
   0.019681     [D2] - Manufacturer: MEC
   0.019695     [D2] - Product: MEC0003
   0.019709     [D2] - Serial Number: unknown
   0.019723     [D2] - Bus: /dev/usb
   0.019737     [D2] - Device: /dev/ugen1.2
   0.019751     [D2] - Device release number: 0100
   0.019765     [D2] Trying to match device
   0.019780     [D3] match_function_regex: matching a device...
   0.019836     [D2] Device matches
   0.019867     [D3] nut_usb_set_altinterface: skipped usb_set_altinterface(udev, 0)
   0.019898     [D5] send_to_all: SETINFO ups.vendorid "0001"
   0.019920     [D5] send_to_all: SETINFO ups.productid "0000"
   0.020005     [D3] send: QGS
   0.020042     [D3] read: QGS
   0.020094     [D2] qx_process_answer: short reply (input.voltage)
   0.020125     [D3] send: QGS
   0.020141     [D3] read: QGS
   0.020157     [D2] qx_process_answer: short reply (input.voltage)
   0.020183     [D3] send: QGS
   0.020208     [D3] read: QGS
   0.020224     [D2] qx_process_answer: short reply (input.voltage)
   0.020244     [D3] send: M
   0.020259     [D3] read: M
   0.020298     [D2] voltronic_qs_protocol: invalid protocol [M]
   0.020316     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020335     [D3] send: M
   0.020351     [D3] read: M
   0.020369     [D2] voltronic_qs_protocol: invalid protocol [M]
   0.020384     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020401     [D3] send: M
   0.020416     [D3] read: M
   0.020433     [D2] voltronic_qs_protocol: invalid protocol [M]
   0.020448     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020468     [D3] send: M
   0.020483     [D3] read: M
   0.020517     [D2] voltronic_qs_hex_protocol: invalid protocol [M]
   0.020536     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020554     [D3] send: M
   0.020570     [D3] read: M
   0.020587     [D2] voltronic_qs_hex_protocol: invalid protocol [M]
   0.020602     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020619     [D3] send: M
   0.020635     [D3] read: M
   0.020652     [D2] voltronic_qs_hex_protocol: invalid protocol [M]
   0.020667     [D4] ups_infoval_set: failed to preprocess value [ups.firmware.aux: M]
   0.020685     [D3] send: QS
   0.020701     [D3] read: QS
   0.020731     [D2] qx_process_answer: short reply (input.voltage)
   0.020750     [D3] send: QS
   0.020766     [D3] read: QS
   0.020782     [D2] qx_process_answer: short reply (input.voltage)
   0.020799     [D3] send: QS
   0.020814     [D3] read: QS
   0.020830     [D2] qx_process_answer: short reply (input.voltage)
   0.020847     [D3] send: D
   0.020862     [D3] read: D
   0.020892     [D2] qx_process_answer: short reply (input.voltage)
   0.020911     [D3] send: D
   0.020927     [D3] read: D
   0.020942     [D2] qx_process_answer: short reply (input.voltage)
   0.020959     [D3] send: D
   0.020974     [D3] read: D
   0.020990     [D2] qx_process_answer: short reply (input.voltage)
   0.021008     [D3] send: Q1
   0.021023     [D4] command index: 0x03
   0.373166     [D3] read: Unknown error (-1)
   0.373331     Permissions problem: Input/output error
zsh: exit 1     ./nutdrv_qx -a eta -DDDDD
aquette commented 3 years ago

Trying to catch @zykh attention. He's the Qx master

dmilith commented 3 years ago

The weirdest thing is that this device works with libusb from Linux with blazer_usb driver. I start to wonder if that's something specific to libusb on FreeBSD 13.0…