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.
