skaffold dev does not show live tail logs after running for a while

[jonog94]

Expected behavior

running skaffold dev should live tail logs after running for a while

Actual behavior

After multiple image rebuilds and changes to source code, I don't get live logs when the server receives HTTP requests.

Information

• Skaffold version: 0b8bd59
• Operating system: macOS Catalina - version 10.15.5
• Contents of skaffold.yaml:

apiVersion: skaffold/v2alpha1
kind: Config
build:
  local:
    push: false
  artifacts:
    - image: jon/kludge-client
      context: client
      sync:
        manual:
          - src: 'src/**/*.tsx'
            dest: '/usr/src/app'
          - src: 'src/**/**/*.tsx'
            dest: '/usr/src/app'
          - src: 'src/**/**/*.ts'
            dest: '/usr/src/app'
          - src: 'src/**/**/*.js'
            dest: '/usr/src/app'
          - src: 'src/**/**/*.scss'
            dest: '/usr/src/app'
          - src: '*.js'
            dest: '/usr/src/app'
      docker:
        dockerfile: Dockerfile
        buildArgs: 
          network: host
    - image: jon/kludge-api
      context: api
      sync:
        manual:
          - src: 'resources/views/*.php'
            dest: '/var/www/api'
          - src: 'app/Models/*.php'
            dest: '/var/www/api'
          - src: 'app/Http/Controllers/*.php'
            dest: '/var/www/api'
          - src: 'app/Http/Controllers/**/*.php'
            dest: '/var/www/api'
          - src: 'app/Abstracts/Repository/*.php'
            dest: '/var/www/api'
          - src: 'app/Repository/**/*.php'
            dest: '/var/www/api'
          - src: 'app/Services/*.php'
            dest: '/var/www/api'
          - src: 'app/Rules/*.php'
            dest: '/var/www/api'
          - src: 'app/Http/Middleware/*.php'
            dest: '/var/www/api'
          - src: 'app/Http/Requests/**/*.php'
            dest: '/var/www/api'
          - src: 'routes/*.php'
            dest: '/var/www/api'
          - src: 'database/**/*.php'
            dest: '/var/www/api'
          - src: 'config/*.php'
            dest: '/var/www/api'
          - src: 'app/Compiler/Languages/**/*'
            dest: '/var/www/api'
          - src: 'app/Examples/*.php'
            dest: '/var/www/api'
          - src: 'app/Examples/**/**/*'
            dest: '/var/www/api'
          - src: 'app/Providers/*.php'
            dest: '/var/www/api'
      docker:
        dockerfile: Dockerfile
deploy:
  kubectl:
    manifests:
      - k8-dev/client/deployment-manifest.yaml
      - k8-dev/api/deployment-manifest.yaml
      - k8-dev/client/service-manifest.yaml
      - k8-dev/api/service-manifest.yaml

Here's the k8 deployment for the pod that does not live tail

apiVersion: apps/v1
kind: Deployment
metadata:
  name: api
  namespace: kludge
spec:
  replicas: 1
  selector:
    matchLabels:
      name: api
  template:
    metadata:
      labels:
        name: api
      namespace: kludge
    spec:
      containers:
        - image: jon/kludge-api
          name: api
          ports:
            - containerPort: 80
          imagePullPolicy: Never
          env:
            - name: APP_NAME
              value: "api"
            - name: APP_ENV
              value: "local"
            - name: APP_DEBUG
              value: "true"
            - name: APP_LOG_LEVEL
              value: "debug"
            - name: APP_URL
              value: "http://kludge.info"
            - name: LOG_CHANNEL
              value: "stack"
            - name: DB_CONNECTION
              value: "mysql"
            - name: DB_HOST
              value: "mysql"
            - name: DB_DATABASE
              value: "kludgedb"
            - name: DB_USERNAME
              value: "kludgedbuser"
            - name: DB_PASSWORD
              value: "secret"

Steps to reproduce the behavior

Running skaffold dev but usually after 2 days or so live tail logs does not work, but the cluster is still running and everything else works.

[jonog94]

Is there a specific amount of time until log tailing stops working? Like a timeout that gets set? It seems like it's 10 hours or so from me until my pods don't redirect stdout to terminal.

[gsquared94]

Thanks for reporting this. I did a quick scan of our code and didn't see anything that would look like us setting any timeouts or deadline on contexts for log tailing. Can you rerun skaffold dev -v DEBUG --tail and see if there's anything obvious in the logs? Otherwise if you can, share them with us. Otherwise share a small project that can repro this behavior.

[gsquared94]

The pod watcher timeout is set to 100 yrs (watcher.go)

var forever int64 = 3600 * 24 * 365 * 100

[jonog94]

Thanks @gsquared94 I will run it with that command. I realised that when skaffold rebuilds the image, log tailing starts working again. It just seems that when it's the same running pod (for over 10 hours) the log streaming does not show. It's hard to determine if the issue is my OS, Minikube or skaffold but I thought I'd start here.

[jonog94]

Running in debug mode shows me that the underlying command is kubectl --context minikube logs --since=3s -f api-66fdc779d4-b992n -c api --namespace kludge when it sets up the log streaming.

When I ran this command individually it ran for 10 hrs before disconnecting (no message was given after dc). I still don't know what causes the underlying issue. Based on my research it could be the following:

1. Apparently log rotation disconnects log streaming (log rotation on node breaks kubectl logs --follow / docker logs --follow kubernetes/kubernetes#28369). I'm not sure though if it's something that's being done by default in a minikube environment.

2. There still could be something that skaffold does that interrupts log streaming as I had skaffold running in the background. Maybe it could be a non related rebuild from a mutually exclusive pod that interrupts the log stream.

3. I have an nginx ingress controller running but based on very different disconnect times I don't think it's a timeout issue coming from this end.

4. Could just be my operating system, I'm always using 14/16g's of ram, maybe it disconnects long running processes? Although I don't know enough about this to conclude anything.

[jonog94]

@gsquared94 I've posted an issue to kubernetes here kubernetes/kubernetes#93819

Log streams get closed off eventually, should skaffold have a way of reconnecting dropped connections?

[nkubala]

we'd want to be careful that we can distinguish between a preliminary failure when first attaching the logger vs. a timeout later on, but I think it would be relatively straightforward to have an "error watcher" that lives inside the pod watcher, and kicks off a retry loop whenever it sees recurring failures from kubectl.

probably not something our team will prioritize in the near term, but contributions would be welcome!