Unusual throttling behavior in DDS

[elliette]

There is odd throttling behavior on some of the requests sent from DevTools when running DWDS with spawnDds set to true.

I’m measuring the time for each of the stream requests here to complete.

With spawnDds set to true, the first few requests complete relatively quickly (100 ms), and the others are significantly slower (300 ms).

STREAM Debug: 132 ms
STREAM Extension: 134 ms
STREAM GC: 317 ms
STREAM Isolate: 317 ms
STREAM Logging: 317 ms
STREAM Stderr: 317 ms
STREAM Stdout: 318 ms
STREAM Timeline: 318 ms
STREAM VM: 318 ms
STREAM Service: 318 ms

With spawnDds set to false, all of the requests take around 200 ms.

STREAM Debug: 167 ms
STREAM Extension: 167 ms
STREAM GC: 199 ms
STREAM Isolate: 200 ms
STREAM Logging: 201 ms
STREAM Stderr: 201 ms
STREAM Stdout: 202 ms
STREAM Timeline: 202 ms
STREAM VM: 203 ms
STREAM Service: 206 ms

[annagrin]

/cc @bkonyi

BTW the first few shorter streamListen calls are short because they are cached by DDS.

[bkonyi]

@elliette can you try adding a 1s delay between the stream listen requests and see if those times go down? There's some synchronization logic around the stream management which might be slowing things down.

[elliette]

Hi! Sure, here are the times with and without a 1 second delay between them. It does look like the times go down.

Without a delay:

--- STREAM Debug: 129 ms
--- STREAM Extension: 131 ms
--- STREAM GC: 319 ms
--- STREAM Isolate: 325 ms
--- STREAM Logging: 326 ms
--- STREAM Stderr: 326 ms
--- STREAM Stdout: 326 ms
--- STREAM Timeline: 326 ms
--- STREAM VM: 327 ms
--- STREAM Service: 327 ms
STREAMS TOTAL: 327 ms

With a 1 second delay:

--- STREAM Debug: 101 ms
--- STREAM Extension: 103 ms
--- STREAM GC: 96 ms
--- STREAM Isolate: 104 ms
--- STREAM Logging: 99 ms
--- STREAM Stderr: 95 ms
--- STREAM Stdout: 111 ms
--- STREAM Timeline: 159 ms
--- STREAM VM: 168 ms
--- STREAM Service: 104 ms
STREAMS TOTAL: 11151 ms

[bkonyi]

Yeah, that makes sense then. We're seeing some lock contention here. I can probably make this synchronization a bit smarter so we only ever lock around streamListen when there's an outstanding streamCancel, since streamCancel can put us in a bad state if it runs while we're in the middle of processing a streamListen on the same stream.