Katib: random-example cannot work

[yeya24]

/kind bug

What steps did you take and what happened:
[A clear and concise description of what the bug is.]

In katib web ui, I submitted https://github.com/kubeflow/katib/blob/7443f02c21/examples/v1alpha3/random-example.yaml as an experiment.

What did you expect to happen:
This example works well.

Anything else you would like to add:
[Miscellaneous information that will assist in solving the issue.]
In each trial, the pod panic.

Error logs of each trial pod:

I1130 23:53:52.422917      18 main.go:78] INFO:root:Epoch[19] Train-accuracy=0.122044
I1130 23:53:52.422934      18 main.go:78] INFO:root:Epoch[19] Time cost=3.282
I1130 23:53:52.550241      18 main.go:78] INFO:root:Epoch[19] Validation-accuracy=0.113854
F1130 23:53:53.003408      18 main.go:94] Failed to wait for worker container: Process 6 hadn't completed: open /var/log/katib/6.pid: no such file or directory
goroutine 1 [running]:
github.com/kubeflow/katib/vendor/k8s.io/klog.stacks(0xc000186100, 0xc000250000, 0xa0, 0x256)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:830 +0xb8
github.com/kubeflow/katib/vendor/k8s.io/klog.(*loggingT).output(0x129ca40, 0xc000000003, 0xc000210000, 0x1236476, 0x7, 0x5e, 0x0)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:781 +0x2d0
github.com/kubeflow/katib/vendor/k8s.io/klog.(*loggingT).printf(0x129ca40, 0x3, 0xc77e24, 0x27, 0xc00008dee8, 0x1, 0x1)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:678 +0x14b
github.com/kubeflow/katib/vendor/k8s.io/klog.Fatalf(...)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:1209
main.main()
    /go/src/github.com/kubeflow/katib/cmd/metricscollector/v1alpha3/file-metricscollector/main.go:94 +0x279

Images I use:

docker images | grep suggestion
gcr.io/kubeflow-images-public/katib/v1alpha3/suggestion-hyperopt      latest               989d1ed70824        5 days ago          1.22GB

All other katib components are using images with tag v0.7.0.

Environment:

• Kubeflow version:
• Minikube version:
• Kubernetes version: (use kubectl version): 1.16.3
• OS (e.g. from /etc/os-release):

[gaocegege]

/cc @hougangliu

[yeya24]

Seems the mutating webhook did not work because I cannot find echo completed in containers' args.

[yeya24]

Oh, I got it. When I use the latest katib controller image, it works. I will close this issue

[janvdvegt]

I have this issue with the v0.8.0 images:

Failed to wait for worker container: Process 15 hadn't completed: open /var/log/katib/15.pid: no such file or directory
goroutine 1 [running]:
github.com/kubeflow/katib/vendor/k8s.io/klog.stacks(0xc000186100, 0xc0001a6000, 0xa2, 0xb2)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:830 +0xb8
github.com/kubeflow/katib/vendor/k8s.io/klog.(*loggingT).output(0x129da40, 0xc000000003, 0xc000169030, 0x12378d6, 0x7, 0x5f, 0x0)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:781 +0x2d0
github.com/kubeflow/katib/vendor/k8s.io/klog.(*loggingT).printf(0x129da40, 0x3, 0xc78f77, 0x27, 0xc000141ed8, 0x1, 0x1)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:678 +0x14b
github.com/kubeflow/katib/vendor/k8s.io/klog.Fatalf(...)
    /go/src/github.com/kubeflow/katib/vendor/k8s.io/klog/klog.go:1209
main.main()
    /go/src/github.com/kubeflow/katib/cmd/metricscollector/v1alpha3/file-metricscollector/main.go:95 +0x279

[andreyvelich]

@janvdvegt Can you describe training job, please?
And in what namespace you run Katib Experiments, are you using Kubeflow Profile controller and Profile namespace?

[janvdvegt]

It's in a custom namespace, we are running it outside of Kubeflow, no Kubeflow Profile or Profile namespace. We have the same setup at another cluster where it doesn't appear to be an issue. Here is a (truncated and masked) definition gotten via get ... -o yaml:

apiVersion: v1
items:
- apiVersion: kubeflow.org/v1alpha3
  kind: Experiment
  metadata:
    annotations:
      dataSnapshotId: t130223257z-ldw80
      experimentId: experiment-7d94c855-uwu12
      workflowId: cbe550c2-124d-4a0a-950d-ba290ab95589
    creationTimestamp: "2020-02-26T13:06:27Z"
    finalizers:
    - update-prometheus-metrics
    generation: 2
    labels:
      controller-tools.k8s.io: "1.0"
    name: experiment-run-workflow-f9ts6
    namespace: XXXX-7o8el
    resourceVersion: "69186919"
    selfLink: /apis/kubeflow.org/v1alpha3/namespaces/XXXX-7o8el/experiments/experiment-run-workflow-f9ts6
    uid: cc6d593c-5898-11ea-b114-02daed885962
  spec:
    algorithm:
      algorithmName: bayesianoptimization
      algorithmSettings: null
    maxFailedTrialCount: 1
    maxTrialCount: 2
    metricsCollectorSpec:
      collector:
        kind: StdOut
    objective:
      additionalMetricNames:
      - accuracy
      - auc
      - log_loss
      - precision
      - recall
      goal: 1000000
      objectiveMetricName: f1_score
      type: maximize
    parallelTrialCount: 2
    parameters:
    - feasibleSpace:
        max: "20"
        min: "10"
      name: max_depth
      parameterType: int
    - feasibleSpace:
        max: "10"
        min: "2"
      name: min_samples_split
      parameterType: int
    - feasibleSpace:
        max: "4"
        min: "2"
      name: max_features
      parameterType: int
    - feasibleSpace:
        list:
        - gini
        - entropy
      name: criterion
      parameterType: categorical
    trialTemplate:
      goTemplate:
        rawTemplate: |
          apiVersion: batch/v1
          kind: Job
          metadata:
            name: '{{.Trial}}'
            namespace: '{{.NameSpace}}'
          spec:
            backoffLimit: 0
            template:
              spec:
                nodeSelector:
                  name: m5large
                tolerations:
                  - key: dedicated
                    operator: Equal
                    value: m5large
                    effect: NoSchedule
                restartPolicy: Never
                volumes:
                  - name: dataset-artifact
                    emptyDir: {}
                imagePullSecrets:
                  - name: dynamic-registry-pull
                initContainers:
                  - name: load-data-init-container
                    image: 'XXXX'
                    imagePullPolicy: IfNotPresent
                    volumeMounts:
                      - name: dataset-artifact
                        mountPath: /usr/src/data
                    command:
                      - python
                      - '-u'
                      - /usr/src/download.py
                    resources:
                      limits:
                        memory: 8192Mi
                        cpu: 2000m
                      requests:
                        memory: 4178Mi
                        cpu: 1730m
                    env:
                      - name: DOWNLOAD_FILES
                        value: '{"bucket":"XXXX","files":[{"s3Path":"snapshots/t130223257z-ldw80/training-set/training-set.pkl","targetPath":"/usr/src/data","targetFilename":"","archived":true}]}'
                containers:
                  - name: '{{ .Trial }}'
                    image: 'XXXX'
                    metadata:
                      annotations:
                        experimentId: experiment-7d94c855-uwu12
                        workflowId: cbe550c2-124d-4a0a-950d-ba290ab95589
                        dataSnapshotId: t130223257z-ldw80
                    resources:
                      limits:
                        memory: 8192Mi
                        cpu: 2000m
                      requests:
                        memory: 4178Mi
                        cpu: 1730m
                    volumeMounts:
                      - name: dataset-artifact
                        mountPath: /usr/src/data
                    command:
                      - /usr/venv/bin/python
                      - '-u'
                      - /usr/src/train.py
                    env:
                      - name: HYPERPARAMETERS
                        value: '{ {{- with .HyperParameters }}{{- range .}}"{{ .Name }}": "{{ .Value }}", {{- end}}{{- end}} }'
  status:
    conditions:
    - lastTransitionTime: "2020-02-26T13:06:27Z"
      lastUpdateTime: "2020-02-26T13:06:27Z"
      message: Experiment is created
      reason: ExperimentCreated
      status: "True"
      type: Created
    - lastTransitionTime: "2020-02-26T13:06:43Z"
      lastUpdateTime: "2020-02-26T13:06:43Z"
      message: Experiment is running
      reason: ExperimentRunning
      status: "True"
      type: Running
    currentOptimalTrial:
      bestTrialName: ""
      observation:
        metrics: null
      parameterAssignments: null
    failedTrialList:
    - experiment-run-workflow-f9ts6-bkbtl6b8
    runningTrialList:
    - experiment-run-workflow-f9ts6-hs6txws6
    startTime: "2020-02-26T13:06:27Z"
    trials: 2
    trialsFailed: 1
    trialsRunning: 1
kind: List
metadata:
  resourceVersion: ""
  selfLink: ""

The init container finished properly, training is started and the logs are flowing into the metrics collector sidecar and after a while, I get the error.

Sorry, you asked about the training job. Basically, we have an init container that loads the data on a volume and we pass hyperparameters using the ENV variables. I tried with a very small experiment, and that one does work. It looks like it times out for some reason.

[janvdvegt]

It looks like the Python process might be going out of memory, sorry about that.

[andreyvelich]

@janvdvegt So on your training job you can see metrics collector container?
Try to increase resources for your training job, maybe it helps.

[janvdvegt]

Yeah, the metrics collector captures the logs. The problem I had was that the limits were too wide so the Pod didn't get OOMKilled but the node had SystemOOM warnings and SIGKILled the container.