Skip to content

Shutting down the pipeline (packager->relay->playout) still gives errors #100

@jackjansen

Description

@jackjansen

Tested with command

Here is the last bit of the output, from when we start to shutdown the pipeline from the sender side.

encoder: stopping thread
lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] Pipeline: asked to flush and exit.

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] Pipeline: waiting for completion

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] Pipeline: condition (remaining: 4) (4 modules in the pipeline)

encoder: thread stopped
lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [2] Pipeline: flushing...

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [2] Pipeline: flushed

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] Pipeline: condition (remaining: 3) (4 modules in the pipeline)

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] notify end-of-stream.

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] Pipeline: flushing...

lldash_packager: asynchronous warning: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] Computed duration is inferior or equal to zero (0). Inferring to 100

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] Segment [in memory] completed (size 8) (startsWithSAP=1)

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] Pipeline: flushed

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Continue transfer (14058 bytes) for URL: "http://127.0.0.1:9000/v_0_0x0/v_0_0x0-1.m4s"

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] Pipeline: condition (remaining: 2) (4 modules in the pipeline)

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Continue transfer (8 bytes) for URL: "http://127.0.0.1:9000/v_0_0x0/v_0_0x0-1.m4s"

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Ending transfer for URL: "http://127.0.0.1:9000/v_0_0x0/v_0_0x0-1.m4s"

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash-relay: t=2025-11-17T11:27:25.337 event=resource_chunk_received url=/v_0_0x0/v_0_0x0-1.m4s chunk_size=14058
lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Processes segment (total processed: 16.000000s)
lldash-relay: t=2025-11-17T11:27:25.337 
event=resource_chunk_received url=/v_0_0x0/v_0_0x0-1.m4s chunk_size=8
lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] notify end-of-stream.

lldash-relay: t=2025-11-17T11:27:25.337 event=chunk_sent url=/v_0_0x0/v_0_0x0-1.m4s chunk_size=14058
lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Pipeline: flushing...
lldash-relay: t=2025-11-17T11:27:25.337 
event=resource_created url=/v_0_0x0/v_0_0x0-1.m4s
lldash-relay: t=2025-11-17T11:27:25.337 event=chunk_sent url=/v_0_0x0/v_0_0x0-1.m4s chunk_size=8
lldash-relay: t=2025-11-17T11:27:25.337 event=request_completed method=GET url=/v_0_0x0/v_0_0x0-1.m4s status=200
lldash-relay: t=2025-11-17T11:27:25.337 event=connection_closed reason=client_closed
lldash-relay: t=2025-11-17T11:27:25.337 event=request_completed method=PUT url=/v_0_0x0/v_0_0x0-1.m4s status=200
lldash-relay: t=2025-11-17T11:27:25.337 lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Manifest was not rewritten for on-demand and all files are being deleted.
event=connection_closed reason=client_closed

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Pipeline: flushed

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] Pipeline: condition (remaining: 1) (4 modules in the pipeline)

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] Output: metadata not equal but comparable by value. Updating.

lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-2.m4s'

lldash-relay: t=2025-11-17T11:27:25.338 event=request_received method=GET url=/v_0_0x0/v_0_0x0-2.m4s version=HTTP/1.1
lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Starting transfer to URL: "http://127.0.0.1:9000/v_0_0x0/v_0_0x0-2.m4s"

lldash_play: read: lldplay_grab_frame(handle, 0, ptr, 13926, None)
netdecoder: decoded pointcloud with 14743 points, qlen=1
lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Continue transfer (8 bytes) for URL: "http://127.0.0.1:9000/v_0_0x0/v_0_0x0-2.m4s"

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Starting transfer to URL: "http://127.0.0.1:9000/lldash_testlatency.mpd"

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Continue transfer (989 bytes) for URL: "http://127.0.0.1:9000/lldash_testlatency.mpd"

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Ending transfer for URL: "http://127.0.0.1:9000/lldash_testlatency.mpd"

lldash-relay: t=2025-11-17T11:27:25.346 event=request_received method=PUT url=/v_0_0x0/v_0_0x0-2.m4s
lldash-relay: t=2025-11-17T11:27:25.347 event=resource_chunk_received url=/v_0_0x0/v_0_0x0-2.m4s chunk_size=24
lldash-relay: t=2025-11-17T11:27:25.347 event=request_received method=PUT url=/lldash_testlatency.mpd
lldash-relay: t=2025-11-17T11:27:25.347 event=resource_chunk_received url=/lldash_testlatency.mpd chunk_size=989
lldash-relay: t=2025-11-17T11:27:25.347 event=resource_created url=/lldash_testlatency.mpd
lldash-relay: t=2025-11-17T11:27:25.347 event=request_completed method=PUT url=/lldash_testlatency.mpd status=200
lldash-relay: t=2025-11-17T11:27:25.347 event=connection_closed reason=client_closed
lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] notify end-of-stream.

lldash_packager: asynchronous debug message: [lldpkg::lldash_testlatency] [HttpSink (#1)] notify end-of-stream.

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Pipeline: flushing...

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Pipeline: flushed

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] Pipeline: completed

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] Pipeline: destroy

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [GPACMuxMP4 (#3)] Pipeline: destroy

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [2] Pipeline: destroy

lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [HttpSink (#1)] Pipeline: destroy

lldash-relay: t=2025-11-17T11:27:25.352 event=resource_created url=/v_0_0x0/v_0_0x0-2.m4s
lldash-relay: t=2025-11-17T11:27:25.352 event=request_completed method=PUT url=/v_0_0x0/v_0_0x0-2.m4s status=200
lldash-relay: t=2025-11-17T11:27:25.352 event=connection_closed reason=client_closed
lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Pipeline: destroy

testlatency: Sender finished with exit status: 0
testlatency: sender thread finished
lldash-relay: t=2025-11-17T11:27:25.443 event=resource_appeared url=/v_0_0x0/v_0_0x0-2.m4s waited_ms=100
lldash-relay: t=2025-11-17T11:27:25.443 event=resource_served url=/v_0_0x0/v_0_0x0-2.m4s
lldash-relay: t=2025-11-17T11:27:25.443 event=chunk_sent url=/v_0_0x0/v_0_0x0-2.m4s chunk_size=24
lldash-relay: t=2025-11-17T11:27:25.443 event=request_completed method=GET url=/v_0_0x0/v_0_0x0-2.m4s status=200
lldash-relay: t=2025-11-17T11:27:25.443 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:25.443 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
lldash-relay: t=2025-11-17T11:27:27.525 event=error_reply method=GET url=/v_0_0x0/v_0_0x0-3.m4s status=404 reason=not_found
lldash-relay: t=2025-11-17T11:27:27.525 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:27.526 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
lldash-relay: t=2025-11-17T11:27:29.601 event=error_reply method=GET url=/v_0_0x0/v_0_0x0-3.m4s status=404 reason=not_found
lldash-relay: t=2025-11-17T11:27:29.601 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:29.602 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
lldash-relay: t=2025-11-17T11:27:31.674 event=error_reply method=GET url=/v_0_0x0/v_0_0x0-3.m4s status=404 reason=not_found
lldash-relay: t=2025-11-17T11:27:31.674 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:31.674 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
lldash-relay: t=2025-11-17T11:27:33.752 event=error_reply method=GET url=/v_0_0x0/v_0_0x0-3.m4s status=404 reason=not_found
lldash-relay: t=2025-11-17T11:27:33.753 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:33.753 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
lldash_play: nothing received for 10 seconds, assuming end of file
lldash_play: thread exiting
netdecoder: source.get returned no data
netdecoder: thread exiting
lldash-relay: t=2025-11-17T11:27:35.829 event=error_reply method=GET url=/v_0_0x0/v_0_0x0-3.m4s status=404 reason=not_found
lldash-relay: t=2025-11-17T11:27:35.829 event=connection_closed reason=client_closed
lldash_play: asynchronous debug message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] wget: 'http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s'

lldash-relay: t=2025-11-17T11:27:35.830 event=request_received method=GET url=/v_0_0x0/v_0_0x0-3.m4s version=HTTP/1.1
netdecoder: stop
testlatency: receiver thread finished
testlatency: Stopping server thread...
testlatency: server thread finished
testlatency: count_total=98, count_lost_initial=0, count_lost_running=1, latency_ignored_count=4, latency_min=0.120, latency_max=0.332, latency_avg=0.216, latency_stddev=0.037
testlatency: Latency test passed.
lldash_play: calling lldplay_destroy()
lldash_play: asynchronous error: [lldplay::cwipc_lldplay] [lldplay_disable_stream] exception caught:failure HTTP download failed (url="http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s"): Server returned nothing (no headers, no data)


lldash_play: asynchronous info message: [lldplay::cwipc_lldplay] Pipeline: destroy

lldash_play: asynchronous info message: [lldplay::cwipc_lldplay] [stream #0] Pipeline: destroy

lldash_play: asynchronous info message: [lldplay::cwipc_lldplay] [DashDemuxer (#0)] Pipeline: destroy

lldash_play: lldplay_destroy() returned
((.venv) ) boor:lldash jack$ 

First thing I notice is the line

ldash-relay: t=2025-11-17T11:27:25.337 lldash_packager: asynchronous info message: [lldpkg::lldash_testlatency] [MPEG_DASH (#0)] Manifest was not rewritten for on-demand and all files are being deleted.

Double-checked, and I am calling lldpkg_destroy() with flush=true.

Just after t=2025-11-17T11:27:25.352 my sender thread exits, so we can be sure that lldpkg_destroy() has returned. The last resource that was pushed just before this was the small one to url=/v_0_0x0/v_0_0x0-2.m4s.

It is subsequently passed to the receiver at t=2025-11-17T11:27:25.443.

Now we get to the "end game" with the receiver asking for url=/v_0_0x0/v_0_0x0-3.m4s which doesn't exist every 2 seconds, after which it gives up.

The Python code now closes the lldplay side, and during lldplay_destroy() we get a spurious error message

lldash_play: asynchronous error: [lldplay::cwipc_lldplay] [lldplay_disable_stream] exception caught:failure HTTP download failed (url="http://127.0.0.1:9000/v_0_0x0/v_0_0x0-3.m4s"): Server returned nothing (no headers, no data)

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions