Mostrando entradas con la etiqueta buffers. Mostrar todas las entradas
Mostrando entradas con la etiqueta buffers. Mostrar todas las entradas

sábado, 6 de mayo de 2017

Understanding SOMAXCONN parameter Part I

This post is kind of a fork of something I worked on the previous week and tries to shed some light on what somaxconn parameter means in the context of Linux Network stack. I've tried to prepare something similar to what I did in TCP Keep Alive - how it works, with examples and some traffic captures so I guess this article will be a bit longer that [I|you]'d like xD, but useful (hopefully).

somaxconn


By definition this value is the maximum number of established connections a socket may have queuing waiting to be accepted by the process holding the socket. This is completely different from tcp_syn_max_backlog since this value is for incomplete connection (connections that haven't been ACKed yet).

To give more context to that statement is necessary to understand a bit more about sockets. When a socket is created, before being able to receive connections two things must happen:
  1. It has to be bind() to a local address.
  2. It has to bet set to listen() for connections.
The listen() syscall is key here, it receives 2 parameters:
Long time ago (before kernel 2.4.25) somaxconn value used to be hardcoded in the kernel, nowadays you can read and update using sysctl as with the rest of the network stack parameters. In most systems the default value is 128, like in my CentOS VM:

[root@server juan]# sysctl -a --pattern net.core.somaxconn
net.core.somaxconn = 128
[root@server juan]#

Test scenario


In order to test and confirm the behavior of somaxconn I have the following setup:
  • Client VM (IP 192.168.0.17) running a C binary (source here) that will start 25 TCP connections to the Server VM on port 8080, in each connection it will send 4 bytes "juan". The binary opens 1 connection per second, and after having opened the 25 connections just waits for 2 minutes to finish.
  • Server VM (IP 192.168.0.26) running ncat (nc, netcat, whatever you like to call it) listening on port 8080, and the maximum open files has been set to 9 (ulimit -n 9) to achieve a condition where we can see established connections being queued easier.
A few more details you should keep in mind:
  • The version of nc shipped with CentOS sets a backlog of 10 on the listen() syscall (using strace):
[juan@server ~]$ ulimit -n 9
[juan@server ~]$ strace nc -lk 8080
execve("/usr/bin/nc", ["nc", "-lk", "8080"], [/* 24 vars */]) = 0
brk(0)                                  = 0x1dd7000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe7075e9000
...
bind(3, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 128) = 0
listen(3, 10)                           = 0
fcntl(3, F_GETFL)
...
  • So we have a backlog of 10 set in the listen syscall and a limit of 9 open files. I will use this value as somaxconn since the meaning is the same.
  • After nc was just started we can see it has already used 5 FD in use (STDIN, STDOUT, STDERR, and two more for the listening sockets on IPv4 and IPv6)
[root@server juan]# lsof -p 14136|grep "CHR\|IPv"
nc      14136 juan    0u   CHR     136,0      0t0        3 /dev/pts/0
nc      14136 juan    1u   CHR     136,0      0t0        3 /dev/pts/0
nc      14136 juan    2u   CHR     136,0      0t0        3 /dev/pts/0
nc      14136 juan    3u  IPv6 488270957      0t0      TCP *:webcache (LISTEN)
nc      14136 juan    4u  IPv4 488270958      0t0      TCP *:webcache (LISTEN)
[root@server juan]#

With all these details in mind and some basic math (2+2=4 :D) we can expect the following behavior:
  • Since 5 out of the 9 available file descriptors are already in use, nc should not be able to receive more than 4 new connections on port 8080. Each new connection will create a new socket that has to be accessible in user space through a file descriptor (have a look at accept() syscall), which can't be created if the max open files limit has been reached.
  • The C binary will issue 25 connections:
    • The first 4 will be answered just fine by nc and the 4 bytes will be read from the socket and printed to STDOUT.
    • The next 10 connections will be indeed accepted by the Network layer of the Server VM, and even the 4 bytes will be received, however nc won't be able to accept the socket and read the 4 bytes. These are the established connections being queued!!!
    •  The remaining 11 connections will look as ESTABLISHED from the client as they have completed the TCP handshake however the 4 bytes won't be ACKnowledged by Network Stack because the queue is full (somaxconn limit has been reached). From the server the connections won't even exist.

Binary execution:

juan@test:~/TCP_connections$ gcc -o tcp_connections tcp_connections.c
juan@test:~/TCP_connections$ ./tcp_connections
Socket opened FD=3, connection number 0
Socket opened FD=4, connection number 1
Socket opened FD=5, connection number 2
Socket opened FD=6, connection number 3
Socket opened FD=7, connection number 4
Socket opened FD=8, connection number 5
Socket opened FD=9, connection number 6
Socket opened FD=10, connection number 7
Socket opened FD=11, connection number 8
Socket opened FD=12, connection number 9
Socket opened FD=13, connection number 10
Socket opened FD=14, connection number 11
Socket opened FD=15, connection number 12
Socket opened FD=16, connection number 13
Socket opened FD=17, connection number 14
Socket opened FD=18, connection number 15
Socket opened FD=19, connection number 16
Socket opened FD=20, connection number 17
Socket opened FD=21, connection number 18
Socket opened FD=22, connection number 19
Socket opened FD=23, connection number 20
Socket opened FD=24, connection number 21
Socket opened FD=25, connection number 22
Socket opened FD=26, connection number 23
Socket opened FD=27, connection number 24
juan@test:~/TCP_connections$

Nc execution on the server


Note: I introduced the new line after the 4th connections just to split them from the rest:
[juan@server ~]$ nc -lvk -p 8080
Ncat: Version 6.40 ( http://nmap.org/ncat )
Ncat: Listening on :::8080
Ncat: Listening on 0.0.0.0:8080
Ncat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49026.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49027.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49028.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49029.
juan

Ncat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49030.
Ncat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49031.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49032.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49033.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49034.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49035.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49036.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49037.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49038.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49039.
juanNcat: Connection from 192.168.0.17.
Ncat: Connection from 192.168.0.17:49040.
juanjuan

Results


To have a  look at what was happening during the test I measured 3 different locations:
  1. TCP connections on the client using ss.
  2. TCP connections on the server using ss.
  3. Captured network traffic on the server using tcpdump.
These 3 locations provided enough information to understand what is going on and to even find something interesting :D.

TCP connections on the client:


I've chopped off a couple of lines for the sake of space and time.  The samples were taken every 2 seconds and only TCP connections to port 8080 were considered:

root@test:/home/juan# for i in {1..100}; do ss -ntpe|grep "State\|8080"; echo ---; sleep 2; done
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
---
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49027         192.168.0.26:8080   users:(("tcp_connections",3342,4)) uid:1000 ino:23350 sk:ffff8800b4914140
ESTAB      0      0              192.168.0.17:49028         192.168.0.26:8080   users:(("tcp_connections",3342,5)) uid:1000 ino:23368 sk:ffff8800b4910e80
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
---
...
---
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49031         192.168.0.26:8080   users:(("tcp_connections",3342,8)) uid:1000 ino:23408 sk:ffff8800b4911d00
ESTAB      0      0              192.168.0.17:49027         192.168.0.26:8080   users:(("tcp_connections",3342,4)) uid:1000 ino:23350 sk:ffff8800b4914140
ESTAB      0      0              192.168.0.17:49029         192.168.0.26:8080   users:(("tcp_connections",3342,6)) uid:1000 ino:23372 sk:ffff8800b4910740
ESTAB      0      0              192.168.0.17:49030         192.168.0.26:8080   users:(("tcp_connections",3342,7)) uid:1000 ino:23390 sk:ffff8800b49115c0
ESTAB      0      0              192.168.0.17:49028         192.168.0.26:8080   users:(("tcp_connections",3342,5)) uid:1000 ino:23368 sk:ffff8800b4910e80
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
ESTAB      0      0              192.168.0.17:49033         192.168.0.26:8080   users:(("tcp_connections",3342,10)) uid:1000 ino:23445 sk:ffff8800b4912b80
ESTAB      0      0              192.168.0.17:49034         192.168.0.26:8080   users:(("tcp_connections",3342,11)) uid:1000 ino:23447 sk:ffff8800b49132c0
ESTAB      0      0              192.168.0.17:49032         192.168.0.26:8080   users:(("tcp_connections",3342,9)) uid:1000 ino:23426 sk:ffff8800b4912440
---
...

After a few seconds, we can see a few ESTABLISHED tcp connections using source ports from 49026 to 49034, 9 connections to be more precise, and they all show 0 bytes in Send-Q which suggests the 4 bytes sent by the application were actually acknowledged by the server.

...
---
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49031         192.168.0.26:8080   users:(("tcp_connections",3342,8)) uid:1000 ino:23408 sk:ffff8800b4911d00
ESTAB      0      0              192.168.0.17:49027         192.168.0.26:8080   users:(("tcp_connections",3342,4)) uid:1000 ino:23350 sk:ffff8800b4914140
ESTAB      0      0              192.168.0.17:49029         192.168.0.26:8080   users:(("tcp_connections",3342,6)) uid:1000 ino:23372 sk:ffff8800b4910740
ESTAB      0      0              192.168.0.17:49030         192.168.0.26:8080   users:(("tcp_connections",3342,7)) uid:1000 ino:23390 sk:ffff8800b49115c0
ESTAB      0      0              192.168.0.17:49028         192.168.0.26:8080   users:(("tcp_connections",3342,5)) uid:1000 ino:23368 sk:ffff8800b4910e80
ESTAB      0      0              192.168.0.17:49037         192.168.0.26:8080   users:(("tcp_connections",3342,14)) uid:1000 ino:23502 sk:ffff8800b4917400
ESTAB      0      0              192.168.0.17:49035         192.168.0.26:8080   users:(("tcp_connections",3342,12)) uid:1000 ino:23465 sk:ffff8800b4913a00
ESTAB      0      0              192.168.0.17:49036         192.168.0.26:8080   users:(("tcp_connections",3342,13)) uid:1000 ino:23484 sk:ffff8800b4915e40
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
ESTAB      0      0              192.168.0.17:49038         192.168.0.26:8080   users:(("tcp_connections",3342,15)) uid:1000 ino:23520 sk:ffff8800b4916580
ESTAB      0      0              192.168.0.17:49033         192.168.0.26:8080   users:(("tcp_connections",3342,10)) uid:1000 ino:23445 sk:ffff8800b4912b80
ESTAB      0      0              192.168.0.17:49034         192.168.0.26:8080   users:(("tcp_connections",3342,11)) uid:1000 ino:23447 sk:ffff8800b49132c0
ESTAB      0      0              192.168.0.17:49040         192.168.0.26:8080   users:(("tcp_connections",3342,17)) uid:1000 ino:23557 sk:ffff8800b4914880
ESTAB      0      0              192.168.0.17:49039         192.168.0.26:8080   users:(("tcp_connections",3342,16)) uid:1000 ino:23539 sk:ffff8800b4915700
ESTAB      0      0              192.168.0.17:49032         192.168.0.26:8080   users:(("tcp_connections",3342,9)) uid:1000 ino:23426 sk:ffff8800b4912440
---
...

A few more seconds later we see even more TCP connections in ESTABLISHED state, including src ports from 49035 to 49040. So we have a total of 15 ESTABLISHED connections with 0 bytes waiting to be ACKnowledged by the server. Remember we were expecting 14 (4 + 10), but instead we got 15 (4 + 11), odd right? I'll get back to this later...

...
---
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49031         192.168.0.26:8080   users:(("tcp_connections",3342,8)) uid:1000 ino:23408 sk:ffff8800b4911d00
ESTAB      0      0              192.168.0.17:49027         192.168.0.26:8080   users:(("tcp_connections",3342,4)) uid:1000 ino:23350 sk:ffff8800b4914140
ESTAB      0      0              192.168.0.17:49029         192.168.0.26:8080   users:(("tcp_connections",3342,6)) uid:1000 ino:23372 sk:ffff8800b4910740
ESTAB      0      0              192.168.0.17:49030         192.168.0.26:8080   users:(("tcp_connections",3342,7)) uid:1000 ino:23390 sk:ffff8800b49115c0
ESTAB      0      0              192.168.0.17:49028         192.168.0.26:8080   users:(("tcp_connections",3342,5)) uid:1000 ino:23368 sk:ffff8800b4910e80
ESTAB      0      0              192.168.0.17:49037         192.168.0.26:8080   users:(("tcp_connections",3342,14)) uid:1000 ino:23502 sk:ffff8800b4917400
ESTAB      0      0              192.168.0.17:49035         192.168.0.26:8080   users:(("tcp_connections",3342,12)) uid:1000 ino:23465 sk:ffff8800b4913a00
ESTAB      0      0              192.168.0.17:49036         192.168.0.26:8080   users:(("tcp_connections",3342,13)) uid:1000 ino:23484 sk:ffff8800b4915e40
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
ESTAB      0      0              192.168.0.17:49038         192.168.0.26:8080   users:(("tcp_connections",3342,15)) uid:1000 ino:23520 sk:ffff8800b4916580
ESTAB      0      0              192.168.0.17:49033         192.168.0.26:8080   users:(("tcp_connections",3342,10)) uid:1000 ino:23445 sk:ffff8800b4912b80
ESTAB      0      0              192.168.0.17:49034         192.168.0.26:8080   users:(("tcp_connections",3342,11)) uid:1000 ino:23447 sk:ffff8800b49132c0
ESTAB      0      0              192.168.0.17:49040         192.168.0.26:8080   users:(("tcp_connections",3342,17)) uid:1000 ino:23557 sk:ffff8800b4914880
ESTAB      0      4              192.168.0.17:49041         192.168.0.26:8080   timer:(on,1.208ms,3) users:(("tcp_connections",3342,18)) uid:1000 ino:23575 sk:ffff8800b4916cc0
ESTAB      0      0              192.168.0.17:49039         192.168.0.26:8080   users:(("tcp_connections",3342,16)) uid:1000 ino:23539 sk:ffff8800b4915700
ESTAB      0      0              192.168.0.17:49032         192.168.0.26:8080   users:(("tcp_connections",3342,9)) uid:1000 ino:23426 sk:ffff8800b4912440
ESTAB      0      4              192.168.0.17:49042         192.168.0.26:8080   timer:(on,608ms,2) users:(("tcp_connections",3342,19)) uid:1000 ino:23593 sk:ffff8800b4910000
---
...

This new sample shows 2 lines that are different than the rest, the ones using src ports 49041 and 49042.  These were the first 2 connections that couldn't fit in the somaxconn queue!!! And even more, you can see how the 4 bytes that were sent from the client haven't been acknowledged by the server and therefore they show up in the Send-Q column. Note how the connection looks as ESTABLISHED for the client though, this is because the 3-way handshake was completed from the client point of view.

...
---
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
ESTAB      0      0              192.168.0.17:49031         192.168.0.26:8080   users:(("tcp_connections",3342,8)) uid:1000 ino:23408 sk:ffff8800b4911d00
ESTAB      0      0              192.168.0.17:49027         192.168.0.26:8080   users:(("tcp_connections",3342,4)) uid:1000 ino:23350 sk:ffff8800b4914140
ESTAB      0      0              192.168.0.17:49029         192.168.0.26:8080   users:(("tcp_connections",3342,6)) uid:1000 ino:23372 sk:ffff8800b4910740
ESTAB      0      4              192.168.0.17:49047         192.168.0.26:8080   timer:(on,460ms,4) users:(("tcp_connections",3342,24)) uid:1000 ino:23632 sk:ffff8800a6efba00
ESTAB      0      4              192.168.0.17:49050         192.168.0.26:8080   timer:(on,132ms,3) users:(("tcp_connections",3342,27)) uid:1000 ino:23635 sk:ffff8800a6efc140
ESTAB      0      0              192.168.0.17:49030         192.168.0.26:8080   users:(("tcp_connections",3342,7)) uid:1000 ino:23390 sk:ffff8800b49115c0
ESTAB      0      0              192.168.0.17:49028         192.168.0.26:8080   users:(("tcp_connections",3342,5)) uid:1000 ino:23368 sk:ffff8800b4910e80
ESTAB      0      4              192.168.0.17:49045         192.168.0.26:8080   timer:(on,4.740ms,5) users:(("tcp_connections",3342,22)) uid:1000 ino:23630 sk:ffff8800a6efcfc0
ESTAB      0      4              192.168.0.17:49049         192.168.0.26:8080   timer:(on,2.336ms,4) users:(("tcp_connections",3342,26)) uid:1000 ino:23634 sk:ffff8800a6efc880
ESTAB      0      0              192.168.0.17:49037         192.168.0.26:8080   users:(("tcp_connections",3342,14)) uid:1000 ino:23502 sk:ffff8800b4917400
ESTAB      0      0              192.168.0.17:49035         192.168.0.26:8080   users:(("tcp_connections",3342,12)) uid:1000 ino:23465 sk:ffff8800b4913a00
ESTAB      0      4              192.168.0.17:49043         192.168.0.26:8080   timer:(on,2.740ms,5) users:(("tcp_connections",3342,20)) uid:1000 ino:23611 sk:ffff8800a6efde40
ESTAB      0      0              192.168.0.17:49036         192.168.0.26:8080   users:(("tcp_connections",3342,13)) uid:1000 ino:23484 sk:ffff8800b4915e40
ESTAB      0      4              192.168.0.17:49044         192.168.0.26:8080   timer:(on,3.732ms,5) users:(("tcp_connections",3342,21)) uid:1000 ino:23616 sk:ffff8800a6efd700
ESTAB      0      4              192.168.0.17:49046         192.168.0.26:8080   timer:(on,5.740ms,5) users:(("tcp_connections",3342,23)) uid:1000 ino:23631 sk:ffff8800a6eff400
ESTAB      0      0              192.168.0.17:49026         192.168.0.26:8080   users:(("tcp_connections",3342,3)) uid:1000 ino:23326 sk:ffff8800b4914fc0
ESTAB      0      4              192.168.0.17:49048         192.168.0.26:8080   timer:(on,1.336ms,4) users:(("tcp_connections",3342,25)) uid:1000 ino:23633 sk:ffff8800a6efecc0
ESTAB      0      0              192.168.0.17:49038         192.168.0.26:8080   users:(("tcp_connections",3342,15)) uid:1000 ino:23520 sk:ffff8800b4916580
ESTAB      0      0              192.168.0.17:49033         192.168.0.26:8080   users:(("tcp_connections",3342,10)) uid:1000 ino:23445 sk:ffff8800b4912b80
ESTAB      0      0              192.168.0.17:49034         192.168.0.26:8080   users:(("tcp_connections",3342,11)) uid:1000 ino:23447 sk:ffff8800b49132c0
ESTAB      0      0              192.168.0.17:49040         192.168.0.26:8080   users:(("tcp_connections",3342,17)) uid:1000 ino:23557 sk:ffff8800b4914880
ESTAB      0      4              192.168.0.17:49041         192.168.0.26:8080   timer:(on,732ms,5) users:(("tcp_connections",3342,18)) uid:1000 ino:23575 sk:ffff8800b4916cc0
ESTAB      0      0              192.168.0.17:49039         192.168.0.26:8080   users:(("tcp_connections",3342,16)) uid:1000 ino:23539 sk:ffff8800b4915700
ESTAB      0      0              192.168.0.17:49032         192.168.0.26:8080   users:(("tcp_connections",3342,9)) uid:1000 ino:23426 sk:ffff8800b4912440
ESTAB      0      4              192.168.0.17:49042         192.168.0.26:8080   timer:(on,1.732ms,5) users:(("tcp_connections",3342,19)) uid:1000 ino:23593 sk:ffff8800b4910000
---
^C
root@test:/home/juan#

The last sample shows the remaining connections from ports 49043 to 49050 all of them in the same condition, 4 bytes not being acknowledged.

From the client side samples we can confirm we got 15 complete TCP connections (src ports from 49026 to 49040) and 10 that even though showed up as ESTABLISHED weren't able to get acknowledged the 4 bytes sent by the client (src ports from 49041 to 49050).

TCP connections on the server


Lets have a look now to the samples taken on the server and see if they match with what we found on the client.

[root@server juan]# for i in {1..100}; do ss -tpn|grep "State\|8080"; echo "---"; sleep 2;done
State      Recv-Q Send-Q Local Address:Port               Peer Address:Port
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49026               users:(("nc",pid=13705,fd=5))
---
State      Recv-Q Send-Q Local Address:Port               Peer Address:Port
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49026               users:(("nc",pid=13705,fd=5))
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49028               users:(("nc",pid=13705,fd=7))
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49027               users:(("nc",pid=13705,fd=6))
---
...

The first samples look ok, nothing fancy there, we can see the first 3 TCP connections using src ports from 49026 to 49028.

...
---
State      Recv-Q Send-Q Local Address:Port               Peer Address:Port
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49026               users:(("nc",pid=13705,fd=5))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49031
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49033
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49029               users:(("nc",pid=13705,fd=8))
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49028               users:(("nc",pid=13705,fd=7))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49032
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49030
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49027               users:(("nc",pid=13705,fd=6))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49034
---
State      Recv-Q Send-Q Local Address:Port               Peer Address:Port
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49036
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49026               users:(("nc",pid=13705,fd=5))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49035
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49031
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49033
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49029               users:(("nc",pid=13705,fd=8))
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49028               users:(("nc",pid=13705,fd=7))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49032
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49030
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49027               users:(("nc",pid=13705,fd=6))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49034
---
...

And here it got interesting! We have now 4 connections (src ports between 49026 and 49029) which besides being ESTABLISHED have a FD associated to our nc process. However we have another 7 ESTABLISHED connections (src ports from 49030 to 49036) with no FD associated (and no process either :D)!!! These 7 connections are the ones waiting on the queue for nc to issue the accept() call. nc is actually issuing the accept calls, but the calls are failing due to nc having reached the maximum open files (because of the "ulimit -n 9").
  
...
---
State      Recv-Q Send-Q Local Address:Port               Peer Address:Port
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49036
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49026               users:(("nc",pid=13705,fd=5))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49038
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49035
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49031
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49033
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49029               users:(("nc",pid=13705,fd=8))
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49028               users:(("nc",pid=13705,fd=7))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49032
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49039
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49030
ESTAB      0      0      192.168.0.26:8080               192.168.0.17:49027               users:(("nc",pid=13705,fd=6))
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49037
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49040
ESTAB      4      0      192.168.0.26:8080               192.168.0.17:49034
---
^C
[root@server juan]#

After the binary issued the 25 connections, on the server we can see 4 ESTABLISHED connections (src ports 49026 to 49029) with corresponding FDs and 11 ESTABLISHED connections (src ports 49030 to 49040) with no FD. So... where are the remaining 10 connections that show up as ESTABLISHED on the client??? Well, these 10 connections didn't reach ESTABLISHED state on the server :D as per the documentation of listen():

The backlog argument defines the maximum length to which the queue of pending connections for sockfd may grow.  If a connection request arrives when the queue is full, the client may receive an error with an indication of ECONNREFUSED or, if the underlying protocol supports retransmission, the request may be ignored so that a later reattempt at connection succeeds.

Considering we are using TCP , the use case matches exactly with the underlined part.

To be continued...
Publicado por en No hay comentarios:
Etiquetas: , , , , , , , , , , , ,

domingo, 17 de mayo de 2015

UDP en GNU/Linux Parte I

Hace unos días me encontré con un caso interesante de pérdida de paquetes en transferencias utilizando UDP. Como se imaginaran poco me asombro que se perdieran paquetes UDP, ya que por definición se trata de un protocolo de transporte que no es fiable a la hora de entregar la información, una especie de cartero ebrio digamos. El control de flujo, el orden y la re transmisión no forman parte de las especificaciones de UDP [1], ya que fue ideado para ser simple. Meter los paquetes al cable y que la fuerza los acompañe.

Usar UDP como protocolo de transporte suele dar lugar a las siguientes situaciones:
  • Paquetes que nunca alcanzan el destino. Sin control de conexión y re transmisión, básicamente el emisor pone el paquete en el cable y se olvida por completo del mismo, no hay notificación de recepción ni nada que se le parezca.
  • Paquetes que llegan desordenados. Por esas cosas de las redes, los paquetes A y B que fueron enviados en ese orden podrían ser recibidos por el receptor en el orden inverso.
por lo tanto muchas aplicaciones que utilizan UDP deciden lidiar con estos problemas en la capa de aplicación.

En GNU/Linux, haciendo uso del programa netstat podemos ver las estadísticas UDP del sistema, por ejemplo:

root@ubuntu:/home/juan# netstat -su
Udp:
    23 packets received
    0 packets to unknown port received.
    0 packet receive errors
    23 packets sent
...
root@ubuntu:/home/juan#

En esta caso particular vemos que se enviaron 23 paquetes y se recibieron 23, muy probablemente se trate de consultas y respuestas DNS, ya que acabo de iniciar la máquina virtual. En total son 4 los campos disponibles de estadísticas UDP:
  • Packets received: número paquetes recibidos de manera satisfactoria por el sistema. Esto significa paquetes recibidos y pasados a la aplicación correspondiente.
  • Packets to unknown port received: número de paquetes que fueron recibidos pero no eran esperados por el sistema, es decir no había ninguna aplicación escuchando en ese puerto.
  • Packet receive errors: número de paquetes que no pasaron el checksum o que llegaron cuando el buffer de recepción se encontraba lleno y por lo tanto fueron descartados.
  • Packets sent: número de paquetes enviados por el sistema.

Probando Packets received:

Para probar este campo primero debemos identificar algún servicio escuchando en un puerto UDP, y para eso usamos netstat:

root@ubuntu:/home/juan# netstat -plun
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
udp        0      0 0.0.0.0:68              0.0.0.0:*                           558/dhclient   
udp        0      0 0.0.0.0:5113            0.0.0.0:*                           558/dhclient   
udp6       0      0 :::43512                :::*                                558/dhclient   
root@ubuntu:/home/juan#

Podemos ver que el puerto 68, 5113 y 43512 están en uso así que apuntaremos al puerto 68 y enviaremos 5 paquetes. Para generar tráfico UDP sin demasiadas complicaciones vamos a utilizar Hping3 [2] (aquí hay un post en donde lo utilicé para probar DNS Amplification attacks), para entender los parámetros man hping3.

root@moon:/home/juan# hping3 192.168.0.10 -2 -c 5 -p 68 -V
using wlan0, addr: 192.168.0.2, MTU: 1500
HPING 192.168.0.10 (wlan0 192.168.0.10): udp mode set, 28 headers + 0 data bytes

--- 192.168.0.10 hping statistic ---
5 packets transmitted, 0 packets received, 100% packet loss
round-trip min/avg/max = 0.0/0.0/0.0 ms
root@moon:/home/juan# 

Ahora veamos cómo se manifiesta esto en las estadísticas UDP:

root@ubuntu:/home/juan# netstat -su
Udp:
    28 packets received
    0 packets to unknown port received.
    0 packet receive errors
    23 packets sent
...
root@ubuntu:/home/juan#

Vemos que los paquetes recibidos se incrementaron en 5, como era de esperarse, ya que los paquetes tenían como destino un puerto donde había una aplicación escuchando (mas allá de que la aplicación haya sido capaz de interpretar el contenido de los paquetes o no).

Probando Packets to unknown port received:

Los campos Packets received y Packets sent son bastante simples de comprobar así que vamos a apuntar a este otro que es un poco mas interesante.El tráfico será:
  • Destinado al puerto 5555.
  • Enviaremos 10 paquetes.
 Shoot!

root@moon:/home/juan# hping3 8.8.8.8 -2 -c 10 -p 5555 -V
using wlan0, addr: 192.168.0.2, MTU: 1500
HPING 8.8.8.8 (wlan0 8.8.8.8): udp mode set, 28 headers + 0 data bytes

--- 8.8.8.8 hping statistic ---
10 packets transmitted, 0 packets received, 100% packet loss
round-trip min/avg/max = 0.0/0.0/0.0 ms
root@moon:/home/juan# hping3 192.168.0.10 -2 -c 10 -p 5555 -V
using wlan0, addr: 192.168.0.2, MTU: 1500
HPING 192.168.0.10 (wlan0 192.168.0.10): udp mode set, 28 headers + 0 data bytes
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1179 seq=0
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1180 seq=1
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1181 seq=2
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1182 seq=3
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1183 seq=4
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1184 seq=5
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1185 seq=6
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1186 seq=7
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1187 seq=8
ICMP Port Unreachable from ip=192.168.0.10 name=UNKNOWN  
status=0 port=1188 seq=9

--- 192.168.0.10 hping statistic ---
10 packets transmitted, 10 packets received, 0% packet loss
round-trip min/avg/max = 3.4/19.6/161.2 ms
root@moon:/home/juan#

Vemos que el destino nos respondió con un mensaje ICMP Port Unreachable por cada paquete que enviamos, lo cuál nos da dos pautas:
  • Los paquetes llegaron al sistema y el kernel reconoció que no tenía a quién entregarlos.
  • El host no tiene un firewall que descarte los paquetes a puertos que no sean necesarios.
Pero bien, ahora veamos qué pasó en los contadores del host destino!!

root@ubuntu:/home/juan# netstat -su
IcmpMsg:
    OutType3: 10
Udp:
    28 packets received
    10 packets to unknown port received.
    0 packet receive errors
    23 packets sent
...
root@ubuntu:/home/juan#

Exacto! Ahora tenemos 10 paquetes reconocidos como "packets to unknown port received" y también vemos los 10 mensajes ICMP enviados como respuesta.

Probando packet receive errors:

Ahora pongamos a prueba el reconocimiento de paquetes con problemas. Por suerte Hping3 nos permite, con el flag -b, enviar paquetes con el checksum corrupto así que usaremos eso para probar. En este punto haremos dos pruebas:

  • Prueba1
    • 5 paquetes con checksum inválido
    • puerto 68
  • Prueba 2
    • 5 paquetes con checksum inválido
    • puerto 5555
Prueba 1:

/root@moon:/home/juan# hping3 192.168.0.10 -2 -c 5 -p 68 -b -V
using wlan0, addr: 192.168.0.2, MTU: 1500
HPING 192.168.0.10 (wlan0 192.168.0.10): udp mode set, 28 headers + 0 data bytes

--- 192.168.0.10 hping statistic ---
5 packets transmitted, 0 packets received, 100% packet loss
round-trip min/avg/max = 0.0/0.0/0.0 ms
root@moon:/home/juan#


root@ubuntu:/home/juan# netstat -su
IcmpMsg:
    OutType3: 10
Udp:
    28 packets received
    10 packets to unknown port received.
    5 packet receive errors
    23 packets sent
    InCsumErrors: 5
...
root@ubuntu:/home/juan#
Ahora podemos ver que el valor de "packet receive errors" pasó de 0 a 5, también tenemos un nuevo campo llamado InCsumErrors con valor 5.

Prueba 2:

root@moon:/home/juan# hping3 192.168.0.10 -2 -c 5 -p 5555 -b -V
using wlan0, addr: 192.168.0.2, MTU: 1500
HPING 192.168.0.10 (wlan0 192.168.0.10): udp mode set, 28 headers + 0 data bytes

--- 192.168.0.10 hping statistic ---
5 packets transmitted, 0 packets received, 100% packet loss
round-trip min/avg/max = 0.0/0.0/0.0 ms
root@moon:/home/juan#


root@ubuntu:/home/juan# netstat -su
IcmpMsg:
    OutType3: 10
Udp:
    28 packets received
    10 packets to unknown port received.
    10 packet receive errors
    23 packets sent
    InCsumErrors: 10
...
root@ubuntu:/home/juan#

El número de packet receive errors (y InCsumErrors) volvió a incrementarse en 5. Vale notar que esta vez no recibimos los mensajes ICMP, básicamente porque los paquetes fueron descartados rápidamente por no tener el checksum inválido.

Un detalle llamativo de estas dos últimas pruebas es el siguiente. Viendo los logs escritos en /var/log/syslog, encontré:

May 17 15:08:25 ubuntu dhclient: 5 bad udp checksums in 5 packets
May 17 15:08:34 ubuntu kernel: [ 9005.777840] UDP: bad checksum. From 192.168.0.2:2868 to 192.168.0.10:5555 ulen 8
May 17 15:08:35 ubuntu kernel: [ 9006.776665] UDP: bad checksum. From 192.168.0.2:2869 to 192.168.0.10:5555 ulen 8
May 17 15:08:36 ubuntu kernel: [ 9007.781846] UDP: bad checksum. From 192.168.0.2:2870 to 192.168.0.10:5555 ulen 8
May 17 15:08:37 ubuntu kernel: [ 9008.776246] UDP: bad checksum. From 192.168.0.2:2871 to 192.168.0.10:5555 ulen 8
May 17 15:08:38 ubuntu kernel: [ 9009.779863] UDP: bad checksum. From 192.168.0.2:2872 to 192.168.0.10:5555 ulen 8

La primera línea indica que dhclient (el servicio escuchando en 68/UDP) recibió, o al menos se enteró de, los 5 paquetes con checksum erróneo, lo cual me deja un poco desconcertado. Aparentemente el kernel pasa estos paquetes de todas maneras a la aplicación, probablemente para que la aplicación decida qué medidas tomar. Las siguientes 5 líneas son del kernel indicando que se recibieron 5 paquetes UDP con bad checksum (dirigidos al 5555/UDP).

Otra forma un poco mas complicada de analizar packet receive erors es desde /proc/net/udp. La ventaja de este método es que la información está mas detallada, por ejemplo por puerto. netstat resume esta información.

root@ubuntu:/home/juan# cat /proc/net/udp
  sl  local_address rem_address   st tx_queue rx_queue tr tm->when retrnsmt   uid  timeout inode ref pointer drops            
   67: 00000000:0044 00000000:0000 07 00000000:00000000 00:00000000 00000000     0        0 8110 2 caaa82c0 5                
  248: 00000000:13F9 00000000:0000 07 00000000:00000000 00:00000000 00000000     0        0 8044 2 caaa8000 0                 
root@ubuntu:/home/juan#

En este caso marcado en "negrita" vemos 0044 valor hexadecimal del puerto 68, y por último el número de paquetes descartados para ese puerto 5 (los paquetes enviados con bad checksum). Otros valores importantes que vemos son tx_queue y rx_queue que básicamente indican que las colas están vacías dado que no hay paquetes llegando o saliendo del host.

Cuando describí el campo packet receive errors al comienzo del post, dije que este contador no solo se incrementa por paquetes defectuosos sino también por paquetes que al llegar encuentran el buffer de recepción lleno y son descartados. Esta última condición se genera cuando la tasa de llegada de paquetes es mayor a la tasa de procesamiento de los mismos. Un clásico problema productor-consumidor, si se produce a mayor tasa de la que se consume, el productor debe ser capaz de reconocer la situación y frenar la producción (control de flujo que UDP no posee) o el consumidor debe ser capaz de aumentar su velocidad de consumo o ampliar su capacidad de almacenar productos (incrementar el tamaño de los buffers).

Probar esta última situación resulta un poco mas complicado así que queda pendiente para la próxima publicación :P

Links:

[1] UDP - https://www.ietf.org/rfc/rfc768.txt
[2] Hping3 - http://wiki.hping.org/

Publicado por en No hay comentarios:
Etiquetas: , , , , , , , , , , ,
Suscribirse a: Entradas (Atom)