Metadata decoder appends \u0000 - LS-main 2.2.0

joe-ms commented 1 year ago

Problem A few days ago I switched to liquidsoap-main 2.2.0 with ocaml-ffmpeg and ocaml-metadata also pinned to main.

I noticed that metadata written in json to /tmp/songs started looking like this, as well as my tts-speaker would read out the \u0000 from my mp3's with ID3v2 tags. { "album": "album\u0000", "year": "year", "artist": "artist\u0000", "title": "title\u0000", "comment": "comment", "tracknumber": "tracknumber\u0000" }

Actually liquidsoap crashes when special characters (e.g. æ, ø, å) are part of the metadata. In my /tmp/songs it would look something like this: "årtist": "��r(null)t(null)i(null)s(null)t"

Quick-fix I found that prioritising "taglib" before "ID3" solves the problem, as "taglib" is per dev-default last priority. settings.request.metadata_decoders.set(["video-metadata", "ogg-native", "image", "taglib", "ID3", "ID3v1", "ID3v2", "mp4", "ffmpeg", "flac", "ogg"])

Possible solution I guess it is probably something within the ocaml-metadata src, but that is way over my league.

smimram commented 1 year ago

Would it be possible for you to share an mp3 which exhibits the problem so that we can reproduce?

joe-ms commented 1 year ago

Thanks @smimram , here you go. The link is up 24H. https://upload.disroot.org/r/aK9vLgW5#S+z8y9rTUCw5Xzkb11/leAhp5OGOR/kcrnlrfK9Rsmo= { "album": "Sumut\u0000", "year": "1973", "artist": "Sume\u0000", "title": "Ukiak\u0000", "comment": "Created with Ardour", "tracknumber": "10\u0000" }

joe-ms commented 1 year ago

Sorry, the mp3 is without a special character in the metadata. But you can probably easily alter, if it's not just due to faulty ID3v2 encoding. Anyway, hereunder some crash-logs caused by an â.

The crash is caused by my homemade tts-protocol martha:

2022/11/16 22:37:19 [single_1:5] Assigning source content type for frame type: 'A
2022/11/16 22:37:19 [single_1:5] Content type: {audio=pcm(stereo)}
2022/11/16 22:37:19 [source:4] Source single_1 gets up with content type: {audio=pcm(stereo)}.
2022/11/16 22:37:19 [single_1:5] Clock is ?(3fa6f9139b0c:0)[].
2022/11/16 22:37:19 [single_1:4] Content type is {audio=pcm(stereo)}.
2022/11/16 22:37:19 [single_1:5] Activations changed: static=[append_0:switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:37:19 [request:5] Resolving request [[martha:��Sekernup Kingerp�]].
2022/11/16 22:37:19 [append_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [switch_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [on_track_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [switch_1:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [amplify_0:4] Overriding amplification: 1.947601.
2022/11/16 22:37:19 [amplify_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [threads:2] Queue generic queue #2 crashed with exception Lang.Runtime_error { kind: "string", msg: "Error while escaping utf8 string. If you are not sure about the string's encoding, you should use `\"ascii\"` as this encoding never fails.", pos: [at /home/dj/liquidsoap-daemon/script/script.liq, line 70, char 21-142, at /home/dj/.opam/4.14.0/share/liquidsoap-lang/libs/string.liq, line 177, char 6-68, at /home/dj/.opam/4.14.0/share/liquidsoap-lang/libs/string.liq, line 177, char 6-68] }
2022/11/16 22:37:19 [threads:2] Raised at Stdlib.failwith in file "stdlib.ml", line 29, characters 17-33
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Lang_string.escape.f in file "src/lang/lang_string.ml", line 5, characters 19-37
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Lang_string.escape_string in file "src/lang/lang_string.ml", line 126, characters 22-30
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Builtins_string.(fun) in file "src/lang/builtins_string.ml", line 149, characters 10-119
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval in file "src/lang/evaluation.ml", line 205, characters 16-26
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Tutils.finalize in file "src/core/tools/tutils.ml", line 105, characters 12-16
2022/11/16 22:37:19 [threads:2] Re-raised at Tutils.finalize in file "src/core/tools/tutils.ml", line 111, characters 4-38
2022/11/16 22:37:19 [threads:2] Called from Builtins_resolvers.(fun) in file "src/core/builtins/builtins_resolvers.ml", line 163, characters 12-175
2022/11/16 22:37:19 [threads:2] Called from Request.resolve.resolve_step in file "src/core/request.ml", line 615, characters 20-64
2022/11/16 22:37:19 [threads:2] Called from Request_source.queued#fetch in file "src/core/sources/request_source.ml", line 458, characters 14-73
2022/11/16 22:37:19 [threads:2] Called from Request_source.queued#feed_queue in file "src/core/sources/request_source.ml", line 439, characters 14-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.Async.add.task in file "src/duppy.ml", line 393, characters 20-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.Task.t_of_task.(fun) in file "src/duppy.ml", line 148, characters 50-66
2022/11/16 22:37:19 [threads:2] Called from Duppy.exec in file "src/duppy.ml", line 275, characters 12-21
2022/11/16 22:37:19 [threads:2] Called from Duppy.queue.run in file "src/duppy.ml", line 307, characters 7-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.queue in file "src/duppy.ml", line 357, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Duppy.queue in file "src/duppy.ml", line 361, characters 8-17
2022/11/16 22:37:19 [threads:2] Called from Tutils.create.(fun).process in file "src/core/tools/tutils.ml", line 164, characters 12-15
2022/11/16 22:37:19 [threads:2] 
2022/11/16 22:37:19 [threads:1] PANIC: Liquidsoap has crashed, exiting.,
2022/11/16 22:37:19 [threads:1] Please report at: savonet-users@lists.sf.net

I also tested with say: and it shuts down

2022/11/16 22:54:15 [lang:4] No cover found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3.
2022/11/16 22:54:15 [decoder.srt:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [single_1:5] Assigning source content type for frame type: 'A
2022/11/16 22:54:15 [single_1:5] Content type: {audio=pcm(stereo)}
2022/11/16 22:54:15 [source:4] Source single_1 gets up with content type: {audio=pcm(stereo)}.
2022/11/16 22:54:15 [single_1:3] "say:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2" is static, resolving once for all...
2022/11/16 22:54:15 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [request:5] Resolving request [[say:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [request:5] Resolving request [[gtts:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.wav:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [lang:4] Processing mp3,gtts-cli -o $(output) '��Sekernup Kingerp�'
2022/11/16 22:54:15 [lang:4] Executing gtts-cli -o '/tmp/liq-process9101f9.mp3' '��Sekernup Kingerp�'
2022/11/16 22:54:15 [sandbox:5] Command: gtts-cli -o '/tmp/liq-process9101f9.mp3' '��Sekernup Kingerp�'
2022/11/16 22:54:15 [process:4] Starting process
2022/11/16 22:54:15 [lang:4] Stereo: failed to resolve request gtts:��Sekernup Kingerp�
2022/11/16 22:54:15 [request:4] Failed to resolve "stereo:gtts:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2"! For more info, see server command `request.trace 2`.
2022/11/16 22:54:15 [request:5] Resolving request [[text2wave:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [lang:4] Processing wav,echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > $(output)
2022/11/16 22:54:15 [lang:4] Executing echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > '/tmp/liq-process0d514b.wav'
2022/11/16 22:54:15 [sandbox:5] Command: echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > '/tmp/liq-process0d514b.wav'
2022/11/16 22:54:15 [process:4] Starting process
2022/11/16 22:54:15 [lang:4] Stereo: failed to resolve request text2wave:��Sekernup Kingerp�
2022/11/16 22:54:15 [request:4] Failed to resolve "stereo:text2wave:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2"! For more info, see server command `request.trace 2`.
2022/11/16 22:54:15 [request:5] Resolved to [].
2022/11/16 22:54:15 [clock.main:4] Source output_srt failed while streaming: Request_simple.Invalid_URI("say:\255\254S\000e\000k\000e\000r\000n\000u\000p\000 \000K\000i\000n\000g\000e\000r\000p\000\226")!
2022/11/16 22:54:15 [clock.main:4] Raised at Request_simple.unqueued#wake_up in file "src/core/sources/request_simple.ml", line 72, characters 11-34
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 456, characters 8-31
2022/11/16 22:54:15 [clock.main:4] Called from Append.append#get_frame in file "src/core/operators/append.ml", line 55, characters 18-38
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from On_track.on_track#get_frame in file "src/core/operators/on_track.ml", line 36, characters 6-14
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Amplify.amplify#get_frame in file "src/core/operators/amplify.ml", line 39, characters 6-20
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Output.output#output in file "src/core/outputs/output.ml", line 169, characters 10-30
2022/11/16 22:54:15 [clock.main:4] Called from Clock.clock#end_tick.(fun) in file "src/core/clock.ml", line 299, characters 14-22
2022/11/16 22:54:15 [clock.main:4] 
2022/11/16 22:54:15 [output_srt:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source output_srt gets down.
2022/11/16 22:54:15 [amplify_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source amplify_0 gets down.
2022/11/16 22:54:15 [switch_1:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source switch_1 gets down.
2022/11/16 22:54:15 [on_track_0:5] Activations changed: static=[switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:54:15 [GL:5] Activations changed: static=[], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/16 22:54:15 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/16 22:54:15 [on_track_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source on_track_0 gets down.
2022/11/16 22:54:15 [switch_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source switch_0 gets down.
2022/11/16 22:54:15 [GL:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source GL gets down.
2022/11/16 22:54:15 [GL:4] Waiting for feeding task to stop...
2022/11/16 22:54:15 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2022/11/16 22:54:15 [decoder:4] Trying decoder "ffmpeg"
2022/11/16 22:54:15 [decoder.ffmpeg:4] ffmpeg recognizes "/home/dj/music/Jingles/GL/47_Audio 1.mp3" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo)}.
2022/11/16 22:54:15 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/Jingles/GL/47_Audio 1.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2022/11/16 22:54:15 [request:2] Cannot find decoder flac
2022/11/16 22:54:15 [request:2] Cannot find decoder mp4
2022/11/16 22:54:15 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:16 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:16 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:16 [request:5] Resolved to [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [request:5] Resolving request [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [request:5] Resolved to [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [GL:4] Queued 1 requests
2022/11/16 22:54:16 [GL:4] Cleaning up request queue...
2022/11/16 22:54:16 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:54:16 [append_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:16 [source:4] Source append_0 gets down.
2022/11/16 22:54:16 [single_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:16 [source:4] Source single_0 gets down.
2022/11/16 22:54:16 [single_0:4] Finished with "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerp\195\162.mp3".
2022/11/16 22:54:16 [main:3] Shutdown started!
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap core shutdown"
2022/11/16 22:54:16 [main:3] Waiting for main threads to terminate...
2022/11/16 22:54:16 [threads:4] Waiting for thread clock_main to shutdown
2022/11/16 22:54:16 [clock.main:3] Streaming loop stopped.
2022/11/16 22:54:16 [threads:4] Thread "clock_main" terminated (0 remaining).
2022/11/16 22:54:16 [main:3] Main threads terminated.
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown"
2022/11/16 22:54:16 [threads:3] Shutting down scheduler...
2022/11/16 22:54:16 [threads:4] Thread "generic queue #2" terminated (3 remaining).
2022/11/16 22:54:16 [threads:4] Thread "non-blocking queue #1" terminated (2 remaining).
2022/11/16 22:54:16 [threads:4] Thread "non-blocking queue #2" terminated (1 remaining).
2022/11/16 22:54:16 [threads:4] Thread "generic queue #1" terminated (0 remaining).
2022/11/16 22:54:16 [threads:3] Scheduler shut down.
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap final cleanup"
2022/11/16 22:54:16 [main:3] Cleaning downloaded files...
2022/11/16 22:54:16 [main:3] Freeing memory...

smimram commented 1 year ago

Concerning the file you sent me, I have added the id3 header as a test (only the header not the actual mp3). The output clearly shows some parsing problems:

$ ./meta id3v2/liquidsoap2738.tag 

# id3v2/liquidsoap2738.tag

- title: "Ukiak\000"
- artist: "Sume\000"
- tracknumber: "10\000"
- album: "Sumut\000"
- TXXX: "\000year\0001973\000"
- RVA2: "album\000\001\007\210\0167\135"
- RVA2: "track\000\001\r\020\016'\227"
- TXXX: "\000Country\000GL\000"
- TXXX: "\000LABEL\000Demos\000"
- encoder: "Lavf59.16.100\000"
- TXXX: "\000CATALOGNUMBER\000Demos 13\000"
- TXXX: "\003comment\000Created with Ardour\000"
- TXXX: "\003REPLAYGAIN_ALBUM_PEAK\0000.4338\000"
- TXXX: "\003REPLAYGAIN_TRACK_PEAK\0000.3116\000"
- TXXX: "\003REPLAYGAIN_ALBUM_GAIN\0003.91 dB\000"
- TXXX: "\003REPLAYGAIN_TRACK_GAIN\0006.54 dB\000"

joe-ms commented 1 year ago

Does this mean that my id3 is causing the problem or is it liquidsoap? Should I re-encode id3 to clean above parsing problems?

The tags are first created by Ardour, then Kid3, then quodlibet for replaygain.

smimram commented 1 year ago

The problem was on our side. I have just enhanced metadata parsing in ocaml-metadata, and now we get

- title: "Ukiak"
- artist: "Sume"
- tracknumber: "10"
- album: "Sumut"
- year: "1973"
- RVA2: "album\000\001\007\210\0167\135"
- RVA2: "track\000\001\r\020\016'\227"
- Country: "GL"
- LABEL: "Demos"
- encoder: "Lavf59.16.100"
- CATALOGNUMBER: "Demos 13"
- comment: "Created with Ardour"
- REPLAYGAIN_ALBUM_PEAK: "0.4338"
- REPLAYGAIN_TRACK_PEAK: "0.3116"
- REPLAYGAIN_ALBUM_GAIN: "3.91 dB"
- REPLAYGAIN_TRACK_GAIN: "6.54 dB"

joe-ms commented 1 year ago

I just upgraded ocaml-metadata and reset settings.request.metadata_decoders.set Everything seemed to be working fine, but then my radio crashed. In this case a culprit ø

/tmp/songs:

{
  "country": "GL",
  "album": "Ungangisaq",
  "year": "1986",
  "artist": "Q\u0000a\u0000t\u0000a\u0000n\u0000n\u0000g\u0000u\u0000t\u0000i\u0000n\u0000g\u0000i\u0000i\u0000t\u0000 \u0000M\u0000�(null)"
  "title": "Ukendt nummer",
  "tracknumber": "4"
}

smimram commented 1 year ago

Good, we're progressing... Can you please do send me the corresponding mp3?

smimram commented 1 year ago

Actually, the commit https://github.com/savonet/ocaml-metadata/commit/546b23a0cea7f3e26ef48acc368219c46b9e1569 should help. Could you test it if you have a chance?

toots commented 1 year ago

Thanks for this report. I have just pushed a commit mitigating this specific exception. With this commit, we will always fallback to ascii string parsing and escaping when utf8 escaping fails unless an explicit "utf8" encoding parameter is passed.

This should avoid failing the script when the user just wants to escape a string without specific encoding requirements.

2022/11/16 22:37:19 [single_1:5] Assigning source content type for frame type: 'A
2022/11/16 22:37:19 [single_1:5] Content type: {audio=pcm(stereo)}
2022/11/16 22:37:19 [source:4] Source single_1 gets up with content type: {audio=pcm(stereo)}.
2022/11/16 22:37:19 [single_1:5] Clock is ?(3fa6f9139b0c:0)[].
2022/11/16 22:37:19 [single_1:4] Content type is {audio=pcm(stereo)}.
2022/11/16 22:37:19 [single_1:5] Activations changed: static=[append_0:switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:37:19 [request:5] Resolving request [[martha:��Sekernup Kingerp�]].
2022/11/16 22:37:19 [append_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [switch_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [on_track_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [switch_1:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [amplify_0:4] Overriding amplification: 1.947601.
2022/11/16 22:37:19 [amplify_0:5] Got metadata at position 0: calling handlers...
2022/11/16 22:37:19 [threads:2] Queue generic queue #2 crashed with exception Lang.Runtime_error { kind: "string", msg: "Error while escaping utf8 string. If you are not sure about the string's encoding, you should use `\"ascii\"` as this encoding never fails.", pos: [at /home/dj/liquidsoap-daemon/script/script.liq, line 70, char 21-142, at /home/dj/.opam/4.14.0/share/liquidsoap-lang/libs/string.liq, line 177, char 6-68, at /home/dj/.opam/4.14.0/share/liquidsoap-lang/libs/string.liq, line 177, char 6-68] }
2022/11/16 22:37:19 [threads:2] Raised at Stdlib.failwith in file "stdlib.ml", line 29, characters 17-33
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Lang_string.escape.f in file "src/lang/lang_string.ml", line 5, characters 19-37
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Lang_string.escape_string in file "src/lang/lang_string.ml", line 126, characters 22-30
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Builtins_string.(fun) in file "src/lang/builtins_string.ml", line 149, characters 10-119
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval in file "src/lang/evaluation.ml", line 205, characters 16-26
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 258, characters 46-56
2022/11/16 22:37:19 [threads:2] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 258, characters 18-60
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 281, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 49, characters 17-51
2022/11/16 22:37:19 [threads:2] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 284, characters 10-147
2022/11/16 22:37:19 [threads:2] Called from Tutils.finalize in file "src/core/tools/tutils.ml", line 105, characters 12-16
2022/11/16 22:37:19 [threads:2] Re-raised at Tutils.finalize in file "src/core/tools/tutils.ml", line 111, characters 4-38
2022/11/16 22:37:19 [threads:2] Called from Builtins_resolvers.(fun) in file "src/core/builtins/builtins_resolvers.ml", line 163, characters 12-175
2022/11/16 22:37:19 [threads:2] Called from Request.resolve.resolve_step in file "src/core/request.ml", line 615, characters 20-64
2022/11/16 22:37:19 [threads:2] Called from Request_source.queued#fetch in file "src/core/sources/request_source.ml", line 458, characters 14-73
2022/11/16 22:37:19 [threads:2] Called from Request_source.queued#feed_queue in file "src/core/sources/request_source.ml", line 439, characters 14-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.Async.add.task in file "src/duppy.ml", line 393, characters 20-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.Task.t_of_task.(fun) in file "src/duppy.ml", line 148, characters 50-66
2022/11/16 22:37:19 [threads:2] Called from Duppy.exec in file "src/duppy.ml", line 275, characters 12-21
2022/11/16 22:37:19 [threads:2] Called from Duppy.queue.run in file "src/duppy.ml", line 307, characters 7-24
2022/11/16 22:37:19 [threads:2] Called from Duppy.queue in file "src/duppy.ml", line 357, characters 8-12
2022/11/16 22:37:19 [threads:2] Re-raised at Duppy.queue in file "src/duppy.ml", line 361, characters 8-17
2022/11/16 22:37:19 [threads:2] Called from Tutils.create.(fun).process in file "src/core/tools/tutils.ml", line 164, characters 12-15
2022/11/16 22:37:19 [threads:2] 
2022/11/16 22:37:19 [threads:1] PANIC: Liquidsoap has crashed, exiting.,
2022/11/16 22:37:19 [threads:1] Please report at: savonet-users@lists.sf.net

I also tested with say: and it shuts down

2022/11/16 22:54:15 [lang:4] No cover found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3.
2022/11/16 22:54:15 [decoder.srt:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [single_1:5] Assigning source content type for frame type: 'A
2022/11/16 22:54:15 [single_1:5] Content type: {audio=pcm(stereo)}
2022/11/16 22:54:15 [source:4] Source single_1 gets up with content type: {audio=pcm(stereo)}.
2022/11/16 22:54:15 [single_1:3] "say:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2" is static, resolving once for all...
2022/11/16 22:54:15 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [request:5] Resolving request [[say:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [request:5] Resolving request [[gtts:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.wav:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [lang:4] Processing mp3,gtts-cli -o $(output) '��Sekernup Kingerp�'
2022/11/16 22:54:15 [lang:4] Executing gtts-cli -o '/tmp/liq-process9101f9.mp3' '��Sekernup Kingerp�'
2022/11/16 22:54:15 [sandbox:5] Command: gtts-cli -o '/tmp/liq-process9101f9.mp3' '��Sekernup Kingerp�'
2022/11/16 22:54:15 [process:4] Starting process
2022/11/16 22:54:15 [lang:4] Stereo: failed to resolve request gtts:��Sekernup Kingerp�
2022/11/16 22:54:15 [request:4] Failed to resolve "stereo:gtts:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2"! For more info, see server command `request.trace 2`.
2022/11/16 22:54:15 [request:5] Resolving request [[text2wave:��Sekernup Kingerp�]].
2022/11/16 22:54:15 [lang:4] Processing wav,echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > $(output)
2022/11/16 22:54:15 [lang:4] Executing echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > '/tmp/liq-process0d514b.wav'
2022/11/16 22:54:15 [sandbox:5] Command: echo '��Sekernup Kingerp�' | text2wave -scale 1.9 > '/tmp/liq-process0d514b.wav'
2022/11/16 22:54:15 [process:4] Starting process
2022/11/16 22:54:15 [lang:4] Stereo: failed to resolve request text2wave:��Sekernup Kingerp�
2022/11/16 22:54:15 [request:4] Failed to resolve "stereo:text2wave:\xFF\xFES\x00e\x00k\x00e\x00r\x00n\x00u\x00p\x00 \x00K\x00i\x00n\x00g\x00e\x00r\x00p\x00\xE2"! For more info, see server command `request.trace 2`.
2022/11/16 22:54:15 [request:5] Resolved to [].
2022/11/16 22:54:15 [clock.main:4] Source output_srt failed while streaming: Request_simple.Invalid_URI("say:\255\254S\000e\000k\000e\000r\000n\000u\000p\000 \000K\000i\000n\000g\000e\000r\000p\000\226")!
2022/11/16 22:54:15 [clock.main:4] Raised at Request_simple.unqueued#wake_up in file "src/core/sources/request_simple.ml", line 72, characters 11-34
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 456, characters 8-31
2022/11/16 22:54:15 [clock.main:4] Called from Append.append#get_frame in file "src/core/operators/append.ml", line 55, characters 18-38
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from On_track.on_track#get_frame in file "src/core/operators/on_track.ml", line 36, characters 6-14
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Amplify.amplify#get_frame in file "src/core/operators/amplify.ml", line 39, characters 6-20
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 576, characters 6-24
2022/11/16 22:54:15 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 647, characters 10-41
2022/11/16 22:54:15 [clock.main:4] Called from Output.output#output in file "src/core/outputs/output.ml", line 169, characters 10-30
2022/11/16 22:54:15 [clock.main:4] Called from Clock.clock#end_tick.(fun) in file "src/core/clock.ml", line 299, characters 14-22
2022/11/16 22:54:15 [clock.main:4] 
2022/11/16 22:54:15 [output_srt:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source output_srt gets down.
2022/11/16 22:54:15 [amplify_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source amplify_0 gets down.
2022/11/16 22:54:15 [switch_1:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source switch_1 gets down.
2022/11/16 22:54:15 [on_track_0:5] Activations changed: static=[switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:54:15 [GL:5] Activations changed: static=[], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/16 22:54:15 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/16 22:54:15 [on_track_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source on_track_0 gets down.
2022/11/16 22:54:15 [switch_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source switch_0 gets down.
2022/11/16 22:54:15 [GL:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:15 [source:4] Source GL gets down.
2022/11/16 22:54:15 [GL:4] Waiting for feeding task to stop...
2022/11/16 22:54:15 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2022/11/16 22:54:15 [decoder:4] Trying decoder "ffmpeg"
2022/11/16 22:54:15 [decoder.ffmpeg:4] ffmpeg recognizes "/home/dj/music/Jingles/GL/47_Audio 1.mp3" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo)}.
2022/11/16 22:54:15 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/Jingles/GL/47_Audio 1.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2022/11/16 22:54:15 [request:2] Cannot find decoder flac
2022/11/16 22:54:15 [request:2] Cannot find decoder mp4
2022/11/16 22:54:15 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:15 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:15 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:16 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/Jingles/GL/47_Audio 1.mp3"!
2022/11/16 22:54:16 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/47_Audio 1.mp3": audio/mpeg!
2022/11/16 22:54:16 [request:5] Resolved to [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [request:5] Resolving request [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [request:5] Resolved to [[/home/dj/music/Jingles/GL/47_Audio 1.mp3]].
2022/11/16 22:54:16 [GL:4] Queued 1 requests
2022/11/16 22:54:16 [GL:4] Cleaning up request queue...
2022/11/16 22:54:16 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/16 22:54:16 [append_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:16 [source:4] Source append_0 gets down.
2022/11/16 22:54:16 [single_0:5] Activations changed: static=[], dynamic=[].
2022/11/16 22:54:16 [source:4] Source single_0 gets down.
2022/11/16 22:54:16 [single_0:4] Finished with "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerp\195\162.mp3".
2022/11/16 22:54:16 [main:3] Shutdown started!
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap core shutdown"
2022/11/16 22:54:16 [main:3] Waiting for main threads to terminate...
2022/11/16 22:54:16 [threads:4] Waiting for thread clock_main to shutdown
2022/11/16 22:54:16 [clock.main:3] Streaming loop stopped.
2022/11/16 22:54:16 [threads:4] Thread "clock_main" terminated (0 remaining).
2022/11/16 22:54:16 [main:3] Main threads terminated.
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown"
2022/11/16 22:54:16 [threads:3] Shutting down scheduler...
2022/11/16 22:54:16 [threads:4] Thread "generic queue #2" terminated (3 remaining).
2022/11/16 22:54:16 [threads:4] Thread "non-blocking queue #1" terminated (2 remaining).
2022/11/16 22:54:16 [threads:4] Thread "non-blocking queue #2" terminated (1 remaining).
2022/11/16 22:54:16 [threads:4] Thread "generic queue #1" terminated (0 remaining).
2022/11/16 22:54:16 [threads:3] Scheduler shut down.
2022/11/16 22:54:16 [lifecycle:5] At stage: "Liquidsoap final cleanup"
2022/11/16 22:54:16 [main:3] Cleaning downloaded files...
2022/11/16 22:54:16 [main:3] Freeing memory...

joe-ms commented 1 year ago

Just upgraded to latest ocaml-metadata 0.1.0 and liquidsoap 2.2.0 and ran a test with metadata containing an â with below crash result.

This file as single source (up 24H) https://upload.disroot.org/r/kuFUC_vB#2vmmjZn6zxbg7plSI5JVdMKLxoDgFnKeuAtTJxWorbY=

2022/11/18 18:34:46 >>> LOG START
2022/11/18 18:34:42 [main:3] Liquidsoap d6638f9+git@d6638f9a
2022/11/18 18:34:42 [main:3] Using: angstrom=0.15.0 bigarray=[distributed with OCaml] bigarray-compat=1.1.0 bigstringaf=0.9.0 bytes=[distributed with OCaml] cry=0.6.7 ctypes=0.20.1 ctypes.foreign=0.20.1 ctypes.stubs=0.20.1 curl=0.9.2 dtools=0.4.4 dune-build-info=3.5.0 dune-private-libs.dune-section=3.5.0 dune-site=3.5.0 dune-site.private=3.5.0 duppy=0.9.2 ffmpeg-av=705e4cb ffmpeg-avcodec=705e4cb ffmpeg-avdevice=705e4cb ffmpeg-avfilter=705e4cb ffmpeg-avutil=705e4cb ffmpeg-swresample=705e4cb ffmpeg-swscale=705e4cb gen=1.0 integers lame=0.3.6 liquidsoap-lang=d6638f9 liquidsoap_builtins=d6638f9-dirty liquidsoap_core=d6638f9-dirty liquidsoap_ffmpeg=d6638f9-dirty liquidsoap_lame=d6638f9-dirty liquidsoap_mad=d6638f9-dirty liquidsoap_magic=d6638f9-dirty liquidsoap_ogg=d6638f9-dirty liquidsoap_optionals=d6638f9-dirty liquidsoap_opus=d6638f9-dirty liquidsoap_oss=d6638f9-dirty liquidsoap_runtime=d6638f9-dirty liquidsoap_samplerate=d6638f9-dirty liquidsoap_srt=d6638f9-dirty liquidsoap_ssl=d6638f9-dirty liquidsoap_taglib=d6638f9-dirty mad=0.5.2 magic=0.7.3 menhirLib=20220210 metadata=546b23a mm=a241c73 mm.audio=a241c73 mm.base=a241c73 mm.image=a241c73 mm.midi=a241c73 mm.video=a241c73 ogg=0.7.3 ogg.decoder=0.7.3 opus=0.2.2 opus.decoder=0.2.2 pcre=7.5.0 posix-base=2.0.1 posix-socket=2.0.1 posix-socket.constants=2.0.1 posix-socket.stubs=2.0.1 posix-socket.types=2.0.1 samplerate=0.1.6 sedlex=3.0 seq=[distributed with OCaml 4.07 or above] srt=0.2.2 srt.constants=0.2.2 srt.stubs=0.2.2 srt.stubs.locked=0.2.2 srt.types=0.2.2 ssl=0.5.13 stdlib-shims=0.3.0 str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] unix=[distributed with OCaml] uri=4.2.0
2022/11/18 18:34:42 [clock:3] Using builtin (low-precision) implementation for latency control
2022/11/18 18:34:46 [main:3] Standard library loaded in 3.90 seconds.
2022/11/18 18:34:46 [lang.deprecated:2] WARNING: "add_protocol" is deprecated and will be removed in future version. Please use "protocol.add" instead.
2022/11/18 18:34:46 [GL:4] Reloading playlist.
2022/11/18 18:34:46 [GL:4] Playlist is a directory.
2022/11/18 18:34:46 [frame:4] frame.audio.samplerate set to: 44100
2022/11/18 18:34:46 [frame:4] frame.video.framerate set to: 25
2022/11/18 18:34:46 [main:3] Loaded /home/dj/liquidsoap-daemon/script/script.liq in 0.05 seconds.
2022/11/18 18:34:46 [frame:4] frame.audio.channels set to: 2
2022/11/18 18:34:46 [frame:4] frame.video.default set to: false
2022/11/18 18:34:46 [frame:4] frame.midi.channels set to: 0
2022/11/18 18:34:46 [frame:4] frame.video.width set to: 1280
2022/11/18 18:34:46 [frame:4] frame.video.height set to: 720
2022/11/18 18:34:46 [frame:4] frame.audio.samplerate set to: 44100
2022/11/18 18:34:46 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2022/11/18 18:34:46 [frame:3] Video frame size set to: 1280x720
2022/11/18 18:34:46 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2022/11/18 18:34:46 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2022/11/18 18:34:46 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2022/11/18 18:34:46 [sandbox:3] Sandboxing disabled
2022/11/18 18:34:46 [video.converter:3] Using preferred video converter: ffmpeg.
2022/11/18 18:34:46 [audio.converter:3] Using samplerate converter: libsamplerate.
2022/11/18 18:34:46 [lifecycle:5] At stage: "Liquidsoap application start"
2022/11/18 18:34:46 [clock:4] Currently 1 clock(s) allocated.
2022/11/18 18:34:46 [clock.main:4] Starting 1 source(s)...
2022/11/18 18:34:46 [srt_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [srt_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source srt_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [output_srt:5] Clock is main[].
2022/11/18 18:34:46 [output_srt:4] Content type is {audio=pcm(stereo)}.
2022/11/18 18:34:46 [amplify_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [amplify_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source amplify_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [amplify_0:5] Clock is main[].
2022/11/18 18:34:46 [amplify_0:4] Content type is {audio=pcm(stereo)}.
2022/11/18 18:34:46 [switch_1:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [switch_1:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source switch_1 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [on_track_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [on_track_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source on_track_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [on_track_0:5] Clock is main[].
2022/11/18 18:34:46 [on_track_0:4] Content type is {audio=pcm(stereo)}.
2022/11/18 18:34:46 [switch_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [switch_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source switch_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [GL:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [GL:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source GL gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [GL:5] Clock is main[].
2022/11/18 18:34:46 [GL:4] Content type is {audio=pcm(stereo)}.
2022/11/18 18:34:46 [GL:5] Activations changed: static=[], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [append_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [append_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source append_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [single_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/18 18:34:46 [single_0:5] Content type: {audio=pcm(stereo)}
2022/11/18 18:34:46 [source:4] Source single_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [single_0:3] "~/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" is static, resolving once for all...
2022/11/18 18:34:46 [request:5] Resolving request [[/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3]].
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder:4] Available decoders: ffmpeg (priority: 2), mad (priority: 1), image (priority: 1)
2022/11/18 18:34:46 [decoder:4] Trying decoder "ffmpeg"
2022/11/18 18:34:46 [decoder.ffmpeg:4] ffmpeg recognizes "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2022/11/18 18:34:46 [request:2] Cannot find decoder flac
2022/11/18 18:34:46 [request:2] Cannot find decoder mp4
2022/11/18 18:34:46 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/18 18:34:46 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/18 18:34:46 [charset:3] Conversion from UTF-16LE is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/18 18:34:46 [request:5] Resolved to [[/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3]].
2022/11/18 18:34:46 [single_0:5] Activations changed: static=[append_0:switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/18 18:34:46 [append_0:5] Activations changed: static=[], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [switch_0:5] Activations changed: static=[on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/18 18:34:46 [on_track_0:5] Activations changed: static=[], dynamic=[switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [GL:5] Activations changed: static=[], dynamic=[switch_1:amplify_0:output_srt:output_srt, switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [append_0:5] Activations changed: static=[], dynamic=[switch_1:amplify_0:output_srt:output_srt, switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [switch_1:5] Activations changed: static=[amplify_0:output_srt:output_srt], dynamic=[].
2022/11/18 18:34:46 [amplify_0:5] Activations changed: static=[output_srt:output_srt], dynamic=[].
2022/11/18 18:34:46 [output_srt:5] Activations changed: static=[output_srt], dynamic=[].
2022/11/18 18:34:46 [output_srt:5] Enabling caching mode: active source.
2022/11/18 18:34:46 [threads:4] Created thread "clock_main" (1 total).
2022/11/18 18:34:46 [clock:4] Main phase starts.
2022/11/18 18:34:46 [threads:4] Created thread "generic queue #1" (1 total).
2022/11/18 18:34:46 [threads:4] Created thread "generic queue #2" (2 total).
2022/11/18 18:34:46 [threads:4] Created thread "non-blocking queue #1" (3 total).
2022/11/18 18:34:46 [threads:4] Created thread "non-blocking queue #2" (4 total).
2022/11/18 18:34:46 [output_srt:3] Connecting to srt://xx.xxx.xx.xxx:xxxx..
2022/11/18 18:34:46 [video.text:3] Using native implementation
2022/11/18 18:34:46 [GL:5] Next song will be "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3".
2022/11/18 18:34:46 [clock.main:3] Streaming loop starts in auto-sync mode
2022/11/18 18:34:46 [clock.main:3] Delegating synchronisation to CPU clock
2022/11/18 18:34:46 [request:5] Resolving request [[/home/dj/music/Jingles/GL/35.3_Audio 1.mp3]].
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.srt:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.wav:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder:4] Available decoders: ffmpeg (priority: 2), mad (priority: 1), image (priority: 1)
2022/11/18 18:34:46 [decoder:4] Trying decoder "ffmpeg"
2022/11/18 18:34:46 [decoder.ffmpeg:4] ffmpeg recognizes "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo)}.
2022/11/18 18:34:46 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2022/11/18 18:34:46 [request:2] Cannot find decoder flac
2022/11/18 18:34:46 [request:2] Cannot find decoder mp4
2022/11/18 18:34:46 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [GL:5] Queue is empty!
2022/11/18 18:34:46 [GL:5] Failed to prepare track: no file.
2022/11/18 18:34:46 [single_0:3] Prepared "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" (RID 0).
2022/11/18 18:34:46 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [switch_1:3] Switch to on_track_0.
2022/11/18 18:34:46 [on_track_0:5] Activations changed: static=[switch_1:amplify_0:output_srt:output_srt], dynamic=[switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:46 [switch_0:3] Switch to append_0.
2022/11/18 18:34:46 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[switch_1:amplify_0:output_srt:output_srt, switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
[mp3float @ 0x7f3f54022380] Could not update timestamps for skipped samples.
2022/11/18 18:34:46 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3"!
2022/11/18 18:34:46 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/Jingles/GL/35.3_Audio 1.mp3": audio/mpeg!
2022/11/18 18:34:46 [single_0:5] Got metadata at position 0: calling handlers...
2022/11/18 18:34:46 [metadata.cover:5] APIC or PIC not found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3, trying builtin tag reader.
2022/11/18 18:34:46 [lang:4] No cover found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3.
2022/11/18 18:34:46 [clock.main:4] Source output_srt failed while streaming: Invalid_argument("String.blit / Bytes.blit_string")!
2022/11/18 18:34:46 [clock.main:4] Raised at Stdlib.invalid_arg in file "stdlib.ml", line 30, characters 20-45
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Lang_string.escape_string.(fun) in file "src/lang/lang_string.ml", line 136, characters 17-54
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.fold_left in file "list.ml", line 121, characters 24-34
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Lang_string.escape_string in file "src/lang/lang_string.ml", line 131, characters 6-427
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Json.quote_utf8_string.(fun) in file "src/lang/json.ml", line 46, characters 28-79
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Json.to_string_pp in file "src/lang/json.ml", line 98, characters 30-58
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.kfprintf.(fun) in file "format.ml", line 1356, characters 16-34
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.pp_print_list in file "format.ml", line 1193, characters 4-14
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1307, characters 32-48
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.kfprintf.(fun) in file "format.ml", line 1356, characters 16-34
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__Format.kasprintf.k in file "format.ml", line 1391, characters 4-22
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Builtins_json.(fun) in file "src/lang/builtins_json.ml", line 328, characters 14-62
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/18 18:34:46 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/18 18:34:46 [clock.main:4] Called from Tutils.finalize in file "src/core/tools/tutils.ml", line 105, characters 12-16
2022/11/18 18:34:46 [clock.main:4] Re-raised at Tutils.finalize in file "src/core/tools/tutils.ml", line 111, characters 4-38
2022/11/18 18:34:46 [clock.main:4] Called from Lang_source.source_methods.(fun) in file "src/core/lang_source.ml", line 142, characters 40-68
2022/11/18 18:34:46 [clock.main:4] Called from Stdlib__List.iter in file "list.ml", line 110, characters 12-15
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame.(fun) in file "src/core/source.ml", line 620, characters 12-47
2022/11/18 18:34:46 [clock.main:4] Called from Tutils.mutexify in file "src/core/tools/tutils.ml", line 95, characters 14-17
2022/11/18 18:34:46 [clock.main:4] Re-raised at Tutils.mutexify in file "src/core/tools/tutils.ml", line 101, characters 4-38
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 611, characters 6-373
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from Append.append#get_frame in file "src/core/operators/append.ml", line 45, characters 12-26
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from On_track.on_track#get_frame in file "src/core/operators/on_track.ml", line 36, characters 6-14
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from Switch.switch#get_frame in file "src/core/operators/switch.ml", line 253, characters 14-39
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from Amplify.amplify#get_frame in file "src/core/operators/amplify.ml", line 39, characters 6-20
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/18 18:34:46 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/18 18:34:46 [clock.main:4] Called from Output.output#output in file "src/core/outputs/output.ml", line 169, characters 10-30
2022/11/18 18:34:46 [clock.main:4] Called from Clock.clock#end_tick.(fun) in file "src/core/clock.ml", line 299, characters 14-22
2022/11/18 18:34:46 [clock.main:4] 
2022/11/18 18:34:46 [request:5] Resolved to [[/home/dj/music/Jingles/GL/35.3_Audio 1.mp3]].
2022/11/18 18:34:46 [request:5] Resolving request [[/home/dj/music/Jingles/GL/35.3_Audio 1.mp3]].
2022/11/18 18:34:46 [request:5] Resolved to [[/home/dj/music/Jingles/GL/35.3_Audio 1.mp3]].
2022/11/18 18:34:46 [GL:4] Queued 1 requests
2022/11/18 18:34:49 [output_srt:3] Connect failed: Error(Enoserver,Connection setup failure: connection timed out)
2022/11/18 18:34:49 [output_srt:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source output_srt gets down.
2022/11/18 18:34:49 [amplify_0:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source amplify_0 gets down.
2022/11/18 18:34:49 [switch_1:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source switch_1 gets down.
2022/11/18 18:34:49 [on_track_0:5] Activations changed: static=[switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/18 18:34:49 [GL:5] Activations changed: static=[], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:49 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt].
2022/11/18 18:34:49 [on_track_0:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source on_track_0 gets down.
2022/11/18 18:34:49 [switch_0:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source switch_0 gets down.
2022/11/18 18:34:49 [GL:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source GL gets down.
2022/11/18 18:34:49 [GL:4] Waiting for feeding task to stop...
2022/11/18 18:34:49 [GL:4] Cleaning up request queue...
2022/11/18 18:34:49 [append_0:5] Activations changed: static=[switch_0:on_track_0:switch_1:amplify_0:output_srt:output_srt], dynamic=[].
2022/11/18 18:34:49 [append_0:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source append_0 gets down.
2022/11/18 18:34:49 [single_0:5] Activations changed: static=[], dynamic=[].
2022/11/18 18:34:49 [source:4] Source single_0 gets down.
2022/11/18 18:34:49 [single_0:4] Finished with "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerp\195\162.mp3".
2022/11/18 18:34:49 [main:3] Shutdown started!
2022/11/18 18:34:49 [lifecycle:5] At stage: "Liquidsoap core shutdown"
2022/11/18 18:34:49 [main:3] Waiting for main threads to terminate...
2022/11/18 18:34:49 [threads:4] Waiting for thread clock_main to shutdown
2022/11/18 18:34:49 [clock.main:3] Streaming loop stopped.
2022/11/18 18:34:49 [threads:4] Thread "clock_main" terminated (0 remaining).
2022/11/18 18:34:49 [main:3] Main threads terminated.
2022/11/18 18:34:49 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown"
2022/11/18 18:34:49 [threads:3] Shutting down scheduler...
2022/11/18 18:34:49 [threads:4] Thread "generic queue #1" terminated (3 remaining).
2022/11/18 18:34:49 [threads:4] Thread "generic queue #2" terminated (2 remaining).
2022/11/18 18:34:49 [threads:4] Thread "non-blocking queue #1" terminated (1 remaining).
2022/11/18 18:34:49 [threads:4] Thread "non-blocking queue #2" terminated (0 remaining).
2022/11/18 18:34:49 [threads:3] Scheduler shut down.
2022/11/18 18:34:49 [lifecycle:5] At stage: "Liquidsoap final cleanup"
2022/11/18 18:34:49 [main:3] Cleaning downloaded files...
2022/11/18 18:34:49 [main:3] Freeing memory...

toots commented 1 year ago

Well this is the gift that keeps on giving! @joe-ms I think I have a fix. I'd like to run it against the file but it has been deleted now. could you send a link again or email it to me at toots@rastageeks.org ?

joe-ms commented 1 year ago

Thanks @toots , here you go https://upload.disroot.org/r/Jq7HFLSt#jOVIg3CfWKouYKFWi+OStS0BCvH2s6l51f5wPAL+slM=

toots commented 1 year ago

Thanks. I can't reproduce on a simple script. What script are you using?

smimram commented 1 year ago

Note that I have pushed a few fixes on metadata which should have fixed the problem of null ends!

joe-ms commented 1 year ago

Ahh, ok. I have not upgraded since last crashlog four days ago. I will upgrade and test again right away. Anyway here is a script that crashes with my current setup unless I uncomment the settings.request.metadata_decoders.set thus prioritising taglib.

#!/usr/local/bin/liquidsoap

#settings.request.metadata_decoders.set(["taglib", "video-metadata", "ogg-native", "image", "ID3", "ID3v1", "ID3v2", "mp4", "ffmpeg", "flac", "ogg"])

def log_song(m)
  file.write(append=true, data="#{metadata.json.stringify(m)}\n", "/tmp/songs")
end

s = single("~/music/01 Sekernup Kingerpâ.mp3")

radio = s
radio.on_track(log_song)

radio = amplify(1.,override="replaygain_track_gain", radio)

output.srt(host="xx.xxx.xx.xxx", port=xxxx, mode="caller", passphrase="xxxx", polling_delay=10., fallible=true,
  %opus(bitrate=192),
  radio)

joe-ms commented 1 year ago

Just upgraded liquidsoap and metadata. ffmpeg and mm also latest pinned. The problem persists, and it seems the problem is log_song. _I have just edited a copy-typo in above script and removed lognext for simplification.

Above script crashes unless I uncomment settings.request.metadata_decoders.set or comment out radio.on_track(log_song)

2022/11/22 23:28:53 [main:3] Liquidsoap 502595c+git@502595c7
2022/11/22 23:28:53 [main:3] Using: angstrom=0.15.0 bigarray=[distributed with OCaml] bigarray-compat=1.1.0 bigstringaf=0.9.0 bytes=[distributed with OCaml] cry=0.6.7 ctypes=0.20.1 ctypes.foreign=0.20.1 ctypes.stubs=0.20.1 curl=0.9.2 dtools=0.4.4 dune-build-info=3.6.0 dune-private-libs.dune-section=3.6.0 dune-site=3.6.0 dune-site.private=3.6.0 duppy=0.9.2 ffmpeg-av=da05c0d ffmpeg-avcodec=da05c0d ffmpeg-avdevice=da05c0d ffmpeg-avfilter=da05c0d ffmpeg-avutil=da05c0d ffmpeg-swresample=da05c0d ffmpeg-swscale=da05c0d gen=1.0 integers lame=0.3.6 liquidsoap-lang=502595c liquidsoap_builtins=502595c-dirty liquidsoap_core=502595c-dirty liquidsoap_ffmpeg=502595c-dirty liquidsoap_lame=502595c-dirty liquidsoap_mad=502595c-dirty liquidsoap_magic=502595c-dirty liquidsoap_ogg=502595c-dirty liquidsoap_optionals=502595c-dirty liquidsoap_opus=502595c-dirty liquidsoap_oss=502595c-dirty liquidsoap_runtime=502595c-dirty liquidsoap_samplerate=502595c-dirty liquidsoap_srt=502595c-dirty liquidsoap_ssl=502595c-dirty liquidsoap_taglib=502595c-dirty mad=0.5.2 magic=0.7.3 menhirLib=20220210 metadata=5a8239a mm=a241c73 mm.audio=a241c73 mm.base=a241c73 mm.image=a241c73 mm.midi=a241c73 mm.video=a241c73 ogg=0.7.3 ogg.decoder=0.7.3 opus=0.2.2 opus.decoder=0.2.2 pcre=7.5.0 posix-base=2.0.1 posix-socket=2.0.1 posix-socket.constants=2.0.1 posix-socket.stubs=2.0.1 posix-socket.types=2.0.1 samplerate=0.1.6 sedlex=3.0 seq=[distributed with OCaml 4.07 or above] srt=0.2.2 srt.constants=0.2.2 srt.stubs=0.2.2 srt.stubs.locked=0.2.2 srt.types=0.2.2 ssl=0.5.13 stdlib-shims=0.3.0 str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] unix=[distributed with OCaml] uri=4.2.0
2022/11/22 23:28:53 [clock:3] Using builtin (low-precision) implementation for latency control
2022/11/22 23:28:57 [main:3] Standard library loaded in 3.87 seconds.
2022/11/22 23:28:57 [main:3] Loaded /home/dj/liquidsoap-daemon/script/script.liq in 0.01 seconds.
2022/11/22 23:28:57 [frame:4] frame.audio.channels set to: 2
2022/11/22 23:28:57 [frame:4] frame.video.default set to: false
2022/11/22 23:28:57 [frame:4] frame.midi.channels set to: 0
2022/11/22 23:28:57 [frame:4] frame.video.width set to: 1280
2022/11/22 23:28:57 [frame:4] frame.video.height set to: 720
2022/11/22 23:28:57 [frame:4] frame.audio.samplerate set to: 44100
2022/11/22 23:28:57 [frame:4] frame.video.framerate set to: 25
2022/11/22 23:28:57 [frame:4] frame.audio.samplerate set to: 44100
2022/11/22 23:28:57 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2022/11/22 23:28:57 [frame:3] Video frame size set to: 1280x720
2022/11/22 23:28:57 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2022/11/22 23:28:57 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2022/11/22 23:28:57 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2022/11/22 23:28:57 [sandbox:3] Sandboxing disabled
2022/11/22 23:28:57 [video.converter:3] Using preferred video converter: ffmpeg.
2022/11/22 23:28:57 [audio.converter:3] Using samplerate converter: libsamplerate.
2022/11/22 23:28:57 [lifecycle:5] At stage: "Liquidsoap application start"
2022/11/22 23:28:57 [clock:4] Currently 1 clock(s) allocated.
2022/11/22 23:28:57 [clock.main:4] Starting 1 source(s)...
2022/11/22 23:28:57 [srt_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/22 23:28:57 [srt_0:5] Content type: {audio=pcm(stereo)}
2022/11/22 23:28:57 [source:4] Source srt_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/22 23:28:57 [output_srt:5] Clock is main[].
2022/11/22 23:28:57 [output_srt:4] Content type is {audio=pcm(stereo)}.
2022/11/22 23:28:57 [amplify_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/22 23:28:57 [amplify_0:5] Content type: {audio=pcm(stereo)}
2022/11/22 23:28:57 [source:4] Source amplify_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/22 23:28:57 [amplify_0:5] Clock is main[].
2022/11/22 23:28:57 [amplify_0:4] Content type is {audio=pcm(stereo)}.
2022/11/22 23:28:57 [single_0:5] Assigning source content type for frame type: {audio : pcm(stereo)}
2022/11/22 23:28:57 [single_0:5] Content type: {audio=pcm(stereo)}
2022/11/22 23:28:57 [source:4] Source single_0 gets up with content type: {audio=pcm(stereo)}.
2022/11/22 23:28:57 [single_0:3] "~/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" is static, resolving once for all...
2022/11/22 23:28:57 [request:5] Resolving request [[/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3]].
2022/11/22 23:28:57 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2022/11/22 23:28:57 [decoder:4] Trying decoder "ffmpeg"
2022/11/22 23:28:57 [decoder.ffmpeg:4] ffmpeg recognizes "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo)}.
2022/11/22 23:28:57 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2022/11/22 23:28:57 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [charset:3] Conversion from UTF-16LE is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [charset:3] Conversion from ISO-8859-1 is not supported.
2022/11/22 23:28:57 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3"!
2022/11/22 23:28:57 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3": audio/mpeg!
2022/11/22 23:28:57 [request:5] Resolved to [[/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3]].
2022/11/22 23:28:57 [single_0:5] Activations changed: static=[amplify_0:output_srt:output_srt], dynamic=[].
2022/11/22 23:28:57 [amplify_0:5] Activations changed: static=[output_srt:output_srt], dynamic=[].
2022/11/22 23:28:57 [output_srt:5] Activations changed: static=[output_srt], dynamic=[].
2022/11/22 23:28:57 [output_srt:5] Enabling caching mode: active source.
2022/11/22 23:28:57 [threads:4] Created thread "clock_main" (1 total).
2022/11/22 23:28:57 [clock:4] Main phase starts.
2022/11/22 23:28:57 [threads:4] Created thread "generic queue #1" (1 total).
2022/11/22 23:28:57 [threads:4] Created thread "generic queue #2" (2 total).
2022/11/22 23:28:57 [threads:4] Created thread "non-blocking queue #1" (3 total).
2022/11/22 23:28:57 [threads:4] Created thread "non-blocking queue #2" (4 total).
2022/11/22 23:28:57 [output_srt:3] Connecting to srt://xx.xxx.xx.xxx:xxxx..
2022/11/22 23:28:57 [video.text:3] Using native implementation
2022/11/22 23:28:57 [clock.main:3] Streaming loop starts in auto-sync mode
2022/11/22 23:28:57 [clock.main:3] Delegating synchronisation to CPU clock
2022/11/22 23:28:57 [single_0:3] Prepared "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3" (RID 0).
[mp3float @ 0x7f66e0022380] Could not update timestamps for skipped samples.
2022/11/22 23:28:57 [single_0:5] Got metadata at position 0: calling handlers...
2022/11/22 23:28:57 [metadata.cover:5] APIC or PIC not found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3, trying builtin tag reader.
2022/11/22 23:28:57 [lang:4] No cover found for /home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerpâ.mp3.
2022/11/22 23:28:57 [clock.main:4] Source output_srt failed while streaming: Invalid_argument("String.blit / Bytes.blit_string")!
2022/11/22 23:28:57 [clock.main:4] Raised at Stdlib.invalid_arg in file "stdlib.ml", line 30, characters 20-45
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Lang_string.escape_string.(fun) in file "src/lang/lang_string.ml", line 136, characters 17-54
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.fold_left in file "list.ml", line 121, characters 24-34
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Lang_string.escape_string in file "src/lang/lang_string.ml", line 131, characters 6-427
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Json.quote_utf8_string.(fun) in file "src/lang/json.ml", line 46, characters 28-79
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Json.to_string_pp in file "src/lang/json.ml", line 98, characters 30-58
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.kfprintf.(fun) in file "format.ml", line 1356, characters 16-34
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.pp_print_list in file "format.ml", line 1193, characters 4-14
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1307, characters 32-48
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.kfprintf.(fun) in file "format.ml", line 1356, characters 16-34
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.output_acc in file "format.ml", line 1295, characters 4-20
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__Format.kasprintf.k in file "format.ml", line 1391, characters 4-22
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Builtins_json.(fun) in file "src/lang/builtins_json.ml", line 328, characters 14-62
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans.(fun) in file "src/lang/evaluation.ml", line 266, characters 46-56
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 20-23
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.map in file "list.ml", line 92, characters 32-39
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.eval.ans in file "src/lang/evaluation.ml", line 266, characters 18-60
2022/11/22 23:28:57 [clock.main:4] Called from Liquidsoap_lang__Evaluation.apply.f in file "src/lang/evaluation.ml", line 289, characters 8-12
2022/11/22 23:28:57 [clock.main:4] Called from Tutils.finalize in file "src/core/tools/tutils.ml", line 105, characters 12-16
2022/11/22 23:28:57 [clock.main:4] Re-raised at Tutils.finalize in file "src/core/tools/tutils.ml", line 111, characters 4-38
2022/11/22 23:28:57 [clock.main:4] Called from Lang_source.source_methods.(fun) in file "src/core/lang_source.ml", line 142, characters 40-68
2022/11/22 23:28:57 [clock.main:4] Called from Stdlib__List.iter in file "list.ml", line 110, characters 12-15
2022/11/22 23:28:57 [clock.main:4] Called from Source.operator#instrumented_get_frame.(fun) in file "src/core/source.ml", line 620, characters 12-47
2022/11/22 23:28:57 [clock.main:4] Called from Tutils.mutexify in file "src/core/tools/tutils.ml", line 95, characters 14-17
2022/11/22 23:28:57 [clock.main:4] Re-raised at Tutils.mutexify in file "src/core/tools/tutils.ml", line 101, characters 4-38
2022/11/22 23:28:57 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 611, characters 6-373
2022/11/22 23:28:57 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/22 23:28:57 [clock.main:4] Called from Amplify.amplify#get_frame in file "src/core/operators/amplify.ml", line 39, characters 6-20
2022/11/22 23:28:57 [clock.main:4] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 590, characters 6-24
2022/11/22 23:28:57 [clock.main:4] Called from Source.operator#get in file "src/core/source.ml", line 661, characters 10-41
2022/11/22 23:28:57 [clock.main:4] Called from Output.output#output in file "src/core/outputs/output.ml", line 169, characters 10-30
2022/11/22 23:28:57 [clock.main:4] Called from Clock.clock#end_tick.(fun) in file "src/core/clock.ml", line 299, characters 14-22
2022/11/22 23:28:57 [clock.main:4] 
2022/11/22 23:29:00 [output_srt:3] Connect failed: Error(Enoserver,Connection setup failure: connection timed out)
2022/11/22 23:29:00 [output_srt:5] Activations changed: static=[], dynamic=[].
2022/11/22 23:29:00 [source:4] Source output_srt gets down.
2022/11/22 23:29:00 [amplify_0:5] Activations changed: static=[], dynamic=[].
2022/11/22 23:29:00 [source:4] Source amplify_0 gets down.
2022/11/22 23:29:00 [single_0:5] Activations changed: static=[], dynamic=[].
2022/11/22 23:29:00 [source:4] Source single_0 gets down.
2022/11/22 23:29:00 [single_0:4] Finished with "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/01 Sekernup Kingerp\195\162.mp3".
2022/11/22 23:29:00 [clock.main:3] Streaming loop stopped.
2022/11/22 23:29:00 [threads:4] Thread "clock_main" terminated (0 remaining).
2022/11/22 23:29:00 [main:3] Shutdown started!
2022/11/22 23:29:00 [lifecycle:5] At stage: "Liquidsoap core shutdown"
2022/11/22 23:29:00 [main:3] Waiting for main threads to terminate...
2022/11/22 23:29:00 [main:3] Main threads terminated.
2022/11/22 23:29:00 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown"
2022/11/22 23:29:00 [threads:3] Shutting down scheduler...
2022/11/22 23:29:00 [threads:4] Thread "non-blocking queue #1" terminated (3 remaining).
2022/11/22 23:29:00 [threads:4] Thread "generic queue #1" terminated (2 remaining).
2022/11/22 23:29:00 [threads:4] Thread "non-blocking queue #2" terminated (1 remaining).
2022/11/22 23:29:00 [threads:4] Thread "generic queue #2" terminated (0 remaining).
2022/11/22 23:29:00 [threads:3] Scheduler shut down.
2022/11/22 23:29:00 [lifecycle:5] At stage: "Liquidsoap final cleanup"
2022/11/22 23:29:00 [main:3] Cleaning downloaded files...
2022/11/22 23:29:00 [main:3] Freeing memory...

joe-ms commented 1 year ago

Just tested commenting out both log_song and settings.request.metadata_decoders.set and harboring the metadata in the srt receiving end. The harbor fails reading the title after first letter and my tts-speaker (running in the sending end) speaks all kinds of weird letters.

meta = ref([])
radio.on_metadata(fun (m) -> meta := m)
def get_meta(_, response) =
  response.json(!meta)
end

harbor.http.register(port=7000, method="GET", "/md", get_meta)

Raw data harbored hereunder Actually I have two metadata related questions here for another day:

How do I avoid the metadata adding up as below? Something with deduplicate?
Is the metadata not supposed to be harbored as an JSON Object and not an Array?

[
  [
  "country",
  "GL;GL"
],
  [
  "album",
  "Vaigatip Kitigiai Vaigatmusik;Vaigatip Kitigiai Vaigatmusik"
],
  [
  "track",
  "1"
],
  [
  "year",
  "1973;1973"
],
  [
  "artist",
  "Jens Hendriksenip Nipillersortartue;Jens Hendriksenip Nipillersortartue"
],
  [
  "title",
  "S;S"
],
  [
  "label",
  "Demos;Demos"
]
]

toots commented 1 year ago

I was able to reproduce and fix in fc70fcd43442f3567741d0f591a202ff93f7d4ce. It was the same as the previous issue but inside the json string escaping code.

The underlying issue stems from the fact that liquidsoap is expecting utf8 strings internally. We recently made the camomile library optional. This is the library in charge of converting any incoming string into utf8 format. Since you don't have it installed, we ended up with non-utf8 strings extracted from the metadata and passed down to the json escaping function which was still expecting utf8 strings.

I have made the json string escaping more robust which will fix the crash but still result in an non-utf8 string being exported in the json payload, which will inevitably create issues down the road.

I would suggest that you install camomile and that we make it a required dependency again.

cc/ @smimram

savonet / liquidsoap

Metadata decoder appends \u0000 - LS-main 2.2.0 #2738