Re: getline() very very slow on localhost on 5.X

From: Martin Blapp <mb_at_imp.ch>
Date: Thu, 3 Feb 2005 13:19:08 +0100 (CET)
Hi,

I've tested now a lot more and used the old qpopper server to
compare the results. You are correct, it doesn't happen here
with this application. But I found out something very strange
with the tpop3d (the newer popserver which shows the problems)

qpopper:
--------

Case A (Using IP on the first NIC em0)

real    0m1.083s
user    0m0.198s
sys     0m0.038

Case C (Using 127.0.0.1 on lo0)

real    0m0.929s
user    0m0.205s
sys     0m0.025s

Now to tpop3d:
--------------

I tested one case more. I see the pop3 server sending a lot slower in case B+C.
It doesn't matter if I use an IP alias or the real IP - I can even add some
additional IP's which do not have any hostname, the result is the same.

It doesn't matter if I access Case A or Case B externally or
internally. The order of configured IP's within tpop3d.conf
doesn't matter too.

Btw, disable or enable PF did not have any
effect.

> (1) Try connecting to 127.0.0.1 instead of localhost?

Case A (Using IP on the first NIC em0)

real    0m2.971s
user    0m0.248s
sys     0m0.064s

Case B (Using IP on the second NIC em1)

real    0m32.697s
user    0m0.247s
sys     0m0.024s

Case C (Using 127.0.0.1 on lo0)

time perl test.pl >xxx

real    0m32.164s
user    0m0.218s
sys     0m0.044s

> (2) If the problem persists, try writing a C based client to do the same
>     thing?

We see the same behaviour with normal mail clients.

> (3) Use tcpdump on lo0 to create a packet trace?

Thats part of the trace on em1 which has the same problems:

[...]

12:57:37.443544 IP mx2i.53848 > mx1i.pop3: . ack 106497 win 34048 <nop,nop,timestamp 38840793 137977961>
12:57:37.444256 IP mx1i.pop3 > mx2i.53848: P 106497:114689(8192) ack 0 win 34048 <nop,nop,timestamp 137977971 38840793>
12:57:37.543486 IP mx2i.53848 > mx1i.pop3: . ack 114689 win 34048 <nop,nop,timestamp 38840803 137977971>
12:57:37.545426 IP mx1i.pop3 > mx2i.53848: P 114689:122881(8192) ack 0 win 34048 <nop,nop,timestamp 137977982 38840803>
12:57:37.644410 IP mx2i.53848 > mx1i.pop3: . ack 122881 win 34048 <nop,nop,timestamp 38840813 137977982>
12:57:37.645402 IP mx1i.pop3 > mx2i.53848: P 122881:131073(8192) ack 0 win 34048 <nop,nop,timestamp 137977992 38840813>
12:57:37.743474 IP mx2i.53848 > mx1i.pop3: . ack 131073 win 34048 <nop,nop,timestamp 38840823 137977992>
12:57:37.744181 IP mx1i.pop3 > mx2i.53848: P 131073:139265(8192) ack 0 win 34048 <nop,nop,timestamp 137978001 38840823>
12:57:37.843553 IP mx2i.53848 > mx1i.pop3: . ack 139265 win 34048 <nop,nop,timestamp 38840833 137978001>
12:57:37.844312 IP mx1i.pop3 > mx2i.53848: P 139265:147457(8192) ack 0 win 34048 <nop,nop,timestamp 137978011 38840833>
12:57:37.943493 IP mx2i.53848 > mx1i.pop3: . ack 147457 win 34048 <nop,nop,timestamp 38840843 137978011>
12:57:37.944268 IP mx1i.pop3 > mx2i.53848: P 147457:155649(8192) ack 0 win 34048 <nop,nop,timestamp 137978021 38840843>
12:57:38.043582 IP mx2i.53848 > mx1i.pop3: . ack 155649 win 34048 <nop,nop,timestamp 38840853 137978021>
12:57:38.045378 IP mx1i.pop3 > mx2i.53848: P 155649:163841(8192) ack 0 win 34048 <nop,nop,timestamp 137978032 38840853>
12:57:38.143490 IP mx2i.53848 > mx1i.pop3: . ack 163841 win 34048 <nop,nop,timestamp 38840863 137978032>
12:57:38.145353 IP mx1i.pop3 > mx2i.53848: P 163841:172033(8192) ack 0 win 34048
<nop,nop,timestamp 137978042 38840863>12:57:38.243562 IP mx2i.53848 > mx1i.pop3: . ack 172033 win 34048
<nop,nop,timestamp 38840873 137978042>12:57:38.244337 IP mx1i.pop3 > mx2i.53848: P 172033:180225(8192) ack 0 win 34048
<nop,nop,timestamp 137978051 38840873>12:57:38.343490 IP mx2i.53848 > mx1i.pop3: . ack 180225 win 34048
<nop,nop,timestamp 38840883 137978051>12:57:38.344244 IP mx1i.pop3 > mx2i.53848: P 180225:188417(8192) ack 0 win 34048
<nop,nop,timestamp 137978061 38840883>12:57:38.443551 IP mx2i.53848 > mx1i.pop3: . ack 188417 win 34048
<nop,nop,timestamp 38840893 137978061>12:57:38.444288 IP mx1i.pop3 > mx2i.53848: P 188417:196609(8192) ack 0 win 34048
<nop,nop,timestamp 137978071 38840893>12:57:38.543633 IP mx2i.53848 > mx1i.pop3: . ack 196609 win 34048
<nop,nop,timestamp 38840903 137978071>12:57:38.544416 IP mx1i.pop3 > mx2i.53848: P 196609:204801(8192) ack 0 win 34048
<nop,nop,timestamp 137978081 38840903>12:57:38.643569 IP mx2i.53848 > mx1i.pop3: . ack 204801 win 34048
<nop,nop,timestamp 38840913 137978081>12:57:38.644348 IP mx1i.pop3 > mx2i.53848: P 204801:212993(8192) ack 0 win 34048
<nop,nop,timestamp 137978091 38840913>12:57:38.743507 IP mx2i.53848 > mx1i.pop3: . ack 212993 win 34048
<nop,nop,timestamp 38840923 137978091>12:57:38.744292 IP mx1i.pop3 > mx2i.53848: P 212993:221185(8192) ack 0 win 34048
<nop,nop,timestamp 137978101 38840923>12:57:38.843849 IP mx2i.53848 > mx1i.pop3: . ack 221185 win 34048
<nop,nop,timestamp 38840933 137978101>12:57:38.844659 IP mx1i.pop3 > mx2i.53848: P 221185:229377(8192) ack 0 win 34048
<nop,nop,timestamp 137978111 38840933>12:57:38.943517 IP mx2i.53848 > mx1i.pop3: . ack 229377 win 34048
<nop,nop,timestamp 38840943 137978111>12:57:38.945711 IP mx1i.pop3 > mx2i.53848: P 229377:237569(8192) ack 0 win 34048
<nop,nop,timestamp 137978122 38840943>12:57:39.043582 IP mx2i.53848 > mx1i.pop3: . ack 237569 win 34048
<nop,nop,timestamp 38840953 137978122>12:57:39.044412 IP mx1i.pop3 > mx2i.53848: P 237569:245761(8192) ack 0 win 34048

[..]

If needed, I can provide a dump of all connections.

Martin
Received on Thu Feb 03 2005 - 11:19:22 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:27 UTC