Always log into stdout. ALWAYS.

In order to do that, always use logger, and always in real time.
Logger is properly configured.
Then remove -c switch (kept in parameters but doesn't do anything).
Also factor code of whole slapos/grid directory about SlapPopen (now does the
log).

slapos/grid/SlapObject.py

@@ -50,7 +50,7 @@ REQUIRED_COMPUTER_PARTITION_PERMISSION = '0750'
 
 class Software(object):
   """This class is responsible of installing a software release"""
-  def __init__(self, url, software_root, console, buildout,
+  def __init__(self, url, software_root, buildout,
       signature_private_key_file=None, signature_certificate_list=None,
       upload_cache_url=None, upload_dir_url=None, shacache_cert_file=None,
       shacache_key_file=None, shadir_cert_file=None, shadir_key_file=None,
@@ -67,7 +67,6 @@ class Software(object):
                                       self.software_url_hash)
     self.buildout = buildout
     self.logger = logging.getLogger('BuildoutManager')
-    self.console = console
     self.signature_private_key_file = signature_private_key_file
     self.signature_certificate_list = signature_certificate_list
     self.upload_cache_url = upload_cache_url
@@ -185,12 +184,10 @@ class Software(object):
 
       buildout_parameter_list.extend(['-c', self.url])
       utils.bootstrapBuildout(self.software_path, self.buildout,
-          additional_buildout_parametr_list=buildout_parameter_list,
-          console=self.console)
+          additional_buildout_parametr_list=buildout_parameter_list)
       utils.launchBuildout(self.software_path,
                      os.path.join(self.software_path, 'bin', 'buildout'),
-                     additional_buildout_parametr_list=buildout_parameter_list,
-                     console=self.console)
+                     additional_buildout_parametr_list=buildout_parameter_list)
     finally:
       shutil.rmtree(extends_cache)
 
@@ -231,7 +228,6 @@ class Partition(object):
                software_release_url,
                buildout,
                certificate_repository_path=None,
-               console=False
                ):
     """Initialisation of class parameters"""
     self.buildout = buildout
@@ -248,7 +244,6 @@ class Partition(object):
     self.partition_id = partition_id
     self.server_url = server_url
     self.software_release_url = software_release_url
-    self.console = console
 
     self.key_file = ''
     self.cert_file = ''
@@ -378,18 +373,12 @@ class Partition(object):
       invocation_list.append(bootstrap_file)
       self.logger.debug('Invoking %r in %r' % (' '.join(invocation_list),
         self.instance_path))
-      kw = dict()
-      if not self.console:
-        kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+      kw = dict(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
       process_handler = utils.SlapPopen(invocation_list,
         preexec_fn=lambda: utils.dropPrivileges(uid, gid), cwd=self.instance_path,
         env=utils.getCleanEnvironment(pwd.getpwuid(uid).pw_dir), **kw)
-      result_std = process_handler.communicate()[0]
-      if self.console:
-        result_std = 'Please consult messages above.'
       if process_handler.returncode is None or process_handler.returncode != 0:
-        message = 'Failed to bootstrap buildout in %r:\n%s\n' % (
-            self.instance_path, result_std)
+        message = 'Failed to bootstrap buildout in %r.' % (self.instance_path)
         raise BuildoutFailedError(message)
       buildout_binary = os.path.join(self.instance_path, 'sbin', 'buildout')
 
@@ -397,11 +386,10 @@ class Partition(object):
       # use own buildout generation
       utils.bootstrapBuildout(self.instance_path, self.buildout,
         ['buildout:bin-directory=%s'% os.path.join(self.instance_path,
-        'sbin')], console=self.console)
+        'sbin')])
       buildout_binary = os.path.join(self.instance_path, 'sbin', 'buildout')
     # Launches buildout
-    utils.launchBuildout(self.instance_path,
-                   buildout_binary, console=self.console)
+    utils.launchBuildout(self.instance_path, buildout_binary)
     # Generates supervisord configuration file from template
     self.logger.info("Generating supervisord config file from template...")
     # check if CP/etc/run exists and it is a directory
@@ -484,17 +472,13 @@ class Partition(object):
       gid = stat_info.st_gid
       self.logger.debug('Invoking %r' % destroy_executable_location)
       kw = dict()
-      if not self.console:
-        kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+      kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
       process_handler = utils.SlapPopen([destroy_executable_location],
         preexec_fn=lambda: utils.dropPrivileges(uid, gid), cwd=self.instance_path,
         env=utils.getCleanEnvironment(pwd.getpwuid(uid).pw_dir), **kw)
-      result_std = process_handler.communicate()[0]
-      if self.console:
-        result_std = 'Please consult messages above'
       if process_handler.returncode is None or process_handler.returncode != 0:
-        message = 'Failed to destroy Computer Partition in %r:\n%s\n' % (
-            self.instance_path, result_std)
+        message = 'Failed to destroy Computer Partition in %r.' % \
+            self.instance_path
         raise subprocess.CalledProcessError(message)
     # Manually cleans what remains
     try:

slapos/grid/slapgrid.py

@@ -108,7 +108,7 @@ def parseArgumentTupleAndReturnSlapgridObject(*argument_tuple):
   parser.add_argument("--certificate_repository_path",
       help="Path to directory where downloaded certificates would be stored.")
   parser.add_argument("-c", "--console", action="store_true", default=False,
-      help="Enables console output and live output from subcommands.")
+      help="Deprecated, doesn't do anything.")
   parser.add_argument("-v", "--verbose", action="store_true", default=False,
       help="Be verbose.")
   parser.add_argument("--maximum-periodicity", type=int, default=None,
@@ -158,16 +158,20 @@ def parseArgumentTupleAndReturnSlapgridObject(*argument_tuple):
     if argument_value is not None:
       option_dict.update({argument_key: argument_value})
   # Configures logger.
-  logger_format = '%(asctime)s %(name)-18s: %(levelname)-8s %(message)s'
   if option_dict['verbose']:
     level = logging.DEBUG
   else:
     level = logging.INFO
+  logging.basicConfig(format='%(asctime)s %(levelname)-8s %(message)s',
+                      level=level,
+                      datefmt='%Y-%m-%dT%H:%M:%S')
   if option_dict.get('logfile'):
-    logging.basicConfig(filename=option_dict['logfile'],
-      format=logger_format, level=level)
-  if option_dict['console']:
-    logging.basicConfig(level=level)
+    console = logging.FileHandler(option_dict['logfile'])
+    console.setLevel(level)
+    console.setFormatter(logging.Formatter(
+        '%(asctime)s %(name)-18s: %(levelname)-8s %(message)s'))
+    logging.getLogger('').addHandler(console)
+
   missing_mandatory_parameter_list = []
   for mandatory_parameter in MANDATORY_PARAMETER_LIST:
     if not mandatory_parameter in option_dict:
@@ -294,7 +298,6 @@ def parseArgumentTupleAndReturnSlapgridObject(*argument_tuple):
             upload_binary_dir_url=\
               option_dict.get('upload-binary-dir-url', None),
             upload_dir_url=option_dict.get('upload-dir-url', None),
-            console=option_dict['console'],
             buildout=option_dict.get('buildout'),
             promise_timeout=option_dict['promise_timeout'],
             shacache_cert_file=option_dict.get('shacache-cert-file', None),
@@ -390,7 +393,6 @@ class Slapgrid(object):
                upload_dir_url=None,
                master_ca_file=None,
                certificate_repository_path=None,
-               console=False,
                promise_timeout=3,
                shacache_cert_file=None,
                shacache_key_file=None,
@@ -439,7 +441,6 @@ class Slapgrid(object):
     self.instance_etc_directory = os.path.join(self.instance_root, 'etc')
     self.supervisord_configuration_directory = \
         os.path.join(self.instance_etc_directory, 'supervisord.conf.d')
-    self.console = console
     self.buildout = buildout
     self.promise_timeout = promise_timeout
     self.develop = develop
@@ -526,7 +527,7 @@ class Slapgrid(object):
         software_path = os.path.join(self.software_root, url_hash)
         software = Software(url=software_release_uri,
             software_root=self.software_root,
-            console=self.console, buildout=self.buildout,
+            buildout=self.buildout,
             signature_private_key_file=self.signature_private_key_file,
             signature_certificate_list=self.signature_certificate_list,
             download_binary_cache_url=self.download_binary_cache_url,
@@ -730,7 +731,7 @@ class Slapgrid(object):
       server_url=self.master_url,
       software_release_url=software_url,
       certificate_repository_path=self.certificate_repository_path,
-      console=self.console, buildout=self.buildout)
+      buildout=self.buildout)
 
     computer_partition_state = computer_partition.getState()
     if computer_partition_state == "started":
@@ -972,24 +973,17 @@ class Slapgrid(object):
           #stat sys call to get statistics informations
           uid = stat_info.st_uid
           gid = stat_info.st_gid
-          kw = dict()
-          if not self.console:
-            kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+          kw = dict(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
           process_handler = SlapPopen(invocation_list,
             preexec_fn=lambda: dropPrivileges(uid, gid),
             cwd=os.path.join(instance_path, 'etc', 'report'),
             env=None, **kw)
-          result = process_handler.communicate()[0]
-          if self.console:
-            result = 'Please consult messages above'
           if process_handler.returncode is None:
             process_handler.kill()
           if process_handler.returncode != 0:
             clean_run = False
-            failed_script_list.append("Script %r failed with %s." % (script,
-                result))
-            logger.warning("Failed to run %r, the result was. \n%s" %
-              (invocation_list, result))
+            failed_script_list.append("Script %r failed." % script)
+            logger.warning("Failed to run %r" % invocation_list)
           if len(failed_script_list):
             computer_partition.error('\n'.join(failed_script_list))
       # Whatever happens, don't stop processing other instances
@@ -1102,7 +1096,7 @@ class Slapgrid(object):
             server_url=self.master_url,
             software_release_url=software_url,
             certificate_repository_path=self.certificate_repository_path,
-            console=self.console, buildout=self.buildout
+            buildout=self.buildout,
             )
           local_partition.stop()
           try:

slapos/grid/utils.py

@@ -90,7 +90,9 @@ class AlreadyRunning(Exception):
 
 
 class SlapPopen(subprocess.Popen):
-  """Almost normal subprocess with gridish features"""
+  """
+  Almost normal subprocess with greedish features and logging.
+  """
   def __init__(self, *args, **kwargs):
     kwargs.update(stdin=subprocess.PIPE)
     subprocess.Popen.__init__(self, *args, **kwargs)
@@ -98,6 +100,15 @@ class SlapPopen(subprocess.Popen):
     self.stdin.close()
     self.stdin = None
 
+    logger = logging.getLogger('SlapProcessManager')
+    while True:
+      line = self.stdout.readline()
+      if line == '' and self.poll() != None:
+        break
+      if line[-1:] == '\n':
+        line = line[:-1]
+      logger.info(line)
+
 
 def getSoftwareUrlHash(url):
   return md5(url).hexdigest()
@@ -171,6 +182,8 @@ def dropPrivileges(uid, gid):
   Does nothing in case if uid and gid are not 0
   """
   logger = logging.getLogger('dropPrivileges')
+  # XXX-Cedric: remove format / just do a print, otherwise formatting is done
+  # twice
   current_uid, current_gid = os.getuid(), os.getgid()
   if uid == 0 or gid == 0:
     raise OSError('Dropping privileges to uid = %r or ' \
@@ -217,11 +230,11 @@ def dropPrivileges(uid, gid):
   else:
     raise ValueError('%s it was possible to go back to uid = %r and gid = '
         '%r which is fatal.' % (message_pre, current_uid, current_gid))
-  logger.info('Succesfully dropped privileges to uid=%r gid=%r' % (uid, gid))
+  logger.debug('Succesfully dropped privileges to uid=%r gid=%r' % (uid, gid))
 
 
 def bootstrapBuildout(path, buildout=None,
-    additional_buildout_parametr_list=None, console=False):
+    additional_buildout_parametr_list=None):
   if additional_buildout_parametr_list is None:
     additional_buildout_parametr_list = []
   logger = logging.getLogger('BuildoutManager')
@@ -258,20 +271,14 @@ def bootstrapBuildout(path, buildout=None,
     logger.debug('Set umask from %03o to %03o' % (umask, SAFE_UMASK))
     logger.debug('Invoking: %r in directory %r' % (' '.join(invocation_list),
       path))
-    if not console:
-      kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+    kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
     process_handler = SlapPopen(invocation_list,
             preexec_fn=lambda: dropPrivileges(uid, gid),
             cwd=path, **kw)
-    result = process_handler.communicate()[0]
-    if console:
-      result = 'Please consult messages above'
+
     if process_handler.returncode is None or process_handler.returncode != 0:
-      message = 'Failed to run buildout profile in directory %r:\n%s\n' % (
-          path, result)
+      message = 'Failed to run buildout profile in directory %r.\n' % (path)
       raise BuildoutFailedError(message)
-    else:
-      logger.debug('Successful run:\n%s' % result)
   except OSError as error:
     raise BuildoutFailedError(error)
   finally:
@@ -280,7 +287,7 @@ def bootstrapBuildout(path, buildout=None,
 
 
 def launchBuildout(path, buildout_binary,
-                   additional_buildout_parametr_list=None, console=False):
+                   additional_buildout_parametr_list=None):
   """ Launches buildout."""
   logger = logging.getLogger('BuildoutManager')
   if additional_buildout_parametr_list is None:
@@ -306,21 +313,13 @@ def launchBuildout(path, buildout_binary,
     logger.debug('Set umask from %03o to %03o' % (umask, SAFE_UMASK))
     logger.debug('Invoking: %r in directory %r' % (' '.join(invocation_list),
       path))
-    kw = dict()
-    if not console:
-      kw.update(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+    kw = dict(stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
     process_handler = SlapPopen(invocation_list,
             preexec_fn=lambda: dropPrivileges(uid, gid), cwd=path,
             env=getCleanEnvironment(pwd.getpwuid(uid).pw_dir), **kw)
-    result = process_handler.communicate()[0]
-    if console:
-      result = 'Please consult messages above'
     if process_handler.returncode is None or process_handler.returncode != 0:
-      message = 'Failed to run buildout profile in directory %r:\n%s\n' % (
-          path, result)
+      message = 'Failed to run buildout profile in directory %r\n' % (path)
       raise BuildoutFailedError(message)
-    else:
-      logger.debug('Successful run:\n%s' % result)
   except OSError as error:
     raise BuildoutFailedError(error)
   finally: