cancelling server streaming call does not clear deadlineTimer

[alexander-fenster]

Problem description

When a client cancels a server streaming call with stream.cancel(), the server keeps waiting for deadlineTimer that is set in call.js:331:

this.deadlineTimer = setTimeout(handleExpiredDeadline, timeout, this);

I verified that setting a small deadline makes it exit sooner.

Reproduction steps

In a standalone local server instance, make a server streaming call, then shutdown the server. Note that the Node.js process is still waiting for that timer.

Environment

• OS name, version and architecture: [e.g. Linux Ubuntu 18.04 amd64] Linux Debian 6.1.20
• Node version [e.g. 8.10.0] 16.15.0
• Node installation method [e.g. nvm] direct download
• If applicable, compiler version [e.g. clang 3.8.0-2ubuntu4] N/A
• Package name and version [e.g. [email protected]] @grpc/[email protected]

Additional context

Trace logs:

D 2023-05-18T23:52:24.053Z | retrying_call | [1] ended with status: code=1 details="Cancelled on client"
D 2023-05-18T23:52:24.053Z | resolving_call | [0] ended with status: code=1 details="Cancelled on client"
D 2023-05-18T23:52:24.054Z | resolving_call | [0] Received status
D 2023-05-18T23:52:24.054Z | load_balancing_call | [2] Received status
D 2023-05-18T23:52:24.054Z | resolving_call | [0] Received status
D 2023-05-18T23:52:24.066Z | subchannel_call | [3] HTTP/2 stream closed with code 8
D 2023-05-18T23:52:24.071Z | server_call | Request to method /google.bigtable.v2.Bigtable/ReadRows stream closed with rstCode 8
D 2023-05-18T23:52:24.074Z | transport | (42) ::1:1234 connection closed by GOAWAY with code 0
D 2023-05-18T23:52:24.074Z | subchannel | (38) ::1:1234 READY -> IDLE
D 2023-05-18T23:52:24.074Z | subchannel_refcount | (38) ::1:1234 refcount 2 -> 1
D 2023-05-18T23:52:24.074Z | pick_first | READY -> IDLE
D 2023-05-18T23:52:24.074Z | resolving_load_balancer | dns:localhost:1234 READY -> IDLE
D 2023-05-18T23:52:24.074Z | connectivity_state | (36) dns:localhost:1234 READY -> IDLE
D 2023-05-18T23:52:24.074Z | transport | (43) 127.0.0.1:1234 connection closed by GOAWAY with code 0
D 2023-05-18T23:52:24.074Z | subchannel | (39) 127.0.0.1:1234 READY -> IDLE
D 2023-05-18T23:52:24.076Z | transport | (42) ::1:1234 session closed
D 2023-05-18T23:52:24.077Z | transport | (43) 127.0.0.1:1234 session closed
D 2023-05-18T23:52:24.978Z | resolving_load_balancer | dns:localhost:1234 IDLE -> IDLE
D 2023-05-18T23:52:24.979Z | connectivity_state | (36) dns:localhost:1234 IDLE -> IDLE

[murgatroid99]

The fix for this has been published in version 1.9.0.