[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#537383: ProxyScout in Konqueror from testing works VERY slow with proxy autoconfiguration



Package: konqueror
Version: 4:4.2.2-1

When I tried to open a web page in the Konqueror, it often stopped working for 
a while (didn't respond to actions, redraw window, etc). The same happened 
sometimes when I was closing the browser. And the overall performance was very 
low.

I strace'd an instance of the browser to find out what did it wait for:

ximaera@agavrichen2#9:~$ type watch-trace-for-waits 
watch-trace-for-waits is a function                 
watch-trace-for-waits ()                            
{                                                   
    local DELAY=1 PRINTED=false LN=$(cat "$1" | wc -l);
    local SECCNT=$DELAY;                               
    while true; do                                     
        if ! {                                         
            ps -ef | grep -q "$2"                      
        }; then                                        
            $PRINTED && echo $SECCNT;                  
            return;                                    
        fi;                                            
        local NEWLN=$(cat "$1" | wc -l);               
        if [ "$NEWLN" == "$LN" ]; then                 
            if $PRINTED; then                          
                SECCNT=$(($SECCNT+$DELAY));            
            else                                       
                echo -n "Trace line #"$(($LN+1))": ";  
                PRINTED=true;                          
            fi;                                        
        else                                           
            if $PRINTED; then                          
                echo $SECCNT" seconds";                
                PRINTED=false;                         
                SECCNT=$DELAY;                         
            else                                       
                LN="$NEWLN";                           
            fi;                                        
        fi;                                            
        sleep $DELAY;                                  
    done                                               
}                                                      
ximaera@agavrichen2#9:~$ strace konqueror 'http://google.com' 2>konq.strace & 
time watch-trace-for-waits konq.strace $!
[1] 30964                                                                                                              
Trace line #13901: 14 seconds
Trace line #15903: 13 seconds
Trace line #16708: 13 seconds
Trace line #17311: 13 seconds
Trace line #18362: 13 seconds
Trace line #18848: 2 seconds
Trace line #18856: 9 seconds
Trace line #19860: 13 seconds
    <-- Soon after that, the page had been loaded
    <-- and I tried to close the window
Trace line #21607: 4 seconds
Trace line #21615: 5 seconds
Trace line #21638: [1]+  Done                    strace konqueror 
'http://google.com' 2> konq.strace
14 seconds
Trace line #23669: 2

real    2m25.351s
user    0m2.432s
sys     0m3.660s
ximaera@agavrichen2#9:~$ cat konq.strace | lines 13901 15903 16708 17311 18362 
18848 18856 19860 21607 21615 21638
13901:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
15903:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
16708:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
17311:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
18362:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
18848:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
18856:  poll([{fd=8, events=POLLIN}], 1, 20512) = 1 ([{fd=8, revents=POLLIN}])
19860:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
21607:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
21615:  poll([{fd=8, events=POLLIN}], 1, 19156) = 1 ([{fd=8, revents=POLLIN}])
21638:  poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])
ximaera@agavrichen2#9:~$ head -13901 konq.strace | egrep -n '^open.* = 8$' | 
tail -1
2571:open("/usr/lib/libdbus-1.so.3", O_RDONLY) = 8
ximaera@agavrichen2#9:~$ head -21638 konq.strace | egrep -n '^open.* = 8$' | 
tail -1
2571:open("/usr/lib/libdbus-1.so.3", O_RDONLY) = 8
ximaera@agavrichen2#9:~$

As you see, it took more than two minutes to show up the Google's main page, 
making web-surfing in Konqueror impossible. One and a half minute of these two 
was spent waiting for libdbus.

After tracing Konqueror again with the strace string size set to a bigger 
value than the default one I've found that before poll()ing the DBus, the 
browser sends it a message containing words "modules/proxyscout:

writev(8, 
[{"l\1\0\1\0\0\0I\0\0\0w\0\0\0\1\1o\0\23\0\0\0/modules/proxyscout\0\0\0\0\0\6\1s\0\f\0\0\0org.kde.kded\0\0\0\0\2\1s\0\27\0\0\0org.kde.KPAC.ProxyScout\0\3\1s\0\v\0\0\0proxyForUrl\0\0\0\0\0\10\1g\0\1s\0\0"..., 
136}, {"6\0\0\0http://www.google.ru/intl/en_com/images/logo_plain.png\0";..., 
59        }], 2) = 195
gettimeofday({1247848875, 377033}, NULL) = 0
poll([{fd=8, events=POLLIN}], 1, 25000) = 1 ([{fd=8, revents=POLLIN}])

I'm using proxy server autoconfiguration. Seems like Konqueror is not caching 
the autoconfiguration and every time you need to view a page, it sends a new 
query to the proxy configuration URL. If this is intended, it is a -- really 
-- bad idea. Two or five minutes per any single web page exceed much anyone's 
expectations.

I'm using Debian GNU/Linux Testing/Squeeze:
- kernel 2.6.26-2-686 (2.6.26-17)
- libc6 2.9-12

-- 
Artyom Gavrichenkov | Engineer, HP Global Delivery Russia Center | Mailto: 
ximaera@hp.com | Tel. No: +7 916 515 49 58




Reply to: