Bug 1375058 - goa-daemon spins CPU
Summary: goa-daemon spins CPU
Keywords:
Status: CLOSED NEXTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: evolution-data-server
Version: 24
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Milan Crha
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1382498 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-09-12 05:08 UTC by Dimitris
Modified: 2017-02-07 18:42 UTC (History)
6 users (show)

Fixed In Version: evolution-data-server-3.20.6
Clone Of:
Environment:
Last Closed: 2016-12-05 11:21:08 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
pstack of spinning goa-daemon process (8.06 KB, text/plain)
2016-09-12 05:08 UTC, Dimitris
no flags Details
pstack during CPU spin (8.07 KB, text/plain)
2016-09-21 05:56 UTC, Dimitris
no flags Details
pstack after cycling g-o-a calendar integration (3.06 KB, text/plain)
2016-09-21 05:57 UTC, Dimitris
no flags Details


Links
System ID Private Priority Status Summary Last Updated
GNOME Bugzilla 771547 0 Normal RESOLVED Internal Google OAuth2 authentication fails with expired token 2020-10-02 06:02:01 UTC
GNOME Bugzilla 773248 0 Normal RESOLVED [CalDAV] Google OAuth authentication can fail on refresh 2020-10-02 06:02:00 UTC

Description Dimitris 2016-09-12 05:08:55 UTC
Created attachment 1200070 [details]
pstack of spinning goa-daemon process

Description of problem:

After multiple suspend-resume cycles, moving between different wireless networks, empathy no longer seems able to connect, complaining about authorization errors.

To connect again seems to require running "/usr/libexec/goa-daemon --replace".

At that point, empathy connects, but goa-daemon starts spinning about 50% of a core.

Version-Release number of selected component (if applicable):

3.20.3-1.fc24

How reproducible:

Frequent but not 100%

Steps to Reproduce:
1. Wait until empathy incapable to connect to a pair of Google accounts
2. Run "/usr/libexec/goa-daemon --replace" to resolve empathy problem
3. goa-daemon now spins CPU

Actual results:

goa-daemon consuming about 40% CPU

Expected results:

goa-daemon usually barely registers in "top"

Additional info:

Attaching pstack output from spinning goa-daemon process

Comment 1 Dimitris 2016-09-12 05:10:42 UTC
Additional data point: going to the online account settings for each account and cycling the calendar sync off/on seems to resolve the problem.

Comment 2 Dimitris 2016-09-12 17:07:09 UTC
possibly related or duplicate: bug 1375058

Comment 3 Dimitris 2016-09-12 17:08:12 UTC
Sorry, typo: possible related or duplicate is bug 1346228

Comment 4 Debarshi Ray 2016-09-13 11:17:29 UTC

*** This bug has been marked as a duplicate of bug 1346228 ***

Comment 5 Dimitris 2016-09-19 05:32:23 UTC
Still seeing this, versions:
evolution-data-server: 3.20.5-4.fc24
gnome-online-accounts: 3.20.3-1.fc24

Comment 6 Milan Crha 2016-09-20 10:52:14 UTC
I tried with an expired GOA token with changes from an upstream bug:
https://bugzilla.gnome.org/show_bug.cgi?id=771547
and the CalDAV looks fine, it refreshes the token and uses the new one when the token is expired during open of the calendar. If you'd have any details for the reproducer, even something like "have evolution idle for more than an hour, then this strikes" (the tokens are usually provided with an hour expiration period), then it'll be helpful. Ideally if you could install the test evolution-data-server package from the upstream bug (3.20.5-4.2.fc24) and then restart all evolution process (ps ax | grep evolution), or whole machine (re-login is not enough on Fedora 24), to make sure that the new code is in effect. Thanks in advance.

Comment 7 Dimitris 2016-09-21 05:55:18 UTC
I'm not running evolution.  I only use g-o-a for:

- google messaging, on empathy.
- calendar integration in the GNOME calendar.

In the g-o-a settings UI, I have just two google accounts, each with only the calendar integration switched on.

Updated/simplified "steps" to reproduce (not 100% reproducible unfortunately):

- This seems to happen immediately after resume, even when the laptop is in the same location - connecting to the same WLAN network as before.

(I'll be attaching a pstack output - this just happened)

- When I notice the goa-daemon CPU spin I go to g-o-a settings and turn off the calendar integration for each of the accounts.  All other integrations are already off.  Then I wait a little while (call it a minute), and turn them back on.  This seems to make the problem go away.

I'll also attach a pstack output from after *this* step.

Version currently is 3.20.3-1.fc24 on x86_64.

Comment 8 Dimitris 2016-09-21 05:56:46 UTC
Created attachment 1203107 [details]
pstack during CPU spin

Comment 9 Dimitris 2016-09-21 05:57:47 UTC
Created attachment 1203108 [details]
pstack after cycling g-o-a calendar integration

Comment 10 Milan Crha 2016-09-21 11:54:40 UTC
Thanks for the update. It really looks like the calendar doing authentication requests in a quick manner. Could you run the evolution-calendar-factory with CalDAV debugging on, to see what it tries to do in the background, especially when it gets "crazy", please? Just run this from a terminal:

   $ CALDAV_DEBUG=all /usr/libexec/evolution-calendar-factory -w &>log.txt

and then use the machine as usually. Once you'll see the high CPU usage as before, stop the processes and check what the log.txt file contains. The interesting part will be at the end, showing possibly repeated requests with failure responses from the server.

Comment 11 Dimitris 2016-09-21 17:15:29 UTC
Done, it's quiet for now, I'll update when it gets interesting again.

Comment 12 Dimitris 2016-09-25 04:34:21 UTC
Just happed again, on resume from suspend as usual.  Towards the end of the log file, I see a bunch of requests that seem to have succeeded:

----

> PROPFIND /caldav/v2/:id/events/ HTTP/1.1
> Soup-Debug-Timestamp: 1474777373
> Soup-Debug: SoupSessionSync 1 (0x55e7f5d114b0), SoupMessage 10 (0x7fc5d00020e0), SoupSocket 12 (0x7fc5f40026a0)
> Host: apidata.googleusercontent.com
> User-Agent: Evolution/3.20.5
> Depth: 0
> Content-Type: application/xml
> Connection: close
> Accept-Language: en-us, en;q=0.9
> Authorization: Bearer (token)
> 
> <propfind xmlns="DAV:" xmlns:CS="http://calendarserver.org/ns/">
>   <prop>
>     <CS:getctag/>
>   </prop>
> </propfind>
  
< HTTP/1.1 207 Multi-Status
< Soup-Debug-Timestamp: 1474777373
< Soup-Debug: SoupMessage 10 (0x7fc5d00020e0)
< Vary: X-Origin
< Content-Type: text/xml; charset=UTF-8
< Date: Sun, 25 Sep 2016 04:22:55 GMT
< Expires: Sun, 25 Sep 2016 04:22:55 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: quic=":443"; ma=2592000; v="36,35,34,33,32"
< Accept-Ranges: none
< Vary: Origin,Accept-Encoding
< Connection: close
< 
< <?xml version="1.0" encoding="UTF-8"?>
< <D:multistatus xmlns:D="DAV:" xmlns:caldav="urn:ietf:params:xml:ns:caldav" xmlns:cs="http://calendarserver.org/ns/" xmlns:ical="http://apple.com/ns/ical/">
<  <D:response xmlns:carddav="urn:ietf:params:xml:ns:carddav" xmlns:cm="http://cal.me.com/_namespace/" xmlns:md="urn:mobileme:davservices">
<   <D:href>/caldav/v2/:id/events/</D:href>
<   <D:propstat>
<    <D:status>HTTP/1.1 200 OK</D:status>
<    <D:prop>
<     <cs:getctag>:tag</cs:getctag>
<    </D:prop>
<   </D:propstat>
<  </D:response>
< </D:multistatus>
  
CalDAV - finished syncing with 65 items in a cache

----

This is then followed by:

----

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

(evolution-calendar-factory-subprocess:25235): libebackend-WARNING **: backend_source_authenticate_thread: Failed to invoke credentials required: Operation was cancelled

----

Once I ctrl-C the e-c-f process above, CPU usage returns to normal and I notice that a new e-c-f process has been spawned.

Comment 13 Milan Crha 2016-09-26 08:34:41 UTC
Thanks for the update. So it knows the token, the valid one, but then happens some ping-pong when the authentication is cancelled for some reason. That's a good pointer, it'll help to narrow down the root cause of the issue.

Comment 14 Debarshi Ray 2016-09-27 18:43:06 UTC
(In reply to Dimitris from comment #7)
> I'm not running evolution.  I only use g-o-a for:
> 
> - google messaging, on empathy.
> - calendar integration in the GNOME calendar.

Even if you don't use evolution, the application, you are still using evolution-data-server for calendaring.

Comment 15 Milan Crha 2016-10-07 08:29:39 UTC
*** Bug 1382498 has been marked as a duplicate of this bug. ***

Comment 16 Milan Crha 2016-10-21 11:28:26 UTC
I tried to reproduce it here, with your steps, but no luck. But I noticed other issues, which can be related. Please give a try to this test build, which may or may not help (I hope it will):
http://koji.fedoraproject.org/koji/taskinfo?taskID=16149988

Do not forget to restart the machine after you install the test package, to make sure the background processes are those from the package, not from the previous version. Thanks in advance.

Comment 17 Dima Ryazanov 2016-12-02 20:09:24 UTC
Milan: could you create a f25 version of the test package? (Also, how do I install it? I can't see any download links there...)

Comment 18 Milan Crha 2016-12-05 11:21:08 UTC
Scratch (test) builds last only for a week or so, then they are deleted. All the changes from the release had been released recently for the Fedora 24 (evolution-data-server 3.20.6 [1] and the evolution-data-server-3.22.2 for the Fedora 25.

If you see anything odd with 3.22.2+ on the Fedora 25, then please let me know. Also note of [2], where some more details are written.

I'm closing this bug report for now. Feel free to ask anything here, just do not reopen the bug. I'll reopen it myself, if needed.

[1] https://bodhi.fedoraproject.org/updates/FEDORA-2016-77e191e610
[2] https://mail.gnome.org/archives/evolution-list/2016-October/msg00124.html

Comment 19 Dima Ryazanov 2016-12-11 02:36:13 UTC
Well, I keep seeing this bug in Fedora 25, with gnome-online-accounts-3.22.2-1.fc25.x86_64, unfortunately...

Comment 20 Dima Ryazanov 2016-12-11 02:47:07 UTC
Moreover, when I kill goa-daemon, it starts up again immediately, and keeps using up CPU - so I don't even know how do stop it.

Comment 21 Milan Crha 2016-12-12 15:06:46 UTC
What is your evolution-data-server version, please? Because the problem was not in the goa-daemon. I cannot tell whether you are seeing exactly the same issue, though.

Comment 22 Dima Ryazanov 2016-12-13 00:07:09 UTC
Oh, sorry; it's evolution-data-server-3.22.2-1.fc25.x86_64 - so it should contain the fix?

Comment 23 Milan Crha 2016-12-13 08:58:39 UTC
Yes, the evolution-data-server 3.22.2 contains related fixes. To know whether you face the same issue, even with the patched evolution-data-server, we should find out why the evolution-source-registry process asks for the OAuth2 token so much often. Could you open Online Accounts and try to disable the Calendar part in your Google account, to see whether it'll help, please? I'm not sure whether it'll work without restart, though.

Comment 24 Nico Lu 2017-02-07 04:34:52 UTC
(In reply to Milan Crha from comment #23)
> Yes, the evolution-data-server 3.22.2 contains related fixes. To know
> whether you face the same issue, even with the patched
> evolution-data-server, we should find out why the evolution-source-registry
> process asks for the OAuth2 token so much often. Could you open Online
> Accounts and try to disable the Calendar part in your Google account, to see
> whether it'll help, please? I'm not sure whether it'll work without restart,
> though.

Hi I happen to have the same problem and tried your suggestion. It worked.
The goa-daemon disappeared immediately from "top" after I disable the calendar sync, and won't cause problem again if I re-open the sync, as long as I don't poweroff or reboot. However, if I boot with sync enabled, the problem starts all over again.

I am new to linux, and hope what I said makes sense. Thank you!

Comment 25 Nico Lu 2017-02-07 04:58:06 UTC
(In reply to Nico Lu from comment #24)
> (In reply to Milan Crha from comment #23)
> > Yes, the evolution-data-server 3.22.2 contains related fixes. To know
> > whether you face the same issue, even with the patched
> > evolution-data-server, we should find out why the evolution-source-registry
> > process asks for the OAuth2 token so much often. Could you open Online
> > Accounts and try to disable the Calendar part in your Google account, to see
> > whether it'll help, please? I'm not sure whether it'll work without restart,
> > though.
> 
> Hi I happen to have the same problem and tried your suggestion. It worked.
> The goa-daemon disappeared immediately from "top" after I disable the
> calendar sync, and won't cause problem again if I re-open the sync, as long
> as I don't poweroff or reboot. However, if I boot with sync enabled, the
> problem starts all over again.
> 
> I am new to linux, and hope what I said makes sense. Thank you!

Oh, and when I try to figure out another small problem, namely, the screen flickers when I login in (but thankfully only once each login), I turned the login option (the small gear under password box) from gnome to gnome xorg, and the problem of goa somehow disappeared, even with calendar sync on when booting. I haven't done much in this mean time, so I strongly feel like they should have some connection.

Thank you!

Comment 26 Milan Crha 2017-02-07 07:57:58 UTC
What is your evolution-data-server version, please? 
   $ rpm -q evolution-data-server

Did you restart whole machine when changing desktop environment before log in, or you just log out and then log in? If the later, then I suspect bug #1340203 being involved.


Note You need to log in before you can comment on or make changes to this bug.