trozet
commented
11 months ago weird that the node is annotated: 2023-10-16T18:12:29.1293931Z I1016 18:12:29.128478 25316 kube.go:121] Setting annotations map[k8s.ovn.org/l3-gateway-config:{"default":{"mode":"local","interface-id":"br-eth0_node1","mac-address":"11:22:33:44:55:66","ip-addresses":["172.16.16.2/24"],"ip-address":"172.16.16.2/24","next-hops":["172.16.16.1"],"next-hop":"172.16.16.1","node-port-enable":"true","vlan-id":"1024"}} k8s.ovn.org/node-chassis-id:cb9ec8fa-b409-4ef3-9f42-d9283c47aac6] on node node1
but then the failure is it couldn't find the annotation :confused:
https://github.com/ovn-org/ovn-kubernetes/actions/runs/6537444453/job/17751302279?pr=3956
2023-10-16T18:12:28.6166792Z [0mOVN for APB External Route Operations[0m [90mhybrid route policy operations in lgw mode[0m 2023-10-16T18:12:28.6168034Z [1mdelete stale addresses from apb hybrid route policies on startup[0m 2023-10-16T18:12:28.6169501Z [37m/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/external_gateway_apb_test.go:2866[0m 2023-10-16T18:12:28.6175856Z I1016 18:12:28.617191 25316 reflector.go:293] Stopping reflector v1.AdminPolicyBasedExternalRoute (0s) from pkg/crd/adminpolicybasedroute/v1/apis/informers/externalversions/factory.go:116 2023-10-16T18:12:28.6186722Z I1016 18:12:28.608876 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6188248Z I1016 18:12:28.617879 25316 reflector.go:293] Stopping reflector v1.Node (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6189462Z I1016 18:12:28.608893 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6190901Z I1016 18:12:28.617974 25316 reflector.go:293] Stopping reflector v1.EndpointSlice (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6192165Z I1016 18:12:28.608915 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6193512Z I1016 18:12:28.618098 25316 reflector.go:293] Stopping reflector v1.Pod (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6194708Z I1016 18:12:28.608931 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6196086Z I1016 18:12:28.618307 25316 reflector.go:293] Stopping reflector v1.Service (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6207549Z I1016 18:12:28.608952 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6209098Z I1016 18:12:28.619996 25316 reflector.go:293] Stopping reflector v1.NetworkPolicy (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6210561Z I1016 18:12:28.608993 25316 watch.go:183] Stopping fake watcher. 2023-10-16T18:12:28.6211994Z I1016 18:12:28.620076 25316 reflector.go:293] Stopping reflector *v1.Namespace (0s) from k8s.io/client-go/informers/factory.go:150 2023-10-16T18:12:28.6386008Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Database" "uuid"="e240fa8e-d4b0-4904-a5fd-63f4c2d65aab" "model"={"UUID":"e240fa8e-d4b0-4904-a5fd-63f4c2d65aab","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Northbound","Schema":null,"Sid":"694db100"} 2023-10-16T18:12:28.6401195Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Database" "uuid"="e240fa8e-d4b0-4904-a5fd-63f4c2d65aab" "model"={"UUID":"e240fa8e-d4b0-4904-a5fd-63f4c2d65aab","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Northbound","Schema":null,"Sid":"694db100"} 2023-10-16T18:12:28.6406952Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":{},"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""} 2023-10-16T18:12:28.6412403Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Policy" "uuid"="708fe0b5-7103-4e12-b12a-dfcf8f00ca02" "model"={"UUID":"708fe0b5-7103-4e12-b12a-dfcf8f00ca02","Action":"reroute","ExternalIDs":{},"Match":"inport == \"rtos-node1\" && ip4.src == $a11971853777183785484 && ip4.dst != 10.128.0.0/14","Nexthop":null,"Nexthops":["100.64.0.4"],"Options":{},"Priority":501} 2023-10-16T18:12:28.6418060Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router" "uuid"="9a7f0195-2805-4078-8bde-db824cb46c9a" "model"={"UUID":"9a7f0195-2805-4078-8bde-db824cb46c9a","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"ovn_cluster_router","Nat":[],"Options":{},"Policies":["708fe0b5-7103-4e12-b12a-dfcf8f00ca02"],"Ports":[],"StaticRoutes":[]} 2023-10-16T18:12:28.6423495Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c" "model"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} 2023-10-16T18:12:28.6429075Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Port" "uuid"="fc0c7604-2c9e-459d-8418-7a97ed14de51" "model"={"UUID":"fc0c7604-2c9e-459d-8418-7a97ed14de51","Enabled":null,"ExternalIDs":{},"GatewayChassis":[],"HaChassisGroup":null,"Ipv6Prefix":[],"Ipv6RaConfigs":{},"MAC":"","Name":"rtoj-GR_node1","Networks":["100.64.0.4/32"],"Options":{},"Peer":null} 2023-10-16T18:12:28.6434391Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":{},"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""} 2023-10-16T18:12:28.6439902Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Policy" "uuid"="708fe0b5-7103-4e12-b12a-dfcf8f00ca02" "model"={"UUID":"708fe0b5-7103-4e12-b12a-dfcf8f00ca02","Action":"reroute","ExternalIDs":{},"Match":"inport == \"rtos-node1\" && ip4.src == $a11971853777183785484 && ip4.dst != 10.128.0.0/14","Nexthop":null,"Nexthops":["100.64.0.4"],"Options":{},"Priority":501} 2023-10-16T18:12:28.6445447Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router" "uuid"="9a7f0195-2805-4078-8bde-db824cb46c9a" "model"={"UUID":"9a7f0195-2805-4078-8bde-db824cb46c9a","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"ovn_cluster_router","Nat":[],"Options":{},"Policies":["708fe0b5-7103-4e12-b12a-dfcf8f00ca02"],"Ports":[],"StaticRoutes":[]} 2023-10-16T18:12:28.6450869Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c" "model"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} 2023-10-16T18:12:28.6456345Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Logical_Router_Port" "uuid"="fc0c7604-2c9e-459d-8418-7a97ed14de51" "model"={"UUID":"fc0c7604-2c9e-459d-8418-7a97ed14de51","Enabled":null,"ExternalIDs":{},"GatewayChassis":[],"HaChassisGroup":null,"Ipv6Prefix":[],"Ipv6RaConfigs":{},"MAC":"","Name":"rtoj-GR_node1","Networks":["100.64.0.4/32"],"Options":{},"Peer":null} 2023-10-16T18:12:28.7421090Z I1016 18:12:28.741547 25316 client.go:332] "msg"="trying to connect" "database"="OVN_Northbound" "endpoint"="unix:/tmp/ovsdb-28d5b99eebff4cc97f52fe81a4dba476" 2023-10-16T18:12:28.7652125Z I1016 18:12:28.764809 25316 client.go:827] "msg"="transacting operations" "database"="_Server" "operations"="[{Op:select Table:Database Row:map[] Rows:[] Columns:[name model leader sid] Mutations:[] Timeout: Where:[] Until: Durable: Comment: Lock: UUID: UUIDName:}]"
2023-10-16T18:12:28.7659781Z I1016 18:12:28.765738 25316 client.go:263] "msg"="successfully connected" "database"="OVN_Northbound" "endpoint"="unix:/tmp/ovsdb-28d5b99eebff4cc97f52fe81a4dba476" "sid"="694db100"
2023-10-16T18:12:28.7675240Z I1016 18:12:28.767237 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Database" "uuid"="e240fa8e-d4b0-4904-a5fd-63f4c2d65aab"
2023-10-16T18:12:28.7679374Z I1016 18:12:28.767372 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"e240fa8e-d4b0-4904-a5fd-63f4c2d65aab","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Northbound","Schema":null,"Sid":"694db100"} "table"="Database" "uuid"="e240fa8e-d4b0-4904-a5fd-63f4c2d65aab"
2023-10-16T18:12:28.7737154Z I1016 18:12:28.773401 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Port" "uuid"="fc0c7604-2c9e-459d-8418-7a97ed14de51"
2023-10-16T18:12:28.7742051Z I1016 18:12:28.773716 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"fc0c7604-2c9e-459d-8418-7a97ed14de51","Enabled":null,"ExternalIDs":null,"GatewayChassis":null,"HaChassisGroup":null,"Ipv6Prefix":null,"Ipv6RaConfigs":null,"MAC":"","Name":"rtoj-GR_node1","Networks":["100.64.0.4/32"],"Options":null,"Peer":null} "table"="Logical_Router_Port" "uuid"="fc0c7604-2c9e-459d-8418-7a97ed14de51"
2023-10-16T18:12:28.7745858Z I1016 18:12:28.773823 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c"
2023-10-16T18:12:28.7756336Z I1016 18:12:28.774055 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":null,"LoadBalancer":null,"LoadBalancerGroup":null,"Name":"GR_node1","Nat":null,"Options":null,"Policies":null,"Ports":null,"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c"
2023-10-16T18:12:28.7760584Z I1016 18:12:28.774145 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="9a7f0195-2805-4078-8bde-db824cb46c9a"
2023-10-16T18:12:28.7764878Z I1016 18:12:28.774272 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"9a7f0195-2805-4078-8bde-db824cb46c9a","Copp":null,"Enabled":null,"ExternalIDs":null,"LoadBalancer":null,"LoadBalancerGroup":null,"Name":"ovn_cluster_router","Nat":null,"Options":null,"Policies":["708fe0b5-7103-4e12-b12a-dfcf8f00ca02"],"Ports":null,"StaticRoutes":null} "table"="Logical_Router" "uuid"="9a7f0195-2805-4078-8bde-db824cb46c9a"
2023-10-16T18:12:28.7768885Z I1016 18:12:28.774359 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Policy" "uuid"="708fe0b5-7103-4e12-b12a-dfcf8f00ca02"
2023-10-16T18:12:28.7773300Z I1016 18:12:28.774476 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"708fe0b5-7103-4e12-b12a-dfcf8f00ca02","Action":"reroute","ExternalIDs":null,"Match":"inport == \"rtos-node1\" && ip4.src == $a11971853777183785484 && ip4.dst != 10.128.0.0/14","Nexthop":null,"Nexthops":["100.64.0.4"],"Options":null,"Priority":501} "table"="Logical_Router_Policy" "uuid"="708fe0b5-7103-4e12-b12a-dfcf8f00ca02"
2023-10-16T18:12:28.7777162Z I1016 18:12:28.774549 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7"
2023-10-16T18:12:28.7781199Z I1016 18:12:28.774824 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":null,"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""} "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7"
2023-10-16T18:12:28.7952071Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Database" "uuid"="0aa7d13f-37eb-4eba-91d4-203890b229d7" "model"={"UUID":"0aa7d13f-37eb-4eba-91d4-203890b229d7","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Southbound","Schema":null,"Sid":"8c0bb0ce"}
2023-10-16T18:12:28.7957428Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="Database" "uuid"="0aa7d13f-37eb-4eba-91d4-203890b229d7" "model"={"UUID":"0aa7d13f-37eb-4eba-91d4-203890b229d7","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Southbound","Schema":null,"Sid":"8c0bb0ce"}
2023-10-16T18:12:28.8963552Z I1016 18:12:28.895564 25316 client.go:332] "msg"="trying to connect" "database"="OVN_Southbound" "endpoint"="unix:/tmp/ovsdb-cd3ee1df627b3966c880896149fb420e"
2023-10-16T18:12:28.9166568Z I1016 18:12:28.916239 25316 client.go:827] "msg"="transacting operations" "database"="_Server" "operations"="[{Op:select Table:Database Row:map[] Rows:[] Columns:[name model leader sid] Mutations:[] Timeout: Where:[] Until: Durable: Comment: Lock: UUID: UUIDName:}]"
2023-10-16T18:12:28.9177041Z I1016 18:12:28.917414 25316 client.go:263] "msg"="successfully connected" "database"="OVN_Southbound" "endpoint"="unix:/tmp/ovsdb-cd3ee1df627b3966c880896149fb420e" "sid"="8c0bb0ce"
2023-10-16T18:12:28.9193055Z I1016 18:12:28.919020 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Southbound" "table"="Database" "uuid"="0aa7d13f-37eb-4eba-91d4-203890b229d7"
2023-10-16T18:12:28.9197498Z I1016 18:12:28.919251 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Southbound" "model"={"UUID":"0aa7d13f-37eb-4eba-91d4-203890b229d7","Cid":null,"Connected":true,"Index":null,"Leader":true,"Model":"clustered","Name":"OVN_Southbound","Schema":null,"Sid":"8c0bb0ce"} "table"="Database" "uuid"="0aa7d13f-37eb-4eba-91d4-203890b229d7"
2023-10-16T18:12:28.9218528Z I1016 18:12:28.921509 25316 client.go:827] "msg"="transacting operations" "database"="OVN_Northbound" "operations"="[{Op:insert Table:NB_Global Row:map[ipsec:false name:global] Rows:[] Columns:[] Mutations:[] Timeout: Where:[] Until: Durable: Comment: Lock: UUID: UUIDName:}]"
2023-10-16T18:12:28.9233789Z 2023/10/16 18:12:28 server/transaction/cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":[],"ExternalIDs":{},"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":{},"SbCfg":0,"SbCfgTimestamp":0,"SSL":null}
2023-10-16T18:12:28.9238376Z I1016 18:12:28.923651 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7"
2023-10-16T18:12:28.9243147Z I1016 18:12:28.923816 25316 cache.go:1189] cache "msg"="inserting model" "database"="OVN_Northbound" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":null,"ExternalIDs":null,"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":null,"SbCfg":0,"SbCfgTimestamp":0,"SSL":null} "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7"
2023-10-16T18:12:28.9248853Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1189} "level"=5 "msg"="inserting model" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":[],"ExternalIDs":{},"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":{},"SbCfg":0,"SbCfgTimestamp":0,"SSL":null}
2023-10-16T18:12:28.9251695Z I1016 18:12:28.924296 25316 services_controller.go:60] Creating event broadcaster
2023-10-16T18:12:28.9255226Z I1016 18:12:28.924826 25316 client.go:827] "msg"="transacting operations" "database"="OVN_Northbound" "operations"="[{Op:delete Table:NB_Global Row:map[] Rows:[] Columns:[] Mutations:[] Timeout: Where:[where column _uuid == {80cc4469-af2f-4ce0-97ba-e403c4109dc7}] Until: Durable: Comment: Lock: UUID: UUIDName:}]"
2023-10-16T18:12:28.9262491Z 2023/10/16 18:12:28 server/transaction/cache: "caller"={"file":"cache.go","line":1203} "level"=5 "msg"="deleting model" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":[],"ExternalIDs":{},"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":{},"SbCfg":0,"SbCfgTimestamp":0,"SSL":null}
2023-10-16T18:12:28.9269952Z I1016 18:12:28.926087 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7"
2023-10-16T18:12:28.9279546Z I1016 18:12:28.926253 25316 cache.go:1203] cache "msg"="deleting model" "database"="OVN_Northbound" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":null,"ExternalIDs":null,"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":null,"SbCfg":0,"SbCfgTimestamp":0,"SSL":null} "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7"
2023-10-16T18:12:28.9284758Z 2023/10/16 18:12:28 cache: "caller"={"file":"cache.go","line":1203} "level"=5 "msg"="deleting model" "table"="NB_Global" "uuid"="80cc4469-af2f-4ce0-97ba-e403c4109dc7" "model"={"UUID":"80cc4469-af2f-4ce0-97ba-e403c4109dc7","Connections":[],"ExternalIDs":{},"HvCfg":0,"HvCfgTimestamp":0,"Ipsec":false,"Name":"global","NbCfg":0,"NbCfgTimestamp":0,"Options":{},"SbCfg":0,"SbCfgTimestamp":0,"SSL":null}
2023-10-16T18:12:28.9287482Z I1016 18:12:28.926688 25316 factory.go:344] Starting watch factory
2023-10-16T18:12:28.9289168Z I1016 18:12:28.926985 25316 reflector.go:287] Starting reflector v1.NetworkPolicy (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9292679Z I1016 18:12:28.927244 25316 reflector.go:287] Starting reflector v1.Pod (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9295652Z I1016 18:12:28.927018 25316 reflector.go:323] Listing and watching v1.NetworkPolicy from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9297485Z I1016 18:12:28.927368 25316 reflector.go:287] Starting reflector v1.Service (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9299262Z I1016 18:12:28.927389 25316 reflector.go:323] Listing and watching v1.Service from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9301094Z I1016 18:12:28.927469 25316 reflector.go:287] Starting reflector v1.EndpointSlice (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9302885Z I1016 18:12:28.927272 25316 reflector.go:323] Listing and watching v1.Pod from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9304800Z I1016 18:12:28.927574 25316 reflector.go:287] Starting reflector v1.Namespace (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9306847Z I1016 18:12:28.927489 25316 reflector.go:323] Listing and watching v1.EndpointSlice from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9308688Z I1016 18:12:28.928922 25316 reflector.go:287] Starting reflector v1.Node (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9310458Z I1016 18:12:28.927595 25316 reflector.go:323] Listing and watching v1.Namespace from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:28.9312210Z I1016 18:12:28.928976 25316 reflector.go:323] Listing and watching v1.Node from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.0282912Z I1016 18:12:29.027618 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0284018Z I1016 18:12:29.027686 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0285022Z I1016 18:12:29.027843 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0286005Z I1016 18:12:29.027870 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0286967Z I1016 18:12:29.027892 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0291350Z I1016 18:12:29.027916 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.0293472Z I1016 18:12:29.028765 25316 reflector.go:287] Starting reflector v1.AdminPolicyBasedExternalRoute (0s) from pkg/crd/adminpolicybasedroute/v1/apis/informers/externalversions/factory.go:116
2023-10-16T18:12:29.0296486Z I1016 18:12:29.028803 25316 reflector.go:323] Listing and watching v1.AdminPolicyBasedExternalRoute from pkg/crd/adminpolicybasedroute/v1/apis/informers/externalversions/factory.go:116
2023-10-16T18:12:29.1289577Z I1016 18:12:29.128154 25316 shared_informer.go:341] caches populated
2023-10-16T18:12:29.1293931Z I1016 18:12:29.128478 25316 kube.go:121] Setting annotations map[k8s.ovn.org/l3-gateway-config:{"default":{"mode":"local","interface-id":"br-eth0_node1","mac-address":"11:22:33:44:55:66","ip-addresses":["172.16.16.2/24"],"ip-address":"172.16.16.2/24","next-hops":["172.16.16.1"],"next-hop":"172.16.16.1","node-port-enable":"true","vlan-id":"1024"}} k8s.ovn.org/node-chassis-id:cb9ec8fa-b409-4ef3-9f42-d9283c47aac6] on node node1
2023-10-16T18:12:29.1300797Z I1016 18:12:29.129856 25316 repair.go:120] OVN ECMP route cache is: map[10.128.1.3:[0xc002e0b450]]
2023-10-16T18:12:29.1302602Z I1016 18:12:29.129909 25316 repair.go:121] Cluster ECMP route cache is: map[]
2023-10-16T18:12:29.1304810Z I1016 18:12:29.129930 25316 repair.go:128] Found stale exgw ecmp route, podIP: 10.128.1.3, nexthop: 9.0.0.1, router: GR_node1
2023-10-16T18:12:29.1309236Z I1016 18:12:29.130011 25316 model_client.go:399] Delete operations generated as: [{Op:delete Table:Logical_Router_Static_Route Row:map[] Rows:[] Columns:[] Mutations:[] Timeout: Where:[where column _uuid == {902a3d0f-6194-400b-affd-9950d274a6e7}] Until: Durable: Comment: Lock: UUID: UUIDName:}]
2023-10-16T18:12:29.1315420Z I1016 18:12:29.130165 25316 model_client.go:390] Mutate operations generated as: [{Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:static_routes Mutator:delete Value:{GoSet:[{GoUUID:902a3d0f-6194-400b-affd-9950d274a6e7}]}}] Timeout: Where:[where column _uuid == {024302dd-6a0f-41f7-92e3-e5a19c45a64c}] Until: Durable: Comment: Lock: UUID: UUIDName:}]
2023-10-16T18:12:29.1323781Z I1016 18:12:29.130373 25316 transact.go:42] Configuring OVN: [{Op:delete Table:Logical_Router_Static_Route Row:map[] Rows:[] Columns:[] Mutations:[] Timeout: Where:[where column _uuid == {902a3d0f-6194-400b-affd-9950d274a6e7}] Until: Durable: Comment: Lock: UUID: UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:static_routes Mutator:delete Value:{GoSet:[{GoUUID:902a3d0f-6194-400b-affd-9950d274a6e7}]}}] Timeout: Where:[where column _uuid == {024302dd-6a0f-41f7-92e3-e5a19c45a64c}] Until: Durable: Comment: Lock: UUID: UUIDName:}]
2023-10-16T18:12:29.1334321Z I1016 18:12:29.130783 25316 client.go:827] "msg"="transacting operations" "database"="OVN_Northbound" "operations"="[{Op:delete Table:Logical_Router_Static_Route Row:map[] Rows:[] Columns:[] Mutations:[] Timeout: Where:[where column _uuid == {902a3d0f-6194-400b-affd-9950d274a6e7}] Until: Durable: Comment: Lock: UUID: UUIDName:} {Op:mutate Table:Logical_Router Row:map[] Rows:[] Columns:[] Mutations:[{Column:static_routes Mutator:delete Value:{GoSet:[{GoUUID:902a3d0f-6194-400b-affd-9950d274a6e7}]}}] Timeout: Where:[where column _uuid == {024302dd-6a0f-41f7-92e3-e5a19c45a64c}] Until: Durable: Comment: Lock: UUID: UUIDName:}]"
2023-10-16T18:12:29.1342516Z 2023/10/16 18:12:29 server/transaction/cache: "caller"={"file":"cache.go","line":1203} "level"=5 "msg"="deleting model" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":{},"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""}
2023-10-16T18:12:29.1350183Z 2023/10/16 18:12:29 server/transaction/cache: "caller"={"file":"cache.go","line":1196} "level"=5 "msg"="updating model" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c" "old"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} "new"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":[]}
2023-10-16T18:12:29.1355652Z I1016 18:12:29.133017 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c"
2023-10-16T18:12:29.1361606Z I1016 18:12:29.133206 25316 cache.go:1196] cache "msg"="updating model" "database"="OVN_Northbound" "new"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":null,"LoadBalancer":null,"LoadBalancerGroup":null,"Name":"GR_node1","Nat":null,"Options":null,"Policies":null,"Ports":null,"StaticRoutes":null} "old"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":null,"LoadBalancer":null,"LoadBalancerGroup":null,"Name":"GR_node1","Nat":null,"Options":null,"Policies":null,"Ports":null,"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c"
2023-10-16T18:12:29.1367514Z I1016 18:12:29.133298 25316 cache.go:996] cache "msg"="processing update" "database"="OVN_Northbound" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7"
2023-10-16T18:12:29.1372174Z I1016 18:12:29.133406 25316 cache.go:1203] cache "msg"="deleting model" "database"="OVN_Northbound" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":null,"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""} "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7"
2023-10-16T18:12:29.1377954Z 2023/10/16 18:12:29 cache: "caller"={"file":"cache.go","line":1203} "level"=5 "msg"="deleting model" "table"="Logical_Router_Static_Route" "uuid"="902a3d0f-6194-400b-affd-9950d274a6e7" "model"={"UUID":"902a3d0f-6194-400b-affd-9950d274a6e7","BFD":null,"ExternalIDs":{},"IPPrefix":"10.128.1.3/32","Nexthop":"9.0.0.1","Options":{"ecmp_symmetric_reply":"true"},"OutputPort":"rtoe-GR_node1","Policy":"src-ip","RouteTable":""}
2023-10-16T18:12:29.1385218Z 2023/10/16 18:12:29 cache: "caller"={"file":"cache.go","line":1196} "level"=5 "msg"="updating model" "table"="Logical_Router" "uuid"="024302dd-6a0f-41f7-92e3-e5a19c45a64c" "old"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":["902a3d0f-6194-400b-affd-9950d274a6e7"]} "new"={"UUID":"024302dd-6a0f-41f7-92e3-e5a19c45a64c","Copp":null,"Enabled":null,"ExternalIDs":{},"LoadBalancer":[],"LoadBalancerGroup":[],"Name":"GR_node1","Nat":[],"Options":{},"Policies":[],"Ports":[],"StaticRoutes":[]}
2023-10-16T18:12:29.1390056Z I1016 18:12:29.134090 25316 repair.go:33] Syncing exgw routes took 4.511172ms
2023-10-16T18:12:29.1390973Z I1016 18:12:29.135676 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1392735Z I1016 18:12:29.135726 25316 reflector.go:293] Stopping reflector v1.AdminPolicyBasedExternalRoute (0s) from pkg/crd/adminpolicybasedroute/v1/apis/informers/externalversions/factory.go:116
2023-10-16T18:12:29.1394423Z I1016 18:12:29.135767 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1395813Z I1016 18:12:29.135791 25316 reflector.go:293] Stopping reflector v1.Node (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1397012Z I1016 18:12:29.135836 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1398375Z I1016 18:12:29.135859 25316 reflector.go:293] Stopping reflector v1.Pod (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1399559Z I1016 18:12:29.135883 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1401001Z I1016 18:12:29.135904 25316 reflector.go:293] Stopping reflector v1.Namespace (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1402354Z I1016 18:12:29.135931 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1403729Z I1016 18:12:29.135953 25316 reflector.go:293] Stopping reflector v1.Service (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1404960Z I1016 18:12:29.135977 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1406455Z I1016 18:12:29.135999 25316 reflector.go:293] Stopping reflector v1.EndpointSlice (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1407709Z I1016 18:12:29.136018 25316 watch.go:183] Stopping fake watcher.
2023-10-16T18:12:29.1409123Z I1016 18:12:29.136039 25316 reflector.go:293] Stopping reflector v1.NetworkPolicy (0s) from k8s.io/client-go/informers/factory.go:150
2023-10-16T18:12:29.1410072Z
2023-10-16T18:12:29.1410334Z [91m[1m• Failure [0.527 seconds][0m
2023-10-16T18:12:29.1410860Z OVN for APB External Route Operations
2023-10-16T18:12:29.1412013Z [90m/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/external_gateway_apb_test.go:34[0m
2023-10-16T18:12:29.1413124Z hybrid route policy operations in lgw mode
2023-10-16T18:12:29.1414515Z [90m/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/external_gateway_apb_test.go:2369[0m
2023-10-16T18:12:29.1416023Z [91m[1mdelete stale addresses from apb hybrid route policies on startup [It][0m
2023-10-16T18:12:29.1417609Z [90m/home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/external_gateway_apb_test.go:2866[0m
2023-10-16T18:12:29.1418505Z
2023-10-16T18:12:29.1418716Z [91mUnexpected error:
2023-10-16T18:12:29.1419279Z <errors.errorString | 0xc003027920>:
2023-10-16T18:12:29.1422603Z cannot sync exgw bfd: &{nextHop:9.0.0.1 uuid:902a3d0f-6194-400b-affd-9950d274a6e7 router:GR_node1 outport:rtoe-GR_node1 shouldExist:false}, unable to determine exgw switch prefix: extSwitchPrefix: failed to parse l3 gateway annotation for node node1: k8s.ovn.org/l3-gateway-config annotation not found for node "node1"
2023-10-16T18:12:29.1424913Z {
2023-10-16T18:12:29.1436347Z s: "cannot sync exgw bfd: &{nextHop:9.0.0.1 uuid:902a3d0f-6194-400b-affd-9950d274a6e7 router:GR_node1 outport:rtoe-GR_node1 shouldExist:false}, unable to determine exgw switch prefix: extSwitchPrefix: failed to parse l3 gateway annotation for node node1: k8s.ovn.org/l3-gateway-config annotation not found for node \"node1\"",
2023-10-16T18:12:29.1438849Z }
2023-10-16T18:12:29.1439280Z occurred[0m
2023-10-16T18:12:29.1439509Z
2023-10-16T18:12:29.1440411Z /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/ovn/external_gateway_apb_test.go:2969