GNOME Bugzilla – Bug 794879
GOA-configured Google account has set wrong authentication method
Last modified: 2018-04-06 08:25:12 UTC
Since the update to Fedora 28, my Google calendar events don’t show up in GNOME Calendar, Evolution, or GNOME Shell. Mail, Drive and other Google services all work fine. evolution-data-server-3.28.0-1.fc28.x86_64 evolution-3.28.0-1.fc28.x86_64 gnome-calendar-3.28.0-1.fc28.x86_64 gnome-shell-3.28.0-1.fc28.x86_64 gnome-online-accounts-3.28.0-1.fc28.x86_64
Created attachment 370437 [details] Calendars enabled in GNOME Calendar After reboot, events from calendars added by .ics files disappeared as well. None of the calendars on the screenshot are actually displayed.
Not sure if that might help debugging: https://wiki.gnome.org/Apps/Evolution/Debugging#Calendar_Backends
Thanks for a bug report. Google calendar is provided through their CalDAV interface, thus using: $ CALDAV_DEBUG=1 /usr/libexec/evolution-calendar-factory -w should show some activity there (unless there broke anything with GOA Oauth2 retrieval). I tried with an up-to-date rawhide, but it didn't have this issue, I could see all my Google calendars in Evolution and their events as well. I suppose you see the calendars, but not the events in the GUI, right? Could you remove ~/.cache/evolution/calendar/ and then start the calendar factory again, thus it'll download calendar's content again, please? Maybe there's something wrong with the cache. I'll update to F28 soon too, then I'll report back what it did on my side.
(Disregard comment #1, it’s an unrelated issue of GNOME Calendar not handling webcal links.) Running CALDAV_DEBUG=1 /usr/libexec/evolution-calendar-factory -w doesn’t show any output. ~/.cache/evolution/calendar/ is empty, and removing it doesn’t change anything. But, I noticed that Google calendar shows up as “enabled” only in GNOME Calendar, and isn’t in Evolution at all. I also got a “Connection to …@gmail.com failed” message when I opened Evolution once. I suppose this might point in the direction of an issue with GOA.
And with G_MESSAGES_DEBUG_ALL I get: ~ G_MESSAGES_DEBUG=all CALDAV_DEBUG=1 /usr/libexec/evolution-calendar-factory -w (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendHttpEventsFactory ('webcal:Calendar') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendHttpJournalFactory ('webcal:Memo List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendHttpTodosFactory ('webcal:Task List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendWeatherEventsFactory ('weather:Calendar') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendCalDAVEventsFactory ('caldav:Calendar') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendCalDAVJournalFactory ('caldav:Memo List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendCalDAVTodosFactory ('caldav:Task List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendFileEventsFactory ('local:Calendar') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendFileJournalFactory ('local:Memo List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendFileTodosFactory ('local:Task List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendGTasksFactory ('gtasks:Task List') (evolution-calendar-factory:16576): e-backend-DEBUG: 21:35:25.903: Registering ECalBackendContactsEventsFactory ('contacts:Calendar') (evolution-calendar-factory:16576): evolution-calendar-factory-DEBUG: 21:35:25.958: Server is up and running... So, basically, no anything bad here as well. Also, Google Drive in Nautilus, and Google Contacts sync in Contacts work fine, so at least GOA can connect to Google. Also, new ~/.cache/evolution/calendar/ wasn't created. And Google Calendar shows enabled probably just because the account is present in GOA. The individual calendars aren't shown for me.
You do not have the GOA debugging option yet (bug #793963), but this should work as well: $ export WEBDAV_DEBUG=1 $ ESR_DEBUG=1 /usr/libexec/evolution-source-registry This is supposed to connect to the Google server and find out your available (and on the server enabled) calendars/tasks/... and provide them to the other applications. That may fail for some reason. You may also verify content of ~/.config/evolution/sources/ which should have some .source files with "GNOME Online Accounts" in them. Or search for the GOA account ID as found in ~/.config/goa-1.0/accounts.conf These .soruce files should be Enabled=true. Similarly in ~/.cache/evolution/sources/ where are stored found books/calendars/... for these collection accounts. I'm slowly updating my F27 to F28. I'll let you know tomorrow or so.
Hmm ~ ESR_DEBUG=1 /usr/libexec/evolution-source-registry * Skipping old account data migration, already migrated Autoconfig: GSettings' autoconfig-variables line '' doesn't conform format 'name=value'. Bus name 'org.gnome.evolution.dataserver.Sources5' acquired. -snip- <?xml version="1.0" encoding="UTF-8"?> <errors xmlns="http://schemas.google.com/g/2005"> <error> <domain>GData</domain> <code>required</code> <location type="header">Authorization</location> <internalReason>Login Required</internalReason> </error> </errors> Seems auth is broken.
My Fedora 27 updated to Fedora 28 beta works fine here, I do not get the libgdata authorization error. This is with: evolution-data-server-3.28.0-1.fc28.x86_64 gnome-online-accounts-3.28.0-1.fc28.x86_64 You can export these two before running the evolution-source-registry: export G_MESSAGES_DEBUG=all export LIBGDATA_DEBUG=255 which will give you more detailed information from libgdata itself. It looks like GOA didn't return the access token, or the returned access token is somehow broken/expired. With the above two variables exported you'll also see what the libgdata sends to the server and what the server returns. At least the Authorization header is important. It might look like: (evolution-source-registry:2119): libgdata-DEBUG: > Authorization: OAuth $token
I get the same error as Alexander. This is a full log: [x@x ~]$ G_MESSAGES_DEBUG=all LIBGDATA_DEBUG=255 WEBDAV_DEBUG=1 ESR_DEBUG=1 /usr/lib/evolution-source-registry * Skipping old account data migration, already migrated (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.922: Registering EYahooBackendFactory ('yahoo:Collection') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.922: Registering EWebDAVBackendFactory ('webdav:Collection') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.922: Registering EOutlookBackendFactory ('outlook:Collection') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.922: Registering EGoogleBackendFactory ('google:Collection') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.922: Registering ECollectionBackendFactory ('none:Collection') (evolution-source-registry:21616): evolution-source-registry-DEBUG: 15:47:57.922: Server is up and running... Autoconfig: GSettings' autoconfig-variables line '' doesn't conform format 'name=value'. (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.928: Adding system-proxy ('Source') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.929: Adding local ('Source_1') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.939: Adding 5e1437446c0b616627cb54eb8910daf195e3f238 ('Source_2') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.940: Adding 87929ecab13e8fd47a69c0fa4f0355b26e145311 ('Source_3') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.941: Adding 037770ec9c5e4e9e24252b3c8548ea263b586db5 ('Source_4') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.942: Adding 8b646aa53931b873691ef1d419b705adf76fd977 ('Source_5') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.943: Adding vfolder ('Source_6') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.943: Adding caldav-stub ('Source_7') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.944: Adding contacts-stub ('Source_8') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.944: Adding birthdays ('Source_9') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.944: Adding google-stub ('Source_10') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.945: Adding ldap-stub ('Source_11') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.945: Adding local-stub ('Source_12') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.945: Adding system-calendar ('Source_13') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.946: Adding weather-stub ('Source_14') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.946: Adding webcal-stub ('Source_15') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.947: Adding webdav-stub ('Source_16') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.947: Adding sendmail ('Source_17') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.948: Adding system-address-book ('Source_18') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.948: Adding system-memo-list ('Source_19') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.949: Adding system-task-list ('Source_20') (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.949: Scanning data directories (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.949: Scanning cache directories Bus name 'org.gnome.evolution.dataserver.Sources5' acquired. testbugzilla@gmail.com: Pairing 01c3906de523f579d50fd3c98e22a5637eab1a0e with resource Contacts (evolution-source-registry:21616): e-backend-DEBUG: 15:47:57.969: Adding 2522407e1753095f8a6ccfa165b3092f1885bc56 ('Source_21') < HTTP/1.1 2 Error resolving “apidata.googleusercontent.com”: Temporary failure in name resolution < Soup-Debug-Timestamp: 1522936098 < Soup-Debug: SoupMessage 0 (0x7fa3146210a0) > PROPFIND /.well-known/caldav HTTP/1.1 > Soup-Debug-Timestamp: 1522936100 > Soup-Debug: EWebDAVSession 1 (0x7fa31400b1f0), SoupMessage 1 (0x7fa314621190), SoupSocket 1 (0x7fa31464dbf0) > Host: apidata.googleusercontent.com > User-Agent: Evolution/3.28.1 > Connection: close > Cache-Control: no-cache > Pragma: no-cache > Depth: 0 > Content-Type: application/xml; charset="utf-8" > Accept-Language: en-us, en;q=0.9 > > <propfind xmlns="DAV:" xmlns:c="urn:ietf:params:xml:ns:caldav"> > <prop> > <resourcetype/> > <current-user-principal/> > <principal-URL/> > <c:calendar-home-set/> > <c:calendar-user-address-set/> > </prop> > </propfind> < HTTP/1.1 404 Not Found < Soup-Debug-Timestamp: 1522936100 < Soup-Debug: SoupMessage 1 (0x7fa314621190) < Cache-Control: no-cache, no-store, max-age=0, must-revalidate < Pragma: no-cache < Expires: Mon, 01 Jan 1990 00:00:00 GMT < Date: Thu, 05 Apr 2018 13:48:20 GMT < Vary: X-Origin < Content-Type: text/html; charset=UTF-8 < X-Content-Type-Options: nosniff < X-Frame-Options: SAMEORIGIN < X-XSS-Protection: 1; mode=block < Server: GSE < Alt-Svc: hq=":443"; ma=2592000; quic=51303432; quic=51303431; quic=51303339; quic=51303335,quic=":443"; ma=2592000; v="42,41,39,35" < Accept-Ranges: none < Vary: Origin,Accept-Encoding < Connection: close < Not Found > PROPFIND /caldav/v2/testbugzilla@gmail.com/user HTTP/1.1 > Soup-Debug-Timestamp: 1522937192 > Soup-Debug: EWebDAVSession 1 (0x7fa31804c180), SoupMessage 1 (0x7fa3180630c0), SoupSocket 1 (0x7fa314561190) > Host: apidata.googleusercontent.com > User-Agent: Evolution/3.28.1 > Connection: close > Cache-Control: no-cache > Pragma: no-cache > Depth: 0 > Content-Type: application/xml; charset="utf-8" > Accept-Language: en-us, en;q=0.9 > > <propfind xmlns="DAV:" xmlns:c="urn:ietf:params:xml:ns:caldav"> > <prop> > <resourcetype/> > <current-user-principal/> > <principal-URL/> > <c:calendar-home-set/> > <c:calendar-user-address-set/> > </prop> > </propfind> < HTTP/1.1 401 Unauthorized < Soup-Debug-Timestamp: 1522937192 < Soup-Debug: SoupMessage 1 (0x7fa3180630c0) < Vary: X-Origin < WWW-Authenticate: Bearer realm="https://accounts.google.com/" < Content-Type: application/vnd.google.gdata.error+xml; charset=UTF-8 < Date: Thu, 05 Apr 2018 14:06:32 GMT < Expires: Thu, 05 Apr 2018 14:06:32 GMT < Cache-Control: private, max-age=0 < X-Content-Type-Options: nosniff < X-Frame-Options: SAMEORIGIN < X-XSS-Protection: 1; mode=block < Server: GSE < Alt-Svc: hq=":443"; ma=2592000; quic=51303432; quic=51303431; quic=51303339; quic=51303335,quic=":443"; ma=2592000; v="42,41,39,35" < Accept-Ranges: none < Vary: Origin,Accept-Encoding < Connection: close < <?xml version="1.0" encoding="UTF-8"?> <errors xmlns="http://schemas.google.com/g/2005"> <error> <domain>GData</domain> <code>required</code> <location type="header">Authorization</location> <internalReason>Login Required</internalReason> </error> </errors> > PROPFIND /.well-known/caldav HTTP/1.1 > Soup-Debug-Timestamp: 1522937192 > Soup-Debug: EWebDAVSession 1 (0x7fa31804c180), SoupMessage 2 (0x7fa3180632a0), SoupSocket 2 (0x7fa3145614d0) > Host: apidata.googleusercontent.com > User-Agent: Evolution/3.28.1 > Connection: close > Cache-Control: no-cache > Pragma: no-cache > Depth: 0 > Content-Type: application/xml; charset="utf-8" > Accept-Language: en-us, en;q=0.9 > > <propfind xmlns="DAV:" xmlns:c="urn:ietf:params:xml:ns:caldav"> > <prop> > <resourcetype/> > <current-user-principal/> > <principal-URL/> > <c:calendar-home-set/> > <c:calendar-user-address-set/> > </prop> > </propfind> < HTTP/1.1 404 Not Found < Soup-Debug-Timestamp: 1522937192 < Soup-Debug: SoupMessage 2 (0x7fa3180632a0) < Cache-Control: no-cache, no-store, max-age=0, must-revalidate < Pragma: no-cache < Expires: Mon, 01 Jan 1990 00:00:00 GMT < Date: Thu, 05 Apr 2018 14:06:32 GMT < Vary: X-Origin < Content-Type: text/html; charset=UTF-8 < X-Content-Type-Options: nosniff < X-Frame-Options: SAMEORIGIN < X-XSS-Protection: 1; mode=block < Server: GSE < Alt-Svc: hq=":443"; ma=2592000; quic=51303432; quic=51303431; quic=51303339; quic=51303335,quic=":443"; ma=2592000; v="42,41,39,35" < Accept-Ranges: none < Vary: Origin,Accept-Encoding < Connection: close < Not Found
(In reply to Juozas Miškinis from comment #9) > < HTTP/1.1 2 Error resolving “apidata.googleusercontent.com”: Temporary > failure in name resolution This one ^^^ is interesting. Could that confuse goa-daemon? > > PROPFIND /caldav/v2/testbugzilla@gmail.com/user HTTP/1.1 > > Soup-Debug-Timestamp: 1522937192 > > Soup-Debug: EWebDAVSession 1 (0x7fa31804c180), SoupMessage 1 > (0x7fa3180630c0), SoupSocket 1 (0x7fa314561190) > > Host: apidata.googleusercontent.com > > User-Agent: Evolution/3.28.1 This one ^^^ is supposed to include also the "Authorization: Bearer ..." header, which failed for some reason for you. One prerequisite is that the associated account contains OAuth2 method in its Authenticate section. I do not know why that would work for me, but not for you (I just updated the machine, which already had added and working GOA account with enabled Calendar part). Thus, when you search for "GNOME Online Accounts" (quotes for clarity only) in ~/.config/evolution/sources/ then as many .source files as you have configured GOA accounts related to mail should be found there. Look into the [Authentication] section in the file, it should have Method=OAuth2 there and other values like Host, User and Port basically empty/unset. This is used to determine whether OAuth2 should be used. When it's there, and the account is GOA, then it's asked GOA for the token, together with an attempt to refresh the token, which can fail, if your name resolution failed for some reason on start. The GOA daemon has pretty good debugging too, you can run it as this from a terminal: $ G_MESSAGES_DEBUG=all /usr/libexec/goa-daemon --replace (eventually /usr/lib/..., not libexec) then you'll see what it does. When you run evolution-source-registry afterwards, you should see an attempt to refresh the OAuth2 token, something like this: >> (goa-daemon:2779): goa-daemon-DEBUG: 09:08:03.193: 676402236: Received >> EnsureCredentials (google, account_1521792024_0) followed by tons of other output, including the actual token refresh attempt with libsoup debug logging, like in case of evolution-source-registry in the previous comment.
Thanks a lot for a prompt reply Milan. As you suggested, I've checked ~/.config/evolution/sources/. I can confirm that one .source file represents the GOA account. Please refer to the two attachments: 1) goa-source.txt - content of goa.source file and 2) goa-daemon.txt - the output of "G_MESSAGES_DEBUG=all /usr/lib/goa-daemon --replace". You will notice that in the goa-source.txt file the authentication method is "Method=plain/password". Changing it to "Method=OAuth2" and restarting the goa-daemon fixes the problem, i.e. calendars appear in Evolution and gnome-calendar. Any ideas to why the wrong authentication method is saved in the first place?
Created attachment 370567 [details] Content of a goa.source file
Created attachment 370568 [details] Log file for goa-daemon
(In reply to Juozas Miškinis from comment #11) > Any ideas to why the wrong authentication method is saved in the first place? Right, that's the main question. My update to 3.28 from 3.26 worked, because the corresponding GOA account .source had set OAuth2 authentication method, but when I delete the GOA account in GNOME Settings and create a new GOA account there, then the corresponding .source has also set plain/password method, like for you. That's wrong, of course. I'll check where I made a mistake.
I made it force to use OAuth2 for the GOA/UOA accounts, which fixes the problem for new and old accounts, thus only running patched evolution-source-registry fixes it. The problem was that the default authentication method is plain/password and the backend on the source registry side did update the method only when it had been asked to authenticate against the server, but that happens only when any client provides the credentials (due to plain/password, OAuth2 is done transparently, especially with GOA/UOA), but that failed and the authentication method was never corrected. There's also a problem that the OAuth2 support was not advertised without having the method set properly. Setting the method to OAuth2 fixes that part as well. Created commit 79c8f65f7 in eds master (3.29.1+) Created commit 3d9c3a8b5 in eds gnome-3-28 (3.28.1+)