Hi, Thank you so much for the responses. I will be following up with that github issue regarding to the Session closed with error code 2 . For the stream end and server callback, I think I understand enough from your replies. Thanks a lot!
On Friday, January 5, 2024 at 1:40:08 AM UTC+8 Michael Lumish wrote: > 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.thi...@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+u...@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/2dd4b536-a30d-4f49-8884-d4e9576fa055n%40googlegroups.com.
