UlricE / pen

Pen
Other
250 stars 41 forks source link

file descriptor leak when processing UDP packets #46

Open tmueller64 opened 5 years ago

tmueller64 commented 5 years ago

When pen is configured to forward UDP packets, I'm seeing an increasing number of open UDP file descriptors until eventually the process terminates. The root cause appears to be in the add_client method where the downfd socket is opened but is then never closed.

Here is a bit of output from lsof which shows the open file descriptors (pen is being used to forward Kerberos port 88 UDP packets):

pen 4173 root 318u IPv4 10252194 0t0 UDP 10.1.8.71:kerberos->98.161.23.149:60888 pen 4173 root 319u IPv4 10252195 0t0 UDP 10.1.8.71:58509->10.1.93.108:kerberos pen 4173 root 320u IPv4 10252196 0t0 UDP 10.1.8.71:kerberos->98.161.23.149:60888 pen 4173 root 321u IPv4 10252197 0t0 UDP 10.1.8.71:42021->10.1.93.108:kerberos

Here 10.1.8.71 is the IP address of the host running pen, 10.1.93.108 is the server that packets are being forwarded to, and 98.161.23.149 is a client.

UlricE commented 5 years ago

That should not be the case. Pen keeps track of UDP streams with the same 5-tuples, because many applications depend on it. This information is stored in the same connection table as is used for TCP, but since UDP doesn't have the concept of connections, Pen recycles the "connections" using a clock-type algorithm. So the number of open file descriptors should increase to twice the size of the connection table, which is 500 entries by default.

Here's what should happen:

Window 1, start Pen with a small connection table of 10 entries: root@debtest:~# pen -ddfU -x 10 53 8.8.8.8

Window 2, repeatedly make DNS requests to Pen: root@debtest:~# while test ! -f stop;do dig @localhost +short siag.nu; lsof|grep -c '^pen.*UDP';done 93.188.2.52 3 93.188.2.52 5 93.188.2.52 7 93.188.2.52 9 93.188.2.52 11 93.188.2.52 13 93.188.2.52 15 93.188.2.52 17 93.188.2.52 19 93.188.2.52 21 93.188.2.52 21 93.188.2.52 21 93.188.2.52 21 93.188.2.52 21 93.188.2.52 21 93.188.2.52 21

Back in window 1, we have this output: 2018-12-04 13:47:18: add_client: received 36 bytes from client 2018-12-04 13:47:18: socket returns 14, socket_errno=95 2018-12-04 13:47:18: Client 127.0.0.1 has index 0 2018-12-04 13:47:18: store_client returns 0 2018-12-04 13:47:18: Recycling halfdead connection 5 2018-12-04 13:47:18: epoll_event_delete(fd=16) 2018-12-04 13:47:18: epoll_event_delete(fd=15) 2018-12-04 13:47:18: decrementing connections_used to 9 for connection 5 2018-12-04 13:47:18: close_conn: Closing connection 5 to server 0; connections_used = 9

Now that's what should happen - if you say the process terminates, then you may have hit a bug.

tmueller64 commented 5 years ago

We had the -x option set to 1024, but were unaware that the number of sockets could go to twice that.