enable debug logging and add a bunch more tracing

bubblewrap.c

@@ -503,6 +503,8 @@ monitor_child (int event_fd, pid_t child_pid, int setup_finished_fd)
   pid_t died_pid;
   int died_status;
 
+  __debug__(("monitor_child(%d, %d, %d)\n", event_fd, child_pid, setup_finished_fd));
+
   /* Close all extra fds in the monitoring process.
      Any passed in fds have been passed on to the child anyway. */
   if (event_fd != -1)
@@ -594,6 +596,8 @@ do_init (int event_fd, pid_t initial_pid)
   int initial_exit_status = 1;
   LockFile *lock;
 
+  __debug__(("do_init\n"));
+
   for (lock = lock_files; lock != NULL; lock = lock->next)
     {
       int fd = open (lock->path, O_RDONLY | O_CLOEXEC);
@@ -682,6 +686,8 @@ set_required_caps (void)
   struct __user_cap_header_struct hdr = { _LINUX_CAPABILITY_VERSION_3, 0 };
   struct __user_cap_data_struct data[2] = { { 0 } };
 
+  __debug__(("set_required_caps\n"));
+
   /* Drop all non-require capabilities */
   data[0].effective = REQUIRED_CAPS_0;
   data[0].permitted = REQUIRED_CAPS_0;
@@ -699,6 +705,8 @@ drop_all_caps (bool keep_requested_caps)
   struct __user_cap_header_struct hdr = { _LINUX_CAPABILITY_VERSION_3, 0 };
   struct __user_cap_data_struct data[2] = { { 0 } };
 
+  __debug__(("drop_all_caps(%d)\n", keep_requested_caps));
+
   if (keep_requested_caps)
     {
       /* Avoid calling capset() unless we need to; currently
@@ -778,6 +786,7 @@ prctl_caps (uint32_t *caps, bool do_cap_bounding, bool do_set_ambient)
       if (keep && do_set_ambient)
         {
 #ifdef PR_CAP_AMBIENT
+          __debug__(("prctl (PR_CAP_AMBIENT, PR_CAP_AMBENT_RAISE, %ld, 0, 0)\n", cap));
           int res = prctl (PR_CAP_AMBIENT, PR_CAP_AMBIENT_RAISE, cap, 0, 0);
           if (res == -1 && !(errno == EINVAL || errno == EPERM))
             die_with_error ("Adding ambient capability %ld", cap);
@@ -790,6 +799,7 @@ prctl_caps (uint32_t *caps, bool do_cap_bounding, bool do_set_ambient)
 
       if (!keep && do_cap_bounding)
         {
+          __debug__(("prctl (PR_CAPBSET_DROP, %ld, 0, 0, 0)\n", cap));
           int res = prctl (PR_CAPBSET_DROP, cap, 0, 0, 0);
           if (res == -1 && !(errno == EINVAL || errno == EPERM))
             die_with_error ("Dropping capability %ld from bounds", cap);
@@ -800,6 +810,7 @@ prctl_caps (uint32_t *caps, bool do_cap_bounding, bool do_set_ambient)
 static void
 drop_cap_bounding_set (bool drop_all)
 {
+  __debug__(("drop_cap_bounding_set(%d)\n", drop_all));
   if (!drop_all)
     prctl_caps (requested_caps, TRUE, FALSE);
   else
@@ -812,6 +823,7 @@ drop_cap_bounding_set (bool drop_all)
 static void
 set_ambient_capabilities (void)
 {
+  __debug__(("set_ambient_capabilities\n"));
   if (is_privileged)
     return;
   prctl_caps (requested_caps, FALSE, TRUE);
@@ -837,6 +849,7 @@ acquire_privs (void)
   uid_t euid, new_fsuid;
 
   euid = geteuid ();
+  __debug__(("acquire_privs: euid=%d, real_uid=%d\n", euid, real_uid));
 
   /* Are we setuid ? */
   if (real_uid != euid)
@@ -900,6 +913,7 @@ acquire_privs (void)
 static void
 switch_to_user_with_privs (void)
 {
+  __debug__(("switch_to_user_with_privs\n"));
   /* If we're in a new user namespace, we got back the bounding set, clear it again */
   if (opt_unshare_user || opt_userns_fd != -1)
     drop_cap_bounding_set (FALSE);
@@ -934,6 +948,7 @@ drop_privs (bool keep_requested_caps,
             bool already_changed_uid)
 {
   assert (!keep_requested_caps || !is_privileged);
+  __debug__(("drop_privs(%d, %d)\n", keep_requested_caps, already_changed_uid));
   /* Drop root uid */
   if (is_privileged && !already_changed_uid &&
       setuid (opt_sandbox_uid) < 0)
@@ -1170,6 +1185,7 @@ setup_newroot (bool unshare_pid,
                int  privileged_op_socket)
 {
   SetupOp *op;
+  __debug__(("setup_newroot(%d, %d)\n", unshare_pid, privileged_op_socket));
 
   for (op = ops; op != NULL; op = op->next)
     {
@@ -2773,6 +2789,31 @@ main (int    argc,
   if (argc <= 0)
     usage (EXIT_FAILURE, stderr);
 
+  __debug__(("initial resolved options:\n"));
+  __debug__(("  opt_disable_userns: %d\n", opt_disable_userns));
+  __debug__(("  opt_unshare_user: %d\n", opt_unshare_user));
+  __debug__(("  opt_unshare_user_try: %d\n", opt_unshare_user_try));
+  __debug__(("  opt_unshare_pid: %d\n", opt_unshare_pid));
+  __debug__(("  opt_unshare_ipc: %d\n", opt_unshare_ipc));
+  __debug__(("  opt_unshare_net: %d\n", opt_unshare_net));
+  __debug__(("  opt_unshare_uts: %d\n", opt_unshare_uts));
+  __debug__(("  opt_unshare_cgroup: %d\n", opt_unshare_cgroup));
+  __debug__(("  opt_unshare_cgroup_try: %d\n", opt_unshare_cgroup_try));
+  __debug__(("  opt_needs_devpts: %d\n", opt_needs_devpts));
+  __debug__(("  opt_new_session: %d\n", opt_new_session));
+  __debug__(("  opt_die_with_parent: %d\n", opt_die_with_parent));
+  __debug__(("  opt_sandbox_uid: %d\n", opt_sandbox_uid));
+  __debug__(("  opt_sandbox_gid: %d\n", opt_sandbox_gid));
+  __debug__(("  opt_sync_fd: %d\n", opt_sync_fd));
+  __debug__(("  opt_block_fd: %d\n", opt_block_fd));
+  __debug__(("  opt_userns_block_fd: %d\n", opt_userns_block_fd));
+  __debug__(("  opt_info_fd: %d\n", opt_info_fd));
+  __debug__(("  opt_json_status_fd: %d\n", opt_json_status_fd));
+  __debug__(("  opt_seccomp_fd: %d\n", opt_seccomp_fd));
+  __debug__(("  opt_userns_fd: %d\n", opt_userns_fd));
+  __debug__(("  opt_userns2_fd: %d\n", opt_userns2_fd));
+  __debug__(("  opt_pidns_fd: %d\n", opt_pidns_fd));
+
   __debug__ (("Creating root mount point\n"));
 
   if (opt_sandbox_uid == (uid_t)-1)
@@ -2864,6 +2905,7 @@ main (int    argc,
     }
 
   /* Switch to the custom user ns before the clone, gets us privs in that ns (assuming its a child of the current and thus allowed) */
+  __debug__(("maybe(if > 0): setns(%d, CLONE_NEWUSER)\n", opt_userns_fd));
   if (opt_userns_fd > 0 && setns (opt_userns_fd, CLONE_NEWUSER) != 0)
     {
       if (errno == EINVAL)
@@ -2875,10 +2917,12 @@ main (int    argc,
   if (opt_pidns_fd != -1)
     {
       /* Mark us as a subreaper, this way we can get exit status from grandchildren */
+      __debug__(("prctl(PR_SET_CHILD_SUBREAPER, 1, 0, 0, 0)\n"));
       prctl (PR_SET_CHILD_SUBREAPER, 1, 0, 0, 0);
       create_pid_socketpair (intermediate_pids_sockets);
     }
 
+  __debug__(("raw_clone(%d, NULL)\n", clone_flags));
   pid = raw_clone (clone_flags, NULL);
   if (pid == -1)
     {
@@ -2930,6 +2974,7 @@ main (int    argc,
 
       /* Initial launched process, wait for pid 1 or exec:ed command to exit */
 
+      __debug__(("maybe(if > 0): setns(%d, CLONE_NEWUSER)\n", opt_userns2_fd));
       if (opt_userns2_fd > 0 && setns (opt_userns2_fd, CLONE_NEWUSER) != 0)
         die_with_error ("Setting userns2 failed");
 
@@ -2973,19 +3018,23 @@ main (int    argc,
 
   if (opt_pidns_fd > 0)
     {
+      __debug__(("setns(%d, CLONE_NEWPID)\n", opt_pidns_fd));
       if (setns (opt_pidns_fd, CLONE_NEWPID) != 0)
         die_with_error ("Setting pidns failed");
 
       /* fork to get the passed in pid ns */
+      __debug__(("fork_intermediate_child()\n"));
       fork_intermediate_child ();
 
       /* We might both have specified an --pidns *and* --unshare-pid, so set up a new child pid namespace under the specified one */
       if (opt_unshare_pid)
         {
+          __debug__(("unshare(CLONE_NEWPID)\n"));
           if (unshare (CLONE_NEWPID))
             die_with_error ("unshare pid ns");
 
           /* fork to get the new pid ns */
+          __debug__(("fork_intermediate_child()\n"));
           fork_intermediate_child ();
         }
 
@@ -3026,8 +3075,10 @@ main (int    argc,
    */
   switch_to_user_with_privs ();
 
-  if (opt_unshare_net)
+  if (opt_unshare_net) {
+    __debug__(("loopback_setup()\n"));
     loopback_setup (); /* Will exit if unsuccessful */
+  }
 
   ns_uid = opt_sandbox_uid;
   ns_gid = opt_sandbox_gid;
@@ -3102,6 +3153,7 @@ main (int    argc,
       if (socketpair (AF_UNIX, SOCK_SEQPACKET | SOCK_CLOEXEC, 0, privsep_sockets) != 0)
         die_with_error ("Can't create privsep socket");
 
+      __debug__(("is_privileged fork()\n"));
       child = fork ();
       if (child == -1)
         die_with_error ("Can't fork unprivileged helper");
@@ -3142,6 +3194,7 @@ main (int    argc,
     }
   else
     {
+      __debug__(("not is_privileged: setup_newroot\n"));
       setup_newroot (opt_unshare_pid, -1);
     }
 
@@ -3185,6 +3238,7 @@ main (int    argc,
       die_with_error ("chdir /");
   }
 
+  __debug__(("maybe(if > 0): setns(%d, CLONE_NEWUSER)\n", opt_userns2_fd));
   if (opt_userns2_fd > 0 && setns (opt_userns2_fd, CLONE_NEWUSER) != 0)
     die_with_error ("Setting userns2 failed");
 
@@ -3217,6 +3271,7 @@ main (int    argc,
             die_with_error ("sysctl user.max_user_namespaces = 1");
         }
 
+      __debug__(("unshare(CLONE_NEWUSER)\n"));
       if (unshare (CLONE_NEWUSER))
         die_with_error ("unshare user ns");
 
@@ -3231,6 +3286,7 @@ main (int    argc,
   if (opt_disable_userns || opt_assert_userns_disabled)
     {
       /* Verify that we can't make a new userns again */
+      __debug__(("unshare(CLONE_NEWUSER)\n"));
       res = unshare (CLONE_NEWUSER);
 
       if (res == 0)
@@ -3296,12 +3352,14 @@ main (int    argc,
        * need some process to own these.
        */
 
+      __debug__(("!opt_as_pid_1: fork()\n"));
       pid = fork ();
       if (pid == -1)
         die_with_error ("Can't fork for pid 1");
 
       if (pid != 0)
         {
+          __debug__(("parent: drop_all_caps(FALSE)\n"));
           drop_all_caps (FALSE);
 
           /* Close fds in pid 1, except stdio and optionally event_fd

utils.h

@@ -31,7 +31,7 @@
 #include <sys/types.h>
 #include <sys/stat.h>
 
-#if 0
+#if 1
 #define __debug__(x) printf x
 #else
 #define __debug__(x)