Slow with macOS and USB 3 drives

[christiansievers]

It would be good to know what's going on, especially when some transcodings take many days or even some weeks.

We use a bash script that first transcodes a DPX folder and then does an integrity check on the resulting file with --check --coherency.

The terminal output of that looks like this:

Time=00:00:00 (61.8%), 1012 MiB/
Time=00:00:00 (61.9%), 964 MiB/s 
...
Time=00:00:00 (99.98%), 89 MiB/s    
Time=00:00:00 (99.99%), 89 MiB/s  

This is very fast. Then something else starts that is a lot slower:

Time=00:00:00 (0.01%), 7.3 MiB/s, 0.03x realtime    
Time=00:00:00 (0.02%), 8.0 MiB/s, 0.03x realtime    
Time=00:00:01 (0.03%), 7.5 MiB/s, 0.03x realtime    
Time=00:00:01 (0.04%), 8.0 MiB/s, 0.03x realtime    

What is happening? And is this connected to the reason why some transcodings become very slow? I'm seeing this especially with very large DPX folders, bigger than a TB.

[JeromeMartinez]

We use a bash script that first transcodes a DPX folder and then does an integrity check on the resulting file with --check --coherency.

--coherency should be in the first command so you'll have the DPX coherency errors before you transcode.

You can also do all in one command by putting --check --coherency directly in the first command, it is same as doing transcode then integrity check.

What is happening?

It is during transcoding, right?
There is a quick scan of files (fast) then the actual transcoding (slow).

I don't expect 2 parts for the integrity check.

And is this connected to the reason why some transcodings become very slow?

Such speed is expected with e.g. huge 6K5K16-bit content and a 100 € CPU.

Is it with a SAN on maCOS and during the integrity check for the slow part? There is a known issue in same cases with such config, and a patch is in progress for using an alternative method for reading the files, at least for the second command (the check one).
If so, I can update the patch and provide a build for tests.

[christiansievers]

Thanks, good to know! No, the output that I posted above is from running rawcooked --check --coherency myfile_DPX.mkv - which doesn't make much sense, I know now. I'll get rid of the --coherency in there.
I guess the slow process is the --check.

We use a ten year old Mac Pro with a 2,7 GHz 12-Core Intel Xeon processor and 64 GB of RAM. I know, not the best hardware, but that's what is available. It deals with smaller (300GB to 500GB) DPX folders just fine (a couple of hours and sometimes a day), but slows down a lot when transcoding folders above 1 TB. Especially when doing that --check command, apparently. It's the same when reading from a NAS or a locally attached Thunderbolt or USB-3 storage.

Here's a --check process that will take 20 days in the end:

Time=00:42:20 (89.83%), 458.6 KiB/s, 0.00x realtime    
Time=00:42:20 (89.84%), 464.4 KiB/s, 0.00x realtime    
Time=00:42:20 (89.85%), 467.6 KiB/s, 0.00x realtime    

It's almost there so I'm just going to let it run. But if you have any ideas on how to speed this up, I'd be happy to try it out.

[JeromeMartinez]

This hardware is old but should definitely be faster, maybe this is the issue we already spot somewhere else, I'll prepare a test binary.

The issue is closed, does it mean that you found a workaround?

[christiansievers]

I'd be happy to test that binary, thanks!

[christiansievers]

I just had a case, where the encoding took 3,5 hours, the integrity check took 1,5 days and reconstructing the original DPX folder took 2 days.

My hunch is that the larger DPX folders take exponentially longer to process. This was 780 GB.

[JeromeMartinez]

I just had a case, where the encoding took 3,5 hours, the integrity check took 1,5 days and reconstructing the original DPX folder took 2 days.

Thank you for the feedback.
integrity check should take also 3,5 hours, reconstructing the original DPX folder maybe a bit longer e.g. 4 hours (more to write), so definitely an issue here.

I still need to send a test build.

[JeromeMartinez]

@christiansievers please test this snapshot.
with :

• --io fstream
• --io fopen
• --io open

And let me know the processing time of integrity check (no need to reconstruct, no need to encode).

A quick try with Ctrl-C after 1 minute could already give an idea (but test the same way without the io option for fair comparison of all 4 methods).

There may be check issue report due to unfinished work on that, but the speed could give a hint about if the options are eventually useful or not.

[christiansievers]

Thanks, I'll have a go, and will let you know.

[christiansievers]

So. I used the Mac described above, with a USB-3 hard drive as storage. I ran the --check command plus your parameter variations on a 265 GB file, and stopped after a few minutes. I didn't capture stdout to calculate a real average value, but here's what it looks to me:

rawcooked --io fstream --check myfile.mkv
around 16 MiB/s

rawcooked --io fstream --check myfile.mkv
same speed, around 16 MiB/s.

rawcooked --io open --check myfile.mkv
same speed, around 16 MiB/s.

rawcooked --check myfile.mkv
without --io flag: starting with around 1.4 MiB/s, then dropping to 650 KiB/s (which is what I was seeing in production)

Another way to see that the --io flag helps, is that suddenly rawcooked uses more than 100% CPU.

[JeromeMartinez]

16 MiB/s is still low but it seems that the CPU is to be blamed here so fine enough for the issue we are trying to fix.
mmap is not appreciated by the USB-3 HDD :(, even if I find a way to avoid the drop, so need to use the good old access methods...

Could you run one of them completely tonight? I would like to know if there is an issue with the way I access the file (we know the file is good so if there is any error it is because I don't handle well the file I/O).

[christiansievers]

I'll run --io fstream --check on a file that has been checked before. Good?

[JeromeMartinez]

I'll run --io fstream --check on a file that has been checked before. Good?

If you can on the 780 GB file you mentioned, it would be even better.

[christiansievers]

The 800GB file that last time took 21 days to check was done in 8,5h, using --io fopen.