Отброшенные пакеты в модуле - PullRequest
Новая
       22

Отброшенные пакеты в модуле

0 голосов
/ 04 апреля 2020

Я наблюдаю странные прерывистые тайм-ауты при HTTP-вызовах из модуля на k8s. Модуль запускает программу java и выполняет HTTP-вызовы к другим узлам и даже обратно в свой локальный IP-адрес. Мы go через периоды 5-10 минут за раз несколько раз в день, когда некоторые из этих HTTP-вызовов получают тайм-аут, даже если вызываемый удаленный сервер доступен. В это время windows наступают тайм-ауты и go независимо от того, идет ли HTTP-вызов другим модулям или даже обратно к его собственному локальному IP-адресу.

Чтобы проиллюстрировать проблему, вот файл журнала 3 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 за этот период, взятый из работающего контейнера docker: 

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 (hotspot и openj9), разные HTTP-клиенты в коде Java. Все без изменений. Если мы установим очень большое время ожидания, это не будет иметь значения - пакеты никогда не будут видны в tcpdump.

В кластере k8s используется cilium, и кластер работает нормально. В это время нет проблем с сетью, памятью, процессором. Другие модули в кластере не имеют этой проблемы. Мы видели эту проблему на 2 разных кластерах, настроенных независимо и всегда испытываемых модулями, работающими с этим определенным java микросервисом. Микросервис, работающий вне k8s в простом docker, работает нормально без тайм-аутов.

Дополнительная информация: Java - это jdk 11. Контейнерная ОС - это Ubuntu 18.04. Узлы находятся в AWS EC2 и работают под управлением k8s v1.13.9. Операционная система узла - это контейнер Linux для ядра CoreOS 2345.3.0 (Rhyolite) версии 4.19.106-coreos. Docker is docker: //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

Основа c диаграмма, иллюстрирующая ситуацию: Диаграмма

Куда нам вообще начать смотреть и какие-либо подсказки, что может вызвать это?

...