search

ovn-kubernetes / ovn-kubernetes

A robust Kubernetes networking platform
https://ovn-kubernetes.io/
Apache License 2.0
838 stars 349 forks source link

EgressIP Test "should not do anyting for user defined status updates" is broken #3028

Closed tssurya closed 8 months ago

tssurya commented 2 years ago

spoke to @kyrtapz and @flavio-fernandes already, this is regarding: https://github.com/ovn-org/ovn-kubernetes/pull/3008#issuecomment-1149537762 We think this never worked properly OR we regressed :)

tssurya commented 2 years ago

/assign @kyrtapz

flavio-fernandes commented 2 years ago 

OVN master EgressIP Operationson EgressIP UPDATE
should not do anyting for user defined status updates
/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/egressip_test.go:2736
I0608 06:39:08.208347   19414 reflector.go:219] Starting reflector *v1.Node (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.208453   19414 reflector.go:255] Listing and watching *v1.Node from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.209991   19414 reflector.go:219] Starting reflector *v1.Pod (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.210102   19414 reflector.go:255] Listing and watching *v1.Pod from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.210653   19414 reflector.go:219] Starting reflector *v1.NetworkPolicy (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.210773   19414 reflector.go:255] Listing and watching *v1.NetworkPolicy from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.211863   19414 reflector.go:219] Starting reflector *v1.Service (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.211959   19414 reflector.go:255] Listing and watching *v1.Service from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.212370   19414 reflector.go:219] Starting reflector *v1.Endpoints (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.212477   19414 reflector.go:255] Listing and watching *v1.Endpoints from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.214474   19414 reflector.go:219] Starting reflector *v1.Namespace (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.215033   19414 reflector.go:255] Listing and watching *v1.Namespace from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.314951   19414 shared_informer.go:270] caches populated
I0608 06:39:08.315492   19414 shared_informer.go:270] caches populated
I0608 06:39:08.315921   19414 shared_informer.go:270] caches populated
I0608 06:39:08.316333   19414 shared_informer.go:270] caches populated
I0608 06:39:08.316664   19414 shared_informer.go:270] caches populated
I0608 06:39:08.316993   19414 shared_informer.go:270] caches populated
I0608 06:39:08.318733   19414 reflector.go:219] Starting reflector *v1.EgressIP (0s) from pkg/crd/egressip/v1/apis/informers/externalversions/factory.go:117
I0608 06:39:08.318862   19414 reflector.go:255] Listing and watching *v1.EgressIP from pkg/crd/egressip/v1/apis/informers/externalversions/factory.go:117
I0608 06:39:08.418413   19414 shared_informer.go:270] caches populated
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="1806350b-833b-4185-b2b1-c4e2f84fb529" "table"="Database"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="1806350b-833b-4185-b2b1-c4e2f84fb529" "table"="Database" "model"="&{UUID:1806350b-833b-4185-b2b1-c4e2f84fb529 Cid:<nil> Connected:true Index:<nil> Leader:true Model:clustered Name:OVN_Northbound Schema:<nil> Sid:0xc000ef7540}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router" "model"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="d30363e6-033c-4fff-9584-c1731ba553e8" "table"="Logical_Router"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="d30363e6-033c-4fff-9584-c1731ba553e8" "table"="Logical_Router" "model"="&{UUID:d30363e6-033c-4fff-9584-c1731ba553e8 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node1 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router" "model"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="fda9c64e-078f-4532-bbce-426c205e27cb" "table"="Logical_Router_Port"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="fda9c64e-078f-4532-bbce-426c205e27cb" "table"="Logical_Router_Port" "model"="&{UUID:fda9c64e-078f-4532-bbce-426c205e27cb Enabled:<nil> ExternalIDs:map[] GatewayChassis:[] HaChassisGroup:<nil> Ipv6Prefix:[] Ipv6RaConfigs:map[] MAC: Name:rtoj-GR_node2 Networks:[fef0::56/125] Options:map[] Peer:<nil>}"
I0608 06:39:08.557060   19414 client.go:325]  "msg"="trying to connect" "database"="OVN_Northbound" "endpoint"="unix:///tmp/ovsdb-9948b4aa1fa12170fe7894a5d1c10153"
I0608 06:39:08.591643   19414 client.go:781]  "msg"="transacting operations"  "database"="_Server" "operations"="[{Op:select Table:Database Row:map[] Rows:[] Columns:[name model leader sid] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
I0608 06:39:08.594069   19414 client.go:260]  "msg"="successfully connected" "database"="OVN_Northbound" "endpoint"="unix:/tmp/ovsdb-9948b4aa1fa12170fe7894a5d1c10153" "sid"="c3a6c0de"
I0608 06:39:08.597088   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Database" "uuid"="1806350b-833b-4185-b2b1-c4e2f84fb529" 
I0608 06:39:08.597598   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Northbound" "table"="Database" "uuid"="1806350b-833b-4185-b2b1-c4e2f84fb529" "model"="&{UUID:1806350b-833b-4185-b2b1-c4e2f84fb529 Cid:<nil> Connected:true Index:<nil> Leader:true Model:clustered Name:OVN_Northbound Schema:<nil> Sid:0xc0051b0320}"
I0608 06:39:08.606069   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Port" "uuid"="fda9c64e-078f-4532-bbce-426c205e27cb" 
I0608 06:39:08.606620   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Northbound" "table"="Logical_Router_Port" "uuid"="fda9c64e-078f-4532-bbce-426c205e27cb" "model"="&{UUID:fda9c64e-078f-4532-bbce-426c205e27cb Enabled:<nil> ExternalIDs:map[] GatewayChassis:[] HaChassisGroup:<nil> Ipv6Prefix:[] Ipv6RaConfigs:map[] MAC: Name:rtoj-GR_node2 Networks:[fef0::56/125] Options:map[] Peer:<nil>}"
I0608 06:39:08.607183   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" 
I0608 06:39:08.607593   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "model"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.608038   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" 
I0608 06:39:08.608437   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "model"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.608856   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="d30363e6-033c-4fff-9584-c1731ba553e8" 
I0608 06:39:08.609265   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="d30363e6-033c-4fff-9584-c1731ba553e8" "model"="&{UUID:d30363e6-033c-4fff-9584-c1731ba553e8 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node1 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="1fa939f4-65e7-423b-af39-7b7e050a7143" "table"="Database"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="1fa939f4-65e7-423b-af39-7b7e050a7143" "table"="Database" "model"="&{UUID:1fa939f4-65e7-423b-af39-7b7e050a7143 Cid:<nil> Connected:true Index:<nil> Leader:true Model:clustered Name:OVN_Southbound Schema:<nil> Sid:0xc011f238f0}"
I0608 06:39:08.740818   19414 client.go:325]  "msg"="trying to connect" "database"="OVN_Southbound" "endpoint"="unix:///tmp/ovsdb-a1c4f17711380ea1f5eaac3fb4bc96fb"
I0608 06:39:08.770259   19414 client.go:781]  "msg"="transacting operations"  "database"="_Server" "operations"="[{Op:select Table:Database Row:map[] Rows:[] Columns:[name model leader sid] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
I0608 06:39:08.772617   19414 client.go:260]  "msg"="successfully connected" "database"="OVN_Southbound" "endpoint"="unix:/tmp/ovsdb-a1c4f17711380ea1f5eaac3fb4bc96fb" "sid"="b960898f"
I0608 06:39:08.775318   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Southbound" "table"="Database" "uuid"="1fa939f4-65e7-423b-af39-7b7e050a7143" 
I0608 06:39:08.775613   19414 cache.go:658] cache "msg"="creating row" "database"="OVN_Southbound" "table"="Database" "uuid"="1fa939f4-65e7-423b-af39-7b7e050a7143" "model"="&{UUID:1fa939f4-65e7-423b-af39-7b7e050a7143 Cid:<nil> Connected:true Index:<nil> Leader:true Model:clustered Name:OVN_Southbound Schema:<nil> Sid:0xc011627bd0}"
I0608 06:39:08.779729   19414 services_controller.go:57] Creating event broadcaster
I0608 06:39:08.780813   19414 services_controller.go:72] Setting up event handlers for services
I0608 06:39:08.780962   19414 services_controller.go:82] Setting up event handlers for endpoint slices
I0608 06:39:08.781203   19414 port_cache.go:56] port-cache(egressip-namespace_egress-pod): added port &{name:egressip-namespace_egress-pod uuid: logicalSwitch: ips:[0xc013514c00] mac:[] expires:{wall:0 ext:0 loc:<nil>}} with IP: [ae70::66/23] and MAC: 
I0608 06:39:08.782953   19414 obj_retry.go:1327] Add event received for resource *factory.egressIPNamespace, key=egressip-namespace
I0608 06:39:08.783432   19414 obj_retry.go:1364] Creating *factory.egressIPNamespace egressip-namespace took: 135.902µs
I0608 06:39:08.783648   19414 factory.go:490] Added *v1.Namespace event handler 1
I0608 06:39:08.785204   19414 obj_retry.go:1327] Add event received for resource *factory.egressIPPod, key=egressip-namespace/egress-pod
I0608 06:39:08.785601   19414 obj_retry.go:1364] Creating *factory.egressIPPod egressip-namespace/egress-pod took: 205.802µs
I0608 06:39:08.785893   19414 factory.go:490] Added *v1.Pod event handler 2
I0608 06:39:08.786323   19414 egressip.go:1219] syncStaleEgressReroutePolicy will remove stale nexthops: []
I0608 06:39:08.786530   19414 factory.go:490] Added *v1.EgressIP event handler 3
I0608 06:39:08.787250   19414 obj_retry.go:1327] Add event received for resource *v1.EgressIP, key=egressip
I0608 06:39:08.788060   19414 egressip.go:1421] Current assignments are: map[::feff:c0a8:8e1e:{Node:node1 Name:bogus2} ::feff:c0a8:8e23:{Node:node2 Name:bogus3} ::feff:c0a8:8e32:{Node:node1 Name:bogus1}]
I0608 06:39:08.788167   19414 egressip.go:1423] Will attempt assignment for egress IP: ::feff:c0a8:8e0d
I0608 06:39:08.788432   19414 egressip.go:1463] Attempting assignment on egress node: &{egressIPConfig:0xc011edc1e0 mgmtIPs:[] allocations:map[::feff:c0a8:8e23:bogus3] isReady:true isReachable:true isEgressAssignable:true name:node2}
I0608 06:39:08.788660   19414 egressip.go:1492] Successful assignment of egress IP: ::feff:c0a8:8e0d on node: &{egressIPConfig:0xc011edc1e0 mgmtIPs:[] allocations:map[::feff:c0a8:8e23:bogus3] isReady:true isReachable:true isEgressAssignable:true name:node2}
I0608 06:39:08.789243   19414 egressip.go:1023] Adding pod egress IP status: {node2 ::feff:c0a8:8e0d} for EgressIP: egressip and pod: egress-pod/egressip-namespace
I0608 06:39:08.789770   19414 model_client.go:344] Create operations generated as: [{Op:insert Table:Logical_Router_Policy Row:map[action:reroute external_ids:{GoMap:map[name:egressip]} match:ip6.src == ae70::66 nexthops:{GoSet:[fef0::56]} priority:100] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996327}]
I0608 06:39:08.790067   19414 model_client.go:369] Mutate operations generated as: [{Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:u2596996327}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.790296   19414 transact.go:41] Configuring OVN: [{Op:wait Table:Logical_Router_Policy Row:map[] Rows:[map[match:ip6.src == ae70::66 priority:100]] Columns:[priority match] Mutations:[] Timeout:0xc0132d7eb8 Where:[where column priority == 100 where column match == ip6.src == ae70::66] Until:!= Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:insert Table:Logical_Router_Policy Row:map[action:reroute external_ids:{GoMap:map[name:egressip]} match:ip6.src == ae70::66 nexthops:{GoSet:[fef0::56]} priority:100] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996327} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:u2596996327}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.790904   19414 client.go:781]  "msg"="transacting operations"  "database"="OVN_Northbound" "operations"="[{Op:wait Table:Logical_Router_Policy Row:map[] Rows:[map[match:ip6.src == ae70::66 priority:100]] Columns:[priority match] Mutations:[] Timeout:0xc0132d7eb8 Where:[where column priority == 100 where column match == ip6.src == ae70::66] Until:!= Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:insert Table:Logical_Router_Policy Row:map[action:reroute external_ids:{GoMap:map[name:egressip]} match:ip6.src == ae70::66 nexthops:{GoSet:[fef0::56]} priority:100] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996327} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:u2596996327}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy" "model"="&{UUID:b177a47a-9932-4889-b24c-7b356d01c183 Action:reroute ExternalIDs:map[name:egressip] Match:ip6.src == ae70::66 Nexthop:<nil> Nexthops:[fef0::56] Options:map[] Priority:100}"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":684} "level"=5 "msg"="updating row" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router" "old"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}" "new"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[b177a47a-9932-4889-b24c-7b356d01c183] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.797917   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" 
I0608 06:39:08.798300   19414 cache.go:684] cache "msg"="updating row" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "new"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[b177a47a-9932-4889-b24c-7b356d01c183] Ports:[] StaticRoutes:[]}" "old"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.798543   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Policy" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" 
I0608 06:39:08.798956   19414 cache.go:668] cache "msg"="inserting row" "database"="OVN_Northbound" "table"="Logical_Router_Policy" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "model"="&{UUID:b177a47a-9932-4889-b24c-7b356d01c183 Action:reroute ExternalIDs:map[name:egressip] Match:ip6.src == ae70::66 Nexthop:<nil> Nexthops:[fef0::56] Options:map[] Priority:100}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy" "model"="&{UUID:b177a47a-9932-4889-b24c-7b356d01c183 Action:reroute ExternalIDs:map[name:egressip] Match:ip6.src == ae70::66 Nexthop:<nil> Nexthops:[fef0::56] Options:map[] Priority:100}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":684} "level"=5 "msg"="updating row" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router" "old"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}" "new"="&{UUID:ada53c94-b166-46fe-8696-82e4b8e35ce5 Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:ovn_cluster_router Nat:[] Options:map[] Policies:[b177a47a-9932-4889-b24c-7b356d01c183] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.801389   19414 model_client.go:344] Create operations generated as: [{Op:insert Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996328}]
I0608 06:39:08.801781   19414 model_client.go:369] Mutate operations generated as: [{Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:u2596996328}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.802014   19414 transact.go:41] Configuring OVN: [{Op:insert Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996328} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:u2596996328}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.802486   19414 client.go:781]  "msg"="transacting operations"  "database"="OVN_Northbound" "operations"="[{Op:insert Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:u2596996328} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:u2596996328}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT" "model"="&{UUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0 AllowedExtIPs:<nil> ExemptedExtIPs:<nil> ExternalIDs:map[name:egressip] ExternalIP:::feff:c0a8:8e0d ExternalMAC:<nil> ExternalPortRange: LogicalIP:ae70::66 LogicalPort:0xc01557bda0 Options:map[stateless:false] Type:snat}"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":684} "level"=5 "msg"="updating row" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router" "old"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}" "new"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.807830   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="NAT" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" 
I0608 06:39:08.808379   19414 cache.go:668] cache "msg"="inserting row" "database"="OVN_Northbound" "table"="NAT" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "model"="&{UUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0 AllowedExtIPs:<nil> ExemptedExtIPs:<nil> ExternalIDs:map[name:egressip] ExternalIP:::feff:c0a8:8e0d ExternalMAC:<nil> ExternalPortRange: LogicalIP:ae70::66 LogicalPort:0xc0155f16d0 Options:map[stateless:false] Type:snat}"
I0608 06:39:08.808913   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" 
I0608 06:39:08.809421   19414 cache.go:684] cache "msg"="updating row" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "new"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}" "old"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":668} "level"=5 "msg"="inserting row" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT" "model"="&{UUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0 AllowedExtIPs:<nil> ExemptedExtIPs:<nil> ExternalIDs:map[name:egressip] ExternalIP:::feff:c0a8:8e0d ExternalMAC:<nil> ExternalPortRange: LogicalIP:ae70::66 LogicalPort:0xc019ab6ea0 Options:map[stateless:false] Type:snat}"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":684} "level"=5 "msg"="updating row" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router" "old"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}" "new"="&{UUID:b695509c-f505-4a76-972a-a2774b66a69d Copp:<nil> Enabled:<nil> ExternalIDs:map[] LoadBalancer:[] LoadBalancerGroup:[] Name:GR_node2 Nat:[4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0] Options:map[] Policies:[] Ports:[] StaticRoutes:[]}"
I0608 06:39:08.812628   19414 egressip.go:1376] Patching status on EgressIP egressip: [{node2 ::feff:c0a8:8e0d}]
I0608 06:39:08.813518   19414 obj_retry.go:1364] Creating *v1.EgressIP egressip took: 25.961995ms
I0608 06:39:08.813814   19414 obj_retry.go:1377] Update event received for resource *v1.EgressIP, old object is equal to new: false
I0608 06:39:08.813998   19414 obj_retry.go:1406] Update event received for resource *v1.EgressIP, oldKey=egressip, newKey=egressip
I0608 06:39:08.814135   19414 obj_retry.go:1465] Updating *v1.EgressIP egressip
I0608 06:39:08.820900   19414 obj_retry.go:1377] Update event received for resource *v1.EgressIP, old object is equal to new: false
I0608 06:39:08.821022   19414 obj_retry.go:1406] Update event received for resource *v1.EgressIP, oldKey=egressip, newKey=egressip
I0608 06:39:08.821111   19414 obj_retry.go:1465] Updating *v1.EgressIP egressip
E0608 06:39:08.821420   19414 egressip.go:882] Allocator error: EgressIP: egressip claims to have an allocation on a node which is unassignable for egress IP: BOOOOGUUUUUS
I0608 06:39:08.821581   19414 egressip.go:1067] Deleting pod egress IP status: {BOOOOGUUUUUS 192.168.126.9} for EgressIP: egressip
W0608 06:39:08.821710   19414 egressip.go:2030] Unable to retrieve gateway IP for node: BOOOOGUUUUUS, protocol is IPv6: false, err: attempt at finding node gateway router network information failed, err: unable to find router port rtoj-GR_BOOOOGUUUUUS: object not found
I0608 06:39:08.822236   19414 egressip.go:1376] Patching status on EgressIP egressip: []
I0608 06:39:08.823475   19414 obj_retry.go:1377] Update event received for resource *v1.EgressIP, old object is equal to new: false
I0608 06:39:08.823710   19414 obj_retry.go:1406] Update event received for resource *v1.EgressIP, oldKey=egressip, newKey=egressip
I0608 06:39:08.823936   19414 obj_retry.go:1465] Updating *v1.EgressIP egressip
I0608 06:39:08.824445   19414 egressip.go:1421] Current assignments are: map[::feff:c0a8:8e0d:{Node:node2 Name:egressip} ::feff:c0a8:8e1e:{Node:node1 Name:bogus2} ::feff:c0a8:8e23:{Node:node2 Name:bogus3} ::feff:c0a8:8e32:{Node:node1 Name:bogus1}]
I0608 06:39:08.824716   19414 egressip.go:1423] Will attempt assignment for egress IP: ::feff:c0a8:8e0d
I0608 06:39:08.825116   19414 egressip.go:1023] Adding pod egress IP status: {node2 ::feff:c0a8:8e0d} for EgressIP: egressip and pod: egress-pod/egressip-namespace
I0608 06:39:08.825663   19414 model_client.go:369] Mutate operations generated as: [{Op:mutate Table:Logical_Router_Policy Row:map[] Rows:[] Columns:[] Mutations:[{Column:nexthops Mutator:insert Value:{GoSet:[fef0::56]}}] Timeout:<nil> Where:[where column _uuid == {b177a47a-9932-4889-b24c-7b356d01c183}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.826116   19414 model_client.go:369] Mutate operations generated as: [{Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:b177a47a-9932-4889-b24c-7b356d01c183}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.826212   19414 transact.go:41] Configuring OVN: [{Op:mutate Table:Logical_Router_Policy Row:map[] Rows:[] Columns:[] Mutations:[{Column:nexthops Mutator:insert Value:{GoSet:[fef0::56]}}] Timeout:<nil> Where:[where column _uuid == {b177a47a-9932-4889-b24c-7b356d01c183}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:b177a47a-9932-4889-b24c-7b356d01c183}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.827160   19414 client.go:781]  "msg"="transacting operations"  "database"="OVN_Northbound" "operations"="[{Op:mutate Table:Logical_Router_Policy Row:map[] Rows:[] Columns:[] Mutations:[{Column:nexthops Mutator:insert Value:{GoSet:[fef0::56]}}] Timeout:<nil> Where:[where column _uuid == {b177a47a-9932-4889-b24c-7b356d01c183}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:policies Mutator:insert Value:{GoSet:[{GoUUID:b177a47a-9932-4889-b24c-7b356d01c183}]}}] Timeout:<nil> Where:[where column _uuid == {ada53c94-b166-46fe-8696-82e4b8e35ce5}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router"
I0608 06:39:08.831442   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" 
I0608 06:39:08.831643   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Policy" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" 
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b177a47a-9932-4889-b24c-7b356d01c183" "table"="Logical_Router_Policy"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="ada53c94-b166-46fe-8696-82e4b8e35ce5" "table"="Logical_Router"
I0608 06:39:08.832838   19414 model_client.go:353] Update operations generated as: [{Op:update Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[where column _uuid == {4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.833124   19414 model_client.go:369] Mutate operations generated as: [{Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.833234   19414 transact.go:41] Configuring OVN: [{Op:update Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[where column _uuid == {4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]
I0608 06:39:08.833717   19414 client.go:781]  "msg"="transacting operations"  "database"="OVN_Northbound" "operations"="[{Op:update Table:NAT Row:map[external_ids:{GoMap:map[name:egressip]} external_ip:::feff:c0a8:8e0d logical_ip:ae70::66 logical_port:{GoSet:[k8s-node2]} options:{GoMap:map[stateless:false]} type:snat] Rows:[] Columns:[] Mutations:[] Timeout:<nil> Where:[where column _uuid == {4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:nat Mutator:insert Value:{GoSet:[{GoUUID:4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0}]}}] Timeout:<nil> Where:[where column _uuid == {b695509c-f505-4a76-972a-a2774b66a69d}] Until: Durable:<nil> Comment:<nil> Lock:<nil> UUIDName:}]"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT"
2022/06/08 06:39:08 server/cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router"
I0608 06:39:08.837306   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" 
I0608 06:39:08.837504   19414 cache.go:651] cache "msg"="processing update" "database"="OVN_Northbound" "table"="NAT" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" 
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="4bd2a4eb-95c9-4ba5-8f2e-280ccbbb30c0" "table"="NAT"
2022/06/08 06:39:08 cache: "caller"={"file":"cache.go","line":651} "level"=5 "msg"="processing update" "uuid"="b695509c-f505-4a76-972a-a2774b66a69d" "table"="Logical_Router"
I0608 06:39:08.838470   19414 egressip.go:1376] Patching status on EgressIP egressip: [{node2 ::feff:c0a8:8e0d}]
I0608 06:39:08.839412   19414 obj_retry.go:1377] Update event received for resource *v1.EgressIP, old object is equal to new: false
I0608 06:39:08.839557   19414 obj_retry.go:1406] Update event received for resource *v1.EgressIP, oldKey=egressip, newKey=egressip
I0608 06:39:08.839658   19414 obj_retry.go:1465] Updating *v1.EgressIP egressip
I0608 06:39:08.847129   19414 handler.go:139] Sending *v1.Namespace event handler 1 for removal
I0608 06:39:08.847595   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.847811   19414 reflector.go:225] Stopping reflector *v1.Endpoints (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.847961   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.848109   19414 reflector.go:225] Stopping reflector *v1.Service (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.848253   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.848379   19414 reflector.go:225] Stopping reflector *v1.Pod (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.848573   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.848702   19414 reflector.go:225] Stopping reflector *v1.NetworkPolicy (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.848856   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.848981   19414 reflector.go:225] Stopping reflector *v1.Node (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.847672   19414 handler.go:147] Removed *v1.Namespace event handler 1
I0608 06:39:08.850423   19414 handler.go:139] Sending *v1.EgressIP event handler 3 for removal
I0608 06:39:08.847251   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.847465   19414 watch.go:183] Stopping fake watcher.
I0608 06:39:08.850740   19414 reflector.go:225] Stopping reflector *v1.Namespace (0s) from k8s.io/client-go/informers/factory.go:134
I0608 06:39:08.850980   19414 handler.go:139] Sending *v1.Pod event handler 2 for removal
I0608 06:39:08.851162   19414 handler.go:147] Removed *v1.EgressIP event handler 3
I0608 06:39:08.851335   19414 reflector.go:225] Stopping reflector *v1.EgressIP (0s) from pkg/crd/egressip/v1/apis/informers/externalversions/factory.go:117
I0608 06:39:08.851493   19414 handler.go:147] Removed *v1.Pod event handler 2
I0608 06:39:08.851889   19414 obj_retry.go:1169] Stop channel got triggered: will stop retrying failed objects of type *factory.egressIPPod
I0608 06:39:08.852123   19414 obj_retry.go:1169] Stop channel got triggered: will stop retrying failed objects of type *v1.EgressIP
I0608 06:39:08.852198   19414 obj_retry.go:1169] Stop channel got triggered: will stop retrying failed objects of type *factory.egressIPNamespace
• Failure [0.656 seconds]
OVN master EgressIP Operations
/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/egressip_test.go:111
  on EgressIP UPDATE
/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/egressip_test.go:2218
should not do anyting for user defined status updates [It]
/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/egressip_test.go:2736
Expected
        <string>: node2
    to equal
        <string>: BOOOOGUUUUUS
    /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/egressip_test.go:2880
------------------------------
kyrtapz commented 2 years ago

The test worked because initially we were not taking status updates into account: https://github.com/ovn-org/ovn-kubernetes/blob/eae2420678f9c8460636f682c2a7a282765114f1/go-controller/pkg/ovn/ovn.go#L831 It was changed here, since then the test was successful only by accident because delete fails hard with non existing entries:

I0609 14:59:10.162089  669803 kube.go:232] Updating status on EgressIP egressip
E0609 14:59:10.168699  669803 egressip.go:311] Allocator error: EgressIP: egressip claims to have an allocation on a node which is unassignable for egress IP: BOOOOGUUUUUS
E0609 14:59:10.219567  669803 egressip.go:1090] Attempt at finding node gateway router network information failed, err: unable to find router port: rtoj-GR_BOOOOGUUUUUS, err: object not found
E0609 14:59:10.281192  669803 egressip.go:1090] Attempt at finding node gateway router network information failed, err: unable to find router port: rtoj-GR_BOOOOGUUUUUS, err: object not found
E0609 14:59:10.342687  669803 egressip.go:1090] Attempt at finding node gateway router network information failed, err: unable to find router port: rtoj-GR_BOOOOGUUUUUS, err: object not found
E0609 14:59:10.404746  669803 egressip.go:1090] Attempt at finding node gateway router network information failed, err: unable to find router port: rtoj-GR_BOOOOGUUUUUS, err: object not found
E0609 14:59:10.466081  669803 egressip.go:1090] Attempt at finding node gateway router network information failed, err: unable to find router port: rtoj-GR_BOOOOGUUUUUS, err: object not found
E0609 14:59:10.466101  669803 ovn.go:916] Unable to update EgressIP: egressip, err: unable to delete logical router policy, err: unable to retrieve gateway IP for node: BOOOOGUUUUUS, protocol is IPv6: false, err: timed out waiting for the condition

Since https://github.com/ovn-org/ovn-kubernetes/pull/3008 EgressIP removal won't fail when the gateway router doesn't exist, this means that the test will no longer work.

I think this test should be removed since we don't expect users to change the EgressIP status and we reconcile on every update.

trozet commented 2 years ago

@alexanderConstantinescu FYI

tssurya commented 8 months ago

fixed via https://github.com/ovn-org/ovn-kubernetes/pull/3035