Speed Up Publishing Times

[r42-chun]

1. Use concurrent.futures to copy files
2. Use speedcopy.copyfile for windows when copying Hero files as shutil.copy is extremely slow.

Results.
On a test publish job on the farm, have cut down publishing times from 16 mins 51 seconds to 6 mins 50 seconds.

[BigRoy]

Very nice! :) I've added some comments which are mostly cosmetics. I wouldn't have expected that concurrency on the file transfers would've made such a big difference.

The amount of threads being started to do the transfer - I wonder whether we should still customize that - because it may be quite many (e.g. 32 threads), see: https://docs.python.org/3/library/concurrent.futures.html#concurrent.futures.ThreadPoolExecutor

But if this doesn't give issues in production on "regular publishing" on a workstation and doesn't block the user's machine significantly I'd say we can keep the defaults just fine.

[BigRoy]

I know this is copied from here.

However, we're also using speedcopy in the codebase without that fallback, e.g. here:

• ayon-core/client/ayon_core/pipeline/farm/pyblish_functions.py

  Line 1255 in 4bf03f0

  import speedcopy

• ayon-core/client/ayon_core/plugins/publish/extract_review.py

  Line 10 in f7f5904

  import speedcopy

Which may hint that either the fallback is redundant nowadays - or we have other areas in the codebase that are potentially buggy on Linux? @iLLiCiTiT @antirotor do you know?

[antirotor]

Speedcopy is in dependencies of AYON (

ayon-core/client/pyproject.toml

Line 10 in c7899fb

speedcopy = "^2.1"

) and it has its own fallback if it cannot use server-side copy. What is the issue with spedcopy on linux?

[krishnaavril]

Commenting to show the intrest and following this up

This a major problem actually, our large FX caches are taking hours to copy, Finally some relief!

[BigRoy]

Technically this runs in a thread now - and hence it should not do this on an object outside of the thread. However, in Python implementations this should still be safe due to the GIL and how the interpreter locks, etc.

Nonetheless, in a potential non-GIL or free threaded Python 3 world this would be unsafe and instead we should be instead relying on the future.result() instead.

[BigRoy]

I've cleaned up the code to match code style guide + added error handling in both cases (or at least, have it raise and log the errors and stop as soon as possible on an error instead of continuing to finish the rest of the threaded queue.

@iLLiCiTiT @antirotor thoughts?

I have done some simple tests from Maya, Fusion and Silhouette; all good! - however I did not do any speed comparisons.

As far as I know, usually 'threading' file transfers should not make things much faster because the slowness would be IO-bound or network-speed bound regardless. So this making a huge performance impact might need some testing in a few production scenarios. I did see some shuffled outputs in the logs where it logged e.g. frame 59, 55 then 60. It'd hint at the very least that it did speed up something as another part what still waiting to continue.

Also note that the max_workers=8 seems relatively arbitrarily chosen, and depending on actual speed test runs and comparisons a more optimal figure could be found. Without doing actual speed comparisons we may just as well remove the max_workers and have it use the defaults of ThreadPoolExecutor instead (which may be much higher depending on the machine's CPU count in the running process however.)

---

For completeness sake, if it now DOES error then e.g. an output log turns into:

ERROR: Error occurred in worker
Traceback (most recent call last):
  File "C:\Program Files\BorisFX\Silhouette 2024.5\resources\python\lib\concurrent\futures\thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "F:\dev\ayon-core\client\ayon_core\lib\file_transaction.py", line 155, in _transfer_file
    copyfile(src, dst)
  File "C:\Users\User\AppData\Local\Ynput\AYON\dependency_packages\ayon_2406251801_windows.zip\dependencies\speedcopy\__init__.py", line 332, in copyfile
    ret = COPYFILE('\\\\?\\' + source_file,
  File "_ctypes/callproc.c", line 997, in GetResult
PermissionError: [WinError -2147024891] Access is denied

CRITICAL: Error when registering
Traceback (most recent call last):
  File "F:\dev\ayon-core\client\ayon_core\plugins\publish\integrate.py", line 158, in process
    self.register(instance, file_transactions, filtered_repres)
  File "F:\dev\ayon-core\client\ayon_core\plugins\publish\integrate.py", line 290, in register
    file_transactions.process()
  File "F:\dev\ayon-core\client\ayon_core\lib\file_transaction.py", line 129, in process
    as_completed_stop_and_raise_on_error(
  File "F:\dev\ayon-core\client\ayon_core\lib\threadpool.py", line 49, in as_completed_stop_and_raise_on_error
    raise exceptions[-1]
  File "C:\Program Files\BorisFX\Silhouette 2024.5\resources\python\lib\concurrent\futures\thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "F:\dev\ayon-core\client\ayon_core\lib\file_transaction.py", line 155, in _transfer_file
    copyfile(src, dst)
  File "C:\Users\User\AppData\Local\Ynput\AYON\dependency_packages\ayon_2406251801_windows.zip\dependencies\speedcopy\__init__.py", line 332, in copyfile
    ret = COPYFILE('\\\\?\\' + source_file,
  File "_ctypes/callproc.c", line 997, in GetResult
PermissionError: [WinError -2147024891] Access is denied

Traceback (most recent call last):
  File "C:\Users\User\AppData\Local\Ynput\AYON\dependency_packages\ayon_2406251801_windows.zip\dependencies\pyblish\plugin.py", line 528, in __explicit_process
    runner(*args)
  File "F:\dev\ayon-core\client\ayon_core\plugins\publish\integrate.py", line 170, in process
    raise exc
  File "F:\dev\ayon-core\client\ayon_core\plugins\publish\integrate.py", line 158, in process
    self.register(instance, file_transactions, filtered_repres)
  File "F:\dev\ayon-core\client\ayon_core\plugins\publish\integrate.py", line 290, in register
    file_transactions.process()
  File "F:\dev\ayon-core\client\ayon_core\lib\file_transaction.py", line 129, in process
    as_completed_stop_and_raise_on_error(
  File "F:\dev\ayon-core\client\ayon_core\lib\threadpool.py", line 49, in as_completed_stop_and_raise_on_error
    raise exceptions[-1]
  File "C:\Program Files\BorisFX\Silhouette 2024.5\resources\python\lib\concurrent\futures\thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "F:\dev\ayon-core\client\ayon_core\lib\file_transaction.py", line 155, in _transfer_file
    copyfile(src, dst)
  File "C:\Users\User\AppData\Local\Ynput\AYON\dependency_packages\ayon_2406251801_windows.zip\dependencies\speedcopy\__init__.py", line 332, in copyfile
    ret = COPYFILE('\\\\?\\' + source_file,
  File "_ctypes/callproc.c", line 997, in GetResult
PermissionError: [WinError -2147024891] Access is denied

Note that this in particular is from the speedcopy on trying to copy a folder (which never worked anyway) but was the easiest error reproducable I could find. As can be seen - it does make for quite a verbose output.

[r42-chun]

Thanks so much Roy for helping me with the error handling! Much appreciated

Also note that the max_workers=8 seems relatively arbitrarily chosen,

Yes, it was chosen randomly. Wonder if we can make it a parameter or just remove it entirely?

As far as I know, usually 'threading' file transfers should not make things much faster because the slowness would be IO-bound or network-speed bound regardless. So this making a huge performance impact might need some testing in a few production scenarios.

Yes, there are other little speed ups here and there as well so it's not only because of concurrent. For example speedcopy for hero copying instead of shutil.copy. So I just did another test with all the other changes implemented except we don't have concurrent. And I clocked in at 11 min 48 seconds. Just want to manage people's expectations. But I agree, would be good to test in a few production scenarios as you mentioned.

[iLLiCiTiT]

I would add this as method of file transaction. This is not much reusable elsewhere. I guess it is here for hero version integration? If yes, we should use file transactions there too. If that would be too much work, we can skip speed enhancement of hero integration in this PR.

[BigRoy]

I'm re-using it in two places currently - that's why I added it into a separate file. But you mean to add it to file_transaction.py but not necessarily the FileTransaction class itself. If so, I can definitely do that! :)

[BigRoy]

I've now moved it to the other file (but not a method because it's also used outside of the class). See 9c67bf1

@iLLiCiTiT better?

[BigRoy]

Also, I assume the function may get more use if we were to move more things to thread pools, e.g. transcoding, etc.