savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.41k stars 130 forks source link

Error reporting about cert or key problems #3078

Closed vitoyucepi closed 1 year ago

vitoyucepi commented 1 year ago

Describe the bug Liquidsoap will terminate with numerous errors if the SSL certificate or key is inaccessible or damaged.

Permission denied 1 ``` 2023/05/15 21:36:17 [clock.main:2] Error when starting input.harbor_0: SSL: Privte key error: error:0200100D:system library:fopen:Permission denied! 2023/05/15 21:36:17 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/15 21:36:17 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/15 21:36:17 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/15 21:36:17 [clock.main:4] ```
Not found 1 ``` 2023/05/15 21:36:17 [clock:2] Error when leaving output input.harbor_0: Not_found! 2023/05/15 21:36:17 [clock:4] Raised at Stdlib__Hashtbl.find in file "hashtbl.ml", line 539, characters 13-28 2023/05/15 21:36:17 [clock:4] Called from Harbor.Make.remove_source in file "src/core/harbor/harbor.ml", line 1152, characters 30-60 2023/05/15 21:36:17 [clock:4] Called from Source.operator#leave in file "src/core/source.ml", line 557, characters 8-18 2023/05/15 21:36:17 [clock:4] Called from Clock.leave in file "src/core/clock.ml", line 104, characters 6-44 2023/05/15 21:36:17 [clock:4] ```
Permission denied 2 ``` 2023/05/15 21:36:17 [clock.main:2] Error when starting dummy: SSL: Privte key error: error:0200100D:system library:fopen:Permission denied! 2023/05/15 21:36:17 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/15 21:36:17 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/15 21:36:17 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/15 21:36:17 [clock.main:4] Called from Output.output#wake_up in file "src/core/outputs/output.ml", line 122, characters 6-57 2023/05/15 21:36:17 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/15 21:36:17 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/15 21:36:17 [clock.main:4] ```
Not found 2 ``` 2023/05/15 21:36:17 [clock:2] Error when leaving output dummy: Not_found! 2023/05/15 21:36:17 [clock:4] Raised at Stdlib__Hashtbl.find in file "hashtbl.ml", line 539, characters 13-28 2023/05/15 21:36:17 [clock:4] Called from Harbor.Make.remove_source in file "src/core/harbor/harbor.ml", line 1152, characters 30-60 2023/05/15 21:36:17 [clock:4] Called from Source.operator#leave in file "src/core/source.ml", line 557, characters 8-18 2023/05/15 21:36:17 [clock:4] Called from Source.operator#leave in file "src/core/source.ml", line 557, characters 8-18 2023/05/15 21:36:17 [clock:4] Called from Clock.leave in file "src/core/clock.ml", line 104, characters 6-44 2023/05/15 21:36:17 [clock:4] ```

To Reproduce

  1. Generate a certificate. openssl req -x509 -newkey rsa:2048 -keyout key.pem -out cert.pem -sha256 -days 365 -subj '/CN=localhost' -nodes
  2. Change permissions chmod 0000 key.pem
  3. Config

    ssl_transport = http.transport.ssl(
     certificate="cert.pem",
     key="key.pem",
    )
    
    live = input.harbor(
     "live",
     transport=ssl_transport,
     port=8005,
     password="test",
    )
    output.dummy(live, fallible=true)

Expected behavior I think these errors are not very informative. If there is an error regarding file permissions, the exact file location should be shown. The only error message that should appear is Permission denied related.

Version details

Install method Deb package from liquidsoap releases at github

Common issues

3067

toots commented 1 year ago

Thanks for reporting. This is fixed now. The error when file could not be found was already improved but buried under the other one. I added an error when file cannot be read and also fixed the subsequent error.

Typically error now looks like:

Screenshot 2023-05-15 at 5 14 51 PM
vitoyucepi commented 1 year ago

Some exceptions may not be caught.

2023/05/15 23:01:16 [clock.main:2] Error when starting input.harbor_0: SSL: Privte key error: error:0908F066:PEM routines:get_header_and_data:bad end line!
2023/05/15 23:01:16 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94
2023/05/15 23:01:16 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31
2023/05/15 23:01:16 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45
2023/05/15 23:01:16 [clock.main:4] 

Furthermore, could you explain why two errors are triggered when the harbor is defined and sent to the output instead of just one?

toots commented 1 year ago

Some exceptions may not be caught.

2023/05/15 23:01:16 [clock.main:2] Error when starting input.harbor_0: SSL: Privte key error: error:0908F066:PEM routines:get_header_and_data:bad end line!
2023/05/15 23:01:16 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94
2023/05/15 23:01:16 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31
2023/05/15 23:01:16 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45
2023/05/15 23:01:16 [clock.main:4] 

This looks fine. this is a legit error with a descriptive explanation. It's happening inside the streaming loop so there isn't really a reason to re-raise it as a runtime error since it cannot be caught and should be treated as a fatal error.

Furthermore, could you explain why two errors are triggered when the harbor is defined and sent to the output instead of just one?

Do you have context or logs?

vitoyucepi commented 1 year ago

Furthermore, could you explain why two errors are triggered when the harbor is defined and sent to the output instead of just one?

Do you have context or logs?

  1. Config

    ssl_transport = http.transport.ssl(
     certificate="cert.pem",
     key="key.pem",
    )
    
    live = input.harbor(
     "live",
     transport=ssl_transport,
     port=8005,
     password="test",
    )
    output.dummy(live, fallible=true)
  2. Generate a certificate. openssl req -x509 -newkey rsa:2048 -keyout key.pem -out cert.pem -sha256 -days 365 -subj '/CN=localhost' -nodes
  3. Change permissions chmod 0000 key.pem
Log ``` INFO: Loading Sdl_image, Target = linux INFO: Loading Sdl_ttf, Target = linux 2023/05/16 12:51:20 >>> LOG START 2023/05/16 12:51:12 [main:3] Liquidsoap 2.2.0+git@efa40bde1 2023/05/16 12:51:12 [main:3] Using: alsa=0.3.0 angstrom=0.15.0 ao=0.2.4 asetmap=0.8.1 asn1-combinators=0.2.6 astring=0.8.5 base.caml=v0.15.1 base64=3.5.1 bigarray=[distributed with OCaml] bigarray-compat=1.1.0 bigstringaf=0.9.1 bjack=0.1.6 bos=0.2.1 bytes=[distributed with OCaml] ca-certs=v0.2.3 camlimages.all_formats=4.2.6 camlimages.core=5.0.4 camlimages.exif=5.0.4 camlimages.gif=5.0.4 camlimages.jpeg=5.0.4 camlimages.png=5.0.4 camlimages.tiff=5.0.4 camlimages.xpm=5.0.4 camlp-streams camomile=d3773ec camomile.lib=d3773ec cohttp=5.1.0 cohttp-lwt=5.1.0 cohttp-lwt-unix=5.1.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=1.0.0 cstruct=6.2.0 ctypes=0.20.2 ctypes.foreign=0.20.2 ctypes.stubs=0.20.2 curl=0.9.2 domain-name=0.4.0 dssi=0.1.5 dtools=0.4.5 dune-build-info=3.7.1 dune-private-libs.dune-section=3.7.1 dune-site=3.7.1 dune-site.private=3.7.1 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 faad=0.5.2 fdkaac=0.3.3 ffmpeg-av=1.1.8 ffmpeg-avcodec=1.1.8 ffmpeg-avdevice=1.1.8 ffmpeg-avfilter=1.1.8 ffmpeg-avutil=1.1.8 ffmpeg-swresample=1.1.8 ffmpeg-swscale=1.1.8 fileutils=0.6.4 flac=0.4.0 flac.decoder=0.4.0 flac.ogg=0.4.0 fmt=0.9.0 fpath=0.7.3 frei0r=0.1.2 gd=1.0a5 gen=1.1 gmap=0.3.0 hkdf=1.0.4 inotify=2.4.1 integers ipaddr=5.5.0 ipaddr-sexp=5.5.0 ipaddr.unix=5.5.0 irc-client irc-client-unix ladspa=0.2.2 lame=0.3.7 lastfm=0.3.3 lilv=0.1.0 liquidsoap-lang=2.2.0 liquidsoap-lang.console=2.2.0 liquidsoap_alsa=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ao=rolling-release-v2.2.x-56-gefa40bd liquidsoap_bjack=rolling-release-v2.2.x-56-gefa40bd liquidsoap_builtins=rolling-release-v2.2.x-56-gefa40bd liquidsoap_camlimages=rolling-release-v2.2.x-56-gefa40bd liquidsoap_core=rolling-release-v2.2.x-56-gefa40bd liquidsoap_dssi=rolling-release-v2.2.x-56-gefa40bd liquidsoap_faad=rolling-release-v2.2.x-56-gefa40bd liquidsoap_fdkaac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ffmpeg=rolling-release-v2.2.x-56-gefa40bd liquidsoap_flac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_frei0r=rolling-release-v2.2.x-56-gefa40bd liquidsoap_gd=rolling-release-v2.2.x-56-gefa40bd liquidsoap_irc=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ladspa=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lame=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lastfm=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lilv=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lo=rolling-release-v2.2.x-56-gefa40bd liquidsoap_mad=rolling-release-v2.2.x-56-gefa40bd liquidsoap_magic=rolling-release-v2.2.x-56-gefa40bd liquidsoap_mem_usage=rolling-release-v2.2.x-56-gefa40bd liquidsoap_memtrace=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ogg=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ogg_flac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_optionals=rolling-release-v2.2.x-56-gefa40bd liquidsoap_opus=rolling-release-v2.2.x-56-gefa40bd liquidsoap_osc=rolling-release-v2.2.x-56-gefa40bd liquidsoap_oss=rolling-release-v2.2.x-56-gefa40bd liquidsoap_portaudio=rolling-release-v2.2.x-56-gefa40bd liquidsoap_posix_time=rolling-release-v2.2.x-56-gefa40bd liquidsoap_prometheus=rolling-release-v2.2.x-56-gefa40bd liquidsoap_pulseaudio=rolling-release-v2.2.x-56-gefa40bd liquidsoap_runtime=rolling-release-v2.2.x-56-gefa40bd liquidsoap_samplerate=rolling-release-v2.2.x-56-gefa40bd liquidsoap_sdl=rolling-release-v2.2.x-56-gefa40bd liquidsoap_shine=rolling-release-v2.2.x-56-gefa40bd liquidsoap_soundtouch=rolling-release-v2.2.x-56-gefa40bd liquidsoap_speex=rolling-release-v2.2.x-56-gefa40bd liquidsoap_srt=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ssl=rolling-release-v2.2.x-56-gefa40bd liquidsoap_stereotool=rolling-release-v2.2.x-56-gefa40bd liquidsoap_taglib=rolling-release-v2.2.x-56-gefa40bd liquidsoap_theora=rolling-release-v2.2.x-56-gefa40bd liquidsoap_tls=rolling-release-v2.2.x-56-gefa40bd liquidsoap_vorbis=rolling-release-v2.2.x-56-gefa40bd liquidsoap_xmlplaylist=rolling-release-v2.2.x-56-gefa40bd liquidsoap_yaml=rolling-release-v2.2.x-56-gefa40bd lo=0.2.0 logs=0.7.0 logs.fmt=0.7.0 logs.lwt=0.7.0 lwt=5.6.1 lwt.unix=5.6.1 macaddr=5.5.0 mad=0.5.3 magic=0.7.3 magic-mime=1.3.0 mem_usage=0.0.4 memtrace=0.2.3 menhirLib=20220210 metadata=0.2.0 mirage-crypto=0.11.1 mirage-crypto-ec=0.11.1 mirage-crypto-pk=0.11.1 mirage-crypto-rng=0.11.1 mirage-crypto-rng.unix=0.11.1 mm=0.8.3 mm.audio=0.8.3 mm.base=0.8.3 mm.image=0.8.3 mm.midi=0.8.3 mm.video=0.8.3 ocplib-endian ocplib-endian.bigstring ogg=0.7.4 ogg.decoder=0.7.4 opus=0.2.3 opus.decoder=0.2.3 osc osc-unix parsexp=v0.15.0 pbkdf pcre=7.5.0 portaudio=0.2.3 posix-base=65ec333 posix-socket=65ec333 posix-socket.constants=65ec333 posix-socket.stubs=65ec333 posix-socket.types=65ec333 posix-time2=65ec333 posix-time2.constants=65ec333 posix-time2.stubs=65ec333 posix-time2.types=65ec333 posix-types=65ec333 posix-types.constants=65ec333 ppx_sexp_conv.runtime-lib=v0.15.0 prometheus=1.2 prometheus-app=1.2 ptime=1.1.0 ptime.clock.os=1.1.0 pulseaudio=0.1.6 re=1.10.4 result=1.5 rresult=0.7.0 samplerate=0.1.6 sedlex=3.1 seq=[distributed with OCaml 4.07 or above] sexplib=v0.15.1 sexplib0=v0.15.0 shine=0.2.3 soundtouch=0.1.9 speex=0.4.2 speex.decoder=0.4.2 srt=0.3.0 srt.constants=0.3.0 srt.stubs=0.3.0 srt.stubs.locked=0.3.0 srt.types=0.3.0 ssl=0.5.13 stdlib-shims=0.3.0 stereotool=rolling-release-v2.2.x-56-gefa40bd str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 theora=0.4.1 theora.decoder=0.4.1 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] tls=0.17.0 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.5 unix=[distributed with OCaml] unix-errno=0.6.2 unix-errno.errno_bindings=0.6.2 unix-errno.errno_types=0.6.2 unix-errno.errno_types_detected=0.6.2 unix-errno.unix=0.6.2 uri=4.2.0 uri-sexp=4.2.0 uri.services=4.2.0 vorbis=0.8.1 vorbis.decoder=0.8.1 x509=0.16.4 xmlm=1.4.0 xmlplaylist=0.1.5 yaml=3.1.0 yaml.bindings=3.1.0 yaml.bindings.types=3.1.0 yaml.c=3.1.0 yaml.ffi=3.1.0 yaml.types=3.1.0 zarith=1.12 2023/05/16 12:51:12 [clock:3] Using native (high-precision) implementation for latency control 2023/05/16 12:51:20 [main:3] Standard library loaded in 7.14 seconds. 2023/05/16 12:51:20 [frame:4] frame.audio.samplerate set to: 44100 2023/05/16 12:51:20 [frame:4] frame.video.framerate set to: 25 2023/05/16 12:51:20 [frame:4] frame.audio.channels set to: 2 2023/05/16 12:51:20 [frame:4] frame.video.default set to: false 2023/05/16 12:51:20 [frame:4] frame.midi.channels set to: 0 2023/05/16 12:51:20 [frame:4] frame.video.width set to: 1280 2023/05/16 12:51:20 [frame:4] frame.video.height set to: 720 2023/05/16 12:51:20 [frame:4] frame.audio.samplerate set to: 44100 2023/05/16 12:51:20 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main. 2023/05/16 12:51:20 [frame:3] Video frame size set to: 1280x720 2023/05/16 12:51:20 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2023/05/16 12:51:20 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2023/05/16 12:51:20 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2023/05/16 12:51:20 [sandbox:3] Sandboxing disabled 2023/05/16 12:51:20 [startup:3] DSSI plugins registration: 0.00s 2023/05/16 12:51:20 [startup:3] FFmpeg filters registration: 0.02s 2023/05/16 12:51:20 [startup:3] FFmpeg bitstream filters registration: 0.00s 2023/05/16 12:51:20 [startup:3] Lilv plugins registration: 0.00s 2023/05/16 12:51:20 [startup:3] Frei0r plugin registration: 0.00s 2023/05/16 12:51:20 [startup:3] LADSPA plugins registration: 0.00s 2023/05/16 12:51:20 [startup:3] Typechecking: 6.95s 2023/05/16 12:51:20 [startup:3] Evaluation: 0.02s 2023/05/16 12:51:20 [startup:3] Typechecking: 0.03s 2023/05/16 12:51:20 [startup:3] Evaluation: 0.00s 2023/05/16 12:51:20 [startup:3] Typechecking: 0.01s 2023/05/16 12:51:20 [startup:3] Evaluation: 0.00s 2023/05/16 12:51:20 [startup:3] Loaded 1.liq: 0.01s 2023/05/16 12:51:20 [video.converter:3] Using preferred video converter: ffmpeg. 2023/05/16 12:51:20 [audio.converter:3] Using samplerate converter: libsamplerate. 2023/05/16 12:51:20 [lifecycle:5] At stage: "Liquidsoap application start" 2023/05/16 12:51:20 [clock:4] Currently 1 clock(s) allocated. 2023/05/16 12:51:20 [clock.main:4] Starting 2 source(s)... 2023/05/16 12:51:20 [input.harbor_0:5] Assigning source content type for frame type: 'A 2023/05/16 12:51:20 [input.harbor_0:5] Content type: {audio=pcm(stereo)} 2023/05/16 12:51:20 [source:4] Source input.harbor_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 12:51:20 [input.harbor_0:5] Clock is main[]. 2023/05/16 12:51:20 [input.harbor_0:3] Content type is {audio=pcm(stereo)}. 2023/05/16 12:51:20 [harbor:4] Opening port 8005 with icy = false 2023/05/16 12:51:20 [clock.main:2] Error when starting input.harbor_0: Lang.Runtime_error { kind: "not_found", msg: "Cannot read SSL key file! Given path: key.pem, resolved path: /home/debian/key.pem", pos: [at 1.liq, line 3 char 16 - line 6 char 1] }! 2023/05/16 12:51:20 [clock.main:4] Raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 48, characters 14-21 2023/05/16 12:51:20 [clock.main:4] Called from Builtins_ssl.(fun).find in file "src/core/builtins/builtins_ssl.ml", line 192, characters 16-189 2023/05/16 12:51:20 [clock.main:4] Called from Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 49-57 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/16 12:51:20 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94 2023/05/16 12:51:20 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 12:51:20 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/16 12:51:20 [clock.main:4] 2023/05/16 12:51:20 [input.harbor_0:5] Activations changed: static=[], dynamic=[]. 2023/05/16 12:51:20 [input.harbor_0:5] Enabling caching mode: active source. 2023/05/16 12:51:20 [source:4] Source input.harbor_0 gets down. 2023/05/16 12:51:20 [output.dummy_0:5] Assigning source content type for frame type: {audio : pcm(stereo)} 2023/05/16 12:51:20 [output.dummy_0:5] Content type: {audio=pcm(stereo)} 2023/05/16 12:51:20 [source:4] Source output.dummy_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 12:51:20 [dummy:5] Clock is main[]. 2023/05/16 12:51:20 [dummy:3] Content type is {audio=pcm(stereo)}. 2023/05/16 12:51:20 [source:4] Source input.harbor_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 12:51:20 [input.harbor_0:5] Clock is main[]. 2023/05/16 12:51:20 [input.harbor_0:3] Content type is {audio=pcm(stereo)}. 2023/05/16 12:51:20 [harbor:4] Opening port 8005 with icy = false 2023/05/16 12:51:20 [clock.main:2] Error when starting dummy: Lang.Runtime_error { kind: "not_found", msg: "Cannot read SSL key file! Given path: key.pem, resolved path: /home/debian/key.pem", pos: [at 1.liq, line 3 char 16 - line 6 char 1] }! 2023/05/16 12:51:20 [clock.main:4] Raised at Liquidsoap_lang__Runtime_error.raise in file "src/lang/runtime_error.ml", line 48, characters 14-21 2023/05/16 12:51:20 [clock.main:4] Called from Builtins_ssl.(fun).find in file "src/core/builtins/builtins_ssl.ml", line 192, characters 16-189 2023/05/16 12:51:20 [clock.main:4] Called from Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 49-57 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/16 12:51:20 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/16 12:51:20 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94 2023/05/16 12:51:20 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 12:51:20 [clock.main:4] Called from Output.output#wake_up in file "src/core/outputs/output.ml", line 122, characters 6-57 2023/05/16 12:51:20 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 12:51:20 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/16 12:51:20 [clock.main:4] 2023/05/16 12:51:20 [dummy:5] Activations changed: static=[], dynamic=[]. 2023/05/16 12:51:20 [dummy:5] Enabling caching mode: active source. 2023/05/16 12:51:20 [source:4] Source dummy gets down. 2023/05/16 12:51:20 [input.harbor_0:5] Activations changed: static=[], dynamic=[]. 2023/05/16 12:51:20 [source:4] Source input.harbor_0 gets down. 2023/05/16 12:51:20 [clock:4] Main phase starts. 2023/05/16 12:51:20 [threads:4] Created thread "generic queue #1" (1 total). 2023/05/16 12:51:20 [threads:4] Created thread "generic queue #2" (2 total). 2023/05/16 12:51:20 [threads:4] Created thread "non-blocking queue #1" (3 total). 2023/05/16 12:51:20 [threads:4] Created thread "non-blocking queue #2" (4 total). 2023/05/16 12:51:20 [main:3] Shutdown started! 2023/05/16 12:51:20 [lifecycle:5] At stage: "Liquidsoap core shutdown" 2023/05/16 12:51:20 [main:3] Waiting for main threads to terminate... 2023/05/16 12:51:20 [main:3] Main threads terminated. 2023/05/16 12:51:20 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown" 2023/05/16 12:51:20 [threads:3] Shutting down scheduler... 2023/05/16 12:51:20 [threads:4] Thread "non-blocking queue #2" terminated (3 remaining). 2023/05/16 12:51:20 [threads:4] Thread "generic queue #1" terminated (2 remaining). 2023/05/16 12:51:20 [threads:4] Thread "generic queue #2" terminated (1 remaining). 2023/05/16 12:51:20 [threads:4] Thread "non-blocking queue #1" terminated (0 remaining). 2023/05/16 12:51:20 [threads:3] Scheduler shut down. 2023/05/16 12:51:20 [lifecycle:5] At stage: "Liquidsoap final cleanup" 2023/05/16 12:51:20 [main:3] Cleaning downloaded files... 2023/05/16 12:51:20 [main:3] Freeing memory... 2023/05/16 12:51:20 >>> LOG END ```
toots commented 1 year ago

input.harbor is an active source so it is actively animated by its clock. For all intent and purposes, it acts as an output w.r.t. clock. The current initialization loop in clocks does try to initialize all "outputs" so input.harbor is asked to get ready twice, once on its own and once through the output.

The code for get_ready is able to detect if a source is asked multiple times to get ready and only execute once. However, it does not account for a failure to get ready the first time, which explains the double exception here.

This should be changed but this will have to wait for the next major release cycle during which we plan on rewriting the whole streaming API.

vitoyucepi commented 1 year ago

Some exceptions may not be caught.

2023/05/15 23:01:16 [clock.main:2] Error when starting input.harbor_0: SSL: Privte key error: error:0908F066:PEM routines:get_header_and_data:bad end line!
2023/05/15 23:01:16 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53
2023/05/15 23:01:16 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57
2023/05/15 23:01:16 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94
2023/05/15 23:01:16 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31
2023/05/15 23:01:16 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45
2023/05/15 23:01:16 [clock.main:4] 

This looks fine. this is a legit error with a descriptive explanation. It's happening inside the streaming loop so there isn't really a reason to re-raise it as a runtime error since it cannot be caught and should be treated as a fatal error.

But where does it happen? One of the keys is broken, but which one?

This is caused by removing the last line from the key file. Everything is left the same.

  1. Config

    ssl_transport = http.transport.ssl(
     certificate="cert.pem",
     key="key.pem",
    )
    
    live = input.harbor(
     "live",
     transport=ssl_transport,
     port=8005,
     password="test",
    )
    output.dummy(live, fallible=true)
  2. Generate a certificate. openssl req -x509 -newkey rsa:2048 -keyout key.pem -out cert.pem -sha256 -days 365 -subj '/CN=localhost' -nodes
  3. Corrupt file, use one at a time
    • sed 's/-----END PRIVATE KEY-----//' -i key.pem
    • sed '5d' -i key.pem
Log ``` INFO: Loading Sdl_image, Target = linux INFO: Loading Sdl_ttf, Target = linux 2023/05/16 13:05:01 >>> LOG START 2023/05/16 13:04:54 [main:3] Liquidsoap 2.2.0+git@efa40bde1 2023/05/16 13:04:54 [main:3] Using: alsa=0.3.0 angstrom=0.15.0 ao=0.2.4 asetmap=0.8.1 asn1-combinators=0.2.6 astring=0.8.5 base.caml=v0.15.1 base64=3.5.1 bigarray=[distributed with OCaml] bigarray-compat=1.1.0 bigstringaf=0.9.1 bjack=0.1.6 bos=0.2.1 bytes=[distributed with OCaml] ca-certs=v0.2.3 camlimages.all_formats=4.2.6 camlimages.core=5.0.4 camlimages.exif=5.0.4 camlimages.gif=5.0.4 camlimages.jpeg=5.0.4 camlimages.png=5.0.4 camlimages.tiff=5.0.4 camlimages.xpm=5.0.4 camlp-streams camomile=d3773ec camomile.lib=d3773ec cohttp=5.1.0 cohttp-lwt=5.1.0 cohttp-lwt-unix=5.1.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=1.0.0 cstruct=6.2.0 ctypes=0.20.2 ctypes.foreign=0.20.2 ctypes.stubs=0.20.2 curl=0.9.2 domain-name=0.4.0 dssi=0.1.5 dtools=0.4.5 dune-build-info=3.7.1 dune-private-libs.dune-section=3.7.1 dune-site=3.7.1 dune-site.private=3.7.1 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 faad=0.5.2 fdkaac=0.3.3 ffmpeg-av=1.1.8 ffmpeg-avcodec=1.1.8 ffmpeg-avdevice=1.1.8 ffmpeg-avfilter=1.1.8 ffmpeg-avutil=1.1.8 ffmpeg-swresample=1.1.8 ffmpeg-swscale=1.1.8 fileutils=0.6.4 flac=0.4.0 flac.decoder=0.4.0 flac.ogg=0.4.0 fmt=0.9.0 fpath=0.7.3 frei0r=0.1.2 gd=1.0a5 gen=1.1 gmap=0.3.0 hkdf=1.0.4 inotify=2.4.1 integers ipaddr=5.5.0 ipaddr-sexp=5.5.0 ipaddr.unix=5.5.0 irc-client irc-client-unix ladspa=0.2.2 lame=0.3.7 lastfm=0.3.3 lilv=0.1.0 liquidsoap-lang=2.2.0 liquidsoap-lang.console=2.2.0 liquidsoap_alsa=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ao=rolling-release-v2.2.x-56-gefa40bd liquidsoap_bjack=rolling-release-v2.2.x-56-gefa40bd liquidsoap_builtins=rolling-release-v2.2.x-56-gefa40bd liquidsoap_camlimages=rolling-release-v2.2.x-56-gefa40bd liquidsoap_core=rolling-release-v2.2.x-56-gefa40bd liquidsoap_dssi=rolling-release-v2.2.x-56-gefa40bd liquidsoap_faad=rolling-release-v2.2.x-56-gefa40bd liquidsoap_fdkaac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ffmpeg=rolling-release-v2.2.x-56-gefa40bd liquidsoap_flac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_frei0r=rolling-release-v2.2.x-56-gefa40bd liquidsoap_gd=rolling-release-v2.2.x-56-gefa40bd liquidsoap_irc=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ladspa=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lame=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lastfm=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lilv=rolling-release-v2.2.x-56-gefa40bd liquidsoap_lo=rolling-release-v2.2.x-56-gefa40bd liquidsoap_mad=rolling-release-v2.2.x-56-gefa40bd liquidsoap_magic=rolling-release-v2.2.x-56-gefa40bd liquidsoap_mem_usage=rolling-release-v2.2.x-56-gefa40bd liquidsoap_memtrace=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ogg=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ogg_flac=rolling-release-v2.2.x-56-gefa40bd liquidsoap_optionals=rolling-release-v2.2.x-56-gefa40bd liquidsoap_opus=rolling-release-v2.2.x-56-gefa40bd liquidsoap_osc=rolling-release-v2.2.x-56-gefa40bd liquidsoap_oss=rolling-release-v2.2.x-56-gefa40bd liquidsoap_portaudio=rolling-release-v2.2.x-56-gefa40bd liquidsoap_posix_time=rolling-release-v2.2.x-56-gefa40bd liquidsoap_prometheus=rolling-release-v2.2.x-56-gefa40bd liquidsoap_pulseaudio=rolling-release-v2.2.x-56-gefa40bd liquidsoap_runtime=rolling-release-v2.2.x-56-gefa40bd liquidsoap_samplerate=rolling-release-v2.2.x-56-gefa40bd liquidsoap_sdl=rolling-release-v2.2.x-56-gefa40bd liquidsoap_shine=rolling-release-v2.2.x-56-gefa40bd liquidsoap_soundtouch=rolling-release-v2.2.x-56-gefa40bd liquidsoap_speex=rolling-release-v2.2.x-56-gefa40bd liquidsoap_srt=rolling-release-v2.2.x-56-gefa40bd liquidsoap_ssl=rolling-release-v2.2.x-56-gefa40bd liquidsoap_stereotool=rolling-release-v2.2.x-56-gefa40bd liquidsoap_taglib=rolling-release-v2.2.x-56-gefa40bd liquidsoap_theora=rolling-release-v2.2.x-56-gefa40bd liquidsoap_tls=rolling-release-v2.2.x-56-gefa40bd liquidsoap_vorbis=rolling-release-v2.2.x-56-gefa40bd liquidsoap_xmlplaylist=rolling-release-v2.2.x-56-gefa40bd liquidsoap_yaml=rolling-release-v2.2.x-56-gefa40bd lo=0.2.0 logs=0.7.0 logs.fmt=0.7.0 logs.lwt=0.7.0 lwt=5.6.1 lwt.unix=5.6.1 macaddr=5.5.0 mad=0.5.3 magic=0.7.3 magic-mime=1.3.0 mem_usage=0.0.4 memtrace=0.2.3 menhirLib=20220210 metadata=0.2.0 mirage-crypto=0.11.1 mirage-crypto-ec=0.11.1 mirage-crypto-pk=0.11.1 mirage-crypto-rng=0.11.1 mirage-crypto-rng.unix=0.11.1 mm=0.8.3 mm.audio=0.8.3 mm.base=0.8.3 mm.image=0.8.3 mm.midi=0.8.3 mm.video=0.8.3 ocplib-endian ocplib-endian.bigstring ogg=0.7.4 ogg.decoder=0.7.4 opus=0.2.3 opus.decoder=0.2.3 osc osc-unix parsexp=v0.15.0 pbkdf pcre=7.5.0 portaudio=0.2.3 posix-base=65ec333 posix-socket=65ec333 posix-socket.constants=65ec333 posix-socket.stubs=65ec333 posix-socket.types=65ec333 posix-time2=65ec333 posix-time2.constants=65ec333 posix-time2.stubs=65ec333 posix-time2.types=65ec333 posix-types=65ec333 posix-types.constants=65ec333 ppx_sexp_conv.runtime-lib=v0.15.0 prometheus=1.2 prometheus-app=1.2 ptime=1.1.0 ptime.clock.os=1.1.0 pulseaudio=0.1.6 re=1.10.4 result=1.5 rresult=0.7.0 samplerate=0.1.6 sedlex=3.1 seq=[distributed with OCaml 4.07 or above] sexplib=v0.15.1 sexplib0=v0.15.0 shine=0.2.3 soundtouch=0.1.9 speex=0.4.2 speex.decoder=0.4.2 srt=0.3.0 srt.constants=0.3.0 srt.stubs=0.3.0 srt.stubs.locked=0.3.0 srt.types=0.3.0 ssl=0.5.13 stdlib-shims=0.3.0 stereotool=rolling-release-v2.2.x-56-gefa40bd str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 theora=0.4.1 theora.decoder=0.4.1 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] tls=0.17.0 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.5 unix=[distributed with OCaml] unix-errno=0.6.2 unix-errno.errno_bindings=0.6.2 unix-errno.errno_types=0.6.2 unix-errno.errno_types_detected=0.6.2 unix-errno.unix=0.6.2 uri=4.2.0 uri-sexp=4.2.0 uri.services=4.2.0 vorbis=0.8.1 vorbis.decoder=0.8.1 x509=0.16.4 xmlm=1.4.0 xmlplaylist=0.1.5 yaml=3.1.0 yaml.bindings=3.1.0 yaml.bindings.types=3.1.0 yaml.c=3.1.0 yaml.ffi=3.1.0 yaml.types=3.1.0 zarith=1.12 2023/05/16 13:04:54 [clock:3] Using native (high-precision) implementation for latency control 2023/05/16 13:05:01 [main:3] Standard library loaded in 7.17 seconds. 2023/05/16 13:05:01 [frame:4] frame.audio.samplerate set to: 44100 2023/05/16 13:05:01 [frame:4] frame.video.framerate set to: 25 2023/05/16 13:05:01 [frame:4] frame.audio.channels set to: 2 2023/05/16 13:05:01 [frame:4] frame.video.default set to: false 2023/05/16 13:05:01 [frame:4] frame.midi.channels set to: 0 2023/05/16 13:05:01 [frame:4] frame.video.width set to: 1280 2023/05/16 13:05:01 [frame:4] frame.video.height set to: 720 2023/05/16 13:05:01 [frame:4] frame.audio.samplerate set to: 44100 2023/05/16 13:05:01 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main. 2023/05/16 13:05:01 [frame:3] Video frame size set to: 1280x720 2023/05/16 13:05:01 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2023/05/16 13:05:01 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2023/05/16 13:05:01 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2023/05/16 13:05:01 [sandbox:3] Sandboxing disabled 2023/05/16 13:05:01 [startup:3] DSSI plugins registration: 0.00s 2023/05/16 13:05:01 [startup:3] FFmpeg filters registration: 0.02s 2023/05/16 13:05:01 [startup:3] FFmpeg bitstream filters registration: 0.00s 2023/05/16 13:05:01 [startup:3] Lilv plugins registration: 0.00s 2023/05/16 13:05:01 [startup:3] Frei0r plugin registration: 0.00s 2023/05/16 13:05:01 [startup:3] LADSPA plugins registration: 0.00s 2023/05/16 13:05:01 [startup:3] Typechecking: 6.98s 2023/05/16 13:05:01 [startup:3] Evaluation: 0.02s 2023/05/16 13:05:01 [startup:3] Typechecking: 0.02s 2023/05/16 13:05:01 [startup:3] Evaluation: 0.00s 2023/05/16 13:05:01 [startup:3] Typechecking: 0.01s 2023/05/16 13:05:01 [startup:3] Evaluation: 0.00s 2023/05/16 13:05:01 [startup:3] Loaded 1.liq: 0.01s 2023/05/16 13:05:01 [video.converter:3] Using preferred video converter: ffmpeg. 2023/05/16 13:05:01 [audio.converter:3] Using samplerate converter: libsamplerate. 2023/05/16 13:05:01 [lifecycle:5] At stage: "Liquidsoap application start" 2023/05/16 13:05:01 [clock:4] Currently 1 clock(s) allocated. 2023/05/16 13:05:01 [clock.main:4] Starting 2 source(s)... 2023/05/16 13:05:01 [input.harbor_0:5] Assigning source content type for frame type: 'A 2023/05/16 13:05:01 [input.harbor_0:5] Content type: {audio=pcm(stereo)} 2023/05/16 13:05:01 [source:4] Source input.harbor_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 13:05:01 [input.harbor_0:5] Clock is main[]. 2023/05/16 13:05:01 [input.harbor_0:3] Content type is {audio=pcm(stereo)}. 2023/05/16 13:05:01 [harbor:4] Opening port 8005 with icy = false 2023/05/16 13:05:01 [clock.main:2] Error when starting input.harbor_0: SSL: Privte key error: error:0D07209B:asn1 encoding routines:ASN1_get_object:too long! 2023/05/16 13:05:01 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/16 13:05:01 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94 2023/05/16 13:05:01 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 13:05:01 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/16 13:05:01 [clock.main:4] 2023/05/16 13:05:01 [input.harbor_0:5] Activations changed: static=[], dynamic=[]. 2023/05/16 13:05:01 [input.harbor_0:5] Enabling caching mode: active source. 2023/05/16 13:05:01 [source:4] Source input.harbor_0 gets down. 2023/05/16 13:05:01 [output.dummy_0:5] Assigning source content type for frame type: {audio : pcm(stereo)} 2023/05/16 13:05:01 [output.dummy_0:5] Content type: {audio=pcm(stereo)} 2023/05/16 13:05:01 [source:4] Source output.dummy_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 13:05:01 [dummy:5] Clock is main[]. 2023/05/16 13:05:01 [dummy:3] Content type is {audio=pcm(stereo)}. 2023/05/16 13:05:01 [source:4] Source input.harbor_0 gets up with content type: {audio=pcm(stereo)}. 2023/05/16 13:05:01 [input.harbor_0:5] Clock is main[]. 2023/05/16 13:05:01 [input.harbor_0:3] Content type is {audio=pcm(stereo)}. 2023/05/16 13:05:01 [harbor:4] Opening port 8005 with icy = false 2023/05/16 13:05:01 [clock.main:2] Error when starting dummy: SSL: Privte key error: error:0D07209B:asn1 encoding routines:ASN1_get_object:too long! 2023/05/16 13:05:01 [clock.main:4] Raised by primitive operation at Builtins_ssl.server in file "src/core/builtins/builtins_ssl.ml", line 58, characters 4-57 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.open_port in file "src/core/harbor/harbor.ml", line 1007, characters 17-33 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.get_handler in file "src/core/harbor/harbor.ml", line 1128, characters 17-53 2023/05/16 13:05:01 [clock.main:4] Called from Harbor.Make.add_source in file "src/core/harbor/harbor.ml", line 1141, characters 20-57 2023/05/16 13:05:01 [clock.main:4] Called from Harbor_input.http_input_server#wake_up in file "src/core/sources/harbor_input.ml", line 151, characters 6-94 2023/05/16 13:05:01 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 13:05:01 [clock.main:4] Called from Output.output#wake_up in file "src/core/outputs/output.ml", line 122, characters 6-57 2023/05/16 13:05:01 [clock.main:4] Called from Source.operator#get_ready in file "src/core/source.ml", line 514, characters 8-31 2023/05/16 13:05:01 [clock.main:4] Called from Clock.MkClock.clock#start_outputs.(fun) in file "src/core/clock.ml", line 370, characters 18-45 2023/05/16 13:05:01 [clock.main:4] 2023/05/16 13:05:01 [dummy:5] Activations changed: static=[], dynamic=[]. 2023/05/16 13:05:01 [dummy:5] Enabling caching mode: active source. 2023/05/16 13:05:01 [source:4] Source dummy gets down. 2023/05/16 13:05:01 [input.harbor_0:5] Activations changed: static=[], dynamic=[]. 2023/05/16 13:05:01 [source:4] Source input.harbor_0 gets down. 2023/05/16 13:05:01 [clock:4] Main phase starts. 2023/05/16 13:05:01 [threads:4] Created thread "generic queue #1" (1 total). 2023/05/16 13:05:01 [threads:4] Created thread "generic queue #2" (2 total). 2023/05/16 13:05:01 [threads:4] Created thread "non-blocking queue #1" (3 total). 2023/05/16 13:05:01 [threads:4] Created thread "non-blocking queue #2" (4 total). 2023/05/16 13:05:01 [main:3] Shutdown started! 2023/05/16 13:05:01 [lifecycle:5] At stage: "Liquidsoap core shutdown" 2023/05/16 13:05:01 [main:3] Waiting for main threads to terminate... 2023/05/16 13:05:01 [main:3] Main threads terminated. 2023/05/16 13:05:01 [lifecycle:5] At stage: "Liquidsoap scheduler shutdown" 2023/05/16 13:05:01 [threads:3] Shutting down scheduler... 2023/05/16 13:05:01 [threads:4] Thread "generic queue #1" terminated (3 remaining). 2023/05/16 13:05:01 [threads:3] Scheduler shut down. 2023/05/16 13:05:01 [threads:4] Thread "generic queue #2" terminated (2 remaining). 2023/05/16 13:05:01 [threads:4] Thread "non-blocking queue #2" terminated (1 remaining). 2023/05/16 13:05:01 [threads:4] Thread "non-blocking queue #1" terminated (0 remaining). 2023/05/16 13:05:01 [lifecycle:5] At stage: "Liquidsoap final cleanup" 2023/05/16 13:05:01 [main:3] Cleaning downloaded files... 2023/05/16 13:05:01 [main:3] Freeing memory... 2023/05/16 13:05:02 >>> LOG END ```
toots commented 1 year ago

Both errors are the same. I believe your key is considered invalid by libssl/openss if it is missing the last line.

toots commented 1 year ago

Also, the error says the private key is invalid:

Privte key error: error:0908F066:PEM routines:get_header_and_data:bad end line!

That seems pretty clear to me.

vitoyucepi commented 1 year ago

Privte key error: error:0200100D:system library:fopen:Permission denied! Privte key error: error:0908F066:PEM routines:get_header_and_data:bad end line! Privte key error: error:0D07209B:asn1 encoding routines:ASN1_get_object:too long!

The first one is caught, while the rest are not.

I'd like to see the position and file path for all of them.

Error when starting input.harbor_0: Lang.Runtime_error { kind: "not_found", msg: "Cannot read SSL key file! Given path: key.pem, resolved path: /home/debian/key.pem", pos: [at 1.liq, line 3 char 16 - line 6 char 1] }!
toots commented 1 year ago

Internal exceptions like that are triggered in parts that are not script. There's a function to map them to runtime errors, Lang.raise_as_runtime, but it reports the stack tracks as ML files. I think that this can be equally confusing to the user who may or may not know what OCaml is. Besides, it would report the same info that is currently reported the log and wouldn't be catchable so I'm not sure exactly what this would add.

vitoyucepi commented 1 year ago

Is it possible to show which cert/key caused this error?

nginx: [emerg] cannot load certificate key "/etc/nginx/key.pem": PEM_read_bio_PrivateKey() failed (SSL: error:1E08010C:DECODER routines::unsupported:No supported data to decode. Input type: PEM error:0680009B:asn1 encoding routines::too long error:06800066:asn1 encoding routines::bad object header error:0688010A:asn1 encoding routines::nested asn1 error:Type=PKCS8_PRIV_KEY_INFO)
Traceback (most recent call last):
  File "/tmp/1.py", line 7, in <module>
    httpd.socket = ssl.wrap_socket (httpd.socket, keyfile="./key.pem", certfile="./cert.pem", server_side=True)
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/ssl.py", line 1443, in wrap_socket
    context.load_cert_chain(certfile, keyfile)
ssl.SSLError: [SSL] PEM lib (_ssl.c:3921)