GNOME Bugzilla – Bug 771547
Internal Google OAuth2 authentication fails with expired token
Last modified: 2016-12-19 07:49:58 UTC
Created attachment 335724 [details] Trace of hung Evolution process When accessing my Gmail and Google Apps accounts via IMAP with Evolution 3.20.5 I get random hangs on some operations, usually after I send mail. The tabs on the bottom edge show multiple concurrent actions including Sending, Updating folder, Fetching new mail etc. This happens occasionally and unpredictably and at other times everything seems to work as expected. I enclose a trace of such a recent event.
Created attachment 335782 [details] Hang during message send Message send hangs indefinitely until Evolution is killed and restarted, after which it completes immediately.
(In reply to Patrick OCallaghan from comment #1) > Created attachment 335782 [details] > Hang during message send > > Message send hangs indefinitely until Evolution is killed and restarted, > after which it completes immediately. I also did an strace while this was going on: poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}, {fd=36, events=POLLIN}], 5, 99) = 0 (Timeout) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}, {fd=36, events=POLLIN}], 5, 0) = 0 (Timeout) poll([{fd=3, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) writev(3, [{iov_base="\22\0\16\0Z\350\347\4\311\1\0\0\6\0\0\0 \0\0\0\10\0\0\0\7\0\0\0\0\0\0\0"..., iov_len=408}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 408 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}, {fd=36, events=POLLIN}], 5, 100) = 1 ([{fd=3, revents=POLLIN}]) recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\34\0\276\226Z\350\347\4\311\1\0\0\2\237\300\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="A\0\305\226&\267\371\4\3\0\202\0\252\336\341\4\0P9\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}, {fd=36, events=POLLIN}], 5, 99) = 0 (Timeout) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=11, events=POLLIN}, {fd=36, events=POLLIN}], 5, 0) = 0 (Timeout) poll([{fd=3, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) etc. etc. This kept going the entire time until I killed Evo.
Created attachment 335817 [details] Hang while fetching message and refreshing account This time the only activity was trying to fetch a message, while Evolution was refreshing the same account the message is on. It's a Google Apps account in this case. Once again an strace shows: poll([{fd=3, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) writev(3, [{iov_base="&-\2\0006\0\0\2", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8 poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}]) recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1l}\0\0\0\0\225\2\0\0007\0\0\2\200\1\17\3\200\1\17\3\4 \0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) writev(3, [{iov_base="&-\2\0007\0\0\2", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8 poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}]) recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1m}\0\0\0\0\225\2\0\0\5\0\0\3\200\1\17\3\200\1\357\2\4 \0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) poll([{fd=3, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) writev(3, [{iov_base="&-\2\0\5\0\0\3", iov_len=8}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}], 3) = 8 poll([{fd=3, events=POLLIN}], 1, -1) = 1 ([{fd=3, revents=POLLIN}]) recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\1n}\0\0\0\0\225\2\0\0\0\0\0\0\200\1\17\3\200\1\357\2\4 \0\0\0\0\0\0", iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 32 recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) recvmsg(3, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) etc. etc.
Thanks for a bug report and backtraces. The common part for all of them is a prompt for credentials of the 'Google' method, as shown below. I suppose this happens when the OAuth token expires, which is usually an hour later after it's obtained. I'll try to reproduce it here.
+ Trace 236679
Thread 20 (Thread 0x7fb7164ba700 (LWP 3351))
I cannot reproduce the SMTP issue here, but I found other issues in the internal Google OAuth2 processing (it seems nobody was truly using it, or didn't bother to report issues), which influence this. For example, when I clicked to "Reconnect" for a Google calendar when the OAuth2 token was expired, then the whole process seemed like it's trying something, but it was playing a ping-pong of the type: a) calendar-factory: token is expired, give me updated token b) evolution: refreshed the token, here you are c) calendar-factory: token is expired, give me updated token d) evolution: refreshed the token, ... That due to a very unfortunate bug when calculating how long the token will be valid. That most likely prevented to open Google calendars in the 3.20.5-4 for you. I made a scratch build with this particular thing fixed [1], but it's missing other parts. For example I'm unsure whether it'll also fix the SMTP error. It can, but it's uncertain to me at the moment. The [1] will fix the calendar, though. I'm still investigating further, to make the usage of the internal Google OAuth2 token as smooth as possible. [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=15707453
(In reply to Milan Crha from comment #5) > I cannot reproduce the SMTP issue here, but I found other issues in the > internal Google OAuth2 processing (it seems nobody was truly using it, or > didn't bother to report issues), which influence this. For example, when I > clicked to "Reconnect" for a Google calendar when the OAuth2 token was > expired, then the whole process seemed like it's trying something, but it > was playing a ping-pong of the type: > a) calendar-factory: token is expired, give me updated token > b) evolution: refreshed the token, here you are > c) calendar-factory: token is expired, give me updated token > d) evolution: refreshed the token, ... > > That due to a very unfortunate bug when calculating how long the token will > be valid. That most likely prevented to open Google calendars in the > 3.20.5-4 for you. I made a scratch build with this particular thing fixed > [1], but it's missing other parts. For example I'm unsure whether it'll also > fix the SMTP error. It can, but it's uncertain to me at the moment. The [1] > will fix the calendar, though. > > I'm still investigating further, to make the usage of the internal Google > OAuth2 token as smooth as possible. > > [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=15707453 Trying it now. I'll report back when it's been running for a while.
I'll have better version "shortly". What I've found right now is that the hung is caused by certain thread interleaving. I cannot reproduce it always, but I saw it couple times. I added some locking around "affected" places, which will help.
(In reply to Patrick OCallaghan from comment #6) > (In reply to Milan Crha from comment #5) > > I cannot reproduce the SMTP issue here, but I found other issues in the > > internal Google OAuth2 processing (it seems nobody was truly using it, or > > didn't bother to report issues), which influence this. For example, when I > > clicked to "Reconnect" for a Google calendar when the OAuth2 token was > > expired, then the whole process seemed like it's trying something, but it > > was playing a ping-pong of the type: > > a) calendar-factory: token is expired, give me updated token > > b) evolution: refreshed the token, here you are > > c) calendar-factory: token is expired, give me updated token > > d) evolution: refreshed the token, ... > > > > That due to a very unfortunate bug when calculating how long the token will > > be valid. That most likely prevented to open Google calendars in the > > 3.20.5-4 for you. I made a scratch build with this particular thing fixed > > [1], but it's missing other parts. For example I'm unsure whether it'll also > > fix the SMTP error. It can, but it's uncertain to me at the moment. The [1] > > will fix the calendar, though. > > > > I'm still investigating further, to make the usage of the internal Google > > OAuth2 token as smooth as possible. > > > > [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=15707453 > > Trying it now. I'll report back when it's been running for a while. Just got the "Failed to connect calendar 'Gmail :... Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded...." error again. However the SMTP error has not reappeared so far.
(In reply to Patrick OCallaghan from comment #8) > Just got the "Failed to connect calendar 'Gmail :... Failed to login to the > server: Daily Limit for Unauthenticated Use Exceeded...." error again. > However the SMTP error has not reappeared so far. Good, that's a side-effect of the incomplete fix. I made the change complete (according to my local testing) and I made a test build 3.20.5-4.2.fc24 too, it is available at: http://koji.fedoraproject.org/koji/taskinfo?taskID=15716035 Give it a try for about a week, please, and update this bug report if you find anything odd. I receive updates for closed bugs too, thus no need to reopen it. Do not forget to either kill all evolution processes (ps ax | grep evolution) or restart the machine (re-login is not enough on Fedora 24), to make sure the new code is used. Thanks in advance. I committed the changes into the sources: Created commit eaf7192 in eds master (3.23.1+) Created commit 54cf5ff in eds gnome-3-22 (3.22.1+)
(In reply to Milan Crha from comment #9) > (In reply to Patrick OCallaghan from comment #8) > > Just got the "Failed to connect calendar 'Gmail :... Failed to login to the > > server: Daily Limit for Unauthenticated Use Exceeded...." error again. > > However the SMTP error has not reappeared so far. > > Good, that's a side-effect of the incomplete fix. > > I made the change complete (according to my local testing) and I made a test > build 3.20.5-4.2.fc24 too, it is available at: > http://koji.fedoraproject.org/koji/taskinfo?taskID=15716035 > > Give it a try for about a week, please, and update this bug report if you > find anything odd. I receive updates for closed bugs too, thus no need to > reopen it. Do not forget to either kill all evolution processes (ps ax | > grep evolution) or restart the machine (re-login is not enough on Fedora > 24), to make sure the new code is used. Thanks in advance. > > I committed the changes into the sources: > > Created commit eaf7192 in eds master (3.23.1+) > Created commit 54cf5ff in eds gnome-3-22 (3.22.1+) OK, testing now.
(In reply to Patrick OCallaghan from comment #10) > (In reply to Milan Crha from comment #9) > > (In reply to Patrick OCallaghan from comment #8) > > > Just got the "Failed to connect calendar 'Gmail :... Failed to login to the > > > server: Daily Limit for Unauthenticated Use Exceeded...." error again. > > > However the SMTP error has not reappeared so far. > > > > Good, that's a side-effect of the incomplete fix. > > > > I made the change complete (according to my local testing) and I made a test > > build 3.20.5-4.2.fc24 too, it is available at: > > http://koji.fedoraproject.org/koji/taskinfo?taskID=15716035 > > > > Give it a try for about a week, please, and update this bug report if you > > find anything odd. I receive updates for closed bugs too, thus no need to > > reopen it. Do not forget to either kill all evolution processes (ps ax | > > grep evolution) or restart the machine (re-login is not enough on Fedora > > 24), to make sure the new code is used. Thanks in advance. > > > > I committed the changes into the sources: > > > > Created commit eaf7192 in eds master (3.23.1+) > > Created commit 54cf5ff in eds gnome-3-22 (3.22.1+) > > OK, testing now. Once again: "Failed to connect calendar 'Gmail : ..."
(In reply to Patrick OCallaghan from comment #11) > (In reply to Patrick OCallaghan from comment #10) > > (In reply to Milan Crha from comment #9) > > > (In reply to Patrick OCallaghan from comment #8) > > > > Just got the "Failed to connect calendar 'Gmail :... Failed to login to the > > > > server: Daily Limit for Unauthenticated Use Exceeded...." error again. > > > > However the SMTP error has not reappeared so far. > > > > > > Good, that's a side-effect of the incomplete fix. > > > > > > I made the change complete (according to my local testing) and I made a test > > > build 3.20.5-4.2.fc24 too, it is available at: > > > http://koji.fedoraproject.org/koji/taskinfo?taskID=15716035 > > > > > > Give it a try for about a week, please, and update this bug report if you > > > find anything odd. I receive updates for closed bugs too, thus no need to > > > reopen it. Do not forget to either kill all evolution processes (ps ax | > > > grep evolution) or restart the machine (re-login is not enough on Fedora > > > 24), to make sure the new code is used. Thanks in advance. > > > > > > I committed the changes into the sources: > > > > > > Created commit eaf7192 in eds master (3.23.1+) > > > Created commit 54cf5ff in eds gnome-3-22 (3.22.1+) > > > > OK, testing now. > > Once again: "Failed to connect calendar 'Gmail : ..." "SSL certificate for calendar 'Gmail : pocallaghan@gmail.com' is not trusted"
Created attachment 335944 [details] Again hanging on multiple activities Tabs are all related to the same Google Apps account: Checking for new mail, Retrieving folder list, Retrieving message, Storing changes, Retrieving [another] message.
With respect of the calendar, could you run the calendar factory from a terminal, please? It's like this: $ CALDAV_DEBUG=all /usr/libexec/evolution-calendar-factory -w The interesting part will be a little before and after the failure. What I was looking for was whether the request contains any Authenticate header, which should also contain "Bearer" string and the OAuth2 token. Requests without them are rejected as 403 Forbidden by the Google server, which is expected. With respect of the mail part, one of the threads which are retrieving messages is "asking for credentials". The added mutex locking in the patch was to avoid an issue with thread interleaving, which seems to me as it being the problem. Maybe it wasn't. The other threads are mostly downloading data from the server, or better said waiting for the data being received. If a connection had been lost, then it would ideally timeout, but I do not see in the backtrace whether any timeout is set (the value is <optimized out>), one thread shows timeout -1, which is to wait indefinitely. The SSL certificate error is odd, could there happen anything with your connection to the Google server during that time?
Created attachment 335986 [details] [review] eds patch for evolution-data-server; Partly debugging patch, partly should address the hung state in the credentials prompt. I'm building updated package here [1]. Please run evolution from a console and watch it for any runtime warnings. It will print one, if you'd face the hung (if I'm not wrong again). [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=15733754
(In reply to Milan Crha from comment #14) > With respect of the calendar, could you run the calendar factory from a > terminal, please? It's like this: > > $ CALDAV_DEBUG=all /usr/libexec/evolution-calendar-factory -w > > The interesting part will be a little before and after the failure. What I > was looking for was whether the request contains any Authenticate header, > which should also contain "Bearer" string and the OAuth2 token. Requests > without them are rejected as 403 Forbidden by the Google server, which is > expected. OK, I tried this twice, both times with a fresh run of Evo. The first time the UI gave an error on the Gmail calendar, as before, while the command returned no output. The second time the UI did not report an error and the command returned a bunch of XML data followed by: CalDAV - found 136 objects on the server, locally stored 136 objects CalDAV - recognized 0 items to update CalDAV - finished syncing with 136 items in a cache > With respect of the mail part, one of the threads which are retrieving > messages is "asking for credentials". The added mutex locking in the patch > was to avoid an issue with thread interleaving, which seems to me as it > being the problem. Maybe it wasn't. The other threads are mostly downloading > data from the server, or better said waiting for the data being received. If > a connection had been lost, then it would ideally timeout, but I do not see > in the backtrace whether any timeout is set (the value is <optimized out>), > one thread shows timeout -1, which is to wait indefinitely. I would say that waiting indefinitely is never the right thing to do with a user-facing system (which includes a status indicator). Of course deciding on a suitable timeout isn't trivial either. > The SSL certificate error is odd, could there happen anything with your > connection to the Google server during that time? Can't say, though I do run the Google webmail concurrently in a browser (I didn't think to mention that before now, hope it's not important).
(In reply to Milan Crha from comment #15) > Created attachment 335986 [details] [review] [review] > eds patch > > for evolution-data-server; > > Partly debugging patch, partly should address the hung state in the > credentials prompt. I'm building updated package here [1]. Please run > evolution from a console and watch it for any runtime warnings. It will > print one, if you'd face the hung (if I'm not wrong again). > > [1] http://koji.fedoraproject.org/koji/taskinfo?taskID=15733754 Running it now. So far I only get the usual startup warnings, which I include here just in case: Gtk-WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .service files openjdk version "1.8.0_102" OpenJDK Runtime Environment (build 1.8.0_102-b14) OpenJDK 64-Bit Server VM (build 25.102-b14, mixed mode) (evolution:21455): Gtk-WARNING **: Allocating size to EAttachmentButton 0x558aea6a7880 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate? (evolution:21455): Gtk-WARNING **: Allocating size to GtkBox 0x558aea76a120 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate? (evolution:21455): Gtk-WARNING **: Allocating size to EAttachmentButton 0x558aea6a7880 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate? (evolution:21455): Gtk-WARNING **: Allocating size to GtkBox 0x558aea76a120 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate? (evolution:21455): Gtk-WARNING **: Allocating size to EAttachmentButton 0x558aea6a7880 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate? (evolution:21455): Gtk-WARNING **: Allocating size to GtkBox 0x558aea76a120 without calling gtk_widget_get_preferred_width/height(). How does the code know the size to allocate?
Created attachment 336015 [details] Hang on multiple updates As before, the UI is hung when: Storing folder Checking for new mail Retrieving folder list Storing changes in folder All in the same account. This is using evolution-data-server-3.20.5-4.3.fc24.x86_64.rpm. I also updated the debuginfo from the same Koji page, though there are some complaints about outdated debuginfo in the trace file. After a while, also getting: Failed to finish trust prompt for 'Gmail : Tasks'
(In reply to Patrick OCallaghan from comment #18) > Hang on multiple updates Did it also print anythign on the evolution console? That's currently the place where to look. > After a while, also getting: > Failed to finish trust prompt for 'Gmail : Tasks' I do not understand this one, really :-/ It would be the same as the SSL error for the calendar.
(In reply to Milan Crha from comment #19) > (In reply to Patrick OCallaghan from comment #18) > > Hang on multiple updates > > Did it also print anythign on the evolution console? That's currently the > place where to look. Nothing apart from the Gtk-Warning stuff I already noted, which appears from time to time when I do stuff. However I wasn't logging the output so it's possible something came up and scrolled off-screen. I'll log it from now on. > > After a while, also getting: > > Failed to finish trust prompt for 'Gmail : Tasks' > > I do not understand this one, really :-/ It would be the same as the SSL > error for the calendar. Don't know what to tell you. I just copy/pasted from the error message.
(In reply to Patrick OCallaghan from comment #20) > (In reply to Milan Crha from comment #19) > > (In reply to Patrick OCallaghan from comment #18) > > > Hang on multiple updates > > > > Did it also print anythign on the evolution console? That's currently the > > place where to look. > > Nothing apart from the Gtk-Warning stuff I already noted, which appears from > time to time when I do stuff. However I wasn't logging the output so it's > possible something came up and scrolled off-screen. I'll log it from now on. > > > > After a while, also getting: > > > Failed to finish trust prompt for 'Gmail : Tasks' > > > > I do not understand this one, really :-/ It would be the same as the SSL > > error for the calendar. > > Don't know what to tell you. I just copy/pasted from the error message. It did it again: Failed to finish trust prompt for 'Gmail : Tasks' No PEM-encoded certificate found I'm logging both Evo and the calendar-factory. Neither shows any error message.
It's happening to me. Email works perfect but Calendar doesn't connect. Both are the same Google Account. Error message: HTTP error: Unauthorized Using Fedora 24 Workstation.
This starts happening every morning here when my connection is reset. something queues too many login attempts and reaches a google api limit.
Okay, I'm setting this as not fixed. I'm logging the factories and will see what I'll be able to gather. I even saw the error with a certificate, on the git master of the evolution-data-server and evolution. The only problem for me is that it shows up after some time, like few hours running. I also get some kick-offs from the addressbook when opening the composer after the long time when I kept evolution running. Interestingly, my tests of the changes from comment #9 didn't exhibit the issue (wrong testing on my side, it seems).
(In reply to Milan Crha from comment #24) > Okay, I'm setting this as not fixed. I'm logging the factories and will see > what I'll be able to gather. I even saw the error with a certificate, on the > git master of the evolution-data-server and evolution. The only problem for > me is that it shows up after some time, like few hours running. I also get > some kick-offs from the addressbook when opening the composer after the long > time when I kept evolution running. Interestingly, my tests of the changes > from comment #9 didn't exhibit the issue (wrong testing on my side, it > seems). Let me know what I can do to test this further. I'm currently getting the "blocked Send" problem multiple times per day. As soon as it happens I just kill all of Evo and restart it, recover the message and send it immediately. The calendar error is also happening pretty much all the time, but I basically just ignore it and use Google Calendar directly from the web page.
(In reply to Patrick OCallaghan from comment #25) > I'm currently getting the "blocked Send" problem multiple times per day. As > soon as it happens I just kill all of Evo and restart it, recover the > message and send it immediately. Is the evolution console still empty in this case? I may extend debug prints, I think.
(In reply to Milan Crha from comment #26) > (In reply to Patrick OCallaghan from comment #25) > > I'm currently getting the "blocked Send" problem multiple times per day. As > > soon as it happens I just kill all of Evo and restart it, recover the > > message and send it immediately. > > Is the evolution console still empty in this case? I may extend debug > prints, I think. I assume you mean messages on the console. I haven't been running it that way in the past few days because it didn't show anything useful, but I'll do so if you want to add more logging.
(In reply to Milan Crha from comment #26) > (In reply to Patrick OCallaghan from comment #25) > > I'm currently getting the "blocked Send" problem multiple times per day. As > > soon as it happens I just kill all of Evo and restart it, recover the > > message and send it immediately. > > Is the evolution console still empty in this case? I may extend debug > prints, I think. In my case the is empty, it only returns a minimal error related to GTK. But nothing about Calendar or authentication. Actually, nothing but the GTK error.
Normally the quota issue starts 1.5 to 2 hours before midnight google time. Today it started 9 hours before.
*** Bug 772436 has been marked as a duplicate of this bug. ***
I'm sorry for the delay, I didn't forget of this, I was distracted by other things while still thinking of a not-so-evil way of dealing with this. I come up with the below commits. I built also a test package for Fedora with the fix included, thus I'd like to ask for an early testing in the real environment. The package evolution-data-server-3.20.5-4.4.fc24 can be found here: http://koji.fedoraproject.org/koji/taskinfo?taskID=15970613 Just click on the build link and then download the packages for your architecture. Do not forget to restart the machine, to make sure the new binaries are used (re-login is not enough on Fedora 24). The package includes the patch from comment #15, please run evolution from console and watch the warnings there. Thanks in advance. I'm still not sure of the hang on message send Patrick is facing, thus I'll keep this bug opened for now. Created commit 1231c17 in eds master (3.23.1+) Created commit e5aeca3 in eds gnome-3-22 (3.22.1+)
(In reply to Milan Crha from comment #31) > I'm sorry for the delay, I didn't forget of this, I was distracted by other > things while still thinking of a not-so-evil way of dealing with this. I > come up with the below commits. I built also a test package for Fedora with > the fix included, thus I'd like to ask for an early testing in the real > environment. The package evolution-data-server-3.20.5-4.4.fc24 can be found > here: > http://koji.fedoraproject.org/koji/taskinfo?taskID=15970613 > Just click on the build link and then download the packages for your > architecture. Do not forget to restart the machine, to make sure the new > binaries are used (re-login is not enough on Fedora 24). The package > includes the patch from comment #15, please run evolution from console and > watch the warnings there. Thanks in advance. > > I'm still not sure of the hang on message send Patrick is facing, thus I'll > keep this bug opened for now. > > Created commit 1231c17 in eds master (3.23.1+) > Created commit e5aeca3 in eds gnome-3-22 (3.22.1+) OK, testing now. Why is a session restart not enough? I rebooted anyway but I'd like to understand why.
Because when you logout the systemd (or whatever) lefts the session running anyway, on Fedora 24. See https://bugzilla.redhat.com/show_bug.cgi?id=1340203 Due to that there can be still used old D-Bus services, instead of new.
(In reply to Milan Crha from comment #33) > Because when you logout the systemd (or whatever) lefts the session running > anyway, on Fedora 24. See > https://bugzilla.redhat.com/show_bug.cgi?id=1340203 > > Due to that there can be still used old D-Bus services, instead of new. I have KillUserProcesses=true in /etc/systemd/logind.conf, so all user processes are killed on logout.
Just a quick update to say that since installing evolution-data-server-3.20.5-4.4.fc24.x86_64.rpm around 30 hours ago I have had zero issues of either type, i.e. no problems with Google authentication, nor problems with hanging on sending mail (or anything else). Murphy being a fellow Irishman, no doubt it will start failing as soon as I send this :-)
I updated to latest gnome-3-22 branch in latest evolution-data-server and evolution yesterday and rebooted. I still see the issue.
I was right about Murphy. I've just got this again, first time since updating to the latest version: Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. Continued use requires signup.
It seems to be two phases. First phase is "Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded." After a reboot, the next error is "Failed to login to the server: Daily Limit Exceeded. The quota will be reset at midnight Pacific Time (PT). You may monitor your quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/caldav/quotas?project=923794261470".
FWIW I see this same issue with Calendar never working with either of my Google accounts, with Ubuntu GNOME 16.10 which uses Evolution 3.22.0. When I was using Ubuntu GNOME 16.04 with both Evolution 3.18 and 3.20 I had no trouble. So far I've not had any issues sending email but I've only tried a few times. I should point out FYI, I don't have 2-step verification set up on either of my Google accounts: I'm using the old-school simple password verification. For one of my accounts it's because I'm lazy, and for the other one it's because it's a corporate gmail account and 2-step verification is not available. I get a stream of these types of messages (I subscribe to a lot of calendars so there are a lot of instances): Oct 16 08:51:01 homebase gnome-shell-cal[4508]: Error opening calendar 1472049368.29988.15@homebase: Cannot open calendar: Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. Continued use requires signup. Oct 16 08:51:02 homebase gnome-calendar[18650]: source_credentials_required_cb: Failed to authenticate 'me@gmail.com': Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. Continued use requires signup. Oct 16 08:51:04 homebase evolution-calen[4777]: ecb_gtasks_start_update: assertion 'cancellable != NULL' failed ... Oct 16 09:05:27 homebase evolution-calen[4740]: (e-source.c:4518):e_source_invoke_credentials_required_sync: runtime check failed: (dbus_source != NULL) Oct 16 09:05:27 homebase evolution-calen[4740]: caldav_do_open: Failed to call credentials required: Unknown error Oct 16 09:05:27 homebase gnome-shell-cal[4508]: Error opening calendar 1472049340.29988.7@homebase: Cannot open calendar: Data source 'Contacts' does not support OAuth 2.0 authentication
(In reply to Paul Smith from comment #39) > FWIW I see this same issue with Calendar never working with either of my > Google accounts, with Ubuntu GNOME 16.10 which uses Evolution 3.22.0. When > I was using Ubuntu GNOME 16.04 with both Evolution 3.18 and 3.20 I had no > trouble. > > So far I've not had any issues sending email but I've only tried a few times. > > I should point out FYI, I don't have 2-step verification set up on either of > my Google accounts: I'm using the old-school simple password verification. > For one of my accounts it's because I'm lazy, and for the other one it's > because it's a corporate gmail account and 2-step verification is not > available. > > I get a stream of these types of messages (I subscribe to a lot of calendars > so there are a lot of instances): > > Oct 16 08:51:01 homebase gnome-shell-cal[4508]: Error opening calendar > 1472049368.29988.15@homebase: Cannot open calendar: Failed to login to the > server: Daily Limit for Unauthenticated Use Exceeded. Continued use requires > signup. > Oct 16 08:51:02 homebase gnome-calendar[18650]: > source_credentials_required_cb: Failed to authenticate 'me@gmail.com': > Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. > Continued use requires signup. > Oct 16 08:51:04 homebase evolution-calen[4777]: ecb_gtasks_start_update: > assertion 'cancellable != NULL' failed ... > Oct 16 09:05:27 homebase evolution-calen[4740]: > (e-source.c:4518):e_source_invoke_credentials_required_sync: runtime check > failed: (dbus_source != NULL) > Oct 16 09:05:27 homebase evolution-calen[4740]: caldav_do_open: Failed to > call credentials required: Unknown error Oct 16 09:05:27 homebase > gnome-shell-cal[4508]: Error opening calendar 1472049340.29988.7@homebase: > Cannot open calendar: Data source 'Contacts' does not support OAuth 2.0 > authentication FWIW I have two-factor authentication on both my accounts, both the normal Gmail one and my corporate (university) Google Apps one.
(In reply to Patrick OCallaghan from comment #37) > I was right about Murphy. I've just got this again, first time since > updating to the latest version: > > Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. > Continued use requires signup. Just an update on this. I haven't seen the problem again in the past few days, I think since installing evolution-data-server-3.20.5-5.fc24.x86_64
(In reply to Paul Smith from comment #39) > gnome-shell-cal[4508]: Error opening calendar 1472049340.29988.7@homebase: > Cannot open calendar: Data source 'Contacts' does not support OAuth 2.0 > authentication This one is odd ^^^. It says "opening calendar", but it names "Contacts". Could you search ~/.config/evolution/sources and ~/.cache/evolution/sources (I'm not sure in which it is) for a 1472049340.29988.7@homebase.source file and paste the content of it here (with censored private information), then also it's Parent=xxx source file (it's xxx.source, which should reference the Method=OAuth or Method=Google; similar censoring will be required here). The files will show it, but anyway, did you configure the accounts in GOA or directly in the evolution?
(In reply to Patrick OCallaghan from comment #41) > (In reply to Patrick OCallaghan from comment #37) > > I was right about Murphy. I've just got this again, first time since > > updating to the latest version: > > > > Failed to login to the server: Daily Limit for Unauthenticated Use Exceeded. > > Continued use requires signup. > > Just an update on this. I haven't seen the problem again in the past few > days, I think since installing evolution-data-server-3.20.5-5.fc24.x86_64 I think there's some special condition to trigger it, which happens close to the token expiration time, thus it's hard to reproduce for me. It's only a theory I have about it.
Comment on attachment 335986 [details] [review] eds patch I forgot to mark this patch as committed, it's part of commits from comment #31.
That particular source file is now gone. I created and deleted the accounts a number of times, both through Evolution directly and also through GOA. I'm not sure which of those attempts that error message was related to, unfortunately :( I've only upgraded my home system, not my work system, and I've been out and about in the evenings this week so I've not had a chance to check things. Now that I get back to it, my calendar is actually working now with no errors! I restarted Evolution and it still works. When I have a chance to sit down at my system again (maybe not until this weekend) I'll try logging out and back in / rebooting and see if I can get it back into a non-working state and collect more details about exactly what I did.
A change from bug #773248 is closely related to this issue. There are common parts for both GOA configured and in-the-evolution configured Google calendars, which are addressed by this change. For anyone interested, here is built evolution-data-server-3.20.5-5.1.fc24 with that fix included: http://koji.fedoraproject.org/koji/taskinfo?taskID=16149988
(In reply to Milan Crha from comment #46) > A change from bug #773248 is closely related to this issue. There are common > parts for both GOA configured and in-the-evolution configured Google > calendars, which are addressed by this change. For anyone interested, here > is built evolution-data-server-3.20.5-5.1.fc24 with that fix included: > http://koji.fedoraproject.org/koji/taskinfo?taskID=16149988 OK, testing. I'll report if anything bad happens but the previous version seemed to be working well for me.
(In reply to Patrick OCallaghan from comment #47) > OK, testing. I'll report if anything bad happens but the previous version > seemed to be working well for me. Thanks. If I'm not mistaken, then you still use the in-the-evolution configured Google account, right?
(In reply to Milan Crha from comment #48) > (In reply to Patrick OCallaghan from comment #47) > > OK, testing. I'll report if anything bad happens but the previous version > > seemed to be working well for me. > > Thanks. If I'm not mistaken, then you still use the in-the-evolution > configured Google account, right? That's right.
(In reply to Patrick OCallaghan from comment #47) > (In reply to Milan Crha from comment #46) > > A change from bug #773248 is closely related to this issue. There are common > > parts for both GOA configured and in-the-evolution configured Google > > calendars, which are addressed by this change. For anyone interested, here > > is built evolution-data-server-3.20.5-5.1.fc24 with that fix included: > > http://koji.fedoraproject.org/koji/taskinfo?taskID=16149988 > > OK, testing. I'll report if anything bad happens but the previous version > seemed to be working well for me. Just got this, which is new: Error while Storing folder 'XXXXXXXX'. Unable to move deleted messages: Failed to select mailbox: Server sent unexpected response: [OK] It happened after I selected all Unread messages in the folder, hit Delete and Expunge, then immediately switched to a different folder. After I dismissed the error I returned to the XXXXXXXX folder and the messages had been deleted and expunged. Of course that might be unrelated to the current bug, but I haven't seen it before so I'm reporting here just in case.
(In reply to Patrick OCallaghan from comment #50) > Of course that might be unrelated to the current bug, but I haven't seen it > before so I'm reporting here just in case. I believe it's unrelated. There is no indication it being related to the authentication token. having an IMAPx log with the faulty behaviour would help to narrow this down. A way to get it is: $ CAMEL_DEBUG=imapx:io evolution which stores raw data between the server and the IMAPx code, thus surely nothing you'd like to share in public. In any case, if you manage to reproduce it, please file a new bug report. We can always mark it as a duplicate of this one. Thanks in advance.
I added a hussam-project account on google with google apps apis enabled. I recompiled goa and evolution-data-server with my key this morning. I restarted gnome. the google dashboard logged around three hundred 403 attempts on tasks api before working again. caldav worked immediately. No other problems since then. I am monitoring the query count on the dashboard and it seems very low. I will know in a few mornings if the tasks issue was an accident.
(In reply to Hussam Al-Tayeb from comment #52) > the google dashboard logged around three hundred 403 > attempts on tasks api before working again. Does the addressbook API work the same? Both tasks and contacts use libgdata and give it its own authorizer subclass, which is (almost) the same for the both. That may make them work the same. I noticed in the logs of the calendar factory that libgdata can try with a wrong (outdated) OAuth2 token, which results into 403 or 401, I do not recall precisely. Then it asks the authorizer to refresh credentials, which picks the new token and then re-tries with it and eventually succeeds. It did so here at least. It can fail like once per hour, due to the token being given for an hour, which makes it around 24 failed attempts per day per user for the tasks. I know that libgdata provides also OAuth2 authorizer. I didn't investigate this further yet, maybe the eds should subclass the OAuth2 authorizer instead, to avoid the failed attempt with the expired token. It requires a deeper look.
Address book sync didn't cause any errors. Tasks sync could have also been trying to access the expired token I guess? I have no idea why it pushed close to 300 attempts at once though so I thought it may be worth mentioning. No errors since then though so it may have been a glitch. I am perfectly happy right now. Would it be a good idea for the evolution team to post on distributors-list and suggest each distribution uses its own Google API keys?
(In reply to Hussam Al-Tayeb from comment #54) > Would it be a good idea for the evolution team to post on distributors-list > and suggest each distribution uses its own Google API keys? I do not think so. Better to fix the software. You won't cover "old distributions" anyway. And maintaining the key adds some maintenance burden. There are caveats, as always. I didn't hear from others for the past two weeks, but I'll rather wait for the end of November, then I'll ask for the experience from those whom use patched evolution-data-server and if it'll be positive, then I'll release 3.20.6, thus the distributions which use 3.20.x series will be able to pick the fixes easily. The today's 3.22.2 release has the fixes already included.
I just got the "Failed to login to the server: Daily Limit Exceeded." message on bootup, and starting evolution. I didn't run anything before (since last night), and it was a reboot, so any cached GOA tokens should be gone. evolution-data-server-3.20.5-5.1.fc24.x86_64 It's mostly for 'calendar account@gmail: Contacts'. There are two accounts, so it loops over both accounts. 'Reconnect' gets the same error; 'X' makes the error go away. The accounts are set to what I assume are the defaults: use for mail, calendar, contacts, documents, photos; but not for files, printers.
Thanks for the update. That's kind of expected and a reason why Hussam uses his own application "keys". Also see: https://mail.gnome.org/archives/evolution-list/2016-October/msg00124.html
Please see [1] and if you can, feel free to respond either here or on the list. Thanks in advance. [1] https://mail.gnome.org/archives/evolution-list/2016-November/msg00130.html
I made an evolution-data-server 3.20.6 release yesterday. The changes are already part of the evolution-data-server 3.22.2. It's up to the distribution maintainers to pick that release and include them in the distribution.
Milan, I see that Debarshi pushed a new gnome-online-accounts release this week that changed the Google API key there (since as you discussed earlier, people using old versions of e-d-s will cause problems for users using fixed versions as long as the same API key is used). If I understand correctly, e-d-s can use either gnome-online-accounts or its own method to authenticate with Google online services. Do you plan to similarly replace Evolution's Google API key?
Also, do you know if e-d-s 3.18 has the same Google authentication issues that e-d-s 3.20 and 3.22 do? I'm asking because I want to know whether I need to try to backport these fixes to Ubuntu 16.04 LTS too.
The internal Google OAuth2 authentication had been introduced in eds 3.20.0 (thus it's pretty new), for which I released eds 3.20.6 with all the yet-known fixes recently, in a hope that distros which still use 3.20.x will update and thus will help all users. I'm not going to change the Google API keys in eds, because the statistics which the Google server provides indicate that the usage is pretty fine with the internal eds Google API keys. Just compare, the numbers from the Tuesday this week: - for the GOA, the past 24 hours: CalDAV API - 104 millions of requests, 99 millions errors (95.34%) Tasks API - 65 millions of requests, 65 millions errors (99.93%) - for the eds, the past 24 hours: CalDAV API - 399 thousands of requests, 5 thousands errors (1.37%) CardDAV API - 59 thousands of requests, 12 errors (0.02%) Contacts API - 30 thousands of requests, 31 errors (0.1%) Tasks API - 9 thousands of requests, 0 errors (0%)
Fedora 25 + GNOME 3.22 + evolution-data-server-3.22.2 I've noticed issues with Google calendar functionality too. Multiple evolution-calendar-factory-subprocess processes are running, and at least some of them uploads and downloads 7 KB/s constantly. If I turn off Calendars in Gnome Online Accounts, this stops. Tasks and contacts don't do this.
Milan, thank you for the thorough answer. I think I need to backport the GOA key change for Ubuntu 16.04 LTS then? It never had the e-d-s Google auth key in use (even in the GNOME3 Staging PPA for 16.04, we build with --disable-google-auth because we didn't want to add a webkit1 dependency).
(In reply to Jeremy Bicha from comment #64) > I think I need to backport the GOA key change for Ubuntu 16.04 LTS then? Please do not do that unless you also update evolution-data-server. That way you'd just break the experience for everyone else, which is the opposite why the new keys had been created. Such behaviour (only using the new GOA keys) would be considered hostile, from my point of view. You are free to create Ubuntu specific Google API keys and use then with GOA, of course, just do not use those upstream GOA keys on their own. Having Ubuntu specific keys can also mean that you can have branding of Ubuntu shown, when user's will create the account in GOA (at the place where the list of accepted privileges is, at the bottom with Allow/Deny buttons). By the way, I do not know what versions the Ubuntu 16.04 ships, especially the evolution-data-server and GNOME Online Accounts. Rishi is preparing 3.20.5 release of the gnome-online-accounts [1], but still, unless you update to the latest evolution-data-server 3.20.6 release had been made few weeks ago), then it'll just break things to others. In other words, it's both or nothing state. > we build with --disable-google-auth because we didn't want to add a webkit1 > dependency) The evolution-data-server uses the same webkit version as the evolution, thus you have there the webkit dependency already. 3.22.0+ uses WebKit2. [1] https://git.gnome.org/browse/gnome-online-accounts/commit/?h=gnome-3-20
Milan, I'm sorry you think I'm possibly acting hostile here. I think I am trying to do the right thing here by asking questions before taking action, but I think action is needed. Let me rephrase what I said in comment 61. Ubuntu 16.04 LTS "xenial" has evolution-data-server 3.18.5. [1] If I understood you correctly, there is nothing to fix for Google authentication in 3.18.5. However, my understanding is that the bugs in early versions of 3.20 and 3.22 are causing everyone using the GOA keys to receive Google authentication errors. Therefore, this is what I'm proposing: 1. Upgrade users to non-buggy versions of e-d-s. For Ubuntu, only 16.10 is affected and I did that upload this week. Ubuntu's usual policy is that these updates are tested ("proposed") for 7 days first. 2. Once the e-d-s update is fully released, release the goa key update to 16.10. 3. Update the goa keys for all other supported versions of Ubuntu too. This does not need to wait for e-d-s updates since there are no updates needed for e-d-s 3.18 and lower. [1] https://launchpad.net/ubuntu/+source/evolution-data-server
Also to clarify, for Ubuntu 16.04 LTS with the GNOME3 Staging PPA [1] we have evolution-data-server 3.20. Because that version used webkit1, we did not enable Google authentication there. For 16.10, we shipped e-d-s 3.22 with Google authentication enabled since it used webkit2. Maybe I should not even have mentioned the PPA here since it has 3.20.6 now anyway. [1] https://launchpad.net/~gnome3-team/+archive/ubuntu/gnome3-staging/+packages?field.series_filter=xenial
I wish the pre-3.20.x would not be affected, but it's not the case. While the current versions claim error, you might notice all those "Daily Limit Exceeded", the 3.18.x and below silently ignore the error and keep polling the Google server with no gain (and just the bandwidth wasting). Thus using the new GOA keys with anything below eds 3.20.6 is not a good idea. That's also the reason why GOA had released only 3.20 and 3.22 version (or will shortly). I didn't mean that you are acting hostile, I said that I would consider a hostile behaviour if only the new keys were taken to version where they were not released for by the upstream. I appreciate that you are asking first, and I'm sorry if I sounded rude. It wasn't my intention. Comment #57 contains a link where some more detailed explanation is written, with some follow-up messages as well.
Ok, I filed a separate bug for 3.18 then: https://bugzilla.gnome.org/776161
I am now getting Failed to authenticate: Failed to obtain an access token for 'xxxx@gmail.com': Failed to refresh access token (rest-proxy-error-quark, 401): Unauthorized evolution-data-server-3.22.3-1.fc25.x86_64 gnome-online-accounts-3.22.3-1.fc25.x86_64
(In reply to Berend De Schouwer from comment #70) > I am now getting > > Failed to authenticate: Failed to obtain an access token for > 'xxxx@gmail.com': Failed to refresh access token (rest-proxy-error-quark, > 401): Unauthorized > > evolution-data-server-3.22.3-1.fc25.x86_64 > gnome-online-accounts-3.22.3-1.fc25.x86_64 Apologies, the credentials had expired -- possibly due to a new API key. The error message could be clearer, though... :)