Problem while ocrd import with parent stage

[markusweigelt]

2024-02-23T17:11:59.485877804Z # ocrd-controller:22 SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
2024-02-23T17:11:59.527277263Z # ocrd-controller:22 SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
2024-02-23T17:11:59.557043131Z # ocrd-controller:22 SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
2024-02-23T17:11:59.574767342Z # ocrd-controller:22 SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
2024-02-23T17:11:59.608877392Z # ocrd-controller:22 SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
2024-02-23T17:11:59.861086654Z  * Starting enhanced syslogd rsyslogd       �[80G 
�[74G[ OK ]
2024-02-23T17:11:59.922960890Z  * Starting OpenBSD Secure Shell server sshd       �[80G 
�[74G[ OK ]
2024-02-23T17:12:01.927283612Z Feb 23 17:12:00 ocrd-manager rsyslogd: rsyslogd's groupid changed to 106
2024-02-23T17:12:01.927332732Z Feb 23 17:12:00 ocrd-manager rsyslogd: rsyslogd's userid changed to 105
2024-02-23T17:12:01.927337851Z Feb 23 17:12:00 ocrd-manager rsyslogd: [origin software="rsyslogd" swVersion="8.2001.0" x-pid="41" x-info="https://www.rsyslog.com"] start
2024-02-23T17:12:42.931658761Z Feb 23 17:12:42 ocrd-manager process_images.sh: ocr_init initialize variables and directory structure
2024-02-23T17:12:42.931687958Z Feb 23 17:12:42 ocrd-manager process_images.sh: running with --proc-id testdata-kitodo --task-id 1 /data/testdata-kitodo CONTROLLER=ocrd-controller:22 ACTIVEMQ=kitodo-mq:61616
2024-02-23T17:12:42.931693640Z Feb 23 17:12:42 ocrd-manager process_images.sh: using workflow '/workflows/ocr-workflow-default.sh':
2024-02-23T17:12:42.931697470Z Feb 23 17:12:42 ocrd-manager process_images.sh: "tesserocr-recognize -P segmentation_level region -P model frak2021 -I OCR-D-IMG -O OCR-D-OCR" "fileformat-transform -P from-to \"page alto\" -P script-args \"--no-check-border --dummy-word\" -I OCR-D-OCR -O FULLTEXT" 
2024-02-23T17:12:42.931702091Z Feb 23 17:12:42 ocrd-manager process_images.sh: {
2024-02-23T17:12:42.931705277Z Feb 23 17:12:42 ocrd-manager process_images.sh:   acknowledged: true,
2024-02-23T17:12:42.931708584Z Feb 23 17:12:42 ocrd-manager process_images.sh:   insertedId: ObjectId("65d8d20aa1d63d842e4cd3bb")
2024-02-23T17:12:42.931711992Z Feb 23 17:12:42 ocrd-manager process_images.sh: }
2024-02-23T17:12:42.931714911Z Feb 23 17:12:42 ocrd-manager process_images.sh: ocr_exit in async mode - immediate termination of the script
2024-02-23T17:12:42.931718062Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images' -> 'ocr-d//data/testdata-kitodo/images'
2024-02-23T17:12:42.931721547Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000009.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000009.tif.original.jpg'
2024-02-23T17:12:42.931724963Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000010.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000010.tif.original.jpg'
2024-02-23T17:12:42.931728330Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000011.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000011.tif.original.jpg'
2024-02-23T17:12:42.931748705Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000012.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000012.tif.original.jpg'
2024-02-23T17:12:42.931752960Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000013.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000013.tif.original.jpg'
2024-02-23T17:12:42.931757638Z Feb 23 17:12:42 ocrd-manager process_images.sh: '/data/testdata-kitodo/images/00000014.tif.original.jpg' -> 'ocr-d//data/testdata-kitodo/images/00000014.tif.original.jpg'
2024-02-23T17:12:43.931749676Z Feb 23 17:12:43 ocrd-manager process_images.sh: sending incremental file list
2024-02-23T17:12:43.931772295Z Feb 23 17:12:43 ocrd-manager process_images.sh: created directory /data/KitodoJob_91_testdata-kitodo
2024-02-23T17:12:43.931776007Z Feb 23 17:12:43 ocrd-manager process_images.sh: ./
2024-02-23T17:12:43.931778915Z Feb 23 17:12:43 ocrd-manager process_images.sh: ocrd.log
2024-02-23T17:12:43.931781509Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/
2024-02-23T17:12:43.931784407Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000009.tif.original.jpg
2024-02-23T17:12:43.931786999Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000010.tif.original.jpg
2024-02-23T17:12:43.931789452Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000011.tif.original.jpg
2024-02-23T17:12:43.931791830Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000012.tif.original.jpg
2024-02-23T17:12:43.931794341Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000013.tif.original.jpg
2024-02-23T17:12:43.931796792Z Feb 23 17:12:43 ocrd-manager process_images.sh: images/00000014.tif.original.jpg
2024-02-23T17:12:43.931799163Z Feb 23 17:12:43 ocrd-manager process_images.sh: 
2024-02-23T17:12:43.931801563Z Feb 23 17:12:43 ocrd-manager process_images.sh: sent 2,485,620 bytes  received 221 bytes  1,657,227.33 bytes/sec
2024-02-23T17:12:43.931804089Z Feb 23 17:12:43 ocrd-manager process_images.sh: total size is 2,484,374  speedup is 1.00
2024-02-23T17:12:43.931806624Z Feb 23 17:12:43 ocrd-manager process_images.sh: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
2024-02-23T17:12:43.931809302Z Feb 23 17:12:43 ocrd-manager process_images.sh: 2024-02-23 17:12:43 INFO  KitodoActiveMQClient:76 - Sending of message for taskId='1' was successful
2024-02-23T17:12:43.931811868Z Feb 23 17:12:43 2024-02-23 17: 12:43 INFO  KitodoActiveMQClient:76 - Sending of message for taskId='1' was successful
2024-02-23T17:12:43.931814423Z Feb 23 17:12:43 ocrd-manager process_images.sh: execute 3 commands via SSH by the controller
2024-02-23T17:12:44.931855609Z Feb 23 17:12:44 ocrd-manager process_images.sh: set -Ee#015
2024-02-23T17:12:44.931881209Z Feb 23 17:12:44 ocrd-manager process_images.sh: cd 'KitodoJob_91_testdata-kitodo'#015
2024-02-23T17:12:44.931886180Z Feb 23 17:12:44 ocrd-manager process_images.sh: echo $$ > ocrd.pid#015
2024-02-23T17:12:44.931889606Z Feb 23 17:12:44 ocrd-manager process_images.sh: if test -f mets.xml; then OV=--overwrite; else OV=; ocrd-import -j 1 -i; fi#015
2024-02-23T17:12:44.931905620Z Feb 23 17:12:44 ocrd-manager process_images.sh: ocrd validate tasks $OV --workspace . "tesserocr-recognize -P segmentation_level region -P model frak2021 -I OCR-D-IMG -O OCR-D-OCR" "fileformat-transform -P from-to \"page alto\" -P script-args \"--no-check-border --dummy-word\" -I OCR-D-OCR -O FULLTEXT" #015
2024-02-23T17:12:44.931909600Z Feb 23 17:12:44 ocrd-manager process_images.sh: ocrd process $OV "tesserocr-recognize -P segmentation_level region -P model frak2021 -I OCR-D-IMG -O OCR-D-OCR" "fileformat-transform -P from-to \"page alto\" -P script-args \"--no-check-border --dummy-word\" -I OCR-D-OCR -O FULLTEXT" #015
2024-02-23T17:12:44.931912684Z Feb 23 17:12:44 ocrd-manager process_images.sh: /data$ set -Ee#015
2024-02-23T17:12:44.931915066Z Feb 23 17:12:44 ocrd-manager process_images.sh: /data$ cd 'KitodoJob_91_testdata-kitodo'#015
2024-02-23T17:12:44.931917346Z Feb 23 17:12:44 ocrd-manager process_images.sh: /data/KitodoJob_91_testdata-kitodo$ echo $$ > ocrd.pid#015
2024-02-23T17:12:44.931919862Z Feb 23 17:12:44 ocrd-manager process_images.sh: /data/KitodoJob_91_testdata-kitodo$ #015<n OV=--overwrite; else OV=; ocrd-import -j 1 -i; fi#015
2024-02-23T17:12:47.932406598Z Feb 23 17:12:47 ocrd-manager process_images.sh: 17:12:47.241 INFO ocrd.resolver.workspace_from_nothing - Writing METS to /data/KitodoJob_91_testdata-kitodo/mets.xml#015
2024-02-23T17:12:47.932428400Z Feb 23 17:12:47 ocrd-manager process_images.sh: /data/KitodoJob_91_testdata-kitodo#015
2024-02-23T17:12:49.932654074Z Feb 23 17:12:48 ocrd-manager process_images.sh: Traceback (most recent call last):#015
2024-02-23T17:12:49.932683532Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/bin/ocrd", line 8, in <module>#015
2024-02-23T17:12:49.932687943Z Feb 23 17:12:48 ocrd-manager process_images.sh:     sys.exit(cli())#015
2024-02-23T17:12:49.932690835Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1157, in __call__#015
2024-02-23T17:12:49.932693810Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return self.main(*args, **kwargs)#015
2024-02-23T17:12:49.932696434Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1078, in main#015
2024-02-23T17:12:49.932699308Z Feb 23 17:12:48 ocrd-manager process_images.sh:     rv = self.invoke(ctx)#015
2024-02-23T17:12:49.932701705Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1688, in invoke#015
2024-02-23T17:12:49.932704398Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return _process_result(sub_ctx.command.invoke(sub_ctx))#015
2024-02-23T17:12:49.932706839Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1688, in invoke#015
2024-02-23T17:12:49.932709546Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return _process_result(sub_ctx.command.invoke(sub_ctx))#015
2024-02-23T17:12:49.932712114Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 1434, in invoke#015
2024-02-23T17:12:49.932727189Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return ctx.invoke(self.callback, **ctx.params)#015
2024-02-23T17:12:49.932730349Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 783, in invoke#015
2024-02-23T17:12:49.932733035Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return __callback(*args, **kwargs)#015
2024-02-23T17:12:49.932735526Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/decorators.py", line 92, in new_func#015
2024-02-23T17:12:49.932738530Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return ctx.invoke(f, obj, *args, **kwargs)#015
2024-02-23T17:12:49.932742360Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/click/core.py", line 783, in invoke#015
2024-02-23T17:12:49.932745175Z Feb 23 17:12:48 ocrd-manager process_images.sh:     return __callback(*args, **kwargs)#015
2024-02-23T17:12:49.932748117Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/ocrd/cli/workspace.py", line 484, in workspace_find#015
2024-02-23T17:12:49.932750853Z Feb 23 17:12:48 ocrd-manager process_images.sh:     pages = workspace.mets.get_physical_pages(for_fileIds=fileIds)#015
2024-02-23T17:12:49.932753401Z Feb 23 17:12:48 ocrd-manager process_images.sh:   File "/usr/local/lib/python3.8/site-packages/ocrd_models/ocrd_mets.py", line 696, in get_physical_pages#015
2024-02-23T17:12:49.932756084Z Feb 23 17:12:48 ocrd-manager process_images.sh:     assert for_fileIds # at this point we know for_fileIds is set, assert to convince pyright#015
2024-02-23T17:12:49.932758602Z Feb 23 17:12:48 ocrd-manager process_images.sh: AssertionError#015
2024-02-23T17:12:49.932761006Z Feb 23 17:12:49 ocrd-manager process_images.sh: Connection to ocrd-controller closed.#015
2024-02-23T17:12:49.932763491Z Feb 23 17:12:49 ocrd-manager process_images.sh: terminating with error $?=129 from ssh -tt -p "${CONTROLLERPORT}" ocrd@${CONTROLLERHOST} 2>&1 on line 138 /usr/bin/ocrd_lib.sh
2024-02-23T17:12:49.932766434Z Feb 23 17:12:49 ocrd-manager process_images.sh: WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
2024-02-23T17:12:49.932768992Z Feb 23 17:12:49 ocrd-manager process_images.sh: 2024-02-23 17:12:49 INFO  KitodoActiveMQClient:76 - Sending of message for taskId='1' was successful
2024-02-23T17:12:49.932771625Z Feb 23 17:12:49 2024-02-23 17: 12:49 INFO  KitodoActiveMQClient:76 - Sending of message for taskId='1' was successful
2024-02-23T17:12:50.933192826Z Feb 23 17:12:50 ocrd-manager process_images.sh: {
2024-02-23T17:12:50.933267048Z Feb 23 17:12:50 ocrd-manager process_images.sh:   _id: ObjectId("65d8d20aa1d63d842e4cd3bb"),
2024-02-23T17:12:50.933287308Z Feb 23 17:12:50 ocrd-manager process_images.sh:   pid: 91,
2024-02-23T17:12:50.933300746Z Feb 23 17:12:50 ocrd-manager process_images.sh:   time_created: ISODate("2024-02-23T17:12:42.000Z"),
2024-02-23T17:12:50.933362766Z Feb 23 17:12:50 ocrd-manager process_images.sh:   process_id: 'testdata-kitodo',
2024-02-23T17:12:50.933378095Z Feb 23 17:12:50 ocrd-manager process_images.sh:   task_id: '1',
2024-02-23T17:12:50.933392016Z Feb 23 17:12:50 ocrd-manager process_images.sh:   process_dir: '/data/testdata-kitodo',
2024-02-23T17:12:50.933406321Z Feb 23 17:12:50 ocrd-manager process_images.sh:   workdir: 'ocr-d//data/testdata-kitodo',
2024-02-23T17:12:50.933418506Z Feb 23 17:12:50 ocrd-manager process_images.sh:   remotedir: 'KitodoJob_91_testdata-kitodo',
2024-02-23T17:12:50.933431287Z Feb 23 17:12:50 ocrd-manager process_images.sh:   workflow_file: '/workflows/ocr-workflow-default.sh',
2024-02-23T17:12:50.933443297Z Feb 23 17:12:50 ocrd-manager process_images.sh:   controller_address: 'ocrd-controller:22'
2024-02-23T17:12:50.933454902Z Feb 23 17:12:50 ocrd-manager process_images.sh: }
2024-02-23T17:12:50.933466197Z Feb 23 17:12:50 ocrd-manager process_images.sh: null

[bertsky]

Thanks for digging this out!

See OCR-D/core#1192