• [6.9.0 betas & 6.9.1] Apcupsd issue when booting


    Gnomuz
    • Solved Annoyance

    Hi all,

     

    I'd like to report an issue I have with my brand new APC UPS SMC1000IC (tower model) on my Unraid server. All that follows was first seen in beta30, and beta35 didn't change anything.

     

    I first updated the UPS to the latest firmware (v 04.1) and enabled ModBus communication protocol via the LCD display (it is disabled by default, even though the operation manual states the contrary, so beware ...)

    After setting up apcupsd accordingly (UPS cable USB, UPS type ModBus), I plugged the UPS in the server (USB-A to USB-A), and all information were properly populated, especially the nominal power and load percent. So far, it was plug and play, what a good surprise after the various posts I had read in the forum !

     

    But, there's a but, as you may have guessed... After a reboot, all info were wrong, except for "runtime left" and status (Online/On battery): a fully charged battery was reported as 6% charged, no nominal power nor load percent, and many other tags were absent or totally out of range, including an output voltage of 400+ volts !

     

    After many attempts stopping and starting the daemon, with the UPS plugged or unplugged, I finally reached a stable behaviour :

    - when the server boots with the UPS plugged in (USB), the daemon gets fanciful information, and the workaround is to unplug the UPS, stop/start the daemon, plug the UPS back, and everything is back to normal

    - when the server boots with the UPS unplugged, and I plug it after the boot process is over, communication with the UPS is established, and all information are correct at first sight.

     

    I have also tried to use NUT instead of the built-in apcupsd, but the problem is NUT doesn't seem to know of the ModBus protocol, it only manages communication with UPS in "basic" USB mode. And this UPS reports very little information in basic USB mode (just battery charge level and runtime left, no load percent, no nominal power, no voltages, ...). I get the same limited set of information with both apcupsd in USB  mode and NUT.

    I agree these info (batt level and runtime left) are sufficient to manage a smooth shutdown in case of power outage, so I could run apcupsd with UPS type set to "USB" instead of "ModBus" (or NUT, which would be the same), as I have no issue at boot with this setup.

     

    But I also want to feed various UPS data to my Grafana dashboard (custom UUD 1.4 currently) through telegraf, so I don't see any other solution than apcupsd running with UPS type set to "ModBus" to capture what I want in the dashboard.

     

    So, I've been stuck on this problem for a while now, and my setup is still not operational in case of an unexpected power outage. As the reboot will be automatic when the power comes back, the daemon will get false information (no possible USB unplug/replug if I'm away or sleeping...). It will see the UPS Online with the correct Runtime left, but with a ridiculously low battery charge level (1 to 6% "captured" vs 90+% in reality during my tests). And the batt level remains stuck over time. As I have set the "Battery level to initiate shutdown" to 60%, when a second power outage will occur, even for a few seconds, the shut down will be immediately initiated, due to the false battery charge level. I haven't tested what happens next when the power comes back, but I think it may enter a loop of shutdowns/reboots each time a power outage occurs. That is obviously not a proper setup for a 24/7 server...

     

    I suspect the apcupsd dameon establishes the communication "a bit" too early on my setup, at a stage where the USB "stack" on the server is not totally ready (sorry for the improper words, I'm not an Unraid/Linux expert...) and thus the communication with the UPS is not initialized properly. To try and sort it out, I think that delaying the launch of the apcupsd daemon might be a solution, but I didn't find any setting or thread on this forum to do so. Another possible solution may be to fully reset the USB device through a script, but again I didn't find anything similar in the forum.

     

    Thanks in advance for your thoughts and guidance on this issue.




    User Feedback

    Recommended Comments



    Thanks for the answer.

     

    As required, I rebooted without disconnecting the UPS from the server. Of course, no power outage occurred, and the battery charge level was 100% from the start. 

     

    You will find the following attachments (01 to 09) :

     

    A) Before the reboot

    01 & 02 : screenshots of the UPS settings tab, with correct information

    1750900989_01-Snapshot1beforereboot.thumb.jpg.4c63780aba402c5a4016d3f2da6718a3.jpg

    1294050208_02-Snapshot2beforereboot.thumb.jpg.6939c84acadbab85eae10aad0995ea06.jpg

    03 : diagnostics file

    03 - Diagnostics before reboot.zip

     

    B) After the graceful reboot

    04 & 05 : screenshots of the UPS settings tab, with fanciful information. The status of the UPS is "Online LOWBATT", the battery charge level is 6.2%, UPS load % is 0, battery voltage is 0.4V, line frequency is 6.6 Hz (instead of 50Hz here in Europe), output current is 480.25A (!!!), and nominal output voltage is 120V (instead of 230V). To summarize, the communication between the daemon and the UPS is somehow heavily buggy !

    1973839148_04-Snapshot1afterreboot.thumb.jpg.9cf426cddd47308d5cff2929220a4ec0.jpg

    1819518407_05-Snapshot2afterreboot.thumb.jpg.a26a5123ef5d909aa0842e2a38f3a1bf.jpg

    06 : diagnostic file after reboot

    06 - Diagnostics after reboot.zip

     

    I then applied the reinitialization process described in the OP to return to normal :

    - 19:06:13 stop apcupsd daemon in the UPS settings tab

    - 19:06:22 : disconnect the USB cable between the UPS and the server

    - 19:06:54 : restart the daemon

    - 19:07:24 reconnect the UPS to the server

     

    C) After reinitialization

    07 & 08 : screenshots of the UPS settings tab, which clearly show all information are now correct

    382526840_07-Snapshot1afterreinit.thumb.jpg.d24fcb7b1ea1f5894cfd5b08957e10d8.jpg

    86100361_08-Snapshot2afterreinit.thumb.jpg.e933c6021e61e72c027bef039bf629c6.jpg

    09 : diagnostic file after reinit, with the new syslog messages (nothing unexpected, as far as I can see)

    09 - Diagnostics after reinit.zip

     

    I hope that will be enough to chase the root cause of this malfunctioning. Do not hesitate to ask for more, I'll be more than happy to help and finally sort it out.

     

    Edited by Gnomuz
    typo
    Link to comment
    1 hour ago, Vr2Io said:

    How about if init in basic USB then Modbus ?

    Hum, it's 11pm here, I'm not really willing to reboot now, but I'll try tomorrow morning.

     

    If ever it worked, there could be a temporary workaround :

    - somehow boot with an apcupsd.conf file where UPSTYPE would be forced to "usb"

    - trigger a user script on boot which would sleep for instance 2 minutes, stop the apcupsd daemon, set UPSTYPE to "modbus" in apcupsd.conf, and restart the daemon.

     

    The "only" issue is how to make sure a specific .conf file with "usb" would be present at boot time. The only customization I know of is the "go" file, but it's launched well after the daemon has started. And I even don't know how the UPS settings persist a reboot. So I can't see how I could force the server to modify the UPSTYPE directive during a clean shutdown. Anyhow, in case of a dirty shutdown due to a hang, the server would restart with the "modbus" setting in place. But I'm sure others may have ideas on possible implementations.

     

    Btw @Vr2Io, I've seen posts from you in another thread about apcupsd issues. As you may have seen in my logs, in my case it can't be a USB conflict with a fancy RGB whatever, as the UPS is the only USB device, apart from the Unraid USB key ofc. A NAS is a server, not a night-club or a Christmas tree😉

     

    Edited by Gnomuz
    Link to comment

    I tried to boot with "USBTYPE usb" (partial but correct information) and then switch to "USBTYPE modbus" through the UPS settings tab, as suggested by @Vr2Io. No luck, definitely I need a reinit at USB device level to have the dameon working properly.

     

    Then another idea came to my mind for a workaround. Allright, the "normal" boot sequence ends up in a faulty communication between the UPS and the apcupsd daemon, for whatever reason, probably a sync issue between the daemon startup (very early in boot sequence) and the USB device initialization.

    But I found, after many attempts, a proper post boot workaround to come back to normal :

    - stop the daemon

    - unplug USB cable

    - start daemon

    - plug USB cable

     

    I'm pretty sure it's possible to emulate the unplug and plug actions in a script. If I found a way to do this, that would be pretty simple to have a user script triggered @reboot which would sleep for a minute or so, and would then chain the 4 actions above, perhaps with some kind of temporization in between.

     

    So my question to linux/Unraid experts is simple, is there any way I could emulate the USB cable unplug and plug actions in a script ? I'm aware the answer may be more complicated than the question, but it's key for me not to have to physically access the server or UPS to complete the boot sequence properly, especially in the case of a power outage when I'm away from home.

     

    Thanks in advance for your brilliant ideas 😉

    Link to comment

    Not sure how easy it is to simulate the physical unplug/plug of USB in software.   Are you saying that stopping the USB daemon; waiting a short while for the USB to reset; and then restarting the USB daemon is not sufficient?  Feels much simpler than trying to emulate a USB unplug/plug sequence

    Link to comment
    1 hour ago, Gnomuz said:

    No luck

    Note.

     

    Another workaround suggest, but need you test work or not.

     

    Manboard BIOS may have some option to turn off USB power during reboot or restart, i.e. disable USB charging, enable power saving, enable ERP, disable USB wakeup etc.

    Link to comment
    2 hours ago, itimpi said:

    Not sure how easy it is to simulate the physical unplug/plug of USB in software.   Are you saying that stopping the USB daemon; waiting a short while for the USB to reset; and then restarting the USB daemon is not sufficient?  Feels much simpler than trying to emulate a USB unplug/plug sequence

    Agreed, but simply restarting the daemon without unplugging the UPS between stop and restart has no effect, I tried it as a first possible workaround.

     

    2 hours ago, SimonF said:

    found this article that shows a way to reset a device, but challenge will be to identify correct device.

     

    https://askubuntu.com/questions/645/how-do-you-reset-a-usb-device-from-the-command-line

     

    Does bus change when you unplug? 

     

    sudo sh -c "echo 0 > /sys/bus/usb/devices/1-4.6/authorized"

    sudo sh -c "echo 1 > /sys/bus/usb/devices/1-4.6/authorized"

    In the meantime I found https://raspberrypi.stackexchange.com/questions/6782/commands-to-simulate-removing-and-re-inserting-a-usb-peripheral/7396#7396 , which is also based on sysfs, the proposed commands here are :

    sudo sh -c 'echo 1-1.2 > /sys/bus/usb/drivers/usb/unbind'
    sudo sh -c 'echo 1-1.2 > /sys/bus/usb/drivers/usb/bind'

     

    Unluckily, I tried both (your commands and mine), and they don't work, the information remains fanciful. And my physical magic formula (stop daemon/unplug/start daemon/replug) still works.

     

    Watching the logs while messing with all that, I noticed that the physical unplug/replug sequence increases the device number (device number is currently 7 !), while the bus of course remains the same (bus 3/port 1 for me). None of the sysfs commands (unbind/bind or authorized 0/1) I tried had this effect, which certainly explains why they don't work.

     

    My guess is the device changing its number forces somehow apcupsd to reinitiate its communication sequence with the "new" UPS from zero, which brings things back to normal. And that doesn't happen when the device "reappears" with the sysfs commands under the same device number.

     

    Here is a typical log example of the device number increasing :

    Nov 28 15:11:57 NAS apcupsd[32176]: apcupsd shutdown succeeded                                   <------- 1 - stop daemon   
    Nov 28 15:12:04 NAS kernel: usb 3-1: USB disconnect, device number 6                             <------- 2 - unplug USB
    Nov 28 15:12:11 NAS apcupsd[32742]: apcupsd 3.14.14 (31 May 2016) slackware startup succeeded    <------- 3 - start daemon
    Nov 28 15:12:11 NAS apcupsd[32742]: NIS server startup succeeded
    Nov 28 15:12:21 NAS kernel: usb 3-1: new full-speed USB device number 7 using xhci_hcd           <------- 4 - replug USB
    Nov 28 15:12:21 NAS kernel: hid-generic 0003:051D:0003.0010: hiddev96,hidraw0: USB HID v1.11 Device [American Power Conversion Smart-UPS_1000 FW:UPS 04.1 / ID=1018] on usb-0000:2e:00.3-1/input0

     

     

    I think we are getting closer to a viable workaround, we "just" need someone who would be highly technical on the usb part of the kernel, which is far from being my case ! 

     

    Thanks all for your help, we'll find in the end !

     

    Edited by Gnomuz
    Link to comment
    2 hours ago, Vr2Io said:

    Note.

     

    Another workaround suggest, but need you test work or not.

     

    Manboard BIOS may have some option to turn off USB power during reboot or restart, i.e. disable USB charging, enable power saving, enable ERP, disable USB wakeup etc.

    My mainboard is an AsrockRack X470D4U2-2T, and there are very few USB related BIOS options. To be honest the MB has great hardware, but the BIOS & (non)updates are very poor, not documented at all, and the community around this board is very little ...

    Anyway, if your suggestion is to boot the server without USB connectivity to the UPS, I'm almost sure the BIOS options are not granular enough to disable a specific USB port or hub without disabling the whole USB stack, which will for sure raise an issue when it comes to booting Unraid from the USB flash drive.

    Unless you have more specific directions, I don't think it's the way to go.

     

    Thanks for your help

    Link to comment

    I have compile the usbreset.c in the post.

     

    root@Tower:/dev# /tmp/usbreset /dev/bus/usb/004/005
    Resetting USB device /dev/bus/usb/004/005
    Reset successful
    root@Tower:/dev# 

     

    Nov 28 16:29:21 Tower kernel: usb 4-2: new SuperSpeed Gen 1 USB device number 5 using xhci_hcd
    Nov 28 16:29:54 Tower kernel: usb 4-2: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd

     

    here is the binary attached. I have put in /tmp for testing on my test server.

     

    you will need to chmod +x /tmp/usbreset before using.

     

     

    usbreset

    Link to comment
    3 hours ago, SimonF said:

    I have compile the usbreset.c in the post.

     

    root@Tower:/dev# /tmp/usbreset /dev/bus/usb/004/005
    Resetting USB device /dev/bus/usb/004/005
    Reset successful
    root@Tower:/dev# 

     

    Nov 28 16:29:21 Tower kernel: usb 4-2: new SuperSpeed Gen 1 USB device number 5 using xhci_hcd
    Nov 28 16:29:54 Tower kernel: usb 4-2: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd

     

    here is the binary attached. I have put in /tmp for testing on my test server.

     

    you will need to chmod +x /tmp/usbreset before using.

     

     

    usbreset 8.41 kB · 0 downloads

    Thanks a lot for that @SimonF !

    I had seen various versions of this program, but didn't know how to simply compile them with gcc under Unraid. Btw, how do you do that, I didn't find a way to install gcc in Unraid (no Nerd Pack package, an old unmaintained plugin) ?

     

    With the UPS communicating properly with the daemon, everything seems fine :

     

    root@NAS:~# /tmp/usbreset /dev/bus/usb/003/014
    Resetting USB device /dev/bus/usb/003/014
    Reset successful
    
    Nov 28 20:09:02 NAS kernel: usb 3-2: reset full-speed USB device number 14 using xhci_hcd
    Nov 28 20:09:02 NAS kernel: hid-generic 0003:051D:0003.0018: hiddev96,hidraw0: USB HID v1.11 Device [American Power Conversion Smart-UPS_1000 FW:UPS 04.1 / ID=1018] on usb-0000:2e:00.3-2/input0
    Nov 28 20:09:02 NAS apcupsd[18031]: Communications with UPS lost.
    Nov 28 20:09:02 NAS kernel: usb 3-2: usbfs: process 18031 (apcupsd) did not claim interface 0 before use
    Nov 28 20:09:03 NAS kernel: usb 3-2: reset full-speed USB device number 14 using xhci_hcd
    Nov 28 20:09:05 NAS kernel: usb 3-2: reset full-speed USB device number 14 using xhci_hcd
    Nov 28 20:09:05 NAS apcupsd[18031]: Communications with UPS restored.

    And after this soft reset the daemon still gets correct information.

     

    I now have to reboot without unplugging the UPS, and check if the sequence stop daemon/soft reset/start daemon restores a proper communication.

    I noticed that this soft reset, unlike the unplug/replug which obviously re-enumerates, keeps the same device number (see 14 above). So I'm a bit doubtful, as with the "physical" sequence, the daemon restarts without any device connected, and then "discovers" a new one. We'll see ....

    I will reboot later this evening or tomorrow morning (8:30 pm here) and let you posted. I've copied usbreset on the flash and prepared a script :

    #!/bin/bash
    sleep 10
    DEVNUMS=`lsusb | grep -i 'American Power Conversion UPS' | tr -d : | awk '{print "/dev/bus/usb/" $2 "/" $4;}'`
    /boot/config/usbreset $DEVNUMS

     

     

    Edited by Gnomuz
    Link to comment
    29 minutes ago, Gnomuz said:

    gcc in Unraid

    There is a devpack plugin which allowed me to install gcc but could not get it to compile as couldnt find headers.

     

    I have a build linux vm I use for changes to smartctl I have created and to package my plugins.

     

    No worries, I am in the UK so its nearly 8pm here also. You will need to put on flash and either copy in go file or run from boot as /tmp will be lost during reboot.

    Edited by SimonF
    Link to comment

    Well, I just copied usbreset to /boot/config/, but chmod +x /boot/config/usbreset sends no error, but doesn't change the file permissions (still -rw-------). Sounds like a noob question, but I'm a noob in linux !!!

    Edited by Gnomuz
    Link to comment
    14 minutes ago, Gnomuz said:

    Well, I just copied usbreset to /boot/config/, but chmod +x /boot/config/usbreset sends no error, but doesn't change the file permissions (still -rw-------). Sounds like a noob question, but I'm a noob in linux !!!

    You MUST copy the file to somewhere other than /boot. Linux permissions aren't honored in any path under /boot because it's FAT32, which doesn't support linux file permissions fully.

    Link to comment

    Edit the go file in /boot/config

     

    Below is an example of changes I have in my go on my test server for new version of smartctl to support SAS drives.  Not sure if you need to do before or after the GUI starts for your requirements. 

     

    cp /boot/extras/smartctl /usr/local/sbin/smartctl.real
    chmod +x /usr/local/sbin/smartctl.real
    cp /boot/extras/smartctl.wrapper /usr/sbin/smartctl
    chmod +x /usr/sbin/smartctl

    cp /usr/sbin/hdparm /usr/local/sbin/hdparm.real
    chmod +x /usr/local/sbin/hdparm.real
    cp /boot/extras/hdparm.wrapper /usr/sbin/hdparm
    chmod +x /usr/sbin/hdparm

     

    /usr/local/sbin/emhttp &

    Link to comment

    Thanks for the lesson @jonathanm, next time I will think of what file sytem is used before posting ...

    go file modified, usbreset will be copied to /usr/local/sbin and I modified the user script accordingly. Thks for the template @SimonF

     

    We'll see tomorrow, as now it's 10pm, good night all.

    • Thanks 1
    Link to comment

    Hi all,

    I'm back on this issue. I had the opportunity to reboot and thus test the usbreset program @SimonF kindly compiled for me.

     

    Bad news, although highly anticipated for me. The software reset by usbreset does not work :

    - after the reboot without unplugging the UPS, apcupsd had the usual crazy information

    - I stopped apcupsd

    - I launched usbreset which did its job ("reset full-speed USB device number 2 using xhci_hid")

    - I relaunched apcupsd, still faulty

    - The usual unplug/restart daemon/replug did the job, as expected.

    As already stated, the major difference with a physical unplug/replug action is that the device number changes. I have the feeling the daemon then sees the UPS as a brand new one, and restarts dialog from the very beginning. I now have to admit my technical skills as well as my patience have reached their limit on this issue.

     

    As a reminder, the "latest" release of apcupsd is dated May 2016, and my UPS is brand new (product launched late 2019). I didn't check, but it's possible, if not likely, the ModBus protocol has evolved in the past 4 years and a half (!), and my issue may be some kind of incompatibility between a non-maintained critical package as apcupsd and an up-to-date firmware in the UPS. In May 2016, the latest kernel version was 4.6. I didn't take time to go through the release notes, but it's reasonable to think the USB management has "slightly" evolved in the kernel since then, due for instance to USB 3.2 appearance in 2017. And I think many other possible causes could be found for explaining the malfunctioning of an obsolete low-level software with up-to-date hardware and firmware.

     

    So, thanks for all the help from community members, but I think I definitely need @limetech on this one, as UPS management is a built-in feature of Unraid, supported as such by Limetech, even if the maintenance of the underlying open-source software seems to have stopped mid-2016.

    Of course, I'll be more than happy to participate in the debugging of this OS functionality, for the benefit of all existing and future Unraid users owning a similar common UPS model.

     

    Thanks in advance for your attention and help.

    Edited by Gnomuz
    Link to comment

    It's a month now that I last posted on this thread, concluding we definitely needed help from the developers to debug this critical built-in function of Unraid, without any feedback.

    Diagnostics and screenshots to document the bug had been, as required by @limetech, provided on November 24th 2020, followed-up with a deafening silence.

     

    It's winter now in Europe, I've had a few power outages, and it was a mess to restart everything properly, especially because unplugging / replugging the USB cable is not that easy when you're away from home... It's just a crappy workaround, and I think nobody would seriously consider it as a stable production setup.

     

    So, I hope everybody will understand my bump ;-)

    If any further diagnostics, tests, attempts, ... are required, I'll be more than happy to provide them in a timely manner.

    Edited by Gnomuz
    Link to comment

    [I just spent 3 hours documenting the step by step work I'd been doing on this for logging in this thread.  I have the same UPS and the same errors and the same problems.  I don't use unRAID though but I'm sure it's nothing to do with unRaid.  I've spent several nights attacking this problem from a low level USB /HID driver problem.

     

    Then, 5 minutes ago, I tried something different.

     

    And it fixed it.

    What... the...

     

    No guarantees, but here's what I did:

    # usb_modeswitch -v 0x051d -p 0x0003 --reset-usb


    (Check lsusb output to find out your vendor and product IDs)


    That's it.  apctest works.  apcaccess now reports ALL data.]

     

    Background:

    UPS: APC smc1500-2UC (same as the smc1500 but rack-mount. )

    bios: 1.41, modbus enabled via front panel.

    ubuntu 20.04

    apcupsd 3.14.14

    apcupsd.conf:
        UPSCABLE usb
        UPSTYPE modbus
        DEVICE

    Unplug the usb cable then plug it back in.

    lsusb reports the device with the incremented port:

    root@sophie:/etc/apcupsd# lsusb
    Bus 001 Device 022: ID 051d:0003 American Power Conversion UPS

     

    dmesg shows:

    [Sun Jan 17 21:31:31 2021] usb 1-6.4: USB disconnect, device number 21
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: new full-speed USB device number 22 using xhci_hcd
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: New USB device found, idVendor=051d, idProduct=0003, bcdDevice= 0.01
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: Product: Smart-UPS_1500 FW:UPS 04.1 / ID=1018
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: Manufacturer: American Power Conversion  
    [Sun Jan 17 21:31:36 2021] usb 1-6.4: SerialNumber: 3S2012X12122     
    [Sun Jan 17 21:31:36 2021] hid-generic 0003:051D:0003.001C: hiddev1,hidraw5: USB HID v1.11 Device [American Power Conversion  Smart-UPS_1500 FW:UPS 04.1 / ID=1018] on usb-0000:00:14.0-6.4/input0

     

    Making sure that apcupsd is not running, I can run apctest but get the following:
     

    root@sophie:/etc/apcupsd# apctest
    
            2021-01-17 21:15:44 apctest 3.14.14 (31 May 2016) debian
            Checking configuration ...
            sharenet.type = Network & ShareUPS Disabled
            cable.type = USB Cable
            mode.type = MODBUS UPS Driver
            Setting up the port ...
            0.837 apcupsd: ModbusUsbComm.cpp:142 ModbusRx: TIMEOUT
            Doing prep_device() ...
            4.091 apcupsd: ModbusUsbComm.cpp:142 ModbusRx: TIMEOUT
    
            You are using a MODBUS cable type, so I'm entering MODBUS test mode
            Hello, this is the apcupsd Cable Test program.
            This part of apctest is for testing MODBUS 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
            10) Perform battery calibration
            11) Test alarm
            Q) Quit

    Note that it glitches during initialisation but gets there in the end.  Trying a safe function (Perform self-test) works, as does 'Read last self-test result'.

     

    However, the moment I exit apctest, the following appears in dmesg:

    [Sun Jan 17 21:17:27 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd

     

    Ok, fine.  apctest resets the device.  However, if I try to re-run apctest immediately, the following occurs:

    root@sophie:/etc/apcupsd# apctest
            2021-01-17 21:18:31 apctest 3.14.14 (31 May 2016) debian
            Checking configuration ...
            sharenet.type = Network & ShareUPS Disabled
            cable.type = USB Cable
            mode.type = MODBUS UPS Driver
            Setting up the port ...
            0.289 apcupsd: ModbusUsbComm.cpp:258 WaitIdle: interrupt_read failed: Success
            0.849 apcupsd: ModbusUsbComm.cpp:142 ModbusRx: TIMEOUT
            1.402 apcupsd: ModbusUsbComm.cpp:142 ModbusRx: TIMEOUT
            1.602 apcupsd: ModbusComm.cpp:201 SendAndWait: Wrong size (exp=7, rx=21)
            1.674 apcupsd: ModbusComm.cpp:201 SendAndWait: Wrong size (exp=7, rx=21)
            1.962 apcupsd: ModbusComm.cpp:201 SendAndWait: Wrong size (exp=21, rx=7)
            2.033 apcupsd: ModbusComm.cpp:201 SendAndWait: Wrong size (exp=21, rx=7)
            ...

     

    followed by many, many more glitchy lines, and eventually the menu.

    Exiting apctest and trying to start up the apcupsd daemon causes the following to start appearing in the syslogs:

    [Sun Jan 17 21:19:28 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd
    [Sun Jan 17 21:19:55 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd
    [Sun Jan 17 21:19:57 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd
    [Sun Jan 17 21:24:08 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd
    [Sun Jan 17 21:25:09 2021] usb 1-6.4: reset full-speed USB device number 21 using xhci_hcd

     

    Which I assume is happening as a consequence of something "not quite right".

     

    Here's the (wrong) output of apcaccess when things aren't working:
     

    root@sophie:/etc/apcupsd# systemctl start apcupsd
    
    root@sophie:/etc/apcupsd# apcaccess
    
            APC      : 001,018,0436
            DATE     : 2021-01-17 21:19:46 -0800  
            HOSTNAME : sophie
            VERSION  : 3.14.14 (31 May 2016) debian
            UPSNAME  : sophieUPS
            CABLE    : USB Cable
            DRIVER   : MODBUS UPS Driver
            UPSMODE  : Stand Alone
            STARTTIME: 2021-01-17 21:19:43 -0800  
            STATUS   :
            MBATTCHG : 5 Percent
            MINTIMEL : 3 Minutes
            MAXTIME  : 0 Seconds
            NUMXFERS : 0
            TONBATT  : 0 Seconds
            CUMONBATT: 0 Seconds
            XOFFBATT : N/A
            STATFLAG : 0x05000000
            END APC  : 2021-01-17 21:19:46 -0800  

     

    And even when things are sort of working, here's the output of apcacess that still isn't any good:

     

    image.thumb.png.cde17c8cdad61a7edca445d432851b42.png

     

     

     

    WIthout going into the 3 day jungle safari that has been my digging into learning the apcupcd code and how usb devices work when plugged into linux, suffice to say that I learned much about things I will never have a use for, but eventually worked out that I wanted to be able to disconnect and reconnect the usb device "at will", in the hopes of using the failed workaround documented by @Gnomuz.

    This led me through HID space and the frustrations of identifying the device path when something is plugged in.  But then I discovered that 'mod_switch' has a reset parameter, and you only need to provide it with the Vendor and product IDs reported by 'lsusb'.

     

    Thus, the still-unbelievable simplicity of this:

    root@sophie:/etc/apcupsd# usb_modeswitch -v 0x051d -p 0x0003 --reset-usb
    Look for default devices ...
    Found devices in default mode (1)
    Access device 022 on bus 001
    Get the current device configuration ...
    Current configuration number is 1
    Use interface number 0
    with class 3
    Warning: no switching method given. See documentation
    Reset USB device .
    Device was reset
    -> Run lsusb to note any changes. Bye!

     

    Followed pessimistically by

    root@sophie:/etc/apcupsd# apctest
    
    2021-01-17 22:38:48 apctest 3.14.14 (31 May 2016) debian
    Checking configuration ...
    sharenet.type = Network & ShareUPS Disabled
    cable.type = USB Cable
    mode.type = MODBUS UPS Driver
    Setting up the port ...
    Doing prep_device() ...
    
    You are using a MODBUS cable type, so I'm entering MODBUS test mode
    Hello, this is the apcupsd Cable Test program.
    This part of apctest is for testing MODBUS 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
    10) Perform battery calibration
    11) Test alarm
    Q) Quit
    
    Select function number: q

     

    Where I noticed that I didn't get any of the glitch messages at all.

    I then repeatedly ran apctest over and over expecting errors, and got none.  Anywhere.

     

    Still not believing anything, I started up apcupsd:

     

    root@sophie:/etc/apcupsd# systemctl start apcupsd

     

    and of course immediately tried the penultimate test, apcaccess.  Which now reported this [you're gonna love this]:

    root@sophie:/etc/apcupsd# apcaccess
    APC      : 001,038,0879
    DATE     : 2021-01-17 22:39:52 -0800   
    HOSTNAME : sophie
    VERSION  : 3.14.14 (31 May 2016) debian
    UPSNAME  : SophieUPS
    CABLE    : USB Cable
    DRIVER   : MODBUS UPS Driver
    UPSMODE  : Stand Alone
    STARTTIME: 2021-01-17 22:39:45 -0800   
    STATUS   : ONLINE  
    LINEV    : 118.4 Volts
    LOADPCT  : 34.9 Percent
    LOADAPNT : 22.6 Percent
    BCHARGE  : 98.4 Percent
    TIMELEFT : 28.0 Minutes
    MBATTCHG : 5 Percent
    MINTIMEL : 3 Minutes
    MAXTIME  : 0 Seconds
    OUTPUTV  : 118.4 Volts
    DWAKE    : 0 Seconds
    DSHUTD   : 180 Seconds
    ITEMP    : 22.6 C
    BATTV    : 26.0 Volts
    LINEFREQ : 60.0 Hz
    OUTCURNT : 2.75 Amps
    NUMXFERS : 0
    TONBATT  : 0 Seconds
    CUMONBATT: 0 Seconds
    XOFFBATT : N/A
    SELFTEST : OK
    STATFLAG : 0x05000008
    MANDATE  : 2020-03-17
    SERIALNO : 3S2012X12122
    BATTDATE : 2020-04-14
    NOMOUTV  : 120 Volts
    NOMPOWER : 900 Watts
    NOMAPNT  : 1440 VA
    FIRMWARE : UPS 04.1 / 00.5
    END APC  : 2021-01-17 22:40:46 -0800

     

    It's all there, and more.

    My current best guess is that something isn't being initialized properly, or reset properly, within the apcupsd / apctest code.  But running usb_modeswitch resets it properly/fully.

     

    That'll do me.

     

    • Like 2
    • Thanks 1
    Link to comment
    16 hours ago, Dir said:

    I don't use unRAID though but I'm sure it's nothing to do with unRaid.

    Kudos for posting the results of your extensive research here, despite not being an Unraid user.

    Link to comment

    It is with great regret, and some slight deja vu, that I have to report that my "solution" didn't in fact, work.  It turns out that the same underlying problem remains - you only get valid data after you unplug/plug in the UPS and run the daemon, or apctest, >once<.  After that, it's buggered.

     

    My current suspicion is that the UPS becomes out of sync with the port / hid status and considers itself still communicating with it.  So any subsequent "Hi, I'm apctest, let's start from scratch and get to know each other" is met by the UPS with, "...the other day, and so Sally then said,...". 

     

    In other words, something needs to tell the ups "HEY, STOP.  Now start like you've never met me before".

    • Haha 1
    Link to comment

    Hello all,

     

    I'm back on this persistent and expasperating issue, which obliges me to go back and forth from my basement to my office whenever I reboot my Unraid server ... I've just upgraded the server to 6.9.1 and of course nothing has changed. I do agree with @Dirthat Unraid as the base distro is very likely not at stake, and that apcupsd somehow messes up with this particular UPS during the initialization/reset phase. Nothing suprising either, the latest release of apcupsd in 2016 (!!!) is 3 years older than this UPS launch ...

     

    So I went through the apcupsd mailing list as suggested by @jademonkee and obviously @Dir and I are not the only ones to meet this issue. From what I've seen, the generally agreed "solution" is to switch to the good old serial connection instead of USB, with a specific RJ45 to DB9 female cable (ref APC AP940-0625A, 2 meters long). I'm lucky enough to have a serial port on my motherboard, so i've just ordered the cable from amazon for roughly 30€ and should receive it next week.

     

    I understand the apcupsd settings should be as follows with this setup :

    • UPS Cable : Custom
    • Custom UPS Cable : 940-0625A
    • UPS type : APCsmart or ModBus (depending on ModBus activation or not on the UPS ?)
    • Device : /dev/tty**

     

    If anyone has already succeeded in running a similar setup, you're welcome to confirm or amend !

     

    I'll report back once I've received the cable and tried this solution, which will remain a workaround for me, even if it happened to work in the end...

    Edited by Gnomuz
    Link to comment



    Join the conversation

    You can post now and register later. If you have an account, sign in now to post with your account.
    Note: Your post will require moderator approval before it will be visible.

    Guest
    Add a comment...

    ×   Pasted as rich text.   Restore formatting

      Only 75 emoji are allowed.

    ×   Your link has been automatically embedded.   Display as a link instead

    ×   Your previous content has been restored.   Clear editor

    ×   You cannot paste images directly. Upload or insert images from URL.


  • Status Definitions

     

    Open = Under consideration.

     

    Solved = The issue has been resolved.

     

    Solved version = The issue has been resolved in the indicated release version.

     

    Closed = Feedback or opinion better posted on our forum for discussion. Also for reports we cannot reproduce or need more information. In this case just add a comment and we will review it again.

     

    Retest = Please retest in latest release.


    Priority Definitions

     

    Minor = Something not working correctly.

     

    Urgent = Server crash, data loss, or other showstopper.

     

    Annoyance = Doesn't affect functionality but should be fixed.

     

    Other = Announcement or other non-issue.