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

Files containing unknown streams cause an Internal Server Error #584

Open
Lyamc opened this issue Nov 24, 2023 · 5 comments
Open

Files containing unknown streams cause an Internal Server Error #584

Lyamc opened this issue Nov 24, 2023 · 5 comments
Labels
S-needs-triage Status: Needs triage T-bug Something isn't working the way it is supposed to

Comments

@Lyamc
Copy link

Lyamc commented Nov 24, 2023 •
edited
Loading

Describe the bug
The server dies session until the service is restarted browser is refreshed if I try to play a file where any of the streams are unknown to ffmpeg. Examples might include bitmap subtitles from blurays.

To Reproduce
Not sure how to create such a file, but attempting to play one will cause it.

Additional context
This can be worked around with a simple copy so that the unknowables gets stripped from the file. For example:

ffmpeg -i problem_file.mkv -c copy fixed_file.mkv
@Lyamc Lyamc added S-needs-triage Status: Needs triage T-bug Something isn't working the way it is supposed to labels Nov 24, 2023
@vgarleanu
Copy link
Member

Does the server die with any particular panic message? would be useful to get that 🙏🏻

@Lyamc
Copy link
Author

Lyamc commented Nov 24, 2023

When it's run through the command line it seems more stable, or perhaps this file is just different. When running as a service, the internal service error repeats a few times.

2023-11-24T13:50:15.975707Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:15.975780Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=101
2023-11-24T13:50:16.056404Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:16.056456Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=101
2023-11-24T13:50:21.545100Z DEBUG request{method=GET uri=/play/6743 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.545146Z DEBUG request{method=GET uri=/play/6743 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.579755Z DEBUG request{method=GET uri=/static/js/main.29349bb0.js version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.580432Z DEBUG request{method=GET uri=/static/js/main.29349bb0.js version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.601903Z DEBUG request{method=GET uri=/static/css/main.ad2e53af.css version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.601966Z DEBUG request{method=GET uri=/static/css/main.ad2e53af.css version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.741792Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.741840Z DEBUG request{method=GET uri=/ws version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=101
2023-11-24T13:50:21.840988Z DEBUG request{method=GET uri=/static/media/roboto_regular.a8d6ac03c7b96b7acb62.ttf version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.841051Z DEBUG request{method=GET uri=/api/v1/auth/whoami version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.841160Z DEBUG request{method=GET uri=/static/media/roboto_regular.a8d6ac03c7b96b7acb62.ttf version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.841631Z DEBUG request{method=GET uri=/api/v1/auth/whoami version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.858425Z DEBUG request{method=GET uri=/api/v1/mediafile/6743 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.858497Z DEBUG request{method=GET uri=/api/v1/user/settings version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.858999Z DEBUG request{method=GET uri=/api/v1/user/settings version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.859046Z DEBUG request{method=GET uri=/api/v1/mediafile/6743 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.869148Z DEBUG request{method=GET uri=/static/media/roboto_bold.75371f53f06181df75f1.ttf version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.869214Z DEBUG request{method=GET uri=/static/media/roboto_bold.75371f53f06181df75f1.ttf version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.875503Z DEBUG request{method=GET uri=/api/v1/media/5248 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.875581Z DEBUG request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.882893Z DEBUG request{method=GET uri=/api/v1/media/5248 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=7 ms status=200
2023-11-24T13:50:21.913913Z DEBUG request{method=GET uri=/api/v1/media/5262/files version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.918044Z DEBUG request{method=GET uri=/api/v1/media/5262/files version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=4 ms status=200
2023-11-24T13:50:21.933164Z DEBUG request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=57 ms status=500
2023-11-24T13:50:21.933201Z ERROR request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=57 ms
2023-11-24T13:50:21.939842Z DEBUG request{method=GET uri=/static/logoWhite128.png version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:21.939871Z DEBUG request{method=GET uri=/static/logoWhite128.png version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T13:50:21.954105Z DEBUG request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T13:50:22.011641Z DEBUG request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=57 ms status=500
2023-11-24T13:50:22.011675Z ERROR request{method=GET uri=/api/v1/stream/6743/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=57 ms

With the server, I'll see the error repeated. In the case where it required a restart, the error repeated about 6-8 times:

Nov 24 13:53:59 dim dim[163302]: 2023-11-24T13:53:59.856567Z ERROR tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=56 ms
Nov 24 13:53:59 dim dim[163302]: 2023-11-24T13:53:59.922194Z ERROR tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=56 ms

@Lyamc
Copy link
Author

Lyamc commented Nov 24, 2023

Here's another one with a specific error about EBML header parsing:

2023-11-24T14:04:01.601682Z DEBUG request{method=GET uri=/api/v1/mediafile/6332 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:04:01.602093Z DEBUG request{method=GET uri=/api/v1/mediafile/6332 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T14:04:01.615244Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:04:01.620826Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}:get_meta: dim_core::streaming::ffprobe: ffprobe exited with an error status. status=ExitStatus(unix_wait_status(256)) stderr=[matroska,webm @ 0x55bc2312fe00] EBML header parsing failed
/media/bad-file.mkv: Invalid data found when processing input

2023-11-24T14:04:01.623043Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=7 ms status=500
2023-11-24T14:04:01.623069Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=7 ms
2023-11-24T14:04:01.624667Z DEBUG request{method=GET uri=/api/v1/media/4311 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:04:01.628099Z DEBUG request{method=GET uri=/api/v1/media/4311 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=3 ms status=200
2023-11-24T14:04:01.635910Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:04:01.641357Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}:get_meta: dim_core::streaming::ffprobe: ffprobe exited with an error status. status=ExitStatus(unix_wait_status(256)) stderr=[matroska,webm @ 0x562d892f3e00] EBML header parsing failed
/media/bad-file.mkv: Invalid data found when processing input

2023-11-24T14:04:01.641445Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=5 ms status=500
2023-11-24T14:04:01.641471Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=5 ms
2023-11-24T14:04:01.663451Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:04:01.668997Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}:get_meta: dim_core::streaming::ffprobe: ffprobe exited with an error status. status=ExitStatus(unix_wait_status(256)) stderr=[matroska,webm @ 0x557e06813e00] EBML header parsing failed
/media/bad-file.mkv: Invalid data found when processing input

2023-11-24T14:04:01.669098Z DEBUG request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=5 ms status=500
2023-11-24T14:04:01.669131Z ERROR request{method=GET uri=/api/v1/stream/6332/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 500 Internal Server Error latency=5 ms

@Lyamc
Copy link
Author

Lyamc commented Nov 24, 2023

After this occurs, and I navigate elsewhere, say to another piece of media that should work, I get a grey screen with no errors or video. Last time this happened, I had to restart the service to recover, but today I can just refresh the browser and it resolves itself.

image 
2023-11-24T14:14:33.439414Z DEBUG request{method=GET uri=/api/v1/mediafile/7323 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:33.439511Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:33.439896Z DEBUG request{method=GET uri=/api/v1/mediafile/7323 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T14:14:34.877202Z  INFO nightfall: New session bf4c203f-f16d-4ad8-8a88-740af937f563 map 0 -> h264@10000000
2023-11-24T14:14:34.877226Z  INFO nightfall: Session bf4c203f-f16d-4ad8-8a88-740af937f563 chain h264 -> h264_cuda
2023-11-24T14:14:34.877254Z  INFO nightfall: New session 21cde943-436c-4acd-84ea-7199a4bbc0e4 map 0 -> h264@5000000
2023-11-24T14:14:34.877262Z  INFO nightfall: Session 21cde943-436c-4acd-84ea-7199a4bbc0e4 chain h264 -> h264_cuda
2023-11-24T14:14:34.877285Z  INFO nightfall: New session ca064423-a48d-4f40-b5db-6ce2f7ee4e77 map 0 -> h264@1000000
2023-11-24T14:14:34.877294Z  INFO nightfall: Session ca064423-a48d-4f40-b5db-6ce2f7ee4e77 chain h264 -> h264_cuda
2023-11-24T14:14:34.877312Z  INFO nightfall: New session a7877471-7fbc-4dbc-a337-1a6a03ced473 map 1 -> aac@120000
2023-11-24T14:14:34.877320Z  INFO nightfall: Session a7877471-7fbc-4dbc-a337-1a6a03ced473 chain aac
2023-11-24T14:14:34.877342Z  INFO nightfall: New session 5171465f-71f1-4720-8319-e7da7254f832 map 2 -> aac@120000
2023-11-24T14:14:34.877352Z  INFO nightfall: Session 5171465f-71f1-4720-8319-e7da7254f832 chain aac
2023-11-24T14:14:34.877371Z  INFO nightfall: New session 74ba47cb-9b02-483e-b2ae-b25f0216a11d map 3 -> webvtt
2023-11-24T14:14:34.877377Z  INFO nightfall: Session 74ba47cb-9b02-483e-b2ae-b25f0216a11d chain webvtt
2023-11-24T14:14:34.877394Z  INFO nightfall: New session bac37a64-318a-418c-89d5-e64aa4fe090d map 4 -> webvtt
2023-11-24T14:14:34.877406Z  INFO nightfall: Session bac37a64-318a-418c-89d5-e64aa4fe090d chain webvtt
2023-11-24T14:14:34.877489Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=1437 ms status=200
2023-11-24T14:14:34.890932Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.902381Z  INFO nightfall: New session bd5864ff-4a5b-4fe7-93ae-dca11fc2bdfa map 0 -> h264@10000000
2023-11-24T14:14:34.902401Z  INFO nightfall: Session bd5864ff-4a5b-4fe7-93ae-dca11fc2bdfa chain h264 -> h264_cuda
2023-11-24T14:14:34.902426Z  INFO nightfall: New session 5af0042b-83d1-44b4-9fd4-a419443e29cc map 0 -> h264@5000000
2023-11-24T14:14:34.902433Z  INFO nightfall: Session 5af0042b-83d1-44b4-9fd4-a419443e29cc chain h264 -> h264_cuda
2023-11-24T14:14:34.902453Z  INFO nightfall: New session 96d9f2a9-7d03-44f0-96c7-6c7da249ff24 map 0 -> h264@1000000
2023-11-24T14:14:34.902459Z  INFO nightfall: Session 96d9f2a9-7d03-44f0-96c7-6c7da249ff24 chain h264 -> h264_cuda
2023-11-24T14:14:34.902474Z  INFO nightfall: New session b536ceb3-5d57-4137-8fb7-e0a14bc244ec map 1 -> aac@120000
2023-11-24T14:14:34.902480Z  INFO nightfall: Session b536ceb3-5d57-4137-8fb7-e0a14bc244ec chain aac
2023-11-24T14:14:34.902498Z  INFO nightfall: New session 9d42ffcc-89f0-4261-b98d-a08dc98929b5 map 2 -> aac@120000
2023-11-24T14:14:34.902504Z  INFO nightfall: Session 9d42ffcc-89f0-4261-b98d-a08dc98929b5 chain aac
2023-11-24T14:14:34.902527Z  INFO nightfall: New session 35811335-b764-41cd-8394-4fb3d4205a48 map 3 -> webvtt
2023-11-24T14:14:34.902534Z  INFO nightfall: Session 35811335-b764-41cd-8394-4fb3d4205a48 chain webvtt
2023-11-24T14:14:34.902550Z  INFO nightfall: New session f1dc42e5-1c55-41f8-ade6-c83df990c00c map 4 -> webvtt
2023-11-24T14:14:34.902555Z  INFO nightfall: Session f1dc42e5-1c55-41f8-ade6-c83df990c00c chain webvtt
2023-11-24T14:14:34.902629Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=11 ms status=200
2023-11-24T14:14:34.914481Z DEBUG request{method=GET uri=/api/v1/stream/866b7fa9-dedf-48c9-a41e-ec984722c5d9/manifest.mpd?start_num=0&should_kill=false&includes=bf4c203f-f16d-4ad8-8a88-740af937f563,21cde943-436c-4acd-84ea-7199a4bbc0e4,ca064423-a48d-4f40-b5db-6ce2f7ee4e77,a7877471-7fbc-4dbc-a337-1a6a03ced473,5171465f-71f1-4720-8319-e7da7254f832 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.914840Z DEBUG request{method=GET uri=/api/v1/stream/866b7fa9-dedf-48c9-a41e-ec984722c5d9/manifest.mpd?start_num=0&should_kill=false&includes=bf4c203f-f16d-4ad8-8a88-740af937f563,21cde943-436c-4acd-84ea-7199a4bbc0e4,ca064423-a48d-4f40-b5db-6ce2f7ee4e77,a7877471-7fbc-4dbc-a337-1a6a03ced473,5171465f-71f1-4720-8319-e7da7254f832 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T14:14:34.918214Z DEBUG request{method=GET uri=/api/v1/stream/866b7fa9-dedf-48c9-a41e-ec984722c5d9/state/kill version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.918261Z  INFO nightfall: Killing session bf4c203f-f16d-4ad8-8a88-740af937f563
2023-11-24T14:14:34.918278Z  INFO nightfall: Killing session 21cde943-436c-4acd-84ea-7199a4bbc0e4
2023-11-24T14:14:34.918291Z  INFO nightfall: Killing session ca064423-a48d-4f40-b5db-6ce2f7ee4e77
2023-11-24T14:14:34.918302Z  INFO nightfall: Killing session a7877471-7fbc-4dbc-a337-1a6a03ced473
2023-11-24T14:14:34.918382Z  INFO nightfall: Killing session 5171465f-71f1-4720-8319-e7da7254f832
2023-11-24T14:14:34.918400Z  INFO nightfall: Killing session 74ba47cb-9b02-483e-b2ae-b25f0216a11d
2023-11-24T14:14:34.918427Z  INFO nightfall: Killing session bac37a64-318a-418c-89d5-e64aa4fe090d
2023-11-24T14:14:34.918454Z DEBUG request{method=GET uri=/api/v1/stream/866b7fa9-dedf-48c9-a41e-ec984722c5d9/state/kill version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=204
2023-11-24T14:14:34.922486Z DEBUG request{method=GET uri=/api/v1/stream/dee9e5be-5d6d-4c34-85d0-a3658ee713ec/manifest.mpd?start_num=0&should_kill=false&includes=bf4c203f-f16d-4ad8-8a88-740af937f563,21cde943-436c-4acd-84ea-7199a4bbc0e4,ca064423-a48d-4f40-b5db-6ce2f7ee4e77,a7877471-7fbc-4dbc-a337-1a6a03ced473,5171465f-71f1-4720-8319-e7da7254f832 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.922761Z DEBUG request{method=GET uri=/api/v1/stream/dee9e5be-5d6d-4c34-85d0-a3658ee713ec/manifest.mpd?start_num=0&should_kill=false&includes=bf4c203f-f16d-4ad8-8a88-740af937f563,21cde943-436c-4acd-84ea-7199a4bbc0e4,ca064423-a48d-4f40-b5db-6ce2f7ee4e77,a7877471-7fbc-4dbc-a337-1a6a03ced473,5171465f-71f1-4720-8319-e7da7254f832 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T14:14:34.926439Z DEBUG request{method=GET uri=/api/v1/stream/dee9e5be-5d6d-4c34-85d0-a3658ee713ec/state/kill version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.926459Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.926472Z  INFO nightfall: Killing session bd5864ff-4a5b-4fe7-93ae-dca11fc2bdfa
2023-11-24T14:14:34.926487Z  INFO nightfall: Killing session 5af0042b-83d1-44b4-9fd4-a419443e29cc
2023-11-24T14:14:34.926503Z  INFO nightfall: Killing session 96d9f2a9-7d03-44f0-96c7-6c7da249ff24
2023-11-24T14:14:34.926514Z  INFO nightfall: Killing session b536ceb3-5d57-4137-8fb7-e0a14bc244ec
2023-11-24T14:14:34.926528Z  INFO nightfall: Killing session 9d42ffcc-89f0-4261-b98d-a08dc98929b5
2023-11-24T14:14:34.926537Z  INFO nightfall: Killing session 35811335-b764-41cd-8394-4fb3d4205a48
2023-11-24T14:14:34.926569Z  INFO nightfall: Killing session f1dc42e5-1c55-41f8-ade6-c83df990c00c
2023-11-24T14:14:34.926590Z DEBUG request{method=GET uri=/api/v1/stream/dee9e5be-5d6d-4c34-85d0-a3658ee713ec/state/kill version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=204
2023-11-24T14:14:34.937580Z  INFO nightfall: New session 7c37b921-2610-4b88-8679-9ffcfc94f5d6 map 0 -> h264@10000000
2023-11-24T14:14:34.937597Z  INFO nightfall: Session 7c37b921-2610-4b88-8679-9ffcfc94f5d6 chain h264 -> h264_cuda
2023-11-24T14:14:34.937621Z  INFO nightfall: New session 83de8cd4-f2e1-465a-bf80-b7dc593c3555 map 0 -> h264@5000000
2023-11-24T14:14:34.937627Z  INFO nightfall: Session 83de8cd4-f2e1-465a-bf80-b7dc593c3555 chain h264 -> h264_cuda
2023-11-24T14:14:34.937647Z  INFO nightfall: New session 01cefd29-9e46-4579-90fb-0a9f1e95f41b map 0 -> h264@1000000
2023-11-24T14:14:34.937652Z  INFO nightfall: Session 01cefd29-9e46-4579-90fb-0a9f1e95f41b chain h264 -> h264_cuda
2023-11-24T14:14:34.937666Z  INFO nightfall: New session 5dd5e264-7d12-446a-a064-8248ece600fa map 1 -> aac@120000
2023-11-24T14:14:34.937673Z  INFO nightfall: Session 5dd5e264-7d12-446a-a064-8248ece600fa chain aac
2023-11-24T14:14:34.937690Z  INFO nightfall: New session f584174e-e79f-4bf1-a7e7-087c1774da2a map 2 -> aac@120000
2023-11-24T14:14:34.937696Z  INFO nightfall: Session f584174e-e79f-4bf1-a7e7-087c1774da2a chain aac
2023-11-24T14:14:34.937710Z  INFO nightfall: New session 0980e6f0-801f-43bf-b5bf-501964d7e126 map 3 -> webvtt
2023-11-24T14:14:34.937717Z  INFO nightfall: Session 0980e6f0-801f-43bf-b5bf-501964d7e126 chain webvtt
2023-11-24T14:14:34.937732Z  INFO nightfall: New session b5be575d-0564-42fa-99d4-603700961e5f map 4 -> webvtt
2023-11-24T14:14:34.937738Z  INFO nightfall: Session b5be575d-0564-42fa-99d4-603700961e5f chain webvtt
2023-11-24T14:14:34.937808Z DEBUG request{method=GET uri=/api/v1/stream/7323/manifest?force_ass=false version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=11 ms status=200
2023-11-24T14:14:34.950612Z DEBUG request{method=GET uri=/api/v1/stream/1b249a91-0974-451d-ac25-1b0e94a2ee4c/manifest.mpd?start_num=0&should_kill=false&includes=7c37b921-2610-4b88-8679-9ffcfc94f5d6,83de8cd4-f2e1-465a-bf80-b7dc593c3555,01cefd29-9e46-4579-90fb-0a9f1e95f41b,5dd5e264-7d12-446a-a064-8248ece600fa,f584174e-e79f-4bf1-a7e7-087c1774da2a version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.950930Z DEBUG request{method=GET uri=/api/v1/stream/1b249a91-0974-451d-ac25-1b0e94a2ee4c/manifest.mpd?start_num=0&should_kill=false&includes=7c37b921-2610-4b88-8679-9ffcfc94f5d6,83de8cd4-f2e1-465a-bf80-b7dc593c3555,01cefd29-9e46-4579-90fb-0a9f1e95f41b,5dd5e264-7d12-446a-a064-8248ece600fa,f584174e-e79f-4bf1-a7e7-087c1774da2a version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2023-11-24T14:14:34.979515Z DEBUG request{method=GET uri=/api/v1/stream/5dd5e264-7d12-446a-a064-8248ece600fa/data/init.mp4?start_num=0 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:34.979529Z DEBUG request{method=GET uri=/api/v1/stream/7c37b921-2610-4b88-8679-9ffcfc94f5d6/data/init.mp4?start_num=0 version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:35.182706Z DEBUG request{method=GET uri=/api/v1/stream/5dd5e264-7d12-446a-a064-8248ece600fa/data/init.mp4?start_num=0 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=203 ms status=200
2023-11-24T14:14:35.200334Z DEBUG request{method=GET uri=/api/v1/stream/5dd5e264-7d12-446a-a064-8248ece600fa/data/0.m4s version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:35.201941Z DEBUG request{method=GET uri=/api/v1/stream/5dd5e264-7d12-446a-a064-8248ece600fa/data/0.m4s version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=1 ms status=200
2023-11-24T14:14:35.349032Z  INFO nightfall: Reaping 14 streams
2023-11-24T14:14:35.384932Z  INFO nightfall: Session 7c37b921-2610-4b88-8679-9ffcfc94f5d6 chunk=0 trying profile h264
2023-11-24T14:14:36.807876Z DEBUG request{method=GET uri=/api/v1/stream/7c37b921-2610-4b88-8679-9ffcfc94f5d6/data/init.mp4?start_num=0 version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=1828 ms status=200
2023-11-24T14:14:36.904099Z DEBUG request{method=GET uri=/api/v1/stream/7c37b921-2610-4b88-8679-9ffcfc94f5d6/data/0.m4s version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:36.928754Z DEBUG request{method=GET uri=/api/v1/stream/7c37b921-2610-4b88-8679-9ffcfc94f5d6/data/0.m4s version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=24 ms status=200
2023-11-24T14:14:37.478511Z DEBUG request{method=GET uri=/api/v1/stream/7c37b921-2610-4b88-8679-9ffcfc94f5d6/data/1.m4s version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:37.494807Z DEBUG request{method=GET uri=/api/v1/stream/1b249a91-0974-451d-ac25-1b0e94a2ee4c/state/kill version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:37.494879Z  INFO nightfall: Killing session 7c37b921-2610-4b88-8679-9ffcfc94f5d6
2023-11-24T14:14:37.496597Z DEBUG request{method=GET uri=/static/textLogoWhite128.png version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:14:37.496623Z DEBUG request{method=GET uri=/static/textLogoWhite128.png version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=404
2023-11-24T14:14:37.513981Z  INFO nightfall: Killing session 83de8cd4-f2e1-465a-bf80-b7dc593c3555
2023-11-24T14:14:37.514017Z  INFO nightfall: Killing session 01cefd29-9e46-4579-90fb-0a9f1e95f41b
2023-11-24T14:14:37.514031Z  INFO nightfall: Killing session 5dd5e264-7d12-446a-a064-8248ece600fa
2023-11-24T14:14:37.515537Z  INFO nightfall: Killing session f584174e-e79f-4bf1-a7e7-087c1774da2a
2023-11-24T14:14:37.515559Z  INFO nightfall: Killing session 0980e6f0-801f-43bf-b5bf-501964d7e126
2023-11-24T14:14:37.515571Z  INFO nightfall: Killing session b5be575d-0564-42fa-99d4-603700961e5f
2023-11-24T14:14:37.515599Z DEBUG request{method=GET uri=/api/v1/stream/1b249a91-0974-451d-ac25-1b0e94a2ee4c/state/kill version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=20 ms status=204
2023-11-24T14:14:38.349137Z  INFO nightfall: Reaping 7 streams
2023-11-24T14:15:51.584376Z DEBUG request{method=GET uri=/static/logoBlack128.png version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2023-11-24T14:15:51.584422Z DEBUG request{method=GET uri=/static/logoBlack128.png version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200

@jpeeler
Copy link

jpeeler commented Nov 28, 2023

I'm seeing the same thing. I'm new to this project, so maybe I'm doing something wrong. But I can't get a single file to play, even after using the proposed ffmpeg re-encoding. Using the docker image dim:dev, which seems pretty recent. I don't have any logs that seem relevant outside of what's been reported above.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
S-needs-triage Status: Needs triage T-bug Something isn't working the way it is supposed to
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jpeeler @Lyamc @vgarleanu