ERROR Error while accepting connection (kafka.network.Acceptor)

Да, именно с таким сообщением начала падать kafka спустя некоторое время после запуска. Включение режима debug немного увеличило «понятность»


ERROR Error while accepting connection (kafka.network.Acceptor)
java.net.SocketException: Invalid argument
at sun.nio.ch.Net.setIntOption0(Native Method)
at sun.nio.ch.Net.setSocketOption(Net.java:341)
at sun.nio.ch.SocketChannelImpl.setOption(SocketChannelImpl.java:190)
at sun.nio.ch.SocketAdaptor.setBooleanOption(SocketAdaptor.java:271)
at sun.nio.ch.SocketAdaptor.setTcpNoDelay(SocketAdaptor.java:306)
at kafka.network.Acceptor.accept(SocketServer.scala:654)
at kafka.network.Acceptor.run(SocketServer.scala:579)
at java.lang.Thread.run(Thread.java:748)

Почему падала kafka? Она плодила сокеты с портом 0

sockname: AF_INET 0.0.0.0 port: 0

И сокеты не закрывались. В какой-то момент достигался лимит на количество открытых файлов и процесс прибивался системой.

По словам java-сотрудника дело могло быть в установке setTcpNoDelay при создании TCP-сокета. Быстрое гугление навело на bug и вариант решения (кстати, этот баг так же присутствовал и в остальных Solaris-based OS, например Illumos , smartOS). Несмотря на «старость» бага, он всё ещё присутствовал и решился предложенным вариантом по ссылке. Ну, как решился, сокеты прекратились создаваться, но ошибки в лог продолжали писаться.

Казалось бы, на этом статью можно закончить, ведь проблема «вроде бы» решена. Но академический интерес взял свой и я решил поглубже узнать, почему возникает данная ошибка и можно ли вообще от неё избавится?

Из вывода ошибки, значит, что по какой-то причине нельзя установить TCP_NODELAY. Если кратко — то эта опция позволяет отправлять пакеты сразу, не дожидаясь формирования более объёмного пакета с отправкой за 1 раз всех данных. Такой вариант позволяет ускорять работу обмена в сети при некоторых условиях. Детальнее об этом можно прочитать здесь и здесь

Давайте посмотрим, что происходит через truss:


/46: accept(676, 0x07463D30, 0x7FFF9FFF64F4, SOV_DEFAULT) = 21992
/46: fcntl(21992, F_GETFL) = 130
/46: fcntl(21992, F_SETFL, FWRITE) = 0
/46: getsockname(21992, 0x7FFF9FFF64F0, 0x7FFF9FFF64E8, SOV_DEFAULT) = 0
/46: getsockname(21992, 0x7FFF9FFF64F0, 0x7FFF9FFF64EC, SOV_DEFAULT) = 0
/46: fcntl(21992, F_GETFL) = 2
/46: fcntl(21992, F_SETFL, FWRITE|FNONBLOCK) = 0
/46: setsockopt(21992, tcp, TCP_NODELAY, 0x7FFF9FFF6470, 4, SOV_DEFAULT) = 0
/46: setsockopt(21992, SOL_SOCKET, SO_KEEPALIVE, 0x7FFF9FFF6470, 4, SOV_DEFAULT) = 0
/46: setsockopt(21992, SOL_SOCKET, SO_SNDBUF, 0x7FFF9FFF6470, 4, SOV_DEFAULT) = 0

Как видим, идёт попытка установки флага TCP_NODELAY и код возврата функции setsockopt == 0, значит, что успешно установлено, но если взглянуть через pfiles на процесс и найти соответствующий сокет, мы увидим, что флага TCP_NODELAY — нет:

 32404: S_IFSOCK mode:0666 dev:16377,0 ino:21992 uid:0 gid:0 size:0 
      O_RDWR|O_NONBLOCK
        sockname: AF_INET 0.0.0.0  port: 0
        SOCK_STREAM
        SO_REUSEADDR,SO_SNDBUF(256000),SO_RCVBUF(104256)
        congestion control: newreno

Как же так? Обратимся к документации функции setsockopts и попробуем найти TCP_NODELAY и в версии для Solaris его действительно нет. На всякий случай приложу выдержку из документации по установке TCP_NODELAY. Выходит, этого параметра нет, но при этом, setsockopt не ругается на неверный параметр и возврат значения говорит, что типа всё применилось. Пробуем поискать по папке include и находим описание параметра

/usr/include/netinet/tcp.h:#define      TCP_NODELAY     0x01    /* don't delay send to coalesce packets */

Значит есть! Давайте проверим. Для проверки я взял скрипт на python’e, который устанавливает TCP_NODELAY

#!/usr/bin/python

import socket

sock = socket.socket()
sock.bind(('127.0.0.1', 45454))
sock.setsockopt(socket.SOL_SOCKET, socket.TCP_NODELAY, 1)
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.setsockopt(socket.SOL_TCP, socket.TCP_NODELAY, 1)
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
sock.listen(1)
conn, addr = sock.accept()

print ('connected:', addr)

while True:
    data = conn.recv(1024)
    if not data:
        break
    conn.send(data.upper())

conn.close()

Но через pfiles никакого NODELAY не видно. Зато вместо него появился SO_DEBUG.

3: S_IFSOCK mode:0666 dev:16377,0 ino:33482 uid:0 gid:0 size:0 
      O_RDWR
        sockname: AF_INET 127.0.0.1  port: 45454
        SOCK_STREAM
        SO_DEBUG,SO_ACCEPTCONN,SO_SNDBUF(256000),SO_RCVBUF(256000)

Пробуем поискать по SO_DEBUG и находим интересную вещь:

$ grep SO_DEBUG /usr/include/sys/socket.h
#define SO_DEBUG        0x0001          /* turn on debugging info recording */

и что мы видим? Правильно, одно и то же числовое значение «1«. То есть, вместо TCP_NODELAY выставляется флаг DEBUG. Для уверенности, решил проверить установку флага через С-шный код. Я знал, что результат будет таким же, но на всякий случай проверил. Да, результат оказался таким же. То есть, по факту TCP_NODELAY отключён на уровне ОС. Это косвенно подтверждает и попытка манипулировать параметром tcp_naglim_def , но в 11.4 (был вплоть до 11.0 и убрали, начиная с 11.1) его уже нет в документации, хотя по факту присутствует и имеет максимальное значение 65535. Смена значения в 1 (хотя в документации выше сказано, что именно там можно отключить алгоритм Нагеля, то есть включить TCP_NODELAY) ни к чему не приводит.

И тут наверное нужно было сделать вывод, что TCP_NODELAY, отключён. Но! Нужно же провести практический эксперимент, где будет видно, что действительно отправляются маленькие пакеты или, наоборот, большие. Нашлась статья, с помощью которой это можно проверить. После проверки, оказывается что TCP_NODELAY включён и выключить его нельзя. То есть, логика такая: в параметрах sock opts не светится, по факту работает, в документации не описан и ошибок не вызывает )).

Резюмируем, причина — найдена. А как дела обстоят в других ОС?

FreeBSD.

Тут всё работает как надо без проблем:

$ lsof -a -p 18011 -i 4 -T f
COMMAND     PID     USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
python3.7 18011 skeletor    3u  IPv4 0xfffff8002bda87a0      0t0  TCP 127.0.0.1:45454 (SO=ACCEPTCONN,DEBUG,PQLEN=0,QLEN=0,QLIM=1,RCVBUF=0,REUSEADDR,SNDBUF=0 TF=MSS=536,NODELAY,REQ_SCALE,REQ_TSTMP)

Linux.

Тут тоже всё работает без проблем, но вот посмотреть socket options через lsof уже нельзя. Ниже выдержка из man lsof:

Linux
No socket options and values, socket states, or TCP
flags and values are reported. The support for «-Tf»
could not be added to Linux, because socket options,
socket states, and TCP flags and values are not
available via the /proc file system.»

Тут на помощь приходит модуль ядра knetstat Ниже пример использования:

     0      0 0.0.0.0:80              0.0.0.0:*               LSTN      SO_REUSEADDR=1,SO_REUSEPORT=0,SO_KEEPALIVE=0,TCP_NODELAY=0,TCP_FASTOPEN=0,TCP_DEFER_ACCEPT=0
     0      0 127.0.0.1:45454           0.0.0.0:*               LSTN      SO_REUSEADDR=1,SO_REUSEPORT=0,SO_KEEPALIVE=0,TCP_NODELAY=1,TCP_FASTOPEN=0,TCP_DEFER_ACCEPT=0

Некоторое ПО позволяет меня TCP_NODELAY, например, nginx

Добавить комментарий

Ваш адрес email не будет опубликован. Обязательные поля помечены *