account-polld tries hard to open a trust session and fails repeatedly

Bug #1496773 reported by Dave Morley on 2015-09-17
22
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Canonical System Image
High
Bill Filler
account-polld (Ubuntu)
High
Niklas Wenzel

Bug Description

Affects <= OTA7

Reproduce:
1. Add a google account and allow gmail
2. Make sure it works, (account n has 0 new updates etc…)
3. Change the account's password

Expected:
By looking at the logs, I'd expect the output to say something along the lines of "authentication failed, stopping poll"

Actual:
You'll see an endless repetition of:
2015/10/13 13:39:13 Polling account 7
2015/10/13 13:39:14 Error while polling 7: Token expired
2015/10/13 13:39:14 Poll for account 7 has failed: Token expired
2015/10/13 13:39:14 Ending poll for account 7
2015/10/13 13:39:14 New account data for existing account with id 7
2015/10/13 13:39:14 Starting poll for account 7
2015/10/13 13:39:14 Polling account 7

Memory on device is at a minimum too. As can be seen here http://paste.ubuntu.com/12436034/ this system has no app open.

Logs: I have included the entire .cache/upstart folder and syslog.

Related branches

Dave Morley (davmor2) wrote :
Jean-Baptiste Lallement (jibel) wrote :

This message is printed in a loop in dbus.log

Activating service name='com.google.code.AccountsSSO.SingleSignOn'
Successfully activated service 'com.google.code.AccountsSSO.SingleSignOn'
Activating service name='com.nokia.singlesignonui'
Successfully activated service 'com.nokia.singlesignonui'
Invalid prompt session: /build/mir-xon0uu/mir-0.14.1+15.04.20150821/src/server/scene/prompt_session_manager_impl.cpp(137): Throw in function virtual std::shared_ptr<mir::scene::PromptSession> mir::scene::PromptSessionManagerImpl::start_prompt_session_for(const std::shared_ptr<mir::scene::Session>&, const mir::scene::PromptSessionCreationParameters&) const
Dynamic exception type: N5boost16exception_detail10clone_implINS0_19error_info_injectorISt13runtime_errorEEEE
std::exception::what: Could not identify application session

Couldn't setup prompt session
UiProxy initialization failed!

Jean-Baptiste Lallement (jibel) wrote :

From unity8.log online-accounts-service keeps restarting over and over again

qtmir.mir: SessionListener::starting - this= SessionListener(0xb1935214) session= 0x92003a0c
qtmir.sessions: SessionManager::onSessionStarting - sessionName= online-accounts-service
qtmir.sessions: Session::Session() "online-accounts-service"
qtmir.mir: SessionListener::stopping - this= SessionListener(0xb1935214) session= 0x92003a0c
qtmir.sessions: SessionManager::onSessionStopping - sessionName= online-accounts-service
qtmir.sessions: Session::release "online-accounts-service"
qtmir.sessions: Session::~Session() "online-accounts-service"

affects: dbus (Ubuntu) → ubuntu-system-settings-online-accounts (Ubuntu)
Alberto Mardegan (mardy) wrote :

There is a process continuosly invoking online accounts, presumably with wrong parameters. Unfortunately I cannot tell which process it is from the logs.

Dave, can you still reproduce it? Next time it happens, please run:

   OAU_LOGGING_LEVEL=2 OAU_DAEMON_TIMEOUT=9999 online-accounts-service

and attach the output here.

Looking at top, I suspect that sync-monitor could be the client continuously invoking Online Accounts. I'm adding sync-monitor to the bug, just to have some people confirm whether it's possible that a failed invocation to online accounts results in a loop.

Changed in ubuntu-system-settings-online-accounts (Ubuntu):
status: New → Triaged
kevin gunn (kgunn72) wrote :

what's interesting is going back to the previous unity8.log (unity8.log7) in the zip. at the end of it is the beginning of that spew pattern listed in the previous comment.

Dave Morley (davmor2) wrote :
Download full text (14.5 KiB)

davmor2@stryder:~$ adb shell
ounts-serviceu-phablet:~$ OAU_LOGGING_LEVEL=2 OAU_DAEMON_TIMEOUT=9999 online-acc
signonui-service.cpp 227 queryDialog Got request: QMap(("AppId", QVariant(QString, "unconfined") ) ( "Caption" , QVariant(QString, "google") ) ( "ClientData" , QVariant(QVariantMap, QMap(("AllowedSchemes", QVariant(QStringList, ("https", "http")) ) ( "AuthPath" , QVariant(QString, "o/oauth2/auth?access_type=offline") ) ( "ClientId" , QVariant(QString, "759250720802-4sii0me9963n9fdqdmi7cepn6ub8luoh.apps.googleusercontent.com") ) ( "ClientSecret" , QVariant(QString, "juFngKUcuhB7IRQqHtSLavqJ") ) ( "ForceClientAuthViaRequestBody" , QVariant(bool, true) ) ( "Host" , QVariant(QString, "accounts.google.com") ) ( "RedirectUri" , QVariant(QString, "https://wiki.ubuntu.com/") ) ( "ResponseType" , QVariant(QString, "code") ) ( "Scope" , QVariant(QStringList, ("https://docs.google.com/feeds/", "https://www.googleapis.com/auth/googletalk", "https://www.googleapis.com/auth/userinfo.email", "https://www.googleapis.com/auth/userinfo.profile", "https://picasaweb.google.com/data/", "https://mail.google.com/", "https://www.google.com/m8/feeds/", "https://www.googleapis.com/auth/calendar", "https://www.googleapis.com/auth/carddav")) ) ( "TokenPath" , QVariant(QString, "o/oauth2/token") ) ) ) ) ( "FinalUrl" , QVariant(QString, "https://wiki.ubuntu.com/") ) ( "Identity" , QVariant(uint, 2) ) ( "Mechanism" , QVariant(QString, "web_server") ) ( "Method" , QVariant(QString, "oauth2") ) ( "OpenUrl" , QVariant(QString, "https://accounts.google.com/o/oauth2/auth?access_type=offline&client_id=759250720802-4sii0me9963n9fdqdmi7cepn6ub8luoh.apps.googleusercontent.com&redirect_uri=https://wiki.ubuntu.com/&state=473866745&response_type=code&scope=https://docs.google.com/feeds/ https://www.googleapis.com/auth/googletalk https://www.googleapis.com/auth/userinfo.email https://www.googleapis.com/auth/userinfo.profile https://picasaweb.google.com/data/ https://mail.google.com/ https://www.google.com/m8/feeds/ https://www.googleapis.com/auth/calendar https://www.googleapis.com/auth/carddav") ) ( "Pid" , QVariant(int, 2522) ) ( "StoredIdentity" , QVariant(bool, true) ) ( "UserName" , QVariant(QString, "") ) ( "requestId" , QVariant(QString, "/com/google/code/AccountsSSO/SingleSignOn/AuthSession_1") ) )
utils.cpp 49 apparmorProfileOfPeer App ID: "unconfined"
request-manager.cpp 113 runQueue Head: OnlineAccountsUi::Request(0x1146508)
Invalid prompt session: /build/mir-xon0uu/mir-0.14.1+15.04.20150821/src/server/scene/prompt_session_manager_impl.cpp(137): Throw in function virtual std::shared_ptr<mir::scene::PromptSession> mir::scene::PromptSessionManagerImpl::start_prompt_session_for(const std::shared_ptr<mir::scene::Session>&, const mir::scene::PromptSessionCreationParameters&) const
Dynamic exception type: N5boost16exception_detail10clone_implINS0_19error_info_injectorISt13runtime_errorEEEE
std::exception::what: Could not identify application session

Couldn't setup prompt session
UiProxy initialization failed!
signonui-service.cpp 227 queryDialog Got request: QMap(("AppId", QVariant(QString, "unconfined") ) ( "Caption" , QVariant(QString, "google") ...

Alberto Mardegan (mardy) wrote :

Thanks Dave for this info. Also, I checked with Dave on IRC that PID 2522 (from which the request starts) is account-polld:

    phablet 2522 0.0 1.4 934112 14176 ? Ssl Sep09 9:38 /usr/bin/account-polld

online-accounts-service tries to create a trusted session having PID 2522 as initiatior, but since account-polld has no window associated with it, mir cannot create the trust session.
I think there are two problems here:
1) when talking to signond, account-polld should set the "UiPolicy" parameter to 2 (aka NoUserInteractionPolicy), so that we won't try to open a trust session for it.
2) account-polld should not continuosly retry authenticating if the previous attempt just failed.

no longer affects: sync-monitor (Ubuntu)
no longer affects: ubuntu-system-settings-online-accounts (Ubuntu)
summary: - Dbus-daemon-system-fork on ota6 is using large amounts of CPU
+ account-polld tries hard open a trust session and fails repeatedly
Changed in canonical-devices-system-image:
importance: Undecided → High
Changed in account-polld (Ubuntu):
importance: Undecided → High
status: New → Triaged
summary: - account-polld tries hard open a trust session and fails repeatedly
+ account-polld tries hard to open a trust session and fails repeatedly
Changed in canonical-devices-system-image:
status: New → Confirmed
assignee: nobody → Bill Filler (bfiller)
Changed in canonical-devices-system-image:
milestone: none → ww46-2015
tags: added: push
Niklas Wenzel (nikwen) wrote :

One can also find the following line in the account-polld log:

2015/09/17 09:29:13 Account 2 failed to authenticate: GDBus.Error:com.google.code.AccountsSSO.SingleSignOn.Error.UserInteraction: userActionFinished error: 2

> 2) account-polld should not continuosly retry authenticating if
> the previous attempt just failed.

Agreed, but I still think that it should try at least a few times, otherwise we get LP: #1405649 again. To me it happens very often that after rebooting the first authentication cycle fails because the phone has not established a network connection yet.

Niklas Wenzel (nikwen) wrote :
Niklas Wenzel (nikwen) wrote :
Niklas Wenzel (nikwen) wrote :

I also tried to fix #1 but I couldn't find out how to get libsignon-glib to pass that parameter. Alberto, do you have any ideas here?

Alberto Mardegan (mardy) wrote :

Thanks Niklas for looking into this!
In accounts/account-watcher.c, in the account_info_login() function, there is a line calling ag_auth_data_get_login_parameters(), which gets passed NULL as a second parameter. Instead of passing NULL, we should build a GVariant containing a dictionary of extra parameters which we want to use.

You can see a similar example here:
https://github.com/GNOME/empathy/blob/master/libempathy/empathy-uoa-auth-handler.c#L177

The only difference is that instead of SIGNON_POLICY_REQUEST_PASSWORD you should use SIGNON_POLICY_NO_USER_INTERACTION.

Niklas Wenzel (nikwen) wrote :

Alberto, thank you for the example!

I had already suspected that we needed to pass a GVariant to ag_auth_data_get_login_parameters() but I couldn't figure out how to properly build that one and which key to use when adding the SIGNON_POLICY_NO_USER_INTERACTION value. I guess I need to read a proper introduction to Glib at some point to get a proper overview of how it works. That said, I learned a lot from the example. Thanks again!

I implemented this in https://code.launchpad.net/~nikwen/account-polld/no-user-interaction/+merge/272309. I've tested normal operation and that seems to work fine. I haven't tried to reproduce this bug though. :)

Niklas Wenzel (nikwen) on 2015-09-24
Changed in account-polld (Ubuntu):
assignee: nobody → Niklas Wenzel (nikwen)
status: Triaged → In Progress
Niklas Wenzel (nikwen) wrote :

Both MPs should be ready for review now. :)

description: updated
Bill Filler (bfiller) on 2015-10-23
Changed in account-polld (Ubuntu):
status: In Progress → Fix Released
Changed in canonical-devices-system-image:
status: Confirmed → Fix Committed

 account-polld (0.1+15.04.20151016.1-0ubuntu1) vivid; urgency=medium
 .
   [ Alberto Mardegan ]
   * Remove non-working facebook integration. (LP: #1493733)
   * debian/control, debian/account-polld.conf:
     Remove mentions of Facebook from the descriptions.
 .
   [ Niklas Wenzel ]
   * Tell libsignon-glib not to open a trust session by passing
     SIGNON_POLICY_NO_USER_INTERACTION as the
     SIGNON_SESSION_DATA_UI_POLICY value (part of the issue experienced
     in LP: #1496773) (LP: #1496773)
   * When authentification of an account fails continuously, we should
     wait a bit before trying again (part of the issue experienced in LP:
     #1496773) (LP: #1496773)

Changed in canonical-devices-system-image:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Bug attachments