Merge lp:~rvb/maas/node-trans-log into lp:~maas-committers/maas/trunk

[Raphaël Badin]

Log node status transition at info level: having the node status transitions in the log by default (i.e. logged at 'info' level) is tremendously helpful when debugging issues.

[Gavin Panella (allenap)]

review: Approve

=== modified file 'src/maasserver/event_connect.py'
--- src/maasserver/event_connect.py	2015-03-25 15:33:23 +0000
+++ src/maasserver/event_connect.py	2015-04-21 08:50:22 +0000
@@ -45,7 +45,7 @@
         NODE_STATUS_CHOICES_DICT[node.status],
     )
 
-    # Special-case for allocating ndoes: we can include usernames here
+    # Special-case for allocating nodes: we can include usernames here
     # to make the event log more useful.
     if node.status == NODE_STATUS.ALLOCATED:
         description += " (to %s)" % node.owner.username

=== modified file 'src/maasserver/models/node.py'
--- src/maasserver/models/node.py	2015-04-16 19:52:24 +0000
+++ src/maasserver/models/node.py	2015-04-21 08:50:22 +0000
@@ -726,8 +726,8 @@
             # Valid transition.
             if old_status is not None:
                 stat = map_enum_reverse(NODE_STATUS, ignore=['DEFAULT'])
-                maaslog.debug(
-                    "%s: Transition status from %s to %s",
+                maaslog.info(
+                    "%s: Status transition from %s to %s",
                     self.hostname, stat[old_status], stat[self.status])
             pass
         else:

=== modified file 'src/maasserver/models/tests/test_node.py'
--- src/maasserver/models/tests/test_node.py	2015-04-16 14:15:25 +0000
+++ src/maasserver/models/tests/test_node.py	2015-04-21 08:50:22 +0000
@@ -119,7 +119,10 @@
 from provisioningserver.rpc.exceptions import NoConnectionsAvailable
 from provisioningserver.rpc.power import QUERY_POWER_TYPES
 from provisioningserver.rpc.testing import always_succeed_with
-from provisioningserver.utils.enum import map_enum
+from provisioningserver.utils.enum import (
+    map_enum,
+    map_enum_reverse,
+)
 from testtools import ExpectedException
 from testtools.matchers import (
     Contains,
@@ -746,7 +749,7 @@
         self.assertThat(node._set_status, MockCalledOnceWith(
             node, node.system_id, status=NODE_STATUS.FAILED_DISK_ERASING))
         # It's logged too.
-        self.assertThat(logger.output, Equals(
+        self.assertThat(logger.output, Contains(
             "%s: Could not start node for disk erasure: %s\n"
             % (node.hostname, error_message)))
 
@@ -1438,7 +1441,7 @@
         self.assertThat(node._set_status, MockCalledOnceWith(
             node, node.system_id, status=status))
         # It's logged too.
-        self.assertThat(logger.output, Equals(
+        self.assertThat(logger.output, Contains(
             "%s: Could not start node for commissioning: %s\n"
             % (node.hostname, error_message)))
 
@@ -1553,6 +1556,22 @@
                 NodeStateViolation, node.abort_commissioning,
                 factory.make_admin())
 
+    def test_full_clean_logs_node_status_transition(self):
+        node = factory.make_Node(
+            status=NODE_STATUS.DEPLOYING, owner=factory.make_User())
+        node.status = NODE_STATUS.DEPLOYED
+
+        with LoggerFixture("maas") as logger:
+            node.full_clean()
+
+        stat = map_enum_reverse(NODE_STATUS)
+        self.assertThat(logger.output.strip(), Equals(
+            "%s: Status transition from %s to %s" % (
+                node.hostname, stat[NODE_STATUS.DEPLOYING],
+                stat[NODE_STATUS.DEPLOYED])
+            )
+        )
+
     def test_full_clean_checks_status_transition_and_raises_if_invalid(self):
         # RETIRED -> ALLOCATED is an invalid transition.
         node = factory.make_Node(