┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓
┃   FAIL  package: github.com/cilium/cilium/pkg/bgpv1/test   ┃
┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛

--- FAIL: Test_PodIPPoolAdvert (15.07s)

time="2024-10-29T08:58:11Z" level=info msg="deleting dummy links"
time="2024-10-29T08:58:11Z" level=info msg="adding dummy links"
time="2024-10-29T08:58:11Z" level=info msg="GoBGP test instance: starting"
time="2024-10-29T08:58:11Z" level=info msg="Add a peer configuration" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:11Z" level=debug msg="IdleHoldTimer expired" Duration=0 Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:11Z" level=debug msg="state changed" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP new=BGP_FSM_ACTIVE old=BGP_FSM_IDLE reason=idle-hold-timer-expired subsys=basic
time="2024-10-29T08:58:11.43679186Z" level=info msg="Unsupported IPAM mode, disabling PodCIDR advertisements. exportPodCIDR doesn't take effect." subsys=bgp-control-plane
time="2024-10-29T08:58:11.439029233Z" level=info msg="Unsupported IPAM mode, disabling PodCIDR advertisements." subsys=bgp-control-plane
    logger.go:257: time=2024-10-29T08:58:11.443Z level=INFO source=/host/vendor/github.com/cilium/hive/hive.go:338 msg=Starting
time="2024-10-29T08:58:11.449249417Z" level=info msg="Using v1.Endpoints" subsys=k8s
    logger.go:257: time=2024-10-29T08:58:11.450Z level=INFO source=/host/vendor/github.com/cilium/hive/hive.go:342 msg=Started duration=3.14707ms
time="2024-10-29T08:58:11Z" level=info msg="GoBGP test instance: Peer Event: {0 IDLE}"
time="2024-10-29T08:58:11Z" level=info msg="GoBGP test instance: Peer Event: {65001 IDLE}"
time="2024-10-29T08:58:11Z" level=info msg="GoBGP test instance: Peer Event: {65001 ACTIVE}"
time="2024-10-29T08:58:11.55454248Z" level=info msg="Cilium BGP Control Plane Controller now running..." component=Controller.Run subsys=bgp-control-plane
time="2024-10-29T08:58:11.554684675Z" level=info msg="Registering BGP servers for policy with local ASN 65001" component=manager.registerBGPServer subsys=bgp-control-plane
time="2024-10-29T08:58:11.555051309Z" level=error msg="Error while registering new BGP server for local ASN 65001." component=manager.add error="failed initial reconciliation for peer config with local ASN 65001: reconciliation of virtual router with local ASN 65001 failed: failed to list endpoints from diffstore: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:11.650250451Z" level=error msg="Encountered error reconciling virtual router with local ASN 65001" component=manager.reconcile error="reconciliation of virtual router with local ASN 65001 failed: full reconciliation failed: failed to list ip pools from store: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:11.650317916Z" level=error msg="Encountered error reconciling virtual router with local ASN 65001" component=manager.reconcile error="reconciliation of virtual router with local ASN 65001 failed: full reconciliation failed: failed to list ip pools from store: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:11.65042158Z" level=error msg="Encountered error reconciling virtual router with local ASN 65001" component=manager.reconcile error="reconciliation of virtual router with local ASN 65001 failed: full reconciliation failed: failed to list ip pools from store: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:11.650461695Z" level=error msg="Encountered error reconciling virtual router with local ASN 65001" component=manager.reconcile error="reconciliation of virtual router with local ASN 65001 failed: full reconciliation failed: failed to list ip pools from store: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:11.650509895Z" level=error msg="Encountered error reconciling virtual router with local ASN 65001" component=manager.reconcile error="reconciliation of virtual router with local ASN 65001 failed: full reconciliation failed: failed to list ip pools from store: the store has not initialized yet" subsys=bgp-control-plane
time="2024-10-29T08:58:19Z" level=debug msg="try to connect" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:19Z" level=debug msg="state changed" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP new=BGP_FSM_OPENSENT old=BGP_FSM_ACTIVE reason=new-connection subsys=basic
time="2024-10-29T08:58:19Z" level=info msg="GoBGP test instance: Peer Event: {65001 OPENSENT}"
time="2024-10-29T08:58:19.43753344Z" level=info msg="Can't find configuration for a new passive connection" Key=172.16.100.2 Topic=Peer asn=65001 component=gobgp.BgpServerInstance subsys=bgp-control-plane
time="2024-10-29T08:58:19Z" level=debug msg="state changed" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP new=BGP_FSM_IDLE old=BGP_FSM_OPENSENT reason=read-failed subsys=basic
time="2024-10-29T08:58:19Z" level=info msg="GoBGP test instance: Peer Event: {65001 IDLE}"
time="2024-10-29T08:58:24Z" level=debug msg="IdleHoldTimer expired" Duration=5 Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:24Z" level=debug msg="state changed" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP new=BGP_FSM_ACTIVE old=BGP_FSM_IDLE reason=idle-hold-timer-expired subsys=basic
time="2024-10-29T08:58:24Z" level=info msg="GoBGP test instance: Peer Event: {65001 ACTIVE}"
    adverts_test.go:433: 
        	Error Trace:	/host/pkg/bgpv1/test/adverts_test.go:433
        	Error:      	Received unexpected error:
        	            	did not receive expected peering state ["ESTABLISHED"]: context deadline exceeded
        	Test:       	Test_PodIPPoolAdvert
time="2024-10-29T08:58:26Z" level=info msg="GoBGP test instance: stopping"
time="2024-10-29T08:58:26Z" level=info msg="Delete a peer configuration" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:26Z" level=debug msg="stop connect loop" Key=172.16.100.1 Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:26Z" level=debug msg="freed fsm.h" Key=172.16.100.1 State=BGP_FSM_ACTIVE Topic=Peer asn=65011 component=tests.BGP subsys=basic
time="2024-10-29T08:58:26Z" level=error msg="failed to close existing tcp connection" Key=172.16.100.1 State=BGP_FSM_ACTIVE Topic=Peer asn=65011 component=tests.BGP subsys=basic
    logger.go:257: time=2024-10-29T08:58:26.410Z level=INFO source=/host/vendor/github.com/cilium/hive/hive.go:354 msg=Stopping
time="2024-10-29T08:58:26Z" level=info msg="deleting dummy links"