Nut upsuser - Oct 2013 - Shutdown problem with Mecer 1000VA Online UPS

Hi,

There seems to be a problem turning of the inverter on a Mecer online 1000VA 
UPS.

OS:  Debian Wheezy
Nut: Installed via apt - version 2.6.4-2.3

Debug output from driver.

root at proxmox1:~# /lib/nut/blazer_usb -DDDDD -a mecer -k
Network UPS Tools - Megatec/Q1 protocol USB driver 0.08 (2.6.4)
    0.000000     send_to_all: SETINFO driver.parameter.port "auto"
    0.000023     send_to_all: SETINFO driver.parameter.vendorid "0665"
    0.000029     send_to_all: SETINFO driver.parameter.protocol
"megatec"
    0.000039     debug level is '5'
    0.022310     Checking device (1D6B/0003) (004/001)
    0.022330     - VendorID: 1d6b
    0.022333     - ProductID: 0003
    0.022336     - Manufacturer: unknown
    0.022338     - Product: unknown
    0.022340     - Serial Number: unknown
    0.022342     - Bus: 004
    0.022345     Trying to match device
    0.022352     Device does not match - skipping
    0.022357     Checking device (1D6B/0002) (003/001)
    0.022365     - VendorID: 1d6b
    0.022367     - ProductID: 0002
    0.022369     - Manufacturer: unknown
    0.022372     - Product: unknown
    0.022374     - Serial Number: unknown
    0.022376     - Bus: 003
    0.022378     Trying to match device
    0.022381     Device does not match - skipping
    0.022385     Checking device (0665/5161) (002/003)
    0.030156     - VendorID: 0665
    0.030170     - ProductID: 5161
    0.030177     - Manufacturer: unknown
    0.030182     - Product: unknown
    0.030187     - Serial Number: unknown
    0.030192     - Bus: 002
    0.030204     Trying to match device
    0.030220     Device matches
    0.031025     send_to_all: SETINFO ups.vendorid "0665"
    0.031037     send_to_all: SETINFO ups.productid "5161"
    0.031046     Initiating UPS shutdown
    0.033050     send: C
    1.033388     read: error sending control message: Operation not permitted
    1.033404     instcmd: command [shutdown.stop] handled
    1.038035     send: S.5R0003
    1.109163     read: (ACK
    1.109179     instcmd: command [shutdown.return] failed
    1.111018     send: C
    1.149165     read: (ACK
    1.149180     instcmd: command [shutdown.stop] failed
    1.151017     send: C
    1.197111     read: (NAK
    1.197125     instcmd: command [shutdown.stop] failed
    1.197138     Shutdown failed!


It seems that failures are seen as successes and the other way around.

While the drivers are running upscmd can successfully send a 
"shutdown.return" to the UPS.

I've worked around the problem by creating the following script.
root at proxmox1:~# cat /usr/local/bin/upsshutdown
#!/bin/sh

/etc/init.d/nut-server start
/bin/sleep 1
/bin/upscmd -uadmin -padminpass mecer shutdown.return
EXITCODE=$?
/etc/init.d/nut-server stop
return $EXITCODE

I modified /etc/init.d/nut-server to call my script instead of upsdrvctl 
shutdown.

This works, but I suspect the blazer driver must be fixed at some stage.
I looked at the code, but don't understand enough to help.

Please let me know if I can be of any assistance.

Regards,


-- 


Johan Meiring
Cape PC Services CC
Tel: (021) 883-8271
Fax: (021) 886-7782

--------------------
Before acting on this email or opening any attachments
you should read Cape PC Service's email disclaimer at:

http://www.pcservices.co.za/documents/disclaimer.pdf

Hi Johan,

The driver is expecting either 'ACK' or no reply at all in case of
success and the command itself echoed back in case of errors.
On the other hand, your UPS replies '(ACK' in case of success and
'(NAK' on failure.

So.. when the driver first tries to stop pending shutdowns and you get
the 'operation not permitted' error, the driver interprets it as a
success.
When it tries to shutdown.return and you get '(ACK', the driver
interprets it as a failure..

You could try and change line 467 of blazer.c from this:

if (strncmp(buf, "ACK", 3)) {

to this:

if (strncmp(buf, "(ACK", 4)) {

..this should do the trick.

However, your UPS seems to speak an idiom that's more akin to the one
covered by the voltronic drivers (i.e. the (ACK/(NAK replies) -
available in the github repo - so maybe they're worth a try.

/dan

2013/10/24 Johan Meiring <jmeiring at
pcservices.co.za>:
> Hi,
>
> There seems to be a problem turning of the inverter on a Mecer online
1000VA
> UPS.
>
> OS:  Debian Wheezy
> Nut: Installed via apt - version 2.6.4-2.3
>
> Debug output from driver.
>
> root at proxmox1:~# /lib/nut/blazer_usb -DDDDD -a mecer -k
> Network UPS Tools - Megatec/Q1 protocol USB driver 0.08 (2.6.4)
>    0.000000     send_to_all: SETINFO driver.parameter.port "auto"
>    0.000023     send_to_all: SETINFO driver.parameter.vendorid
"0665"
>    0.000029     send_to_all: SETINFO driver.parameter.protocol
"megatec"
>    0.000039     debug level is '5'
>    0.022310     Checking device (1D6B/0003) (004/001)
>    0.022330     - VendorID: 1d6b
>    0.022333     - ProductID: 0003
>    0.022336     - Manufacturer: unknown
>    0.022338     - Product: unknown
>    0.022340     - Serial Number: unknown
>    0.022342     - Bus: 004
>    0.022345     Trying to match device
>    0.022352     Device does not match - skipping
>    0.022357     Checking device (1D6B/0002) (003/001)
>    0.022365     - VendorID: 1d6b
>    0.022367     - ProductID: 0002
>    0.022369     - Manufacturer: unknown
>    0.022372     - Product: unknown
>    0.022374     - Serial Number: unknown
>    0.022376     - Bus: 003
>    0.022378     Trying to match device
>    0.022381     Device does not match - skipping
>    0.022385     Checking device (0665/5161) (002/003)
>    0.030156     - VendorID: 0665
>    0.030170     - ProductID: 5161
>    0.030177     - Manufacturer: unknown
>    0.030182     - Product: unknown
>    0.030187     - Serial Number: unknown
>    0.030192     - Bus: 002
>    0.030204     Trying to match device
>    0.030220     Device matches
>    0.031025     send_to_all: SETINFO ups.vendorid "0665"
>    0.031037     send_to_all: SETINFO ups.productid "5161"
>    0.031046     Initiating UPS shutdown
>    0.033050     send: C
>    1.033388     read: error sending control message: Operation not
permitted
>    1.033404     instcmd: command [shutdown.stop] handled
>    1.038035     send: S.5R0003
>    1.109163     read: (ACK
>    1.109179     instcmd: command [shutdown.return] failed
>    1.111018     send: C
>    1.149165     read: (ACK
>    1.149180     instcmd: command [shutdown.stop] failed
>    1.151017     send: C
>    1.197111     read: (NAK
>    1.197125     instcmd: command [shutdown.stop] failed
>    1.197138     Shutdown failed!
>
>
> It seems that failures are seen as successes and the other way around.
>
> While the drivers are running upscmd can successfully send a
> "shutdown.return" to the UPS.
>
> I've worked around the problem by creating the following script.
> root at proxmox1:~# cat /usr/local/bin/upsshutdown
> #!/bin/sh
>
> /etc/init.d/nut-server start
> /bin/sleep 1
> /bin/upscmd -uadmin -padminpass mecer shutdown.return
> EXITCODE=$?
> /etc/init.d/nut-server stop
> return $EXITCODE
>
> I modified /etc/init.d/nut-server to call my script instead of upsdrvctl
> shutdown.
>
> This works, but I suspect the blazer driver must be fixed at some stage.
> I looked at the code, but don't understand enough to help.
>
> Please let me know if I can be of any assistance.
>
> Regards,
>
>
> --
>
>
> Johan Meiring
> Cape PC Services CC
> Tel: (021) 883-8271
> Fax: (021) 886-7782
>
> --------------------
> Before acting on this email or opening any attachments
> you should read Cape PC Service's email disclaimer at:
>
> http://www.pcservices.co.za/documents/disclaimer.pdf
>
>
> _______________________________________________
> Nut-upsuser mailing list
> Nut-upsuser at lists.alioth.debian.org
> http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/nut-upsuser

Hi,

They say one should never argue with people that know more than you, so please
bear with me.

On 2013/10/24 09:47 PM, hyouko at gmail.com wrote:
> The driver is expecting either 'ACK' or no reply at all in case of
> success and the command itself echoed back in case of errors.
> On the other hand, your UPS replies '(ACK' in case of success and
> '(NAK' on failure.
This I agree with, but...
> 
> So.. when the driver first tries to stop pending shutdowns and you get
> the 'operation not permitted' error, the driver interprets it as a
> success.
Looking at the debug log, this is actually a failure.
The 'operation not permitted' is a comms failure with the UPS.

Later on in the debug log you can see where it tries to cancel the pending
shutdown, a "(NAK" is sent, and not a 'operation not
permitted' error.

In any case, this is actually considered to be a success by the code.
This is not right.

Code as follows:
418	/*
419	 * If a command is invalid, it will be echoed back
420	 */
421	if (blazer_command(buf, buf, sizeof(buf)) > 0) {
422		upslogx(LOG_ERR, "instcmd: command [%s] failed", cmdname);
423		return STAT_INSTCMD_FAILED;
424	}
425
426	upslogx(LOG_INFO, "instcmd: command [%s] handled", cmdname);
427	return STAT_INSTCMD_HANDLED;

As far as I understand the code line 421 tries to test for a 'comms
failure' (e.g. driver disconnection) or any return string.  I also suspect
that comms failures are negative numbers.
Should the test not be "!= 0".

What is clear though is that the code does not try to check the response.
If there was not a comms failure or a return string, it is considered handled.

Should it not also test for an "ACK" or "(ACK"?
> When it tries to shutdown.return and you get '(ACK', the driver
> interprets it as a failure..
Again looking at the code.
462 /*
463  * If a command is invalid, it will be echoed back.
464  * As an exception, Best UPS units will report "ACK" in case of
success!
465  */
466 if (blazer_command(buf, buf, sizeof(buf)) > 0) {
467 	if (strncmp(buf, "ACK", 3)) {
468 		upslogx(LOG_ERR, "instcmd: command [%s] failed", cmdname);
469 		return STAT_INSTCMD_FAILED;
470 	}
471 }
472 
473 upslogx(LOG_INFO, "instcmd: command [%s] handled", cmdname);
474 return STAT_INSTCMD_HANDLED;

It seems from the code that the test on line 466 tests for comms failures 
(again e.g. driver disconnection) or a return string.  On line 467 if there was
a failure, it checks for 'ACK' and this will override the failure.

Similarty the test on line 466 should probably be
"!=0".
> 
> You could try and change line 467 of blazer.c from this:
> 
> if (strncmp(buf, "ACK", 3)) {
> 
> to this:
> 
> if (strncmp(buf, "(ACK", 4)) {
> 
> ..this should do the trick.
> 
The following patch might be better?

--- blazer.c.orig       2013-10-25 10:34:54.000000000 +0200
+++ blazer.c    2013-10-25 10:49:03.000000000 +0200
@@ -417,10 +417,13 @@

                /*
                 * If a command is invalid, it will be echoed back
+                * As an exception, some UPS units will report "ACK"
or "(ACK" in case of success!
                 */
-               if (blazer_command(buf, buf, sizeof(buf)) > 0) {
-                       upslogx(LOG_ERR, "instcmd: command [%s]
failed", cmdname);
-                       return STAT_INSTCMD_FAILED;
+               if (blazer_command(buf, buf, sizeof(buf)) != 0) {
+                       if (strncmp(buf, "ACK", 3) &&
strncmp(buf, "(ACK", 4) ) {
+                               upslogx(LOG_ERR, "instcmd: command [%s]
failed", cmdname);
+                               return STAT_INSTCMD_FAILED;
+                       }
                }

                upslogx(LOG_INFO, "instcmd: command [%s] handled",
cmdname);
@@ -461,10 +464,10 @@

        /*
         * If a command is invalid, it will be echoed back.
-        * As an exception, Best UPS units will report "ACK" in case
of success!
+        * As an exception, some UPS units will report "ACK" or
"(ACK" in case of success!
         */
        if (blazer_command(buf, buf, sizeof(buf)) > 0) {
-               if (strncmp(buf, "ACK", 3)) {
+               if (strncmp(buf, "ACK", 3) && strncmp(buf,
"(ACK", 4) ) {
                        upslogx(LOG_ERR, "instcmd: command [%s]
failed", cmdname);
                        return STAT_INSTCMD_FAILED;
                }

Opinions?
Is this the correct place to submit pathes?
> However, your UPS seems to speak an idiom that's more akin to the one
> covered by the voltronic drivers (i.e. the (ACK/(NAK replies) -
> available in the github repo - so maybe they're worth a try.
> 
I looked at the voltronic.c file.
The protocol seems to be quite different.
The rest of the driver works perfectly.
(Unless voltronic firmware has an older "backwards compatible mode ??)

The UPS is also a Mecer, sold by a company called Mustek.
and the Blazer Driver seems to mention Mustek in a few places.

If you still think I must try it, I will gladly do so.


Thanks!


-- 


Johan Meiring
Cape PC Services CC
Tel: (021) 883-8271
Fax: (021) 886-7782

--------------------
Before acting on this email or opening any attachments
you should read Cape PC Service's email disclaimer at:

http://www.pcservices.co.za/documents/disclaimer.pdf