Bug 1963880 - Forklift Controller pod restarts 4 times in 22 hours
Summary: Forklift Controller pod restarts 4 times in 22 hours
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Migration Toolkit for Virtualization
Classification: Red Hat
Component: Controller
Version: 2.0.0
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: 2.0.0
Assignee: Jeff Ortel
QA Contact: Tzahi Ashkenazi
Avital Pinnick
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-05-24 10:08 UTC by Tzahi Ashkenazi
Modified: 2021-06-24 20:56 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-06-10 17:12:05 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHEA-2021:2381 0 None None None 2021-06-10 17:12:11 UTC

Description Tzahi Ashkenazi 2021-05-24 10:08:24 UTC
on cloud38 BM :
MTV: 2.0.0.19
CNV: 2.6.3

during 22 hours, the forklift-controller pod was restarted 4 times :
1 x inventory container 
3 x controller container 

root@f02-h07-000-r640:~$ oc get pods -nopenshift-mtv
NAME                                   READY   STATUS    RESTARTS   AGE
forklift-controller-67494db894-vmrvl   2/2     Running   4          22h
forklift-operator-597945c895-nhhvh     1/1     Running   0          22h
forklift-ui-788cf8546f-7ls9p           1/1     Running   0          22h
forklift-validation-755c9bc64-nwnrq    1/1     Running   0          22h
v2v-vmware-6b66864746-c6pcq            1/1     Running   0          21h

oc describe  pods/forklift-controller-67494db894-vmrvl  -nopenshift-mtv


Containers:
  controller:
    Container ID:  cri-o://ddf0c88e06e5236e5e3b06f977a3f1af68afefea894427f5756aa40963b5480b
    Image:         registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    Image ID:      registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    Port:          9876/TCP
    Host Port:     0/TCP
    Command:
      /usr/local/bin/manager
    State:          Running
      Started:      Mon, 24 May 2021 09:00:25 +0000
    Last State:     Terminated
      Reason:       Error
      Exit Code:    2
      Started:      Sun, 23 May 2021 13:51:29 +0000
      Finished:     Mon, 24 May 2021 09:00:24 +0000
    Ready:          True
    Restart Count:  3
    Limits:
      cpu:     500m
      memory:  800Mi
    Requests:
      cpu:     100m
      memory:  350Mi
    Environment Variables from:
      forklift-controller-config  ConfigMap  Optional: false
    Environment:
      POD_NAMESPACE:    openshift-mtv (v1:metadata.namespace)
      ROLE:             main
      API_HOST:         forklift-inventory.openshift-mtv.svc.cluster.local
      API_PORT:         8443
      API_TLS_ENABLED:  true
      SECRET_NAME:      webhook-server-secret
      MAX_VM_INFLIGHT:  50
    Mounts:
      /tmp/cert from cert (ro)
      /var/cache/profiler from profiler (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from forklift-controller-token-qqzpx (ro)
  inventory:
    Container ID:  cri-o://8b7b506f3b3715c836d0ce91d14d15716a4cc84723188d8d21dc8a413dc4526c
    Image:         registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    Image ID:      registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    Port:          8443/TCP
    Host Port:     0/TCP
    Command:
      /usr/local/bin/manager
    State:          Running
      Started:      Sun, 23 May 2021 12:52:10 +0000
    Last State:     Terminated
      Reason:       Error
      Exit Code:    2
      Started:      Sun, 23 May 2021 11:38:53 +0000
      Finished:     Sun, 23 May 2021 12:52:08 +0000
    Ready:          True
    Restart Count:  1
    Limits:
      cpu:     10
      memory:  8Gi
    Requests:
      cpu:     1
      memory:  2Gi
    Environment Variables from:
      forklift-controller-config  ConfigMap  Optional: false
    Environment:
      POD_NAMESPACE:                 openshift-mtv (v1:metadata.namespace)
      ROLE:                          inventory
      SECRET_NAME:                   webhook-server-secret
      API_PORT:                      8443
      API_TLS_ENABLED:               true
      API_TLS_CERTIFICATE:           /var/run/secrets/forklift-inventory-serving-cert/tls.crt
      API_TLS_KEY:                   /var/run/secrets/forklift-inventory-serving-cert/tls.key
      METRICS_PORT:                  8081
      POLICY_AGENT_URL:              https://forklift-validation.openshift-mtv.svc.cluster.local:8181
      POLICY_AGENT_SEARCH_INTERVAL:  120
    Mounts:
      /var/cache/inventory from inventory (rw)
      /var/cache/profiler from profiler (rw)
      /var/run/secrets/forklift-inventory-serving-cert from forklift-inventory-serving-cert (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from forklift-controller-token-qqzpx (to)



oc get  pods/forklift-controller-67494db894-vmrvl  -nopenshift-mtv -oyaml  |less

  - containerID: cri-o://ddf0c88e06e5236e5e3b06f977a3f1af68afefea894427f5756aa40963b5480b
    image: registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    imageID: registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    lastState:
      terminated:
        containerID: cri-o://3c50c96952c5fafbc7bbd0413bdce3ae4fc30e76e0d1807958b086f1d6668023
        exitCode: 2
        finishedAt: "2021-05-24T09:00:24Z"
        reason: Error
        startedAt: "2021-05-23T13:51:29Z"
    name: controller
    ready: true
    restartCount: 3
    started: true
    state:
      running:
        startedAt: "2021-05-24T09:00:25Z"
  - containerID: cri-o://8b7b506f3b3715c836d0ce91d14d15716a4cc84723188d8d21dc8a413dc4526c
    image: registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    imageID: registry.redhat.io/mtv/mtv-controller@sha256:075c4aaba15ff47806b80f742920adcb240b2c61ba97495c358c6df4ab8c27da
    lastState:
      terminated:
        containerID: cri-o://73b200f48ca8130b904c9f5ffe0cc7c93458ddd9c460c40d856d6537f9b8dccf
        exitCode: 2
        finishedAt: "2021-05-23T12:52:08Z"
        reason: Error
        startedAt: "2021-05-23T11:38:53Z"
    name: inventory
    ready: true
    restartCount: 1
    started: true
    state:
      running:
        startedAt: "2021-05-23T12:52:10Z"
  hostIP: 192.168.208.14
  phase: Running
  podIP: 10.128.2.192
  podIPs:
  - ip: 10.128.2.192
  qosClass: Burstable
  startTime: "2021-05-23T11:38:50Z"


the inventory  and the controller containers  full logs can be found :

https://drive.google.com/drive/folders/1ieWEO0WQl3mvYJOVmgpBh4qCFHFtfkia?usp=sharing




seems like its related that there are a lot of ERRORS messages om the inventory container ( with two VMware providers 5.6 & 6.7 )



{"level":"info","ts":1621853374.3508742,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1332 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:1.493254022s,Concerns:[]"}
{"level":"info","ts":1621853374.355132,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-4233 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:1.491640968s,Concerns:[]"}
{"level":"info","ts":1621853374.3556187,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-855 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:1.499125131s,Concerns:[]"}
{"level":"info","ts":1621853374.355652,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1062 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:1.498927905s,Concerns:[]"}
{"level":"info","ts":1621853374.3556619,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1483 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:1.497614562s,Concerns:[]"}
{"level":"info","ts":1621853374.365808,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1433 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:411.421355ms,Concerns:[]"}
{"level":"info","ts":1621853374.7631204,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1063 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:390.370554ms,Concerns:[]"}
{"level":"info","ts":1621853374.8535395,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1415 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:408.63281ms,Concerns:[]"}
{"level":"info","ts":1621853374.8562274,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1307 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:401.709717ms,Concerns:[]"}
{"level":"info","ts":1621853374.8562732,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-6552 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:406.074291ms,Concerns:[]"}
{"level":"info","ts":1621853374.8562853,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1010 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:401.831736ms,Concerns:[]"}
{"level":"info","ts":1621853374.8600519,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-6553 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:429.386127ms,Concerns:[]"}
{"level":"info","ts":1621853374.8601372,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-831 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:402.051761ms,Concerns:[]"}
{"level":"info","ts":1621853374.8601775,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1051 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:411.666514ms,Concerns:[]"}
{"level":"info","ts":1621853374.8602002,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-846 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:415.975746ms,Concerns:[]"}
{"level":"info","ts":1621853374.8618195,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1066 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:497.768758ms,Concerns:[]"}
{"level":"info","ts":1621853375.1916451,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-860 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:434.046574ms,Concerns:[]"}
{"level":"info","ts":1621853375.191697,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1089 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:434.614949ms,Concerns:[]"}
{"level":"info","ts":1621853375.1917045,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1015 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:434.705782ms,Concerns:[]"}
{"level":"info","ts":1621853375.1917915,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-857 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:435.016471ms,Concerns:[]"}
{"level":"info","ts":1621853375.1918004,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-856 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:434.17505ms,Concerns:[]"}
{"level":"info","ts":1621853375.1918273,"logger":"reconciler|vsphere","msg":"[No VM found that matches input parameters]","provider":"openshift-mtv/vmware65"}
{"level":"info","ts":1621853375.1918092,"logger":"reconciler|vsphere","msg":"[No VM found that matches input parameters]","provider":"default/node-05"}
{"level":"info","ts":1621853375.191845,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1048 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:434.168749ms,Concerns:[]"}
{"level":"info","ts":1621853375.2789593,"logger":"reconciler|vsphere","msg":"[No VM found that matches input parameters]","provider":"openshift-mtv/vmware67"}
{"level":"info","ts":1621853375.2790334,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-710 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:435.658872ms,Concerns:[]"}
{"level":"info","ts":1621853375.2790554,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-868 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:502.93809ms,Concerns:[]"}
{"level":"info","ts":1621853375.2790697,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-855 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:413.644499ms,Concerns:[]"}
{"level":"info","ts":1621853375.27908,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1072 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:509.332066ms,Concerns:[]"}
{"level":"info","ts":1621853375.388521,"logger":"reconciler|vsphere","msg":"[No VM found that matches input parameters]","provider":"openshift-mtv/vmware67"}
{"level":"info","ts":1621853375.5632555,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-850 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:371.50534ms,Concerns:[]"}
{"level":"info","ts":1621853375.65457,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-443 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:389.431934ms,Concerns:[]"}
{"level":"info","ts":1621853375.6579058,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1039 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:389.978092ms,Concerns:[]"}
{"level":"info","ts":1621853375.657942,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1413 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:390.37023ms,Concerns:[]"}
{"level":"info","ts":1621853375.6579573,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1461 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:391.064079ms,Concerns:[]"}
{"level":"info","ts":1621853375.659756,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-851 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:391.492234ms,Concerns:[]"}
{"level":"info","ts":1621853375.6614454,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1314 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:461.949084ms,Concerns:[]"}
{"level":"info","ts":1621853375.661481,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-446 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:388.384562ms,Concerns:[]"}
{"level":"info","ts":1621853375.6615157,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1044 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:388.842999ms,Concerns:[]"}
{"level":"info","ts":1621853375.6615286,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1074 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:389.069071ms,Concerns:[]"}
{"level":"info","ts":1621853375.9396513,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-847 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:376.376377ms,Concerns:[]"}
{"level":"info","ts":1621853375.9660277,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-846 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:383.209029ms,Concerns:[]"}
{"level":"info","ts":1621853375.9735816,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1073 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:391.702735ms,Concerns:[]"}
{"level":"info","ts":1621853375.9737675,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-806 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:390.656183ms,Concerns:[]"}
{"level":"info","ts":1621853375.9740431,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1319 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:392.331371ms,Concerns:[]"}
{"level":"info","ts":1621853376.0272973,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-643 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:371.091615ms,Concerns:[]"}
{"level":"info","ts":1621853376.0533187,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-831 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:389.922905ms,Concerns:[]"}
{"level":"info","ts":1621853376.0534253,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1327 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:392.050591ms,Concerns:[]"}
{"level":"info","ts":1621853376.053439,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-444 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:472.104487ms,Concerns:[]"}
{"level":"info","ts":1621853376.0534468,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1460 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:398.071016ms,Concerns:[]"}
{"level":"info","ts":1621853376.3200443,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-1023 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:380.392782ms,Concerns:[]"}
{"level":"info","ts":1621853376.3379114,"logger":"validation|policy","msg":"VM Validation failed.","task":"Ref: id:vm-710 name:'' ,Version:0,Error:'[No VM found that matches input parameters]',Duration:371.87457ms,Concerns:[]"}
{"level":"info","ts":1621853376.3380187,"logger":"reconciler|vsphere","msg":"[No VM found that matches input parameters]","provider":"openshift-mtv/vmware65"}

Comment 2 Fabien Dupont 2021-05-27 10:03:33 UTC
Please try with build 2.0.0-20 / iib:77891.

Comment 3 mlehrer 2021-05-31 16:44:09 UTC
Verified with  2.0.0-20, no restarts of the controller over several days, original issue showed restarts within 22 hours of 4 times.
Moving to verified.

$ oc get pods -nopenshift-mtv
NAME                                   READY   STATUS    RESTARTS   AGE
forklift-controller-7b67c668bb-f7k8g   2/2     Running   0          3d19h
forklift-operator-86d5968bdf-bpqxf     1/1     Running   0          3d20h
forklift-ui-5d4747cc6b-kjqrq           1/1     Running   0          3d20h
forklift-validation-7995b6fdc8-h66jm   1/1     Running   0          3d20h

Comment 6 errata-xmlrpc 2021-06-10 17:12:05 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (MTV 2.0.0 images), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2021:2381


Note You need to log in before you can comment on or make changes to this bug.