I don’t know what is going on here. I have merged the outputs from two separate extractions. I was running heterogeneous refinement and it showed me the following error.
================= CRYOSPARCW ======= 2025-01-07 11:52:33.333137 =========
Project P25 Job J154
Master localhost Port 39002
===========================================================================
MAIN PROCESS PID 1642892
========= now starting main process at 2025-01-07 11:52:33.333753
hetero_refine.run cryosparc_compute.jobs.jobregister
MONITOR PROCESS PID 1642894
========= monitor process now waiting for main process
========= sending heartbeat at 2025-01-07 11:52:34.234129
***************************************************************
Transparent hugepages setting: [always] madvise never
Running job J154 of type hetero_refine
Running job on hostname %s localhost
Allocated Resources : {'fixed': {'SSD': True}, 'hostname': 'localhost', 'lane': 'default', 'lane_type': 'node', 'license': True, 'licenses_acquired': 1, 'slots': {'CPU': [0, 1, 2, 3], 'GPU': [0], 'RAM': [0, 1]}, 'target': {'cache_path': '/scratch/cryosparc', 'cache_quota_mb': None, 'cache_reserve_mb': 10000, 'desc': None, 'gpus': [{'id': 0, 'mem': 21151088640, 'name': 'NVIDIA RTX A4500'}, {'id': 1, 'mem': 21151088640, 'name': 'NVIDIA RTX A4500'}, {'id': 2, 'mem': 21151088640, 'name': 'NVIDIA RTX A4500'}], 'hostname': 'localhost', 'lane': 'default', 'monitor_port': None, 'name': 'localhost', 'resource_fixed': {'SSD': True}, 'resource_slots': {'CPU': [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47], 'GPU': [0, 1, 2], 'RAM': [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31]}, 'ssh_str': 'cryosparc@localhost', 'title': 'Worker node localhost', 'type': 'node', 'worker_bin_path': '/usr/local/cryosparc/2.0/cryosparc_worker/bin/cryosparcw'}}
2025-01-07 11:52:39,182 run_with_executor INFO | Resolving 10823 source path(s) for caching
2025-01-07 11:52:39,562 run_with_executor INFO | Resolved 10823 sources in 0.38 seconds
2025-01-07 11:52:39,580 allocate INFO | Cache allocation start. Active run IDs: P25-J154-1736286750
2025-01-07 11:52:40,382 refresh INFO | Refreshed cache drive in 0.80 seconds
2025-01-07 11:52:40,421 allocate INFO | Deleted 0 cached files, encountered 0 errors
2025-01-07 11:52:40,421 allocate INFO | Allocated 0 stub cache files; creating links
2025-01-07 11:52:40,760 allocate INFO | Cache allocation complete
2025-01-07 11:52:40,761 run_with_executor INFO | Cache allocation ran in 1.19 seconds
2025-01-07 11:52:40,761 run_with_executor INFO | Found 10823 SSD hit(s)
2025-01-07 11:52:40,762 run_with_executor INFO | Requested files successfully cached to SSD
2025-01-07 11:52:41,845 run_with_executor INFO | SSD cache complete
========= sending heartbeat at 2025-01-07 11:52:44.249346
========= sending heartbeat at 2025-01-07 11:52:54.270137
========= sending heartbeat at 2025-01-07 11:53:04.291001
gpufft: creating new cufft plan (plan id 0 pid 1642892)
gpu_id 0
ndims 2
dims 360 360 0
inembed 360 360 0
istride 1
idist 129600
onembed 360 360 0
ostride 1
odist 129600
batch 500
type C2C
wkspc automatic
Python traceback:
gpufft: creating new cufft plan (plan id 1 pid 1642892)
gpu_id 0
ndims 2
dims 360 360 0
inembed 360 360 0
istride 1
idist 129600
onembed 360 360 0
ostride 1
odist 129600
batch 500
type C2C
wkspc automatic
Python traceback:
HOST ALLOCATION FUNCTION: using numba.cuda.pinned_array
/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/numba/cuda/cudadrv/nvrtc.py:257: UserWarning: NVRTC log messages whilst compiling kernel:
kernel(35): warning #68-D: integer conversion resulted in a change of sign
kernel(44): warning #68-D: integer conversion resulted in a change of sign
kernel(17): warning #177-D: variable "N_I" was declared but never referenced
warnings.warn(msg)
<string>:1: UserWarning: Cannot manually free CUDA array; will be freed when garbage collected
========= sending heartbeat at 2025-01-07 11:53:14.305288
gpufft: creating new cufft plan (plan id 2 pid 1642892)
gpu_id 0
ndims 3
dims 128 128 128
inembed 128 128 130
istride 1
idist 2129920
onembed 128 128 65
ostride 1
odist 1064960
batch 1
type R2C
wkspc manual
Python traceback:
gpufft: creating new cufft plan (plan id 3 pid 1642892)
gpu_id 0
ndims 3
dims 64 64 64
inembed 64 64 33
istride 1
idist 135168
onembed 64 64 66
ostride 1
odist 270336
batch 1
type C2R
wkspc manual
Python traceback:
========= sending heartbeat at 2025-01-07 11:53:24.325829
========= sending heartbeat at 2025-01-07 11:53:34.344500
<string>:1: UserWarning: Cannot manually free CUDA array; will be freed when garbage collected
========= sending heartbeat at 2025-01-07 11:53:44.365051
**custom thread exception hook caught something
**** handle exception rc
Exception in thread Thread-10:
Traceback (most recent call last):
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2308, in run_with_except_hook
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2270, in handle_exception
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 1869, in log
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 323, in __init__
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 359, in _init
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 752, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1945, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 497, in wrapper
File "<string>", line 3, in raise_from
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 495, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1777, in _parse_stat_file
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 840, in bcat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 828, in cat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 788, in open_binary
OSError: [Errno 24] Too many open files: '/proc/1642892/stat'
**custom thread exception hook caught something
**** handle exception rc
Exception in thread Thread-9:
Traceback (most recent call last):
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2308, in run_with_except_hook
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2270, in handle_exception
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 1869, in log
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 323, in __init__
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 359, in _init
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 752, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1945, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 497, in wrapper
File "<string>", line 3, in raise_from
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 495, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1777, in _parse_stat_file
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 840, in bcat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 828, in cat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 788, in open_binary
OSError: [Errno 24] Too many open files: '/proc/1642892/stat'
2025-01-07 11:53:50,236 __del__ INFO | Deleting plot real-slice-0
2025-01-07 11:53:50,260 __del__ INFO | Deleting plot fsc-0
2025-01-07 11:53:50,266 __del__ INFO | Deleting plot viewing-dist-0
2025-01-07 11:53:50,280 __del__ INFO | Deleting plot postprec-dist-0
2025-01-07 11:53:50,292 __del__ INFO | Deleting plot real-slice-1
2025-01-07 11:53:50,315 __del__ INFO | Deleting plot fsc-1
2025-01-07 11:53:50,322 __del__ INFO | Deleting plot viewing-dist-1
2025-01-07 11:53:50,336 __del__ INFO | Deleting plot postprec-dist-1
2025-01-07 11:53:50,348 __del__ INFO | Deleting plot noise-model
**** handle exception rc
2025-01-07 11:53:50,581 safe_rm ERROR | /scratch/cryosparc/instance_localhost:39001/links/P25-J154-1736286750: Could not clear job cache links
2025-01-07 11:53:50,581 safe_rm ERROR | Traceback (most recent call last):
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2270, in handle_exception
2025-01-07 11:53:50,581 safe_rm ERROR | log(tbstr, type='error')
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 1869, in log
2025-01-07 11:53:50,581 safe_rm ERROR | cpumem_mb = psutil.Process().memory_info().rss / 1024.0**2
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 323, in __init__
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 359, in _init
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 752, in create_time
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1945, in create_time
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 497, in wrapper
2025-01-07 11:53:50,581 safe_rm ERROR | File "<string>", line 3, in raise_from
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 495, in wrapper
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1777, in _parse_stat_file
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 840, in bcat
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 828, in cat
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 788, in open_binary
2025-01-07 11:53:50,581 safe_rm ERROR | OSError: [Errno 24] Too many open files: '/proc/1642892/stat'
2025-01-07 11:53:50,581 safe_rm ERROR |
2025-01-07 11:53:50,581 safe_rm ERROR | During handling of the above exception, another exception occurred:
2025-01-07 11:53:50,581 safe_rm ERROR |
2025-01-07 11:53:50,581 safe_rm ERROR | Traceback (most recent call last):
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/cache_v2.py", line 1135, in safe_rm
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/util/__init__.py", line 192, in try_rm
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/shutil.py", line 721, in rmtree
2025-01-07 11:53:50,581 safe_rm ERROR | File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/shutil.py", line 718, in rmtree
2025-01-07 11:53:50,581 safe_rm ERROR | OSError: [Errno 24] Too many open files: '/scratch/cryosparc/instance_localhost:39001/links/P25-J154-1736286750'
Traceback (most recent call last):
File "<string>", line 1, in <module>
File "cryosparc_master/cryosparc_compute/run.py", line 255, in cryosparc_master.cryosparc_compute.run.run
File "cryosparc_master/cryosparc_compute/run.py", line 153, in cryosparc_master.cryosparc_compute.run.main
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 2270, in handle_exception
File "/usr/local/cryosparc/2.0/cryosparc_worker/cryosparc_compute/jobs/runcommon.py", line 1869, in log
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 323, in __init__
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 359, in _init
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/__init__.py", line 752, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1945, in create_time
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1714, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 497, in wrapper
File "<string>", line 3, in raise_from
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 495, in wrapper
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_pslinux.py", line 1777, in _parse_stat_file
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 840, in bcat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 828, in cat
File "/usr/local/cryosparc/2.0/cryosparc_worker/deps/anaconda/envs/cryosparc_worker_env/lib/python3.10/site-packages/psutil/_common.py", line 788, in open_binary
OSError: [Errno 24] Too many open files: '/proc/1642892/stat'
Total: 75.201s
iosys:2:
iocb processing [hits 12]: 0.299431s 0.40% (10.015288s 13.32% with children)
iosys_sort_jobs [hits 12]: 0.005603s 0.01%
iosys_open_cacheable_fds [hits 12]: 1.513447s 2.01%
iosys_process_cached_fd_reads [hits 12]: 0.000462s 0.00% (8.196748s 10.90% with children)
io_uring fill sq [hits 12]: 0.001647s 0.00%
io_uring block [hits 12]: 7.728208s 10.28%
io_uring drain cq [hits 12]: 0.466430s 0.62%
slow_path [hits 12]: 0.000059s 0.00%
iosys:1:
iocb processing [hits 12]: 0.433579s 0.58% (10.053170s 13.37% with children)
iosys_sort_jobs [hits 12]: 0.005360s 0.01%
iosys_open_cacheable_fds [hits 12]: 1.670265s 2.22%
iosys_process_cached_fd_reads [hits 12]: 0.000341s 0.00% (7.943908s 10.56% with children)
io_uring fill sq [hits 12]: 0.001602s 0.00%
io_uring block [hits 12]: 7.497515s 9.97%
io_uring drain cq [hits 12]: 0.444450s 0.59%
slow_path [hits 12]: 0.000058s 0.00%
iosys:0:
iocb processing [hits 13]: 0.295921s 0.39% (10.840830s 14.42% with children)
iosys_sort_jobs [hits 13]: 0.006503s 0.01%
iosys_open_cacheable_fds [hits 13]: 1.861952s 2.48%
iosys_process_cached_fd_reads [hits 13]: 0.000398s 0.00% (8.676389s 11.54% with children)
io_uring fill sq [hits 13]: 0.001712s 0.00%
io_uring block [hits 13]: 8.157646s 10.85%
io_uring drain cq [hits 13]: 0.516634s 0.69%
slow_path [hits 13]: 0.000064s 0.00%
MAIN THREAD:
========= main process now complete at 2025-01-07 11:53:54.386519.
========= monitor process now complete at 2025-01-07 11:53:54.440468.