Failed to query node's BMC - Power state could not be queried: 'in <string>' requires string as left operand, not bytes

[Dimiter Naydenov]

I see this error in the rackd.log a lot and errors checking the power state of all AMT-controller NUCs I have:

2016-04-13 15:39:57+0300 [ClusterClient,client] Failed to refresh power state.
        Traceback (most recent call last):
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 434, in errback
            self._startRunCallbacks(fail)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 501, in _startRunCallbacks
            self._runCallbacks()
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 588, in _runCallbacks
            current.result = callback(current.result, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1184, in gotResult
            _inlineCallbacks(r, g, deferred)
        --- <exception caught here> ---
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1126, in _inlineCallbacks
            result = result.throwExceptionIntoGenerator(g)
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 389, in throwExceptionIntoGenerator
            return g.throw(self.type, self.value, self.tb)
          File "/usr/lib/python3/dist-packages/provisioningserver/power/query.py", line 103, in get_power_state
            raise exc_type(exc_value).with_traceback(exc_trace)
          File "/usr/lib/python3/dist-packages/provisioningserver/power/query.py", line 92, in get_power_state
            system_id, hostname, power_type, context)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1126, in _inlineCallbacks
            result = result.throwExceptionIntoGenerator(g)
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 389, in throwExceptionIntoGenerator
            return g.throw(self.type, self.value, self.tb)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/__init__.py", line 240, in query
            self.power_query, system_id, context)
          File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 246, in inContext
            result = inContext.theWork()
          File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 262, in <lambda>
            inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 118, in callWithContext
            return self.currentContext().callWithContext(ctx, func, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 81, in callWithContext
            return func(*args,**kw)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/amt.py", line 369, in power_query
            return self.amttool_query_state(ip_address, power_pass)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/amt.py", line 169, in amttool_query_state
            if b'S5' in output:
        builtins.TypeError: 'in <string>' requires string as left operand, not bytes

This MAAS was originally 1.9 on trusty, later upgraded to xenial and then the latest beta from the experimental3 PPA.

--------------------------

maashw@maas-hw:/var/log/maas$ dpkg -l '*maas*'|cat
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-===============================-====================================-============-=================================================
ii maas 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all "Metal as a Service" is a physical cloud and IPAM
ii maas-cli 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS client and command-line interface
rc maas-cluster-controller 1.9.0+bzr4533-0ubuntu1~trusty1 all MAAS server cluster controller
ii maas-common 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS server common files
ii maas-dhcp 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS DHCP server
ii maas-dns 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS DNS server
ii maas-proxy 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS Caching Proxy
ii maas-rack-controller 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all Rack Controller for MAAS
ii maas-region-api 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all Region controller API service for MAAS
ii maas-region-controller 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all Region Controller for MAAS
rc maas-region-controller-min 1.9.0+bzr4533-0ubuntu1~trusty1 all MAAS Server minimum region controller
un python-django-maas <none> <none> (no description available)
un python-maas-client <none> <none> (no description available)
un python-maas-provisioningserver <none> <none> (no description available)
ii python3-django-maas 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS server Django web framework (Python 3)
ii python3-maas-client 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS python API client (Python 3)
ii python3-maas-provisioningserver 2.0.0~beta2+bzr4910-0ubuntu1~xenial1 all MAAS server provisioning libraries (Python 3)

[Dimiter Naydenov (dimitern)]

In case it might help, here's the output of `amtterm 10.14.0.11 info` for one of the nodes (issue happens with all nodes):

maashw@maas-hw:~$ amttool 10.14.0.11 info
### AMT info on machine '10.14.0.11' ###
AMT version: 8.1.30
Hostname: node-11.maas
Powerstate: S5 (soft-off)
Remote Control Capabilities:
    IanaOemNumber 157
    OemDefinedCapabilities IDER SOL BiosSetup
    SpecialCommandsSupported PXE-boot HD-boot cd-boot
    SystemCapabilitiesSupported powercycle powerdown powerup reset
    SystemFirmwareCapabilities 7821

[Dimiter Naydenov (dimitern)]

I've dropped all "b" prefixes from the power states in provisioningserver/drivers/power/amt.py and now I'm seeing another error, which causes a similar power check errors. The new error is because apparently the AMT controller often responds with "500 Can't connect to <IP>", which is treated as PowerFatalError, but it shouldn't (as retrying usually works as expected - in my observations at least).

Here's the patch I used: http://paste.ubuntu.com/15810913/

The error I described earlier causes the following traceback in the rackd.log:

2016-04-13 16:22:15+0300 [ClusterClient,client] Failed to refresh power state.
        Traceback (most recent call last):
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 434, in errback
            self._startRunCallbacks(fail)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 501, in _startRunCallbacks
            self._runCallbacks()
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 588, in _runCallbacks
            current.result = callback(current.result, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1184, in gotResult
            _inlineCallbacks(r, g, deferred)
        --- <exception caught here> ---
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1126, in _inlineCallbacks
            result = result.throwExceptionIntoGenerator(g)
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 389, in throwExceptionIntoGenerator
            return g.throw(self.type, self.value, self.tb)
          File "/usr/lib/python3/dist-packages/provisioningserver/power/query.py", line 103, in get_power_state
            raise exc_type(exc_value).with_traceback(exc_trace)
          File "/usr/lib/python3/dist-packages/provisioningserver/power/query.py", line 92, in get_power_state
            system_id, hostname, power_type, context)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1126, in _inlineCallbacks
            result = result.throwExceptionIntoGenerator(g)
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 389, in throwExceptionIntoGenerator
            return g.throw(self.type, self.value, self.tb)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/__init__.py", line 240, in query
            self.power_query, system_id, context)
          File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 246, in inContext
            result = inContext.theWork()
          File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 262, in <lambda>
            inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 118, in callWithContext
            return self.currentContext().callWithContext(ctx, func, *args, **kw)
          File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 81, in callWithContext
            return func(*args,**kw)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/powe...