After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 794879 - GOA-configured Google account has set wrong authentication method
GOA-configured Google account has set wrong authentication method
Status: RESOLVED FIXED
Product: evolution-data-server
Classification: Platform
Component: Calendar
3.28.x
Other Linux
: Normal normal
: ---
Assigned To: evolution-calendar-maintainers
Evolution QA team
Depends on:
Blocks:
 
 
Reported: 2018-04-01 15:17 UTC by Piotr Drąg
Modified: 2018-04-06 08:25 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Calendars enabled in GNOME Calendar (39.95 KB, image/png)
2018-04-02 12:50 UTC, Piotr Drąg
Details
Content of a goa.source file (680 bytes, text/plain)
2018-04-05 23:32 UTC, Juozas Miškinis
Details
Log file for goa-daemon (5.33 KB, text/plain)
2018-04-05 23:32 UTC, Juozas Miškinis
Details

Description Piotr Drąg 2018-04-01 15:17:15 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
Comment 1 Piotr Drąg 2018-04-02 12:50:08 UTC
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.
Comment 2 André Klapper 2018-04-02 13:48:10 UTC
Not sure if that might help debugging: https://wiki.gnome.org/Apps/Evolution/Debugging#Calendar_Backends
Comment 3 Milan Crha 2018-04-03 16:16:21 UTC
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.
Comment 4 Piotr Drąg 2018-04-03 16:53:52 UTC
(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.
Comment 5 Alexander Mikhaylenko 2018-04-03 17:00:31 UTC
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.
Comment 6 Milan Crha 2018-04-03 17:02:37 UTC
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.
Comment 7 Alexander Mikhaylenko 2018-04-03 17:05:04 UTC
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.
Comment 8 Milan Crha 2018-04-04 07:23:14 UTC
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
Comment 9 Juozas Miškinis 2018-04-05 14:23:55 UTC
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
Comment 10 Milan Crha 2018-04-05 16:11:24 UTC
(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.
Comment 11 Juozas Miškinis 2018-04-05 23:30:59 UTC
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?
Comment 12 Juozas Miškinis 2018-04-05 23:32:05 UTC
Created attachment 370567 [details]
Content of a goa.source file
Comment 13 Juozas Miškinis 2018-04-05 23:32:56 UTC
Created attachment 370568 [details]
Log file for goa-daemon
Comment 14 Milan Crha 2018-04-06 07:10:20 UTC
(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.
Comment 15 Milan Crha 2018-04-06 08:25:12 UTC
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+)