Re: nginx introduces extra delay when talking to slow backend (probably FreeBSD kevent specific)

[Maxim Dounin]

Hello!

On Fri, Oct 12, 2018 at 11:31:26PM +0300, Dmitry Marakasov wrote:

> * Dmitry Marakasov (amd...@amdmi3.ru) wrote:
> 
> I've gathered ktrace dumps for both cases, and it really looks that
> the problem is related to kevent. After nginx sends response back
> to client, it calls kevent(2) on client fd (which is 5).
> 
> When there is a bug (FreeBSD 11.2), the following happens:
> 
>  49365 nginx3.099362 CALL  
> kevent(0x7,0x8022a2000,0,0x8023005c0,0x200,0x7fffe598)
>  49365 nginx3.099419 STRU  struct kevent[] = {  }
>  49365 nginx3.194695 STRU  struct kevent[] = { { ident=5, 
> filter=EVFILT_WRITE, flags=0x20, fflags=0, data=0xbf88, 
> udata=0x8023633d1 } }
>  49365 nginx3.194733 RET   kevent 1
> ...
>  49365 nginx3.194858 CALL  
> kevent(0x7,0x8022a2000,0,0x8023005c0,0x200,0x7fffe598)
>  49365 nginx3.194875 STRU  struct kevent[] = {  }
>  49365 nginx3.835259 STRU  struct kevent[] = { { ident=5, 
> filter=EVFILT_READ, flags=0x8020, fflags=0, data=0, 
> udata=0x802346111 } }
>  49365 nginx3.835299 RET   kevent 1
> 
> E.g. read and write events come separately, both with huge delays.
> 
> On FreeBSD-CURRENT which doesn't experience the problem, kdump looks this way:
> 
>   8049 nginx3.081367 CALL  
> kevent(0x7,0x8012d1b40,0,0x8012da040,0x200,0x7fffe598)
>   8049 nginx3.081371 STRU  struct kevent[] = {  }
>   8049 nginx3.081492 STRU  struct kevent[] = { { ident=5, 
> filter=EVFILT_WRITE, flags=0x20, fflags=0, data=0xbf88, 
> udata=0x801341f11 }
>  { ident=5, filter=EVFILT_READ, flags=0x8020, 
> fflags=0, data=0, udata=0x801324e51 } }
>   8049 nginx3.081498 RET   kevent 2
> 
> E.g. both events come immediately and at the same time.
> 
> Not sure if that's problem of kevent or something it relies on or the
> way nginx uses it.

Have you tried looking into what happens in the client?  These 
events are client-related, and seems to match what client does as 
per tcpdump of traffic between nginx and the client.

Also, at least on my box (FreeBSD 10.4) this issue can be 
reproduced with curl, but not with fetch or wget.  Seems to be 
something curl-specific.  I'm not familiar with curl source code, 
but it seems to be sitting in a poll() call without any file 
descriptors for some reason:

  8862 curl 0.013972 GIO   fd 3 wrote 78 bytes
   "GET / HTTP/1.1\r
Host: localhost:8080\r
User-Agent: curl/7.61.0\r
Accept: */*\r
\r
   "
  8862 curl 0.013977 RET   sendto 78/0x4e
  8862 curl 0.013984 CALL  poll(0xbfbfe610,0x1,0)
  8862 curl 0.013987 RET   poll 0
  8862 curl 0.013992 CALL  poll(0xbfbfe768,0x1,0x1)
  8862 curl 0.016042 RET   poll 0
  8862 curl 0.016118 CALL  poll(0xbfbfe610,0x1,0)
  8862 curl 0.016137 RET   poll 0
  8862 curl 0.016197 CALL  poll(0xbfbfe768,0x1,0xc5)
  8862 curl 0.228557 RET   poll 0
  8862 curl 0.228605 CALL  poll(0xbfbfe610,0x1,0)
  8862 curl 0.228617 RET   poll 0
  8862 curl 0.228631 CALL  poll(0xbfbfe768,0x1,0x3e8)
  8862 curl 1.246374 RET   poll 0
  8862 curl 1.246420 CALL  poll(0,0,0x3e8)
  8862 curl 2.298297 RET   poll 0
  8862 curl 2.298410 CALL  poll(0xbfbfe610,0x1,0)
  8862 curl 2.298452 RET   poll 1
  8862 curl 2.298517 CALL  recvfrom(0x3,0x28ca,0x19000,0,0,0)
  8862 curl 2.298584 GIO   fd 3 read 171 bytes
   "HTTP/1.1 200 OK\r
Server: nginx/1.15.5\r

Note these lines:

  8862 curl 1.246420 CALL  poll(0,0,0x3e8)
  8862 curl 2.298297 RET   poll 0

This is a call without any file descriptors and with 1000 
millisecond timeout, so it will result in an unconditional 1 
second delay.

Not sure why you are seeing the problem with some FreeBSD version 
but not others, but different curl versions or curl compilation 
flags may explain things.  In my case curl version is as follows:

$ curl --version
curl 7.61.0 (i386-portbld-freebsd10.4) libcurl/7.61.0 OpenSSL/1.0.1u 
zlib/1.2.11 nghttp2/1.32.0
Release-Date: 2018-07-11
Protocols: dict file ftp ftps gopher http https imap imaps pop3 pop3s rtsp smtp 
smtps telnet tftp 
Features: AsynchDNS IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL 
libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy 

Upgrading curl to 7.61.1 doesn't fix things.

-- 
Maxim Dounin
http://mdounin.ru/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: RLIMIT_DATA and malloc(3) use of mmap(2)

[Maxim Dounin]

Hello!

On Tue, Nov 22, 2011 at 02:44:10PM +0200, Kostik Belousov wrote:

 I was reminded about the patch I wrote for Igor Sysoev some time ago.
 The issue the patch tries to handle is that jemalloc uses mmap() instead
 of sbrk() for pages allocation, and thus RLIMIT_DATA limit is no longer
 effective to put the bounds on the process heap. Since reverting to sbrk
 for such purpose is worse then the issue itself, I proposed a solution
 of 'self-restricting malloc'.

Just a little clarification for others: currently, there is no way 
to *safely* limit memory usage of a process while using jemalloc 
with mmap().

The only thing available is RLIMIT_VMEM, but it's not safe as it 
may be reached on stack grow (leaving no possibility for an 
application to handle this).

 The patch adds a flag MAP_DATALIMIT to the flags argument of mmap(2),
 which instructs the system to account the mapping in the RLIMIT_DATA
 resource count. The malloc(3) also gets new option 'L' to enable
 passing MAP_DATALIMIT to mmap() when allocating pages. By default,
 the 'L' option is not activated.
 
 Now, if user wants to ensure that process heap is restricted by the
 ulimit -d and still use mmap() for jemalloc, he supplies the option
 using any mechanism. The behaviour is voluntaristic, to prevent the
 trashing use RLIMIT_SWAP.
 
 Do people consider the facility useful ?

Yes, at least some way to safely limit process memory usage is 
certainly needed.

It's a bit sad this isn't enabled by default, but it's probably 
too late for this.  RLIMIT_DATA was (almost) a noop for too long 
and making it work again to limit all memory allocations will 
break POLA.

 Any comments for the patch itself ?
 
 http://people.freebsd.org/~kib/misc/map_datalimit.1.patch

Patch looks ok for me (though I'm not a VM expert).

Another possible aproach would be to introduce separate anonymous 
(private?) mmap limit, this will allow to do essentially the same 
thing in a bit more consistent (IMHO) manner.

Maxim Dounin
___
freebsd-current@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org

Re: TCP loopback socket fusing

[Maxim Dounin]

Hello!

On Tue, Sep 14, 2010 at 12:12:03PM +0200, Ian FREISLICH wrote:

 Fabien Thomas wrote:
  Great,
  
  This will maybe kill the long time debate about my loopback is slow vs
  linux
  To have the best of both world what about a socket option to
  enable/disable fusing:
  can be useful when you need to see some connection packetized.
 
 To chime in, I had a slow loopback issue earlier this week.  It
 turned out the problem was caused by delayed ack on the loopback
 where the client didn't need to transmit any data to the server.
 It delayed each packet from the server by 100ms.  After patching
 the server to:
 
 setsockopt(desc-accept_fd, IPPROTO_TCP, TCP_NODELAY, x, sizeof(x));
 
 It's now faster than on linux.
 
 Perhaps this is one of the causes of my loopback is slow vs linux.
 
 FWIW, I couldn't find a way to turn off dealyed_ack on just loopback
 interface.

AFAIK in linux delayed ack behaves a bit more gently and doesn't 
delay first ack(s) in a connection.  As a result linux hides some 
classic delayed ack vs. Nagle problems.

Something similar probably should be adapted.

Maxim Dounin
___
freebsd-current@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org