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

Client connections get disconnected after ~60sec #806

Closed
cloudcover2021 opened this issue Jul 5, 2022 · 10 comments
Closed

Client connections get disconnected after ~60sec #806

cloudcover2021 opened this issue Jul 5, 2022 · 10 comments
Labels
help

Comments

@cloudcover2021
Copy link

cloudcover2021 commented Jul 5, 2022 •
edited by dimiden
Loading

PROBLEM

Client connections get disconnected after ~60sec from Tester Server which is used for performance tuning.

  1. OME server is running on a GCE(Google Compute Instance) instance. All ports are open on this server
  2. The OME testing tool(https://airensoft.gitbook.io/ovenmediaengine/performance-tuning) is deployed on another instance(Google Compute Instance).
  3. We are publishing using the OvenStreamEncoder app and then starting the load test from the instance mentioned in step 2.
  4. Issue:
    a. After 60 secs the connection is disconnected from the testing server
    b. Following logs are observed on the OME var/log/ovenmediaengine/ovenmediaengine.log file
[2022-07-05 07:53:19.681] I [DQHTTPTimer:106990] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/109
[2022-07-05 07:53:19.681] I [DQHTTPTimer:106990] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(4)/Stream total(4)/App total(4)]
[2022-07-05 07:53:19.681] I [DQHTTPTimer:106990] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f55b006d100) : WebSocket <ClientSocket: 0x7f55b000f2a0, #40, Connected, TCP, Nonblocking, <TEST SERVER IP>:47316> TLS(Disabled) (#default#app / stream, ufrag: local: 8jZr9c, remote: UuXfEpflHtPaTGPY)
[2022-07-05 07:53:19.682] I [DQHTTPTimer:106990] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/107
[2022-07-05 07:53:19.682] I [DQHTTPTimer:106990] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(3)/Stream total(3)/App total(3)]
[2022-07-05 07:53:19.682] I [DQHTTPTimer:106990] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f55b000af90) : WebSocket <ClientSocket: 0x7f55b0001310, #36, Connected, TCP, Nonblocking, <TEST SERVER IP>:47312> TLS(Disabled) (#default#app / stream, ufrag: local: IFS78g, remote: ECEYHWbzApqJKrZp)
[2022-07-05 07:53:19.682] I [DQHTTPTimer:106990] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/106
[2022-07-05 07:53:19.683] I [DQHTTPTimer:106990] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(2)/Stream total(2)/App total(2)]
[2022-07-05 07:53:19.683] I [DQHTTPTimer:106990] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f55b0057480) : WebSocket <ClientSocket: 0x7f55800169f0, #34, Connected, TCP, Nonblocking, <TEST SERVER IP>:47310> TLS(Disabled) (#default#app / stream, ufrag: local: mWl6IT, remote: PbjrArjDaEJFlbfX)
[2022-07-05 07:53:19.683] I [DQHTTPTimer:106990] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/108
[2022-07-05 07:53:19.684] I [DQHTTPTimer:106990] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(1)/Stream total(1)/App total(1)]
[2022-07-05 07:53:19.684] I [DQHTTPTimer:106990] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f55b0002e10) : WebSocket <ClientSocket: 0x7f55b006b9f0, #38, Connected, TCP, Nonblocking, <TEST SERVER IP>:47314> TLS(Disabled) (#default#app / stream, ufrag: local: EwjOQs, remote: VXXwogzlPMADozJY)
[2022-07-05 07:53:19.684] I [DQHTTPTimer:106990] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/105
[2022-07-05 07:53:19.684] I [DQHTTPTimer:106990] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(0)/Stream total(0)/App total(0)]
[2022-07-05 07:53:19.684] I [DQHTTPTimer:106990] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f55b0034010) : WebSocket <ClientSocket: 0x7f55b0033dd0, #32, Connected, TCP, Nonblocking, <TEST SERVER IP>:47308> TLS(Disabled) (#default#app / stream, ufrag: local: njVeZx, remote: dCXIzcoNxvgkyrJC)
[2022-07-05 07:53:19.726] I [SPICE-T3478:107000] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f5510006550, #39, Closed, TCP, Nonblocking, <TEST SERVER IP>:44680>
[2022-07-05 07:53:19.726] I [SPICE-T3478:107000] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f54f00080a0, #33, Closed, TCP, Nonblocking, <TEST SERVER IP>:44674>
[2022-07-05 07:53:19.726] I [SPICE-T3478:107000] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f5580013a00, #35, Closed, TCP, Nonblocking, <TEST SERVER IP>:44676>
[2022-07-05 07:53:19.726] I [SPICE-T3478:107000] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f5510003300, #37, Closed, TCP, Nonblocking, <TEST SERVER IP>:44678>
[2022-07-05 07:53:19.727] I [SPICE-T3478:107000] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f55800131d0, #41, Closed, TCP, Nonblocking, <TEST SERVER IP>:44684>

ENVIRONMENTAL INFORMATION

  • OvenMediaEngine Information

Version used 0.12.4.
Deployed on GCE(Google Compute Engine)

  • Encoder information

OvenStreamEncoder is used for streaming video

  • URL

Please tell me which address you used to send and play. You can hide IP or Domain.

  • Operating system and version

Ubuntu 20.04
@dimiden
Copy link
Member

dimiden commented Jul 5, 2022

@cloudcover2021
Thank you for your detailed bug reporting, but I think you are using old version of OME.
If there is no specific reason, could you use the latest OME?
A ton of bugs have been fixed in latest OME, and it is highly likely that the bugs you mentioned above have already been fixed.
If the same symptoms occur with the latest version, please tell us again.

@cloudcover2021
Copy link
Author

@dimiden By latest you mean this one: https://airensoft.gitbook.io/ovenmediaengine/v/master-1/

@cloudcover2021
Copy link
Author

cloudcover2021 commented Jul 5, 2022 •
edited by dimiden
Loading

@dimiden I installed the version mentioned above but still same issue. No changes made to configurations. PFB the OME logs:

root@ovenmediaserver-1:/home/sagarpatil/OME/OvenMediaEngine-master/src# cd /var/log/ovenmediaengine/
root@ovenmediaserver-1:/var/log/ovenmediaengine# tail -f ovenmediaengine.log
[2022-07-05 17:16:57.517] I [DQHTTPTimer:104898] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/104
[2022-07-05 17:16:57.518] I [DQHTTPTimer:104898] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(4)/Stream total(4)/App total(4)]
[2022-07-05 17:16:57.518] I [DQHTTPTimer:104898] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f12b0041cc0) : WebSocket <ClientSocket: 0x7f12b006bda0, #40, Connected, TCP, Nonblocking, <TEST SERVER IP>:62625> TLS(Disabled) (#default#app / stream, ufrag: local: m2lePK, remote: FlhOhFLYHSlBhtdO)
[2022-07-05 17:16:57.519] I [DQHTTPTimer:104898] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/103
[2022-07-05 17:16:57.519] I [DQHTTPTimer:104898] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(3)/Stream total(3)/App total(3)]
[2022-07-05 17:16:57.519] I [DQHTTPTimer:104898] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f12b00452d0) : WebSocket <ClientSocket: 0x7f12b003c720, #38, Connected, TCP, Nonblocking, <TEST SERVER IP>:62622> TLS(Disabled) (#default#app / stream, ufrag: local: qAK5dT, remote: QJufBKAtAkBPacyl)
[2022-07-05 17:16:57.520] I [DQHTTPTimer:104898] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/101
[2022-07-05 17:16:57.520] I [DQHTTPTimer:104898] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(2)/Stream total(2)/App total(2)]
[2022-07-05 17:16:57.520] I [DQHTTPTimer:104898] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f12b003cf30) : WebSocket <ClientSocket: 0x7f12b00152f0, #34, Connected, TCP, Nonblocking, <TEST SERVER IP>:62616> TLS(Disabled) (#default#app / stream, ufrag: local: RzOeqQ, remote: EVLJPjufFsjFoUfV)
[2022-07-05 17:16:57.520] I [DQHTTPTimer:104898] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/102
[2022-07-05 17:16:57.521] I [DQHTTPTimer:104898] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(1)/Stream total(1)/App total(1)]
[2022-07-05 17:16:57.521] I [DQHTTPTimer:104898] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f12b0047500) : WebSocket <ClientSocket: 0x7f12b004f310, #36, Connected, TCP, Nonblocking, <TEST SERVER IP>:62619> TLS(Disabled) (#default#app / stream, ufrag: local: xgauVR, remote: ClSfVpfEruQceums)
[2022-07-05 17:16:57.521] I [DQHTTPTimer:104898] WebRTC Publisher | webrtc_publisher.cpp:701  | Stop command received : #default#app/stream/100
[2022-07-05 17:16:57.522] I [DQHTTPTimer:104898] Monitor | stream_metrics.cpp:136  | A session has been stopped playing #default#app/stream on the WebRTC publisher. Concurrent Viewers[WebRTC(0)/Stream total(0)/App total(0)]
[2022-07-05 17:16:57.522] I [DQHTTPTimer:104898] Signalling | rtc_signalling_server.cpp:365  | Client is disconnected: HttpConnection(0x7f12b0002090) : WebSocket <ClientSocket: 0x7f12b0001650, #32, Connected, TCP, Nonblocking, <TEST SERVER IP>:62613> TLS(Disabled) (#default#app / stream, ufrag: local: Qi0euj, remote: vOQdsNeLAqLNYZDq)
[2022-07-05 17:16:57.528] I [SPICE-T3478:104908] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f128c00d390, #39, Closed, TCP, Nonblocking, <TEST SERVER IP>:62624>
[2022-07-05 17:16:57.528] I [SPICE-T3478:104908] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f128c00f040, #37, Closed, TCP, Nonblocking, <TEST SERVER IP>:62621>
[2022-07-05 17:16:57.528] I [SPICE-T3478:104908] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f128c0096c0, #35, Closed, TCP, Nonblocking, <TEST SERVER IP>:62618>
[2022-07-05 17:16:57.529] I [SPICE-T3478:104908] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f128c008250, #33, Closed, TCP, Nonblocking, <TEST SERVER IP>:62615>
[2022-07-05 17:16:57.529] I [SPICE-T3478:104908] ICE | ice_port.cpp:493  | Turn client has disconnected : <ClientSocket: 0x7f128c011080, #41, Closed, TCP, Nonblocking, <TEST SERVER IP>:62626>

** Also I checked the status of the OME service on ubuntu VM after the load test failure and the following was its status. Error highlighted in BOLD:

● ovenmediaengine.service - OvenMediaEngine
     Loaded: loaded (/lib/systemd/system/ovenmediaengine.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2022-07-05 17:12:27 UTC; 6min ago
   Main PID: 104893 (OvenMediaEngine)
      Tasks: 58 (limit: 4697)
     Memory: 50.5M
     CGroup: /system.slice/ovenmediaengine.service
             └─104893 /usr/bin/OvenMediaEngine -d

Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.513] W [OvenMediaEngine:104893] HLS | hls_publisher.cpp:38   | HLS Publisher is disabled by configuration
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.514] W [OvenMediaEngine:104893] DASH | dash_publisher.cpp:36   | DASH Publisher is disabled by configuration
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.514] W [OvenMediaEngine:104893] LLDASH | cmaf_publisher.cpp:39   | LLDASH Publisher is disabled by configuration
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.517] W [OvenMediaEngine:104893] Thumbnail | thumbnail_publisher.cpp:45   | ThumbnailPublisher is disabled by configuration
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.533] W [OvenMediaEngine:104893] Publisher | publisher.cpp:69   | File publisher is disabled in #default#app application, so it was not created
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.533] W [OvenMediaEngine:104893] Publisher | publisher.cpp:69   | MPEGTSPush publisher is disabled in #default#app application, so it was not created
Jul 05 17:12:27 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:12:27.533] W [OvenMediaEngine:104893] Publisher | publisher.cpp:69   | RTMPPush publisher is disabled in #default#app application, so it was not created
Jul 05 17:12:27 ovenmediaserver-1 systemd[1]: Started OvenMediaEngine.
*****
Jul 05 17:15:48 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:15:48.772] E [Decaac:106041] FFmpeg | third_parties.cpp:111  | [AVCodecContext: 0x7f127401ea00] Input buffer exhausted before END element found
Jul 05 17:15:48 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:15:48.772] E [Decaac:106041] Transcoder | decoder_aac.cpp:166  | An error occurred while sending a packet for decoding: Unhandled error (-1094995529:Invalid data found when processing input)
*****

@cloudcover2021
Copy link
Author

Is there any configuration to increase the timeout from 60 sec to a higher value.

@cloudcover2021
Copy link
Author

cloudcover2021 commented Jul 5, 2022 •
edited by dimiden
Loading

I changed from the OvenStreamEncoder app to OBS(https://obsproject.com/) to start the stream. Same error but this time the status of the OME service on ubuntu VM after the load test failure was below:

● ovenmediaengine.service - OvenMediaEngine
     Loaded: loaded (/lib/systemd/system/ovenmediaengine.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2022-07-05 17:32:49 UTC; 12min ago
    Process: 504 ExecStart=/usr/bin/OvenMediaEngine -d (code=exited, status=0/SUCCESS)
   Main PID: 520 (OvenMediaEngine)
      Tasks: 58 (limit: 4697)
     Memory: 118.6M
     CGroup: /system.slice/ovenmediaengine.service
             └─520 /usr/bin/OvenMediaEngine -d

Jul 05 17:32:48 ovenmediaserver-1 systemd[1]: Starting OvenMediaEngine...
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.109] W [OvenMediaEngine:520] HLS | hls_publisher.cpp:38   | HLS Publisher is disabled by configuration
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.111] W [OvenMediaEngine:520] DASH | dash_publisher.cpp:36   | DASH Publisher is disabled by configuration
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.111] W [OvenMediaEngine:520] LLDASH | cmaf_publisher.cpp:39   | LLDASH Publisher is disabled by configuration
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.134] W [OvenMediaEngine:520] Thumbnail | thumbnail_publisher.cpp:45   | ThumbnailPublisher is disabled by configuration
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.230] W [OvenMediaEngine:520] Publisher | publisher.cpp:69   | File publisher is disabled in #default#app application, so it was not created
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.230] W [OvenMediaEngine:520] Publisher | publisher.cpp:69   | MPEGTSPush publisher is disabled in #default#app application, so it was not created
Jul 05 17:32:49 ovenmediaserver-1 OvenMediaEngine[520]: [2022-07-05 17:32:49.230] W [OvenMediaEngine:520] Publisher | publisher.cpp:69   | RTMPPush publisher is disabled in #default#app application, so it was not created
Jul 05 17:32:49 ovenmediaserver-1 systemd[1]: Started OvenMediaEngine.

No error this time

@dimiden
Copy link
Member

dimiden commented Jul 6, 2022

@cloudcover2021

By latest you mean this one: https://airensoft.gitbook.io/ovenmediaengine/v/master-1/

Yes. The version I mentioned is master branch or v0.14.2.

Also I checked the status of the OME service on ubuntu VM after the load test failure and the following was its status. Error highlighted in BOLD

Decoding issues related to OvenStreamEncoder have been assigned to the person in charge. (However, this is not a reason.)

Is there any configuration to increase the timeout from 60 sec to a higher value.

Adjusting timeout is not recommended because increasing the timeout will only cause the problem to appear later.

This is a complex issue, so the exact cause should be analyzed by looking at the system/full log/settings/etc.
Please attach the following additional information.

  • Cores/Network bandwidth of the instance
  • Server.xml
  • Complete ovenmediaengine.log (instead of the result of tail)
  • Command line at the time of running the Testing tool

P.S. There was a timeout issue when we tested it before, which was a symptom of packet transmission being slowed down little by little at the point of a certain number of times, and many of the connected clients being disconnected as the slow speed accumulated.

@dimiden
Copy link
Member

dimiden commented Jul 6, 2022

@cloudcover2021
Oh! We have confirmed that this problem is reproduced. I will tell you again when the contents are updated.

@getroot
Copy link
Member

getroot commented Jul 6, 2022

@cloudcover2021

Thanks for reporting this issue.
It was a websocket stuck issue in OvenRtcTester, I fixed this issue and committed it.

4fb4af2

@cloudcover2021
Copy link
Author

Issue fixed. Thanks

@Keukhan
Copy link
Member

Keukhan commented Jul 6, 2022 •
edited
Loading

@cloudcover2021

While trying to figure out the cause, I found a problem with the OvenStreamEncoder app and solved it.
The cause of the error in AAC Decoder when using OvenStreamEncoder is that OvenStreamEncoder sends an invalid audio packet.
I need to update the app in the google store.

Thank you so much.

Jul 05 17:15:48 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:15:48.772] E [Decaac:106041] FFmpeg | third_parties.cpp:111 | [AVCodecContext: 0x7f127401ea00] Input buffer exhausted before END element found
Jul 05 17:15:48 ovenmediaserver-1 OvenMediaEngine[104893]: [2022-07-05 17:15:48.772] E [Decaac:106041] Transcoder | decoder_aac.cpp:166 | An error occurred while sending a packet for decoding: Unhandled error (-1094995529:Invalid data found when processing input)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
help
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@dimiden @getroot @Keukhan @cloudcover2021