[gdm/wip/timed-login-fix: 1/3] manager, session: Add some debugging around starting reauthentication

[Ray Strode <halfline src gnome org>]

commit 1c3d450a6204b2caee350f3af6e69bca32c2aaaa
Author: Iain Lane <iainl gnome org>
Date:   Thu Jan 31 10:52:35 2019 +0000

    manager,session: Add some debugging around starting reauthentication
    
    There's a bug right now dealing with timed login and reauthentication,
    but it's not clear what's going on by looking at the logs.
    
    This commit sprinkles some more logging throughout the code, to make
    the bug easier to track.

 daemon/gdm-manager.c | 46 ++++++++++++++++++++++++++++++++++++++++------
 daemon/gdm-session.c | 21 +++++++++++++++++----
 2 files changed, 57 insertions(+), 10 deletions(-)
---
diff --git a/daemon/gdm-manager.c b/daemon/gdm-manager.c
index 2c3d76e2..5fde0b39 100644
--- a/daemon/gdm-manager.c
+++ b/daemon/gdm-manager.c
@@ -336,23 +336,40 @@ find_session_for_user_on_seat (GdmManager *manager,
 
         for (node = manager->priv->user_sessions; node != NULL; node = node->next) {
                 GdmSession *candidate_session = node->data;
-                const char *candidate_username, *candidate_seat_id;
+                const char *candidate_username, *candidate_seat_id, *candidate_session_id;
 
-                if (candidate_session == dont_count_session)
+                candidate_session_id = gdm_session_get_session_id (candidate_session);
+
+                if (candidate_session == dont_count_session) {
+                        g_debug ("GdmSession: Ignoring session %s as requested",
+                                 candidate_session_id);
                         continue;
+                }
 
-                if (!gdm_session_is_running (candidate_session))
+                if (!gdm_session_is_running (candidate_session)) {
+                        g_debug ("GdmSession: Ignoring session %s as it isn't running",
+                                 candidate_session_id);
                         continue;
+                }
 
                 candidate_username = gdm_session_get_username (candidate_session);
                 candidate_seat_id = gdm_session_get_display_seat_id (candidate_session);
 
+                g_debug ("GdmManager: Considering session %s on seat %s belonging to user %s",
+                         candidate_session_id,
+                         candidate_seat_id,
+                         candidate_username);
+
                 if (g_strcmp0 (candidate_username, username) == 0 &&
                     g_strcmp0 (candidate_seat_id, seat_id) == 0) {
+                        g_debug ("GdmManager: yes, found session %s", candidate_session_id);
                         return candidate_session;
                 }
+
+                g_debug ("GdmManager: no, will not use session %s", candidate_session_id);
         }
 
+        g_debug ("GdmManager: no matching sessions found");
         return NULL;
 }
 
@@ -836,8 +853,12 @@ gdm_manager_handle_open_session (GdmDBusManager        *manager,
 #endif
         if (session == NULL) {
                 session = get_user_session_for_display (display);
+                g_debug ("GdmSession: Considering session %s for username %s",
+                         gdm_session_get_session_id (session),
+                         gdm_session_get_username (session));
 
                 if (gdm_session_is_running (session)) {
+                        g_debug ("GdmSession: the session is running, and therefore can't be used");
                         g_dbus_method_invocation_return_error_literal (invocation,
                                                                        G_DBUS_ERROR,
                                                                        G_DBUS_ERROR_ACCESS_DENIED,
@@ -1013,6 +1034,10 @@ open_temporary_reauthentication_channel (GdmManager            *self,
                                    environment);
         g_strfreev (environment);
 
+        g_debug ("GdmSession: Created session for temporary reauthentication channel for user %d (seat %s)",
+                 (int) uid,
+                 seat_id);
+
         g_object_set_data_full (G_OBJECT (session),
                                 "caller-session-id",
                                 g_strdup (session_id),
@@ -1092,11 +1117,13 @@ gdm_manager_handle_open_reauthentication_channel (GdmDBusManager        *manager
         }
 
         if (is_login_screen) {
+                g_debug ("GdmManager: looking for login screen session for user %s on seat %s", username, 
seat_id);
                 session = find_session_for_user_on_seat (self,
                                                          username,
                                                          seat_id,
                                                          NULL);
         } else {
+                g_debug ("GdmManager: looking for user session on display");
                 session = get_user_session_for_display (display);
         }
 
@@ -2049,7 +2076,7 @@ on_session_client_connected (GdmSession      *session,
         gboolean enabled;
         gboolean allow_timed_login = FALSE;
 
-        g_debug ("GdmManager: client connected");
+        g_debug ("GdmManager: client with pid %d connected", (int) pid_of_client);
 
         display = get_display_for_user_session (session);
 
@@ -2095,7 +2122,7 @@ on_session_client_disconnected (GdmSession   *session,
                                 GPid          pid_of_client,
                                 GdmManager   *manager)
 {
-        g_debug ("GdmManager: client disconnected");
+        g_debug ("GdmManager: client with pid %d disconnected", (int) pid_of_client);
 }
 
 typedef struct
@@ -2162,9 +2189,10 @@ on_session_conversation_started (GdmSession *session,
         gboolean    enabled;
         char       *username;
 
-        g_debug ("GdmManager: session conversation started for service %s", service_name);
+        g_debug ("GdmManager: session conversation started for service %s on session", service_name);
 
         if (g_strcmp0 (service_name, "gdm-autologin") != 0) {
+                g_debug ("GdmManager: ignoring session conversation since its not automatic login 
conversation");
                 return;
         }
 
@@ -2274,6 +2302,12 @@ create_user_session_for_display (GdmManager *manager,
                                    display_auth_file,
                                    display_is_local,
                                    NULL);
+
+        g_debug ("GdmSession: Created user session for user %d on display %s (seat %s)",
+                 (int) allowed_user,
+                 display_id,
+                 display_seat_id);
+
         g_free (display_name);
         g_free (remote_hostname);
         g_free (display_auth_file);
diff --git a/daemon/gdm-session.c b/daemon/gdm-session.c
index db95e8c4..f3b4d8e0 100644
--- a/daemon/gdm-session.c
+++ b/daemon/gdm-session.c
@@ -656,7 +656,9 @@ gdm_session_select_user (GdmSession *self,
                          const char *text)
 {
 
-        g_debug ("GdmSession: Setting user: '%s'", text);
+        g_debug ("GdmSession: selecting user '%s' for session '%s'",
+                 text,
+                 gdm_session_get_session_id (self));
 
         g_free (self->selected_user);
         self->selected_user = g_strdup (text);
@@ -1431,6 +1433,7 @@ gdm_session_handle_client_select_user (GdmDBusGreeter        *greeter_interface,
                 gdm_dbus_greeter_complete_select_user (greeter_interface,
                                                        invocation);
         }
+        g_debug ("GdmSession: client selected user '%s'", username);
         gdm_session_select_user (self, username);
         return TRUE;
 }
@@ -1487,7 +1490,9 @@ gdm_session_handle_client_begin_auto_login (GdmDBusGreeter        *greeter_inter
                                                             invocation);
         }
 
-        g_debug ("GdmSession: begin auto login for user '%s'", username);
+        g_debug ("GdmSession: client requesting automatic login for user '%s' on session '%s'",
+                 username,
+                 gdm_session_get_session_id (self));
 
         gdm_session_setup_for_user (self, "gdm-autologin", username);
 
@@ -1788,7 +1793,8 @@ setup_outside_server (GdmSession *self)
         GDBusServer *server;
         GError *error = NULL;
 
-        g_debug ("GdmSession: Creating D-Bus server for greeters and such");
+        g_debug ("GdmSession: Creating D-Bus server for greeters and such for session %s",
+                 gdm_session_get_session_id (self));
 
         observer = g_dbus_auth_observer_new ();
         g_signal_connect_object (observer,
@@ -2168,7 +2174,7 @@ gdm_session_start_conversation (GdmSession *self,
                 conversation->job = NULL;
         }
 
-        g_debug ("GdmSession: starting conversation %s", service_name);
+        g_debug ("GdmSession: starting conversation  for service '%s'", service_name);
 
         conversation = start_conversation (self, service_name);
 
@@ -2327,6 +2333,9 @@ gdm_session_setup_for_user (GdmSession *self,
 
         update_session_type (self);
 
+        g_debug ("GdmSession: Set up service %s for username %s",
+                 service_name,
+                 username);
         gdm_session_select_user (self, username);
 
         self->is_program_session = FALSE;
@@ -2957,6 +2966,10 @@ gdm_session_start_reauthentication (GdmSession *session,
 
         g_return_if_fail (conversation != NULL);
 
+        g_debug ("GdmSession: starting reauthentication for session %s for client with pid %d",
+                 conversation->session_id,
+                 (int) uid_of_caller);
+
         conversation->reauth_pid_of_caller = pid_of_caller;
 
         gdm_dbus_worker_call_start_reauthentication (conversation->worker_proxy,