search

nschlia / ffmpegfs

FUSE-based transcoding filesystem with video support from many formats to FLAC, MP4, TS, WebM, OGG, MP3, HLS, and others.
https://nschlia.github.io/ffmpegfs/
GNU General Public License v3.0
196 stars 14 forks source link

HLS: cp operation occasionally fails with EPERM (Operation not permitted) #143

Closed nschlia closed 1 year ago

nschlia commented 1 year ago

Seems the line "2023-02-10 21:02:17.694 ERROR : CACHE [snowboard.mp4.000002.ts.cache.ts] INTERNAL ERROR: Buffer::copy()! size(segment_no) < offset - Segment: 1 Size: 0 Offset: 917504" is the reason. Why is segment_size (and probably ci->m_buffer_size) suddenly 0?!?!

2023-02-10 21:02:17.667 TRACE  : OTHER   [snowboard.mp4] getattr
2023-02-10 21:02:17.667 TRACE  : OTHER   [snowboard.mp4/000001.ts] getattr
2023-02-10 21:02:17.667 TRACE  : OTHER   [snowboard.mp4/000001.ts] open
2023-02-10 21:02:17.667 TRACE  : INPUT   [snowboard.mp4] Reusing cached transcoder.
2023-02-10 21:02:17.667 TRACE  : INPUT   [snowboard.mp4] Creating transcoder object.
2023-02-10 21:02:17.667 TRACE  : OUTPUT  [snowboard.mp4] Reading file from cache.
2023-02-10 21:02:17.668 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 0 to 131072.
2023-02-10 21:02:17.668 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 0 to 131072 for segment no. 1.
2023-02-10 21:02:17.668 DEBUG  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Reading from cache file.
2023-02-10 21:02:17.668 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Mapping cache file.
2023-02-10 21:02:17.668 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 0 to 131072.
2023-02-10 21:02:17.669 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 131072 to 262144.
2023-02-10 21:02:17.669 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 131072 to 262144 for segment no. 1.
2023-02-10 21:02:17.669 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.669 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 131072 to 262144.
2023-02-10 21:02:17.669 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 262144 to 393216.
2023-02-10 21:02:17.670 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 262144 to 393216 for segment no. 1.
2023-02-10 21:02:17.670 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.670 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 262144 to 393216.
2023-02-10 21:02:17.670 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 393216 to 524288.
2023-02-10 21:02:17.671 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 393216 to 524288 for segment no. 1.
2023-02-10 21:02:17.671 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.671 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 393216 to 524288.
2023-02-10 21:02:17.671 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 524288 to 655360.
2023-02-10 21:02:17.671 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 524288 to 655360 for segment no. 1.
2023-02-10 21:02:17.671 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.672 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 524288 to 655360.
2023-02-10 21:02:17.672 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 655360 to 786432.
2023-02-10 21:02:17.672 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 655360 to 786432 for segment no. 1.
2023-02-10 21:02:17.672 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.672 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 655360 to 786432.
2023-02-10 21:02:17.673 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 786432 to 917504.
2023-02-10 21:02:17.673 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 786432 to 917504 for segment no. 1.
2023-02-10 21:02:17.673 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.673 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 786432 to 917504.
2023-02-10 21:02:17.694 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 917504 to 1048576.
2023-02-10 21:02:17.694 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 917504 to 1048576 for segment no. 1.
2023-02-10 21:02:17.694 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-10 21:02:17.694 ERROR  : CACHE   [snowboard.mp4.000002.ts.cache.ts] INTERNAL ERROR: Buffer::copy()! size(segment_no) < offset - Segment: 1 Size: 0 Offset: 917504
2023-02-10 21:02:17.700 TRACE  : OTHER   [snowboard.mp4/000001.ts] release
2023-02-10 21:02:17.700 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Closing cache file.
2023-02-10 21:02:17.700 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Unmapping cache file.

Also here (2nd copy op):

2023-02-12 14:54:39.825 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 50928 bytes from offset 1441792 to 1492720.
2023-02-12 14:54:39.826 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 1492720 to 1623792.
2023-02-12 14:54:39.826 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 1492720 to 1623792 for segment no. 1.
2023-02-12 14:54:39.826 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-12 14:54:39.826 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read output file to EOF.
2023-02-12 14:54:39.828 TRACE  : OTHER   [snowboard.mp4/000001.ts] release
2023-02-12 14:54:39.828 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Closing cache file.
2023-02-12 14:54:39.828 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Unmapping cache file.
2023-02-12 14:54:39.829 TRACE  : OTHER   [snowboard.mp4] getattr
2023-02-12 14:54:39.830 TRACE  : OTHER   [snowboard.mp4/000001.ts] getattr
2023-02-12 14:54:39.832 TRACE  : OTHER   [snowboard.mp4/000001.ts] open
2023-02-12 14:54:39.832 TRACE  : INPUT   [snowboard.mp4] Reusing cached transcoder.
2023-02-12 14:54:39.832 TRACE  : INPUT   [snowboard.mp4] Creating transcoder object.
2023-02-12 14:54:39.832 TRACE  : OUTPUT  [snowboard.mp4] Reading file from cache.
2023-02-12 14:54:39.848 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 0 to 131072.
2023-02-12 14:54:39.848 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 0 to 131072 for segment no. 1.
2023-02-12 14:54:39.848 DEBUG  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Reading from cache file.
2023-02-12 14:54:39.848 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Mapping cache file.
2023-02-12 14:54:39.883 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Read 131072 bytes from offset 0 to 131072.
2023-02-12 14:54:39.896 TRACE  : OTHER   [snowboard.mp4/000001.ts] read: Reading 131072 bytes from offset 131072 to 262144.
2023-02-12 14:54:39.896 TRACE  : OUTPUT  [snowboard.mp4] Reading 131072 bytes from offset 131072 to 262144 for segment no. 1.
2023-02-12 14:54:39.896 TRACE  : CACHE   [snowboard.mp4.000001.ts.cache.ts] Cache file is already open.
2023-02-12 14:54:39.896 ERROR  : CACHE   [snowboard.mp4.000002.ts.cache.ts] INTERNAL ERROR: Buffer::copy()! size(segment_no) < offset - Segment: 1 Size: 0 Offset: 131072
2023-02-12 14:54:39.897 TRACE  : OTHER   [snowboard.mp4/000001.ts] release

This happens only occasionally, and only with the test_filesizes_hls check, and on the Debian 12 build machine (never under Debian 11). Happens when test_filesize_hls check is run. test_filesize_hls.builtin(1).log test_filesize_hls.builtin(2).log test_filesize_hls(1).log test_filesize_hls(2).log