search

livekit / egress

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

Auto Track Participant does not record to mp4 #685

Closed Nitschi closed 3 months ago

Nitschi commented 3 months ago

Describe the bug We use LiveKit to stream a Video to an operator and would like to record the video as soon as it's published as mp4 and codec h264 to disk. This is why we use the Participant Auto Egress.

According to the logs egress is started normally (except for some warnings that don't seem critical to me), but ends with an error in the "egress_ended" event: error: "error": "stat /out/KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA.mp4: no such file or directory"

Egress Version 1.8.4 (from Dockerhub)

LiveKit Version 1.6.1 (from Dockerhub)

Egress Request The request to create the room (from the livekit-server logs):

service/twirp.go:124    API RoomService.CreateRoom      {"service": "RoomService", "method": "CreateRoom", "room": "KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA", "request": "name:\"KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA\"  empty_timeout:60  metadata:\"omitted\"  egress:{participant:{advanced:{video_codec:H264_MAIN}  file_outputs:{file_type:MP4  filepath:\"/out/{room_name}.mp4\"  disable_manifest:true}}}", "duration": "49.396133ms", "status": "200"}

Additional context Using AutoTrackEgress (where encoding etc. can't be defined) the recording works, but creates them as webm, which is why we chose the Auto Track Participant Approach.

Folder /out/ exists and egress has all rights (chmod -R 777 /out)

Logs LiveKit-Server Request:

2024-05-30T14:11:03.109Z        INFO    livekit.api     service/twirp.go:124    API RoomService.CreateRoom      {"service": "RoomService", "method": "CreateRoom", "room": "KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA", "request": "name:\"KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA\"  empty_timeout:60  metadata:\"cL133dxaBTWpLDghs/oBM56dQvAMF2zdF/cZxpa3uC/E7OW0bY2R/QrbfYMgRszPLRgif44rs3D0bFDl2ZMODYlsrrpoWzQqneCei+icBbpbsn7CrKzhJWpzG8F4eMsQp0CS97JmM+PjDgzJ0V4zO2Y7O0i+gKzoftO/KZPjdyaamG8IDpHbN/6z7RW5o4o2vn/geIarzvtS0Dx0x5YNMeH/spSi9DV4Mp9IMtDBx5+F2iMwSJmRyJbGCu1goT14AYmhjwG/z/0ErqrmFxF2C+wEIPC0/VOqvYsOdu2RslKY46R7iLW7JG2o3xQ17EmUy1OvD8ZgrMMu7wiFduuR8OUG/wk+EPTgUUvXdxr/1mYzAvNQU5V40W8vDEjACSlN3CGPZFyFYuZpszd1O+40Cw==\"  egress:{participant:{advanced:{video_codec:H264_MAIN}  file_outputs:{file_type:MP4  filepath:\"/out/{room_name}.mp4\"  disable_manifest:true}}}", "duration": "49.396133ms", "status": "200"}

LiveKit-Server Error Message

2024-05-30T14:11:31.143Z        INFO    livekit.webhook webhook/url_notifier.go:88      sent webhook    {"url": "<omitted>:5000/webhook", "event": "egress_ended", "eventDetails": {"event": "egress_ended", "egressInfo": {"egressId": "EG_vcdswtZvuX8y", "roomId": "RM_vB8FczegZTQf", "roomName": "KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA", "status": 4, "startedAt": 1717078278978269497, "endedAt": 1717078291188120836, "updatedAt": 1717078291188120836, "error": "stat /out/KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA.mp4: no such file or directory", "participant": {"roomName": "KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA", "identity": "+41991112202", "advanced": {"videoCodec": 2}, "fileOutputs": [{"fileType": 1, "filepath": "/out/{room_name}.mp4", "disableManifest": true}]}, "file": {"filename": "/out/KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA.mp4", "startedAt": 1717078278969355470, "endedAt": 1717078291079331918, "duration": 12109976448}, "fileResults": [{"filename": "/out/KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA.mp4", "startedAt": 1717078278969355470, "endedAt": 1717078291079331918, "duration": 12109976448}]}, "id": "EV_kUkwkDktYrsK", "createdAt": 1717078291}}

LiveKit-Egress Full Logs

[user@vm-video-rec1 ~]$ docker logs livekit-egress --follow
+ rm -rf '/home/egress/tmp/*'
+ rm -rf /var/run/pulse /var/lib/pulse /home/egress/.config/pulse /home/egress/.cache/xdgr/pulse
+ pulseaudio -D --verbose --exit-idle-time=-1 --disallow-exit
I: [pulseaudio] main.c: Daemon startup successful.
+ exec egress
2024-05-30T14:09:56.244Z        INFO    egress  redis/redis.go:142      connecting to redis     {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "simple": true, "addr": "<omitted>:6379"}
2024-05-30T14:09:56.407Z        INFO    egress  stats/monitor.go:134    cpu available: 4.000000 max cost: 4.000000      {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": ""}
2024-05-30T14:09:56.409Z        INFO    egress  server/server.go:146    service ready   {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": ""}
2024-05-30T14:11:16.490Z        INFO    egress  server/server_rpc.go:54 request received        {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "egressID": "EG_vcdswtZvuX8y"}
2024-05-30T14:11:16.496Z        INFO    egress  server/server_rpc.go:71 request validated       {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "requestType": "participant", "outputType": "file", "room": "KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA", "request": {"Participant":{"room_name":"KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA","identity":"<omitted>","Options":{"Advanced":{"video_codec":2}},"file_outputs":[{"file_type":1,"filepath":"/out/{room_name}.mp4","disable_manifest":true,"Output":null}]}}}
2024-05-30T14:11:16.537Z        INFO    egress  redis/redis.go:142      connecting to redis     {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "simple": true, "addr": "<omitted>:6379"}
2024-05-30T14:11:17.651Z        INFO    egress  source/sdk.go:341       subscribing to track    {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "trackID": "TR_VCbWRHuFi9eZBy"}
0:00:01.088052926    31 0x55c7b03cbd40 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:01.088131540    31 0x55c7b03cbd40 WARN                 nvcodec plugin.c:94:plugin_init: Failed to load cuda library
2024-05-30T14:11:17.816Z        INFO    logger/logger.go:310    track subscribed        {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "participant": "+41991112202", "track": "TR_VCbWRHuFi9eZBy", "kind": "video"}
0:00:01.989279894    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x120000: 'AVR (Audio Visual Research)' is not mapped
0:00:01.989326759    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x180000: 'CAF (Apple Core Audio File)' is not mapped
0:00:01.989350346    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x100000: 'HTK (HMM Tool Kit)' is not mapped
0:00:01.989366903    31 0x55c7b03cbd40 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:01.989380824    31 0x55c7b03cbd40 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:01.989393056    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x210000: 'MPC (Akai MPC 2k)' is not mapped
0:00:01.989407635    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x230000: 'MPEG-1/2 Audio' is not mapped
0:00:01.989424315    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0xe0000: 'PVF (Portable Voice Format)' is not mapped
0:00:01.989439202    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x160000: 'SD2 (Sound Designer II)' is not mapped
0:00:01.989460429    31 0x55c7b03cbd40 WARN                 default gstsfelement.c:97:gst_sf_create_audio_template_caps: format 0x190000: 'WVE (Psion Series 3)' is not mapped
2024-05-30T14:11:18.985Z        INFO    egress  pipeline/watch.go:240   TR_VCbWRHuFi9eZBy playing       {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y"}
2024-05-30T14:11:19.189Z        INFO    egress  pipeline/watch.go:235   pipeline playing        {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y"}
2024-05-30T14:11:19.200Z        INFO    egress  service/io.go:75        egress updated  {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "requestType": "participant", "outputType": "file", "status": "EGRESS_ACTIVE"}
2024-05-30T14:11:31.075Z        INFO    egress  sdk/appwriter.go:240    writer finished {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "trackID": "TR_VCbWRHuFi9eZBy", "kind": "video", "sampleDuration": "40.333333ms", "avgDrift": "65.846µs", "maxDrift": "406.37µs", "packetLoss": "0.00%"}
2024-05-30T14:11:31.075Z        INFO    logger/logger.go:310    server initiated leave  {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "reason": "ROOM_DELETED", "canReconnect": false}
2024-05-30T14:11:31.075Z        WARN    egress  source/sdk.go:592       disconnected from room  {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y"}
2024-05-30T14:11:31.079Z        INFO    egress  service/io.go:75        egress updated  {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "requestType": "participant", "outputType": "file", "status": "EGRESS_ENDING"}
2024-05-30T14:11:31.175Z        INFO    egress  pipeline/watch.go:123   EOS received    {"nodeID": "NE_CdYkuoUAzzvi", "handlerID": "EGH_K2RjYNEwNAZa", "clusterID": "", "egressID": "EG_vcdswtZvuX8y"}
2024-05-30T14:11:31.191Z        WARN    egress  service/io.go:63        egress failed   {"nodeID": "NE_CdYkuoUAzzvi", "clusterID": "", "egressID": "EG_vcdswtZvuX8y", "requestType": "participant", "outputType": "file", "error": "stat /out/KAZWKwQ9VFIwFBxETQteEBVGAVJGURIGWRh6dm0RUFpBShkWDg1KQUA.mp4: no such file or directory"}

Config Egress:

logging:
    level: info

api_key: <omitted>
api_secret: <omitted> 
ws_url: wss://<omitted>h:443

redis:
    address: <omitted>:6379
    username: ""
    password: "<omitted>"
    db: 0
    use_tls: true

    sentinel_master_name: ""
    sentinel_username: ""
    sentinel_password: ""
    sentinel_addresses: []
    cluster_addresses: []
    max_redirects: null
Nitschi commented 3 months ago

It's probably another component interfering and removing the file mid-stream. Closing for now

Nitschi commented 3 months ago

Confirmed, it was the other component