Add message from grandchild to parent to indicate successful host launch.

remoting/host/linux/linux_me2me_host.py

 #!/usr/bin/python
 # Copyright (c) 2012 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 # Virtual Me2Me implementation.  This script runs and manages the processes
 # required for a Virtual Me2Me desktop, which are: X server, X desktop
 # session, and Host process.
 # This script is intended to run continuously as a background daemon
 # process, running under an ordinary (non-root) user account.
@@ skipping 494 matching lines @@
     if self.ssh_auth_sockname:
       args.append("--ssh-auth-sockname=%s" % self.ssh_auth_sockname)
 
     # Have the host process use SIGUSR1 to signal a successful start.
     def sigusr1_handler(signum, frame):
       _ = signum, frame
       logging.info("Host ready to receive connections.")
       self.host_ready = True
       if (ParentProcessLogger.instance() and
           False not in [desktop.host_ready for desktop in g_desktops]):
-        ParentProcessLogger.instance().release_parent()
+        ParentProcessLogger.instance().release_parent(True)
 
     signal.signal(signal.SIGUSR1, sigusr1_handler)
     args.append("--signal-parent")
 
     self.host_proc = subprocess.Popen(args, env=self.child_env,
                                       stdin=subprocess.PIPE)
     logging.info(args)
     if not self.host_proc.pid:
       raise Exception("Could not start Chrome Remote Desktop host")
 
@@ skipping 149 matching lines @@
     # Ensure write_pipe is closed on exec, otherwise it will be kept open by
     # child processes (X, host), preventing the read pipe from EOF'ing.
     old_flags = fcntl.fcntl(write_pipe, fcntl.F_GETFD)
     fcntl.fcntl(write_pipe, fcntl.F_SETFD, old_flags | fcntl.FD_CLOEXEC)
     self._read_file = os.fdopen(read_pipe, 'r')
     self._write_file = os.fdopen(write_pipe, 'w')
     self._logging_handler = None
     ParentProcessLogger.__instance = self
 
   def start_logging(self):
-    """Installs a logging handler that sends log entries to a pipe.
+    """Installs a logging handler that sends log entries to a pipe, prefixed
+    with the string 'MSG:'. This allows them to be distinguished by the parent
+    process from commands sent over the same pipe.
 
     Must be called by the child process.
     """
     self._read_file.close()
     self._logging_handler = logging.StreamHandler(self._write_file)
+    self._logging_handler.setFormatter(logging.Formatter(fmt='MSG:%(message)s'))
     logging.getLogger().addHandler(self._logging_handler)
 
-  def release_parent(self):
+  def release_parent(self, success):
     """Uninstalls logging handler and closes the pipe, releasing the parent.
 
     Must be called by the child process.
+
+    success: If true, write a "host ready" message to the parent process before
+             closing the pipe.
     """
     if self._logging_handler:
       logging.getLogger().removeHandler(self._logging_handler)
       self._logging_handler = None
+    if success:
+      self._write_file.write("READY\n")
+      self._write_file.flush()
     if not self._write_file.closed:
       self._write_file.close()
 
   def wait_for_logs(self):
     """Waits and prints log lines from the daemon until the pipe is closed.
 
     Must be called by the parent process.

[Lambros, 2016/02/10 19:43:32]

Document the return value (maybe in a "Returns:" section).

[Jamie, 2016/02/11 00:00:22]

Done.

     """
     # If Ctrl-C is pressed, inform the user that the daemon is still running.
     # This signal will cause the read loop below to stop with an EINTR IOError.
     def sigint_handler(signum, frame):
       _ = signum, frame
       print("Interrupted. The daemon is still running in the background.",
             file=sys.stderr)
 
     signal.signal(signal.SIGINT, sigint_handler)
 
     # Install a fallback timeout to release the parent process, in case the
     # daemon never responds (e.g. host crash-looping, daemon killed).
     # This signal will cause the read loop below to stop with an EINTR IOError.
     def sigalrm_handler(signum, frame):
       _ = signum, frame
       print("No response from daemon. It may have crashed, or may still be "
             "running in the background.", file=sys.stderr)
 
     signal.signal(signal.SIGALRM, sigalrm_handler)
     signal.alarm(30)
 
     self._write_file.close()
 
     # Print lines as they're logged to the pipe until EOF is reached or readline
     # is interrupted by one of the signal handlers above.
+    host_ready = False
     try:
       for line in iter(self._read_file.readline, ''):
-        sys.stderr.write(line)
+        if line[:4] == "MSG:":
+          sys.stderr.write(line[4:])
+        elif line == "READY\n":
+          host_ready = True
+        else:
+          sys.stderr.write("Unrecognized command: " + line)
     except IOError as e:
       if e.errno != errno.EINTR:
         raise
     print("Log file: %s" % os.environ[LOG_FILE_ENV_VAR], file=sys.stderr)
+    return host_ready
 
   @staticmethod
   def instance():
     """Returns the singleton instance, if it exists."""
     return ParentProcessLogger.__instance
 
 
 def daemonize():
   """Background this process and detach from controlling terminal, redirecting
   stdout/stderr to a log file."""
@@ skipping 38 matching lines @@
     pid = os.fork()
 
     if pid == 0:
       # Grandchild process
       pass
     else:
       # Child process
       os._exit(0)  # pylint: disable=W0212
   else:
     # Parent process
-    parent_logger.wait_for_logs()
-    os._exit(0)  # pylint: disable=W0212
+    if parent_logger.wait_for_logs():
+      os._exit(0)  # pylint: disable=W0212
+    else:
+      os._exit(1)  # pylint: disable=W0212

[Lambros, 2016/02/10 19:43:32]

What will happen in the case of timeout after 30 seconds?
I don't know if we fail and deregister the host if the timeout is exceeded?
It has been known to sometimes take more than 30 seconds to start the desktop
session and host process and successfully make an XMPP connection.
I think we "fixed" this by increasing the DaemonControllerDelegateLinux timeout
to 60s. But now DaemonControllerDelegateLinux no longer applies any timeout, so
we could probably get away with increasing the timeout here from 30 to 60
seconds?

[Jamie, 2016/02/11 00:00:22]

According to the comment on line 733, the read loop will exit with EINTR, which
I think propagates an exception to the top level, which will then exit with a
non-zero code. I believe the web-app is responsible for unregistering the host
in that case.
That feels like a separate bug. If you think that's the right call, I'm happy to
do a follow-up CL for it. However, I'm also considering removing the wait logic
from this script altogether, and adding code to the web-app to wait for a
heartbeat before reporting a host as on-line. That will be cross platform, but
will require polling, so it's less elegant than the solution we have right now
for Linux.

[Lambros, 2016/02/11 21:46:02]

My reading of the old code is that, after the 30s timeout, the loop would exit
with EINTR, and the exception is swallowed (if-statement on line 737 of original
file). Then the process exits with code 0 and so the web-app assumes the host is
registered, and therefore doesn't delete the registration.

Now you're returning host_ready which is False in the case of timeout, you're
exiting the process with code 1 and the web-app will now delete the host
registration. So this CL introduces an extra chance of incorrect
de-registration.

[Jamie, 2016/02/12 18:32:11]

Good point. I've removed the timeout from this script.

 
   logging.info("Daemon process started in the background, logging to '%s'" %
                os.environ[LOG_FILE_ENV_VAR])
 
   os.chdir(HOME_DIR)
 
   parent_logger.start_logging()
 
   # Copy the file-descriptors to create new stdin, stdout and stderr.  Note
   # that dup2(oldfd, newfd) closes newfd first, so this will close the current
@@ skipping 25 matching lines @@
           # process refuses to die for some reason.
           psutil_proc.wait(timeout=10)
         except psutil.TimeoutExpired:
           logging.error("Timed out - sending SIGKILL")
           psutil_proc.kill()
         except psutil.Error:
           logging.error("Error terminating process")
 
   g_desktops = []
   if ParentProcessLogger.instance():
-    ParentProcessLogger.instance().release_parent()
+    ParentProcessLogger.instance().release_parent(False)
 
 class SignalHandler:
   """Reload the config file on SIGHUP. Since we pass the configuration to the
   host processes via stdin, they can't reload it, so terminate them. They will
   be relaunched automatically with the new config."""
 
   def __init__(self, host_config):
     self.host_config = host_config
 
   def __call__(self, signum, _stackframe):
@@ skipping 518 matching lines @@
         else:
           logging.info("Host exited with status %s." % os.WEXITSTATUS(status))
       elif os.WIFSIGNALED(status):
         logging.info("Host terminated by signal %s." % os.WTERMSIG(status))
 
 
 if __name__ == "__main__":
   logging.basicConfig(level=logging.DEBUG,
                       format="%(asctime)s:%(levelname)s:%(message)s")
   sys.exit(main())