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

When stopEgress, report "pipeline frozen" #158

Closed shentianyu93 closed 1 year ago

shentianyu93 commented 2 years ago

Describe the Issue When I use stopEgress api, report "pipeline frozen"

Detail log:

2022-10-15T04:24:03.399356008Z {"level":"debug","ts":1665807843.3717582,"logger":"egress","caller":"service/handler.go:80","msg":"handling request","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","requestID":"RPC_jcUadiSuK4wk"} 2022-10-15T04:24:03.399449155Z {"level":"info","ts":1665807843.3959792,"logger":"egress","caller":"service/handler.go:128","msg":"egress updated","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","status":"EGRESS_ENDING"} 2022-10-15T04:24:03.413872294Z {"level":"debug","ts":1665807843.400598,"logger":"egress","caller":"sdk/appwriter.go:505","msg":"draining","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","trackID":"TR_AMiBfGVtjEppCa","kind":"audio"} 2022-10-15T04:24:03.414205856Z {"level":"debug","ts":1665807843.4014,"logger":"egress","caller":"service/handler.go:146","msg":"request handled","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","requestID":"RPC_jcUadiSuK4wk","senderID":"ND_PUqFna5f"} 2022-10-15T04:24:03.414225330Z {"level":"debug","ts":1665807843.4023511,"logger":"egress","caller":"pipeline/pipeline.go:466","msg":"sending EOS to pipeline","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:03.414238792Z {"level":"debug","ts":1665807843.4024138,"logger":"egress","caller":"sdk/appwriter.go:505","msg":"draining","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","trackID":"TR_VCy8b3Gq2ABk2m","kind":"video"} 2022-10-15T04:24:03.414251863Z {"level":"debug","ts":1665807843.4024372,"logger":"egress","caller":"sdk/appwriter.go:512","msg":"draining show data","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","trackID":"TR_VCy8b3Gq2ABk2m","kind":"video","startTime":1665807749604602990,"endTime":1665807843402394514,"delay":88849} 2022-10-15T04:24:03.414265474Z {"level":"debug","ts":1665807843.4029996,"logger":"egress","caller":"sdk/appwriter.go:505","msg":"draining","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","trackID":"TR_AMfW5HWLm9zU4v","kind":"audio"} 2022-10-15T04:24:03.414278417Z {"level":"debug","ts":1665807843.4030902,"logger":"egress","caller":"sdk/appwriter.go:512","msg":"draining show data","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","trackID":"TR_AMfW5HWLm9zU4v","kind":"audio","startTime":1665807749604602990,"endTime":1665807843402394514,"delay":88849} 2022-10-15T04:24:03.430030514Z {"level":"debug","ts":1665807843.4007235,"logger":"egress","caller":"sdk/appwriter.go:512","msg":"draining show data","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","trackID":"TR_AMiBfGVtjEppCa","kind":"audio","startTime":1665807749648765494,"endTime":0,"delay":364349} 2022-10-15T04:24:03.430122921Z {"level":"debug","ts":1665807843.4256253,"logger":"egress","caller":"service/handler.go:80","msg":"handling request","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","requestID":"RPC_uyz5hswuvGCN"} 2022-10-15T04:24:03.430139606Z {"level":"debug","ts":1665807843.4257643,"logger":"egress","caller":"sdk/appwriter.go:505","msg":"draining","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","trackID":"TR_VCL9qh4k8Z8xFT","kind":"video"} 2022-10-15T04:24:03.430153464Z {"level":"debug","ts":1665807843.4257987,"logger":"egress","caller":"sdk/appwriter.go:512","msg":"draining show data","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","trackID":"TR_VCL9qh4k8Z8xFT","kind":"video","startTime":1665807749648765494,"endTime":0,"delay":364349} 2022-10-15T04:24:03.430167049Z {"level":"info","ts":1665807843.4257927,"logger":"egress","caller":"service/handler.go:128","msg":"egress updated","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","status":"EGRESS_ENDING"} 2022-10-15T04:24:03.430180317Z {"level":"debug","ts":1665807843.4278357,"logger":"egress","caller":"service/handler.go:146","msg":"request handled","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","requestID":"RPC_uyz5hswuvGCN","senderID":"ND_PUqFna5f"} 2022-10-15T04:24:03.430193375Z {"level":"debug","ts":1665807843.4283607,"logger":"egress","caller":"pipeline/pipeline.go:466","msg":"sending EOS to pipeline","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:03.430206351Z {"level":"debug","ts":1665807843.4290228,"logger":"egress","caller":"sdk/input.go:128","msg":"audio writer finished","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:03.491763410Z {"level":"debug","ts":1665807843.487576,"logger":"egress","caller":"sdk/input.go:136","msg":"video writer finished","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:03.635753595Z {"level":"info","ts":1665807843.6327517,"logger":"egress","caller":"server-sdk-go@v1.0.0/signalclient.go:238","msg":"received offer for subscriber","nodeID":"NE_A3TVuVFZVcyL"} 2022-10-15T04:24:03.635842990Z {"level":"debug","ts":1665807843.6340482,"logger":"egress","caller":"sdk/input.go:136","msg":"video writer finished","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:07.546744128Z {"level":"debug","ts":1665807847.5438342,"logger":"egress","caller":"sdk/input.go:128","msg":"audio writer finished","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:31.350248168Z {"level":"info","ts":1665807871.3496008,"logger":"egress","caller":"stats/monitor.go:142","msg":"high cpu load","nodeID":"NE_VLVwpdqrdLXv","load":99.98770491803279} 2022-10-15T04:24:33.405864025Z {"level":"error","ts":1665807873.4037387,"logger":"egress","caller":"pipeline/pipeline.go:468","msg":"pipeline frozen","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","stacktrace":"github.com/livekit/egress/pkg/pipeline.(Pipeline).SendEOS.func1.1.1\n\t/workspace/pkg/pipeline/pipeline.go:468"} 2022-10-15T04:24:33.409096432Z {"level":"debug","ts":1665807873.406767,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from mp4mux0: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.416997627Z {"level":"debug","ts":1665807873.416202,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src_0] STREAM-STATUS - Stream status from multiqueue0: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.417144922Z {"level":"debug","ts":1665807873.4166791,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src_1] STREAM-STATUS - Stream status from multiqueue0: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.443106502Z {"level":"error","ts":1665807873.4420493,"logger":"egress","caller":"pipeline/pipeline.go:468","msg":"pipeline frozen","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","stacktrace":"github.com/livekit/egress/pkg/pipeline.(Pipeline).SendEOS.func1.1.1\n\t/workspace/pkg/pipeline/pipeline.go:468"} 2022-10-15T04:24:33.448133966Z {"level":"debug","ts":1665807873.4474752,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from mp4mux0: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.452381073Z {"level":"debug","ts":1665807873.45092,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src_0] STREAM-STATUS - Stream status from multiqueue0: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.491883548Z {"level":"debug","ts":1665807873.4892042,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src_1] STREAM-STATUS - Stream status from multiqueue0: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.560884441Z {"level":"debug","ts":1665807873.560232,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":49933333333,\"StreamTime\":49933333333,\"Timestamp\":3600049933333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.568358059Z {"level":"debug","ts":1665807873.565523,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50000000000,\"StreamTime\":50000000000,\"Timestamp\":3600050000000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.568444758Z {"level":"debug","ts":1665807873.5656924,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50166666666,\"StreamTime\":50166666666,\"Timestamp\":3600050166666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.620876896Z {"level":"debug","ts":1665807873.619866,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50100000000,\"StreamTime\":50100000000,\"Timestamp\":3600050100000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.620963198Z {"level":"debug","ts":1665807873.620183,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50066666666,\"StreamTime\":50066666666,\"Timestamp\":3600050066666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.784010056Z {"level":"debug","ts":1665807873.7816818,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50133333333,\"StreamTime\":50133333333,\"Timestamp\":3600050133333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.784099955Z {"level":"debug","ts":1665807873.7818623,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50200000000,\"StreamTime\":50200000000,\"Timestamp\":3600050200000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.806776620Z {"level":"debug","ts":1665807873.804248,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32566666666,\"StreamTime\":32566666666,\"Timestamp\":3600032566666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.811159911Z {"level":"debug","ts":1665807873.8099113,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50333333333,\"StreamTime\":50333333333,\"Timestamp\":3600050333333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.815782233Z {"level":"debug","ts":1665807873.8150344,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32533333333,\"StreamTime\":32533333333,\"Timestamp\":3600032533333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.815842058Z {"level":"debug","ts":1665807873.8153234,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32600000000,\"StreamTime\":32600000000,\"Timestamp\":3600032600000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.853004411Z {"level":"debug","ts":1665807873.8518572,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32766666666,\"StreamTime\":32766666666,\"Timestamp\":3600032766666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:33.986123219Z {"level":"debug","ts":1665807873.9846718,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50266666666,\"StreamTime\":50266666666,\"Timestamp\":3600050266666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.998091536Z {"level":"debug","ts":1665807873.9971309,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50233333333,\"StreamTime\":50233333333,\"Timestamp\":3600050233333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:33.998187185Z {"level":"debug","ts":1665807873.9975362,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50300000000,\"StreamTime\":50300000000,\"Timestamp\":3600050300000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.034946542Z {"level":"debug","ts":1665807874.033164,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50466666666,\"StreamTime\":50466666666,\"Timestamp\":3600050466666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.072888417Z {"level":"debug","ts":1665807874.071892,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32700000000,\"StreamTime\":32700000000,\"Timestamp\":3600032700000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.072988191Z {"level":"debug","ts":1665807874.072209,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32666666666,\"StreamTime\":32666666666,\"Timestamp\":3600032666666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.077373543Z {"level":"debug","ts":1665807874.0751317,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32733333333,\"StreamTime\":32733333333,\"Timestamp\":3600032733333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.097923032Z {"level":"debug","ts":1665807874.0970166,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50400000000,\"StreamTime\":50400000000,\"Timestamp\":3600050400000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.105720890Z {"level":"debug","ts":1665807874.1052663,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50366666666,\"StreamTime\":50366666666,\"Timestamp\":3600050366666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.109517725Z {"level":"debug","ts":1665807874.1093113,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50433333333,\"StreamTime\":50433333333,\"Timestamp\":3600050433333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.109764966Z {"level":"debug","ts":1665807874.1094456,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50600000000,\"StreamTime\":50600000000,\"Timestamp\":3600050600000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.146298641Z {"level":"debug","ts":1665807874.1447618,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32900000000,\"StreamTime\":32900000000,\"Timestamp\":3600032900000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.155979171Z {"level":"debug","ts":1665807874.154044,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32833333333,\"StreamTime\":32833333333,\"Timestamp\":3600032833333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.166901372Z {"level":"debug","ts":1665807874.166427,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32800000000,\"StreamTime\":32800000000,\"Timestamp\":3600032800000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.295688918Z {"level":"debug","ts":1665807874.2594798,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50533333333,\"StreamTime\":50533333333,\"Timestamp\":3600050533333333,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.295783089Z {"level":"debug","ts":1665807874.259829,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32866666666,\"StreamTime\":32866666666,\"Timestamp\":3600032866666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.298753076Z {"level":"debug","ts":1665807874.2959285,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50500000000,\"StreamTime\":50500000000,\"Timestamp\":3600050500000000,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.319720488Z {"level":"debug","ts":1665807874.3186996,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":50566666666,\"StreamTime\":50566666666,\"Timestamp\":3600050566666666,\"Duration\":-1}","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.432744900Z {"level":"debug","ts":1665807874.4314778,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from queue0: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.433712673Z {"level":"debug","ts":1665807874.4325073,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from queue1: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.434009097Z {"level":"debug","ts":1665807874.4337912,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from audioAppSrc: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.444858700Z {"level":"debug","ts":1665807874.4438663,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from videoAppSrc: A thread has left its loop function","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.459876056Z {"level":"debug","ts":1665807874.4594486,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33033333333,\"StreamTime\":33033333333,\"Timestamp\":3600033033333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.489996444Z {"level":"debug","ts":1665807874.488885,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32966666666,\"StreamTime\":32966666666,\"Timestamp\":3600032966666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.496394738Z {"level":"debug","ts":1665807874.495987,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":32933333333,\"StreamTime\":32933333333,\"Timestamp\":3600032933333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.496567088Z {"level":"debug","ts":1665807874.4961376,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33000000000,\"StreamTime\":33000000000,\"Timestamp\":3600033000000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.496804051Z {"level":"debug","ts":1665807874.4962206,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33166666666,\"StreamTime\":33166666666,\"Timestamp\":3600033166666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.538848752Z {"level":"debug","ts":1665807874.5381598,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33100000000,\"StreamTime\":33100000000,\"Timestamp\":3600033100000000,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.541390307Z {"level":"debug","ts":1665807874.5410333,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33066666666,\"StreamTime\":33066666666,\"Timestamp\":3600033066666666,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.541437253Z {"level":"debug","ts":1665807874.541136,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[x264enc0] QOS - {\"Live\":false,\"RunningTime\":33133333333,\"StreamTime\":33133333333,\"Timestamp\":3600033133333333,\"Duration\":-1}","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.629027221Z {"level":"debug","ts":1665807874.6285198,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from queue0: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.629675339Z {"level":"debug","ts":1665807874.6289916,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from queue1: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.629733903Z {"level":"debug","ts":1665807874.6292062,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from audioAppSrc: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.637485866Z {"level":"debug","ts":1665807874.6372833,"logger":"egress","caller":"pipeline/pipeline.go:363","msg":"[src] STREAM-STATUS - Stream status from videoAppSrc: A thread has left its loop function","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.660485410Z {"level":"debug","ts":1665807874.6601262,"logger":"egress","caller":"pipeline/pipeline.go:599","msg":"pipeline stopped","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.704647685Z {"level":"info","ts":1665807874.6715665,"logger":"egress","caller":"service/handler.go:124","msg":"egress failed","nodeID":"NE_A3TVuVFZVcyL","egressID":"EG_MBUx8GYMYqit","error":"pipeline frozen"} 2022-10-15T04:24:34.750801087Z {"level":"debug","ts":1665807874.7503872,"logger":"egress","caller":"service/service.go:267","msg":"deleting handler temporary directory","nodeID":"NE_VLVwpdqrdLXv","path":"/tmp/lkegress/EG_MBUx8GYMYqit"} 2022-10-15T04:24:34.867796916Z {"level":"debug","ts":1665807874.8674388,"logger":"egress","caller":"pipeline/pipeline.go:599","msg":"pipeline stopped","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf"} 2022-10-15T04:24:34.869575144Z {"level":"info","ts":1665807874.868991,"logger":"egress","caller":"service/handler.go:124","msg":"egress failed","nodeID":"NE_kPvongLFqpfC","egressID":"EG_geSxWWZeJksf","error":"pipeline frozen"} 2022-10-15T04:24:34.924819859Z {"level":"debug","ts":1665807874.923875,"logger":"egress","caller":"service/service.go:267","msg":"deleting handler temporary directory","nodeID":"NE_VLVwpdqrdLXv","path":"/tmp/lkegress/EG_geSxWWZeJksf"}

Server Version: docker, livekit/livekit-server:v1.2.3 Version: docker, livekit/livekit-egress:v1.4.4

dathuynh1108 commented 1 year ago

Hello, I have the same problem with your gstreamer pipeline architecture (quite rare). So I added some detailed logs and found that all appsrc called EndStream() but in the message watcher of pipeline bus (messageWatch), it didn't receive the EOS message. So the EOS Timer will force stop the pipeline and log “pipeline frozen” after 30 seconds. It seems to be a bug of gstreamer, isn't it? (It will causes the MP4 file crash because the mp4mux need EOS). In addition, if I don’t force stop pipeline, the file size will increase forever. Thanks!

davidzhao commented 1 year ago

Thanks for the feedback, we'll take a look at this. It's also possible that it's an issue with the Go bindings to GStreamer.

davidzhao commented 1 year ago

Are you still experiencing this with the latest version?

dathuynh1108 commented 1 year ago

Are you still experiencing this with the latest version?

Hello, thanks for your attention to this matter. With the latest version, until now, I have not seen this error appear. However, this error occurs quite rarely so I am not sure if it still exists or not because I have tried but couldn't find the real reason for why the message watcher is not receiving EOS after the entire appsrc has called EndStream, so I can't reproduce it. Did you find the reason of this bug?

davidzhao commented 1 year ago

We've made several fixes around this area. I think the one that's most relevant is #220