search

openatv / enigma2

openatv-gui
GNU General Public License v2.0
200 stars 317 forks source link

Streams not retried when stalled #2469

Open wedebe opened 2 years ago

wedebe commented 2 years ago 
11:52:11.9218 Gstreamer error: Server does not support seeking. (11, 2153) from source
11:52:11.9233 Gstreamer error: Internal data stream error. (1, 2146) from source
11:52:12.4248 [eServiceMP3] ** EOS RECEIVED **
11:52:12.4254 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
11:52:12.4258 [eServiceMP3] trickSeek no need to unpause!

OpenATV doesn't attempt to retry connecting from this streaming failure. Changing channel and changing back will get things working again.

jbleyel commented 2 years ago

What if you have a real error? The detailed error info is currently not available in InfoBar to force a retry, so you can't force a retry via InfoBar.

Retry in eServiceMP3 is probably very complex to implement.

wedebe commented 2 years ago

What if you have a real error?

D'you have any examples of a real error?

jbleyel commented 2 years ago

What if you have a real error?

D'you have any examples of a real error?

That's simple.. open a non existing or non working link.

wedebe commented 2 years ago

That's simple.. open a non existing or non working link.

Working:

13:21:01.6499 [Navigation] playing ref 4097:0:1:0:0:0:0:0:0:0:https%3a//media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web:♪ Smooth Chill
13:21:01.6507 [eServiceMP3] stop https://streamssl.chilltrax.com/
13:21:01.6508 [eServiceMP3] stop state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:21:01.6974 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:21:01.7011 [eServiceMP3] **** PIPELINE DESTRUCTED ****
13:21:01.7033 [eServiceFactoryMP3] ****new play service total services played is 2****
13:21:01.7039 [eServiceMP3] playbin uri=https://media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:21:01.7054 [eServiceMP3] *** starting pipeline ****
13:21:01.7087 "::ffff:192.168.43.154" - - [12/Aug/2022:12:21:00 +0000] "GET /api/zap?sRef=4097%3A0%3A1%3A0%3A0%3A0%3A0%3A0%3A0%3A0%3Ahttps%253a//media-ssl.musicradio.com/SmoothChill%3Fdax_player%3DGlobalPlayer%26dax_platform%3DWeb%3A%25E2%2599%25AA%20Smooth%20Chill&_=1660306791844 HTTP/1.1" 200 175 "http://mutant51.local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.134 Safari/537.36"
13:21:01.7100 [eServiceMP3] ****STATE TRANSITION NULL -> READY ****
13:21:01.7183 [Screen] Showing screen 'InfoBar'.
13:21:01.7379 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:01.7386 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:01.7443 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:01.7447 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:01.7456 [Notifications] RemovePopup id = ZapError
13:21:01.9836 [eServiceMP3] PLAYBIN WITH BLOCK READY TO PAUSED state:PAUSED pending:VOID_PENDING ret:SUCCESS
13:21:02.0017 [eServiceMP3] ****STATE TRANSITION READY -> PAUSED ****
13:21:02.0181 [eServiceMP3] PLAYBIN WITH BLOCK PLAYSTART state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:21:02.0197 [eServiceMP3] GST_MESSAGE_ASYNC_DONE before evUpdatedInfo
13:21:02.0326 [VolumeAdjust] Normal volume is 80.
13:21:02.0339 [eServiceMP3] ** START USE LAST SEEK TIMER
13:21:02.1170 [eServiceMP3] ****STATE TRANSITION PAUSED -> PLAYING ****

No such page:

13:21:21.4631 [Navigation] playing ref 4097:0:1:0:0:0:0:0:0:0:https%3a//media-ssl.musicradio.com/SmoothChill404?dax_player=GlobalPlayer&dax_platform=Web:♪ Smooth Chill-nosuchpage
13:21:21.4637 [eServiceMP3] stop https://media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:21:21.4637 [eServiceMP3] stop state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:21:21.5316 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:21:21.5348 [eServiceMP3] **** PIPELINE DESTRUCTED ****
13:21:21.5370 [eServiceFactoryMP3] ****new play service total services played is 3****
13:21:21.5376 [eServiceMP3] playbin uri=https://media-ssl.musicradio.com/SmoothChill404?dax_player=GlobalPlayer&dax_platform=Web
13:21:21.5386 [eServiceMP3] *** starting pipeline ****
13:21:21.5420 "::ffff:192.168.43.154" - - [12/Aug/2022:12:21:18 +0000] "GET /api/zap?sRef=4097%3A0%3A1%3A0%3A0%3A0%3A0%3A0%3A0%3A0%3Ahttps%253a//media-ssl.musicradio.com/SmoothChill404%3Fdax_player%3DGlobalPlayer%26dax_platform%3DWeb%3A%25E2%2599%25AA%20Smooth%20Chill-nosuchpage&_=1660306791845 HTTP/1.1" 200 187 "http://mutant51.local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.134 Safari/537.36"
13:21:21.5445 [eServiceMP3] ****STATE TRANSITION NULL -> READY ****
13:21:21.5524 [Screen] Showing screen 'InfoBar'.
13:21:21.5708 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:21.5715 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:21.5775 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:21.5781 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:21.5789 [Notifications] RemovePopup id = ZapError
13:21:21.7160 [eServiceMP3] PLAYBIN WITH BLOCK READY TO PAUSED state:READY pending:PAUSED ret:FAILURE
13:21:21.7194 Gstreamer error: NOT FOUND: RESOURCE NOT FOUND (3, 2166) from source
13:21:21.7201 Gstreamer error: Internal data stream error. (1, 2146) from source
13:21:21.7204 Gstreamer error: Stream doesn't contain enough data. (4, 2146) from typefindelement2

No such domain:

13:21:28.2641 [Navigation] playing ref 4097:0:1:0:0:0:0:0:0:0:https%3a//xmedia-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web:♪ Smooth Chill-nosuchdomain
13:21:28.2649 [eServiceMP3] stop https://media-ssl.musicradio.com/SmoothChill404?dax_player=GlobalPlayer&dax_platform=Web
13:21:28.2652 [eServiceMP3] stop state:READY pending:PAUSED ret:FAILURE
13:21:28.2758 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:21:28.2792 [eServiceMP3] **** PIPELINE DESTRUCTED ****
13:21:28.2796 [eServiceFactoryMP3] ****new play service total services played is 4****
13:21:28.2799 [eServiceMP3] playbin uri=https://xmedia-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:21:28.2808 [eServiceMP3] *** starting pipeline ****
13:21:28.2841 "::ffff:192.168.43.154" - - [12/Aug/2022:12:21:27 +0000] "GET /api/zap?sRef=4097%3A0%3A1%3A0%3A0%3A0%3A0%3A0%3A0%3A0%3Ahttps%253a//xmedia-ssl.musicradio.com/SmoothChill%3Fdax_player%3DGlobalPlayer%26dax_platform%3DWeb%3A%25E2%2599%25AA%20Smooth%20Chill-nosuchdomain&_=1660306791846 HTTP/1.1" 200 185 "http://mutant51.local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.134 Safari/537.36"
13:21:28.2851 [eServiceMP3] ****STATE TRANSITION NULL -> READY ****
13:21:28.2927 [Screen] Showing screen 'InfoBar'.
13:21:28.3135 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:28.3142 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:28.3205 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:21:28.3208 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:21:28.3218 [Notifications] RemovePopup id = ZapError
13:21:30.3632 [gRC] Warning: Main thread is busy, displaying spinner!
13:21:31.4126 [eServiceMP3] PLAYBIN WITH BLOCK READY TO PAUSED state:READY pending:PAUSED ret:FAILURE
13:21:31.4241 StackTrace
13:21:31.4293 ========== Stacktrace of active Python threads ===========
13:21:31.4295 ========== Thread ID  0xaf5d8380 =========================
13:21:31.4296 File: "/usr/lib/python3.9/threading.py", line 930, in _bootstrap
13:21:31.4296 File: "/usr/lib/python3.9/threading.py", line 973, in _bootstrap_inner
13:21:31.4297 File: "/usr/lib/python3.9/threading.py", line 910, in run
13:21:31.4298 File: "/usr/lib/python3.9/site-packages/twisted/_threads/_threadworker.py", line 46, in work
13:21:31.4298 File: "/usr/lib/python3.9/queue.py", line 171, in get
13:21:31.4299 File: "/usr/lib/python3.9/threading.py", line 312, in wait
13:21:31.4300 ========== Thread ID  0xb0739380 =========================
13:21:31.4300 File: "/usr/lib/python3.9/threading.py", line 930, in _bootstrap
13:21:31.4301 File: "/usr/lib/python3.9/threading.py", line 973, in _bootstrap_inner
13:21:31.4302 File: "/usr/lib/python3.9/threading.py", line 910, in run
13:21:31.4302 File: "/usr/lib/python3.9/socketserver.py", line 232, in serve_forever
13:21:31.4304 File: "/usr/lib/python3.9/selectors.py", line 416, in select
13:21:31.4307 ========== MainThread 0xb5ddb3c0 =========================
13:21:31.4308 File: "/usr/lib/enigma2/python/StartEnigma.py", line 945, in <module>
13:21:31.4308   runScreenTest()  # Start running the first screen.
13:21:31.4309 File: "/usr/lib/enigma2/python/StartEnigma.py", line 440, in runScreenTest
13:21:31.4309   runReactor()
13:21:31.4311 File: "/usr/lib/enigma2/python/StartEnigma.py", line 615, in runReactor
13:21:31.4312   reactor.run(installSignalHandlers=False)
13:21:31.4313 File: "/usr/lib/python3.9/site-packages/twisted/internet/base.py", line 1318, in run
13:21:31.4313 File: "/usr/lib/python3.9/site-packages/twisted/internet/base.py", line 1331, in mainLoop
13:21:31.4314 File: "/usr/lib/enigma2/python/e2reactor.py", line 156, in doPoll
13:21:31.4314 File: "/usr/lib/enigma2/python/e2reactor.py", line 45, in poll
13:21:31.4315 File: "/usr/lib/enigma2/python/Components/ConditionalWidget.py", line 29, in update
13:21:31.4315 ========== Stacktrace end ================================
13:21:31.4454 Gstreamer error: Could not resolve server name. (3, 2166) from source
13:21:31.4459 Gstreamer error: Internal data stream error. (1, 2146) from source
13:21:31.4463 Gstreamer error: Stream doesn't contain enough data. (4, 2146) from typefindelement3

Connected to local network but no internet connection:

13:27:38.7916 [Navigation] playing ref 4097:0:1:0:0:0:0:0:0:0:https%3a//media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web:♪ Smooth Chill
13:27:38.7924 [eServiceMP3] stop https://streamssl.chilltrax.com/
13:27:38.7926 [eServiceMP3] stop state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:27:38.8462 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:27:38.8503 [eServiceMP3] **** PIPELINE DESTRUCTED ****
13:27:38.8520 [eServiceFactoryMP3] ****new play service total services played is 15****
13:27:38.8524 [eServiceMP3] playbin uri=https://media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:27:38.8532 [eServiceMP3] *** starting pipeline ****
13:27:38.8567 "::ffff:192.168.43.154" - - [12/Aug/2022:12:27:36 +0000] "GET /api/zap?sRef=4097%3A0%3A1%3A0%3A0%3A0%3A0%3A0%3A0%3A0%3Ahttps%253a//media-ssl.musicradio.com/SmoothChill%3Fdax_player%3DGlobalPlayer%26dax_platform%3DWeb%3A%25E2%2599%25AA%20Smooth%20Chill&_=1660306791850 HTTP/1.1" 200 175 "http://mutant51.local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.134 Safari/537.36"
13:27:38.8578 [eServiceMP3] ****STATE TRANSITION NULL -> READY ****
13:27:38.8657 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:27:38.8661 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:27:38.8718 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:27:38.8720 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:27:38.8727 [Notifications] RemovePopup id = ZapError
13:27:42.7336 [gRC] Warning: Main thread is busy, displaying spinner!
13:27:43.8768 [eServiceMP3] PLAYBIN WITH BLOCK READY TO PAUSED state:READY pending:PAUSED ret:ASYNC
13:27:43.8779 StackTrace
13:27:43.8797 ========== Stacktrace of active Python threads ===========
13:27:43.8800 ========== Thread ID  0xaf5d8380 =========================
13:27:43.8801 File: "/usr/lib/python3.9/threading.py", line 930, in _bootstrap
13:27:43.8801 File: "/usr/lib/python3.9/threading.py", line 973, in _bootstrap_inner
13:27:43.8803 File: "/usr/lib/python3.9/threading.py", line 910, in run
13:27:43.8804 File: "/usr/lib/python3.9/site-packages/twisted/_threads/_threadworker.py", line 46, in work
13:27:43.8804 File: "/usr/lib/python3.9/queue.py", line 171, in get
13:27:43.8805 File: "/usr/lib/python3.9/threading.py", line 312, in wait
13:27:43.8805 ========== Thread ID  0xb0739380 =========================
13:27:43.8806 File: "/usr/lib/python3.9/threading.py", line 930, in _bootstrap
13:27:43.8806 File: "/usr/lib/python3.9/threading.py", line 973, in _bootstrap_inner
13:27:43.8807 File: "/usr/lib/python3.9/threading.py", line 910, in run
13:27:43.8807 File: "/usr/lib/python3.9/socketserver.py", line 232, in serve_forever
13:27:43.8808 File: "/usr/lib/python3.9/selectors.py", line 416, in select
13:27:43.8808 ========== MainThread 0xb5ddb3c0 =========================
13:27:43.8808 File: "/usr/lib/enigma2/python/StartEnigma.py", line 945, in <module>
13:27:43.8809   runScreenTest()  # Start running the first screen.
13:27:43.8809 File: "/usr/lib/enigma2/python/StartEnigma.py", line 440, in runScreenTest
13:27:43.8810   runReactor()
13:27:43.8811 File: "/usr/lib/enigma2/python/StartEnigma.py", line 615, in runReactor
13:27:43.8811   reactor.run(installSignalHandlers=False)
13:27:43.8812 File: "/usr/lib/python3.9/site-packages/twisted/internet/base.py", line 1318, in run
13:27:43.8812 File: "/usr/lib/python3.9/site-packages/twisted/internet/base.py", line 1331, in mainLoop
13:27:43.8812 File: "/usr/lib/enigma2/python/e2reactor.py", line 156, in doPoll
13:27:43.8813 File: "/usr/lib/enigma2/python/e2reactor.py", line 45, in poll
13:27:43.8813 ========== Stacktrace end ================================

Connected to local network but internet disconnected during playback: (several seconds of playback buffers through, then a longer period of silence before Gstreamer outputs a message)

13:29:03.6645 [Navigation] playing ref 4097:0:1:0:0:0:0:0:0:0:https%3a//media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web:♪ Smooth Chill
13:29:03.6652 [eServiceMP3] stop https://streamssl.chilltrax.com/
13:29:03.6653 [eServiceMP3] stop state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:29:03.7302 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:29:03.7330 [eServiceMP3] **** PIPELINE DESTRUCTED ****
13:29:03.7347 [eServiceFactoryMP3] ****new play service total services played is 18****
13:29:03.7351 [eServiceMP3] playbin uri=https://media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:29:03.7361 [eServiceMP3] *** starting pipeline ****
13:29:03.7394 "::ffff:192.168.43.154" - - [12/Aug/2022:12:29:02 +0000] "GET /api/zap?sRef=4097%3A0%3A1%3A0%3A0%3A0%3A0%3A0%3A0%3A0%3Ahttps%253a//media-ssl.musicradio.com/SmoothChill%3Fdax_player%3DGlobalPlayer%26dax_platform%3DWeb%3A%25E2%2599%25AA%20Smooth%20Chill&_=1660306791853 HTTP/1.1" 200 175 "http://mutant51.local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.134 Safari/537.36"
13:29:03.7404 [eServiceMP3] ****STATE TRANSITION NULL -> READY ****
13:29:03.7480 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:29:03.7483 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:29:03.7539 [eServiceMP3] pause(ePtr<iPauseableService> &ptr)
13:29:03.7541 [Pixmap] setPixmapNum(0) failed!  Defined pixmaps: [].
13:29:03.7547 [Notifications] RemovePopup id = ZapError
13:29:05.4822 [eServiceMP3] PLAYBIN WITH BLOCK READY TO PAUSED state:PAUSED pending:VOID_PENDING ret:SUCCESS
13:29:05.4974 [eServiceMP3] ****STATE TRANSITION READY -> PAUSED ****
13:29:05.5080 [eServiceMP3] PLAYBIN WITH BLOCK PLAYSTART state:PLAYING pending:VOID_PENDING ret:SUCCESS
13:29:05.5089 [eServiceMP3] GST_MESSAGE_ASYNC_DONE before evUpdatedInfo
13:29:05.5195 [VolumeAdjust] Normal volume is 80.
13:29:05.5368 [eServiceMP3] ** START USE LAST SEEK TIMER
13:29:05.5658 [eServiceMP3] ****STATE TRANSITION PAUSED -> PLAYING ****

13:29:51.7649 Gstreamer error: A network error occurred, or the server closed the connection unexpectedly. (9, 2166) from source
13:29:51.7653 [eServiceMP3] stop https://media-ssl.musicradio.com/SmoothChill?dax_player=GlobalPlayer&dax_platform=Web
13:29:51.7655 [eServiceMP3] stop state:PLAYING pending:VOID_PENDING ret:FAILURE
13:29:52.3036 [eServiceMP3] **** TO NULL state:NULL pending:VOID_PENDING ret:SUCCESS ****
13:29:52.3053 Gstreamer error: Internal data stream error. (1, 2146) from source
13:29:52.3141 [eServiceMP3] ****STATE TRANSITION PLAYING -> PAUSED ****
13:29:52.3148 [eServiceMP3] ****STATE TRANSITION PAUSED -> READY ****

Hope that helps :)

wedebe commented 2 years ago

Notably also an unhandled exception, seems I may have opened a can of worms here 🙈