Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Plugin does not start fresh connection after Curl timeout #75

Closed
Rayn0r opened this issue May 20, 2021 · 2 comments
Closed

Plugin does not start fresh connection after Curl timeout #75

Rayn0r opened this issue May 20, 2021 · 2 comments

Comments

@Rayn0r
Copy link

Rayn0r commented May 20, 2021 •
edited
Loading

I recently "upgraded" my setup with a Kathrein EXIP 418.
It seems that the box is rather allergic to EPG scans. After a while the device seems to "stall" for around 15 seconds before talking to VDR again.
When this happens, the log shows something like this:

May 20 11:46:10 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Timeout was reached (28)
May 20 11:46:10 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:10 server vdr[28570]: [28609] SATIP-ERROR: Pid update failed - retuning [device 2]
May 20 11:46:10 server vdr[28570]: [28601] curl_easy_perform() [rtsp.c,369] failed: Timeout was reached (28)
May 20 11:46:10 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 0]
May 20 11:46:10 server vdr[28570]: [28601] SATIP-ERROR: Pid update failed - retuning [device 0]
May 20 11:46:10 server vdr[28570]: [28612] curl_easy_perform() [rtsp.c,369] failed: Timeout was reached (28)
May 20 11:46:10 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 3]
May 20 11:46:10 server vdr[28570]: [28612] SATIP-ERROR: Pid update failed - retuning [device 3]
May 20 11:46:11 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Timeout was reached (28)

Shortly after that the messages show that the machine is reachable, but the port is closes.

May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Pid update failed - retuning [device 2]
May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,244] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Keep-alive failed - retuning [device 2]
May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28601] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 0]
May 20 11:46:23 server vdr[28570]: [28601] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 0]
May 20 11:46:23 server vdr[28570]: [28601] SATIP-ERROR: Pid update failed - retuning [device 0]
May 20 11:46:23 server vdr[28570]: [28601] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 0]
May 20 11:46:23 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:23 server vdr[28570]: [28609] SATIP-ERROR: Connect failed [device 2]
May 20 11:46:23 server vdr[28570]: [28612] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 3]
May 20 11:46:23 server vdr[28570]: [28612] curl_easy_perform() [rtsp.c,369] failed: Couldn't connect to server (7)
May 20 11:46:23 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 3]
May 20 11:46:23 server vdr[28570]: [28612] SATIP-ERROR: Pid update failed - retuning [device 3]

As far as I understood error "7" is connection refused. So from here I'd say it is safe to assume, that we need to reset the connection and start anew.
Unfortunately the SATIP plugin seems to continue using the old sequence numbers after the EXIP418 has started talking to VDR again, instead of doing a "SETUP":

May 20 11:46:24 server vdr[28570]: [28609] curl_easy_perform() [rtsp.c,244] failed: Couldn't connect to server (7)
May 20 11:46:24 server vdr[28570]: [28609] SATIP-ERROR: Detected invalid status code 0: rtsp://10.6.66.254/ [device 2]
May 20 11:46:24 server vdr[28570]: [28609] SATIP-ERROR: Connect failed [device 2]
May 20 11:46:24 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 3]
May 20 11:46:24 server vdr[28570]: [28612] SATIP-ERROR: Pid update failed - retuning [device 3]
May 20 11:46:24 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 3]
May 20 11:46:24 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 0]
May 20 11:46:24 server vdr[28570]: [28601] SATIP-ERROR: Pid update failed - retuning [device 0]
May 20 11:46:24 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 0]
May 20 11:46:25 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 3]
May 20 11:46:25 server vdr[28570]: [28612] SATIP-ERROR: Pid update failed - retuning [device 3]
May 20 11:46:25 server vdr[28570]: [28612] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 3]
May 20 11:46:25 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 0]
May 20 11:46:25 server vdr[28570]: [28601] SATIP-ERROR: Pid update failed - retuning [device 0]
May 20 11:46:25 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 0]
May 20 11:46:25 server vdr[28570]: [28601] SATIP-ERROR: Detected invalid status code 454: rtsp://10.6.66.254/ [device 0]
May 20 11:46:25 server vdr[28570]: [28601] SATIP-ERROR: Pid update failed - retuning [device 0]

It seems as if the EXIP418 did infact reboot here. The uptime is 3:03h. Which corresponds to the time of the log error.

Any help is greatly appreciated.
@rofafor
Copy link
Owner

rofafor commented May 24, 2021

You logs shows "Connect failed" messages meaning that in those places the RTSP stack is recreated and session should be reset. You could try changing rtspM.Reset(); line in https://github.com/rofafor/vdr-plugin-satip/blob/master/tuner.c#L257 into Disconnect();, that's sends also Teardown message to the server before reseting the RTSP stack.

@Rayn0r
Copy link
Author

Rayn0r commented May 25, 2021

The session, does not seem to be closed by a Disconnect().
Since this problems is usually cured by changing the channel manually, it is not that a big problem.
This also only occurred because the SatIP box was under heavy load and rebooted because of rapid PID changes, I guess it's safe to close this issue.
The other issue of those rapid PID changes in VDR itselt is hopefully being looked at.

@Rayn0r Rayn0r closed this as completed May 25, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Rayn0r @rofafor