extremely long delay before uploaded segment gets transcoded

[iameli]

TLDR: There's some kind of pause ~120s after a segment gets uploaded before it gets processed. Full logs here but pertinent log lines are like... segment gets pushed and authWebhookUrl fires:

I0708 19:30:28.104708       1 mediaserver.go:766] Got push request at url=http://lax.livepeer.monster/live/REDACTED/5.ts ua=curl/7.64.1 addr=10.42.2.11:57448 bytes=4338100 dur=8333 resolution=
I0708 19:30:28.567497       1 mediaserver.go:361] Stream authentication for url=http://lax.livepeer.monster/live/REDACTED/5.ts dur=462.536095ms

Then it refreshes its O list, no problems there, but then it stops for a while - we get to ProcessingSegment and "segment emerged":

I0708 19:30:29.310873       1 broadcast.go:378] Processing segment nonce=4248943909422663 manifestID=REDACTED seqNo=5 dur=8.333 bytes=4338100
I0708 19:30:29.310896       1 census.go:993] Logging SegmentEmerged... nonce=4248943909422663 seqNo=5 duration=8.333

Then nothing happens for 12 seconds, until we log a LostSegment error:

E0708 19:30:40.797322       1 census.go:914] LostSegment nonce=4248943909422663 seqNo=5 emerged=11.486376843ss ago

Watchdog reset:

I0708 19:31:23.311168       1 mediaserver.go:906] watchdog reset manifestID=REDACTED seq=5 dur=8333 started=2021-07-08 19:30:28.104779269 +0000 UTC m=+1967.392174778

Then lpms_is_bypass_needed happens and we proceed with the transcode:

E0708 19:31:54.150928       1 ffmpeg.go:112] Error sending data to lpms_is_bypass_needed function err=write |1: broken pipe
I0708 19:31:54.151128       1 census.go:1014] Logging SourceSegmentAppeared... nonce=4248943909422663 manifestID=REDACTED seqNo=5 profile=source
I0708 19:31:54.151826       1 broadcast.go:521] Trying to transcode segment manifestID=REDACTED nonce=4248943909422663 seqNo=5
I0708 19:31:54.180970       1 segment_rpc.go:449] Submitting segment nonce=4248943909422663 manifestID=REDACTED sessionID=c25e2cc9 seqNo=5 bytes=4338100 orch=https://ord-staging-livepeer-orchestrator-1.livepeer.monster:443 timeout=33.332s
I0708 19:31:54.816871       1 segment_rpc.go:484] Uploaded segment nonce=4248943909422663 manifestID=REDACTED sessionID=c25e2cc9 seqNo=5 orch=https://ord-staging-livepeer-orchestrator-1.livepeer.monster:443 dur=635.837776ms
I0708 19:31:54.816943       1 census.go:1040] Logging SegmentUploaded... nonce=4248943909422663 seqNo=5 dur=635.837776ms
I0708 19:31:55.442705       1 census.go:1132] Logging SegmentTranscode nonce=4248943909422663 seqNo=5 dur=625.796207ms
I0708 19:31:55.442788       1 segment_rpc.go:565] Successfully transcoded segment nonce=4248943909422663 manifestID=REDACTED sessionID=c25e2cc9 segName= seqNo=5 orch=https://ord-staging-livepeer-orchestrator-1.livepeer.monster:443 dur=625.796207ms

And after that we're done within two seconds:

I0708 19:31:56.679800       1 mediaserver.go:872] Finished push request at url=http://lax.livepeer.monster/live/REDACTED/5.ts ua=curl/7.64.1 addr=10.42.2.11:57448 len=4338100 dur=8333 resolution= took=1m28.575001194s

[iameli]

Segment causing problems: 4.ts.zip