Buildout debug mode for slapos node software / instance

Expose buildout debugging capabilities in `slapos node software` and `slapos node instance` with a `--buildout-debug` command line option.

From buildout's command line reference:

> `-D`
>  Debug errors. If an error occurs, then the post-mortem debugger will be started. This is especially useful 
>  for debugging recipe problems.

This is to make it easier to debug instance profiles written as jinja templates.

This fix from buildout nexedi/slapos.buildout!17 is recommended, otherwise slapos node does not realize there was an error in buildout if that error is debugged.

/reviewed-on nexedi/slapos.core!51

slapos/cli/slapgrid.py

@@ -131,6 +131,9 @@ class SoftwareCommand(SlapgridCommand):
     def get_parser(self, prog_name):
         ap = super(SoftwareCommand, self).get_parser(prog_name)
 
+        ap.add_argument('--buildout-debug',
+                        action='store_true',
+                        help='Run buildout in debug mode (with -D command line switch)')
         only = ap.add_mutually_exclusive_group()
         only.add_argument('--all', action='store_true',
                           help='Process all Software Releases, even if already installed.')
@@ -151,6 +154,9 @@ class InstanceCommand(SlapgridCommand):
     def get_parser(self, prog_name):
         ap = super(InstanceCommand, self).get_parser(prog_name)
 
+        ap.add_argument('--buildout-debug',
+                        action='store_true',
+                        help='Run buildout in debug mode (with -D command line switch)')
         only = ap.add_mutually_exclusive_group()
         only.add_argument('--all', action='store_true',
                           help='Process all Computer Partitions.')

slapos/grid/SlapObject.py

@@ -109,7 +109,8 @@ class Software(object):
                download_binary_dir_url=None, upload_binary_dir_url=None,
                download_from_binary_cache_url_blacklist=None,
                upload_to_binary_cache_url_blacklist=None,
-               software_min_free_space=None):
+               software_min_free_space=None,
+               buildout_debug=False,):
     """Initialisation of class parameters
     """
 
@@ -125,6 +126,7 @@ class Software(object):
     self.software_path = os.path.join(self.software_root,
                                       self.software_url_hash)
     self.buildout = buildout
+    self.buildout_debug = buildout_debug
     self.logger = logger
     self.signature_private_key_file = signature_private_key_file
     self.signature_certificate_list = signature_certificate_list
@@ -268,7 +270,8 @@ class Software(object):
       utils.launchBuildout(path=self.software_path,
                            buildout_binary=os.path.join(self.software_path, 'bin', 'buildout'),
                            logger=self.logger,
-                           additional_buildout_parameter_list=additional_parameters)
+                           additional_buildout_parameter_list=additional_parameters,
+                           debug=self.buildout_debug)
     finally:
       shutil.rmtree(extends_cache)
 
@@ -348,9 +351,11 @@ class Partition(object):
                instance_min_free_space=None,
                instance_storage_home='',
                ipv4_global_network='',
+               buildout_debug=False,
                ):
     """Initialisation of class parameters"""
     self.buildout = buildout
+    self.buildout_debug = buildout_debug
     self.logger = logger
     self.software_path = software_path
     self.instance_path = instance_path
@@ -619,7 +624,8 @@ class Partition(object):
     # Launches buildout
     utils.launchBuildout(path=self.instance_path,
                          buildout_binary=buildout_binary,
-                         logger=self.logger)
+                         logger=self.logger,
+                         debug=self.buildout_debug)
     self.generateSupervisorConfigurationFile()
     self.createRetentionLockDelay()
 

slapos/grid/slapgrid.py

@@ -242,6 +242,7 @@ def create_slapgrid_object(options, logger):
                   master_url=op['master_url'],
                   computer_id=op['computer_id'],
                   buildout=op.get('buildout'),
+                  buildout_debug=op.get('buildout_debug'),
                   logger=logger,
                   maximum_periodicity = op.get('maximum_periodicity', 86400),
                   key_file=op.get('key_file'),
@@ -336,6 +337,7 @@ class Slapgrid(object):
                ipv4_global_network=None,
                firewall_conf={},
                config=None,
+               buildout_debug=False,
                ):
     """Makes easy initialisation of class parameters"""
     # Parses arguments
@@ -375,6 +377,7 @@ class Slapgrid(object):
     self.computer = self.slap.registerComputer(self.computer_id)
     # Defines all needed paths
     self.buildout = buildout
+    self.buildout_debug = buildout_debug
     self.promise_timeout = promise_timeout
     self.develop = develop
     if software_release_filter_list is not None:
@@ -537,6 +540,7 @@ stderr_logfile_backups=1
         software = Software(url=software_release_uri,
             software_root=self.software_root,
             buildout=self.buildout,
+            buildout_debug=self.buildout_debug,
             logger=self.logger,
             signature_private_key_file=self.signature_private_key_file,
             signature_certificate_list=self.signature_certificate_list,
@@ -1009,6 +1013,7 @@ stderr_logfile_backups=1
       software_release_url=software_url,
       certificate_repository_path=self.certificate_repository_path,
       buildout=self.buildout,
+      buildout_debug=self.buildout_debug,
       logger=self.logger,
       retention_delay=getattr(computer_partition, '_filter_dict', {}).get('retention_delay', '0'),
       instance_min_free_space=self.instance_min_free_space,
@@ -1595,6 +1600,7 @@ stderr_logfile_backups=1
             software_release_url=software_url,
             certificate_repository_path=self.certificate_repository_path,
             buildout=self.buildout,
+            buildout_debug=self.buildout_debug,
             logger=self.logger,
             instance_storage_home=self.instance_storage_home,
             ipv4_global_network=self.ipv4_global_network,

slapos/grid/utils.py

@@ -91,12 +91,23 @@ LOCALE_ENVIRONMENT_REMOVE_LIST = [
 class SlapPopen(subprocess.Popen):
   """
   Almost normal subprocess with greedish features and logging.
+
   Each line is logged "live", and self.output is a string containing the whole
-  log.
+  log, unless kwargs['debug'] is True, in which case the process outputs
+  normally on stdout and stderr.
   """
   def __init__(self, *args, **kwargs):
     logger = kwargs.pop('logger')
+
+    debug = kwargs.pop('debug', False)
+    if debug:
+      kwargs.pop('stdout', None)
+      kwargs.pop('stderr', None)
+    else:
+      kwargs.setdefault('stdout', subprocess.PIPE)
+      kwargs.setdefault('stderr', subprocess.STDOUT)
       kwargs.update(stdin=subprocess.PIPE)
+
     if sys.platform == 'cygwin' and kwargs.get('env') == {}:
       kwargs['env'] = None
 
@@ -104,6 +115,10 @@ class SlapPopen(subprocess.Popen):
     kwargs.setdefault('close_fds', True)
 
     subprocess.Popen.__init__(self, *args, **kwargs)
+    if debug:
+      self.wait()
+      self.output = '(output not captured in debug mode)'
+      return
     self.stdin.flush()
     self.stdin.close()
     self.stdin = None
@@ -273,8 +288,6 @@ def bootstrapBuildout(path, logger, buildout=None,
     process_handler = SlapPopen(invocation_list,
                                 preexec_fn=lambda: dropPrivileges(uid, gid, logger=logger),
                                 cwd=path,
-                                stdout=subprocess.PIPE,
-                                stderr=subprocess.STDOUT,
                                 logger=logger)
     if process_handler.returncode is None or process_handler.returncode != 0:
       message = 'Failed to run buildout profile in directory %r' % path
@@ -289,7 +302,8 @@ def bootstrapBuildout(path, logger, buildout=None,
 
 
 def launchBuildout(path, buildout_binary, logger,
-                   additional_buildout_parameter_list=None):
+                   additional_buildout_parameter_list=None,
+                   debug=False):
   """ Launches buildout."""
   if additional_buildout_parameter_list is None:
     additional_buildout_parameter_list = []
@@ -304,6 +318,10 @@ def launchBuildout(path, buildout_binary, logger,
     line = line[2:]
     # Prepares parameters for buildout
     invocation_list = line.split() + [buildout_binary]
+
+  if debug:
+    invocation_list.append('-D')
+
   # Run buildout without reading user defaults
   invocation_list.append('-U')
   invocation_list.extend(additional_buildout_parameter_list)
@@ -317,8 +335,7 @@ def launchBuildout(path, buildout_binary, logger,
                                 cwd=path,
                                 env=getCleanEnvironment(logger=logger,
                                                         home_path=path),
-                                stdout=subprocess.PIPE,
-                                stderr=subprocess.STDOUT,
+                                debug=debug,
                                 logger=logger)
     if process_handler.returncode is None or process_handler.returncode != 0:
       message = 'Failed to run buildout profile in directory %r' % path

slapos/tests/cli.py

@@ -33,6 +33,7 @@ import StringIO
 import sys
 
 from mock import patch, create_autospec
+import mock
 
 import slapos.cli.console
 import slapos.cli.entry
@@ -81,6 +82,66 @@ product2 url2"""
         {}
     )
 
+class TestCliNode(CliMixin):
+
+  def test_node_software(self):
+    """slapos node software command
+    """
+    app = slapos.cli.entry.SlapOSApp()
+
+    software_release = mock.MagicMock()
+    software_release.getState = mock.Mock(return_value='available')
+    software_release.getURI = mock.Mock(return_value='http://example.org/software.cfg')
+    software_release.building = mock.Mock()
+
+    computer = mock.MagicMock()
+    computer.getSoftwareReleaseList = mock.Mock(return_value=[software_release])
+
+    software = mock.MagicMock()
+    from slapos.grid.slapgrid import Slapgrid
+    from slapos.slap.slap import slap
+    with patch('slapos.cli.slapgrid.check_root_user', return_value=True) as checked_root_user, \
+         patch('slapos.cli.slapgrid.setRunning') as write_pid_file, \
+         patch.object(Slapgrid, 'checkEnvironmentAndCreateStructure') as checkEnvironmentAndCreateStructure, \
+         patch.object(slap, 'registerComputer', return_value=computer) as registerComputer, \
+         patch('slapos.grid.slapgrid.Software', return_value=software) as Software, \
+         patch('slapos.grid.slapgrid.open') as _open:
+
+      app.run(('node', 'software'))
+
+      checked_root_user.assert_called_once()
+      write_pid_file.assert_called_once_with(
+          logger=mock.ANY,
+          pidfile='/opt/slapos/slapgrid-sr.pid')
+      checkEnvironmentAndCreateStructure.assert_called_once()
+      registerComputer.assert_called_once()
+
+      software_constructor_call, = Software.call_args_list
+      self.assertEqual('http://example.org/software.cfg', software_constructor_call[1]['url'])
+      # by default software are not built in debug mode
+      self.assertFalse(software_constructor_call[1]['buildout_debug'])
+
+      software.install.assert_called_once()
+
+  def test_node_instance(self):
+    """slapos node instance command
+    """
+    app = slapos.cli.entry.SlapOSApp()
+
+    from slapos.grid.slapgrid import Slapgrid
+    with patch('slapos.cli.slapgrid.check_root_user', return_value=True) as checked_root_user, \
+         patch('slapos.cli.slapgrid.setRunning') as write_pid_file, \
+         patch.object(Slapgrid, 'processComputerPartitionList') as processComputerPartitionList:
+
+      app.run(('node', 'instance'))
+
+      checked_root_user.assert_called_once()
+      write_pid_file.assert_called_once_with(
+          logger=mock.ANY,
+          pidfile='/opt/slapos/slapgrid-cp.pid')
+      processComputerPartitionList.assert_called_once()
+
+
 class TestCliList(CliMixin):
   def test_list(self):
     """
@@ -185,7 +246,7 @@ master_url=null
         sys.stdout = app_stdout = StringIO.StringIO()
         app.run(('console', '--cfg', self.config_file.name))
       finally:
-        sys.sdin = saved_stdin
+        sys.stdin = saved_stdin
         sys.stdout = saved_stdout
 
       self.mock_request.assert_called_once_with('software_release', 'instance')

slapos/tests/grid_utils.py

+##############################################################################
+#
+# Copyright (c) 2018 Vifib SARL and Contributors. All Rights Reserved.
+#
+# WARNING: This program as such is intended to be used by professional
+# programmers who take the whole responsibility of assessing all potential
+# consequences resulting from its eventual inadequacies and bugs
+# End users who are looking for a ready-to-use solution with commercial
+# guarantees and support are strongly adviced to contract a Free Software
+# Service Company
+#
+# This program is Free Software; you can redistribute it and/or
+# modify it under the terms of the GNU General Public License
+# as published by the Free Software Foundation; either version 3
+# of the License, or (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
+#
+##############################################################################
+import os
+import sys
+import tempfile
+import unittest
+import logging
+import mock
+
+
+import slapos.grid.utils
+
+
+class SlapPopenTestCase(unittest.TestCase):
+  def setUp(self):
+    self.script = tempfile.NamedTemporaryFile(delete=False)
+    # make executable
+    os.chmod(self.script.name, 0o777)
+
+  def tearDown(self):
+    os.unlink(self.script.name)
+
+  def test_exec(self):
+    """Test command execution with SlapPopen.
+    """
+    self.script.write('#!/bin/sh\necho "hello"\nexit 123')
+    self.script.close()
+
+    logger = mock.MagicMock()
+    program = slapos.grid.utils.SlapPopen(
+        self.script.name,
+        logger=logger)
+
+    # error code and output are returned
+    self.assertEqual(123, program.returncode)
+    self.assertEqual('hello\n', program.output)
+
+    # output is also logged "live"
+    logger.info.assert_called_with('hello')
+
+  def test_debug(self):
+    """Test debug=True, which keeps interactive.
+    """
+    self.script.write('#!/bin/sh\necho "exit code?"\nread rc\nexit $rc')
+    self.script.close()
+
+    # keep a reference to stdin and stdout to restore them later
+    stdin_backup = os.dup(sys.stdin.fileno())
+    stdout_backup = os.dup(sys.stdout.fileno())
+
+    # replace stdin with a pipe that will write 123
+    child_stdin_r, child_stdin_w = os.pipe()
+    os.write(child_stdin_w, "123")
+    os.close(child_stdin_w)
+    os.dup2(child_stdin_r, sys.stdin.fileno())
+
+    # and stdout with the pipe to capture output
+    child_stdout_r, child_stdout_w = os.pipe()
+    os.dup2(child_stdout_w, sys.stdout.fileno())
+
+    try:
+      program = slapos.grid.utils.SlapPopen(
+          self.script.name,
+          debug=True,
+          logger=logging.getLogger())
+      # program output
+      self.assertEqual('exit code?\n', os.read(child_stdout_r, 1024))
+
+      self.assertEqual(123, program.returncode)
+      self.assertEqual('(output not captured in debug mode)', program.output)
+    finally:
+      # restore stdin & stderr
+      os.dup2(stdin_backup, sys.stdin.fileno())
+      os.dup2(stdout_backup, sys.stdout.fileno())
+      # close all fds open for the test
+      for fd in (child_stdin_r, child_stdout_r, child_stdout_w, stdin_backup, stdout_backup):
+        os.close(fd)
+
+