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

Bug #1555269 reported by Andres Rodriguez on 2016-03-09
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MAAS
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  Edit
Everyone can see this information.

Other bug subscribers