Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use) #4370

Closed
MarkTopping opened this issue Sep 18, 2023 · 10 comments
Labels
bug An issue reporting a potential bug

Comments

@MarkTopping
Copy link

MarkTopping commented Sep 18, 2023

Describe the bug
When ingress controller instances are OOM Killed then the containers fail (indefinatly) to restart. It seems they are unable to bind to a Port and one assumes that's because the port has not been released by the container what was OOM Killed.

Manual intervention in the form of restarting the Pods is required in order to bring the Ingress Controller instances back online.

For added context only... In our case, we think the OOM Kill was the result of an 'nginx config reload' which I believe was triggered on the back of an unrelated deployment auto-scaling and therefore Endpoints being updated. I've checked and I don't think any new Ingress resources were created at the time but obviously if they had been then this would be another reason for the reload.

From our end we are taking remedial steps by increasing the memory available to the Nginx IC pods and by decreasing the number of worker processes. But this only reduces the likelihood of the OOM Kill occurring....

I'm raising this issue because it should be possible for the nginx containers to restart without manual intervention if they are subject to an OOM Kill event.

To Reproduce
Steps to reproduce the behavior:

  1. Deploy Nginx 3.1.1 to an Azure AKS Cluster. Set the memory low enough such that you can cause Nginx to consume more than the limit of the Pod if you throw some load its way.

In our case we had 4 instances of nginx running each with a request/limit of 500Mi. Using a lower number of instances and of memory would make it easier to replicate the issue

  1. See Nginx pods become 'Not Ready'.

  2. View logs for any failing Pod

  3. See error:

init-ingresscontroller-nginx-ingress '/etc/nginx/./conf.d' -> '/mnt/etc/./conf.d'
init-ingresscontroller-nginx-ingress '/etc/nginx/./fastcgi_params' -> '/mnt/etc/./fastcgi_params'
init-ingresscontroller-nginx-ingress '/etc/nginx/./mime.types' -> '/mnt/etc/./mime.types'
init-ingresscontroller-nginx-ingress '/etc/nginx/./modules' -> '/mnt/etc/./modules'
init-ingresscontroller-nginx-ingress '/etc/nginx/./nginx.conf' -> '/mnt/etc/./nginx.conf'
init-ingresscontroller-nginx-ingress '/etc/nginx/./scgi_params' -> '/mnt/etc/./scgi_params'
init-ingresscontroller-nginx-ingress '/etc/nginx/./secrets' -> '/mnt/etc/./secrets'
init-ingresscontroller-nginx-ingress '/etc/nginx/./stream-conf.d' -> '/mnt/etc/./stream-conf.d'
init-ingresscontroller-nginx-ingress '/etc/nginx/./uwsgi_params' -> '/mnt/etc/./uwsgi_params'
ingresscontroller-nginx-ingress NGINX Ingress Controller Version=3.1.1 Commit=72473392d14cb0971de4b916a8db9bb675a16634 Date=2023-05-04T23:50:20Z DirtyState=false Arch=linux/amd64 Go=go1.20.4
ingresscontroller-nginx-ingress I0918 06:50:31.897078       1 flags.go:294] Starting with flags: ["-nginx-plus=false" "-nginx-reload-timeout=60000" "-enable-app-protect=false" "-enable-app-protect-dos=false" "-nginx-configmaps=ingress/
ingresscontroller-nginx-ingress I0918 06:50:31.922072       1 main.go:234] Kubernetes version: 1.26.3
ingresscontroller-nginx-ingress I0918 06:50:31.935332       1 main.go:380] Using nginx version: nginx/1.23.4
ingresscontroller-nginx-ingress I0918 06:50:32.043153       1 main.go:776] Pod label updated: ingresscontroller-nginx-ingress-6d975bd49d-p6xb8
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-502-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-418-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [notice] 18#18: try again to bind() after 500ms
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-502-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-418-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [notice] 18#18: try again to bind() after 500ms
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-502-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-418-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [notice] 18#18: try again to bind() after 500ms
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-502-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-418-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [notice] 18#18: try again to bind() after 500ms
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-config-version.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-502-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: bind() to unix:/var/lib/nginx/nginx-418-server.sock failed (98: Address already in use)
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [notice] 18#18: try again to bind() after 500ms
ingresscontroller-nginx-ingress 2023/09/18 06:50:32 [emerg] 18#18: still could not bind()
Stream closed EOF for ingress/ingresscontroller-nginx-ingress-6d975bd49d-p6xb8 (init-ingresscontroller-nginx-ingress)
  1. Witness that the Pods will be continually restarted but they'll incur the same error over and over. I left one instance running over a weekend during which it went through 700+ restarts and did not come back online.

Expected behavior
I expect that when the nginx ingress controller container is restarted after it has been OOM Killed that it should be able to bind to the port(s) it requires and then start up successfully and without the need of a human having to restart the Pod(s).

Your environment

  • Version of the Ingress Controller - "nginx-ingress:3.1.1"
  • 1.26.3
  • Azure AKS
  • Using NGINX
@github-actions
Copy link

Hi @MarkTopping thanks for reporting!

Be sure to check out the docs and the Contributing Guidelines while you wait for a human to take a look at this 🙂

Cheers!

@jasonwilliams14
Copy link
Contributor

@MarkTopping
Do you have your deployment file available by chance?
Also, do you have some additional NGINX logs (maybe with debugging turned on) that we could review?
If you have some log data that we could review, I would like to see what events are occurring within NIC to find some clues.
Thank you

@MarkTopping
Copy link
Author

@MarkTopping Do you have your deployment file available by chance? Also, do you have some additional NGINX logs (maybe with debugging turned on) that we could review? If you have some log data that we could review, I would like to see what events are occurring within NIC to find some clues. Thank you

Hi Jason,

Thanks for responding.

The deployment manifest:

# Source: nginx-ingress/templates/controller-deployment.yaml
apiVersion: apps/v1
kind: Deployment
metadata:
  name: ingresscontroller-nginx-ingress
  namespace: ingress
  labels:
    helm.sh/chart: nginx-ingress-0.17.1
    app.kubernetes.io/name: ingresscontroller-nginx-ingress
    app.kubernetes.io/instance: ingresscontroller
    app.kubernetes.io/version: "3.1.1"
    app.kubernetes.io/managed-by: Helm
spec:
  replicas: 4
  selector:
    matchLabels:
      app.kubernetes.io/name: ingresscontroller-nginx-ingress
      app.kubernetes.io/instance: ingresscontroller
      app: ingresscontroller-nginx-ingress
  template:
    metadata:
      labels:
        app: ingresscontroller-nginx-ingress
        app.kubernetes.io/name: ingresscontroller-nginx-ingress
        app.kubernetes.io/instance: ingresscontroller
    spec:
      tolerations:
      - effect: NoSchedule
        key: purpose
        operator: Equal
        value: ingress
      volumes:
      - name: nginx-etc
        emptyDir: {}
      - name: nginx-cache
        emptyDir: {}
      - name: nginx-lib
        emptyDir: {}
      - name: nginx-log
        emptyDir: {}
      - csi:
          driver: secrets-store.csi.k8s.io
          readOnly: true
          volumeAttributes:
            secretProviderClass: ingress
        name: default-ingress
      serviceAccountName: ingresscontroller-nginx-ingress
      automountServiceAccountToken: true
      securityContext:
        seccompProfile:
          type: RuntimeDefault
        fsGroup: 101
      terminationGracePeriodSeconds: 300
      hostNetwork: false
      dnsPolicy: ClusterFirst
      containers:
      - image: "[REDACTED]/nginx/nginx-ingress:3.1.1"
        name: ingresscontroller-nginx-ingress
        imagePullPolicy: "Always"
        ports:
        - name: http
          containerPort: 80
        - name: https
          containerPort: 443
        - name: readiness-port
          containerPort: 8081
        readinessProbe:
          httpGet:
            path: /nginx-ready
            port: readiness-port
          periodSeconds: 5
          timeoutSeconds: 10
          initialDelaySeconds: 10
        resources:
          limits:
            cpu: 1000m
            memory: 500Mi
          requests:
            cpu: 500m
            memory: 500Mi
        securityContext:
          allowPrivilegeEscalation: true
          runAsGroup: 2001
          runAsNonRoot: true
          runAsUser: 101
          seccompProfile:
            type: RuntimeDefault
          readOnlyRootFilesystem: true
          capabilities:
            drop:
            - ALL
            add:
            - NET_BIND_SERVICE
        volumeMounts:
        - mountPath: /etc/nginx
          name: nginx-etc
        - mountPath: /var/cache/nginx
          name: nginx-cache
        - mountPath: /var/lib/nginx
          name: nginx-lib
        - mountPath: /var/log/nginx
          name: nginx-log
        - mountPath: /mnt/keyvault
          name: default-ingress
          readOnly: true
        env:
        - name: POD_NAMESPACE
          valueFrom:
            fieldRef:
              fieldPath: metadata.namespace
        - name: POD_NAME
          valueFrom:
            fieldRef:
              fieldPath: metadata.name
        args:
          - -nginx-plus=false
          - -nginx-reload-timeout=60000
          - -enable-app-protect=false
          - -enable-app-protect-dos=false
          - -nginx-configmaps=$(POD_NAMESPACE)/ingresscontroller-nginx-ingress
          - -default-server-tls-secret=ingress/default-tls
          - -ingress-class=nginx
          - -health-status=true
          - -health-status-uri=/nginx-health
          - -nginx-debug=false
          - -v=1
          - -nginx-status=true
          - -nginx-status-port=8080
          - -nginx-status-allow-cidrs=127.0.0.1
          - -report-ingress-status
          - -external-service=ingresscontroller-nginx-ingress
          - -enable-leader-election=true
          - -leader-election-lock-name=ingresscontroller-nginx-ingress-leader-election
          - -enable-prometheus-metrics=false
          - -prometheus-metrics-listen-port=9113
          - -prometheus-tls-secret=
          - -enable-service-insight=false
          - -service-insight-listen-port=9114
          - -service-insight-tls-secret=
          - -enable-custom-resources=false
          - -enable-snippets=true
          - -include-year=false
          - -disable-ipv6=false
          - -ready-status=true
          - -ready-status-port=8081
          - -enable-latency-metrics=false
      initContainers:
      - name: init-ingresscontroller-nginx-ingress
        image: "[REDACTED]/nginx/nginx-ingress:3.1.1"
        imagePullPolicy: "Always"
        command: ['cp', '-vdR', '/etc/nginx/.', '/mnt/etc']
        resources:
          requests:
            cpu: 25m
            memory: 50Mi
          limits:
            cpu: 25m
            memory: 50Mi
        securityContext:
          allowPrivilegeEscalation: false
          readOnlyRootFilesystem: true
          runAsUser: 101
          runAsNonRoot: true
          capabilities:
            drop:
            - ALL
        volumeMounts:
        - mountPath: /mnt/etc
          name: nginx-etc
  minReadySeconds: 15

However I'm afraid I don't have additional log data. We chose not to scrape them and this isn't something I can happily replicate without causing reasonable disruption.

In case this should happen again though and I have an opportunity to look for more logs what would you be after and where would I find them? I provided the container logs but I'm assuming you mean other logs from an additional source?

During my investigation I inspected traffic logs for applications which Nginx fronts and the nginx controller was under load at the time. Additionally services which it fronts were undergoing scaling (via HPA). You mentioned NIC logs... I need some clarification there - do you mean traffic logs for the NIC on the underlying VM?

I should note that I've since made two changes to the deployment which differ from what I've pasted above... we've set CPU Request == CPU Limit == 1000m and also tripled the Memory. From my end this should greatly reduce the likelihood of reoccurrence but obviously that doesn't negate the fact that we've stumped upon a bug/issue - hence the ticket

@haywoodsh haywoodsh self-assigned this Sep 25, 2023
@haywoodsh
Copy link
Contributor

Hi @MarkTopping, for the issue of unrelated deployments triggering reload, we have included a fix in the latest release to stop watching some unrelated resources https://github.com/nginxinc/kubernetes-ingress/releases/tag/v3.3.0 Can you let me know if it reduces the resource the ingress controller consumes in your cluster?

As for the port binding error, I have only managed to get the pod killed under extreme resource limit, and then it restarted and worked properly as the resources freed up. Can you give me more information on how to reproduce the port binding error?

@jjngx jjngx added the bug An issue reporting a potential bug label Oct 10, 2023
@shaun-nx
Copy link
Contributor

HI @MarkTopping I hope you're doing well.
We've made some new discoveries around this issue that we wanted to share with you.

We do see that in your deployment manifest you have readOnlyRootFileSystem: true
When deploying the Ingress Controller with this setting, we provide volumes and volumeMounts in our Deployment manifests for directories that NGINX still needs to write to (e.g. /var/lib/nginx)

In our testing we saw that, for example, files in /var/lib/nginx persist when the container exists in this way as the files in the volume for /var/lib/nginx are tied to the lifecycle of the Pod and not the container.

As @haywoodsh mentioned, we have provided an update to release v3.3.0 that should prevent the Ingress Controller from encountering an OOM kill in the way you describe.

@MarkTopping
Copy link
Author

Thanks for your responses @shaun-nx and @haywoodsh; and my apologies for not responding sooner @haywoodsh - honestly it slipped my mind.

Good news that you've found a potential fix.

We've rolled out version 3.3.0 into all non-prod environments and shall progress into production next week I expect.

At my end, since I made the changes to a) increase the resources, and b) reduce the number of worker services we've not seen the issue re-occur even on the old version (3.1.1). Alas it's going to be very difficult to know whether or not your fix actually remediates the issue without reverting our other changes and trying to force an OOMKill. If I find myself with time to spare I'll give it a go.

Thank you once again for your attention

@shaun-nx
Copy link
Contributor

shaun-nx commented Nov 3, 2023

Hi @MarkTopping

I've opened a new issue which specifically talks about the behaviour of NGINX when it exists this way: #4604

We'd like to close this issue for now as the change in 3.3.0 provides measures to prevent NGINX from experiencing and OOM kill in the way you described, and use the above issue to track progress around the specific behaviour of NGINX.

@MarkTopping
Copy link
Author

Untested but hopefully remediated as per shaun-nx's comments. thank you

@shaun-nx
Copy link
Contributor

@MarkTopping this bug has been fixed now in #7121
It'll be fully available in our next release. In the mean time, please feel free to build an image from edge if you want to confirm the fix works as expected for you :)

@MarkTopping
Copy link
Author

Thank you very much for notifying me!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An issue reporting a potential bug
Projects
None yet
Development

No branches or pull requests

5 participants