Description

the first vrf bgp cannot Established if started early

Steps to reproduce the issue
1.run vrf script
2.the vrf bgp cannot Established if bgp start early DEVICE_METADATA

Describe the results you received

admin@tau1t8-01:~$ show bgp vrf all summary

Instance Vrf1:

IPv4 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 12
BGP table version 12802
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
10.0.0.57 4 64600 3373 5147 0 0 0 00:08:24 6400
10.0.0.59 4 64600 3370 5144 0 0 0 00:08:23 6400

Total number of neighbors 2

IPv6 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 12
BGP table version 12802
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
fc00::72 4 64600 3374 6017 0 0 0 00:08:24 6400
fc00::76 4 64600 3370 6020 0 0 0 00:08:23 6400

Total number of neighbors 2

Instance Vrf2:

IPv4 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 13
BGP table version 12802
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
10.0.0.61 4 64600 3373 3376 0 0 0 00:08:24 6400
10.0.0.63 4 64600 3373 3374 0 0 0 00:08:24 6400

Total number of neighbors 2

IPv6 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 13
BGP table version 6402
RIB entries 12801, using 2300 KiB of memory
Peers 1, using 20 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
fc00::7e 4 64600 3373 3375 0 0 0 00:08:24 6400

Total number of neighbors 1
admin@tau1t8-01:~$

Errors in syslog:
Jan 13 03:31:42.666005 tau1t8-01 INFO swss#supervisord: start.sh rsyslogd: started
Jan 13 03:31:42.668956 tau1t8-01 INFO teamd.sh[3846]: teamd
Jan 13 03:31:42.669505 tau1t8-01 INFO teamd.sh[3620]: 0
Jan 13 03:31:42.684741 tau1t8-01 INFO systemd[1]: Stopped TEAMD container.
Jan 13 03:31:42.688568 tau1t8-01 INFO systemd[1]: Starting TEAMD container...
Jan 13 03:31:42.746480 tau1t8-01 INFO radv.sh[3823]: Starting existing radv container with HWSKU Accton-AS7116-54X
Jan 13 03:31:42.831324 tau1t8-01 INFO snmp.sh[3842]: Starting existing snmp container with HWSKU Accton-AS7116-54X
Jan 13 03:31:42.831957 tau1t8-01 INFO telemetry.sh[3826]: Starting existing telemetry container with HWSKU Accton-AS7116-54X
Jan 13 03:31:42.832524 tau1t8-01 INFO dhcp_relay.sh[3822]: Starting existing dhcp_relay container with HWSKU Accton-AS7116-54X
Jan 13 03:31:42.833094 tau1t8-01 INFO sflow.sh[3829]: Starting existing sflow container with HWSKU Accton-AS7116-54X
Jan 13 03:31:42.843328 tau1t8-01 ERR bgp#bgpcfgd: Peer Vrf2|fc00::7a. Error in rendering the template for "SET" command {'rrclient': '0', 'name': 'ARISTA03T1', 'local_addr': 'fc00::
:79', 'nhopself': '0', 'admin_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:42.886333 tau1t8-01 INFO accton_as7116_util.py[467]: Checking system....
Jan 13 03:31:42.886862 tau1t8-01 INFO accton_as7116_util.py[467]: No driver, installing....
Jan 13 03:31:42.887235 tau1t8-01 INFO accton_as7116_util.py[467]: No device, installing....
Jan 13 03:31:42.888101 tau1t8-01 INFO systemd[1]: Started Accton AS7116-54X Platform initialization service.
Jan 13 03:31:42.889812 tau1t8-01 INFO systemd[1]: Starting Platform monitor container...
Jan 13 03:31:43.001719 tau1t8-01 INFO lldp.sh[3827]: Starting existing lldp container with HWSKU Accton-AS7116-54X
Jan 13 03:31:43.014558 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf2|fc00::7e added with attributes {'rrclient': '0', 'name': 'ARISTA04T1', 'local_addr': 'fc00::7d', 'nhopself': '0', 'admii
n_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.074452 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:43.072510650Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/b59ddc31d55
8d6b5a8f171f388b4502b8844778bb55195b4be585cb1491f880b8/shim.sock" debug=false pid=4320
Jan 13 03:31:43.190139 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf1|fc00::76 added with attributes {'rrclient': '0', 'name': 'ARISTA02T1', 'local_addr': 'fc00::75', 'nhopself': '0', 'admii
n_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.204327 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:43.203539440Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/f53ab55af11
7516aa6aba51c5774c9b0ee459bdd97fc02fa081f811bc99415331/shim.sock" debug=false pid=4361
Jan 13 03:31:43.232002 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:43.231859400Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/0bc7162a277
bf3a4a41c7ad55a1463bb5d70c08c5ddbdbe41f0cf8819945e815d/shim.sock" debug=false pid=4390
Jan 13 03:31:43.245848 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:43.245689138Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/99b4ba27900
2cf4b38c0bce2785ba02bcec6d17c08ff43d388ea5d7ced24dc1a6/shim.sock" debug=false pid=4413
Jan 13 03:31:43.249177 tau1t8-01 INFO syncd#liblogging-stdlog: [origin software="rsyslogd" swVersion="8.24.0" x-pid="18" x-info="http://www.rsyslog.com"] start
Jan 13 03:31:43.252812 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:43.252625363Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/be997b24177
98423e085d10a5ef8a4f7af9f496f7be7c73d2e562031f61da1342/shim.sock" debug=false pid=4417
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:30:43,955 INFO stopped: rsyslogd (exit status 0)
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:41,788 CRIT Set uid to user 0
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:41,789 INFO Included extra file "/etc/supervisor/conf.d/ptf_nn_agent.conf" during parsing
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:41,789 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:41,804 INFO RPC interface 'supervisor' initialized
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:41,804 INFO supervisord started with pid 1
Jan 13 03:31:43.253974 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:42,807 INFO spawned: 'start.sh' with pid 13
Jan 13 03:31:43.254007 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:42,809 INFO spawned: 'ptf_nn_agent' with pid 14
Jan 13 03:31:43.254007 tau1t8-01 INFO syncd#supervisord 2020-01-13 03:31:43,218 INFO spawned: 'rsyslogd' with pid 18
Jan 13 03:31:43.342505 tau1t8-01 INFO snmp.sh[3842]: 1
Jan 13 03:31:43.344751 tau1t8-01 NOTICE swss#orchagent: :- main: --- Starting Orchestration Agent ---
Jan 13 03:31:43.351571 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf1|fc00::72 added with attributes {'rrclient': '0', 'name': 'ARISTA01T1', 'local_addr': 'fc00::71', 'nhopself': '0', 'admii
n_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.373382 tau1t8-01 NOTICE swss#orchagent: :- loadRedisScript: lua script loaded, sha: 88270a7c5c90583e56425aca8af8a4b8c39fe757
Jan 13 03:31:43.404796 tau1t8-01 NOTICE swss#orchagent: :- loadRedisScript: lua script loaded, sha: cefe851bf060b761fe2588021df0704782f3269b
Jan 13 03:31:43.411481 tau1t8-01 NOTICE swss#orchagent: :- clear_local_state: clearing local state
Jan 13 03:31:43.411763 tau1t8-01 NOTICE swss#orchagent: :- sai_log_set: not implemented
Jan 13 03:31:43.427833 tau1t8-01 NOTICE swss#orchagent: message repeated 26 times: [ :- sai_log_set: not implemented]
Jan 13 03:31:43.427833 tau1t8-01 NOTICE swss#orchagent: :- startRecording: started recording: /var/log/swss/sairedis.rec
Jan 13 03:31:43.427833 tau1t8-01 NOTICE swss#orchagent: :- initSaiRedis: Enable redis pipeline
Jan 13 03:31:43.427833 tau1t8-01 NOTICE swss#orchagent: :- sai_redis_notify_syncd: sending syncd INIT view
Jan 13 03:31:43.429698 tau1t8-01 NOTICE swss#orchagent: :- sai_redis_internal_notify_syncd: wait for notify response
Jan 13 03:31:43.439423 tau1t8-01 INFO radv.sh[3823]: radv
Jan 13 03:31:43.518017 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf1|10.0.0.57 added with attributes {'rrclient': '0', 'name': 'ARISTA01T1', 'local_addr': '10.0.0.56', 'nhopself': '0', 'add
min_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.652707 tau1t8-01 INFO sflow.sh[3829]: sflow
Jan 13 03:31:43.689829 tau1t8-01 INFO lldp.sh[3827]: lldp
Jan 13 03:31:43.690387 tau1t8-01 INFO dhcp_relay.sh[3822]: dhcp_relay
Jan 13 03:31:43.705119 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf2|10.0.0.63 added with attributes {'rrclient': '0', 'name': 'ARISTA04T1', 'local_addr': '10.0.0.62', 'nhopself': '0', 'add
min_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.907128 tau1t8-01 INFO teamd.sh[4187]: Starting existing teamd container with HWSKU Accton-AS7116-54X
Jan 13 03:31:43.936509 tau1t8-01 INFO systemd[1]: Started Router advertiser container.
Jan 13 03:31:43.957496 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf1|10.0.0.59 added with attributes {'rrclient': '0', 'name': 'ARISTA02T1', 'local_addr': '10.0.0.58', 'nhopself': '0', 'add
min_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:43.965926 tau1t8-01 INFO systemd[1]: Started Telemetry container.
Jan 13 03:31:44.003484 tau1t8-01 INFO pmon.sh[4278]: Starting existing pmon container with HWSKU Accton-AS7116-54X
Jan 13 03:31:44.011333 tau1t8-01 INFO swss#supervisord: start.sh orchagent: started
Jan 13 03:31:44.080059 tau1t8-01 INFO database#supervisord 2020-01-13 03:31:35,070 INFO success: rsyslogd entered RUNNING state, process has stayed up for > than 1 seconds (startsee
cs)
Jan 13 03:31:44.080059 tau1t8-01 INFO database#supervisord 2020-01-13 03:31:35,070 INFO success: redis entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Jan 13 03:31:44.104891 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:44.104730806Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/776f7441722
3528a60fda014da892b769eddba5c4863498030b43ce684289e73e/shim.sock" debug=false pid=5027
Jan 13 03:31:44.112259 tau1t8-01 INFO systemd[1]: Started sFlow container.
Jan 13 03:31:44.141891 tau1t8-01 INFO bgp#bgpcfgd: Peer Vrf2|10.0.0.61 added with attributes {'rrclient': '0', 'name': 'ARISTA03T1', 'local_addr': '10.0.0.60', 'nhopself': '0', 'add
min_status': 'up', 'holdtime': '10', 'asn': '64600', 'keepalive': '3'}
Jan 13 03:31:44.167938 tau1t8-01 INFO containerd[515]: time="2020-01-13T03:31:44.167745821Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/d14ffd13cbb
3271eca46484ec1d200403bdd1cbe5d90c9bee371b9e3888a2fef2/shim.sock" debug=false pid=5101
Jan 13 03:31:44.194846 tau1t8-01 INFO systemd[1]: Started LLDP container.
Jan 13 03:31:44.211662 tau1t8-01 INFO systemd[1]: Started DHCP relay container.
Jan 13 03:31:44.222314 tau1t8-01 INFO syncd#supervisord: start.sh rsyslogd: started
Jan 13 03:31:44.366137 tau1t8-01 INFO swss#supervisord: start.sh restore_neighbors: started

Describe the results you expected

admin@tau1t8-01:~$ show bgp vrf all summary

Instance Vrf1:

IPv4 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 12
BGP table version 12498
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
10.0.0.57 4 64600 3212 5128 0 0 0 00:00:22 6400
10.0.0.59 4 64600 3210 4335 0 0 793 00:00:22 6400

Total number of neighbors 2

IPv6 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 12
BGP table version 12678
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
fc00::72 4 64600 3212 5519 0 0 0 00:00:22 6400
fc00::76 4 64600 3210 3005 0 0 2514 00:00:22 6400

Total number of neighbors 2

Instance Vrf2:

IPv4 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 13
BGP table version 11811
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
10.0.0.61 4 64600 3212 3509 0 0 0 00:00:24 6400
10.0.0.63 4 64600 3212 3512 0 0 0 00:00:24 6400

Total number of neighbors 2

IPv6 Unicast Summary:
BGP router identifier 10.1.0.32, local AS number 65100 vrf-id 13
BGP table version 12570
RIB entries 12803, using 2301 KiB of memory
Peers 2, using 41 KiB of memory
Peer groups 4, using 256 bytes of memory

Neighbor V AS MsgRcvd MsgSent TblVer InQ OutQ Up/Down State/PfxRcd
fc00::7a 4 64600 3212 4446 0 0 0 00:00:24 6400
fc00::7e 4 64600 3212 4449 0 0 0 00:00:23 6400

Total number of neighbors 2
admin@tau1t8-01:~$

Additional information you deem important (e.g. issue happens only occasionally)

Output of show version

SONiC Software Version: SONiC.nephos-master-df11b2b-201911190056.0-dirty-20191120.014533
Distribution: Debian 9.11
Kernel: 4.9.0-9-2-amd64
Build commit: 9adcc586
Build date: Thu Nov 21 02:00:00 UTC 2019
Built by: build@nps65

Platform: x86_64-accton_as7116_54x-r0
HwSKU: Accton-AS7116-54X
ASIC: nephos
Serial Number: 711654X1737002
Uptime: 06:47:41 up 17:21, 1 user, load average: 0.30, 0.23, 0.23

Docker images:
REPOSITORY TAG IMAGE ID SIZE
docker-syncd-nephos-rpc latest 8e556269be0e 594MB
docker-syncd-nephos latest 8e556269be0e 594MB
docker-syncd-nephos-dbg latest 0bd2224b1b46 422MB
docker-syncd-nephos-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 0bd2224b1b46 422MB
docker-syncd-nephos nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 0bd2224b1b46 422MB
docker-platform-monitor-dbg latest 822cfb8d7712 397MB
docker-platform-monitor-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 822cfb8d7712 397MB
docker-platform-monitor latest 822cfb8d7712 397MB
docker-platform-monitor nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 822cfb8d7712 397MB
docker-fpm-frr-dbg latest e9aa287c0c67 430MB
docker-fpm-frr-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 e9aa287c0c67 430MB
docker-fpm-frr latest e9aa287c0c67 430MB
docker-fpm-frr nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 e9aa287c0c67 430MB
docker-sflow-dbg latest b83be3838a02 378MB
docker-sflow-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 b83be3838a02 378MB
docker-sflow latest b83be3838a02 378MB
docker-sflow nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 b83be3838a02 378MB
docker-teamd-dbg latest 4bbe6423bbb9 404MB
docker-teamd-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 4bbe6423bbb9 404MB
docker-teamd latest 4bbe6423bbb9 404MB
docker-teamd nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 4bbe6423bbb9 404MB
docker-lldp-sv2 latest 5a91928ef05a 376MB
docker-lldp-sv2 nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 5a91928ef05a 376MB
docker-lldp-sv2-dbg latest 5a91928ef05a 376MB
docker-lldp-sv2-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 5a91928ef05a 376MB
docker-dhcp-relay-dbg latest 9b5975ab704c 359MB
docker-dhcp-relay-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 9b5975ab704c 359MB
docker-dhcp-relay latest 9b5975ab704c 359MB
docker-dhcp-relay nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 9b5975ab704c 359MB
docker-database-dbg latest 2f4d4b2aa7e2 355MB
docker-database-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 2f4d4b2aa7e2 355MB
docker-database latest 2f4d4b2aa7e2 355MB
docker-database nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 2f4d4b2aa7e2 355MB
docker-snmp-sv2-dbg latest 72a18efc13a3 406MB
docker-snmp-sv2-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 72a18efc13a3 406MB
docker-snmp-sv2 latest 72a18efc13a3 406MB
docker-snmp-sv2 nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 72a18efc13a3 406MB
docker-orchagent-dbg latest 34992853d9a5 419MB
docker-orchagent-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 34992853d9a5 419MB
docker-orchagent latest 34992853d9a5 419MB
docker-orchagent nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 34992853d9a5 419MB
docker-sonic-telemetry-dbg latest 932acb156980 377MB
docker-sonic-telemetry-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 932acb156980 377MB
docker-sonic-telemetry latest 932acb156980 377MB
docker-sonic-telemetry nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 932acb156980 377MB
docker-router-advertiser-dbg latest 7b9253e28770 354MB
docker-router-advertiser-dbg nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 7b9253e28770 354MB
docker-router-advertiser latest 7b9253e28770 354MB
docker-router-advertiser nephos-master-df11b2b-201911190056.0-dirty-20191120.014533 7b9253e28770 354MB