Uploaded image for project: 'OpenShift Bugs'
  1. OpenShift Bugs
  2. OCPBUGS-31334

Ipv6/Disconnected Upgade fails: "Error: finalizing"

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Undefined Undefined
    • None
    • 4.15.z
    • LCA operator
    • None
    • Quality / Stability / Reliability
    • False
    • Hide

      None

      Show
      None
    • None
    • None
    • No
    • None
    • None
    • None
    • None
    • None
    • None
    • None
    • None
    • None
    • None
    • None

      Steps to reproduce.

      Attempted upgrade on an ipv6/disconnected setup.

      Result.
      The prep succeeded but after pivot the cluster doesn't come up.
      Crio isn't running.
      Podman shows:

       podman ps -a
      CONTAINER ID  IMAGE                                                                                                                   COMMAND               CREATED      STATUS                  PORTS       NAMES
      a6ff48567ce4  quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:cd0e11d2f239dcd6fed038e52ad60d173b1b965aab01ae43cded91e17a5f56af  --name editor --d...  4 hours ago  Exited (0) 4 hours ago              recert_etcd
      
      

      Looking at the node for errors. Seeing the following in journalctl:

      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:58.262361Z","caller":"embed/config.go:683","msg":"Running http and grpc server on single port. This is not recommended for production."}                 
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.265039Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--name","editor","--data-dir","/store"]}                                    
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.265067Z","caller":"etcdmain/etcd.go:100","msg":"failed to detect default host","error":"could not find default route"}                                
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.265172Z","caller":"etcdmain/etcd.go:116","msg":"server has been already initialized","data-dir":"/store","dir-type":"member"}                         
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:58.265196Z","caller":"embed/config.go:683","msg":"Running http and grpc server on single port. This is not recommended for production."}                 
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.265206Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]}                                
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.269074Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["http://localhost:2379"]}                            
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.269509Z","caller":"embed/etcd.go:309","msg":"starting an etcd server","etcd-version":"3.5.12","git-sha":"GitNotFound","go-version":"go1.19.13 X:stric>
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:58.269585Z","caller":"fileutil/fileutil.go:53","msg":"check file permission","error":"directory \"/store\" exist, but the permission is \"drwxr-xr-x\". >
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:58.272511Z","caller":"fileutil/fileutil.go:53","msg":"check file permission","error":"directory \"/store/member/snap\" exist, but the permission is \"dr>
      Mar 22 17:48:58 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:58.348129Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/store/member/snap/db","took":"75.144761ms"}                           
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.007746Z","caller":"etcdserver/server.go:514","msg":"recovered v2 store from snapshot","snapshot-index":30153,"snapshot-size":"8.1 kB"}                
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.007968Z","caller":"etcdserver/server.go:527","msg":"recovered v3 backend from snapshot","backend-size-bytes":82894848,"backend-size":"83 MB","backend>
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.353379Z","caller":"etcdserver/raft.go:530","msg":"restarting local member","cluster-id":"754d740f26a128db","local-member-id":"a89e1a3e27709607","comm$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.353649Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 switched to configuration voters=(12150177698944161287)"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.353715Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 became follower at term 5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.353733Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft a89e1a3e27709607 [peers: [a89e1a3e27709607], term: 5, commit: 31100, app$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.353947Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.354227Z","caller":"membership/cluster.go:280","msg":"recovered/added member from store","cluster-id":"754d740f26a128db","local-member-id":"a89e1a3e27$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.354255Z","caller":"membership/cluster.go:290","msg":"set cluster version from store","cluster-version":"3.5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:59.354328Z","caller":"fileutil/fileutil.go:53","msg":"check file permission","error":"directory \"/store/member\" exist, but the permission is \"drwxr-x$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"warn","ts":"2024-03-22T17:48:59.356192Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.357062Z","caller":"mvcc/kvstore.go:341","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev",$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.41853Z","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":29262}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.419653Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.420461Z","caller":"etcdserver/server.go:860","msg":"starting etcd server","local-member-id":"a89e1a3e27709607","local-server-version":"3.5.12","clust$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.420672Z","caller":"etcdserver/server.go:753","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"a89e1a3e27709607","for$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.420942Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/store/member/snap","suffix":"snap.db","max":5,"interval":"30s"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.421034Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/store/member/snap","suffix":"snap","max":5,"interval":"30s"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.421043Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/store/member/wal","suffix":"wal","max":5,"interval":"30s"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.422257Z","caller":"embed/etcd.go:599","msg":"serving peer traffic","address":"127.0.0.1:2380"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.422245Z","caller":"embed/etcd.go:278","msg":"now serving peer/client/metrics","local-member-id":"a89e1a3e27709607","initial-advertise-peer-urls":["ht$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.422287Z","caller":"embed/etcd.go:571","msg":"cmux::serve","address":"127.0.0.1:2380"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455187Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 is starting a new election at term 5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455314Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 became pre-candidate at term 5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455361Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 received MsgPreVoteResp from a89e1a3e27709607 at term 5"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455394Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 became candidate at term 6"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455405Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 received MsgVoteResp from a89e1a3e27709607 at term 6"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455419Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a89e1a3e27709607 became leader at term 6"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.455432Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: a89e1a3e27709607 elected leader a89e1a3e27709607 at term 6"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.457102Z","caller":"etcdserver/server.go:2077","msg":"published local member to cluster through raft","local-member-id":"a89e1a3e27709607","local-memb$
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.457138Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.457352Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.457457Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"}
      Mar 22 17:48:59 target-0-0 recert_etcd[1567]: {"level":"info","ts":"2024-03-22T17:48:59.460077Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.$
      Mar 22 17:49:21 target-0-0 recert[1659]: Error: finalizing                                 
      Mar 22 17:49:21 target-0-0 recert[1659]:                                                   
      Mar 22 17:49:21 target-0-0 recert[1659]: Caused by:                                        
      Mar 22 17:49:21 target-0-0 recert[1659]:     0: performing ocp specific post-processing    
      Mar 22 17:49:21 target-0-0 recert[1659]:     1: renaming IP                                
      Mar 22 17:49:21 target-0-0 recert[1659]:     2: renaming all                               
      Mar 22 17:49:21 target-0-0 recert[1659]:     3: renaming etcd resources                    
      Mar 22 17:49:21 target-0-0 recert[1659]:     4: fixing oauth apiserver deployment          
      Mar 22 17:49:21 target-0-0 recert[1659]:     5: name not found  
      

              jche@redhat.com Jun Chen
              achuzhoy@redhat.com Alexander Chuzhoy
              None
              None
              Alexander Chuzhoy Alexander Chuzhoy
              None
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Created:
                Updated: