>From that trace log, it looks like this is the same error as in https://github.com/grpc/grpc-node/issues/2625. It would be helpful to consolidate further discussions of this error in that issue.
You do need a 'status' event handler if you want to always see trailers,
and it looks like you do want that in your code.
On Thu, Jan 4, 2024 at 9:33 AM Kyaw Thit Lwin <kyaw.thitlwin...@gmail.com>
wrote:
> Hi,
> first of all, thank you so much for your response and sorry for the
> late reply.
>
> The below are the logs from client and server regarding to the
> original error, 13 INTERNAL: Received RST_STREAM with code 2 triggered by
> internal client error: Session closed with error code 2.
>
> *Client*
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | subchannel_call | [4139]
> sending data chunk of length 22
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | load_balancing_call | [4138]
> write() called with message of length 22
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | subchannel_call | [4139]
> write() called with message of length 22
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | subchannel_call | [4139]
> sending data chunk of length 22
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | load_balancing_call | [4138]
> halfClose called
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | subchannel_call | [4139]
> end() called
> D 2024-01-04T15:33:21.496Z | v1.9.13 965056 | subchannel_call | [4139]
> calling end() on HTTP/2 stream
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | transport | (3)
> 127.0.0.1:50052 connection closed by GOAWAY with code 2 and data undefined
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | subchannel | (2)
> 127.0.0.1:50052 READY -> IDLE
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | subchannel_refcount | (2)
> 127.0.0.1:50052 refcount 2 -> 1
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | pick_first | READY -> IDLE
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | resolving_load_balancer |
> dns:localhost:50052 READY -> IDLE
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | connectivity_state | (1)
> dns:localhost:50052 READY -> IDLE
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | dns_resolver | resolution
> update delayed by "min time between resolutions" rate limit
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | resolving_load_balancer |
> dns:localhost:50052 IDLE -> CONNECTING
> D 2024-01-04T15:33:21.497Z | v1.9.13 965056 | connectivity_state | (1)
> dns:localhost:50052 IDLE -> CONNECTING
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | subchannel_call | [4139]
> Node error event: message=Session closed with error code 2
> code=ERR_HTTP2_SESSION_ERROR errno=Unknown system error undefined
> syscall=undefined
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | subchannel_call | [4139]
> HTTP/2 stream closed with code 2
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | subchannel_call | [4139]
> ended with status: code=13 details="Received RST_STREAM with code 2
> triggered by internal client error: Session closed with error code 2"
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | load_balancing_call | [4138]
> Received status
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | load_balancing_call | [4138]
> ended with status: code=13 details="Received RST_STREAM with code 2
> triggered by internal client error: Session closed with error code 2"
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | retrying_call | [4137]
> Received status from child [4138]
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | retrying_call | [4137]
> state=TRANSPARENT_ONLY handling status with progress PROCESSED from child
> [4138] in state ACTIVE
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | retrying_call | [4137] ended
> with status: code=13 details="Received RST_STREAM with code 2 triggered by
> internal client error: Session closed with error code 2"
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | resolving_call | [4136]
> Received status
> D 2024-01-04T15:33:21.498Z | v1.9.13 965056 | resolving_call | [4136]
> ended with status: code=13 details="Received RST_STREAM with code 2
> triggered by internal client error: Session closed with error code 2"
> Received error Error: 13 INTERNAL: Received RST_STREAM with code 2
> triggered by internal client error: Session closed with error code 2
> timestamp expected but doesn't exist in trailer
>
>
> *Server*D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call |
> Received message of length 17
> Received request {"message":"hello metatdata"}
> D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call | Received
> message of length 17
> Received request {"message":"hello metatdata"}
> D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call | Received
> message of length 17
> Received request {"message":"hello metatdata"}
> D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call | Received end
> of stream
> Call end!
> D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call | Request to
> method /grpc.examples.echo.Echo/ClientStreamingEcho ended with status code:
> OK details: OK
> D 2024-01-04T15:33:21.495Z | v1.9.13 964523 | server_call | Request to
> method /grpc.examples.echo.Echo/ClientStreamingEcho stream closed with
> rstCode 0
> D 2024-01-04T15:33:21.496Z | v1.9.13 964523 | server | (1) Received call
> to method /grpc.examples.echo.Echo/ClientStreamingEcho at address null
> D 2024-01-04T15:33:21.496Z | v1.9.13 964523 | server_call | Request to
> /grpc.examples.echo.Echo/ClientStreamingEcho received headers
> {"timestamp":["2024-01-04T15:33:21.496Z"],"grpc-accept-encoding":["identity,deflate,gzip"],"accept-encoding":["identity"],"user-agent":["grpc-node-js/1.9.13"],"content-type":["application/grpc"],"te":["trailers"]}
> Timestamp from metadata:
> 0. 2024-01-04T15:33:21.496Z
> D 2024-01-04T15:33:21.496Z | v1.9.13 964523 | server_call | Received
> message of length 17
> Received request {"message":"hello metatdata"}
> D 2024-01-04T15:33:21.497Z | v1.9.13 964523 | server_call | Request to
> method /grpc.examples.echo.Echo/ClientStreamingEcho stream closed with
> rstCode 7
>
> And from your reply, *On the client side, you do need to pass a function
> for the callback parameter, but it doesn't need to do anything*, *it
> means that I don't necessarily need to listen to `status` event on the
> client side, right?*
>
> Thank you so much.
> On Thursday, January 4, 2024 at 5:52:50 AM UTC+8 Michael Lumish wrote:
>
>> You do need to call the callback on the server to end the call. If I am
>> understanding correctly that those trace logs are from the test where you
>> removed that call. In that case they will not be helpful. It would be
>> helpful to have the logs that show the original error you were experiencing.
>>
>> On the client side, you do need to pass a function for the callback
>> parameter, but it doesn't need to do anything.
>>
>> On Tue, Jan 2, 2024 at 10:47 PM Kyaw Thit Lwin <kyaw.thi...@gmail.com>
>> wrote:
>>
>>> Hi guys, I have some confusions about grpc-js client streaming. Sorry
>>> for the long question.
>>>
>>> I have encountered multiple errors, 13 INTERNAL: Received
>>> RST_STREAM with code 2 triggered by internal client error: Session closed
>>> with error code 2 during the load testing. May I know what could
>>> trigger this error?
>>>
>>> I have the following grpc server and client implementation,
>>> referencing from
>>> *https://github.com/grpc/grpc-node/blob/master/examples/metadata/server.js
>>> <https://github.com/grpc/grpc-node/blob/master/examples/metadata/server.js>*.
>>>
>>> *Client*
>>> function clientStreamingWithMetadata(client, message) {
>>> return new Promise((resolve, reject) => {
>>> const requestMetadata = new grpc.Metadata();
>>> requestMetadata.set('timestamp', new Date().toISOString());
>>> const call = client.clientStreamingEcho(requestMetadata, (error, value)
>>> => {
>>> if (error) {
>>> console.log(`Received error ${error}`);
>>> return;
>>> }
>>> });
>>> call.on('status', status => {
>>> const timestamps = status.metadata.get('timestamp');
>>> if (timestamps.length == 0) {
>>> console.error("timestamp expected but doesn't exist in trailer");
>>> }
>>> resolve();
>>> });
>>> for (let i = 0; i < STREAMING_COUNT; i++) {
>>> call.write({message});
>>> }
>>> call.end();
>>> });
>>> }
>>>
>>>
>>> *Server*
>>> function clientStreamingEcho(call, callback) {
>>> const incomingTimestamps = call.metadata.get('timestamp');
>>> if (incomingTimestamps.length > 0) {
>>> console.log('Timestamp from metadata:');
>>> for (const [index, value] of incomingTimestamps.entries()) {
>>> console.log(` ${index}. ${value}`);
>>> }
>>> }
>>>
>>> let lastReceivedMessage = '';
>>> call.on('data', value => {
>>> console.log(`Received request ${JSON.stringify(value)}`);
>>> lastReceivedMessage = value.message;
>>> });
>>> call.on('end', () => {
>>> console.log("Call end!")
>>> const outgoingTrailers = new grpc.Metadata();
>>> outgoingTrailers.set('timestamp', new Date().toISOString());
>>> callback(null, {message: lastReceivedMessage}, outgoingTrailers);
>>> });
>>> }
>>>
>>> May I also know that do I really need to listen back to the server
>>> callback on stream end initiated by client side?
>>>
>>> I tried running the code by removing the server callback on stream end
>>> event and remove the call.on('status') listener on the client side.
>>> Then the client stream doesn't seem to be ended even after call.end() and
>>> keep pinging the server. These are the logs from server and client.
>>>
>>> *Client*
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 354656 | subchannel_call | [3]
>>> write() called with message of length 32
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 354656 | subchannel_call | [3]
>>> sending data chunk of length 32
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 354656 | load_balancing_call | [2]
>>> halfClose called
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 354656 | subchannel_call | [3]
>>> end() called
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 354656 | subchannel_call | [3]
>>> calling end() on HTTP/2 stream
>>> D 2024-01-03T04:11:10.277Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Sending ping with timeout 20000ms
>>> D 2024-01-03T04:11:10.277Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Received ping response
>>> D 2024-01-03T04:11:10.277Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Starting keepalive timer for 1000ms
>>> D 2024-01-03T04:11:11.278Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Sending ping with timeout 20000ms
>>> D 2024-01-03T04:11:11.278Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Received ping response
>>> D 2024-01-03T04:11:11.278Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Starting keepalive timer for 1000ms
>>> D 2024-01-03T04:11:12.279Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Sending ping with timeout 20000ms
>>> D 2024-01-03T04:11:12.279Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Received ping response
>>> D 2024-01-03T04:11:12.279Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Starting keepalive timer for 1000ms
>>> D 2024-01-03T04:11:13.281Z | v1.9.13 354656 | keepalive | (3)
>>> 127.0.0.1:50052 Sending ping with timeout 20000ms
>>>
>>> *Server*
>>> D 2024-01-03T04:11:09.278Z | v1.9.13 352893 | server_call | Received
>>> message of length 27
>>> Received request {"message":"this is examples/metadata"}
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 352893 | server_call | Received
>>> message of length 27
>>> Received request {"message":"this is examples/metadata"}
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 352893 | server_call | Received
>>> message of length 27
>>> Received request {"message":"this is examples/metadata"}
>>> D 2024-01-03T04:11:09.279Z | v1.9.13 352893 | server_call | Received end
>>> of stream
>>> Call end!
>>> D 2024-01-03T04:11:26.004Z | v1.9.13 352893 | server_call | Request to
>>> method /grpc.examples.echo.Echo/ClientStreamingEcho stream closed with
>>> rstCode 8
>>>
>>> Thank you so much and appreciated any explanation.
>>>
>>> --
>>> You received this message because you are subscribed to the Google
>>> Groups "grpc.io" group.
>>> To unsubscribe from this group and stop receiving emails from it, send
>>> an email to grpc-io+u...@googlegroups.com.
>>> To view this discussion on the web visit
>>> https://groups.google.com/d/msgid/grpc-io/9b6662fe-d368-45de-a454-a0273f0c1c09n%40googlegroups.com
>>> <https://groups.google.com/d/msgid/grpc-io/9b6662fe-d368-45de-a454-a0273f0c1c09n%40googlegroups.com?utm_medium=email&utm_source=footer>
>>> .
>>>
>> --
> You received this message because you are subscribed to the Google Groups "
> grpc.io" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to grpc-io+unsubscr...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/grpc-io/a802e930-8ffa-4c1c-a24b-2f2f81e8d353n%40googlegroups.com
> <https://groups.google.com/d/msgid/grpc-io/a802e930-8ffa-4c1c-a24b-2f2f81e8d353n%40googlegroups.com?utm_medium=email&utm_source=footer>
> .
>
--
You received this message because you are subscribed to the Google Groups
"grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to grpc-io+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/grpc-io/CAPK2-4ffWGRpyZMym6b%3DQkFeNTs9tEnKmBqcmX%2BVq6ruoU5rog%40mail.gmail.com.
smime.p7s
Description: S/MIME Cryptographic Signature
