Bug 122020

Hello,

I can reproduce this on my IBM ThinkPad T23 with Pentium 3 1.13GHz with Debian Etch/Sid using KDE 3.5.1 and 

root@deepdance:~ -> dpkg -l | grep kdesvn
ii  kdesvn                  0.7.3-1                 subversion client with tight KDE integration
ii  kdesvn-kio-plugins      0.7.3-1                 subversion I/O slaves for KDE

AFAIK it didn't happen with 0.7.2 or less or kdesvn.

I either get:

1)

4 or 5 error messages like this
"Die Desktop-Datei /usr/share/apps/konqueror/servicemenus/kdesvn_subversion_toplevel.desktop
hat einen ungültigen Menü-Eintrag
Log."

(in english: the desktop file blabla has a invalid menu entry)

Also with: Info. Blame and Rename.

2) 

"Won't receive DCOP signal" or something like this

I am trying the workaround to comment out "X-KDE-GetActionMenu="

/usr/share/apps/konqueror/servicemenus/kdesvn_subversion.desktop
/usr/share/apps/konqueror/servicemenus/kdesvn_subversion_toplevel.desktop

that is described in that debian bug (348411) as that bug is rather annoying over time. ;)

I also tried to reproduce this with a new user with new KDE configuration, but there this bug doesn't seem to happen. So maybe its some migration issue (old config or menu files laying around)? But I didn't find anything. Or maybe that new KDE user setup doesn't start as many services so it starts up faster?

Regards,
Martin

Is there any analysis or even solution for this bug? The maintainer of the kdesvn Debian package Michael Biebl tried to solve the bug, but this doesn't work. It is still in kdesvn 0.8.0-1.

BTW the work-around does worked okay here.

I can also reproduce this with KDE 3.5.2.

Right click in Konqueror uses I'd say about a gig+ of RAM to bring up the above-mentioned messages, which thrashes my system (only 512MB of RAM). But this doesn't happen all the time. Usually, I can observe this behaviour when my system has an above average load, which is consistent with the hypothesis that this bug is a timing issue. I wish I could provide more details, but I don't even know where to start. What's relevant?

*** This bug has been confirmed by popular vote. ***

Can you help me understand the bug by describing what's in those servicemenus and which dcop call is being made? I don't have kdesvn[d] installed.

On 15.08.06 19:59:11, David Faure wrote:
> Can you help me understand the bug by describing what's in those servicemenus


Various subversion-related actions, for example Checkout, Blame log and
so on.

> and which dcop call is being made? I don't have kdesvn[d] installed.


The dcop call is: kded kdesvnd getActionMenu(KURL::List) and is given to
konqueror via:

X-KDE-GetActionMenu=kded kdesvnd getActionMenu(KURL::List)

Andreas

On Tuesday 15 August 2006 22:08, Andreas Pakulat wrote:
> The dcop call is: kded kdesvnd getActionMenu(KURL::List)

OK - and this loads kdesvnd on demand. But that's synchronous, I don't understand "not fast enough" in the descirption of this bug.

Is the problem reproduceable with the "dcop" command-line client?
I just found out that I have ksvnd (but not kdesvnd), and for that one it seems to work:

$ dcop kded kded unloadModule ksvnd
true
$ dcop kded ksvnd getActionMenu '' ''
Diff
Rename
[...]

The problem is, if the system is under high load or if you have a slow machine, it seems that the dcop reply times out or better is too late.
If I start konqueror from the console I get 
>> Very strange! got a DCOPReply opcode, but we were not waiting for a reply!
and konqueror displays the error messages.

Below I attach bug122020.tar.gz, a small testcase, demonstrating this bug. When you run it, you will get something like this on the console.

DCOPsrv: Starting DCOPsrv, registering as dcopsrv1
DCOPsrv: Starting new DCOPsrv service...
DCOPsrv: Starting DCOPsrv, registering as dcopsrv2
DCOPsrv: Starting new DCOPsrv service...
Executing the 1st DCOP call: service dcopsrv1 function sleep(3000)
DCOPcl: 1st dcop call sleep(3000) with timeout failed. The first part of the bug
Executing the 2nd DCOP call: service dcopsrv2 function sleep(4000)
2nd dcop call sleep(4000) w/o timeout returned 3000
2nd dcop call returned the return value (3000) of the 1st DCOP call. Bug proven!
Very strange! got a DCOPReply opcode, but we were not waiting for a reply!

sleep(int msecs) is a small DCOP function, which causes the process (the DCOP service provider) to sleep for msecs miliseconds and returns msecs value to the caller. As you a return value of the 2nd DCOP call is wrong (should have been 4000) due to this bug. And "Very strange! got a DCOPReply opcode, but we were not waiting for a reply!" message is where the real reply of the 2nd call (return value 4000) gets discarded.

I also attach a patch to avoid using timeout in kdelibs/kio/kio/kmimetype.diff It's not truly a fix for the actual DCOP bug, but rather a workaround to avoid it. The other workaround could be to establish a new DCOP connection and call with timeout on it, but, in my opinion, abandoning timeout is a clean and logical solution.

A true solution would be to fix this race condition in DCOP code. That's where experienced DCOP dev should step in. Or at least please clearly DOCUMENT this bug in DCOPClient documentation (e.g. a big fat warning that it is not safe to do another dcop call on the same connection if a previous call might have timed out).

Created attachment 18270 [details]
A testcase demostrating this bug

$ tar xvzf bug122020.tar.gz
$ cd bug122020
<edit Makefile if necessary (it's OK for debian based systems)>
$ make && ./run.sh ; killall dcopsrv

Created attachment 18271 [details]
A path to kdelibs/kio/kio/kmimetype.cpp - do not timeout

Do not time out when waiting for the reply for the X-KDE-GetActionMenu DCOP
call. DCOP protocol is synchronouos by design and a reply for the timed out
call (i.e. garbage) still arrives and might be falsely returned as a valid
reply for the subsequent DCOP call on the same connection. The application
currently known to be badly hurt by this is kdesvn and its konqueror service
menu integration. Its X-KDE-GetActionMenu might take longer than current 100
milisecond timeout to complete. As a result then, a late reply will "pollute" a
main DCOP connection of the client application (e.g. konqueror) causing further
DCOP failures.

Thanks for the very good analysis of the problem.
I agree with your comments relative to the kmimetype.cpp patch, and I have applied it to branches/KDE/3.5/kdelibs/kio/kio/kmimetype.cpp in subversion.
At this point I seriously doubt that anyone is going to fix the DCOP problem; those developers who knew the DCOP internals have dropped out,
and the KDE4 development branch has already replaced DCOP with DBUS.
I also think that whoever added the timeout in the kmimetype call didn't really think of the implications :)