[2.0a1] Commissioning yields in BMC password not being updated

Bug #1555269 reported by Andres Rodriguez
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MAAS
Fix Released
Critical
Unassigned

Bug Description

Commissioning resulted in password not being updated. This is 2.0 pre alpha2.

The commissioning output:

Setting up libipmidetect0 (1.1.5-3ubuntu3.3) ...
Setting up freeipmi-tools (1.1.5-3ubuntu3.3) ...
Processing triggers for libc-bin (2.19-0ubuntu6.7) ...
Processing triggers for ureadahead (0.100.0-16) ...
[ 70.853141] ipmi-locate:2424 map pfn expected mapping type uncached-minus for [mem 0x7f5bc000-0x7f5bcfff], got write-back
[...]
[ 72.495883] ipmi-locate:2441 map pfn expected mapping type uncached-minus for [mem 0x7f5bc000-0x7f5bcfff], got write-back
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success
Success

MAAS logs
=========

2016-03-10 02:37:06 [-] 127.0.0.1 - - [09/Mar/2016:18:37:05 +0000] "GET /MAAS/rpc/ HTTP/1.0" 200 520 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"

==> /var/log/maas/maas.log <==
Mar 10 02:37:13 trusty-maas9 maas.service_monitor: [INFO] Service 'maas-dhcpd' has been restarted. Its current state is 'on' and 'running'.

==> /var/log/maas/regiond.log <==
2016-03-10 02:37:13 [RegionServer,2,10.216.160.107] Successfully configured DHCP on rack controller '4y3h7n'.
2016-03-10 02:37:14 [-] 127.0.0.1 - - [09/Mar/2016:18:37:13 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:14 [-] 127.0.0.1 - - [09/Mar/2016:18:37:13 +0000] "GET /MAAS/metadata/2012-03-01/maas-commissioning-scripts HTTP/1.1" 200 20480 "-" "Python-urllib/3.4"
2016-03-10 02:37:14 [-] 127.0.0.1 - - [09/Mar/2016:18:37:14 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:20 [-] 127.0.0.1 - - [09/Mar/2016:18:37:19 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:20 [-] 127.0.0.1 - - [09/Mar/2016:18:37:19 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:20 [-] 127.0.0.1 - - [09/Mar/2016:18:37:19 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:21 [-] 127.0.0.1 - - [09/Mar/2016:18:37:20 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:23 [-] 127.0.0.1 - - [09/Mar/2016:18:37:22 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:23 [-] 127.0.0.1 - - [09/Mar/2016:18:37:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:24 [-] 127.0.0.1 - - [09/Mar/2016:18:37:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:24 [-] 127.0.0.1 - - [09/Mar/2016:18:37:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:24 [-] 127.0.0.1 - - [09/Mar/2016:18:37:24 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:25 [-] 127.0.0.1 - - [09/Mar/2016:18:37:24 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:25 [-] 127.0.0.1 - - [09/Mar/2016:18:37:24 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:26 [-] 127.0.0.1 - - [09/Mar/2016:18:37:25 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:37:36 [-] 127.0.0.1 - - [09/Mar/2016:18:37:35 +0000] "GET /MAAS/rpc/ HTTP/1.0" 200 520 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"
2016-03-10 02:38:06 [-] 127.0.0.1 - - [09/Mar/2016:18:38:05 +0000] "GET /MAAS/rpc/ HTTP/1.0" 200 520 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"
2016-03-10 02:38:23 [-] 127.0.0.1 - - [09/Mar/2016:18:38:22 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:38:23 [-] 127.0.0.1 - - [09/Mar/2016:18:38:22 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:38:24 [-] 127.0.0.1 - - [09/Mar/2016:18:38:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:38:24 [-] 127.0.0.1 - - [09/Mar/2016:18:38:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:38:24 [-] 127.0.0.1 - - [09/Mar/2016:18:38:23 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"

==> /var/log/maas/maas.log <==
Mar 10 02:38:25 trusty-maas9 maas.node: [INFO] gableended-elizabet: Storage layout was set to flat.
Mar 10 02:38:25 trusty-maas9 maas.node: [INFO] gableended-elizabet: Status transition from COMMISSIONING to READY

==> /var/log/maas/regiond.log <==
2016-03-10 02:38:25 [-] 127.0.0.1 - - [09/Mar/2016:18:38:24 +0000] "POST /MAAS/metadata/2012-03-01/ HTTP/1.1" 200 2 "-" "Python-urllib/3.4"
2016-03-10 02:38:36 [-] 127.0.0.1 - - [09/Mar/2016:18:38:35 +0000] "GET /MAAS/rpc/ HTTP/1.0" 200 520 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"

==> /var/log/maas/maas.log <==
Mar 10 02:38:44 trusty-maas9 maas.service_monitor: [INFO] Service 'maas-dhcpd' has been restarted. Its current state is 'on' and 'running'.

==> /var/log/maas/regiond.log <==
2016-03-10 02:38:44 [RegionServer,2,10.216.160.107] Successfully configured DHCP on rack controller '4y3h7n'.

==> /var/log/maas/rackd.log <==
2016-03-10 02:38:45+0800 [-] Unhandled failure dispatching AMP command. This is probably a bug. Please ensure that this error is handled within application code or declared in the signature of the b'PowerQuery' command. [trusty-maas9:pid=26478:cmd=PowerQuery:ask=d]
        Traceback (most recent call last):
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1184, in gotResult
            _inlineCallbacks(r, g, deferred)
          File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1174, in _inlineCallbacks
            deferred.errback()
          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()
        --- <exception caught here> ---
          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/protocols/amp.py", line 1149, in checkKnownErrors
            key = error.trap(*command.allErrors)
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 342, in trap
            self.raiseException()
          File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 368, in raiseException
            raise self.value.with_traceback(self.tb)
          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/ipmi.py", line 158, in power_query
            return self._issue_ipmi_command('query', **context)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/ipmi.py", line 149, in _issue_ipmi_command
            ipmipower_command, power_change, power_address)
          File "/usr/lib/python3/dist-packages/provisioningserver/drivers/power/ipmi.py", line 83, in _issue_ipmi_power_command
            power_change, power_address, e.output_as_unicode))
        provisioningserver.drivers.power.PowerFatalError: Failed to power query 192.168.4.41:

==> /var/log/maas/maas.log <==
Mar 10 02:38:45 trusty-maas9 maas.node_query: [ERROR] gableended-elizabet: Error when checking power state: (b'UNHANDLED', 'Unknown Error [trusty-maas9:pid=26478:cmd=PowerQuery:ask=d]')
Mar 10 02:38:45 trusty-maas9 maas.node_query: [INFO] gableended-elizabet: Unable to determine power state.

==> /var/log/maas/regiond.log <==
2016-03-10 02:39:06 [-] 127.0.0.1 - - [09/Mar/2016:18:39:05 +0000] "GET /MAAS/rpc/ HTTP/1.0" 200 520 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"

apache2 logs
============

192.168.10.64 - - [10/Mar/2016:02:37:14 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:14 +0800] "GET /MAAS/metadata//2012-03-01/maas-commissioning-scripts HTTP/1.1" 200 20806 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:14 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:19 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:20 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:20 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:21 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:23 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:23 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:25 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:25 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:37:26 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:23 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:23 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:24 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"
192.168.10.64 - - [10/Mar/2016:02:38:25 +0800] "POST /MAAS/metadata//2012-03-01/ HTTP/1.1" 200 304 "-" "Python-urllib/3.4"

Related branches

summary: - Commissioning yields in BMC password not being updated
+ [2.0a1] Commissioning yields in BMC password not being updated
Changed in maas:
importance: Undecided → Critical
status: New → Confirmed
milestone: none → 2.0.0
description: updated
Changed in maas:
status: Confirmed → Fix Committed
Changed in maas:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.