livekit / egress

Export and record WebRTC sessions and tracks
https://blog.livekit.io/livekit-universal-egress-launch/
Apache License 2.0
186 stars 76 forks source link

Failed to create egress #525

Closed rafaelhutter closed 1 year ago

rafaelhutter commented 1 year ago

I just started testing 1.8.0 but unfortunately egress is unable to start the recording. LiveKit version is 1.5.0 and testing the same with egress 1.7.12 works fine. Here are the logs:

heckm4n commented 1 year ago

@frostbyte73 Hi David, we are currently pinning all our hopes on a fix because we are building a great setup and really want to use it. Is there hope for a quick fix?

frostbyte73 commented 1 year ago

Please revert to v1.7.12 for now. I'll be removing 1.8.0, since it won't work until the next release of livekit server

rafaelhutter commented 1 year ago

@frostbyte73 I've created my own image for livekit from the source and in the initial tests I could't reproduce the issue anymore. Thanks a lot! We'll run more tests today

furkanKotic commented 11 months ago

@frostbyte73 I had the same problem with version v1.8.0, so I downgraded it to v1.7.12. This time the following error occurs:

+ rm -rf '/home/egress/tmp/*'
+ rm -rf /var/run/pulse /var/lib/pulse /home/egress/.config/pulse
+ pulseaudio -D --verbose --exit-idle-time=-1 --disallow-exit
I: [pulseaudio] main.c: Daemon startup successful.
+ exec egress
2023-12-11T13:13:30.551Z    INFO    egress  redis/redis.go:127  connecting to redis {"nodeID": "NE_RqDVTJybZ3Jw", "clusterID": "", "simple": true, "addr": "*******:6478"}
2023-12-11T13:13:30.728Z    INFO    egress  stats/monitor.go:130    cpu available: 12.000000 max cost: 4.000000 {"nodeID": "NE_RqDVTJybZ3Jw", "clusterID": ""}
2023-12-11T13:13:30.879Z    INFO    egress  service/service.go:100  service ready   {"nodeID": "NE_RqDVTJybZ3Jw", "clusterID": ""}
2023-12-11T13:13:56.216Z    INFO    egress  service/service.go:123  request received    {"nodeID": "NE_RqDVTJybZ3Jw", "clusterID": "", "egressID": "EG_YY2zGCivVshV"}
2023-12-11T13:13:56.216Z    INFO    egress  service/service.go:132  request validated   {"nodeID": "NE_RqDVTJybZ3Jw", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "requestType": "room_composite", "outputType": "stream", "room": "20338", "request": {"RoomComposite":{"room_name":"20338","layout":"grid-light","Output":null,"Options":{"Preset":4},"stream_outputs":[{"protocol":1,"urls":["rtmp://rtmp.mydomain.org/live/{106...Me}"]}]}}}
2023-12-11T13:13:56.234Z    INFO    egress  redis/redis.go:127  connecting to redis {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "simple": true, "addr": "*******:6478"}
0:00:00.180945255    47 0x55e94e8e7860 WARN              cudaloader gstcudaloader.c:169:gst_cuda_load_library: Could not open library libcuda.so.1, libcuda.so.1: cannot open shared object file: No such file or directory
0:00:00.180960385    47 0x55e94e8e7860 WARN                 nvcodec plugin.c:94:plugin_init: Failed to load cuda library
0:00:00.214879086    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x120000: 'AVR (Audio Visual Research)' is not mapped
0:00:00.214889236    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x180000: 'CAF (Apple Core Audio File)' is not mapped
0:00:00.214892416    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x100000: 'HTK (HMM Tool Kit)' is not mapped
0:00:00.214895636    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xc0000: 'MAT4 (GNU Octave 2.0 / Matlab 4.2)' is not mapped
0:00:00.214898506    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xd0000: 'MAT5 (GNU Octave 2.1 / Matlab 5.0)' is not mapped
0:00:00.214901246    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x210000: 'MPC (Akai MPC 2k)' is not mapped
0:00:00.214904636    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xe0000: 'PVF (Portable Voice Format)' is not mapped
0:00:00.214907676    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x160000: 'SD2 (Sound Designer II)' is not mapped
0:00:00.214911726    47 0x55e94e8e7860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x190000: 'WVE (Psion Series 3)' is not mapped
2023-12-11T13:13:58.683Z    INFO    egress  source/web.go:271   chrome: START_RECORDING {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV"}
2023-12-11T13:13:58.686Z    INFO    egress  pipeline/watch.go:228   pipeline playing    {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV"}
2023-12-11T13:13:58.686Z    INFO    egress  service/handler.go:226  egress updated  {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "egressID": "EG_YY2zGCivVshV", "requestType": "room_composite", "outputType": "stream", "status": "EGRESS_ACTIVE"}
2023-12-11T13:13:59.837Z    DEBUG   egress  [gst error] gst_rtmp_connection_input_ready: read error: g-io-error-quark 44 connection closed remotely {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "caller": "../gst/rtmp2/rtmp/rtmpconnection.c:496"}
2023-12-11T13:13:59.837Z    DEBUG   egress  [gst warning] error_callback: error: Connection error: connection closed remotely   {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "caller": "../gst/rtmp2/gstrtmp2sink.c:1085"}
2023-12-11T13:13:59.837Z    DEBUG   egress  [gst warning] error_callback: error: domain g-io-error-quark, code 44   {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "caller": "../gst/rtmp2/gstrtmp2sink.c:1085"}
2023-12-11T13:13:59.838Z    INFO    egress  pipeline/controller.go:328  removing stream sink    {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "url": "rtmp://rtmp.mydomain.org/live/{106...Me}", "status": "FAILED", "duration": 1151676251, "error": "Connection error: connection closed remotely"}
2023-12-11T13:13:59.838Z    DEBUG   egress  [gst warning] audioringbuffer_thread_func: error reading data -1 (reason: Success), skipping segment    {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "caller": "../gst-libs/gst/audio/gstaudiosrc.c:227"}
2023-12-11T13:13:59.909Z    WARN    egress  service/handler.go:214  egress failed   {"nodeID": "NE_RqDVTJybZ3Jw", "handlerID": "EGH_nM4c9p2V4xQq", "clusterID": "", "egressID": "EG_YY2zGCivVshV", "egressID": "EG_YY2zGCivVshV", "requestType": "room_composite", "outputType": "stream", "error": "Connection error: connection closed remotely"}

Before upgrading to Livekit v1.5.0, Egress v1.7.8 was working fine. Currently, the following logs are created in v1.7.8 version.

+ rm -rf '/home/egress/tmp/*'
+ rm -rf /var/run/pulse /var/lib/pulse /home/egress/.config/pulse
+ pulseaudio -D --verbose --exit-idle-time=-1 --disallow-exit
I: [pulseaudio] main.c: Daemon startup successful.
+ exec egress
2023-12-11T13:46:43.993Z    INFO    egress  redis/redis.go:127  connecting to redis {"nodeID": "NE_CZPKJCYtQR4a", "clusterID": "", "simple": true, "addr": "********:6478"}
2023-12-11T13:46:44.171Z    INFO    egress  stats/monitor.go:129    cpu available: 12.000000 max cost: 4.000000 {"nodeID": "NE_CZPKJCYtQR4a", "clusterID": ""}
2023-12-11T13:46:44.323Z    INFO    egress  service/service.go:100  service ready   {"nodeID": "NE_CZPKJCYtQR4a", "clusterID": ""}
2023-12-11T13:46:57.990Z    INFO    egress  service/service.go:123  request received    {"nodeID": "NE_CZPKJCYtQR4a", "clusterID": "", "egressID": "EG_FrCmLgESGGxj"}
2023-12-11T13:46:57.991Z    INFO    egress  service/service.go:132  request validated   {"nodeID": "NE_CZPKJCYtQR4a", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "requestType": "room_composite", "outputType": "stream", "room": "20342", "request": {"RoomComposite":{"room_name":"20342","layout":"grid-light","Output":null,"Options":{"Preset":4},"stream_outputs":[{"protocol":1,"urls":["rtmp://rtmp.mydomain.org/live/{106...Me}"]}]}}}
2023-12-11T13:46:58.010Z    INFO    egress  redis/redis.go:127  connecting to redis {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "simple": true, "addr": "*********:6478"}
0:00:00.166450404    45 0x55de3f596860 WARN              cudaloader gstcudaloader.c:169:gst_cuda_load_library: Could not open library libcuda.so.1, libcuda.so.1: cannot open shared object file: No such file or directory
0:00:00.166464984    45 0x55de3f596860 WARN                 nvcodec plugin.c:94:plugin_init: Failed to load cuda library
0:00:00.200771588    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x120000: 'AVR (Audio Visual Research)' is not mapped
0:00:00.200781178    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x180000: 'CAF (Apple Core Audio File)' is not mapped
0:00:00.200784438    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x100000: 'HTK (HMM Tool Kit)' is not mapped
0:00:00.200787837    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xc0000: 'MAT4 (GNU Octave 2.0 / Matlab 4.2)' is not mapped
0:00:00.200790687    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xd0000: 'MAT5 (GNU Octave 2.1 / Matlab 5.0)' is not mapped
0:00:00.200795127    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x210000: 'MPC (Akai MPC 2k)' is not mapped
0:00:00.200799547    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xe0000: 'PVF (Portable Voice Format)' is not mapped
0:00:00.200803457    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x160000: 'SD2 (Sound Designer II)' is not mapped
0:00:00.200808937    45 0x55de3f596860 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x190000: 'WVE (Psion Series 3)' is not mapped
2023-12-11T13:47:00.362Z    INFO    egress  source/web.go:266   chrome: START_RECORDING {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj"}
2023-12-11T13:47:00.365Z    INFO    egress  pipeline/watch.go:236   pipeline playing    {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj"}
2023-12-11T13:47:00.365Z    INFO    egress  service/handler.go:226  egress updated  {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "egressID": "EG_FrCmLgESGGxj", "requestType": "room_composite", "outputType": "stream", "status": "EGRESS_ACTIVE"}
2023-12-11T13:47:01.553Z    DEBUG   egress  [gst error] gst_rtmp_connection_input_ready: read error: g-io-error-quark 44 connection closed remotely {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "caller": "../gst/rtmp2/rtmp/rtmpconnection.c:496"}
2023-12-11T13:47:01.553Z    DEBUG   egress  [gst warning] error_callback: error: Connection error: connection closed remotely   {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "caller": "../gst/rtmp2/gstrtmp2sink.c:1085", "object": "rtmp2sink_dF9ndSWwZB7K"}
2023-12-11T13:47:01.554Z    DEBUG   egress  [gst warning] error_callback: error: domain g-io-error-quark, code 44   {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "caller": "../gst/rtmp2/gstrtmp2sink.c:1085", "object": "rtmp2sink_dF9ndSWwZB7K"}
2023-12-11T13:47:01.554Z    ERROR   egress  pipeline/watch.go:171   failed to reset stream  {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "error": "stream rtmp2sink_dF9ndSWwZB7K not found"}
github.com/livekit/egress/pkg/pipeline.(*Controller).handleMessageError
    /workspace/pkg/pipeline/watch.go:171
github.com/livekit/egress/pkg/pipeline.(*Controller).messageWatch
    /workspace/pkg/pipeline/watch.go:131
github.com/tinyzimmer/go-gst/gst.goBusFunc
    /root/go/pkg/mod/github.com/livekit/go-gst@v0.2.34-0.20230901155409-dd09095b979e/gst/cgo_exports.go:128
_cgoexp_cd0fe6f73e38_goBusFunc
    _cgo_gotypes.go:17413
runtime.cgocallbackg1
    /usr/local/go/src/runtime/cgocall.go:315
runtime.cgocallbackg
    /usr/local/go/src/runtime/cgocall.go:234
runtime.cgocallback
    /usr/local/go/src/runtime/asm_amd64.s:998
runtime.systemstack_switch
    /usr/local/go/src/runtime/asm_amd64.s:463
runtime.cgocall
    /usr/local/go/src/runtime/cgocall.go:167
github.com/tinyzimmer/go-glib/glib._Cfunc_g_main_loop_run
    _cgo_gotypes.go:2801
github.com/tinyzimmer/go-glib/glib.(*MainLoop).Run.func1
    /root/go/pkg/mod/github.com/livekit/go-glib@v0.0.0-20230223001336-834490045522/glib/gmainloop.go:53
github.com/tinyzimmer/go-glib/glib.(*MainLoop).Run
    /root/go/pkg/mod/github.com/livekit/go-glib@v0.0.0-20230223001336-834490045522/glib/gmainloop.go:53
github.com/livekit/egress/pkg/gstreamer.(*Pipeline).Run
    /workspace/pkg/gstreamer/pipeline.go:132
github.com/livekit/egress/pkg/pipeline.(*Controller).Run
    /workspace/pkg/pipeline/controller.go:241
github.com/livekit/egress/pkg/service.(*Handler).Run.func1
    /workspace/pkg/service/handler.go:113
2023-12-11T13:47:01.554Z    INFO    egress  pipeline/controller.go:414  removing stream sink    {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "url": "rtmp://rtmp.mydomain.org/live/{106...Me}", "status": "FAILED", "duration": 1189153264, "error": "Connection error: connection closed remotely"}
2023-12-11T13:47:01.554Z    WARN    egress  service/handler.go:214  egress failed   {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "egressID": "EG_FrCmLgESGGxj", "requestType": "room_composite", "outputType": "stream", "error": "Connection error: connection closed remotely"}
2023-12-11T13:47:01.554Z    DEBUG   egress  [gst warning] audioringbuffer_thread_func: error reading data -1 (reason: Success), skipping segment    {"nodeID": "NE_CZPKJCYtQR4a", "handlerID": "EGH_m4sMa2aovTDY", "clusterID": "", "egressID": "EG_FrCmLgESGGxj", "caller": "../gst-libs/gst/audio/gstaudiosrc.c:227", "object": "pulsesrc0"}
frostbyte73 commented 11 months ago

These logs look like stream failures

furkanKotic commented 11 months ago

The problem was caused by Nginx RTMP ip control. The IP address is outdated due to the server change. Thanks