[BGPCEP-320] Not a reasonable duration of 1M prefix introduction from BGP application peer via restconf Created: 30/Nov/15  Updated: 03/Mar/19  Resolved: 22/Jan/16

Status: Resolved
Project: bgpcep
Component/s: BGP
Affects Version/s: Bugzilla Migration
Fix Version/s: Bugzilla Migration

Type: Bug
Reporter: Radovan Sajben Assignee: Milos Fabian
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


Issue Links:
Blocks
blocks BGPCEP-334 BGPSessionImpl: Failed to send messag... Resolved
External issue ID: 4689

 Description   

Not a reasonable period (not comparable to 1M BGP peer scenario) needed for 1M prefixes introduction from BGP application peer (restconf) to controller and to BGP peer (BGP Updates). It points to performance issue and/or lack of environment specification and expected result definition for such case.

bgpcep-bgp-ingest.txt.Bgp App Peer Prefixcount :: BGP performance of ingest...
==============================================================================
Check_For_Empty_Ipv4_Topology_Before_Starting :: Wait for example-... | PASS |
------------------------------------------------------------------------------
Reconfigure_ODL_To_Accept_Connection :: Configure BGP peer module ... | PASS |
------------------------------------------------------------------------------
Reconfigure_ODL_To_Accept_BGP_Application_Peer :: Configure BGP ap... | PASS |
------------------------------------------------------------------------------
Connect_BGP_Peer :: Start BGP peer tool | PASS |
------------------------------------------------------------------------------
Start_BGP_Application_Peer_To_Introduce_Routes :: Start BGP applic... | PASS |
------------------------------------------------------------------------------
Wait_For_Ipv4_Topology_Is_Filled :: Wait until example-ipv4-topolo... | FAIL |
Keyword 'PrefixCounting.Check_Ipv4_Topology_Count' failed after retrying for 5 minutes 20 seconds. The last error was: 32358 != 1000000

test suite: https://git.opendaylight.org/gerrit/#/c/30256/15
test log temporary available at https://jenkins.opendaylight.org/sandbox/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/26/console

Note: test suite follows specifications: https://wiki.opendaylight.org/view/BGP_LS_PCEP:Programmer_Guide#BGP
https://wiki.opendaylight.org/view/BGP_LS_PCEP:User_Guide#BGP_Application_Peer



 Comments   
Comment by Milos Fabian [ 01/Dec/15 ]

Seems to be a problem in both Lithium and Beryllium, lets figure out where is the bottleneck.

Comment by Vratko Polak [ 01/Dec/15 ]

Yesterday I left this comment unsent:

> 5 minutes 20 seconds. The last error was: 32358

That is only ~100 routes per second, I would expect Restconf to be around 5-times faster.

From description it is not clear whether the bottleneck is Restconf or Bgpcep code. The suite should also have separated cases for putting data to app-peer without bgp-peer connected, and for connecting bgp-peer when app-peer is fully populated.

Comment by Radovan Sajben [ 02/Dec/15 ]

some additional info ... the test where the controller just announces routes to BGP peer is there ... aproximatelly 32k routes in 1 min (see the total_received_update_message_counter) ... a scheduler on the controller side?

https://jenkins.opendaylight.org/sandbox/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/26/robot/report/log.html#s1-s4-t16-k4-k2

2015-11-30 09:40:01,828 INFO: No message received in 9.94529294968s
2015-11-30 09:40:01,830 INFO: total_received_update_message_counter: 0
2015-11-30 09:40:01,830 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:01,830 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:01,830 INFO: total_rx_idle_time_counter: 60.006s
2015-11-30 09:40:01,830 INFO: KEEP ALIVE is sent.
2015-11-30 09:40:02,668 INFO: KEEP ALIVE message received: 0xffffffffffffffffffffffffffffffff001304
2015-11-30 09:40:12,678 INFO: No message received in 10s
2015-11-30 09:40:12,678 INFO: total_received_update_message_counter: 9113
2015-11-30 09:40:12,679 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:12,679 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:12,679 INFO: total_rx_idle_time_counter: 70.199s
2015-11-30 09:40:22,689 INFO: No message received in 10s
2015-11-30 09:40:22,690 INFO: total_received_update_message_counter: 9113
2015-11-30 09:40:22,690 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:22,690 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:22,690 INFO: total_rx_idle_time_counter: 80.209s
2015-11-30 09:40:32,700 INFO: No message received in 10s
2015-11-30 09:40:32,701 INFO: total_received_update_message_counter: 9113
2015-11-30 09:40:32,701 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:32,701 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:32,701 INFO: total_rx_idle_time_counter: 90.220s
2015-11-30 09:40:42,711 INFO: No message received in 10s
2015-11-30 09:40:42,712 INFO: total_received_update_message_counter: 9113
2015-11-30 09:40:42,712 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:42,712 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:42,712 INFO: total_rx_idle_time_counter: 100.230s
2015-11-30 09:40:52,722 INFO: No message received in 10s
2015-11-30 09:40:52,723 INFO: total_received_update_message_counter: 9113
2015-11-30 09:40:52,723 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:40:52,723 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:40:52,723 INFO: total_rx_idle_time_counter: 110.240s
2015-11-30 09:41:01,840 INFO: No message received in 9.10711407661s
2015-11-30 09:41:01,840 INFO: total_received_update_message_counter: 9113
2015-11-30 09:41:01,840 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:41:01,840 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:41:01,840 INFO: total_rx_idle_time_counter: 119.356s
2015-11-30 09:41:01,841 INFO: KEEP ALIVE is sent.
2015-11-30 09:41:02,666 INFO: KEEP ALIVE message received: 0xffffffffffffffffffffffffffffffff001304
2015-11-30 09:41:14,920 INFO: No message received in 10s
2015-11-30 09:41:14,921 INFO: total_received_update_message_counter: 32391
2015-11-30 09:41:14,921 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:41:14,921 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:41:14,921 INFO: total_rx_idle_time_counter: 130.787s
2015-11-30 09:41:24,931 INFO: No message received in 10s
2015-11-30 09:41:24,932 INFO: total_received_update_message_counter: 32391
2015-11-30 09:41:24,932 INFO: total_received_nlri_prefix_counter: 0
2015-11-30 09:41:24,932 INFO: total_received_withdrawn_prefix_counter: 0
2015-11-30 09:41:24,932 INFO: total_rx_idle_time_counter: 140.797s
2015-11-30 09:41:34,942 INFO: No message received in 10s

... about the restconf performance ... based on https://wiki.opendaylight.org/view/BGP_LS_PCEP:Programmer_Guide#BGP test tool uses a single POST request for addition of single route (anyway gauges will be introduced to the test tool to measure total response time). Performance could be increased using single request for all routes. Is it the target to announce 1M routes in a single POST request? Does controller support routes announcement via restconf in batches?

Comment by Radovan Sajben [ 02/Dec/15 ]

... some additional info from BGP application peer tool - restconf interface ... 1000 POST requests handled by controller in cca 16s

python bgp_app_peer_test.py --command add --count 1000 --prefix 1.1.1.1 --prefixlen 32 --info
2015-12-02 02:01:02,339 INFO: Add 1000 prefixes (starting from 1.1.1.1/32) into 127.0.0.1:8181/restconf/config/bgp-rib:application-rib/example-app-rib/tables/bgp-types:ipv4-address-family/bgp-types:unicast-subsequent-address-family/
2015-12-02 02:01:20,436 INFO: Done
2015-12-02 02:01:20,436 INFO: Total test execution time: 18.097s
2015-12-02 02:01:20,437 INFO: Total build data time: 1.048s
2015-12-02 02:01:20,437 INFO: Total response time: 16.159s
2015-12-02 02:01:20,437 INFO: Total number of response(s): 1000

Comment by Milos Fabian [ 02/Dec/15 ]

I can't find a way for batching routes without overriding existing routes. Also putting 1M in single request does not seems to be real for me.

Agree on Vratko's idea - split the test on two parts. First measure how long does it take to fill application-rib and/or loc-rib and then connect "receiver" and see how long does it take to send all routes.

Comment by Vratko Polak [ 02/Dec/15 ]

> Is it the target to announce 1M routes in a single POST request?

In principle yes, but Restconf memory overhead is not known yet.
With current 6GB heap, 500k or at least 300k should be doable.

> Does controller support routes announcement via restconf in batches?

It is missing PATCH support in Restconf.
Alternatively, a specialized RPC could be implemented in BGP code.
Neither of those are likely to make it into Beryllium.

Comment by Radovan Sajben [ 08/Dec/15 ]

... similar behavior for deleting all routes (waiting for updates failed - timeout for this TC set 10x longer than other bgp performance suites have, ROBOT OPTIONS: --suite *ready --suite *bgp_app_peer_prefixcount -v COUNT:50000 -v PREFILL:25000 -v TEST_DURATION_MULTIPLIER:10):

Karaf log:
=========

https://jenkins.opendaylight.org/sandbox/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/22/artifact/karaf.log

2015-12-08 10:15:13,551 | INFO | h for user karaf | command | 255 - org.apache.karaf.log.command - 3.0.3 | ROBOT MESSAGE: Starting test Reconnect_BGP_Peer
2015-12-08 10:15:13,670 | INFO | oupCloseable-6-3 | StrictBGPPeerRegistry | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | BGP Open message session parameters differ, session still accepted.
2015-12-08 10:15:13,670 | INFO | oupCloseable-6-3 | BGPSessionImpl | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | BGP HoldTimer new value: 180
2015-12-08 10:15:13,671 | INFO | oupCloseable-6-3 | BGPPeer | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | Session with peer 10.30.32.55 went up with tables: [BgpTableTypeImpl [getAfi()=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.Ipv4AddressFamily, getSafi()=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.UnicastSubsequentAddressFamily]]
2015-12-08 10:15:13,673 | INFO | oupCloseable-6-3 | AbstractBGPSessionNegotiator | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | BGP Session with peer [id: 0x4249a7c0, /10.30.32.55:17900 => /10.30.32.60:1790] established successfully.
2015-12-08 10:15:23,691 | INFO | h for user karaf | command | 255 - org.apache.karaf.log.command - 3.0.3 | ROBOT MESSAGE: Starting test Check_Bgp_Peer_Updates_For_Reintroduced_Routes
2015-12-08 10:15:34,272 | INFO | h for user karaf | command | 255 - org.apache.karaf.log.command - 3.0.3 | ROBOT MESSAGE: Starting test BGP_Application_Peer_Delete_All_Routes
2015-12-08 10:15:34,572 | INFO | h for user karaf | command | 255 - org.apache.karaf.log.command - 3.0.3 | ROBOT MESSAGE: Starting test Wait_For_Stable_Topology_After_Deletion
2015-12-08 10:15:36,229 | INFO | oupCloseable-6-2 | BGPSessionImpl | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | Failed to send message Update [_attributes=Attributes [_asPath=AsPath{augmentations={}}, _clusterId=ClusterId{getCluster=[Ipv4Address [_value=40.40.40.40]], augmentations={}}, _localPref=LocalPref{getPref=100, augmentations={}}, _multiExitDisc=MultiExitDisc{getMed=0, augmentations={}}, _origin=Origin{getValue=Igp, augmentations={}}, _originatorId=OriginatorId{getOriginator=Ipv4Address [_value=41.41.41.41], augmentations={}}, augmentation=[Attributes2 [_mpUnreachNlri=MpUnreachNlri [_afi=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.Ipv4AddressFamily, _safi=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.UnicastSubsequentAddressFamily, _withdrawnRoutes=WithdrawnRoutes [_destinationType=DestinationIpv4Case [_destinationIpv4=DestinationIpv4 [_ipv4Prefixes=[Ipv4Prefixes [_prefix=Ipv4Prefix [_value=8.2.134.192/28], augmentation=[]]], augmentation=[]], augmentation=[]], augmentation=[]], augmentation=[]]]]], augmentation=[]] to socket java.nio.channels.ClosedChannelException
2015-12-08 10:15:36,230 | INFO | oupCloseable-6-2 | BGPSessionImpl | 238 - org.opendaylight.bgpcep.bgp-rib-impl - 0.4.4.SNAPSHOT | Failed to send message Update [_attributes=Attributes [_asPath=AsPath{augmentations={}}, _clusterId=ClusterId{getCluster=[Ipv4Address [_value=40.40.40.40]], augmentations={}}, _localPref=LocalPref{getPref=100, augmentations={}}, _multiExitDisc=MultiExitDisc{getMed=0, augmentations={}}, _origin=Origin{getValue=Igp, augmentations={}}, _originatorId=OriginatorId{getOriginator=Ipv4Address [_value=41.41.41.41], augmentations={}}, augmentation=[Attributes2 [_mpUnreachNlri=MpUnreachNlri [_afi=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.Ipv4AddressFamily, _safi=class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.bgp.types.rev130919.UnicastSubsequentAddressFamily, _withdrawnRoutes=WithdrawnRoutes [_destinationType=DestinationIpv4Case [_destinationIpv4=DestinationIpv4 [_ipv4Prefixes=[Ipv4Prefixes [_prefix=Ipv4Prefix [_value=12.0.43.160/28], augmentation=[]]], augmentation=[]], augmentation=[]], augmentation=[]], augmentation=[]]]]], augmentation=[]] to socket java.nio.channels.ClosedChannelException

BGP peer simulator log (play.py):
=================================

please see the total_received_withdrawn_prefix_counter: 35229 frozen for long time

https://jenkins.opendaylight.org/sandbox/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/22/robot/report/log.html#s1-s2-t17-k4-k2

2015-12-08 10:15:14,039 INFO: Connecting in the talking mode.
2015-12-08 10:15:14,042 INFO: Connected to ODL.
2015-12-08 10:15:14,052 INFO: Open message received.
2015-12-08 10:15:14,053 INFO: Generator initialisation
2015-12-08 10:15:14,053 INFO: Target total number of prefixes to be introduced: 0
2015-12-08 10:15:14,053 INFO: Prefix base: 8.0.1.0/28
2015-12-08 10:15:14,053 INFO: My Autonomous System number: 64496
2015-12-08 10:15:14,053 INFO: My Hold Time: 180
2015-12-08 10:15:14,053 INFO: My BGP Identifier: 169746487
2015-12-08 10:15:14,053 INFO: Next Hop: 192.0.2.1
2015-12-08 10:15:14,053 INFO: Prefix count to be inserted at once: 1
2015-12-08 10:15:14,053 INFO: Prefix count to be withdrawn at once: 0
2015-12-08 10:15:14,054 INFO: Fast pre-fill up to 0 prefixes
2015-12-08 10:15:14,054 INFO: Remaining number of prefixes to be processed in parallel with withdrawals: 0
2015-12-08 10:15:14,054 INFO: Two separate UPDATEs will be generated for each NLRI & WITHDRAWN lists
2015-12-08 10:15:14,054 INFO: Let's go ...

2015-12-08 10:15:14,055 INFO: total_received_update_message_counter: 0
2015-12-08 10:15:14,055 INFO: total_received_nlri_prefix_counter: 0
2015-12-08 10:15:14,056 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:15:15,763 INFO: ... idle for 1.707s
2015-12-08 10:15:15,763 INFO: total_rx_idle_time_counter: 1.707s
2015-12-08 10:15:24,023 INFO: total_received_update_message_counter: 50000
2015-12-08 10:15:24,024 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:15:24,024 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:15:34,034 INFO: ... idle for 10.010s
2015-12-08 10:15:34,034 INFO: total_rx_idle_time_counter: 11.717s
2015-12-08 10:15:34,035 INFO: total_received_update_message_counter: 50000
2015-12-08 10:15:34,035 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:15:34,035 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:15:44,045 INFO: ... idle for 10.010s
2015-12-08 10:15:44,045 INFO: total_rx_idle_time_counter: 21.727s
2015-12-08 10:15:44,046 INFO: total_received_update_message_counter: 50000
2015-12-08 10:15:44,046 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:15:44,046 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:15:54,056 INFO: ... idle for 10.010s
2015-12-08 10:15:54,057 INFO: total_rx_idle_time_counter: 31.737s
2015-12-08 10:15:54,057 INFO: total_received_update_message_counter: 50000
2015-12-08 10:15:54,057 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:15:54,057 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:16:04,067 INFO: ... idle for 10.010s
2015-12-08 10:16:04,068 INFO: total_rx_idle_time_counter: 41.748s
2015-12-08 10:16:04,068 INFO: total_received_update_message_counter: 50000
2015-12-08 10:16:04,068 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:04,068 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:16:14,066 INFO: ... idle for 9.997s
2015-12-08 10:16:14,066 INFO: total_rx_idle_time_counter: 51.745s
2015-12-08 10:16:14,066 INFO: KEEP ALIVE is sent.
2015-12-08 10:16:14,066 INFO: total_received_update_message_counter: 50000
2015-12-08 10:16:14,066 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:14,066 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:16:24,077 INFO: ... idle for 10.010s
2015-12-08 10:16:24,077 INFO: total_rx_idle_time_counter: 61.755s
2015-12-08 10:16:24,077 INFO: total_received_update_message_counter: 50000
2015-12-08 10:16:24,077 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:24,078 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:16:34,088 INFO: ... idle for 10.010s
2015-12-08 10:16:34,088 INFO: total_rx_idle_time_counter: 71.765s
2015-12-08 10:16:34,088 INFO: total_received_update_message_counter: 50000
2015-12-08 10:16:34,089 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:34,089 INFO: total_received_withdrawn_prefix_counter: 0
2015-12-08 10:16:36,946 INFO: ... idle for 2.857s
2015-12-08 10:16:36,946 INFO: total_rx_idle_time_counter: 74.622s
2015-12-08 10:16:42,443 INFO: KEEP ALIVE message received: 0xffffffffffffffffffffffffffffffff001304
2015-12-08 10:16:42,444 INFO: total_received_update_message_counter: 85229
2015-12-08 10:16:42,444 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:42,444 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:16:52,454 INFO: ... idle for 10.010s
2015-12-08 10:16:52,455 INFO: total_rx_idle_time_counter: 84.632s
2015-12-08 10:16:52,455 INFO: total_received_update_message_counter: 85229
2015-12-08 10:16:52,455 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:16:52,455 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:02,465 INFO: ... idle for 10.010s
2015-12-08 10:17:02,466 INFO: total_rx_idle_time_counter: 94.643s
2015-12-08 10:17:02,466 INFO: total_received_update_message_counter: 85229
2015-12-08 10:17:02,466 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:02,466 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:12,476 INFO: ... idle for 10.009s
2015-12-08 10:17:12,476 INFO: total_rx_idle_time_counter: 104.652s
2015-12-08 10:17:12,476 INFO: total_received_update_message_counter: 85229
2015-12-08 10:17:12,476 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:12,476 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:14,068 INFO: ... idle for 1.592s
2015-12-08 10:17:14,069 INFO: total_rx_idle_time_counter: 106.244s
2015-12-08 10:17:14,069 INFO: KEEP ALIVE is sent.
2015-12-08 10:17:14,069 INFO: total_received_update_message_counter: 85229
2015-12-08 10:17:14,069 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:14,069 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:24,080 INFO: ... idle for 10.010s
2015-12-08 10:17:24,080 INFO: total_rx_idle_time_counter: 116.254s
2015-12-08 10:17:24,080 INFO: total_received_update_message_counter: 85229
2015-12-08 10:17:24,080 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:24,080 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:34,091 INFO: ... idle for 10.010s
2015-12-08 10:17:34,091 INFO: total_rx_idle_time_counter: 126.264s
2015-12-08 10:17:34,091 INFO: total_received_update_message_counter: 85229
2015-12-08 10:17:34,091 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:34,091 INFO: total_received_withdrawn_prefix_counter: 35229
2015-12-08 10:17:42,135 INFO: ... idle for 8.044s
2015-12-08 10:17:42,135 INFO: total_rx_idle_time_counter: 134.308s
2015-12-08 10:17:43,683 INFO: KEEP ALIVE message received: 0xffffffffffffffffffffffffffffffff001304
2015-12-08 10:17:43,683 INFO: total_received_update_message_counter: 95214
2015-12-08 10:17:43,683 INFO: total_received_nlri_prefix_counter: 50000
2015-12-08 10:17:43,684 INFO: total_received_withdrawn_prefix_counter: 45214
Traceback (most recent call last):
File "play.py", line 1580, in <module>
state.perform_one_loop_iteration()
File "play.py", line 1522, in perform_one_loop_iteration
self.reader.wait_for_read()
File "play.py", line 1355, in wait_for_read
select.select([self.socket], [], [self.socket], wait_timedelta)
KeyboardInterrupt

Comment by Milos Fabian [ 15/Dec/15 ]

Be: https://git.opendaylight.org/gerrit/#/c/31033/
Li: https://git.opendaylight.org/gerrit/#/c/31264/

Testing (with java application for pushing routes) proved significant performance improvement.

Comment by Radovan Sajben [ 22/Dec/15 ]

BGP application peer performance suite results available at: https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/

test suite indicates improvements, operation duration is still not comparable to results/targets for routes introduced by iBGP peer.

100k routes introduced in single request:
=========================================
Waiting for 100k updates (15 min), restconf operation is done:
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/report/log.html#s1-s4-t7

BGP peer log:
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/report/log.html#s1-s4-t11-k4-k2

Re-introduced 200k routes after BGP peer re-connection (4m 30s):
================================================================
Waiting for introduced 200k routes (no restconf operation):
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/report/log.html#s1-s4-t13

Waiting for 200k withdrawals, timeout after 22 min (restconf request is done):
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/report/log.html#s1-s4-t17

BGP peer log:
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/report/log.html#s1-s4-t18-k4-k2

Test duration:
==============
pre-filled 100k routes in one request: https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/bgpcep-bgp-ingest.txt/Bgp%20App%20Peer%20Prefixcount/Check_Bgp_Peer_Updates_For_Prefilled_Routes/

re-introduced 100k routes after BGP peer re-connection:
https://jenkins.opendaylight.org/releng/view/bgpcep/job/bgpcep-csit-1node-periodic-bgp-ingest-only-stable-lithium/53/robot/bgpcep-bgp-ingest.txt/Bgp%20App%20Peer%20Prefixcount/Check_Bgp_Peer_Updates_For_Reintroduced_Routes/

Comment by Milos Fabian [ 20/Jan/16 ]

Reopening - performance issues persist.

Comment by Milos Fabian [ 20/Jan/16 ]

Boron: https://git.opendaylight.org/gerrit/#/c/33096/

Comment by Milos Fabian [ 22/Jan/16 ]

Be: https://git.opendaylight.org/gerrit/#/c/33239
Li: https://git.opendaylight.org/gerrit/#/c/33340

Generated at Wed Feb 07 19:12:41 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.