[Nut-upsdev] Suspend-to-disk & NUT

[Arjen de Korte]

>> I made good progress today. The problem is not in the (SafeNet) driver,
> Have you tried this with other drivers? How about with the dummy driver?

Not now, since I really do not have that much free time on my hands at the
moment.

[...]

> I don't see anything wrong with the log, though... if you pulled the
> cable at 21:03:00, and the driver was still reporting failed comms
> until 21:03:13,

This is where you misinterpret the log. The driver (safenet) was not
reporting failed communications (and consequently, declared data stale)
until 21:03:07 when it logged this for the first time ("safenet[27012]:
Communications with UPS lost: Status read failed").

> then upsd and upsmon were doing the right thing, given
> the data provided by the driver.

No, they were not. The driver was communicating with the UPS. Otherwise
there would be messages that serial communication was lost before
21:03:00. Unplugging the serial cable from the UPS proves this, since
(after the build in grace period in the driver) it reported immediately
that the communication was lost and restored when the cable was plugged in
again. Which means that before yanking the serial cable, communication
must have been OK. In case of the SafeNet driver this means that the data
should not have been stale (since both ser_comm_good() and 
dstate_dataok() are called right after one another). The driver will not
call dstate_datastale() without a call to ser_comm_fail(), so if the
driver would have set this flag, this should be visible in the logs.

> In the course of debugging, you may want to do a hex dump of the bytes
> that trigger the ser_comm_fail() in safenet_command().

The point is, ser_comm_fail() is not triggered. I double checked by
replacing the upsdebugx() calls with upslogx() calls (unfortunately,
passing debuglevels to the drivers has been broken from the moment they
are started by upsdrvctrl). In fact, I added more logging to make sure
that dstate_dataok() is called (time permitting, I will post a log later
today to show this). Throughout the whole procedure, it is called each
time the UPS is polled. The problem is, either upsd or upsmon are not
aware of this, until I force a state change by either cycling the mains to
the UPS or pulling the serial cable and plug it in again. To me, this
proves that something in the chain driver-upsd-upsmon is missing a state
change. Since the SafeNet driver is stateless (short of the grace period
for failed communications), the problem must be somewhere in the other
two.

Regards,
Arjen