Uploaded image for project: 'OpenShift Virtualization'
  1. OpenShift Virtualization
  2. CNV-59991

virt-controller excessive info-level logging during migrations

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Normal Normal
    • CNV v4.21.0
    • CNV v4.99.0
    • CNV Virt-Node
    • None
    • Quality / Stability / Reliability
    • 0.42
    • False
    • Hide

      None

      Show
      None
    • False
    • None
    • Low
    • None

      Description of problem:

      virt-controller has excessive logging during migrations

      Version-Release number of selected component (if applicable):

      4.99 (IIB:947297)

      Steps to Reproduce:

      1. Run large number of migrations (2000 tested)
      

      Actual results:

      {"component":"virt-controller","level":"info","msg":"reenqueuing Migration default/kubevirt-migrate-vm-gq27g","pos":"migration.go:257","reason":"Operation cannot be fulfilled on virtualmachineinstancemigrations.kubevirt.io \"kubevirt-migra
      te-vm-gq27g\": the object has been modified; please apply your changes to the latest version and try again","timestamp":"2025-04-15T11:48:09.902700Z"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing VirtualMachineInstance default/vm-instancetype-cirros-test-1701","pos":"vmi.go:243","reason":"patching of vmi conditions and activePods failed: the server rejected our reques
      t due to an error in our request","timestamp":"2025-04-15T11:48:09.917588Z"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing VirtualMachineInstance default/vm-instancetype-cirros-test-1849","pos":"vmi.go:243","reason":"patching of vmi conditions and activePods failed: the server rejected our reques
      t due to an error in our request","timestamp":"2025-04-15T11:48:09.918970Z"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Created migration target pod default/virt-launcher-vm-instancetype-cirros-test-1665-hxsns with uuid a725eed6-84cc-407b-9ac1-064da43278ab for migration kubevirt-migrate-vm-b4j8x
       with uuid 0911ce53-5d74-45de-b1d9-7b99691607ca","name":"vm-instancetype-cirros-test-1665","namespace":"default","pos":"migration.go:810","timestamp":"2025-04-15T11:48:09.941910Z","uid":"f72202fd-f9d1-4abb-b153-6d0e0418c010"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing VirtualMachineInstance default/vm-instancetype-cirros-test-1849","pos":"vmi.go:243","reason":"patching of vmi conditions and activePods failed: the server rejected our reques
      t due to an error in our request","timestamp":"2025-04-15T11:48:09.947153Z"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing VirtualMachineInstance default/vm-instancetype-cirros-test-1665","pos":"vmi.go:243","reason":"patching of vmi conditions and activePods failed: the server rejected our reques
      t due to an error in our request","timestamp":"2025-04-15T11:48:09.970529Z"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Created migration target pod default/virt-launcher-vm-instancetype-cirros-test-1237-66jvz with uuid 822e1150-d0ab-4f80-b607-413169596975 for migration kubevirt-migrate-vm-gq5kr
       with uuid f7de78cc-e506-4863-ab65-04aa2d13dc04","name":"vm-instancetype-cirros-test-1237","namespace":"default","pos":"migration.go:810","timestamp":"2025-04-15T11:48:09.992756Z","uid":"7d945237-763a-4a87-be2c-c578db311ad5"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing Migration default/kubevirt-migrate-vm-gq5kr","pos":"migration.go:257","reason":"Operation cannot be fulfilled on virtualmachineinstancemigrations.kubevirt.io \"kubevirt-migra
      te-vm-gq5kr\": the object has been modified; please apply your changes to the latest version and try again","timestamp":"2025-04-15T11:48:10.006649Z"}
      {"component":"virt-controller","level":"info","msg":"reenqueuing VirtualMachineInstance default/vm-instancetype-cirros-test-1237","pos":"vmi.go:243","reason":"patching of vmi conditions and activePods failed: the server rejected our reques
      t due to an error in our request","timestamp":"2025-04-15T11:48:10.023766Z"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1263] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-cn9bd","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:10.032564Z","uid":"f7880a5d-bcd5-4fdd-a0e0-86dde571b46e"}
      {"component":"virt-controller","kind":"","level":"info","msg":"shrinking pdb default/kubevirt-disruption-budget-drh4g due to migration completion","name":"vm-instancetype-cirros-test-1579","namespace":"default","pos":"disruptionbudget.go:5
      52","timestamp":"2025-04-15T11:48:10.506414Z","uid":"d0c43b21-f359-450b-8e4f-07894295b513"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0980] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-4r9bc","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:10.721880Z","uid":"af4bf173-d1e5-41c1-b219-0036ca6c9176"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0156] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-4g9bz","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:10.939447Z","uid":"9e70b5b3-0c76-4079-845d-98a3d113b26f"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0421] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-w65bb","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.002676Z","uid":"afca3298-2770-493d-9bd2-620a0d818d28"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1142] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-trp42","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.196517Z","uid":"63e89f3a-a804-43c0-8ee0-f71d7cf5d6a3"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1647] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-pk2wn","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.350011Z","uid":"418fce91-cc46-4e24-8b75-8e121c84d4cb"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0733] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-p5jh7","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.684762Z","uid":"c127944d-61fe-4d0d-8509-960b74737b30"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1992] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-6nwrp","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.738199Z","uid":"7ee91ffb-2840-4db4-80a2-ec1317b76a42"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0946] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-l7lrq","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.830265Z","uid":"de2ffa40-b7aa-42a2-88c9-34cb74657747"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1369] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-zsgbc","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:11.990504Z","uid":"7f84f062-3a67-4eb9-b9b8-763222f1c26d"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1825] migration because total running parallel migration count [5] is currently at the global cluste
      r limit.","name":"kubevirt-migrate-vm-l98qn","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:12.167095Z","uid":"9f6a7e06-6a2a-4060-980b-0ee33169478e"}
      {"component":"virt-controller","kind":"","level":"info","msg":"shrinking pdb default/kubevirt-disruption-budget-pxjrg due to migration completion","name":"vm-instancetype-cirros-test-1131","namespace":"default","pos":"disruptionbudget.go:552","timestamp":"2025-04-15T11:48:12.672638Z","uid":"f953fcd1-c217-457a-888b-9f34c8e42f91"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1791] migration because total running parallel migration count [5] is currently at the global cluster limit.","name":"kubevirt-migrate-vm-9p8dj","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:12.817477Z","uid":"54a2ecdf-c408-412f-93db-402d64cc5be2"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1015] migration because total running parallel migration count [5] is currently at the global cluster limit.","name":"kubevirt-migrate-vm-7bp8l","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:12.922730Z","uid":"d580694b-57e3-4fa1-a336-4f9fa07326b7"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-0460] migration because total running parallel migration count [5] is currently at the global cluster limit.","name":"kubevirt-migrate-vm-bb4j7","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:13.031309Z","uid":"af36dc11-da50-44cd-9088-6f0c4ee1725a"}
      {"component":"virt-controller","kind":"","level":"info","msg":"Waiting to schedule target pod for vmi [default/vm-instancetype-cirros-test-1184] migration because total running parallel migration count [5] is currently at the global cluster limit.","name":"kubevirt-migrate-vm-7jmpq","namespace":"default","pos":"migration.go:1104","timestamp":"2025-04-15T11:48:13.089033Z","uid":"82dfdc67-b8e1-4d70-925d-18a1dd195b42"}
      {"component":"virt-controller","kind":"","level":"info","msg":"shrinking pdb default/kubevirt-disruption-budget-pcdht due to migration completion","name":"vm-instancetype-cirros-test-1648","namespace":"default","pos":"disruptionbudget.go:552","timestamp":"2025-04-15T11:48:13.376064Z","uid":"1813bfff-2377-4777-b711-4fa14b8b3ba2"}
      

      Expected results:

      less

      Additional info:

       

              sgott@redhat.com Stuart Gott
              rhn-support-sbennert Sarah Bennert
              Luboslav Pivarc
              Denys Shchedrivyi Denys Shchedrivyi
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated: