Chocobozzz
Tripled transcoding
Describe the current behavior
An user uploaded a video yesterday, 1080px resolution. It ran transcoding for all resolutions three times, except for the upload resolution which only was transcoded once. Only after the first batch of transcodes it was running the move-to-object-storage job, which lead to the video to be broken for the users. A summary of all the jobs, which all was successful according to the states (timestamps are for processed on-finished on):
First batch:
- optimize, 13:11-13:12
- 1080, 15:40-16:18 (Error: Missing lock for job 174 finished)
- audio, 13:49-13:49
- 480, 13:49-14:05
- 360, 14:05-14:19
- 720, 14:19-14:41
- 240, 14:41-14:52
- move-to-object-storage 14:53-14:54
Second batch:
- audio, 16:17-16:20
- 480, 16:39-16:58 (Error: Missing lock for job 182 finished)
- 360, det 16:58-17:13
- 720, 17:34-17:56 (Error: Missing lock for job 184 finished)
- 240, 17:58-18:09
Third batch:
- audio, 18:15-18:16
- 480, 18:32-18:48 (Error: Missing lock for job 189 finished)
- 360, 18:48-19:00
- 720, 19:01-19:22
- 240, 19:33-19:44 (Error: Missing lock for job 192 finished)
In parentheses is the message that's shown under the JSON data in the job. I've seen this message for other jobs, even though they seems to haven't broke the video. I couldn't find any errors in other logs.
Since we've versioned enabled in our bucket we can see that our master.m3u8 and segments-sha256.json has been updated at the following timestamps:
- 14:53:38
- 15:28:50
- 16:16:06
- 16:18:54
- 16:37:46
- 16:56:23
- 17:11:25
- 17:33:49
- 17:55:59
- 18:08:27
- 18:15:25
- 18:31:25
- 18:47:27
- 19:00:18
- 19:22:10
- 19:32:54
- 19:44:02
But neither master och segments-sha256 has been renamed, which I guess It should've done?
Steps to reproduce
No response
Describe the expected behavior
No response
Additional information
- PeerTube instance:
- Version: 4.2.2
- NodeJS version: v16.15.1
- Ffmpeg version: 5.0.1-1+20.04.sav1
Hello and thanks for the detailed information.
Can you also provide logs that contain the video UUID? Can you also provide the creation date of these jobs?
Here's the full information about the jobs:
[
{
"id": "173",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "optimize-to-webtorrent",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f"
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:11:47.726Z",
"finishedOn": "2022-07-07T11:12:42.573Z",
"processedOn": "2022-07-07T11:11:47.730Z"
},
{
"id": "174",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"autoDeleteWebTorrentIfNeeded": true,
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 1080,
"isPortraitMode": false,
"copyCodecs": false,
"isMaxQuality": true,
"hasAudio": true
},
"progress": 100,
"priority": 138,
"error": "Error: Missing lock for job 174 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-07-07T11:12:42.567Z",
"finishedOn": "2022-07-07T14:17:47.944Z",
"processedOn": "2022-07-07T13:40:19.669Z"
},
{
"id": "175",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 0,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:48:46.706Z",
"finishedOn": "2022-07-07T11:49:13.055Z",
"processedOn": "2022-07-07T11:48:51.781Z"
},
{
"id": "176",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 480,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:48:46.715Z",
"finishedOn": "2022-07-07T12:05:46.476Z",
"processedOn": "2022-07-07T11:49:13.055Z"
},
{
"id": "177",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 360,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:48:46.726Z",
"finishedOn": "2022-07-07T12:19:07.187Z",
"processedOn": "2022-07-07T12:05:46.476Z"
},
{
"id": "178",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 720,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:48:46.733Z",
"finishedOn": "2022-07-07T12:41:18.556Z",
"processedOn": "2022-07-07T12:19:07.187Z"
},
{
"id": "179",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 240,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 138,
"error": null,
"createdAt": "2022-07-07T11:48:46.747Z",
"finishedOn": "2022-07-07T12:52:50.322Z",
"processedOn": "2022-07-07T12:41:18.556Z"
},
{
"id": "181",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 0,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 139,
"error": null,
"createdAt": "2022-07-07T13:30:04.875Z",
"finishedOn": "2022-07-07T14:20:26.705Z",
"processedOn": "2022-07-07T14:17:47.944Z"
},
{
"id": "182",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 480,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 139,
"error": "Error: Missing lock for job 182 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-07-07T13:30:04.888Z",
"finishedOn": "2022-07-07T14:57:34.199Z",
"processedOn": "2022-07-07T14:38:59.195Z"
},
{
"id": "183",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 360,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 139,
"error": null,
"createdAt": "2022-07-07T13:30:04.911Z",
"finishedOn": "2022-07-07T15:12:28.999Z",
"processedOn": "2022-07-07T14:57:34.199Z"
},
{
"id": "184",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 720,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 139,
"error": "Error: Missing lock for job 184 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-07-07T13:30:04.924Z",
"finishedOn": "2022-07-07T15:56:23.264Z",
"processedOn": "2022-07-07T15:34:16.216Z"
},
{
"id": "185",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 240,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 139,
"error": null,
"createdAt": "2022-07-07T13:30:04.932Z",
"finishedOn": "2022-07-07T16:08:43.804Z",
"processedOn": "2022-07-07T15:57:40.676Z"
},
{
"id": "188",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 0,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 140,
"error": null,
"createdAt": "2022-07-07T14:17:47.860Z",
"finishedOn": "2022-07-07T16:15:43.064Z",
"processedOn": "2022-07-07T16:15:10.785Z"
},
{
"id": "189",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 480,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 140,
"error": "Error: Missing lock for job 189 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-07-07T14:17:47.870Z",
"finishedOn": "2022-07-07T16:47:43.474Z",
"processedOn": "2022-07-07T16:31:47.862Z"
},
{
"id": "190",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 360,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 140,
"error": null,
"createdAt": "2022-07-07T14:17:47.877Z",
"finishedOn": "2022-07-07T17:00:36.338Z",
"processedOn": "2022-07-07T16:47:43.474Z"
},
{
"id": "191",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 720,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 140,
"error": null,
"createdAt": "2022-07-07T14:17:47.887Z",
"finishedOn": "2022-07-07T17:22:26.485Z",
"processedOn": "2022-07-07T17:00:36.338Z"
},
{
"id": "192",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "0723eff8-e93e-4567-b645-17db0437878f",
"resolution": 240,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 140,
"error": "Error: Missing lock for job 192 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-07-07T14:17:47.912Z",
"finishedOn": "2022-07-07T17:44:20.576Z",
"processedOn": "2022-07-07T17:33:15.055Z"
}
]
Did you have high CPU usage between 2022-07-07T13:40:19.669Z and 2022-07-07T14:17:47.944Z? (or during other failed job)
I'm sorry but I can't see if that where the case. May the high CPU usage be the cause of the tripled jobs?
Yes, I think the root cause is Missing lock for job error. It means that Bull did not manage to extend the lock key when the job was processed. It can happens when the node event loop has too much work, so Bull doesn't have the opportunity do reassign the lock.
Okay. We've a separate server where redis is running, is it that server that needs more CPU? Is it possible to retry later if Missing lock for job is thrown? Because it seems that the transcoding worked as expected.
is it that server that needs more CPU
No, it's the peertube one. But it should not happen. We need to find what happened on peertube side to understand why the event loop was so busy.
May be related to this:
Yesterday we found that a video transcoded 18th July didn't work for resolution 240 and 720. The playlists for each resolution returned 404. When looking in the s3 version history we couldn't find the files there either. So we started a new HLS transcoding for the video. After the transcoding was done the samme issue persisted; 240 och 720 playlists returned 404. But surprisingly the old resolution playlists (which was referred to in the original master playlist) had been created.
So the issue was solved by:
- Do a manual HLS transcoding
- Restore the segments file and master.m3u8 generated after the "original" transcoding
May be related to this:
Yesterday we found that a video transcoded 18th July didn't work for resolution 240 and 720. The playlists for each resolution returned 404. When looking in the s3 version history we couldn't find the files there either. So we started a new HLS transcoding for the video. After the transcoding was done the samme issue persisted; 240 och 720 playlists returned 404. But surprisingly the old resolution playlists (which was referred to in the original master playlist) had been created.
So the issue was solved by:
- Do a manual HLS transcoding
- Restore the segments file and master.m3u8 generated after the "original" transcoding
This has happened to a lot of videos since last upgrade. It seems to be related to "Missing lock for job" message, since for every broken video we try to retranscode at least one video-transcoding job will put the "Missing lock for job" message.
Now we've some more graphs to look at.
Job: 438
Type: video-transcoding
Processed on Jul 21, 2022, 8:35:40 PM
Finished on Jul 21, 2022, 8:49:37 PM
--
{
"type": "new-resolution-to-hls",
"videoUUID": "ed476745-dba3-4e06-91e3-ead51a174739",
"resolution": 240,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isNewVideo": false,
"autoDeleteWebTorrentIfNeeded": false,
"isMaxQuality": false
}
Error: Missing lock for job 438 finished
Regarding the last graph there's peaks around 19.35 and 21.35, but not 20.35.
No, I don't know what happened. Redis is only used for PeerTube, so it's PT related. There hasn't been any peaks like that since then, we'll run some transcoding later to see if there will be peaks again.
Case study
Here's a case study for one video which where broken, not sure if was related to original topic, but probably.
Initial transcoding
During initial transcoding three versions of master playlist where uploaded.
Uploaded July 15, 2022, 21:23:04 (UTC+02:00):
#EXTM3U
#EXT-X-VERSION:3
#EXT-X-STREAM-INF:BANDWIDTH=1717480,RESOLUTION=1920x1080,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
f9d96666-dac6-4202-835c-3478da4ddb1d-1080.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=319221,RESOLUTION=0x0,CODECS="mp4a.40.2"
054b477b-607f-4685-b297-c02958592774-0.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=754208,RESOLUTION=854x480,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
dc4f188d-3056-482a-8dc5-6433396a3434-480.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=604158,RESOLUTION=640x360,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
ca431fa0-fb55-4806-b675-93b945cd454c-360.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=1083674,RESOLUTION=1280x720,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
350d0bd1-b0a5-42d0-a3d9-6a2e21cdcfe7-720.m3u8
Uploaded July 15, 2022, 21:31:27 (UTC+02:00):
#EXTM3U
#EXT-X-VERSION:3
#EXT-X-STREAM-INF:BANDWIDTH=1717480,RESOLUTION=1920x1080,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
f9d96666-dac6-4202-835c-3478da4ddb1d-1080.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=604158,RESOLUTION=640x360,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
ca431fa0-fb55-4806-b675-93b945cd454c-360.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=319221,RESOLUTION=0x0,CODECS="mp4a.40.2"
054b477b-607f-4685-b297-c02958592774-0.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=754208,RESOLUTION=854x480,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
dc4f188d-3056-482a-8dc5-6433396a3434-480.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=1083674,RESOLUTION=1280x720,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
350d0bd1-b0a5-42d0-a3d9-6a2e21cdcfe7-720.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=470323,RESOLUTION=426x240,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
ff23cfc9-3be1-4da0-8c53-987cdbcf9bc2-240.m3u8
Uploaded July 15, 2022, 21:42:23 (UTC+02:00):
#EXTM3U
#EXT-X-VERSION:3
#EXT-X-STREAM-INF:BANDWIDTH=1717480,RESOLUTION=1920x1080,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
f9d96666-dac6-4202-835c-3478da4ddb1d-1080.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=604158,RESOLUTION=640x360,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
ca431fa0-fb55-4806-b675-93b945cd454c-360.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=319221,RESOLUTION=0x0,CODECS="mp4a.40.2"
054b477b-607f-4685-b297-c02958592774-0.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=754208,RESOLUTION=854x480,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
dc4f188d-3056-482a-8dc5-6433396a3434-480.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=1083674,RESOLUTION=1280x720,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
350d0bd1-b0a5-42d0-a3d9-6a2e21cdcfe7-720.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=470321,RESOLUTION=426x240,FRAME-RATE=25,CODECS="avc1.64001f,mp4a.40.2"
1210e1bb-1398-4542-9d91-69835ecb4424-240.m3u8
Three versions of segments-sha256 uploaded at the following times:
- July 15, 2022, 21:23:04 (UTC+02:00)
- July 15, 2022, 21:32:24 (UTC+02:00)
- July 15, 2022, 21:43:13 (UTC+02:00)
Resolution files only has one version:
- 054b477b-607f-4685-b297-c02958592774-0, July 15, 2022, 21:22:45 (UTC+02:00)
- ca431fa0-fb55-4806-b675-93b945cd454c-360, July 15, 2022, 21:22:53 (UTC+02:00)
- dc4f188d-3056-482a-8dc5-6433396a3434-480, July 15, 2022, 21:22:48 (UTC+02:00)
- 350d0bd1-b0a5-42d0-a3d9-6a2e21cdcfe7-720, July 15, 2022, 21:22:57 (UTC+02:00)
- f9d96666-dac6-4202-835c-3478da4ddb1d-1080, July 15, 2022, 21:22:35 (UTC+02:00)
Resolution files for 240 is missing.
Summary
The first playlist, which was uploaded direct after the video files where uploaded, contains accurate "links" to the playlists, but is missing the 240 resolution. The two other playlists has a link to the 240 resolution, but the file is missing.
Second transcoding
After that I created a new transcoding for the video, which resulted in the following jobs:
- 0 - Failed due to ffprobe:
/var/www/peertube/storage/streaming-playlists/hls/ce688ab0-a1c0-41bd-92be-5c6c3e23d141/1210e1bb-1398-4542-9d91-69835ecb4424-240-fragmented.mp4: No such file or directory - 480 - Failed due to ffprobe:
/var/www/peertube/storage/streaming-playlists/hls/ce688ab0-a1c0-41bd-92be-5c6c3e23d141/1210e1bb-1398-4542-9d91-69835ecb4424-240-fragmented.mp4: No such file or directory - 360 - Failed due to ffprobe:
/var/www/peertube/storage/streaming-playlists/hls/ce688ab0-a1c0-41bd-92be-5c6c3e23d141/1210e1bb-1398-4542-9d91-69835ecb4424-240-fragmented.mp4: No such file or directory - 720 - Failed due to ffprobe:
/var/www/peertube/storage/streaming-playlists/hls/ce688ab0-a1c0-41bd-92be-5c6c3e23d141/1210e1bb-1398-4542-9d91-69835ecb4424-240-fragmented.mp4: No such file or directory - 240 - Completed
- 1080 - Completed, but with
Error: Missing lock for job 463 finished
No video files or playlists where uploaded. The following times where master and segments file uploaded:
- July 24, 2022, 15:25:21 (UTC+02:00)
- July 24, 2022, 15:54:40 (UTC+02:00)
- July 24, 2022, 16:23:15 (UTC+02:00)
The last transcoding job ended 16:23:28 (according to the web server, the time may differ a bit from the S3).
Summary
It looks strange that the 240 resolution is needed for transcoding +360 resolutions. No files where created, even though 1-2 jobs succeeded, and the move-to-object-storage job succeeded.
Sum up
Before I think I've seen jobs that has been re-ran, i.e. once they're 100% the start over again. It looks that what might has happened here as well, according to the timestamps for the two latter playlists for each transcoding "phase".
When I look in the monitoring logs I can't see any suspicious around the time for the second transcoding.
This is still happening for ~30% of our videos. A typical scenario is that 240p (I think every time it's 240p, sometimes also 720p) resolution m3u8 and mp4 files are missing. When looking into S3 versions there's two versions with master playlist and segments files:
- The first versions are created near after the 240p transcoding job started (40 seconds later processedOn in the latest scenario) and they doesn't contain references to the 240p resolution.
- The second version are created ~5 minutes later and does contain references to the 240p resolution, but there's no 240p resolution files. Meaning a 404 for the users.
In this latest case I also checked the jobs, and there's a Missing lock error, but it's on the 480p resolution, which was finished 25 minutes before 240p resolution job was processed.
{
"id": "1328",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 240,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T13:00:04.066Z",
"finishedOn": "2022-09-07T13:54:47.416Z",
"processedOn": "2022-09-07T13:46:43.638Z"
},
{
"id": "1327",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 720,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T13:00:04.057Z",
"finishedOn": "2022-09-07T13:46:43.638Z",
"processedOn": "2022-09-07T13:29:36.642Z"
},
{
"id": "1326",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 360,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T13:00:04.044Z",
"finishedOn": "2022-09-07T13:29:36.642Z",
"processedOn": "2022-09-07T13:21:40.745Z"
},
{
"id": "1325",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 480,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 122,
"error": "Error: Missing lock for job 1325 finished\n at Object.finishedErrors (/var/www/peertube/versions/peertube-v4.2.2-c3/node_modules/bull/lib/scripts.js:219:16)\n at /var/www/peertube/versions/peertube-v4.2.2-c3/node_modules/bull/lib/scripts.js:206:23\n at runMicrotasks (<anonymous>)\n at processTicksAndRejections (node:internal/process/task_queues:96:5)",
"createdAt": "2022-09-07T13:00:04.036Z",
"finishedOn": "2022-09-07T13:21:40.745Z",
"processedOn": "2022-09-07T13:11:03.976Z"
},
{
"id": "1324",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 0,
"isPortraitMode": false,
"hasAudio": true,
"copyCodecs": false,
"isMaxQuality": false,
"autoDeleteWebTorrentIfNeeded": true,
"isNewVideo": true
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T13:00:04.028Z",
"finishedOn": "2022-09-07T13:00:17.194Z",
"processedOn": "2022-09-07T13:00:04.094Z"
},
{
"id": "1323",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "new-resolution-to-hls",
"autoDeleteWebTorrentIfNeeded": true,
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67",
"resolution": 1080,
"isPortraitMode": false,
"copyCodecs": true,
"isMaxQuality": true,
"hasAudio": true
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T12:56:12.616Z",
"finishedOn": "2022-09-07T13:00:04.094Z",
"processedOn": "2022-09-07T12:56:12.621Z"
},
{
"id": "1322",
"state": "completed",
"type": "video-transcoding",
"data": {
"type": "optimize-to-webtorrent",
"videoUUID": "17f950a4-c9ec-4104-9c78-4391e9fa5e67"
},
"progress": 100,
"priority": 122,
"error": null,
"createdAt": "2022-09-07T12:26:52.152Z",
"finishedOn": "2022-09-07T12:56:12.621Z",
"processedOn": "2022-09-07T12:26:52.165Z"
},
This is still happening for ~30% of our videos.
With what peertube version? 4.2.2? Because the next one should fix this issue (hopefully)
This is still happening for ~30% of our videos.
With what peertube version? 4.2.2? Because the next one should fix this issue (hopefully)
Yes, it's 4.2.2. Just added this to add information in case would help.
Okay then closing this issue. Please comment if it happens again with 4.3