fix(fast xmlupload): make process-files more robust (DEV-2235) #395

jnussbaum · 2023-06-02T13:12:53Z

…he XML

…ocessing

linear · 2023-06-02T13:12:55Z

DEV-2235 DSP-TOOLS: process-files fails with docker.errors.APIError: 502 Server Error (Bad Gateway / Bad response from Docker engine)

On Vijs machine, this happened:

(dsp-tools-py3.10) bash-3.2$ dsp-tools process-files --input-dir=multimedia --output-dir=/Volumes/Thunderbay\ 1/tmp-test-sgv sgv-v8.7_v1.0_real-files.xml 
2023-05-30 18:54:17.315364: Created and started Sipi container 'sipi'.
2023-05-30 18:54:30.398737: Found 102960 bitstreams in the XML file.
2023-05-30 18:54:30.862857: Start local file processing...
Traceback (most recent call last):
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/api/client.py", line 268, in _raise_for_status
    response.raise_for_status()
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/requests/models.py", line 1021, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 502 Server Error: Bad Gateway for url: http+docker://localhost/v1.42/containers/0d911f24fc90e76ba9405f6303d8b342cd2c8094182c3bffea503a7ef9d5b8ce/exec

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/bin/dsp-tools", line 6, in <module>
    sys.exit(main())
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/dsp_tools.py", line 411, in main
    success = call_requested_action(
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/dsp_tools.py", line 314, in call_requested_action
    success = process_files(
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/fast_xmlupload/process_files.py", line 771, in process_files
    result = _process_files_in_parallel(
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/fast_xmlupload/process_files.py", line 105, in _process_files_in_parallel
    orig_filepath_2_uuid.append(processed.result())
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/concurrent/futures/_base.py", line 439, in result
    return self.__get_result()
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/concurrent/futures/_base.py", line 391, in __get_result
    raise self._exception
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/fast_xmlupload/process_files.py", line 570, in _process_file
    result = _process_image_file(
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/fast_xmlupload/process_files.py", line 648, in _process_image_file
    sipi_result = _convert_file_with_sipi(
  File "/Users/vijeinathtissaveerasingham/Git/dsp-tools/src/dsp_tools/fast_xmlupload/process_files.py", line 313, in _convert_file_with_sipi
    result = sipi_container.exec_run(f"/sipi/sipi '{in_file_sipi_path}' {out_file_sipi_path}")
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/models/containers.py", line 193, in exec_run
    resp = self.client.api.exec_create(
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/utils/decorators.py", line 19, in wrapped
    return f(self, resource_id, *args, **kwargs)
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/api/exec_api.py", line 78, in exec_create
    return self._result(res, True)
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/api/client.py", line 274, in _result
    self._raise_for_status(response)
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/api/client.py", line 270, in _raise_for_status
    raise create_api_error_from_http_exception(e) from e
  File "/Users/vijeinathtissaveerasingham/Library/Caches/pypoetry/virtualenvs/dsp-tools-Wck1hHBu-py3.10/lib/python3.10/site-packages/docker/errors.py", line 39, in create_api_error_from_http_exception
    raise cls(e, response=response, explanation=explanation) from e
docker.errors.APIError: 502 Server Error for http+docker://localhost/v1.42/containers/0d911f24fc90e76ba9405f6303d8b342cd2c8094182c3bffea503a7ef9d5b8ce/exec: Bad Gateway ("b'Bad response from Docker engine'")
(dsp-tools-py3.10) bash-3.2$

Log file

The log file's last entry is from 2023-06-01 22:01:55,997.

The log file doesn't contain the beginning of the process, because the old entries were already deleted.

Disappearing files

The input folder contains:

102’899 TIF files
34 MP4 files
1 JPG file
→ 102'934 files

The output folder contains:

102'960 Dateien mit Endung "*.orig"
7'272 Dateien mit Endung "*.jp2"
6'820 Dateien mit Endung "*.info"

For some reasons, much more .orig files were written than sidecars and derivates. That's very strange. Also the log files show much more entries for .orig file creation, and very few for derivates and sidecars.

Disappearing docker container

Unfortunately, the Docker container cannot be examined any more, because it was stopped.

Steps to improve

When failing, a timestamp should be written to console
Increase number of log files, and content size
stop the docker container only if terminating successfully. In case of errors, it should stay alive, to allow troubleshooting.
If a Docker error is raised, catch it, restart container, continue processing.
Find out how to prevent that there are too less sidecars and derivates
When process fails, print infos about which files were already processed, and which not yet.
Process a file only once, even if it is referenced several times in the XML.

BalduinLandolt · 2023-06-05T11:01:18Z

src/dsp_tools/fast_xmlupload/process_files.py

+            # restart sipi container
+            _stop_and_remove_sipi_container()
+            _start_sipi_container_and_mount_volumes(input_dir, output_dir)
+            global sipi_container
+            sipi_container = _get_sipi_container()


perfect candidate to extract into a method restart_sipi_container() - then you don't even need the comment

I refactored these methods, because they were a bit spurious anyway.

BalduinLandolt · 2023-06-05T11:13:15Z

src/dsp_tools/fast_xmlupload/process_files.py

+            orig_filepath_2_uuid += _process_files_in_parallel(
+                paths=unprocessed_paths,
+                input_dir=input_dir,
+                output_dir=output_dir,
+                nthreads=nthreads
+            )


doing a recursive call like this can potentially be a cause for errors, if the max recursion depth gets reached. In general, it would probably be more robust to move calling this function again one "level out", so it's flat, not recursive.
But, to be honest, I'm not sure how big the danger is of this actually happening

To be safe, I moved calling this function again one level out. Can you check that there's no logical flaw in it?

I didn't look thoroughly, but at first glance it seems good

src/dsp_tools/fast_xmlupload/process_files.py

jnussbaum added 7 commits June 2, 2023 11:35

retain more log entries

01b38f6

Process a file only once, even if it is referenced several times in t…

f4fcdd9

…he XML

don't remove sipi container if an error happened

88c6e4f

If a Docker error is raised, catch it, restart container, continue pr…

9e5e8c5

…ocessing

when failing, print files with processed & unprocessed filenames

e797e72

log/print file category before skipping

4753109

edit

73c67b2

jnussbaum self-assigned this Jun 2, 2023

jnussbaum requested a review from BalduinLandolt June 2, 2023 13:36

Merge branch 'main' into wip/dev-2235-fix-process-files

429964e

BalduinLandolt approved these changes Jun 5, 2023

View reviewed changes

jnussbaum and others added 3 commits June 6, 2023 09:24

avoid recursive call

c098e52

refactor starting of SIPI container

9cf8e1e

Merge branch 'main' into wip/dev-2235-fix-process-files

9678db3

jnussbaum merged commit 12d527b into main Jun 6, 2023
4 checks passed

jnussbaum deleted the wip/dev-2235-fix-process-files branch June 6, 2023 12:59

daschbot mentioned this pull request Jun 6, 2023

chore: release 2.3.3 #394

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix(fast xmlupload): make process-files more robust (DEV-2235) #395

fix(fast xmlupload): make process-files more robust (DEV-2235) #395

jnussbaum commented Jun 2, 2023

linear bot commented Jun 2, 2023

Log file

Disappearing files

Disappearing docker container

Steps to improve

BalduinLandolt Jun 5, 2023

jnussbaum Jun 6, 2023

BalduinLandolt Jun 5, 2023

jnussbaum Jun 6, 2023

BalduinLandolt Jun 6, 2023

fix(fast xmlupload): make process-files more robust (DEV-2235) #395

fix(fast xmlupload): make process-files more robust (DEV-2235) #395

Conversation

jnussbaum commented Jun 2, 2023

linear bot commented Jun 2, 2023

Log file

Disappearing files

Disappearing docker container

Steps to improve

BalduinLandolt Jun 5, 2023

Choose a reason for hiding this comment

jnussbaum Jun 6, 2023

Choose a reason for hiding this comment

BalduinLandolt Jun 5, 2023

Choose a reason for hiding this comment

jnussbaum Jun 6, 2023

Choose a reason for hiding this comment

BalduinLandolt Jun 6, 2023

Choose a reason for hiding this comment