| Summary: | kopete connection timeout around every 3 minutes (jabber) | ||
|---|---|---|---|
| Product: | [Unmaintained] kopete | Reporter: | Ike Devolder <ike.devolder> |
| Component: | libkopete | Assignee: | Kopete Developers <kopete-bugs-null> |
| Status: | RESOLVED FIXED | ||
| Severity: | normal | CC: | ike.devolder |
| Priority: | NOR | ||
| Version First Reported In: | 1.0.0 | ||
| Target Milestone: | --- | ||
| Platform: | Arch Linux | ||
| OS: | Linux | ||
| Latest Commit: | Version Fixed/Implemented In: | ||
| Sentry Crash Report: | |||
| Attachments: |
proposed patch to make it reachable
no action when data_sent == 0 show some tcp debug logging when started from konsole tcpdum & kopete konsole output another tcpdump & kopete |
||
ok every 3 minutes was just before i submitted this bug, its not that simple, sometimes it keeps up for hours sorry, i had it wrong changed the logging and found the real problem kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 10000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 10000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_recv 43530 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: ack_recv - data_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 25000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 25000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_recv 58530 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: ack_recv - data_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 40000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 40000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_recv 73530 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: ack_recv - data_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 55000 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_recv 88530 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: ack_recv - data_sent 55000 <<------- because data_sent == 0 !!! kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: Connection timeout for QHostAddress( "193.168.4.117" ) Unknown signature value: 795 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_sent 0 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 963 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 966 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_recv 963 kopete(22308) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: ack_recv - data_sent 4294967293 Created attachment 49663 [details]
no action when data_sent == 0
The patch looks good (I actually created the same patch 5 min ago :( ). Could you capture the tcpi_last_ack_recv, tcpi_last_data_sent with your patch, I would like to know what will happen after the tcpi_last_data_sent is 0. Thanks do you mean just kWarning() ? then i attach the patch i used for checking it out, apply after previously attached patch Created attachment 49667 [details]
show some tcp debug logging when started from konsole
apply after kopetesockettimeoutwatcher.cpp.patch
in kdenetwork:
patch -Np0 -i ${srcdir}/kopetesockettimeoutwatcher.cpp.patch
patch -Np0 -i ${srcdir}/kopetesockettimeoutwatcher.cpp.logmsg.patch
(In reply to comment #5) > do you mean just kWarning() ? > > then i attach the patch i used for checking it out, apply after previously > attached patch sorry for the overload of reply's and so the patch as given, is now running for 3 hours straight without one disconnect No I meant, if you could show me Kopete console log with the fix and "show some tcp debug logging when started from konsole" patches applied. I'm interested in the part right after tcpi_last_data_sent is 0. Created attachment 49670 [details]
tcpdum & kopete konsole output
tried to get the data requested with tcpdump
started:
tcpdump -n > tcpdump.log 2>&1
kopete > kopete.log 2>&1
logged with:
tail -n 0 --silent --follow=name --retry kopete.log tcpdump.log
extra info: my ip = 193.168.4.112 jabber server ip = 193.168.4.117 Created attachment 49671 [details]
another tcpdump & kopete
another tcpdump & kopete konsole output log
Thanks for the logs. Do you have SVN account or should I commit your patch? i have no svn account, you can commit the patch SVN commit 1157349 by rjarosz: Fix bug 246156, kopete connection timeout around every 3 minutes. Patch by Ike Devolder, thanks. BUG: 246156 M +5 -5 kopetesockettimeoutwatcher.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1157349 SVN commit 1157350 by rjarosz: Backport commit 1157349. Fix bug 246156, kopete connection timeout around every 3 minutes Patch by Ike Devolder, thanks. CCBUG: 246156 M +5 -5 kopetesockettimeoutwatcher.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1157350 |
Created attachment 49636 [details] proposed patch to make it reachable Version: 1.0.0 (using KDE 4.4.5) OS: Linux kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 48336992 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 0 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: mTimeoutThreshold 15000 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: getSockOpt == 0 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 1 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 32767 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: mTimeoutThreshold 15000 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: getSockOpt == 0 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: Connection timeout for QHostAddress( "193.168.4.117" ) kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_ack_recv 38237024 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: info.tcpi_last_data_sent 4294967295 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: mTimeoutThreshold 15000 kopete(3401) Kopete::SocketTimeoutWatcher::ackTimeoutCheck: getSockOpt == 0 there is some unreachable code in kopetesockettimeoutwatcher.cpp you will never reach the else if ( info.tcpi_last_ack_recv < info.tcpi_last_data_sent ) since the if will be sattisfactory for an 'false' connection timeout Reproducible: Always Steps to Reproduce: just connect to an jabber server Actual Results: from time to time i get a "false" connection timeout Expected Results: connectiontimeout just stay online