Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add support for new APC Modbus protocol #139

Closed
aquette opened this issue Jul 26, 2014 · 128 comments · Fixed by #2063
Closed

Add support for new APC Modbus protocol #139

aquette opened this issue Jul 26, 2014 · 128 comments · Fixed by #2063

Comments

@aquette
Copy link
Member

aquette commented Jul 26, 2014

From APCUPSD (http://apcupsd.cvs.sourceforge.net/viewvc/apcupsd/apcupsd/ReleaseNotes?pathrev=Release-3_14_11):
"APC publicly released documentation[1] on a new UPS control and monitoring protocol, loosely referred to as MODBUS (after the historic industrial control protocol it is based on). The new protocol operates over RS232 serial lines as well as USB connections and is intended to supplement APC's proprietary Microlink protocol. Microlink is not going away, but APC has realized that third parties require access to UPS status and control information. Rather than publicly open Microlink, they have created another protocol to operate along side it.

Many existing Microlink UPSes can be upgraded to support MODBUS via a firmware update. See [2]. Certain older models are not upgradeable. APC support will be your best contact for determining if your UPS supports a MODBUS upgrade the information linked below does not make it clear."

[1] http://www.apc.com/whitepaper/?an=176
[2] http://www.schneider-electric.us/support/index?page=content&country=ITB&lang=EN&id=FA164737
[3] http://www.apcupsd.com/manual/manual.html


Add support for MODBUS over RS232 and USB in NUT.
This effort must be synchronized with the general Modbus support in NUT ( #50 )


Implementation notes:

  • serial version: use the serial RTU support from libnutdrv_modbus (WIP)
  • USB version: 2 possibilities
    • create a HID subdriver, that marshals Modbus => better integration, easier for users
    • create a new driver, which uses interrupt support in NUT libusb, but not libhid (for the 2 usages ModbusRTURx and ModbusRTUTx) => smaller driver footprint
@ggershwf
Copy link

I'm not having much success with this, unfortunately. I'm sure I'm doing something wrong, but I'm not sure what. I've got an APC Smart UPS 1500 (made in 2013). It appears that I've defined it correctly, since the drivers starts, but I get a continuous stream of "Data Stale" from upsmon. I am using Network UPS Tools upsc 2.6.5, if that makes any difference.

@clepple
Copy link
Member

clepple commented Aug 22, 2014

@ggershwf if you are referring to the nutdrv-modbus branch, then as of commit eddcd7e, the driver does not actually retrieve anything yet. It just links against the modbus library, and attempts to open the serial device.

It does not matter if you use an earlier version of upsc - as seen in the README file, any 2.0+ client (e.g. upsc) can talk to a 2.0+ server. The interface that is not guaranteed to be stable between versions is the driver-upsd socket interface.

@clepple
Copy link
Member

clepple commented Aug 23, 2014

@aquette link 1 is broken; searching for the filename turned up this:

http://www.apcmedia.com/salestools/MPAO-98KJ7F/MPAO-98KJ7F_R0_EN.pdf

The paragraph at the bottom of the second page looks troubling.

@ggershwf
Copy link

@clepple Thanks. I guess it's working up to that point, then.

@aquette
Copy link
Member Author

aquette commented Sep 2, 2014

Yep guys, sorry.
I was in the middle of this when I got caught by family vacations.
Resuming ops...

(sent from my eeePad... please excuse my brevity)

@jeffsf
Copy link

jeffsf commented Nov 23, 2015

I'd definitely like to see this as well, especially as SUA-series APC units that aren't trashed are getting pretty scarce and the SMT-series units are coming down to a reasonable point (finally).

I have two SMT1500 units that I can work with here to help support the effort.

@anthonysomerset
Copy link

anthonysomerset commented Mar 23, 2017

throwing my hat into the ring with an offer to support with testing

i have an SMT2200

ups.firmware: UPS 09.3 / ID=18 ups.mfr: American Power Conversion
ups.mfr.date: 2016/11/26 ups.model: Smart-UPS 2200
ups.productid: 0003

@edalquist
Copy link

Is there any progress here? I have a SMC1500 and two SMT1500s. They both have basic functionality in NUT but don't report input/output voltage or load.

"All Data" dumps of the two units: https://gist.github.com/edalquist/3fb91870830242fe8016710449ce0a14

@clepple
Copy link
Member

clepple commented Jun 24, 2017

Question for those who have offered to test: does your APC UPS have a serial port, and if so, do you know if it supports MODBUS?

I ask because the effort mentioned in issue #50 seems to be focused on using libmodbus - but that library currently supports only serial and TCP. APC's method of tunneling MODBUS over USB HID reports is probably similar to the serial stream, but it sounds like it will involve rewriting a lot of code.

@pjcreath
Copy link

According to the white paper, all SRT models and SMT models (excluding rack mount 1U) running firmware >= UPS 09.0 support modbus. SMT models with firmware >= UPS 08.0 can be updated to 09.x, which according to the FAQ includes all 2U models and some tower models.

Given that, @anthonysomerset's SMT2200 with 09.3 should support modbus. Note that modbus is disabled by default, and has to be enabled in the Advanced menu from the front control panel.

All of these devices have serial ports (RJ45) in addition to USB. The white paper documents APC's implementation of modbus, along with its USB encapsulation.

Is this ticket no longer of interest to the team (given apcupsd's support for modbus and modbus-usb), or would you be interested in receiving a sample UPS?

@clepple
Copy link
Member

clepple commented Sep 23, 2018

@pjcreath thanks for the info.

Thank you for your offer of an UPS. I can't speak for the other NUT developers, but for me, time for development has been the primary issue. Most of that time has gone to other efforts like issue #300, and in the case of modbus-over-USB, it really would make sense do this after #300 is resolved to avoid code thrashing. I have an SMT unit in storage, and it probably won't even see the light of day for another few weeks.

We have also fielded some suggestions to just bolt some of the apcupsd modbus code onto NUT's driver system. While the licenses would certainly allow that, I don't see that as being much better than using the apcupsd-ups driver to talk to apcupsd. I would like to understand some of the nuances of the modbus implementation before adding direct support to NUT.

@pjcreath
Copy link

Thank you for the quick response and insight into your thinking. Yes, #300 looks more fundamental and important. And since you already have an SMT, it seems like you're all set for whenever you get around to this feature.

Bolting on the abpcupsd modbus code sounds like a wise approach, since otherwise reimplementing modbus support would just be reinventing the wheel that seems to have received actual support from APC.

To answer your question, the primary benefit of incorporating apcupsd modbus code rather than simply using the apcupsd-ups driver is for appliance and appliance-like projects (such as FreeNAS) that want to provide vendor-agnostic UPS support, and thus don't want to install and manage (and secure) an additional daemon just for APC.

Whether or not that's a reasonable position for downstream projects to take, it seems to be the current practice.

@WiredWonder
Copy link

Can nut-server and apcupsd run on the same machine when using the apcupsd-ups driver? Debian won't allow them both to install. I would really like to get the load level logged.

@clepple
Copy link
Member

clepple commented Apr 5, 2020

Can nut-server and apcupsd run on the same machine when using the apcupsd-ups driver? Debian won't allow them both to install. I would really like to get the load level logged.

@galapogos01 I don't see why they can't. NUT upsd and apcupsd listen on different ports. I guess I've always tested with NUT and apcupsd on separate machines, or with NUT installed from source. It might be worth filing a bug with Debian to remove the conflict.

That said, it wouldn't be too hard to build NUT from source, since the apcupsd-ups driver doesn't have complicated dependencies. More info in the wiki. Since that's starting to get a little far afield of the original topic of this issue, though, I'd recommend opening a separate issue here if you get stuck.

jimklimov added a commit to jimklimov/nut that referenced this issue Oct 12, 2021
@fastcat
Copy link

fastcat commented Oct 22, 2021

The package conflict on Debian actually comes from the nut-client package, because both provide /etc/init.d/ups-monitor: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=170655 -- I double checked, that's still an issue. You can't install two packages providing the same file, and since nut-server depends on nut-client, you can't install both nut & apcupsd on Debian at the same time to work around this 😞 .

@blackie333
Copy link

I'm using nut wrapper from Martin Lang and have both servers (apupsd and nut) available for clients.
Please see the details here: https://www.reddit.com/r/homelab/comments/ar0h9l/apcupsd_nut_wrapper_script_apcupsd_and_nut_on_the/
For Raspbian I have created script for starting/stoppping the wrapper as a service:
nutwrapper.txt
I works for my Synology NAS and Domoticz nut plugin just fine.

@WiredWonder
Copy link

The solution for a nut issue is to use a nut emulator :(

@blackie333
Copy link

It's just a workaround for people like me who need to solve the problem now.
Seems that proper modbus implementation could take some time.

@jimklimov
Copy link
Member

jimklimov commented Dec 7, 2021 via email

@fastcat
Copy link

fastcat commented Dec 8, 2021

The file conflict should be solvable by Debian "alternatives" mechanism to activate one of several implementations, but that needs two package sets to adapt to that.

Unfortunately, alternatives doesn't work for /etc/ files AFAIK, because those are conffiles.

Notably, haven't seen /etc/init.d/nut* anything for a decade, it's all service units now on Linux

Indeed, those files come from the debian packaging.

On closer inspection, I notice the conflicting file (/etc/init.d/ups-monitor) is just a symlink in the nut package, so it may be safe to remove it, with appropriate alerts to the admin, or post-upgrade script to deal with anyone that had enabled the system through that name instead of the "canonical" nut-client name.

I've filed a debian bug to remove that symlink, we'll see what the maintainers say.

@5ft24dave
Copy link

I would be willing to help test as well. I have an APC Back-UPS Pro 1000, Model BX1000M and it also is missing the output voltage data.
upsc C64ups@localhost
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.date: 2001/09/25
battery.mfr.date: 2019/10/11
battery.runtime: 13032
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.8
battery.voltage.nominal: 12.0
device.mfr: American Power Conversion
device.model: Back-UPS XS 1000M
device.serial: 3B1941X68111
device.type: ups
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 15
driver.parameter.port: auto
driver.parameter.productid: 0002
driver.parameter.serial: 3B1941X68111
driver.parameter.synchronous: no
driver.parameter.vendorid: 051d
driver.version: 2.7.4-4245-g36181e16
driver.version.data: APC HID 0.96
driver.version.internal: 0.44
driver.version.usb: libusb-0.1 (or compat)
input.transfer.high: 139
input.transfer.low: 88
input.voltage: 120.0
input.voltage.nominal: 120
ups.beeper.status: disabled
ups.delay.shutdown: 20
ups.delay.start: 30
ups.firmware: 945.d9 .D
ups.firmware.aux: d9
ups.load: 2
ups.mfr: American Power Conversion
ups.mfr.date: 2019/10/11
ups.model: Back-UPS XS 1000M
ups.productid: 0002
ups.realpower.nominal: 600
ups.serial: 3B1941X68111
ups.status: OL
ups.test.result: No test initiated
ups.timer.reboot: 2
ups.timer.shutdown: -1
ups.timer.start: 2
ups.vendorid: 051d

@jimklimov
Copy link
Member

When nothing else helps, RTFM ;)

Per https://networkupstools.org/docs/developer-guide.chunked/apas02.html :

  • nut/docs/nut-names.txt

    Lines 506 to 511 in 5b23cc2

    | battery.date | Battery installation or last change
    date (opaque string) | 11/14/20
    | battery.date.maintenance | Battery next change or maintenance
    date (opaque string) | 11/13/24
    | battery.mfr.date | Battery manufacturing date
    (opaque string) | 2005/04/02

The *.power reports should be "apparent power (Volt-Amps)" and for Watts there's *.realpower as "real power (Watts)".

@WiredWonder
Copy link

Thanks, seems like they are mapped to the correct nut name!

The *.power reports should be "apparent power (Volt-Amps)" and for Watts there's *.realpower as "real power (Watts)".

Currently the driver is reporting the device values directly which are a % of total available capacity. The device also reports capacity, so the value in Watts/VA could be calculated.

Current load is about 180W

ups.power: 29.04
ups.realpower: 29.40

@EchterAgo
Copy link
Contributor

EchterAgo commented Oct 3, 2023

@galapogos01 I pushed a commit that changes power/realpower to absolute numbers. Edit: Also added the nominal values.

@WiredWonder
Copy link

Great work! Looking good here.

ups.power: 218.00
ups.power.nominal: 750.00
ups.realpower: 173.86
ups.realpower.nominal: 600.00

Thank you so much again - it's great to see these very popular models finally get proper support in nut.

@PrplHaz4
Copy link

PrplHaz4 commented Oct 6, 2023

@PrplHaz4 thanks, both of those should work, it would be interesting to test the X version because it has a higher firmware version than mine (9.x)

Great work! Amazing to see this coming alive after 9yrs! 🥇

Does Modbus TCP output help at all?

Modbus TCP Debug
root@4d037edb731c:/srcnut# NUT_DEBUG_LEVEL=5 NUT_CONFPATH=/srcnut NUT_STATEPATH=/srcnut/state /srcnut/drivers/apc_modbus -F -a apcups
Network UPS Tools - NUT APC Modbus driver 0.01 (2.8.0-2602-g095bd306e)
Debug level is 0, dump data count is off, but backgrounding mode requested as off
Defaulting debug verbosity to NUT_DEBUG_LEVEL=5 since none was requested by command-line options
   0.000022     [D1] Network UPS Tools version 2.8.0-2602-g095bd306e (release/snapshot of 2.8.0.1) built with gcc (Debian 10.2.1-6) 10.2.1 20210110 and configured with flags: --with-drivers=apc_modbus --with-usb --with-modbus --with-modbus-includes=-I/build/libmodbus/include/modbus --with-modbus-libs='-L/build/libmodbus/lib -lmodbus'
   0.000055     [D1] debug level is '5'
   0.000059     [D5] send_to_all: SETINFO driver.debug "5"
   0.000075     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.000288     [D1] Succeeded to become_user(nobody): now UID=65534 GID=65534
   0.000312     [D5] send_to_all: SETINFO device.type "ups"
   0.000329     [D5] send_to_all: SETINFO driver.state "init.device"
Connecting to [192.168.4.27]:502
   0.005833     [D5] send_to_all: SETINFO driver.state "init.quiet"
   0.005876     [D5] send_to_all: SETINFO driver.version "2.8.0-2602-g095bd306e"
   0.005910     [D5] send_to_all: SETINFO driver.version.internal "0.01"
   0.005913     [D5] send_to_all: SETINFO driver.name "apc_modbus"
   0.005917     [D5] send_to_all: SETINFO driver.state "init.info"
[00][01][00][00][00][06][01][03][02][04][00][58]
Waiting for a confirmation...
<00><01><00><00><00><B3><01><03><B0><55><50><53><20><31><35><2E><30><20><20><20><20><20><20><20><20><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><53><6D><61><72><74><2D><55><50><53><20><58><20><31><35><30><30><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><53><4D><58><31><35><30><30><52><4D><32><55><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><20><41><53><31><38><33><30><31><33><37><30><31><35><20><20><20><20><41><50><43><52><42><43><31><31><35><20><20><20><20><20><20><20><53><4D><58><34><38><52><4D><42><50><32><55><20><20><20><20><20><05><A0><04><B0><00><0E><1A><7F><00><02><00><00><00><00><21><B3><75><70><73><2D><61><70><63><2D><30><32><20><20><20><20><20><20>
   0.221131     [D5] send_to_all: SETINFO ups.firmware "UPS 15.0"
   0.221150     [D5] send_to_all: SETINFO ups.model "Smart-UPS X 1500"
   0.221156     [D5] send_to_all: SETINFO ups.serial "xxxx"
   0.221164     [D5] send_to_all: SETINFO ups.power.nominal "1440.00"
   0.221170     [D5] send_to_all: SETINFO ups.realpower.nominal "1200.00"
   0.221269     [D5] send_to_all: SETINFO ups.mfr.date "2018-07-28"
   0.221320     [D5] send_to_all: SETINFO battery.date "2023-08-15"
   0.221328     [D5] send_to_all: SETINFO ups.id "ups-apc-02"
   0.221334     [D5] send_to_all: SETINFO ups.mfr "American Power Conversion"
   0.221341     [D5] send_to_all: SETINFO driver.state "init.updateinfo"
[00][02][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><02><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
   0.570370     [D5] send_to_all: SETINFO input.transfer.reason "AcceptableInput"
[00][03][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><03><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0F><00><01><0E><EC><0C><4E><00><00><0C><37><00><00><00><2E><00><00><1E><52><00><00><1E><03><00><32><57><36><00><00><00><00><00><00><00><01><1E><52><00><00><00><00><2D><60><00><00><00><00><00><00><00><00><FF><FF>
   0.931542     [D5] send_to_all: SETINFO battery.runtime "19318"
   0.931562     [D5] send_to_all: SETINFO battery.charge "100.00"
   0.931569     [D5] send_to_all: SETINFO battery.voltage "54.50"
   0.931579     [D5] send_to_all: SETINFO battery.date.maintenance "2028-01-29"
   0.931585     [D5] send_to_all: SETINFO battery.temperature "29.84"
   0.931591     [D5] send_to_all: SETINFO ups.load "12.30"
   0.931598     [D5] send_to_all: SETINFO ups.realpower "147.66"
   0.931650     [D5] send_to_all: SETINFO ups.power "175.89"
   0.931659     [D5] send_to_all: SETINFO output.current "1.44"
   0.931666     [D5] send_to_all: SETINFO output.voltage "121.28"
   0.931693     [D5] send_to_all: SETINFO output.frequency "60.02"
   0.931741     [D5] send_to_all: SETINFO experimental.output.energy "3299126"
   0.931793     [D5] send_to_all: SETINFO input.voltage "121.28"
   0.931843     [D5] send_to_all: SETINFO ups.efficiency "90.8"
   0.931890     [D5] send_to_all: SETINFO ups.timer.shutdown "0"
   0.931937     [D5] send_to_all: SETINFO ups.timer.start "0"
   0.931946     [D5] send_to_all: SETINFO ups.timer.reboot "0"
[00][04][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><04><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
   1.280720     [D5] send_to_all: SETINFO input.transfer.high "127"
   1.280735     [D5] send_to_all: SETINFO input.transfer.low "106"
   1.280742     [D5] send_to_all: SETINFO ups.delay.shutdown "0"
   1.280747     [D5] send_to_all: SETINFO ups.delay.start "0"
   1.280796     [D5] send_to_all: SETINFO ups.delay.reboot "0"
   1.280810     [D5] send_to_all: SETINFO ups.status "OL HE"
   1.280816     [D5] send_to_all: DATAOK
   1.280823     [D5] send_to_all: SETINFO driver.state "init.quiet"

Fatal error: unable to create listener socket

bind /srcnut/state/apc_modbus-apcups failed: Permission denied

   1.281207     Exiting.
   1.281234     [D5] send_to_all: SETINFO driver.state "cleanup.upsdrv"
   1.281342     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
   1.281396     upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it

@EchterAgo
Copy link
Contributor

EchterAgo commented Oct 6, 2023

@PrplHaz4 it is great to know it is working, thanks for testing! What would also be of interest is whether reconnection is handled well. Like if you remove the cable and it times out or if the UPS closes the connection (not sure how to test that).

As for your bind /srcnut/state/apc_modbus-apcups failed: Permission denied error, you probably need to adjust permissions or just set NUT_STATEPATH=/tmp which should work as well.

@PrplHaz4
Copy link

PrplHaz4 commented Oct 8, 2023

@PrplHaz4 it is great to know it is working, thanks for testing! What would also be of interest is whether reconnection is handled well. Like if you remove the cable and it times out or if the UPS closes the connection (not sure how to test that).

As for your bind /srcnut/state/apc_modbus-apcups failed: Permission denied error, you probably need to adjust permissions or just set NUT_STATEPATH=/tmp which should work as well.

Thanks for the tip on /tmp - that worked to keep it running. I put the full build in a docker container, so other things might be going on, but after some time (maybe 5 mins?) the TCP connection times out and seems to loop on error (logs below). the TCP timeout might be a valid failure mode in general. I'll work on a plug/replug USB test as well.

Modbus TCP Debug
<01><3D><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
[01][3E][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><3E><00><00><00><43><01><03><40><00><00><42><FC><C8><00><06><CC><00><00><28><0E><00><01><0F><60><0E><4A><00><00><0C><36><00><00><00><2D><00><00><1E><86><00><00><1E><03><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><80><00><00><00><00><00><00><00><00><FF><FF>
 210.065685     [D5] send_to_all: SETINFO battery.temperature "30.75"
 210.065706     [D5] send_to_all: SETINFO ups.load "14.29"
 210.065710     [D5] send_to_all: SETINFO ups.realpower "171.47"
 210.065713     [D5] send_to_all: SETINFO ups.power "175.84"
 210.065716     [D5] send_to_all: SETINFO output.current "1.41"
 210.065738     [D5] send_to_all: SETINFO output.voltage "122.09"
 210.065757     [D5] send_to_all: SETINFO output.frequency "60.02"
[01][3F][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><3F><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
 210.425786     [D5] send_to_all: SETINFO driver.state "quiet"
 211.443649     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][40][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><40><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
[01][41][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><41><00><00><00><43><01><03><40><00><00><46><EC><C8><00><06><D0><00><00><28><0E><00><01><0F><60><11><77><00><00><0C><FE><00><00><00><30><00><00><1E><86><00><00><1E><03><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><60><00><00><00><00><00><00><00><00><FF><FF>
 212.085596     [D5] send_to_all: SETINFO battery.runtime "18156"
 212.085606     [D5] send_to_all: SETINFO battery.voltage "54.50"
 212.085613     [D5] send_to_all: SETINFO ups.load "17.46"
 212.085615     [D5] send_to_all: SETINFO ups.realpower "209.58"
 212.085618     [D5] send_to_all: SETINFO ups.power "187.09"
 212.085620     [D5] send_to_all: SETINFO output.current "1.50"
 212.085625     [D5] send_to_all: SETINFO ups.efficiency "92.8"
[01][42][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
 212.586686     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
 212.586705     [D2] Communication errors: 1
 212.586713     [D5] send_to_all: DATASTALE
 212.586762     [D5] send_to_all: SETINFO driver.state "quiet"
 213.444582     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][43][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><42><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x142 (not 0x143)
 213.444702     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][44][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><43><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x143 (not 0x144)
 213.814720     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][45][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><44><00><00><00><43><01><03><40><00><00><3F><44><C8><00><06><CC><00><00><28><0E><00><01><0F><60><10><AC><00><00><0B><9C><00><00><00><2B><00><00><1E><86><00><00><1E><03><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><60><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x144 (not 0x145)
 214.120354     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 214.120394     [D2] Communication errors: 3
 214.120400     [D5] send_to_all: SETINFO driver.state "quiet"
 215.446092     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][46][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><45><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x145 (not 0x146)
 215.446255     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][47][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><46><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x146 (not 0x147)
 215.764975     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][48][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><47><00><00><00><43><01><03><40><00><00><42><FC><C8><00><06><CC><00><00><28><0E><00><01><0F><5D><0E><4A><00><00><0C><D3><00><00><00><2F><00><00><1E><8C><00><00><1E><03><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><60><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x147 (not 0x148)
 216.075836     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 216.075858     [D2] Communication errors: 3
 216.075865     [D5] send_to_all: SETINFO driver.state "quiet"
 217.447582     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][49][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><48><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x148 (not 0x149)
 217.447894     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][4A][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><49><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x149 (not 0x14A)
 217.705309     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][4B][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><4A><00><00><00><43><01><03><40><00><00><3F><44><C8><00><06><CC><00><00><28><0E><00><01><0F><60><0E><B0><00><00><0C><A4><00><00><00><2F><00><00><1E><86><00><00><1E><03><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><80><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x14A (not 0x14B)
 218.046276     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 218.046328     [D2] Communication errors: 3
 218.046346     [D5] send_to_all: SETINFO driver.state "quiet"
 219.449228     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][4C][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><4B><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x14B (not 0x14C)
 219.449407     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][4D][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><4C><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x14C (not 0x14D)
 219.755749     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][4E][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><4D><00><00><00><43><01><03><40><00><00><42><FC><C8><00><06><CC><00><00><28><0E><00><01><0F><60><0B><83><00><00><0B><04><00><00><00><28><00><00><1E><86><00><00><1E><02><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><86><00><00><00><00><2E><60><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x14D (not 0x14E)
 220.066876     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 220.066908     [D2] Communication errors: 3
 220.066939     [D5] send_to_all: SETINFO driver.state "quiet"
 221.450720     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][4F][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><4E><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x14E (not 0x14F)
 221.450989     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][50][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><4F><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x14F (not 0x150)
 221.736264     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][51][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><50><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><CC><00><00><28><0E><00><01><0F><5D><0B><1D><00><00><0A><C1><00><00><00><28><00><00><1E><8C><00><00><1E><02><00><32><6F><5F><00><00><00><00><00><00><00><01><1E><8C><00><00><00><00><2E><20><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x150 (not 0x151)
 222.107774     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 222.107781     [D2] Communication errors: 3
 222.107788     [D5] send_to_all: SETINFO driver.state "quiet"
 223.452348     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][52][00][00][00][06][01][03][00][00][00][1B]

@EchterAgo
Copy link
Contributor

Invalid transaction ID received 0x142 (not 0x143)

This indicates that it is getting a response to a previous command. There likely needs to be a buffer flush somewhere. I just pushed a commit for testing that does buffer flushing on reconnect and open.

@EetuRasilainen
Copy link

Do I need the patched libmodbus if I am using ModBus over a serial link (with APC AP940-0625A cable)? As far as I understand the patched libmodbus is only required for Modbus-over-USB.

Right now I am querying my SMT1500 using a custom Python script and pymodbus through this serial cable but I'd prefer to use NUT for this.

@EchterAgo
Copy link
Contributor

@EetuRasilainen you don't need a patched libmodbus for serial.

@PrplHaz4
Copy link

PrplHaz4 commented Oct 8, 2023

Invalid transaction ID received 0x142 (not 0x143)

This indicates that it is getting a response to a previous command. There likely needs to be a buffer flush somewhere. I just pushed a commit for testing that does buffer flushing on reconnect and open.

Thanks again! Still seeing these on 10071db after about 5 mins.

Modbus TCP Debug
Waiting for a confirmation...
<01><C2><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><9D><12><A8><00><00><0D><F0><00><00><00><34><00><00><1E><58><00><00><1E><02><00><32><78><58><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
 298.235534     [D5] send_to_all: SETINFO battery.voltage "54.50"
 298.235547     [D5] send_to_all: SETINFO battery.temperature "29.23"
 298.235566     [D5] send_to_all: SETINFO ups.load "18.66"
 298.235570     [D5] send_to_all: SETINFO ups.realpower "223.88"
 298.235587     [D5] send_to_all: SETINFO ups.power "200.70"
 298.235590     [D5] send_to_all: SETINFO output.current "1.62"
 298.235593     [D5] send_to_all: SETINFO output.voltage "121.38"
 298.235597     [D5] send_to_all: SETINFO input.voltage "121.38"
[01][C3][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><C3><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
 298.584090     [D5] send_to_all: SETINFO driver.state "quiet"
 299.593432     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][C4][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><C4><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
[01][C5][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
ERROR Connection timed out: select
 300.394893     _apc_modbus_read_registers: Read of 128:160 failed: Connection timed out (192.168.4.27:502)
[01][C6][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><C5><00><00><00><43><01><03><40><00><00><46><EC><C8><00><06><D0><00><00><28><0E><00><01><0E><A3><0D><19><00><00><0B><07><00><00><00><29><00><00><1E><58><00><00><1E><03><00><32><78><58><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><20><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x1C5 (not 0x1C6)
 300.398689     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 300.398709     [D2] Communication errors: 2
 300.398724     [D5] send_to_all: DATASTALE
 300.398730     [D5] send_to_all: SETINFO driver.state "quiet"
 301.594838     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][C7][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><C6><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x1C6 (not 0x1C7)
 301.595072     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][C8][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><C7><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x1C7 (not 0x1C8)
 301.872993     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][C9][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><C8><00><00><00><43><01><03><40><00><00><46><EC><C8><00><06><D0><00><00><28><0E><00><01><0E><9D><0B><1D><00><00><0B><33><00><00><00><29><00><00><1E><58><00><00><1E><03><00><32><78><58><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><20><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x1C8 (not 0x1C9)
 302.284140     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 302.284159     [D2] Communication errors: 3
 302.284173     [D5] send_to_all: SETINFO driver.state "quiet"
 303.596205     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][CA][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><C9><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x1C9 (not 0x1CA)
 303.596408     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][CB][00][00][00][06][01][03][00][80][00][20]

@EchterAgo
Copy link
Contributor

EchterAgo commented Oct 8, 2023

Still looks like it receives a response packet that was expected for the previous command.

Could you maybe do a Wireshark / tcpdump packet capture on the Modbus port or the UPS IP address and send it to me privately (derago at gmail.com)? For tcpdump you can do tcpdump -s 1500 -w modbus.cap port 502, I need the modbus.cap this creates.

I asked APC/SE to send me a NMC to test this but so far they only replied telling me where to buy one, and I'm not going to spend multiple hundred bucks on that :\

Maybe I should try to make a RS232 to TCP Modbus converter on a Raspberry Pi Pico.

@EchterAgo
Copy link
Contributor

EchterAgo commented Oct 8, 2023

There is also something very similar here: stephane/libmodbus#525, stephane/libmodbus#255

@EchterAgo
Copy link
Contributor

Also, the serial backend of libmodbus handles such timeouts just fine, but I'll try some more to see if i can produce such a problem.

@EchterAgo
Copy link
Contributor

@PrplHaz4 I made another change, give it a try. I haven't actually tested this yet because I am currently changing the USB modbus driver, but I think it might work.

@PrplHaz4
Copy link

PrplHaz4 commented Oct 9, 2023

@PrplHaz4 I made another change, give it a try. I haven't actually tested this yet because I am currently changing the USB modbus driver, but I think it might work.

First look the additional flush seems to be allowing it to re-connect after timeout and resume displaying values (quickly) after that - so definitely a win there. There definitely seems to be a lot of noise in the output right now - I will get some better data tonight. I know nothing about modbus - is there a really short timeout expected between messages (due to it being more of a stream than a poll) or something like that?

@EchterAgo
Copy link
Contributor

Great. What kind of noise do you mean? I also don't know much about modbus, but the need for a delay between frames seems to be because modbus frames do not really have a uniquely identifiable start condition / preamble, so there is a need to wait a certain time to make sure there is not a message currently transferring. I got this from the APC manual and initially I sometimes hit this delay, but in the current version at least on my computer it wasn't hit.

@PrplHaz4
Copy link

PrplHaz4 commented Oct 9, 2023

Great. What kind of noise do you mean? I also don't know much about modbus, but the need for a delay between frames seems to be because modbus frames do not really have a uniquely identifiable start condition / preamble, so there is a need to wait a certain time to make sure there is not a message currently transferring. I got this from the APC manual and initially I sometimes hit this delay, but in the current version at least on my computer it wasn't hit.

Here is my capture from the train this morning (with a very spotty network connection - so the noise may be related to that). You can see a lot of connection timed out, invalid data and read failed...etc.

TCP Modbus debug
[00][4C][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><4C><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  48.899789     [D5] send_to_all: SETINFO driver.state "quiet"
  49.762261     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][4D][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  50.262996     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][4E][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><4D><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x4D (not 0x4E)
  50.605959     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][4F][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><4E><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0D><7F><00><00><0B><8B><00><00><00><2B><00><00><1E><58><00><00><1E><02><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><A0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x4E (not 0x4F)
  50.968749     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
  50.968776     [D2] Communication errors: 3
  50.968783     [D5] send_to_all: DATASTALE
  50.968789     [D5] send_to_all: SETINFO driver.state "quiet"
  51.763295     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (23)
[00][50][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><50><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][51][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><51><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><09><EC><00><00><09><EB><00><00><00><24><00><00><1E><58><00><00><1E><01><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><E0><00><00><00><00><00><00><00><00><FF><FF>
  52.599061     [D5] send_to_all: SETINFO battery.runtime "19318"
  52.599085     [D5] send_to_all: SETINFO battery.temperature "29.45"
  52.599091     [D5] send_to_all: SETINFO ups.load "9.92"
  52.599098     [D5] send_to_all: SETINFO ups.realpower "119.06"
  52.599104     [D5] send_to_all: SETINFO output.current "1.12"
  52.599111     [D5] send_to_all: SETINFO experimental.output.energy "3309949"
  52.599117     [D5] send_to_all: SETINFO ups.efficiency "91.8"
Bytes flushed (0)
[00][52][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><52><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  52.925893     [D5] send_to_all: DATAOK
  52.925905     [D5] send_to_all: SETINFO driver.state "quiet"
  53.764182     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][53][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><53><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][54][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><54><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0B><E8><00><00><0B><8B><00><00><00><2A><00><00><1E><52><00><00><1E><01><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
  54.539965     [D5] send_to_all: SETINFO battery.runtime "20561"
  54.539978     [D5] send_to_all: SETINFO ups.load "11.91"
  54.539980     [D5] send_to_all: SETINFO ups.realpower "142.88"
  54.539981     [D5] send_to_all: SETINFO ups.power "166.22"
  54.539983     [D5] send_to_all: SETINFO output.current "1.31"
  54.539985     [D5] send_to_all: SETINFO output.voltage "121.28"
  54.539987     [D5] send_to_all: SETINFO ups.efficiency "91.5"
Bytes flushed (0)
[00][55][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><55><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  54.898282     [D5] send_to_all: SETINFO driver.state "quiet"
  55.765124     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][56][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><56><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][57][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><57><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><09><EC><00><00><09><3C><00><00><00><23><00><00><1E><58><00><00><1E><01><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><A0><00><00><00><00><00><00><00><00><FF><FF>
  56.467346     [D5] send_to_all: SETINFO ups.load "9.92"
  56.467351     [D5] send_to_all: SETINFO ups.realpower "119.06"
  56.467353     [D5] send_to_all: SETINFO ups.power "132.97"
  56.467355     [D5] send_to_all: SETINFO output.current "1.09"
  56.467358     [D5] send_to_all: SETINFO output.voltage "121.38"
  56.467361     [D5] send_to_all: SETINFO ups.efficiency "91.2"
Bytes flushed (0)
[00][58][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
  56.968041     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
  56.968052     [D2] Communication errors: 1
  56.968056     [D5] send_to_all: DATASTALE
  56.968062     [D5] send_to_all: SETINFO driver.state "quiet"
  57.766267     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (23)
[00][59][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  58.267152     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][5A][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
ERROR Connection timed out: select
  58.767976     _apc_modbus_read_registers: Read of 128:160 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][5B][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
  59.268831     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
  59.268840     [D2] Communication errors: 3
  59.268847     [D5] send_to_all: SETINFO driver.state "quiet"
  59.766884     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][5C][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  60.267831     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][5D][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><59><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x59 (not 0x5D)
  60.548844     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][5E][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><5A><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0A><52><00><00><09><D5><00><00><00><24><00><00><1E><58><00><00><1E><01><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><60><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x5A (not 0x5E)
  60.907371     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
  60.907420     [D2] Communication errors: 3
  60.907441     [D5] send_to_all: SETINFO driver.state "quiet"
  61.768001     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (86)
[00][5F][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><5D><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><07><8A><00><00><0A><2D><00><00><00><26><00><00><1E><58><00><00><1E><02><00><32><81><7D><00><00><00><00><00><00><00><01><1E><52><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x5D (not 0x5F)
  61.995069     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][60][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><5E><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x5E (not 0x60)
  62.314687     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][61][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><5F><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x5F (not 0x61)
  62.706382     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
  62.706391     [D2] Communication errors: 3
  62.706399     [D5] send_to_all: SETINFO driver.state "quiet"
  63.769132     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (96)
[00][62][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><62><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][63][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><63><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0A><52><00><00><09><D7><00><00><00><25><00><00><1E><58><00><00><1E><02><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><20><00><00><00><00><00><00><00><00><FF><FF>
  64.497819     [D5] send_to_all: SETINFO ups.load "10.32"
  64.497826     [D5] send_to_all: SETINFO ups.realpower "123.84"
  64.497829     [D5] send_to_all: SETINFO ups.power "141.69"
  64.497833     [D5] send_to_all: SETINFO output.current "1.16"
  64.497837     [D5] send_to_all: SETINFO output.frequency "60.02"
  64.497867     [D5] send_to_all: SETINFO ups.efficiency "90.2"
Bytes flushed (0)
[00][64][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><64><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  64.858010     [D5] send_to_all: DATAOK
  64.858025     [D5] send_to_all: SETINFO driver.state "quiet"
  65.770154     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][65][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><65><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][66][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><66><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BD><0D><19><00><00><0B><49><00><00><00><29><00><00><1E><58><00><00><1E><02><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><00><00><00><00><00><00><00><00><00><FF><FF>
  66.483937     [D5] send_to_all: SETINFO battery.temperature "29.48"
  66.483955     [D5] send_to_all: SETINFO ups.load "13.10"
  66.483978     [D5] send_to_all: SETINFO ups.realpower "157.17"
  66.483995     [D5] send_to_all: SETINFO ups.power "162.51"
  66.483998     [D5] send_to_all: SETINFO output.current "1.28"
  66.484028     [D5] send_to_all: SETINFO ups.efficiency "90.0"
Bytes flushed (0)
[00][67][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><67><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  66.881418     [D5] send_to_all: SETINFO driver.state "quiet"
  67.771179     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][68][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><68><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][69][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><69><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><CC><00><00><28><0E><00><01><0E><BA><09><21><00><00><0A><84><00><00><00><27><00><00><1E><58><00><00><1E><03><00><32><81><7D><00><00><00><00><00><00><00><01><1E><52><00><00><00><00><2D><E0><00><00><00><00><00><00><00><00><FF><FF>
  68.487695     [D5] send_to_all: SETINFO battery.runtime "19318"
  68.487706     [D5] send_to_all: SETINFO battery.voltage "54.38"
  68.487712     [D5] send_to_all: SETINFO battery.temperature "29.45"
  68.487715     [D5] send_to_all: SETINFO ups.load "9.13"
  68.487718     [D5] send_to_all: SETINFO ups.realpower "109.55"
  68.487720     [D5] send_to_all: SETINFO ups.power "151.43"
  68.487722     [D5] send_to_all: SETINFO output.current "1.22"
  68.487726     [D5] send_to_all: SETINFO input.voltage "121.28"
  68.487748     [D5] send_to_all: SETINFO ups.efficiency "91.8"
Bytes flushed (0)
[00][6A][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><6A><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  68.856396     [D5] send_to_all: SETINFO driver.state "quiet"
  69.772334     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][6B][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><6B><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][6C][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><6C><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0C><B4><00><00><0A><AF><00><00><00><28><00><00><1E><58><00><00><1E><03><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><00><00><00><00><00><00><00><00><00><FF><FF>
  70.512879     [D5] send_to_all: SETINFO battery.voltage "54.50"
  70.512893     [D5] send_to_all: SETINFO ups.load "12.70"
  70.512898     [D5] send_to_all: SETINFO ups.realpower "152.44"
  70.512901     [D5] send_to_all: SETINFO ups.power "153.84"
  70.512906     [D5] send_to_all: SETINFO output.current "1.25"
  70.512912     [D5] send_to_all: SETINFO input.voltage "121.38"
  70.512916     [D5] send_to_all: SETINFO ups.efficiency "92.0"
Bytes flushed (0)
[00][6D][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><6D><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  70.886514     [D5] send_to_all: SETINFO driver.state "quiet"
  71.773422     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][6E][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><6E><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][6F][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><6F><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BD><0B><1D><00><00><0A><9A><00><00><00><27><00><00><1E><58><00><00><1E><03><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><00><00><00><00><00><00><00><00><00><FF><FF>
  72.469295     [D5] send_to_all: SETINFO battery.temperature "29.48"
  72.469344     [D5] send_to_all: SETINFO ups.load "11.11"
  72.469379     [D5] send_to_all: SETINFO ups.realpower "133.36"
  72.469386     [D5] send_to_all: SETINFO ups.power "152.66"
  72.469421     [D5] send_to_all: SETINFO output.current "1.22"
Bytes flushed (0)
[00][70][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><70><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  72.840208     [D5] send_to_all: SETINFO driver.state "quiet"
  73.774456     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][71][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><71><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][72][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><72><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><08><56><00><00><09><0F><00><00><00><21><00><00><1E><58><00><00><1E><03><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><00><00><00><00><00><00><00><00><00><FF><FF>
  74.517843     [D5] send_to_all: SETINFO battery.temperature "29.45"
  74.517848     [D5] send_to_all: SETINFO ups.load "8.34"
  74.517850     [D5] send_to_all: SETINFO ups.realpower "100.03"
  74.517852     [D5] send_to_all: SETINFO ups.power "130.44"
  74.517853     [D5] send_to_all: SETINFO output.current "1.03"
Bytes flushed (0)
[00][73][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><73><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  74.846298     [D5] send_to_all: SETINFO driver.state "quiet"
  75.775479     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][74][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><74><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][75][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><75><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0B><1D><00><00><09><A9><00><00><00><24><00><00><1E><58><00><00><1E><03><00><32><81><7D><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
  76.430593     [D5] send_to_all: SETINFO battery.runtime "20561"
  76.430607     [D5] send_to_all: SETINFO ups.load "11.11"
  76.430610     [D5] send_to_all: SETINFO ups.realpower "133.36"
  76.430612     [D5] send_to_all: SETINFO ups.power "139.11"
  76.430614     [D5] send_to_all: SETINFO output.current "1.12"
  76.430618     [D5] send_to_all: SETINFO ups.efficiency "91.5"
Bytes flushed (0)
[00][76][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><76><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  76.778824     [D5] send_to_all: SETINFO driver.state "quiet"
  77.775595     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][77][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><77><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][78][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><78><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0A><52><00><00><0A><58><00><00><00><27><00><00><1E><58><00><00><1E><03><00><32><81><7E><00><00><00><00><00><00><00><01><1E><52><00><00><00><00><2D><80><00><00><00><00><00><00><00><00><FF><FF>
  78.494102     [D5] send_to_all: SETINFO ups.load "10.32"
  78.494109     [D5] send_to_all: SETINFO ups.realpower "123.84"
  78.494112     [D5] send_to_all: SETINFO ups.power "148.95"
  78.494114     [D5] send_to_all: SETINFO output.current "1.22"
  78.494118     [D5] send_to_all: SETINFO experimental.output.energy "3309950"
  78.494122     [D5] send_to_all: SETINFO input.voltage "121.28"
  78.494124     [D5] send_to_all: SETINFO ups.efficiency "91.0"
Bytes flushed (0)
[00][79][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><79><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  78.863784     [D5] send_to_all: SETINFO driver.state "quiet"
  79.776654     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][7A][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  80.277608     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][7B][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
ERROR Connection timed out: select
  80.778417     _apc_modbus_read_registers: Read of 128:160 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][7C][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
  81.279267     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
  81.279304     [D2] Communication errors: 3
  81.279314     [D5] send_to_all: DATASTALE
  81.279322     [D5] send_to_all: SETINFO driver.state "quiet"
  81.777271     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (63)
[00][7D][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  82.278314     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][7E][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><7B><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><09><21><00><00><0A><16><00><00><00><25><00><00><1E><58><00><00><1E><03><00><32><81><7E><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2D><E0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x7B (not 0x7E)
  82.457998     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][7F][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
  82.958804     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
  82.958811     [D2] Communication errors: 3
  82.958818     [D5] send_to_all: SETINFO driver.state "quiet"
  83.778261     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (23)
[00][80][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  84.279311     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][81][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
ERROR Connection timed out: select
  84.780036     _apc_modbus_read_registers: Read of 128:160 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][82][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><7D><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x7D (not 0x82)
  85.182335     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
  85.182342     [D2] Communication errors: 3
  85.182348     [D5] send_to_all: SETINFO driver.state "quiet"
  85.778917     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (255)
[00][83][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
ERROR Connection timed out: select
  86.279973     _apc_modbus_read_registers: Read of 0:27 failed: Connection timed out (192.168.4.27:502)
Bytes flushed (0)
[00][84][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><83><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x83 (not 0x84)
  86.361890     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
Bytes flushed (0)
[00][85][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><84><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><B7><0B><E8><00><00><09><67><00><00><00><23><00><00><1E><58><00><00><1E><02><00><32><81><7E><00><00><00><00><00><00><00><01><1E><58><00><00><00><00><2E><00><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x84 (not 0x85)
  86.639099     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
  86.639122     [D2] Communication errors: 3
  86.639152     [D5] send_to_all: SETINFO driver.state "quiet"
  87.779301     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (23)
[00][86][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><86><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][87][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><87><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0E><00><01><0E><BA><0C><B4><00><00><0C><0B><00><00><00><2C><00><00><1E><52><00><00><1E><02><00><32><81><7E><00><00><00><00><00><00><00><01><1E><52><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
  88.547960     [D5] send_to_all: SETINFO ups.load "12.70"
  88.547967     [D5] send_to_all: SETINFO ups.realpower "152.44"
  88.547983     [D5] send_to_all: SETINFO ups.power "173.42"
  88.547987     [D5] send_to_all: SETINFO output.current "1.38"
  88.548008     [D5] send_to_all: SETINFO output.voltage "121.28"
  88.548026     [D5] send_to_all: SETINFO ups.efficiency "91.5"
Bytes flushed (0)
[00][88][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<00><88><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
  88.913095     [D5] send_to_all: DATAOK
  88.913103     [D5] send_to_all: SETINFO driver.state "quiet"
  89.780424     [D5] send_to_all: SETINFO driver.state "updateinfo"
Bytes flushed (0)
[00][89][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<00><89><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Bytes flushed (0)
[00][8A][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<00><8A><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0E><00><01><0E><B7><0F><15><00><00><0B><E0><00><00><00><2C><00><00><1E><4C><00><00><1E><02><00><32><81><7E><00><00><00><00><00><00><00><01><1E><4C><00><00><00><00><2D><A0><00><00><00><00><00><00><00><00><FF><FF>
  90.499480     [D5] send_to_all: SETINFO battery.runtime "19318"
  90.499496     [D5] send_to_all: SETINFO battery.temperature "29.43"
  90.499499     [D5] send_to_all: SETINFO ups.load "15.08"
  90.499502     [D5] send_to_all: SETINFO ups.realpower "180.98"
  90.499505     [D5] send_to_all: SETINFO ups.power "171.00"
  90.499508     [D5] send_to_all: SETINFO output.voltage "121.19"
  90.499512     [D5] send_to_all: SETINFO input.voltage "121.19"
  90.499533     [D5] send_to_all: SETINFO ups.efficiency "91.2"
Bytes flushed (0)

@EchterAgo
Copy link
Contributor

Oh, you did the capture through the spotty network? That does look like what I would expect there.

I wonder if we actually need a higher timeout somewhere, it seems your connection is disconnecting when sending a command and already reconnecting before the response is received, then the response comes, sits in a buffer and gets received (now flushed) when sending the next command.

I'll have to read the modbus TCP code for this some more.

@EchterAgo
Copy link
Contributor

I'm also not sure if this is an issue with the APC firmware or libmodbus, but I don't think it is actually a problem in nut. We could also try just waiting some time after a reconnect, before flusing.

@EchterAgo
Copy link
Contributor

@PrplHaz4 I pushed another commit that removes the flushing before register reads, but instead adds a 1 second delay between connecting and buffer flush. If this works we should try finding a good value for the delay because 1 second is just arbitrarily chosen by me.

@PrplHaz4
Copy link

@PrplHaz4 I pushed another commit that removes the flushing before register reads, but instead adds a 1 second delay between connecting and buffer flush. If this works we should try finding a good value for the delay because 1 second is just arbitrarily chosen by me.

Yes, the capture above was on a spotty network. This capture is from a stable network. It looks like the failures start 184s into the run, and continues until at least 321s without "recovering". The previous capture from the spotty network appears to have recovered after some time, and went in and out of being able to pull full values.

I'm not sure how to help on the timing of the flush - I'm sure it doesn't help providing data from two drastically different networking environments.

TCP Modbus Debug - Stable Network
[01][17][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><17><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0D><00><01><0E><B7><0D><7F><00><00><0A><22><00><00><00><26><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
 184.039766     [D5] send_to_all: SETINFO battery.temperature "29.43"
 184.039771     [D5] send_to_all: SETINFO ups.load "13.50"
 184.039774     [D5] send_to_all: SETINFO ups.realpower "161.95"
 184.039776     [D5] send_to_all: SETINFO ups.power "145.91"
 184.039778     [D5] send_to_all: SETINFO output.current "1.19"
[01][18][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
ERROR Connection timed out: select
 184.540478     _apc_modbus_read_registers: Read of 1026:1033 failed: Connection timed out (192.168.4.27:502)
 184.540522     [D2] Communication errors: 1
 184.540528     [D5] send_to_all: DATASTALE
 184.540553     [D5] send_to_all: SETINFO driver.state "quiet"
 185.421617     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][19][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><18><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x118 (not 0x119)
 185.421733     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][1A][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><19><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x119 (not 0x11A)
 185.699003     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][1B][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><1A><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0D><00><01><0E><B4><08><56><00><00><09><34><00><00><00><22><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><A0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x11A (not 0x11B)
 186.061582     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 186.061650     [D2] Communication errors: 3
 186.061675     [D5] send_to_all: SETINFO driver.state "quiet"
 187.423270     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][1C][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><1B><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x11B (not 0x11C)
 187.423692     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][1D][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><1C><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x11C (not 0x11D)
 187.719371     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][1E][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><1D><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0D><00><01><0E><B4><0B><83><00><00><09><89><00><00><00><23><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><80><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x11D (not 0x11E)
 188.080830     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 188.080857     [D2] Communication errors: 3
 188.080878     [D5] send_to_all: SETINFO driver.state "quiet"
 189.424990     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][1F][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><1E><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x11E (not 0x11F)
 189.425302     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][20][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><1F><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x11F (not 0x120)
 189.689561     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][21][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><20><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><CC><00><00><28><0D><00><01><0E><B4><0B><83><00><00><09><B4><00><00><00><25><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><60><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x120 (not 0x121)
 190.059699     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 190.059713     [D2] Communication errors: 3
 190.059725     [D5] send_to_all: SETINFO driver.state "quiet"
 191.425468     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][22][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><21><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x121 (not 0x122)
 191.425803     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][23][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><22><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x122 (not 0x123)
 191.730711     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][24][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><23><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0D><00><01><0E><B7><0D><19><00><00><0A><79><00><00><00><27><00><00><1E><32><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><80><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x123 (not 0x124)
 192.145261     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 192.145275     [D2] Communication errors: 3
 192.145288     [D5] send_to_all: SETINFO driver.state "quiet"
 193.426943     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][25][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><24><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x124 (not 0x125)
 193.427156     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][26][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><25><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x125 (not 0x126)
 193.730254     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][27][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><26><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0D><00><01><0E><B7><0D><19><00><00><09><F6><00><00><00><25><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x126 (not 0x127)
 194.092448     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 194.092465     [D2] Communication errors: 3
 194.092479     [D5] send_to_all: SETINFO driver.state "quiet"
 195.428342     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][28][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><27><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x127 (not 0x128)
 195.428484     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][29][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><28><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x128 (not 0x129)
 195.699697     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][2A][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><29><00><00><00><43><01><03><40><00><00><50><51><C8><00><06><D0><00><00><28><0D><00><01><0E><B7><0C><B4><00><00><0B><7F><00><00><00><2B><00><00><1E><32><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><32><00><00><00><00><2D><A0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x129 (not 0x12A)
 196.060127     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 196.060139     [D2] Communication errors: 3
 196.060179     [D5] send_to_all: SETINFO driver.state "quiet"
 197.429938     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][2B][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><2A><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x12A (not 0x12B)
 197.430144     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][2C][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><2B><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x12B (not 0x12C)
 197.771843     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][2D][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><2C><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0D><00><01><0E><B4><08><BB><00><00><0A><79><00><00><00><27><00><00><1E><38><00><00><1E><01><00><32><88><1C><00><00><00><00><00><00><00><01><1E><38><00><00><00><00><2D><C0><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x12C (not 0x12D)
 198.181509     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 198.181525     [D2] Communication errors: 3
 198.181540     [D5] send_to_all: SETINFO driver.state "quiet"
 199.431254     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][2E][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><2D><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x12D (not 0x12E)
 199.431427     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][2F][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><2E><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x12E (not 0x12F)
 199.717634     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][30][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...
<01><2F><00><00><00><43><01><03><40><00><00><4B><76><C8><00><06><D0><00><00><28><0D><00><01><0E><B7><10><AC><00><00><0B><53><00><00><00><2A><00><00><1E><32><00><00><1E><01><00><32><88><1D><00><00><00><00><00><00><00><01><1E><32><00><00><00><00><2E><00><00><00><00><00><00><00><00><00><FF><FF>
Invalid transaction ID received 0x12F (not 0x130)
 200.060486     _apc_modbus_read_registers: Read of 1026:1033 failed: Invalid data (192.168.4.27:502)
 200.060502     [D2] Communication errors: 3
 200.060517     [D5] send_to_all: SETINFO driver.state "quiet"
 201.433035     [D5] send_to_all: SETINFO driver.state "updateinfo"
[01][31][00][00][00][06][01][03][00][00][00][1B]
Waiting for a confirmation...
<01><30><00><00><00><11><01><03><0E><00><7F><00><6A><00><01><00><00><00><00><00><00><00><00>
Invalid transaction ID received 0x130 (not 0x131)
 201.433405     _apc_modbus_read_registers: Read of 0:27 failed: Invalid data (192.168.4.27:502)
[01][32][00][00][00][06][01][03][00][80][00][20]
Waiting for a confirmation...
<01><31><00><00><00><39><01><03><36><00><00><20><02><00><08><00><00><00><00><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><01><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><44><00><48><00><01><00><00>
Invalid transaction ID received 0x131 (not 0x132)
 201.711195     _apc_modbus_read_registers: Read of 128:160 failed: Invalid data (192.168.4.27:502)
[01][33][00][00][00][06][01][03][04][02][00][07]
Waiting for a confirmation...

@EchterAgo
Copy link
Contributor

Thanks for testing this. Could you maybe privately (or publicly if you want) share a packet capture from Wireshark or tcpdump on port 502?

With Wireshark you can put a capture filter somewhere, just use port 502, start capturing, reproduce the problem and save the capture file.

With tcpdump you can use something like tcpdump -i <interface> -s 1500 -w apc.cap port 502 and send me the apc.cap.

@p8218
Copy link

p8218 commented Oct 11, 2023

Hi, Good to see this work. If it helps, I just wanted to add that I found an APC SMT2200RMI2UC made in July 2019 didn't work with apcupsd 3.14.14 running on Windows Server 2016 via modbus over USB. modbus over serial was OK. With USB, it looked like an ordering error (responses out of order). apcupsd on Windows (2008 R2) was OK with modbus over USB with a SmartUPS 1500 LCD SMT1500I (vendor id 051d, product id 0003) made in 2015. Not with linux though, where it gave immediate errors. Also I note the new(ish) range of APC Smart-UPS's with Lithium batteries only support modbus over serial, not USB, at least in the brochures. So I wonder if working modbus over USB is restricted to older APC Smart UPS models ? Thanks.

@EchterAgo
Copy link
Contributor

Hi, Good to see this work. If it helps, I just wanted to add that I found an APC SMT2200RMI2UC made in July 2019 didn't work with apcupsd 3.14.14 running on Windows Server 2016 via modbus over USB. modbus over serial was OK. With USB, it looked like an ordering error (responses out of order). apcupsd on Windows (2008 R2) was OK with modbus over USB with a SmartUPS 1500 LCD SMT1500I (vendor id 051d, product id 0003) made in 2015. Not with linux though, where it gave immediate errors. Also I note the new(ish) range of APC Smart-UPS's with Lithium batteries only support modbus over serial, not USB, at least in the brochures. So I wonder if working modbus over USB is restricted to older APC Smart UPS models ? Thanks.

I haven't really had experience with newer APC units, mine is from 2015. If it works with on one OS and not on the other the issue must be software.

It would be nice if you could try the code I posted in #2063, maybe we can diagnose what is going on. The implementation of this is not based on apcupsd so it might even work, in which case the bug is in apcupsd.

@EchterAgo
Copy link
Contributor

@PrplHaz4 I think I know what the issue with TCP is and how to fix it, but I continued the discussion in #2063.

jimklimov added a commit to jimklimov/nut that referenced this issue Oct 18, 2023
jimklimov added a commit to jimklimov/nut that referenced this issue Oct 18, 2023
…ndencies for apc_modbus [networkupstools#139, networkupstools#2063]

Signed-off-by: Jim Klimov <jimklimov+nut@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.