На хосте RHEL 6 у меня есть сервер Cassandra, который прослушивает TCP-соединения на локальном хосте. Параллельно у меня есть клиентское приложение, которое отправляет ему запросы. Клиент (C # Mono) использует sendmsg
для отправки сериализованных байтов.
Я постоянно вижу возвращение sendmsg
не отправив все запрошенные байты. Я использовал strace
чтобы попытаться отладить это
sudo strace -p<pid> -s 100 -f -tt &> tmp.out
и увидел (отфильтрованный образец для нити тид 47605
)
[pid 47605] 16:32:13.388307 sendmsg(8, {msg_name(0)=NULL, msg_iov(2)=[{"\4\0\0\1\n\0\0]x\0\20\2545\250\260\34\26152:{i\261\204\266\3759\0\n\5\0\2\0\0\0\4\0\0\0\1\0\0]Q0_1_2_3_4_5_6_7_8_9_10_11_12_13_14_15_16_17_18_19_20_21_"..., 16384}, {"3490_3491_3492_3493_3494_3495_3496_3497_3498_3499_3500_3501_3502_3503_3504_3505_3506_3507_3508_3509_"..., 7553}], msg_controllen=0, msg_flags=0}, 0 <unfinished ...>
[pid 46142] 16:32:13.413922 tgkill(46142, 47605, SIGPWR) = 0
[pid 47605] 16:32:13.414024 <... sendmsg resumed> ) = 16384
[pid 47605] 16:32:13.414094 --- SIGPWR (Power failure) @ 0 (0) ---
[pid 47605] 16:32:13.414191 rt_sigprocmask(SIG_BLOCK, [XCPU], <unfinished ...>
[pid 47605] 16:32:13.414242 <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 47605] 16:32:13.414304 rt_sigsuspend(~[XCPU RTMIN RT_1] <unfinished ...>
[pid 46142] 16:32:13.418930 tgkill(46142, 47605, SIGXCPU) = 0
[pid 47605] 16:32:13.419057 <... rt_sigsuspend resumed> ) = ? ERESTARTNOHAND (To be restarted)
[pid 47605] 16:32:13.419143 --- SIGXCPU (CPU time limit exceeded) @ 0 (0) ---
[pid 47605] 16:32:13.419236 rt_sigreturn(0x30 <unfinished ...>
[pid 47605] 16:32:13.419306 <... rt_sigreturn resumed> ) = -1 EINTR (Interrupted system call)
[pid 47605] 16:32:13.419360 rt_sigprocmask(SIG_UNBLOCK, [XCPU], <unfinished ...>
[pid 47605] 16:32:13.419431 <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 47605] 16:32:13.419481 rt_sigreturn(0xffffffff <unfinished ...>
[pid 47605] 16:32:13.419562 <... rt_sigreturn resumed> ) = 16384
Кажется, это указывает на то, что поток с tid 46142
использовал tgkill
для отправки сигнала SIGPWR потоку с tid 47605
который находился в процессе отправки байтов с sendmsg
. Это каким-то образом прервало его и закончилось отправкой 16384 из 23937 запрошенных байтов.
Я пытался увидеть, что нить с tid 46142
делает что-нибудь, что может объяснить причину tgkill
, но все, что я вижу, это
[pid 46142] 16:32:13.370983 futex(0x34af8d0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 46142] 16:32:13.371061 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 46142] 16:32:13.371169 futex(0x34af8d0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 46142] 16:32:13.371221 <... futex resumed> ) = 0
[pid 46142] 16:32:13.377014 brk(0x3d45000 <unfinished ...>
[pid 46142] 16:32:13.377254 <... brk resumed> ) = 0x3d45000
[pid 46142] 16:32:13.378971 mmap(0x40696000, 65536, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANONYMOUS|MAP_32BIT, -1, 0) = 0x40696000
[pid 46142] 16:32:13.381868 futex(0x7feb0000b88c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7feb0000b888, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
[pid 46142] 16:32:13.413922 tgkill(46142, 47605, SIGPWR) = 0
[pid 46142] 16:32:13.413992 tgkill(46142, 47599, SIGPWR <unfinished ...>
[pid 46142] 16:32:13.414221 <... tgkill resumed> ) = 0
[pid 46142] 16:32:13.414267 tgkill(46142, 46146, SIGPWR <unfinished ...>
[pid 46142] 16:32:13.414437 <... tgkill resumed> ) = 0
[pid 46142] 16:32:13.414601 futex(0x1b1e320, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 46142] 16:32:13.414718 <... futex resumed> ) = 0
[pid 46142] 16:32:13.414767 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feb19800000
что я не могу понять в контексте системного вызова сети.
Что может привести к тому, что поток отправит сигнал SIGPWR?
Я не уверен, что это уместно, но я использую размер буфера отправки сокета 4096, а размер MTU интерфейса обратной связи установлен на 16436. Я могу последовательно воспроизвести частичный sendmsg
с этими размерами. Однако, если я удвою размер MTU, проблема исчезнет. Точно так же, если я установлю размер буфера отправки моего сокета на что-то намного большее, например, 24000, я больше не смогу воспроизвести проблему.