canonical / canonical/authd

GDM sometimes not showing device code after selecting broker

Open
#1,901 0 comments 0 reactions 0 assignees View on GitHub
e2e-tests jira
Dominant language
Go
Stars
308
Forks
41
Avg merge
2d 4h
Merged PRs (30d)
58

Description

I've seen the test case `Test login with GDM` fail after entering the username and selecting the broker. The "Select the broker" UI elements disappear but the device code dialog is not shown:

Observed in:
* https://authd-e2e-test-logs.adrian-dombeck.workers.dev/push-33891271000/run-33891271000-1/resolute-authd-msentraid/log.html#s1-s20-t1
* https://authd-e2e-test-logs.adrian-dombeck.workers.dev/push-34370596846/run-34370596846-1/resolute-authd-msentraid/log.html#s1-s25

Image

Excerpt from the logs of [run-33891271000-1](https://authd-e2e-test-logs.adrian-dombeck.workers.dev/push-33891271000/run-33891271000-1/resolute-authd-msentraid/log.html#s1-s20-t1):

```
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"pollResponse","pollResponse":[{"type":"brokerSelected","brokerSelected":{"brokerId":"2102147668"}}]}
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: GDM poll response: type:brokerSelected brokerSelected:{brokerId:"2102147668"}
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: adapter.brokerSelected{brokerID:"2102147668"}
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: adapter.BrokerSelected{BrokerID:"2102147668"}
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"event","event":{"type":"brokerSelected","brokerSelected":{"brokerId":"2102147668"}}}
Sep 04 16:41:02 ubuntu dbus-daemon[979]: [system] Activating via systemd: service name='com.ubuntu.authd.MSEntraID' unit='snap.authd-msentraid.authd-msentraid.service' requested by ':1.13' (uid=0 pid=1070 comm="/usr/libexec/authd -vv" label="unconfined")
Sep 04 16:41:02 ubuntu gnome-shell[1500]: authd: Broker selected 2102147668
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"eventAck"}
Sep 04 16:41:02 ubuntu gdm-session-wor[2965]: EventSend&{brokerId:"2102147668"}result
Sep 04 16:41:02 ubuntu systemd[1]: Starting snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid...
Sep 04 16:41:02 ubuntu systemd[1]: tmp-snap\x2dprivate\x2dtmp-snap.rootfs_h6ERoC.mount: Deactivated successfully.
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Version: 0.4.1+7c091d8
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Debug mode is enabled
Sep 04 16:41:04 ubuntu dbus-daemon[979]: [system] Successfully activated service 'com.ubuntu.authd.MSEntraID'
Sep 04 16:41:04 ubuntu systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Initializing broker for interface com.ubuntu.authd.Broker
Sep 04 16:41:04 ubuntu authd[1070]: Could not parse interface version from "org.freedesktop.DBus.Introspectable"
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Creating new session (v3) (username=e2e-test@ubudev1.onmicrosoft.com, lang=C, mode=auth, provider_id=)
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Initializing broker for interface com.ubuntu.authd.Broker2
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Initializing broker for interface com.ubuntu.authd.Broker3
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Building new daemon
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Starting to serve requests
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Serving requests as com.ubuntu.authd.MSEntraID
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Created new session cabb117d-bb76-4711-a758-36ed22088119
Sep 04 16:41:04 ubuntu authd[1070]: 2102147668-cabb117d-bb76-4711-a758-36ed22088119: New auth session for "e2e-test@ubudev1.onmicrosoft.com"
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.SessionStarted{brokerID:"2102147668", sessionID:"2102147668-cabb117d-bb76-4711-a758-36ed22088119", encryptionKey:"MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAyBUpM23d+Irqc4CPLSd5G/FlMdkjN2OTr0Z47J6mHZ+V30WwPDT21oqejcyBt3g8ZIgZOe9MyMl7WH9kRgr2KPJGQ52XWqjIjOwxhAU/usd/BJ1/DwRsgr1/JriNZoPOwaAc7yjFOQ4tkkLnqWCH0q2tAfvnuquD89xQlpEWjMVWEhY3Zz5EvE5joGv2MbZEuTju5wOWTnfRUWg/6zhDOic9pRD+MnrEcBvwa0kuvvQKqAjr6QMpzOaOYsB/DzLa4/Gj+x4/37VDFyEVTZu81bhCynrnev5n0CER4xxKVBQpkXhb97MRkmgEb5po9JBRM51FjyHABsTWwogT+PpTRQIDAQAB"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.GetAuthenticationModesRequested{}
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Getting authentication modes for session cabb117d-bb76-4711-a758-36ed22088119
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Token does not exist for user "e2e-test@ubudev1.onmicrosoft.com", so local password authentication is not available
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: The "entra_auth" flow is disabled in the [flows] config, so it is not available
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Got authentication modes for session cabb117d-bb76-4711-a758-36ed22088119: [map[id:device_auth_qr label:Device code flow]]
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: authModes[id:"device_auth_qr" label:"Device code flow"]
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.authModesReceived{authModes:[]*authd.GAMResponse_AuthenticationMode{(*authd.GAMResponse_AuthenticationMode)(0x3172e9f3e5a0)}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.ChangeStage{Stage:"authModeSelection"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: *adapter.List: Blur
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.List: Focus
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"event","event":{"type":"authModesReceived","authModesReceived":{"authModes":[{"id":"device_auth_qr","label":"Device code flow"}]}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.listFocused{id:0x2}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.listFocused{id:0x2}, autoselect: "device_auth_qr"
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.StageChanged{Stage:"authModeSelection"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"request","request":{"type":"changeStage","changeStage":{"stage":"authModeSelection"}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.authModeSelected{id:"device_auth_qr", fromGDM:false}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.AuthModeSelected{ID:"device_auth_qr", fromGDM:false}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"eventAck"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: EventSend&{authModes:{id:"device_auth_qr" label:"Device code flow"}}result
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"event","event":{"type":"authModeSelected","authModeSelected":{"authModeId":"device_auth_qr"}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"eventAck"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: EventSend&{authModeId:"device_auth_qr"}result
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Selecting authentication mode device_auth_qr for session cabb117d-bb76-4711-a758-36ed22088119
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Sending Device Authorization Request to retrieve device code...
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"response","response":{"type":"changeStage","ack":{}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Gdm stage change to authModeSelection sent
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"pollResponse","pollResponse":[{"type":"authModeSelected","authModeSelected":{"authModeId":"device_auth_qr"}}]}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: GDM poll response: type:authModeSelected authModeSelected:{authModeId:"device_auth_qr"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Ignoring GDM auth mode selection echo for "device_auth_qr"
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Retrieved device code. Device Authorization Response: &oauth2.DeviceAuthResponse{DeviceCode:"ABgABIQEAAAA9VeaV3ywaSLp1O3c4_Et5RXZvU3RzQXJ0aWZhY3RzAQAAAAAA9Ov1kX1CX4vVIVieUpLud4XqRkZGIL4jLTNkKsKCpFsIltJ2VeG-nAmThpclGPumqo2h-2fA6UhlDTlQDMssjh3wQ-sL9rRsA3xLI5xlhouAi_y1TlWlR8j08CTDOYue5SmOukVUuGWc6--9qUXVqt_6ZLkjZ3rmjwci4yyfiHwmO3vpVSGrHQaLP1bfrfxsDL2WWsjrGeZuli3obckAlEh5KHgIW3XTsshCiV2bLkHsfQ_I3vADRaYSLCG8qpUQtzhFGNF4jdJnIyhBIJm8R5vo09TS8yicYmiYpfG5yPg83cb22d3BMuAez4eQhXASGxYKQVIm3gbDCipuRhiNBh1DR45acRLc3DTvoPxUYH-b_hpFQiEHR056Fk-a9zg5nTJv8nIJaX5WhEjsVCgZ7hl1HVOnX35QrndFu_YcEs5NKfM9X7hPciQH2AaNeSEIQ0G3jBBkzFntzweZm0pHBuHNxS9sifWnxbpJDu7U6escykUePDo-3DyGRnnI-MAuWkgY961fjYuFtop81k-u0xdst48eUPi990u4I07YvnNHHKUpmBuHVaK2V8IcRKQHfO3eWriLBuniTkewYvQTvlKiGsUCUw9IoF3-KVL50MeB7K_eXFCi6eXFPZV1-WWvCNbSHrPWIPN1hZsRJQj51C7pBuGqkQAeeSXpgWIun-gJ30UOBk80j4YqvSXz7qDTov-P_RkMic_8nrtw3qv80ow0G-c4w8G78my_z7lCNF4gAA", UserCode:"AE3P6KPNN", VerificationURI:"https://login.microsoft.com/device", VerificationURIComplete:"", Expiry:time.Date(2026, time.September, 4, 16, 56, 4, 676640437, time.UTC), Interval:5}
Sep 04 16:41:04 ubuntu authd-msentraid[2996]: Selected authentication mode device_auth_qr for session cabb117d-bb76-4711-a758-36ed22088119: map[button:Request new code code:AE3P6KPNN content:https://login.microsoft.com/device label:Scan the QR code or open the URL and enter the code below. type:qrcode wait:true]
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.UILayoutReceived{&authd.UILayout{state:impl.MessageState{NoUnkeyedLiterals:pragma.NoUnkeyedLiterals{}, DoNotCompare:pragma.DoNotCompare{}, DoNotCopy:pragma.DoNotCopy{}, atomicMessageInfo:(*impl.MessageInfo)(nil)}, Type:"qrcode", Label:(*string)(0x3172ea0f04b0), Button:(*string)(0x3172ea0f04c0), Wait:(*string)(0x3172ea0f04d0), Entry:(*string)(0x3172ea0f04e0), Content:(*string)(0x3172ea0f04f0), Code:(*string)(0x3172ea0f0500), RendersQrcode:(*bool)(nil), unknownFields:[]uint8(nil), sizeCache:0}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"event","event":{"type":"uiLayoutReceived","uiLayoutReceived":{"uiLayout":{"type":"qrcode","label":"Scan the QR code or open the URL and enter the code below.","button":"Request new code","wait":"true","entry":"","content":"https://login.microsoft.com/device","code":"AE3P6KPNN"}}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"eventAck"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: EventSend&{uiLayout:{type:"qrcode" label:"Scan the QR code or open the URL and enter the code below." button:"Request new code" wait:"true" entry:"" content:"https://login.microsoft.com/device" code:"AE3P6KPNN"}}result
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.ChangeStage{Stage:"challenge"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: *adapter.List: Blur
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.authenticationModel: Focus, focused false
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: *adapter.focusTrackerModel: Focus
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.StageChanged{Stage:"challenge"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.StageChanged{Stage:"challenge"}, in progress false, focused: true
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"request","request":{"type":"changeStage","changeStage":{"stage":"challenge"}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: adapter.startAuthentication{}, current model &{true}, focused true
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Sending to GDM: {"type":"event","event":{"type":"startAuthentication","startAuthentication":{}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"response","response":{"type":"changeStage","ack":{}}}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Gdm stage change to challenge sent
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: Got from GDM: {"type":"eventAck"}
Sep 04 16:41:04 ubuntu gdm-session-wor[2965]: EventSend&{}result
```

Maybe the `Could not parse interface version from "org.freedesktop.DBus.Introspectable"` is the issue?

Edit: The `Could not parse interface version from "org.freedesktop.DBus.Introspectable"` warning is apparently always printed and has nothing to do with the issue.

Contributor guide

Open the contributing guide

Research direction

Start by reproducing the `Test login with GDM` case and compare the linked end-to-end logs around broker selection, authentication-mode selection, and the `uiLayoutReceived` event. Trace why the device-code dialog is not displayed after the broker is selected; done means the test reliably shows the device-code dialog and the persistent DBus warning is not treated as the cause.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
authentication
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Needs clarification
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.