galaxy produces a red output collection for a successfull job

[martenson]

history: https://usegalaxy.cz/u/martincech/h/yolo

the job is an unzip tool that is supposed to decompress archive into a collection with cca 3700 small datasets. Works fine on the same input on usegalaxy.eu

this trace could be related:

2025-08-13T13:37:05.043972+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: galaxy.job_execution.output_collect ERROR 2025-08-13 13:37:05,038 [pN:handler_1,p:3348726,tN:PulsarJobRunner.work_thread-2] Problem gathering output collection.
2025-08-13T13:37:05.044041+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: Traceback (most recent call last):
2025-08-13T13:37:05.044063+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/job_execution/output_collect.py", line 184, in collect_dynamic_outputs
2025-08-13T13:37:05.044078+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     job_context.populate_collection_elements(
2025-08-13T13:37:05.044094+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 339, in populate_collection_elements
2025-08-13T13:37:05.044109+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self._populate_elements(
2025-08-13T13:37:05.044124+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 448, in _populate_elements
2025-08-13T13:37:05.044136+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self.update_object_store_with_datasets(
2025-08-13T13:37:05.044151+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 474, in update_object_store_with_datasets
2025-08-13T13:37:05.044182+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self.object_store.update_from_file(dataset.dataset, file_name=path, create=True)
2025-08-13T13:37:05.044204+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 658, in update_from_file
2025-08-13T13:37:05.044218+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self._invoke(
2025-08-13T13:37:05.044232+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^
2025-08-13T13:37:05.044245+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 492, in _invoke
2025-08-13T13:37:05.044257+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.__getattribute__(f"_{delegate}")(obj=obj, **kwargs)
2025-08-13T13:37:05.044271+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-08-13T13:37:05.044288+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1233, in _update_from_file
2025-08-13T13:37:05.044301+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self._create(
2025-08-13T13:37:05.044314+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1734, in _create
2025-08-13T13:37:05.044327+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.backends[0].create(obj, **kwargs)
2025-08-13T13:37:05.044340+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-08-13T13:37:05.044353+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 548, in create
2025-08-13T13:37:05.044365+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self._invoke(
2025-08-13T13:37:05.044379+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^
2025-08-13T13:37:05.044392+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 492, in _invoke
2025-08-13T13:37:05.044408+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.__getattribute__(f"_{delegate}")(obj=obj, **kwargs)
2025-08-13T13:37:05.044421+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-08-13T13:37:05.044435+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1045, in _create
2025-08-13T13:37:05.044451+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     open(path, "w").close()  # Should be rb?
2025-08-13T13:37:05.044465+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     ^^^^^^^^^^^^^^^
2025-08-13T13:37:05.044478+02:00 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: PermissionError: [Errno 13] Permission denied: '/rbd/data/datasets/2/1/3/dataset_2134c300-36b4-48f4-a70c-447da6aa40a3.dat'

[martenson]

I modified the rules to allow more cpu/ram

Cores Allocated | 4
-- | --
Memory Allocated (MB) | 16000

it succeeded once but I suspect this is a red herring and that was a random success

[martenson]

it really seems like some of the files are missing

Aug 14 15:37:53 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: galaxy.model.store.discover DEBUG 2025-08-14 15:37:53,454 [pN:handler_1,p:3348726,tN:PulsarJobRunner.work_thread-0] (36896) Created dynamic collection dataset for path [/rbd/data/jobs/036/36896/working/out/dataset_seanoe_101899_images_Images_CAM-TEMPO-MINI-2_20141123181553.jpg] with element identifier [dataset_seanoe_101899_images_Images_CAM-TEMPO-MINI-2_20141123181553] for output [unzipped] (0.251 ms)
Aug 14 15:38:08 galaxy-cz.grid.cesnet.cz galaxyctl[3348211]: [2025-08-14 15:38:08,411: DEBUG/main] heartbeat_tick : for connection c6b0b3bca8f746098fa44fd00e9840bd
Aug 14 15:38:08 galaxy-cz.grid.cesnet.cz galaxyctl[3348211]: [2025-08-14 15:38:08,411: DEBUG/main] heartbeat_tick : Prev sent/recv: 4492/259976, now - 4493/260006, monotonic - 3283524.648858672, last_heartbeat_sent - 3283524.648858052, heartbeat int. - 60 for connection c6b0b3bca8f746098fa44fd00e9840bd
Aug 14 15:38:10 galaxy-cz.grid.cesnet.cz galaxyctl[3365841]: uvicorn.access INFO 2025-08-14 15:38:10,164 [pN:main.2,p:3365841,tN:MainThread] 216.144.248.29:0 - "HEAD / HTTP/1.0" 302
Aug 14 15:38:10 galaxy-cz.grid.cesnet.cz galaxyctl[3365841]: uvicorn.access INFO 2025-08-14 15:38:10,525 [pN:main.2,p:3365841,tN:MainThread] 216.144.248.29:0 - "HEAD /root/login?redirect=%2F HTTP/1.0" 302
Aug 14 15:38:10 galaxy-cz.grid.cesnet.cz galaxyctl[3365833]: uvicorn.access INFO 2025-08-14 15:38:10,889 [pN:main.1,p:3365833,tN:MainThread] 216.144.248.29:0 - "HEAD /login/start?redirect=%2F HTTP/1.0" 200
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: galaxy.job_execution.output_collect ERROR 2025-08-14 15:38:15,052 [pN:handler_1,p:3348726,tN:PulsarJobRunner.work_thread-0] Problem gathering output collection.
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: Traceback (most recent call last):
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/job_execution/output_collect.py", line 184, in collect_dynamic_outputs
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     job_context.populate_collection_elements(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 339, in populate_collection_elements
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self._populate_elements(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 448, in _populate_elements
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self.update_object_store_with_datasets(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/model/store/discover.py", line 474, in update_object_store_with_datasets
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self.object_store.update_from_file(dataset.dataset, file_name=path, create=True)
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 658, in update_from_file
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self._invoke(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 492, in _invoke
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.__getattribute__(f"_{delegate}")(obj=obj, **kwargs)
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1233, in _update_from_file
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     self._create(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1734, in _create
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.backends[0].create(obj, **kwargs)
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 548, in create
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self._invoke(
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 492, in _invoke
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     return self.__getattribute__(f"_{delegate}")(obj=obj, **kwargs)
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:   File "/srv/galaxy/server/lib/galaxy/objectstore/__init__.py", line 1045, in _create
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     open(path, "w").close()  # Should be rb?
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]:     ^^^^^^^^^^^^^^^
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: PermissionError: [Errno 13] Permission denied: '/rbd/data/datasets/d/9/2/dataset_d925970c-1b44-4926-804d-ca8419d9b70e.dat'
Aug 14 15:38:15 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: galaxy.jobs INFO 2025-08-14 15:38:15,985 [pN:handler_1,p:3348726,tN:PulsarJobRunner.work_thread-0] Collecting metrics for Job 36896 in /rbd/data/jobs/036/36896/metadata
Aug 14 15:38:16 galaxy-cz.grid.cesnet.cz galaxyctl[3348726]: galaxy.jobs DEBUG 2025-08-14 15:38:16,125 [pN:handler_1,p:3348726,tN:PulsarJobRunner.work_thread-0] job_wrapper.finish for job 36896 executed (69414.435 ms)