dbus_connection_send_with_reply_and_block eats 100% CPU then eventually times out

[Alex Brooks]

Hi Ralf,

I tried with the modifications you suggest (tracking number of 
iterations and time).
There's a magic number: in all cases it starts failing after 300274 
iterations (100% repeatable):

signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=1, relapsed=0.00127s, dt=0.001258s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=2, relapsed=0.012663s, dt=0.001231s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=3, relapsed=0.023954s, dt=0.00118s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=4, relapsed=0.035219s, dt=0.001154s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=5, relapsed=0.046478s, dt=0.001148s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=6, relapsed=0.057801s, dt=0.001208s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=7, relapsed=0.069105s, dt=0.001194s
...
... wait ~55min ...
...
signalInfo rssi=-45
TRACE(signalpoll_onefile.cpp): iter=300268, relapsed=3456.71s, dt=0.001268s
signalInfo rssi=-45
TRACE(signalpoll_onefile.cpp): iter=300269, relapsed=3456.72s, dt=0.001208s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=300270, relapsed=3456.74s, dt=0.001236s
signalInfo rssi=-38
TRACE(signalpoll_onefile.cpp): iter=300271, relapsed=3456.75s, dt=0.001205s
signalInfo rssi=-42
TRACE(signalpoll_onefile.cpp): iter=300272, relapsed=3456.76s, dt=0.001225s
signalInfo rssi=-41
TRACE(signalpoll_onefile.cpp): iter=300273, relapsed=3456.77s, dt=0.001214s
signalInfo rssi=-47
TRACE(signalpoll_onefile.cpp): iter=300274, relapsed=3456.78s, dt=0.001289s
Error: wpa_supplicant DBus error in signalPoll: Did not receive a reply. 
Possible causes include: the remote application did not send a reply, 
the message bus security policy blocked the reply, the reply timeout 
expired, or the network connection was broken.
TRACE(signalpoll_onefile.cpp): iter=300275, relapsed=3481.79s, dt=24.9997s
Error: wpa_supplicant DBus error in signalPoll: Did not receive a reply. 
Possible causes include: the remote application did not send a reply, 
the message bus security policy blocked the reply, the reply timeout 
expired, or the network connection was broken.
TRACE(signalpoll_onefile.cpp): iter=300276, relapsed=3506.8s, dt=24.9995s
Error: wpa_supplicant DBus error in signalPoll: Did not receive a reply. 
Possible causes include: the remote application did not send a reply, 
the message bus security policy blocked the reply, the reply timeout 
expired, or the network connection was broken.
TRACE(signalpoll_onefile.cpp): iter=300277, relapsed=3531.81s, dt=24.9994s



Alex


On 01/02/15 03:12, Ralf Habacker wrote:
>
> Am 31.01.2015 um 16:10 schrieb Ralf Habacker:
>>
>> Am 31.01.2015 um 14:49 schrieb Ralf Habacker:
>>>> 5 19:27, "Ralf Habacker" <ralf at habacker.de 
>>>> <mailto:ralf at habacker.de>> wrote:
>>>>
>>>>
>>>>     Am 31.01.2015 um 05:04 schrieb Alex Brooks:
>>>>     > Hi,
>>>>     >
>>>>     > I've been fighting for a long time with what now looks like a
>>>>     libdbus
>>>>     > bug.
>>>>     > I have a cut-down test program which calls a dbus method of
>>>>     > wpa_supplicant at 100Hz, it does this happily for several
>>>>     hours then
>>>>     > at some point the behaviour changes: any future calls sit at
>>>>     100% CPU
>>>>     > for 25sec then time out.
>>>>
>> After running about 54 minutes I got:
>>
>>  counts      time (ms)
>> 300272 3245606 signalInfo rssi=-63
>> 300273 3245616 signalInfo rssi=-63
>> Error: wpa_supplicant DBus error in signalPoll: Did not receive a 
>> reply. Possible causes include: the remote application did not send a 
>> reply, the message bus security policy blocked the reply, the reply 
>> timeout expired, or the network connection was broken.
>>
> second run gave same results:
> ...
>
> 300272 3548324 1 signalInfo rssi=-57
> 300273 3548413 79 signalInfo rssi=-59
> Error: wpa_supplicant DBus error in signalPoll: Did not receive a 
> reply. Possible causes include: the remote application did not send a 
> reply, the message bus security policy blocked the reply, the reply 
> timeout expired, or the network connection was broken.
>
> Sounds as a kind of limits reached. The counts are collected as shown 
> below:
>
>     while ( true )
>     {
>         try {
>             int a = timer.elapsed();
>             int rssi = signalPoll( *netDevInterfaceInterface_ );
>             int b = timer.elapsed();
>             cout << i++ << " " << b << " " << (b-a) << " signalInfo 
> rssi=" << rssi << endl;
>         }
>
>> Ralf
>>
>>
>> _______________________________________________
>> dbus mailing list
>> dbus at lists.freedesktop.org
>> http://lists.freedesktop.org/mailman/listinfo/dbus
>


-- 
------------------------------
Dr Alex Brooks
Marathon Targets Pty Ltd
Ph: +61 2 8090 7202
Web: www.marathon-targets.com
------------------------------

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/dbus/attachments/20150203/559cac0e/attachment-0001.html>