[
https://issues.apache.org/jira/browse/DISPATCH-1256?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alan Conway reassigned DISPATCH-1256:
-------------------------------------
Assignee: Ted Ross
> Throughput gets worse as more routers are added
> -----------------------------------------------
>
> Key: DISPATCH-1256
> URL: https://issues.apache.org/jira/browse/DISPATCH-1256
> Project: Qpid Dispatch
> Issue Type: Bug
> Reporter: Alan Conway
> Assignee: Ted Ross
> Priority: Major
> Attachments: reproducer.tgz
>
>
> Creating a chain of routers gives worse throughput as the chain gets longer.
> Reproducer:
> Install quiver from here: https://github.com/alanconway/quiver (extened with
> --send-url)
> Run the attached script like this:
> qdr-chain.sh quiver --arrow c --count 1000 --send-url //:10001/testme
> //:10004/testme
> Sets up a chain of 4 routers, each connected to the previous. Waits for
> qdstat -nv at router 1 to show 4 routers in the topology. Receive messages
> from address 'testme' at router 4, send to address 'testme' at router 1.
> This runs the routers with enough tracing to run the dispatch scraper tool,
> which may affect the results. However 1 million message runs without tracing
> show a drop-off in throughput going from 1m0 (no router) up to 1m4 (4-router
> chain) - the more routers the worse it gets. This seems consistent with the
> credit delays seen in the traced case.
> 1m0/out.txt:End-to-end rate ..................................... 296,824
> messages/s
> 1m0/out.txt: 50% ........ 2 ms 99.90% ........ 6 ms
> 1m1/out.txt:End-to-end rate ..................................... 133,851
> messages/s
> 1m1/out.txt: 50% ........ 1 ms 99.90% ........ 3 ms
> 1m2/out.txt:End-to-end rate ...................................... 59,011
> messages/s
> 1m2/out.txt: 50% ........ 2 ms 99.90% ........ 8 ms
> 1m3/out.txt:End-to-end rate ...................................... 42,146
> messages/s
> 1m3/out.txt: 50% ........ 3 ms 99.90% ....... 11 ms
> 1m4/out.txt:End-to-end rate ...................................... 32,415
> messages/s
> 1m4/out.txt: 50% ........ 4 ms 99.90% ....... 13 ms
> The output (config, logs and scrapes) from a 1000-message, 4-router tracing
> run is included, as well as the script to generate new data. Runs of 10k
> messages are feasible, but the HTML gets large and slow to view. From my
> experiments the results are similar.
> From file:scrape.html#c_connections the sender connection is starved of
> credit far more than any other connection: 20x more starvation instances, 40x
> longer total starvation and 100x longer wait for initial credit.
> Overall the flow of credit is slower than the flow of messages, and each
> additional router is reducing the throughput of credits, which reduces
> message throughput.
> Observations:
> - initial credit delay is excessive (100ms in this case when worst-case
> message latency is 33ms), something is wrong there.
> - inter-router link credit is small (250) compared to application credit
> (1000). Giving full credit to a sender creates a credit sharing problem,
> but we could give full credit to the inter-router links.
> - re-evaluate our credit sharing strategy to perform better in the common
> unshared case.
> Extracts from scrape:
> ◊ 2019-01-23 13:55:16.524477 D0#141 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (0,1000)
> ◊ 2019-01-23 13:55:16.633700 A0#287 1 [A0_6] -> [] quiver-sender-3db6ad3f
> flow [0,0] (0,250)
> Initial delay 109ms, much worse than worst-case message latency of 33ms
> ◊ 2019-01-23 13:55:16.639758 D0#153 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (3,1000)
> ◊ 2019-01-23 13:55:16.642682 A0#543 1 [A0_6] -> [] quiver-sender-3db6ad3f
> flow [0,0] (168,85)
> ◊ 2019-01-23 13:55:16.645205 D0#163 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (5,1000)
> ◊ 2019-01-23 13:55:16.645448 D0#167 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (6,1000)
> ◊ 2019-01-23 13:55:16.646510 A0#713 1 [A0_6] <- [] quiver-sender-3db6ad3f
> transfer [0,0] (252) transfer_281 - 158 bytes no more credit (accepted
> settled 0.028323 S)
> ◊ 2019-01-23 13:55:16.647142 D0#193 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (7,1000)
> ◊ 2019-01-23 13:55:16.647198 D0#195 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (10,1000)
> ◊ 2019-01-23 13:55:16.647915 D0#214 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (16,1000)
> ◊ 2019-01-23 13:55:16.648060 D0#217 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (25,1000)
> ◊ 2019-01-23 13:55:16.651294 D0#239 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (28,1000)
> ◊ 2019-01-23 13:55:16.652235 D0#257 4 [D0_3] <- [] quiver-receiver-2ebb30e5
> flow [0,0] (41,1000)
> ◊ 2019-01-23 13:55:16.654294 A0#802 1 [A0_6] -> [] quiver-sender-3db6ad3f
> flow [0,0] (253,9) credit restored
> Here we see that the receiver has given 9 credit responses in the same time
> that the front router only gave 2. Either the router is slow to forward
> messages, or it's not giving back credit quickly when it does (or both) See
> flow.txt for the complete history of flow events at the sender and receiver,
> scrape.html for the complete history of everything.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
