NodeError - write after end
andreslavariega opened this issue · 4 comments
Hello I have this error, it is a sporadic error, it usually happens when the iteration is in progress.
"type": "**NodeError**",
"message": "**write after end**",
I use asterisk 16, mosquitto version 1.5.7, yarn run v1.22.19, node v14.19.3.
Thanks for your support.
[1655145086834] INFO (Dialogflow-AudioServer/2182 on desarrollo-rtp-server): Got a message sending to dialogflow-asterisk/1655145077.103/events
[1655145086857] ERROR (Dialogflow-AudioServer/2182 on desarrollo-rtp-server): Got an error from dialogflow
id: "1655145077.103"
err: {
"type": "NodeError",
"message": "write after end",
"stack":
Error [ERR_STREAM_WRITE_AFTER_END]: write after end
at new NodeError (internal/errors.js:322:7)
at ClientHttp2Stream.Writable.write (internal/streams/writable.js:292:11)
at /usr/src/asterisk-dialogflow-rtp-audioserver/node_modules/@grpc/grpc-js/build/src/call-stream.js:603:38
at runMicrotasks (<anonymous>)
at processTicksAndRejections (internal/process/task_queues.js:95:5)
"code": "ERR_STREAM_WRITE_AFTER_END"
When does this happen? Looks like we're writing to the GRPC dialogflow stream after it's been closed...
Sorry for the delay, I was doing more testing and connecting to a sip trunk.
In some tests I see this log, it happens when it takes a while to respond by voice.
[1655420972453] INFO (Asterisk-Dialogflow-ARI-Bridge/9629 on matrix): got a message
topic: "dialogflow-asterisk/1655420962.304/events"
payload: {
"transcript": {
"speechWordInfo": [],
"messageType": "END_OF_SINGLE_UTTERANCE",
"transcript": "",
"isFinal": false,
"confidence": 0,
"stability": 0,
"speechEndOffset": {
"seconds": "9",
"nanos": 30000000
}
},
"intent": null
}
[1655420972522] INFO (Asterisk-Dialogflow-ARI-Bridge/9629 on matrix): got a message
topic: "dialogflow-asterisk/1655420962.304/events"
payload: {
"transcript": null,
"intent": {
"fulfillmentMessages": [],
"outputContexts": [],
"queryText": "",
"speechRecognitionConfidence": 0,
"action": "",
"parameters": null,
"allRequiredParamsPresent": false,
"fulfillmentText": "",
"webhookSource": "",
"webhookPayload": null,
"intent": null,
"intentDetectionConfidence": 0,
"diagnosticInfo": null,
"languageCode": "es",
"sentimentAnalysisResult": null,
"knowledgeAnswers": null
}
}
(node:9629) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'fields' of null
at Bridge.<anonymous> (/usr/src/asterisk-dialogflow-ari-bridge/index.js:86:63)
at Bridge.emit (events.js:400:28)
at Bridge.receivedDialogFlowEvent (/usr/src/asterisk-dialogflow-ari-bridge/lib/Bridge.js:31:14)
at MqttClient.<anonymous> (/usr/src/asterisk-dialogflow-ari-bridge/index.js:29:28)
at MqttClient.emit (events.js:400:28)
at MqttClient._handlePublish (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/async-mqtt/node_modules/mqtt/lib/client.js:1547:12)
at MqttClient._handlePacket (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/async-mqtt/node_modules/mqtt/lib/client.js:535:12)
at work (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/async-mqtt/node_modules/mqtt/lib/client.js:438:12)
at Writable.writable._write (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/async-mqtt/node_modules/mqtt/lib/client.js:452:5)
at doWrite (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/readable-stream/lib/_stream_writable.js:409:139)
at writeOrBuffer (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/readable-stream/lib/_stream_writable.js:398:5)
at Writable.write (/usr/src/asterisk-dialogflow-ari-bridge/node_modules/readable-stream/lib/_stream_writable.js:307:11)
at Socket.ondata (internal/streams/readable.js:731:22)
at Socket.emit (events.js:400:28)
at addChunk (internal/streams/readable.js:293:12)
at readableAddChunk (internal/streams/readable.js:267:9)
(node:9629) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)
Hi, i review the log and I comparated with mqtt events and i see this event from dialogFlow.
This happens when I have a call established, and the audio on the dialogflow side is long (maybe 15 seconds). When dialogFlow finishes speaking I want to respond and that is when the error "ERR_STREAM_WRITE_AFTER_END" appears.
In my conf is this.
singleUtterance: true.
[1694809334507] INFO (Dialogflow-AudioServer/29856 on desarrollo-rtp-server): Dialogflow data
id: "1694809302.1293"
body: {
"transcript": {
"speechWordInfo": [],
"messageType": "END_OF_SINGLE_UTTERANCE",
"transcript": "",
"isFinal": false,
"confidence": 0,
"stability": 0,
"speechEndOffset": {
"seconds": "9",
"nanos": 30000000
}
},
"intent": null
}
and after I see this log
id: "1694809302.1293"
err: {
"type": "NodeError",
"message": "write after end",
"stack":
Error [ERR_STREAM_WRITE_AFTER_END]: write after end
at new NodeError (internal/errors.js:322:7)
at ClientHttp2Stream.Writable.write (internal/streams/writable.js:292:11)
at /usr/src/asterisk-dialogflow-rtp-audioserver/node_modules/@grpc/grpc-js/build/src/call-stream.js:603:38
at runMicrotasks (<anonymous>)
at processTicksAndRejections (internal/process/task_queues.js:95:5)
"code": "ERR_STREAM_WRITE_AFTER_END"
}
Yeah it looks like we're writing to the dialogflow stream after its finished - the streams are short in length so we have to make sure we write to the right one at the right time otherwise we end up writing to a stream object thats ended. I haven't got much time to work on this at the moment. First thing to look at would be whether dialogflow expects less than 59 seconds of audio now? https://github.com/nimbleape/asterisk-dialogflow-rtp-audioserver/blob/master/lib/DialogFlowConnector.js#L51-L142 gets called every 59 seconds by the setupTimer function