Stream aborted if server doesn't immediately provide a chunk

[TheOriginalMrWolf]

Hi,

Thanks for the big refactor & enabling digest auth.

I'm using this library to monitor an IP camera's (Amcrest AD410) event stream. This serves a 'heartbeat' event every 5 mins + events as & when 'interesting' things occur (ie motion).

Unfortunately this means that the camera doesn't immediately provide a chunk when multipart-decoder initially connects, so a timeout occurs & the stream is immediately aborted.

On connection (after digest authentication):

• camera responds with HTTP200
• camera opens the TCP stream
• camera does not immediately send a chunk - the delay before first chunk is sent could be up to 5 mins in this case
• multipart-decoder immediately times out because timestampLastChunk=0
• multipart-decoder drops the connection

Call abort on the abort request controller
Stream aborted event
Stop reading chunks from the response stream (because the active response has been aborted)

I believe what should be happening instead is that on initial connection, if server responds with HTTP 200, then multipart-decoder should wait for the full timeout period before dropping the connection even if no chunk is sent. Timeout should be re-triggered on receiving the first chunk.

I have set httpRequestTimeout: 360000

Workaround at the moment seems to be to continuously poll the camera every second or so until it generates an event 'close enough' to the connection to be detected. Unfortunately this can take quite a while until multipart decoder 'hooks up' and stays in 'streaming' mode.

Hope you can help!

[TheOriginalMrWolf]

curl happily connects & hangs around showing events as they arrive, regardless of how long it takes

[bartbutenaers]

Hi @TheOriginalMrWolf,

Thanks for the detailed description! That really helps...

Your suggestion absolutely makes sense, so I have implemented it like that (see here).

It would be nice if you could test this in your setup, to make sure your issue is solved. When ok, I will publish it on npm afterwards. You can install the fix directly from this Github account (if you have git installed), by executing following command from within your .node-red folder:

npm install bartbutenaers/node-red-contrib-multipart-stream-decoder

And don't forget to restart your Node-RED of course.

Bart

[TheOriginalMrWolf]

Works perfectly, thanks @bartbutenaers!

Whilst I'm at it - maybe another couple of suggestions if I may... 😁

1. Timeout setting - would strongly prefer this to be a per-connection node configuration rather than a global setting if at all possible. For instance, some servers only emit an event very infrequently (eg: once per hour) - I'd rather not set a global 1 hour http connection timeout as that could then significantly impact other functions (ie pushing data to another REST API - which I don't want to wait an hour for before failing...)
2. On timeout/stopped status - if possible could this please be emitted as an (error) status message? I'm currently using status node but this adds unnecessary complexity & complicates the flow

Thanks again!

[bartbutenaers]

@TheOriginalMrWolf, Again two valid remarks...

1. Timeout setting

I have now added two options on the config screen:

The part timeout should occur when no part arrives within that time. While the request timeout should occur when the server doesn't respond with that time when making the initial request.

2. On timeout/stopped status

I have made some changes to act differently on a part timeout:

• The node status should become "part timeout"
• The error should become visible in the Debug sidebar.
• You should be able to intercept it with a Catch node.
• An error msg should be send on the second output with payload "part timeout occured"

Note that I haven't tested any or this. Not my usual approach, but I have a severe lack of free time. So I would appreciate a lot if you could do some testing about those new features, and let me know if it is ok or not.

Thanks and have a nice sunday (evening for you) !!

[bartbutenaers]

Note that I don't use the httpRequestTimeout setting anymore. So a breaking change unfortunately...

[bartbutenaers]

I have added a fix for when no timeout is specified in the config screen.

[TheOriginalMrWolf]

That's brilliant, thank you. Like you, a bit of a time-crunch this week. Will test in the next couple of days & get back to you.

Cheers!

[TheOriginalMrWolf]

Hi @bartbutenaers - seems to be working, thank you!

Only one small issue - documentation (help) and log messages say that the timeouts are in seconds, however the implementation is in milliseconds. I guess you've overlooked the conversion back/forth?

[TheOriginalMrWolf]

Plus another couple of questions -

If the part timeout < req timeout then the part timeout will always trigger, and this can be a little... unexpected (ie: doesn't cater for scenarios where there might be a longer 'setup' time before events start flowing -- ie after connect it might take up to 5 minutes before the first event is received, but after that then expect event updates every 10 seconds).

I suggest either in config don't let part < req; OR only start the part timeout logic after the first part has been received.

Looking through code... why check part timeout every second? Why not just reset the part timeout timer every time a part is received (which also would help with the above suggestion). For instance, every time a part is received, if there is an existing timeout then clear that timeout & set another timeout (this makes the timeout logic dead simple - no need for any checks. If the timeout code runs then simply stop the stream; plus also - this automatically only sets up that timeout once the first part is received).

Or, if you don't like that, then maybe just start the setInterval after the first part is received?

[bartbutenaers]

@TheOriginalMrWolf, Thanks for testing!

• I indeed forgot to convert the timeouts to seconds. Need to change that.
• And I will try to add the time units in the config screen to make it more ckear.
• I did the timeout checking initially look you say (so no loop every second, but a new timer when a part arrived), but don't know anymore why I changed to a check every second.
• I "think" there is a misunderstanding. The request timeout is the time within which I expect a response with status 200 from the server. It is not the time within I expect the first part to arrive. Does this makes sense to you?

[TheOriginalMrWolf]

I indeed forgot to convert the timeouts to seconds. Need to change that. And I will try to add the time units in the config screen to make it more clear.

Super, thanks. BTW - this is why I always put the unit of measure in the variable name (eg timeoutMs vs timeoutSecs) because otherwise I always make those sorts of mistakes! 😂

I "think" there is a misunderstanding. The request timeout is the time within which I expect a response with status 200 from the server. It is not the time within I expect the first part to arrive. Does this makes sense to you?

Indeed - I misunderstood. In my mind there were three steps, but I didn't think this through nor communicate that properly -

1. Initial connection to server (HTTP 200 response)
2. Delay to first part (ie after some sort of 'setup' process before sending the first part)
3. Delay for every part thereafter (ie once events start flowing)

In retrospect this probably over-complicates things, so I think your implementation as described above is probably the most practical.

Maybe just make that a little clearer in the instructions & maybe check that part timeout > req timeout ?

[TheOriginalMrWolf]

However, in that case, maybe there's a problem with the implementation @bartbutenaers?

What I'm seeing is that if I set req timeout to, say, 15000ms & part timeout to 600000ms; and if the first part only comes, say, 45000ms after the connection is established, then even though I get the HTTP200 immediately on successfully connecting (well within the 15000ms), the node still times out before the first part arrives.

Or am I still misunderstanding something? 🤷‍♂️

[bartbutenaers]

@TheOriginalMrWolf,

I have added some labels in the config screen to make the units more visible:

And in the code I multiply now the timeout values with 1000. So if you could install the latest version from Github, to make sure we use the same version.

I have no clue why the node timeouts in your latter example. Unfortunately I have no setup to reproduce that error. So hopefully you can provide me some more information to get it solved. My node contains some debugLog statements that are activated when you set this option in the config screen:

You can share your log content here if you like. Or if you want, you can also add some extra debugLog statements to your local .../.node-red/node_modules/node-red-contrib-multipart-stream-decoder/multipart_decoder.js file to get extra information.

[TheOriginalMrWolf]

Hi @bartbutenaers - sorry it's taken me so long to respond. Work & life... :/

I've tested the new version & the seconds translation seems to be working, thank you.

Re the timeout - my preliminary investigation suggests that with multipart forms if you set a request timeout with Axios, even though you get the HTTP 200 response immediately the timeout is still active until the first multipart chunk is received. If that chunk isn't received within the given timeout then Axios raises a stream abort event.

So, for example, let's say I set a request timeout of 10s and a part timeout of 5 minutes. I make the request & immediately receive the HTTP 200 response. If the first multipart chunk comes in, say, 3 seconds, then no problem. If on the other hand the first chunk were to only come after 1 minute, then the previously set 10s timeout would still kick in and Axios would abort the stream (despite having previously received the HTTP 200 response) before that chunk arrives.

Does that make sense?

Maybe this should be an issue raised with the Axios maintainers?

[bartbutenaers]

@TheOriginalMrWolf, No problem. Me also complete lack of free time...

I see in this StackOverflow discussion that this is a know Axios issue: the axios timeout is response timeout not connection timeout.

I am not going to implement their workaround, because they use Cancel tokens while I use newer Axios AbortController mechanism already.

Instead, I think I simply need to do it like this (instead of using the Axios timeout parameter):

1. Before starting the request, I need to start a timer that calls the stopCurrentResponseStream function when the connection is not opened after the specified connection timeout interval.
2. Then the request is being executed.
3. When I get a connection (status 200 or whatever), I need to clear that timer to make sure it doesn't stop the current stream.
4. When I don't get a connection in time, the timer will be triggered and it will close the connection (by calling the Axios Abort controller).

My time is up for today. Will try to have a look at this tomorrow evening...

[bartbutenaers]

@TheOriginalMrWolf I have implemented the custom connection timeout check. Would be nice if you could install the latest version from Github and do some testing. Now off to the daily job ;-)

[bartbutenaers]

Hi @TheOriginalMrWolf, I would appreciate if you could test this a bit. Because I had made the changes on my master branch, because your original question was rather simple so I thought this would have been finished very quickly. Would like to get this published as soon as possible, in case I need to implement other fixes for other issues. Thanks!!

[TheOriginalMrWolf]

Hi @bartbutenaers,

Seems to work for the most part, however starting the node has some interesting issues. Essentially, the connection appears to be successfully made, but then stopped pretty immediately with a call abort. My error checking node then picks up that this node is now in stopped state so restarts the connection. The second connection attempt appears to successfully realise that the connection is made and hangs around.

NodeRed UI - debug tag, show a red error message: "canceled"

Docker logs for NodeRed show:

MULTIPART STREAM : Starting a new stream (with an abortRequestController)
MULTIPART STREAM : Connection timeout timer stopped
MULTIPART STREAM : Call abort on the abort request controller
MULTIPART STREAM : Error while sending request: CanceledError: canceled
MULTIPART STREAM : Connection timeout timer stopped
MULTIPART STREAM : Call abort on the abort request controller
MULTIPART STREAM : The request timer has been started with a timeout of 15 seconds
MULTIPART STREAM : Starting a new stream (with an abortRequestController)
MULTIPART STREAM : Connection timeout interval stopped, because connection established
MULTIPART STREAM : Timeout check interval started
MULTIPART STREAM : Start reading chunks from the response stream

[bartbutenaers]

@TheOriginalMrWolf, Thanks for testing!

Unfortunately I have no clue what could cause this. If you have some more information, that would be very welcome!

I also think there must be some log lines before the lines you shared? Because the second line (Connection timeout timer stopped) can only occur if a timer has been started in advance.

I have added a small update to this repo, so that the times are added to the log:

MULTIPART STREAM (20:58:11.290): Call abort on the abort request controller
MULTIPART STREAM (20:58:11.296): Stream aborted event
MULTIPART STREAM (20:58:11.300): Stop reading chunks from the response stream (because the active response has been aborted)

Hopefully that learns us something about the timers and timeouts...

[bartbutenaers]

@TheOriginalMrWolf,

It would be nice if you could help me to finalize this version. Because I have now ended with a lot of changes, but I can't publish it because it is not completed. And it is difficult for me to keep track of what I have changed and still need to change, because I am doing a lot of other Node-RED stuff meanwhile...

Thanks!

[TheOriginalMrWolf]

Hi @bartbutenaers - I will have some time over Easter & will look at it then. I'm pretty sure I captured the entirety of MULTIPART STREAM log entries. The issue only occurs immediately on start of the node.

[bartbutenaers]

@TheOriginalMrWolf Ok thanks!! Weird that I don't get it at startup then. But let's wait and see...