latência de 200 ms entre TCP send e tcpdump apenas com mensagens grandes

Question

Em nosso servidor REHL, a latência entre o envio de aplicativos e o log tcpdump é sempre muito grande para mensagens grandes, cerca de 200 milissegundos (veja abaixo 697572-488690 = 208882 microssegundos), enquanto a latência para mensagens pequenas é muito pequeno, apenas alguns microssegundos.

Acho que nenhum dos cronômetros TCP pode explicar o atraso de 200 ms. Esse tipo de latência é geralmente devido ao algoritmo de Nagle para mensagens pequenas, o que não é o caso aqui, pois a alta latência é apenas para mensagens grandes.

Com uma mensagem grande:

IBM MQ registros de rastreio extrai:

12:13:12.488685     4172.1      RSESS:000001 ----{  ccxSend
12:13:12.488688     4172.1      RSESS:000001 -----{  cciTcpSend
12:13:12.488690     4172.1      RSESS:000001 ------{  send
12:13:12.488697     4172.1      RSESS:000001 ------}  send rc=OK
12:13:12.488711     4172.1      RSESS:000001      Sending 1138 bytes
[large message]
12:13:12.488714     4172.1      RSESS:000001      RetCode (OK)
12:13:12.488716     4172.1      RSESS:000001 -----}  cciTcpSend rc=OK

Extrações do

tcpdump:

12:13:05.884715 IP (tos 0x0, ttl  49, id 60415, offset 0, flags [DF], proto: TCP (6), length: 68) otherHost.otherPort > ourHost.ourPort: P, cksum 0x7673 (correct), 2893948259:2893948287(28) ack 1576932354 win 1024                           ....
12:13:05.884718 IP (tos 0x0, ttl  64, id 60352, offset 0, flags [DF], proto: TCP (6), length: 40) ourHost.ourPort > otherHost.otherPort: ., cksum 0xcd9c (correct), ack 2893948287 win 5768
12:13:12.697572 IP (tos 0x0, ttl  64, id 60353, offset 0, flags [DF], proto: TCP (6), length: 1064) ourHost.ourPort > otherHost.otherPort: P, cksum 0x0059 (incorrect (-> 0x6a5a), 1576932354:1576933378(1024) ack 2893948287 win 5768
[first packet of large message]
12:13:12.708367 IP (tos 0x0, ttl  49, id 61060, offset 0, flags [DF], proto: TCP (6), length: 40) otherHost.otherPort > ourHost.ourPort: ., cksum 0xe024 (correct), ack 1576933378 win 0
12:13:12.708865 IP (tos 0x0, ttl  49, id 61061, offset 0, flags [DF], proto: TCP (6), length: 40) otherHost.otherPort > ourHost.ourPort: ., cksum 0xdc24 (correct), ack 1576933378 win 1024
12:13:12.708869 IP (tos 0x0, ttl  64, id 60354, offset 0, flags [DF], proto: TCP (6), length: 154) ourHost.ourPort > otherHost.otherPort: P, cksum 0xfcca (incorrect (-> 0xa1fb), 1576933378:1576933492(114) ack 2893948287 win 5768
[second packet of large message]
12:13:12.716154 IP (tos 0x0, ttl  49, id 61062, offset 0, flags [DF], proto: TCP (6), length: 40) otherHost.otherPort > ourHost.ourPort: ., cksum 0xdc24 (correct), ack 1576933492 win 910
12:13:12.717202 IP (tos 0x0, ttl  49, id 61063, offset 0, flags [DF], proto: TCP (6), length: 68) otherHost.otherPort > ourHost.ourPort: P, cksum 0x71e5 (correct), 2893948287:2893948315(28) ack 1576933492 win 1024
12:13:12.717209 IP (tos 0x0, ttl  64, id 60355, offset 0, flags [DF], proto: TCP (6), length: 40) ourHost.ourPort > otherHost.otherPort: ., cksum 0xc90e (correct), ack 2893948315 win 5768

Com uma mensagem pequena (menos contexto em extrações):

15:15:33.133940     4215.1      RSESS:000001 ------{ send               
15:15:33.133954     4215.1      RSESS:000001 ------}  send rc=OK
...
15:15:33.133966     4215.1      RSESS:000001      Sending 512 bytes
[small message]
15:15:33.133969     4215.1      RSESS:000001      RetCode (OK)

tcpdump:

15:15:33.133949 IP (tos 0x0, ttl  64, id 37357, offset 0, flags [DF], proto: TCP (6), length: 552) ourHost.ourPort > otherHost.otherPort: P, cksum 0xfe58 (incorrect (-> 0x2dd8), 1566021015:1566021527(512) ack 2491002247 win 5768
[small message]

Versões de sistema e drivers:

Linux 2.6.18-128.el5 # 1 SMP qua Dez 17 11:41:38 EST 2008 x86_64 x86_64 x86_64 GNU / Linux

Servidor Red Hat Enterprise Linux versão 5.3 (Tikanga)

# /usr/sbin/ethtool -i bond0
driver: bonding
version: 3.2.4
firmware-version: 2

$ cat /proc/net/bonding/bond0
Ethernet Channel Bonding Driver: v3.2.4 (January 28, 2008)
Bonding Mode: fault-tolerance (active-backup)
Currently Active Slave: eth2

# /usr/sbin/ethtool -i eth2
driver: e1000e
version: 1.2.10-NAPI
firmware-version: 5.12-2

Próximos passos?

Sem encontrar a causa raiz desse problema, estou pensando em:

• Apenas tentando atualizar vínculo ou e1000e drivers. A propósito, para verificar se algum bug de ligação pode estar envolvido, alguém sabe onde estão as versões do driver de ligação e as notas de lançamento?
• pedindo ao outro lado para definir uma janela TCP maior, já que não há problema quando apenas um pacote tem que ser enviado para uma mensagem. Além disso, isso diminuiria a latência em 10 milissegundos, o tempo entre o primeiro e o segundo pacote para uma mensagem grande.

Alguém tem alguma outra ideia? Existe alguma maneira de obter logs de rastreamento para ligação ou drivers e1000e?

    

Answer 1

Você está passando muito poucos bytes em cada chamada para send ou write . Você precisa tentar passar pelo menos 2 KB por chamada ou, melhor, 4 KB por chamada. Se possível, acumule toda a mensagem lógica e envie-a imediatamente. Isso salvará as chamadas do sistema, compactará seus pacotes com mais eficiência e evitará que o ACK atrasado destrua sua latência.

    

Answer 2

De acordo com Linux Tuning: Expert Guide da Base de Conhecimento de Desempenho da Rede ESnet:

NOTE: There seems to be bugs in both bic and cubic for a number of versions of the 2.6.18 kernel used by Redhat Enterprise Linux 5.3 - 5.5 and its variants (Centos, Scientific Linux, etc.) We recommend using htcp with a 2.6.18.x kernel to be safe.

Não encontrei nenhum detalhe sobre esses bugs bic ou cúbicos em Banco de dados de bugs da Red Hat ou qualquer outro lugar, portanto não há prova de que esta é a resposta real.