Пропавшие пакеты внутри контейнера
Я наблюдаю странные прерывистые тайм-ауты HTTP-вызовов из модуля на k8s. Модуль запускает java-программу и выполняет HTTP-вызовы на другие узлы и даже обратно на свой локальный IP-адрес. Мы проходим периоды около 5-10 минут за раз несколько раз в день, когда некоторые из этих HTTP-вызовов получают тайм-аут, даже если вызываемый удаленный сервер доступен. В этих временных окнах таймауты приходят и уходят независимо от того, идет ли HTTP-вызов к другим модулям или даже обратно на собственный локальный IP-адрес.
Чтобы проиллюстрировать проблему, вот файл журнала трех HTTP-вызовов и связанного захвата пакетов, выполненного с помощью tcpdump на узле:
Call 1 - success
2020/03/10 22:38:24.471 FINE [jg-es-1][guru.jini.arch.impl.other.HttpImpl.doHttpMethodReactive] # Sending [GET] request to [http://100.96.26.24:8080] --
2020/03/10 22:38:24.475 FINE [jg-async-http-3-4][guru.jini.arch.impl.rest.JaxRsResponse.<init>] # Response to [GET] on [http://100.96.26.24:8080] with RequestId [4545818456] after [3.307892]ms --
2 seconds later... Call 2 - fail
2020/03/10 22:38:26.471 FINE [jg-es-1][guru.jini.arch.impl.other.HttpImpl.doHttpMethodReactive] # Sending [GET] request to [http://100.96.26.24:8080] --
2020/03/10 22:38:27.506 WARNING [jg-async-http-timer-1-1][guru.jini.arch.impl.servicediscovery.ServiceImpl.failedTest] # Failed: java.util.concurrent.TimeoutException: Request timeout to 100.96.26.24:8080 after 1000 ms]
2 seconds later... Call 3 - success
2020/03/10 22:38:28.471 FINE [jg-es-1][guru.jini.arch.impl.other.HttpImpl.doHttpMethodReactive] # Sending [GET] request to [http://100.96.26.24:8080] --
2020/03/10 22:38:28.475 FINE [jg-async-http-3-1][guru.jini.arch.impl.rest.JaxRsResponse.<init>] # Response to [GET] on [http://100.96.26.24:8080] with RequestId [4545818464] after [3.483304]ms --
Вот tcpdump за этот период, взятый из работающего контейнера докеров:
Call 1
22:38:24.472285 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [S], seq 2419932923, win 65535, options [mss 8911,sackOK,TS val 1192127411 ecr 0,nop,wscale 9], length 0
22:38:24.472837 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45124: Flags [S.], seq 331830089, ack 2419932924, win 65535, options [mss 8911,sackOK,TS val 2177727951 ecr 1192127411,nop,wscale 9], length 0
22:38:24.472853 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [.], ack 1, win 128, options [nop,nop,TS val 1192127412 ecr 2177727951], length 0
22:38:24.473302 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [P.], seq 1:219, ack 1, win 128, options [nop,nop,TS val 1192127412 ecr 2177727951], length 218: HTTP: GET / HTTP/1.1
22:38:24.473711 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45124: Flags [.], ack 219, win 131, options [nop,nop,TS val 2177727952 ecr 1192127412], length 0
22:38:24.475130 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45124: Flags [P.], seq 1:18, ack 219, win 131, options [nop,nop,TS val 2177727954 ecr 1192127412], length 17: HTTP: HTTP/1.0 200 OK
22:38:24.475140 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [.], ack 18, win 128, options [nop,nop,TS val 1192127414 ecr 2177727954], length 0
22:38:24.475278 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45124: Flags [FP.], seq 18:3550, ack 219, win 131, options [nop,nop,TS val 2177727954 ecr 1192127412], length 3532: HTTP
22:38:24.475286 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [.], ack 3551, win 163, options [nop,nop,TS val 1192127414 ecr 2177727954], length 0
22:38:24.475335 IP wakanda-wep-v024-428bk.45124 > 100.96.26.24.8080: Flags [F.], seq 219, ack 3551, win 163, options [nop,nop,TS val 1192127414 ecr 2177727954], length 0
22:38:24.475750 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45124: Flags [.], ack 220, win 131, options [nop,nop,TS val 2177727954 ecr 1192127414], length 0
Call 3
22:38:28.472442 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [S], seq 1259113428, win 65535, options [mss 8911,sackOK,TS val 1192131411 ecr 0,nop,wscale 9], length 0
22:38:28.472999 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45182: Flags [S.], seq 3440185005, ack 1259113429, win 65535, options [mss 8911,sackOK,TS val 2177731951 ecr 1192131411,nop,wscale 9], length 0
22:38:28.473031 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [.], ack 1, win 128, options [nop,nop,TS val 1192131412 ecr 2177731951], length 0
22:38:28.473366 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [P.], seq 1:219, ack 1, win 128, options [nop,nop,TS val 1192131412 ecr 2177731951], length 218: HTTP: GET / HTTP/1.1
22:38:28.473773 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45182: Flags [.], ack 219, win 131, options [nop,nop,TS val 2177731952 ecr 1192131412], length 0
22:38:28.475348 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45182: Flags [P.], seq 1:18, ack 219, win 131, options [nop,nop,TS val 2177731954 ecr 1192131412], length 17: HTTP: HTTP/1.0 200 OK
22:38:28.475361 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [.], ack 18, win 128, options [nop,nop,TS val 1192131414 ecr 2177731954], length 0
22:38:28.475492 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45182: Flags [FP.], seq 18:3550, ack 219, win 131, options [nop,nop,TS val 2177731954 ecr 1192131412], length 3532: HTTP
22:38:28.475501 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [.], ack 3551, win 163, options [nop,nop,TS val 1192131414 ecr 2177731954], length 0
22:38:28.475545 IP wakanda-wep-v024-428bk.45182 > 100.96.26.24.8080: Flags [F.], seq 219, ack 3551, win 163, options [nop,nop,TS val 1192131414 ecr 2177731954], length 0
22:38:28.476074 IP 100.96.26.24.8080 > wakanda-wep-v024-428bk.45182: Flags [.], ack 220, win 131, options [nop,nop,TS val 2177731954 ecr 1192131414], length 0
Как видите, запрос вызова 2 в 22:38:26 даже не виден в дампе TCP. Это объясняет, почему существует тайм-аут, поскольку запрос даже не попадает в сеть.
Я не понимаю, где искать. Мы пробовали разные JVM (хотспот и openj9), разные HTTP-клиенты в коде Java. Все без изменений. Если мы установим очень большой тайм-аут, это не будет иметь никакого значения - пакеты никогда не видны в tcpdump.
Кластер k8s использует ресничку, и кластер работает нормально. Нет проблем с сетью, памятью, скачками ЦП в это время. Другие модули в кластере не имеют этой проблемы. Мы видели эту проблему на двух разных кластерах, настроенных независимо, и всегда с ней сталкивались модули, на которых запущен этот конкретный микросервис Java. Микросервис, работающий за пределами k8s в обычном докере, отлично работает без каких-либо тайм-аутов.
Дополнительная информация: Java - это jdk 11. Контейнерная ОС - Ubuntu 18.04. Узлы находятся в AWS EC2 и работают под управлением k8s v1.13.9. Node OS - это контейнерный Linux от CoreOS 2345.3.0 (Rhyolite), версия ядра 4.19.106-coreos. Докер - это докер://18.6.3
манифест службы:
apiVersion: apps/v1
kind: Deployment
metadata:
name: wakanda-wep
annotations:
moniker.spinnaker.io/application: wakanda-wep
moniker.spinnaker.io/cluster: deployment wakanda-wep
traffic.spinnaker.io/load-balancers: '["service wakanda-wep"]'
labels:
app.kubernetes.io/name: wakanda-wep
app.kubernetes.io/managed-by: spinnaker
spec:
replicas: 1
revisionHistoryLimit: 1
selector:
matchLabels:
app.kubernetes.io/name: wakanda-wep
template:
metadata:
annotations:
moniker.spinnaker.io/application: wakanda-wep
moniker.spinnaker.io/cluster: deployment wakanda-wep
labels:
app.kubernetes.io/name: wakanda-wep
app.kubernetes.io/managed-by: spinnaker
spec:
containers:
- name: wakanda-wep
image: xxx/wakanda-wep
imagePullPolicy: Always
envFrom:
- configMapRef:
name: wakanda-wep
env:
- name: XXX
valueFrom:
secretKeyRef:
key: XXX
name: XXX
resources:
limits:
cpu: 2000m
memory: 2000Mi
requests:
cpu: 1000m
memory: 1000Mi
ports:
- containerPort: 8000
name: http
protocol: TCP
livenessProbe:
failureThreshold: 5
httpGet:
path: wep-conductor/rest/v1/isup
port: 8000
initialDelaySeconds: 60
periodSeconds: 3
timeoutSeconds: 1
readinessProbe:
failureThreshold: 5
httpGet:
path: wep-conductor/rest/v1/isup
port: 8000
initialDelaySeconds: 30
periodSeconds: 5
timeoutSeconds: 1
ingress:
enabled: true
annotations:
nginx.ingress.kubernetes.io/rewrite-target: /$2
labels:
app: wakanda-wep
path: /prod/wep(/|$)(.*)
servicePort: https
hosts:
- internal-api.xxx.yyy
tls:
- hosts:
- internal-api.xxx.yyy
secretName: xxx
service:
enabled: true
ports:
https:
port: 443
targetPort: 8000
protocol: TCP
horizontalPodAutoscaler:
enabled: true
minReplicas: 1
maxReplicas: 3
avgCpuUtilization: 80
avgMemoryUtilization: 80
canary:
enabled: false
Базовая диаграмма, иллюстрирующая ситуацию: Диаграмма
С чего бы нам вообще начать искать и какие подсказки о том, что могло это вызвать?