Improve "slapos node boot"

See merge request nexedi/slapos.core!303

slapos/cli/boot.py

@@ -43,7 +43,9 @@ from slapos.cli.config import ConfigCommand
 from slapos.format import isGlobalScopeAddress
 from slapos.util import string_to_boolean
 import argparse
+import logging
 
+logger = logging.getLogger("slapos.boot")
 
 def _removeTimestamp(instancehome, partition_base_name):
     """
@@ -54,7 +56,7 @@ def _removeTimestamp(instancehome, partition_base_name):
         "%s*" % partition_base_name,
         ".timestamp")
     for timestamp_path in glob.glob(timestamp_glob_path):
-       print("Removing %s" % timestamp_path)
+       logger.info("Removing %s", timestamp_path)
        os.remove(timestamp_path)
 
 
@@ -62,7 +64,7 @@ def _runBang(app):
     """
     Launch slapos node format.
     """
-    print("[BOOT] Invoking slapos node bang...")
+    logger.info("[BOOT] Invoking slapos node bang...")
     result = app.run(['node', 'bang', '-m', 'Reboot'])
     if result == 1:
       return 0
@@ -73,7 +75,7 @@ def _runFormat(app):
     """
     Launch slapos node format.
     """
-    print("[BOOT] Invoking slapos node format...")
+    logger.info("[BOOT] Invoking slapos node format...")
     result = app.run(['node', 'format', '--now', '--verbose'])
     if result == 1:
       return 0
@@ -84,15 +86,15 @@ def _ping(hostname):
     """
     Ping a hostname
     """
-    print("[BOOT] Invoking ipv4 ping to %s..." % hostname)
+    logger.info("[BOOT] Invoking ipv4 ping to %s...", hostname)
     p = subprocess.Popen(["ping", "-c", "2", hostname],
                          stdout=subprocess.PIPE,
                          stderr=subprocess.PIPE)
     stdout, stderr = p.communicate()
     if p.returncode == 0:
-      print("[BOOT] IPv4 network reachable...")
+      logger.info("[BOOT] IPv4 network reachable...")
       return 1
-    print("[BOOT] [ERROR] IPv4 network unreachable...")
+    logger.error("[BOOT] IPv4 network unreachable...")
     return 0
 
 
@@ -100,15 +102,15 @@ def _ping6(hostname):
     """
     Ping an ipv6 address
     """
-    print("[BOOT] Invoking ipv6 ping to %s..." % hostname)
+    logger.info("[BOOT] Invoking ipv6 ping to %s...", hostname)
     p = subprocess.Popen(
         ["ping6", "-c", "2", hostname],
         stdout=subprocess.PIPE, stderr=subprocess.PIPE)
     stdout, stderr = p.communicate()
     if p.returncode == 0:
-        print("[BOOT] IPv6 network reachable...")
+        logger.info("[BOOT] IPv6 network reachable...")
         return 1
-    print("[BOOT] [ERROR] IPv6 network unreachable...")
+    logger.error("[BOOT] IPv6 network unreachable...")
     return 0
 
 
@@ -141,18 +143,16 @@ def _waitIpv6Ready(ipv6_interface):
   """
     test if ipv6 is ready on ipv6_interface
   """
-  ipv6_address = ""
-  print("[BOOT] Checking if %r has IPv6..." % ipv6_interface)
-  while ipv6_address == "":
-    for inet_dict in netifaces.ifaddresses(ipv6_interface)[socket.AF_INET6]:
+  logger.info("[BOOT] Checking if %r has IPv6...", ipv6_interface)
+  while True:
+    for inet_dict in netifaces.ifaddresses(ipv6_interface).get(socket.AF_INET6, ()):
       ipv6_address = inet_dict['addr'].split('%')[0]
       if isGlobalScopeAddress(ipv6_address):
-        break
-    else:
-      ipv6_address = ""
-      print("[BOOT] [ERROR] No IPv6 found on interface %r, "
-            "try again in 5 seconds..." % ipv6_interface)
-      sleep(5)
+        return
+
+    logger.error("[BOOT] No IPv6 found on interface %r, "
+          "try again in 5 seconds...", ipv6_interface)
+    sleep(5)
 
 class BootCommand(ConfigCommand):
     """
@@ -208,12 +208,12 @@ class BootCommand(ConfigCommand):
         app = SlapOSApp()
         # Make sure slapos node format returns ok
         while not _runFormat(app):
-            print("[BOOT] [ERROR] Fail to format, try again in 15 seconds...")
+            logger.error("[BOOT] Fail to format, try again in 15 seconds...")
             sleep(15)
 
         # Make sure slapos node bang returns ok
         while not _runBang(app):
-            print("[BOOT] [ERROR] Fail to bang, try again in 15 seconds...")
+            logger.error("[BOOT] Fail to bang, try again in 15 seconds...")
             sleep(15)
 
         _removeTimestamp(instance_root, partition_base_name)

slapos/tests/test_cli.py

@@ -340,14 +340,19 @@ class TestCliBoot(CliMixin):
               timestamp)
 
   def test_boot_failure(self):
-    # In this test, node and bang command will fail two time each.
+    # In this test, the network interfaces will not have
+    # IP address at the beginning, the global IPv6 address only appears later,
+    # then format and bang commands will fail two time each.
     # `slapos node boot` command retries on failures.
 
     app = slapos.cli.entry.SlapOSApp()
+    net1 = {socket.AF_INET: ({'addr': '127.0.0.1'},),}
+    net2 = {socket.AF_INET: ({'addr': '127.0.0.1'},), socket.AF_INET6: ({'addr': 'fe80::1'},),}
+    net3 = {socket.AF_INET: ({'addr': '127.0.0.1'},), socket.AF_INET6: ({'addr': 'fe80::1'}, {'addr': '2000::1'},),}
     with patch('slapos.cli.boot.check_root_user', return_value=True) as check_root_user,\
         patch('slapos.cli.boot.sleep') as sleep,\
         patch('slapos.cli.boot.netifaces.ifaddresses',
-              return_value={socket.AF_INET6: ({'addr': '2000::1'},),},),\
+              side_effect=[net1, net2, net3]),\
         patch('slapos.cli.boot._ping_hostname', return_value=0),\
         patch('slapos.cli.format.check_root_user', return_value=True),\
         patch('slapos.cli.format.logging.FileHandler', return_value=logging.NullHandler()),\
@@ -362,8 +367,9 @@ class TestCliBoot(CliMixin):
     self.assertEqual(do_format.call_count, 3)
     self.assertEqual(do_bang.call_count, 3)
 
-    # between retries we sleep 15 seconds.
-    sleep.assert_called_with(15)
+    # between retries of ping, we sleep 5 seconds
+    # between retries of bang, we sleep 15 seconds
+    self.assertEqual(sleep.mock_calls, [mock.call(5)]*2 + [mock.call(15)]*4)
 
     # we have only one logger on the console
     from slapos.cli import coloredlogs