[Dovecot] pop3 TCP_CORK too late error
I was straceing a pop3 process and noticed that the TCP_CORK option isn't set soon enough:
epoll_wait(8, {{EPOLLOUT, {u32=37481984, u64=37481984}}}, 38, 207) = 1 write(41, "iTxPBrNlaNFao+yQzLhuO4/+tQ5cuiKSe"..., 224) = 224 epoll_ctl(8, EPOLL_CTL_MOD, 41, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=37481984, u64=37481984}}) = 0 pread(19, "AFABQAlAC0AJ\nQAUALQAUAFABQAlAC0AF"..., 8192, 811008) = 8192 setsockopt(41, SOL_TCP, TCP_CORK, [1], 4) = 0 write(41, "\r\nKUWtGCjKO5N8UbW5uYLZbS0nmaNi4ZB"..., 4134) = 4134 write(41, "\r\npckt0KMGuho6r4H1ay0sXbx+YyuC0Sn"..., 4134) = 4134 pread(19, "kivLO4WgAoAKACgBKAFoAr3V0lpH5kuQg"..., 8192, 819200) = 8192 write(41, "\r\nJkm1ZFXSIr1Ig19KGYj7oHT61dWUG/d"..., 4134) = 4134 write(41, "\r\nSNUHRRipGU9bu2sdLubhPvxoSv1qoK7"..., 4134) = 4134 pread(19, "NcOu1l/u1rGGl2YVKnQb8M9X09dKg\n0v7"..., 8192, 827392) = 8192 write(41, "\r\nAAp/Uo/zfgP29S9rB/wnRTcXsvu8YEg"..., 4134) = 4134 write(41, "\r\nYHT5jx+tJ1Z9x8iF/wCEb0ny/LNmmM5"..., 4134) = 4134 pread(19, "4GhGM3jkA/3B09Kr66+wewj0BfA8f8d8/"..., 8192, 835584) = 8192 write(41, "\r\nxHf8JPpm/b54/I/4UfVKhX1h3tYT/hJ"..., 4134) = 3932 write(41, "tdGIPCOsquY5oRkcoSev1p/Xl2D6s0tGN"..., 202) = -1 EAGAIN (Resource temporarily unavailable) epoll_ctl(8, EPOLL_CTL_MOD, 41, {EPOLLIN|EPOLLPRI|EPOLLOUT|EPOLLERR| EPOLLHUP, {u32=37481984, u64=37481984}}) = 0 setsockopt(41, SOL_TCP, TCP_CORK, [0], 4) = 0
The TCP_CORK option should get set before the first call to write() there, rather than after the first pread().
-- Ryan Murray rmurray@cyberhqz.com
On 2010-10-09 21:33:11 -0700, Ryan Murray wrote:
epoll_wait(8, {{EPOLLOUT, {u32=37481984, u64=37481984}}}, 38, 207) = 1 write(41, "iTxPBrNlaNFao+yQzLhuO4/+tQ5cuiKSe"..., 224) = 224 epoll_ctl(8, EPOLL_CTL_MOD, 41, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=37481984, u64=37481984}}) = 0 pread(19, "AFABQAlAC0AJ\nQAUALQAUAFABQAlAC0AF"..., 8192, 811008) = 8192 setsockopt(41, SOL_TCP, TCP_CORK, [1], 4) = 0 write(41, "\r\nKUWtGCjKO5N8UbW5uYLZbS0nmaNi4ZB"..., 4134) = 4134 *snip* setsockopt(41, SOL_TCP, TCP_CORK, [0], 4) = 0
The TCP_CORK option should get set before the first call to write() there, rather than after the first pread().
there are 2 calls to setsocketopt for it. maybe you missed the first one?
darix-- openSUSE - SUSE Linux is my linux openSUSE is good for you www.opensuse.org
On Mon, 2010-10-11 at 03:30 +0200, Marcus Rueckert wrote:
On 2010-10-09 21:33:11 -0700, Ryan Murray wrote:
epoll_wait(8, {{EPOLLOUT, {u32=37481984, u64=37481984}}}, 38, 207) = 1 write(41, "iTxPBrNlaNFao+yQzLhuO4/+tQ5cuiKSe"..., 224) = 224 epoll_ctl(8, EPOLL_CTL_MOD, 41, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=37481984, u64=37481984}}) = 0 pread(19, "AFABQAlAC0AJ\nQAUALQAUAFABQAlAC0AF"..., 8192, 811008) = 8192 setsockopt(41, SOL_TCP, TCP_CORK, [1], 4) = 0 write(41, "\r\nKUWtGCjKO5N8UbW5uYLZbS0nmaNi4ZB"..., 4134) = 4134 *snip* setsockopt(41, SOL_TCP, TCP_CORK, [0], 4) = 0
The TCP_CORK option should get set before the first call to write() there, rather than after the first pread().
there are 2 calls to setsocketopt for it. maybe you missed the first one?
One setting it on, and one setting it off, yes. The point of TCP_CORK is to set it on before _any_ write() calls, and off after the write calls. This allows the kernel to make TCP packets of MSS size, regardless of the size of your write()s. The write that occurs before enabling the cork causes a < MSS size packet to be sent, which increases the time spent waiting for ACKs.
On Sat, 2010-10-09 at 21:33 -0700, Ryan Murray wrote:
I was straceing a pop3 process and noticed that the TCP_CORK option isn't set soon enough:
epoll_wait(8, {{EPOLLOUT, {u32=37481984, u64=37481984}}}, 38, 207) = 1 write(41, "iTxPBrNlaNFao+yQzLhuO4/+tQ5cuiKSe"..., 224) = 224
http://hg.dovecot.org/dovecot-2.0/rev/f3aa8be626fa should fix this.
participants (3)
-
Marcus Rueckert
-
Ryan Murray
-
Timo Sirainen