Bug 339223 - Infinite loop due to KWallet usage
Summary: Infinite loop due to KWallet usage
Status: VERIFIED FIXED
Alias: None
Product: plasma-nm
Classification: Plasma
Component: general (show other bugs)
Version: 0.9.3.4
Platform: Arch Linux Linux
: NOR normal
Target Milestone: ---
Assignee: Lukáš Tinkl
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-09-20 10:02 UTC by Peter Wu
Modified: 2014-09-24 08:35 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Peter Wu 2014-09-20 10:02:50 UTC
Under certain conditions (password request for a WPA2 network?), the CPU usage rises and the .xsession-errors log grows dramatically (I observed a loud fan and a 3 GiB log file).

The lines that are repeatedly printed are:
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"

Looking in the backtrace (see additional info), I see a strange pattern:
1. SecretAgent::useWallet() calls KWallet::Wallet::openWallet and connects two signals to it, including KWallet::Wallet::walletOpened, connected to SecretAgent::walletOpened. This is only done if m_wallet is NULL.
2. walletOpened calls processNext. m_calls contains one element for SecretAgent::GetSecrets, so call processGetSecrets. Somehow m_wallet is NULL.
3. processGetSecrets calls useWallet, useWallet gets called. As m_wallet is NULL, it will get a new wallet and connect signals.
4. Back in `processGetSecrets, m_wallet->isOpen()` is apparantly false, so the request sticks in the queue.
5. goto 1.

Hmm.

Reproducible: Always

Steps to Reproduce:
0. (optional) kill the existing kded4 and start kded4 using plasma-nm which has debugging symbols compiled in: KDEDIRS=/tmp/kdeplasma-applets-plasma-nm-no-mm/pkg/kdeplasma-applets-plasma-nm-no-mm/usr kded4
1. Enter an environment with a wireless network which has no credentials stored in NM, so KWallet must be used.
2. Wait for NM to connect and request a password.

Actual Results:  
No wireless network connection is established, instead the .xsession-errors log get flooded and the CPU gets burnt.

Expected Results:  
KWallet should supply password (or failing on that, NM should ask for a password). Certainly not CPU burning.

# manually compiled plasma-nm without modemmanager and with debugging symbols enabled
(gdb) bt
#0  SecretAgent::useWallet (this=0x18ab230) at plasma-nm-0.9.3.4/kded/secretagent.cpp:448
#1  0x00007ff4bb9cd2c8 in SecretAgent::processGetSecrets (this=0x18ab230, request=...) at plasma-nm-0.9.3.4/kded/secretagent.cpp:310
#2  0x00007ff4bb9cf388 in SecretAgent::processNext (this=0x18ab230) at plasma-nm-0.9.3.4/kded/secretagent.cpp:272
#3  0x00007ff4bb9c5f64 in SecretAgent::qt_static_metacall (_o=0x18ab230, _id=-1271474624, _a=0x7fffb436d890, _c=<optimized out>) at build/kded/moc_secretagent.cpp:72
#4  0x00007ff4dc5cf30a in QMetaObject::activate(QObject*, QMetaObject const*, int, void**) () from /usr/lib/libQtCore.so.4
#5  0x00007ff4dd3f28b2 in KWallet::Wallet::walletOpened(bool) () from /usr/lib/libkdeui.so.5
#6  0x00007ff4dc5cf30a in QMetaObject::activate(QObject*, QMetaObject const*, int, void**) () from /usr/lib/libQtCore.so.4

stderr (.xsession-errors):
kded(566)/networkstatus NetworkStatusModule::solidNetworkingStatusChanged: SolidNetwork changed status:  1
kded(566)/networkstatus NetworkStatusModule::setNetworkStatus: "SolidNetwork" ,  1
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
kded(566)/networkstatus NetworkStatusModule::solidNetworkingStatusChanged: SolidNetwork changed status:  3
kded(566)/networkstatus NetworkStatusModule::setNetworkStatus: "SolidNetwork" ,  3
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
NetworkManagerQt "plasma-desktop" ( 628 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
NetworkManagerQt "plasma-desktop" ( 628 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
kded(566)/networkstatus NetworkStatusModule::solidNetworkingStatusChanged: SolidNetwork changed status:  4
kded(566)/networkstatus NetworkStatusModule::setNetworkStatus: "SolidNetwork" ,  4
kded(566)/networkstatus NetworkStatusModule::solidNetworkingStatusChanged: SolidNetwork changed status:  4
kded(566)/networkstatus NetworkStatusModule::setNetworkStatus: "SolidNetwork" ,  4
void NetworkManager::ActiveConnection::propertiesChanged(const QVariantMap&) Unhandled property "Dhcp4Config" 
void NetworkManager::ActiveConnection::propertiesChanged(const QVariantMap&) Unhandled property "Dhcp6Config" 
void NetworkManager::ActiveConnection::propertiesChanged(const QVariantMap&) Unhandled property "Ip4Config" 
void NetworkManager::ActiveConnection::propertiesChanged(const QVariantMap&) Unhandled property "Ip6Config" 
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/7" 
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/7" 
NetworkManagerQt "kded" ( 566 ) void NetworkManager::NetworkManagerPrivate::propertiesChanged(const QVariantMap&) :    "/org/freedesktop/NetworkManager/ActiveConnection/6" 
virtual NMVariantMapMap SecretAgent::GetSecrets(const NMVariantMapMap&, const QDBusObjectPath&, const QString&, const QStringList&, uint) 
Path: "/org/freedesktop/NetworkManager/Settings/6" 
Setting name: "802-11-wireless-security" 
Hints: () 
Flags: 1 
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
kwalletd(3062)/kdeui (Wallet) KWalletD::openAsync: openAsync for  ":1.2"
kded(566)/kdeui (Wallet) KWallet::Wallet::openWallet: Pass a valid window to KWallet::Wallet::openWallet().
Comment 1 Peter Wu 2014-09-20 10:14:22 UTC
The backtrace for the first call (break on SecretAgent::useWallet):

#0  0x00007fef66c796c0 in SecretAgent::useWallet() const@plt () from kded_networkmanagement.so
#1  0x00007fef66c812c8 in SecretAgent::processGetSecrets (this=0xbd5330, request=...) at plasma-nm-0.9.3.4/kded/secretagent.cpp:310
#2  0x00007fef66c83388 in SecretAgent::processNext (this=this@entry=0xbd5330) at plasma-nm-0.9.3.4/kded/secretagent.cpp:272
#3  0x00007fef66c83eb6 in SecretAgent::GetSecrets (this=0xbd5330, connection=..., connection_path=..., setting_name=..., hints=..., flags=1) at plasma-nm-0.9.3.4/kded/secretagent.cpp:86
#4  0x00007fef664d91a3 in SecretAgentAdaptor::GetSecrets(QMap<QString, QMap<QString, QVariant> > const&, QDBusObjectPath const&, QString const&, QStringList const&, unsigned int) () from /usr/lib/libNetworkManagerQt.so.1
#5  0x00007fef664d9302 in ?? () from /usr/lib/libNetworkManagerQt.so.1
#6  0x00007fef664d95e3 in SecretAgentAdaptor::qt_metacall(QMetaObject::Call, int, void**) () from /usr/lib/libNetworkManagerQt.so.1
Comment 2 Jan Grulich 2014-09-22 07:27:03 UTC
That's really strange. When processGetSecrets() is called after KWallet is opened, then the pointer to m_wallet shouldn't be definitely NULL, unless it failed to open it. Hmm, as I see it will keep trying to open it again and again. We will have to probably add there a flag that indicates that it previously failed to open it and prevent from opening it again.
Comment 3 Jan Grulich 2014-09-22 11:38:36 UTC
Git commit 6d2593bc09cd39a33b3ac2cd33f9248790d01da3 by Jan Grulich.
Committed on 22/09/2014 at 11:38.
Pushed by grulich into branch 'master'.

Do not keep trying to open KWallet if we failed before
REVIEW:120313

M  +16   -4    kded/secretagent.cpp
M  +1    -0    kded/secretagent.h

http://commits.kde.org/plasma-nm/6d2593bc09cd39a33b3ac2cd33f9248790d01da3
Comment 4 Jan Grulich 2014-09-22 11:46:09 UTC
Git commit 634738b27ed14508d17e9a99ebd8760d8c9edb01 by Jan Grulich.
Committed on 22/09/2014 at 11:38.
Pushed by grulich into branch '0.9.3'.

Do not keep trying to open KWallet if we failed before
REVIEW:120313

M  +16   -4    kded/secretagent.cpp
M  +1    -0    kded/secretagent.h

http://commits.kde.org/plasma-nm/634738b27ed14508d17e9a99ebd8760d8c9edb01
Comment 5 Peter Wu 2014-09-22 11:48:19 UTC
If the wallet failed to open, shouldn't a message be logged?

It is also not clear why the wallet failed to open, the daemon is certainly running and openWallet succeeded. I think this is hiding a real bug?

Does the "0" parameter to openWallet have something to do with this?
Comment 6 Jan Grulich 2014-09-22 11:58:59 UTC
Can you please try to compile plasma-nm from git (0.9.3 branch) and try it? If openWallet succeeds, then m_wallet shouldn't be NULL, in that case it could be a problem in KWallet maybe? 

Nope, the "0" parameter is for a window ID.
Comment 7 Peter Wu 2014-09-23 16:07:01 UTC
I discovered why KWallet was inaccessible. Apparently I accidentally clicked "Deny Forever" when requested to the "KDE Daemon" requested KWallet access. This is now reverted and the old unpatched plasma-nm applet works again.

The latest 0.9.3.4 tree (v0.9.3.4-15-g634738b) does not work for me. The SecretAgent::useWallet break point is never triggered and I can see the following message in my logs:
<error> [1411488098.418893] [vpn-manager/nm-vpn-connection.c:1778] get_secrets_cb(): Failed to request VPN secrets #2: (6) No agents were available for this request.

(there is no other message near this)
Comment 8 Jan Grulich 2014-09-23 16:55:57 UTC
Where did you put the break point?  Did you restart kded4 and plasma-desktop after you updated plasma-nm?
Comment 9 Peter Wu 2014-09-23 17:13:00 UTC
I killed kded4 and started it after setting KDE_DIRS:

KDEDIRS=/tmp/plasma-nm-prefix kded4

Then I attached a debugger to this:
LD_LIBRARY_PATH=/tmp/plasma-nm-prefix/kde4/ gdb -ex break\ SecretAgent::useWallet -p `pgrep kded4`

To trigger authentication, I clicked the Connect button in the applet.
Comment 10 Jan Grulich 2014-09-23 17:18:52 UTC
You also need to start plasma-desktop from your /tmp/plasma-nm-prefix, because there is a code initializing our secret agent.
Comment 11 Peter Wu 2014-09-23 17:31:45 UTC
The infinite loop is gone, but it seems that the applet does not retry the wallet should it become available at a later point (the breakpoint is not triggered). Am I correct?
Comment 12 Jan Grulich 2014-09-23 18:34:56 UTC
The applet should request secrets from KWallet only in case you are trying to activate a connection or you are editing a connection from the connection editor.
Comment 13 Jan Grulich 2014-09-24 08:35:43 UTC
Git commit 800503fec7ec25e5ab21da4006655e30fe83c2ce by Jan Grulich.
Committed on 24/09/2014 at 08:35.
Pushed by grulich into branch '0.9.3'.

Connect to the correct signal

M  +1    -1    kded/service.cpp

http://commits.kde.org/plasma-nm/800503fec7ec25e5ab21da4006655e30fe83c2ce