search

Project-MONAI / MONAILabel

MONAI Label is an intelligent open source image labeling and learning tool.
https://docs.monai.io/projects/label
Apache License 2.0
624 stars 196 forks source link

MONAILabel Annotation job fails on _name_to_id - Digital Slide Archive (DSA) integration #1470

Closed qritive-aahan closed 1 year ago

qritive-aahan commented 1 year ago

As discussed in #1191 The issue is not resolved in the newest versions of MONAI Label. I am using the most recent version of DSA and Monai Label. I encounter the same error as mentioned in #1191. Any help is appreciated, thank you.

Describe the bug Same as #1191 The issue is with MONAILabel annotation failing on line 149 in monailabel/datastore/dsa.py due to the self._name_to_id method. Error type is ValueError: too many values to unpack (expected 2)

Server logs Same as #1191

To Reproduce Followed instructions here to install MONAILabel for the DSA viewer.

Environment

Ensuring you use the relevant python executable, please paste the output of:

python -c 'import monai; monai.config.print_debug_info()'
===============================
Printing MONAI config...
================================
MONAI version: 1.2.0
Numpy version: 1.24.1
Pytorch version: 1.12.1+cu113
MONAI flags: HAS_EXT = False, USE_COMPILED = False, USE_META_DICT = False
MONAI rev id: c33f1ba588ee00229a309000e888f9817b4f1934
MONAI __file__: /home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/monai-1.2.0-py3.9.egg/monai/__init__.py

Optional dependencies:
Pytorch Ignite version: 0.4.11
ITK version: 5.3.0
Nibabel version: 5.1.0
scikit-image version: 0.19.3
Pillow version: 9.3.0
Tensorboard version: 2.11.0
gdown version: 4.7.1
TorchVision version: 0.13.1+cu113
tqdm version: 4.64.1
lmdb version: 1.4.1
psutil version: 5.9.4
pandas version: 2.0.0
einops version: 0.6.1
transformers version: NOT INSTALLED or UNKNOWN VERSION.
mlflow version: 2.4.1
pynrrd version: 1.0.0

For details about installing the optional dependencies, please visit:
    https://docs.monai.io/en/latest/installation.html#installing-the-recommended-dependencies

================================
Printing system config...
================================
System: Linux
Linux version: Ubuntu 18.04.5 LTS
Platform: Linux-5.4.0-1072-aws-x86_64-with-glibc2.27
Processor: x86_64
Machine: x86_64
Python version: 3.9.16
Process name: python
Command: ['python', '-c', 'import monai; monai.config.print_debug_info()']
Open files: []
Num physical CPUs: 4
Num logical CPUs: 8
Num usable CPUs: 8
CPU usage (%): [28.9, 11.8, 11.2, 8.7, 11.1, 96.5, 9.1, 99.0]
CPU freq. (MHz): 3143
Load avg. in last 1, 5, 15 mins (%): [18.4, 14.8, 14.0]
Disk usage (%): 58.3
Avg. sensor temp. (Celsius): UNKNOWN for given OS
Total physical memory (GB): 30.9
Available memory (GB): 21.6
Used memory (GB): 8.9

================================
Printing GPU config...
================================
Num GPUs: 1
Has CUDA: True
CUDA version: 11.3
cuDNN enabled: True
cuDNN version: 8302
Current device: 0
Library compiled for CUDA architectures: ['sm_37', 'sm_50', 'sm_60', 'sm_70', 'sm_75', 'sm_80', 'sm_86']
GPU 0 Name: Tesla T4
GPU 0 Is integrated: False
GPU 0 Is multi GPU board: False
GPU 0 Multi processor count: 40
GPU 0 Total memory (GB): 14.8
GPU 0 CUDA capability (maj.min): 7.5

Additional context Unlike #1191 I am using ubuntu-18.04.

SachidanandAlle commented 1 year ago

How about the monailabel plugin for DSA? Docker version?

qritive-aahan commented 1 year ago

Yes, the plugin is the docker image: projectmonai/monailabel-dsa:latest The monai label server running is via the cli using the following command: ./monailabel/scripts/monailabel start_server --app sample-apps/pathology/ --studies http://0.0.0.0:8081/api/v1 --conf preload true (i am running dsa on port 8081, hence the change in the studies param from the default 8080)

SachidanandAlle commented 1 year ago

Can you share both MONAI Server and Plugin logs... if the problem is similar to https://github.com/Project-MONAI/MONAILabel/issues/1191 then it should have got resolved after upgrading the docker plugin

SachidanandAlle commented 1 year ago

Also as I reported the problem happened due to: girder_client.HttpError: HTTP error 400: GET http://0.0.0.0:8080/api/v1/item/sample-image

the fetch from DSA server failed.. hence you are seeing this problem.. lets make sure the URI is accessible for MONAI Label server (API Key, access permission etc.. all are correct and configured)

qritive-aahan commented 1 year ago

Can you share both MONAI Server and Plugin logs... if the problem is similar to #1191 then it should have got resolved after upgrading the docker plugin

Here are the logs for the monai label server:

Using PYTHONPATH=/home/ubuntu/git_projects/MONAILabel

[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: version = False
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: app = /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: studies = http://0.0.0.0:8081/api/v1
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: verbose = INFO
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: conf = [['preload', 'true']]
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: host = 0.0.0.0
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: port = 8000
[2023-06-13 08:03:56,217] [30353] [MainThread] [INFO] (__main__:285) - USING:: uvicorn_app = monailabel.app:app
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: ssl_keyfile = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: ssl_certfile = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: ssl_keyfile_password = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: ssl_ca_certs = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: workers = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: limit_concurrency = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: access_log = False
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: root_path = /
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: log_level = info
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: log_config = None
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: dryrun = False
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:285) - USING:: action = start_server
[2023-06-13 08:03:56,218] [30353] [MainThread] [INFO] (__main__:296) - 
[2023-06-13 08:04:04,702] [30353] [MainThread] [INFO] (uvicorn.error:74) - Started server process [30353]
[2023-06-13 08:04:04,703] [30353] [MainThread] [INFO] (uvicorn.error:48) - Waiting for application startup.
[2023-06-13 08:04:04,703] [30353] [MainThread] [INFO] (monailabel.interfaces.utils.app:37) - Initializing App from: /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology; studies: http://0.0.0.0:8081/api/v1; conf: {'preload': 'true'}
[2023-06-13 08:04:05,984] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:57) - Subclass for MONAILabelApp Found: <class 'main.MyApp'>
[2023-06-13 08:04:06,246] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:57) - Subclass for TaskConfig Found: <class 'lib.configs.classification_nuclei.ClassificationNuclei'>
[2023-06-13 08:04:06,269] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:57) - Subclass for TaskConfig Found: <class 'lib.configs.hovernet_nuclei.HovernetNuclei'>
[2023-06-13 08:04:06,293] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:57) - Subclass for TaskConfig Found: <class 'lib.configs.nuclick.NuClick'>
[2023-06-13 08:04:06,317] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:57) - Subclass for TaskConfig Found: <class 'lib.configs.segmentation_nuclei.SegmentationNuclei'>
[2023-06-13 08:04:06,317] [30353] [MainThread] [INFO] (main:83) - +++ Adding Model: classification_nuclei => lib.configs.classification_nuclei.ClassificationNuclei
[2023-06-13 08:04:06,318] [30353] [MainThread] [INFO] (main:83) - +++ Adding Model: hovernet_nuclei => lib.configs.hovernet_nuclei.HovernetNuclei
[2023-06-13 08:04:06,318] [30353] [MainThread] [INFO] (main:83) - +++ Adding Model: nuclick => lib.configs.nuclick.NuClick
[2023-06-13 08:04:06,318] [30353] [MainThread] [INFO] (main:83) - +++ Adding Model: segmentation_nuclei => lib.configs.segmentation_nuclei.SegmentationNuclei
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (main:87) - +++ Using Models: ['classification_nuclei', 'hovernet_nuclei', 'nuclick', 'segmentation_nuclei']
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (monailabel.interfaces.app:135) - Init Datastore for: http://0.0.0.0:8081/api/v1
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (main:106) - Using DSA Server: http://0.0.0.0:8081/api/v1
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (monailabel.datastore.dsa:45) - DSA:: Api Url: http://0.0.0.0:8081/api/v1
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (monailabel.datastore.dsa:46) - DSA:: Api Key: 
[2023-06-13 08:04:06,411] [30353] [MainThread] [INFO] (monailabel.datastore.dsa:47) - DSA:: Folder (Images): None
[2023-06-13 08:04:06,412] [30353] [MainThread] [INFO] (monailabel.datastore.dsa:48) - DSA:: Annotation Groups: None
[2023-06-13 08:04:06,412] [30353] [MainThread] [INFO] (monailabel.datastore.dsa:49) - DSA:: Local Asset Store Path: None
[2023-06-13 08:04:08,362] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:117) - Preload Network for device: cuda
[2023-06-13 08:04:08,362] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:418) - Infer model path: /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology/model/pathology_nuclei_classification/models/model.pt
[2023-06-13 08:04:12,044] [30353] [MainThread] [INFO] (main:129) - +++ Adding Inferer:: classification_nuclei => <lib.infers.classification_nuclei.ClassificationNuclei object at 0x7fdfcbc997f0>
[2023-06-13 08:04:12,047] [30353] [MainThread] [INFO] (monailabel.utils.others.class_utils:33) - Remove/Reload previous Modules: ['scripts', 'scripts.handlers', 'scripts.writer']
[2023-06-13 08:04:12,692] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:117) - Preload Network for device: cuda
[2023-06-13 08:04:12,692] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:418) - Infer model path: /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology/model/pathology_nuclei_segmentation_classification/models/model.pt
[2023-06-13 08:04:18,332] [30353] [MainThread] [INFO] (main:129) - +++ Adding Inferer:: hovernet_nuclei => <lib.infers.hovernet_nuclei.HovernetNuclei object at 0x7fdfcb2cc430>
[2023-06-13 08:04:18,456] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:117) - Preload Network for device: cuda
[2023-06-13 08:04:18,456] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:418) - Infer model path: /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology/model/pathology_nuclick_annotation/models/model.pt
[2023-06-13 08:04:19,451] [30353] [MainThread] [INFO] (main:129) - +++ Adding Inferer:: nuclick => <lib.infers.nuclick.NuClick object at 0x7fdfcb2cc460>
[2023-06-13 08:04:19,451] [30353] [MainThread] [INFO] (lib.configs.segmentation_nuclei:88) - Using Preload: True; ROI Size: [1024, 1024]
[2023-06-13 08:04:19,451] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:117) - Preload Network for device: cuda
[2023-06-13 08:04:19,452] [30353] [MainThread] [INFO] (monailabel.tasks.infer.basic_infer:418) - Infer model path: /home/ubuntu/git_projects/MONAILabel/sample-apps/pathology/model/pretrained_segmentation_nuclei_consep.pt
[2023-06-13 08:04:20,543] [30353] [MainThread] [INFO] (main:129) - +++ Adding Inferer:: segmentation_nuclei => <lib.infers.segmentation_nuclei.SegmentationNuclei object at 0x7fdfc063ff40>
[2023-06-13 08:04:20,560] [30353] [MainThread] [INFO] (main:153) - +++ Adding Trainer:: classification_nuclei => <lib.trainers.classification_nuclei.ClassificationNuclei object at 0x7fdfc05d1730>
[2023-06-13 08:04:20,600] [30353] [MainThread] [INFO] (main:153) - +++ Adding Trainer:: hovernet_nuclei => <lib.trainers.hovernet_nuclei.HovernetNuclei object at 0x7fdfc02ccfa0>
[2023-06-13 08:04:20,614] [30353] [MainThread] [INFO] (main:153) - +++ Adding Trainer:: nuclick => <lib.trainers.nuclick.NuClick object at 0x7fdfc038c340>
[2023-06-13 08:04:20,614] [30353] [MainThread] [INFO] (main:153) - +++ Adding Trainer:: segmentation_nuclei => <lib.trainers.segmentation_nuclei.SegmentationNuclei object at 0x7fdfc0184dc0>
[2023-06-13 08:04:20,615] [30353] [MainThread] [INFO] (main:174) - Active Learning Strategies:: ['wsi_random']
[2023-06-13 08:04:20,615] [30353] [MainThread] [INFO] (monailabel.utils.sessions:51) - Session Path: /home/ubuntu/.cache/monailabel/sessions
[2023-06-13 08:04:20,615] [30353] [MainThread] [INFO] (monailabel.utils.sessions:52) - Session Expiry (max): 3600
[2023-06-13 08:04:20,615] [30353] [MainThread] [INFO] (monailabel.interfaces.app:469) - App Init - completed
Allow Origins: ['*']
BasicUNet features: (32, 64, 128, 256, 512, 32).
BasicUNet features: (32, 64, 128, 256, 512, 32).
[2023-06-13 08:04:20,615] [timeloop] [INFO] Starting Timeloop..
[2023-06-13 08:04:20,615] [30353] [MainThread] [INFO] (timeloop:60) - Starting Timeloop..
[2023-06-13 08:04:20,616] [timeloop] [INFO] Registered job <function MONAILabelApp.on_init_complete.<locals>.run_scheduler at 0x7fdfcad5a820>
[2023-06-13 08:04:20,616] [30353] [MainThread] [INFO] (timeloop:42) - Registered job <function MONAILabelApp.on_init_complete.<locals>.run_scheduler at 0x7fdfcad5a820>
[2023-06-13 08:04:20,616] [timeloop] [INFO] Timeloop now started. Jobs will run based on the interval set
[2023-06-13 08:04:20,616] [30353] [MainThread] [INFO] (timeloop:63) - Timeloop now started. Jobs will run based on the interval set
[2023-06-13 08:04:20,616] [30353] [MainThread] [INFO] (uvicorn.error:62) - Application startup complete.
[2023-06-13 08:04:20,616] [30353] [MainThread] [INFO] (uvicorn.error:217) - Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
[2023-06-13 08:13:05,024] [30353] [MainThread] [INFO] (monailabel.endpoints.wsi_infer:109) - WSI Infer Request: {'model': 'segmentation_nuclei', 'image': 'test-slide', 'output': 'dsa', 'level': 0, 'location': [27188, 16448], 'size': [2544, 2118], 'tile_size': [1024, 1024], 'min_poly_area': 80, 'wsi_tiles': []}
[2023-06-13 08:13:05,048] [30353] [MainThread] [ERROR] (uvicorn.error:434) - Exception in ASGI application
Traceback (most recent call last):
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/datastore/dsa.py", line 148, in get_image_uri
    name = self.get_image_info(image_id)["name"]
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/datastore/dsa.py", line 175, in get_image_info
    return self.gc.getItem(image_id)  # type: ignore
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/girder_client-3.1.17-py3.9.egg/girder_client/__init__.py", line 619, in getItem
    return self.getResource('item', itemId)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/girder_client-3.1.17-py3.9.egg/girder_client/__init__.py", line 519, in getResource
    return self.get(route)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/girder_client-3.1.17-py3.9.egg/girder_client/__init__.py", line 471, in get
    return self.sendRestRequest('GET', path, parameters, jsonResp=jsonResp)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/girder_client-3.1.17-py3.9.egg/girder_client/__init__.py", line 463, in sendRestRequest
    raise HttpError(
girder_client.HttpError: HTTP error 400: GET http://0.0.0.0:8081/api/v1/item/test-slide
Response text: {"field": "id", "message": "Invalid ObjectId: test-slide", "type": "validation"}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/uvicorn-0.21.1-py3.9.egg/uvicorn/protocols/http/h11_impl.py", line 429, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/uvicorn-0.21.1-py3.9.egg/uvicorn/middleware/proxy_headers.py", line 78, in __call__
    return await self.app(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/fastapi-0.95.0-py3.9.egg/fastapi/applications.py", line 276, in __call__
    await super().__call__(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/applications.py", line 122, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/middleware/errors.py", line 184, in __call__
    raise exc
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/middleware/errors.py", line 162, in __call__
    await self.app(scope, receive, _send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/middleware/cors.py", line 84, in __call__
    await self.app(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/middleware/exceptions.py", line 79, in __call__
    raise exc
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/middleware/exceptions.py", line 68, in __call__
    await self.app(scope, receive, sender)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/fastapi-0.95.0-py3.9.egg/fastapi/middleware/asyncexitstack.py", line 21, in __call__
    raise e
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/fastapi-0.95.0-py3.9.egg/fastapi/middleware/asyncexitstack.py", line 18, in __call__
    await self.app(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/routing.py", line 718, in __call__
    await route.handle(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/routing.py", line 276, in handle
    await self.app(scope, receive, send)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/starlette-0.26.1-py3.9.egg/starlette/routing.py", line 66, in app
    response = await func(request)
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/fastapi-0.95.0-py3.9.egg/fastapi/routing.py", line 237, in app
    raw_response = await run_endpoint_function(
  File "/home/ubuntu/virtualenvs/env/lib/python3.9/site-packages/fastapi-0.95.0-py3.9.egg/fastapi/routing.py", line 163, in run_endpoint_function
    return await dependant.call(**values)
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/endpoints/wsi_infer.py", line 132, in api_run_wsi_inference
    return run_wsi_inference(background_tasks, model, image, session_id, None, wsi, output)
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/endpoints/wsi_infer.py", line 111, in run_wsi_inference
    result = instance.infer_wsi(request)
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/interfaces/app.py", line 622, in infer_wsi
    image = datastore.get_image_uri(request["image"])
  File "/home/ubuntu/git_projects/MONAILabel/monailabel/datastore/dsa.py", line 151, in get_image_uri
    image_id, name = self._name_to_id(image_id)
ValueError: too many values to unpack (expected 2)

The last few lines of the dsa logs:

girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/item?limit=251&offset=0&sort=name&sortdir=1&folderId=6486c6b2529f199d840f3e3b HTTP/1.1" 200 463 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/folder/6486c6b2529f199d840f3e3b/yaml_config/.large_image_config.yaml HTTP/1.1" 200 4 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/folder/6486c6b2529f199d840f3e3b/details HTTP/1.1" 200 28 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/large_image/settings HTTP/1.1" 200 651 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/histomicsui/settings HTTP/1.1" 200 197 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/system/setting?list=%5B%22slicer_cli_web.task_folder%22%2C%22slicer_cli_web.worker_config_item%22%5D HTTP/1.1" 200 101 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "GET /api/v1/annotation/folder/6486c6b2529f199d840f3e3b/present?recurse=true HTTP/1.1" 200 5 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:40] "POST /api/v1/annotation/counts HTTP/1.1" 200 31 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/item/648823a5a578d247ef8f01f7 HTTP/1.1" 200 461 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/folder/6486c6b2529f199d840f3e3b HTTP/1.1" 200 448 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/item/648823a5a578d247ef8f01f7/files?limit=101&offset=0&sort=name&sortdir=1 HTTP/1.1" 200 319 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/item/648823a5a578d247ef8f01f7/rootpath HTTP/1.1" 200 775 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/annotation/folder/6486c6b2529f199d840f3e3b/create HTTP/1.1" 200 4 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:41] "GET /api/v1/annotation?limit=10001&offset=0&sort=%5B%5B%22updated%22%2C-1%5D%2C%5B%22annotation.updated%22%2C-1%5D%2C%5B%22updated%22%2C1%5D%2C%5B%22annotation.updated%22%2C1%5D%5D&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:42] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles/zxy/0/0/0?_=2023-06-13T08-07-01.178000_00-00 HTTP/1.1" 200 5482 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36" (4 similar messages)
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /histomics HTTP/1.1" 200 3476 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/user/me HTTP/1.1" 200 357 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 57558 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/histomicsui/settings HTTP/1.1" 200 197 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/folder?limit=1&offset=0&sort=name&sortdir=1&parentId=6486b9d17b5e975a6b9dde8b&parentType=user&name=Private HTTP/1.1" 200 440 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7 HTTP/1.1" 200 461 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/notification/stream?since=1686643513 HTTP/1.1" 200 - "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/folder/6486c6b2529f199d840f3e3b/yaml_config/.histomicsui_config.yaml HTTP/1.1" 200 4 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/folder?limit=1&offset=0&sort=name&sortdir=1&parentId=6486b9d17b5e975a6b9dde8b&parentType=user&name=Private HTTP/1.1" 200 440 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/annotation?limit=10001&offset=0&sort=created&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/previous_image HTTP/1.1" 200 471 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/rootpath HTTP/1.1" 200 775 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/item/648823a5a578d247ef8f01f7/next_image HTTP/1.1" 200 471 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/slicer_cli_web/docker_image HTTP/1.1" 200 1905 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/folder/6486c6b2529f199d840f3e3b HTTP/1.1" 200 448 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:43] "GET /api/v1/folder/6486c6b2529f199d840f3e3b HTTP/1.1" 200 448 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:44] "GET /api/v1/folder/6486c6b2529f199d840f3e3b HTTP/1.1" 200 448 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:44] "GET /api/v1/annotation/folder/6486c6b2529f199d840f3e3b/create HTTP/1.1" 200 4 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:44] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles/zxy/4/2/3 HTTP/1.1" 200 1124 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36" (250 similar messages)
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:46] "GET /api/v1/item/648823a5a578d247ef8f01f7 HTTP/1.1" 200 461 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:46] "GET /api/v1/slicer_cli_web/cli/6486c115cb6a65484153c167/xml HTTP/1.1" 200 4916 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/folder?limit=1&offset=0&sort=name&sortdir=1&parentId=6486b9d17b5e975a6b9dde8b&parentType=user&name=Private HTTP/1.1" 200 440 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/folder?limit=1&offset=0&sort=name&sortdir=1&parentId=6486b9d17b5e975a6b9dde8b&parentType=user&name=Private HTTP/1.1" 200 440 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles HTTP/1.1" 200 187 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:47] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:47.772+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":498}}
rabbitmq_1   | 2023-06-13 08:11:47.807873+00:00 [info] <0.670.0> accepting AMQP connection <0.670.0> (172.19.0.6:33012 -> 172.19.0.4:5672)
rabbitmq_1   | 2023-06-13 08:11:47.809508+00:00 [info] <0.670.0> connection <0.670.0> (172.19.0.6:33012 -> 172.19.0.4:5672): user 'guest' authenticated and granted access to vhost '/'
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:48.416+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.job","command":{"insert":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":5,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":601}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:48.984+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":566}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:49.248+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":261}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:50.033+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":783}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:50] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 59067 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:50.437+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":402}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:50.938+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":495}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:51.270+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":326}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:51.675+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":720}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:51] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles/zxy/8/107/65 HTTP/1.1" 200 10546 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36" (250 similar messages)
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:52.105+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{"data":{"bytesRead":8176,"timeReadingMicros":10}},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":833}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:52.652+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":976}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:11:52] "PUT /api/v1/job/648824c3a578d247ef8f01fb HTTP/1.1" 200 791 "" "python-requests/2.31.0"
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:52.962+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":855}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:53] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 59124 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:53.774+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":1091}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:54.056+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":281}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:11:54] "PUT /api/v1/job/648824c3a578d247ef8f01fb HTTP/1.1" 200 791 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:11:54,058: WARNING/ForkPoolWorker-2] [2023-06-13 08:11:52,677] INFO: Running container: image: projectmonai/monailabel-dsa@sha256:01dca09ce6ff80aa681af02e7506a915b172ff8012c0c7ed88113f54175e7ca5 args: ['MONAILabelAnnotation', '--analysis_level', '0', '--analysis_roi', '-1, -1, -1, -1', '--analysis_tile_size', '1024', '--api-url', 'http://girder:8080/api/v1/', '--extra_params', '{}', '--girder-token', 'tnfvUyCzgQTddtofgqlU7utBq0sHN6A7bL6p1tZInSb75PMye9l8c0dpcjDzPJfb', '--min_fgnd_frac', '-1', '--min_poly_area', '80', '--model_name', '__datalist__', '--server', 'http://monai.label.com:8000', 'skip', 'skip'] runtime: None kwargs: {'tty': False, 'volumes': {'/tmp/tmpk22qvxhv': {'bind': '/mnt/girder_worker/b656e545dc984894a1c01dff91829063', 'mode': 'rw'}}, 'detach': True, 'network_mode': 'host'}
worker_1     | [2023-06-13 08:11:52,677: INFO/ForkPoolWorker-2] Running container: image: projectmonai/monailabel-dsa@sha256:01dca09ce6ff80aa681af02e7506a915b172ff8012c0c7ed88113f54175e7ca5 args: ['MONAILabelAnnotation', '--analysis_level', '0', '--analysis_roi', '-1, -1, -1, -1', '--analysis_tile_size', '1024', '--api-url', 'http://girder:8080/api/v1/', '--extra_params', '{}', '--girder-token', 'tnfvUyCzgQTddtofgqlU7utBq0sHN6A7bL6p1tZInSb75PMye9l8c0dpcjDzPJfb', '--min_fgnd_frac', '-1', '--min_poly_area', '80', '--model_name', '__datalist__', '--server', 'http://monai.label.com:8000', 'skip', 'skip'] runtime: None kwargs: {'tty': False, 'volumes': {'/tmp/tmpk22qvxhv': {'bind': '/mnt/girder_worker/b656e545dc984894a1c01dff91829063', 'mode': 'rw'}}, 'detach': True, 'network_mode': 'host'}
rabbitmq_1   | 2023-06-13 08:11:54.252359+00:00 [info] <0.688.0> accepting AMQP connection <0.688.0> (172.19.0.5:41702 -> 172.19.0.4:5672)
rabbitmq_1   | 2023-06-13 08:11:54.254318+00:00 [info] <0.688.0> connection <0.688.0> (172.19.0.5:41702 -> 172.19.0.4:5672): user 'guest' authenticated and granted access to vhost '/'
rabbitmq_1   | 2023-06-13 08:11:54.262863+00:00 [info] <0.706.0> accepting AMQP connection <0.706.0> (172.19.0.5:41704 -> 172.19.0.4:5672)
rabbitmq_1   | 2023-06-13 08:11:54.265081+00:00 [info] <0.706.0> connection <0.706.0> (172.19.0.5:41704 -> 172.19.0.4:5672): user 'guest' authenticated and granted access to vhost '/'
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:55] "GET /api/v1/item/648823a5a578d247ef8f01f7/tiles/zxy/8/111/61 HTTP/1.1" 200 11546 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36" (250 similar messages)
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:11:55] "PUT /api/v1/job/648824c3a578d247ef8f01fb HTTP/1.1" 200 791 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:11:55,122: WARNING/ForkPoolWorker-2] Traceback (most recent call last):
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 174, in <module>
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     main(CLIArgumentParser().parse_args())
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 81, in main
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     return get_model_names(args)
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 75, in get_model_names
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     for model_name in client.info()["models"]:
worker_1     |   File "/opt/monailabel/dsa/cli/client.py", line 47, in info
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     status, response, _ = MONAILabelUtils.http_method("GET", self._server_url, selector)
worker_1     |   File "/opt/monailabel/dsa/cli/client.py", line 282, in http_method
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     conn.request(method, selector, body=body, headers=headers)
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 1285, in request
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     self._send_request(method, url, body, headers, encode_chunked)
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 1331, in _send_request
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     self.endheaders(body, encode_chunked=encode_chunked)
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 1280, in endheaders
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     self._send_output(message_body, encode_chunked=encode_chunked)
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 1040, in _send_output
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     self.send(msg)
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 980, in send
worker_1     | [2023-06-13 08:11:55,134: WARNING/ForkPoolWorker-2]     self.connect()
worker_1     |   File "/usr/local/lib/python3.9/http/client.py", line 946, in connect
worker_1     | [2023-06-13 08:11:55,135: WARNING/ForkPoolWorker-2]     self.sock = self._create_connection(
worker_1     |   File "/usr/local/lib/python3.9/socket.py", line 823, in create_connection
worker_1     | [2023-06-13 08:11:55,135: WARNING/ForkPoolWorker-2]     for res in getaddrinfo(host, port, 0, SOCK_STREAM):
worker_1     |   File "/usr/local/lib/python3.9/socket.py", line 954, in getaddrinfo
worker_1     | [2023-06-13 08:11:55,135: WARNING/ForkPoolWorker-2]     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
worker_1     | socket.gaierror: [Errno -2] Name or service not known
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:56.282+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":1053}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:56.520+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":237}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:11:56] "PUT /api/v1/job/648824c3a578d247ef8f01fb HTTP/1.1" 200 791 "" "python-requests/2.31.0"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:56] "POST /api/v1/slicer_cli_web/cli/6486c115cb6a65484153c167/datalist/model_name HTTP/1.1" 200 3892 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:56.995+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":468}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:11:57.544+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":546}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:11:57] "PUT /api/v1/job/648824c3a578d247ef8f01fb HTTP/1.1" 200 850 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:11:57,546: ERROR/ForkPoolWorker-2] Task slicer_cli_web.girder_worker_plugin.direct_docker_run.run[80f5babd-c20c-4ab4-b208-85dcac99b6af] raised unexpected: DockerException('Non-zero exit code from docker container (1).')
worker_1     | Traceback (most recent call last):
worker_1     |   File "/opt/venv/lib/python3.9/site-packages/celery/app/trace.py", line 477, in trace_task
worker_1     |     R = retval = fun(*args, **kwargs)
worker_1     |   File "/opt/slicer_cli_web/slicer_cli_web/girder_worker_plugin/direct_docker_run.py", line 87, in __call__
worker_1     |     super().__call__(*args, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 337, in __call__
worker_1     |     super(DockerTask, self).__call__(*args, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/task.py", line 154, in __call__
worker_1     |     results = super(Task, self).__call__(*_t_args, **_t_kwargs)
worker_1     |   File "/opt/venv/lib/python3.9/site-packages/celery/app/trace.py", line 760, in __protected_call__
worker_1     |     return self.run(*args, **kwargs)
worker_1     |   File "/opt/slicer_cli_web/slicer_cli_web/girder_worker_plugin/direct_docker_run.py", line 123, in run
worker_1     |     return _docker_run(task, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 405, in _docker_run
worker_1     |     _run_select_loop(task, container, read_streams, write_streams)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 251, in _run_select_loop
worker_1     |     raise DockerException('Non-zero exit code from docker container (%d).' % exit_code)
worker_1     | docker.errors.DockerException: Non-zero exit code from docker container (1).
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:57] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 59183 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:11:58] "GET /api/v1/annotation?limit=10001&offset=0&sort=created&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:17] "GET /api/v1/notification/stream?since=1686643917 HTTP/1.1" 200 - "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /api/v1 HTTP/1.1" 200 2990 "http://localhost:8081/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/docs.css HTTP/1.1" 304 - "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/lib/jquery-1.8.0.min.js HTTP/1.1" 200 92032 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/lib/handlebars-4.0.5.js HTTP/1.1" 200 71504 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/swagger-ui.min.js HTTP/1.1" 200 453076 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/lib/jsoneditor.min.js HTTP/1.1" 200 129835 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /static/built/swagger/girder-swagger.js HTTP/1.1" 304 - "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:20] "GET /api/v1/describe HTTP/1.1" 200 459594 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:36] "GET /api/v1/token/current HTTP/1.1" 200 334 "http://localhost:8081/api/v1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:39] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 59183 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:39] "GET /api/v1/notification/stream?since=1686643917 HTTP/1.1" 200 - "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:39] "GET /api/v1/annotation?limit=10001&offset=0&sort=created&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:47.518+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":563}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:48.018+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":497}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:48.494+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.job","command":{"insert":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":5,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":460}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:49.065+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":569}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:49.423+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":355}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:50.042+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":618}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:50] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 60854 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:50.375+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":331}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:50.970+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":593}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:51.208+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":233}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:51.661+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":677}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:52.065+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"token","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":168,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":855}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:52.875+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":1213}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:12:52] "PUT /api/v1/job/64882500a578d247ef8f0202 HTTP/1.1" 200 810 "" "python-requests/2.31.0"
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:12:52] "GET /api/v1/file/648823a5a578d247ef8f01f8 HTTP/1.1" 200 317 "" "python-requests/2.31.0"
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:12:52] "GET /api/v1/file/648823a5a578d247ef8f01f8/download HTTP/1.1" 200 577361177 "" "python-requests/2.31.0"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:53] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 60911 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:12:53.159+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn13","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"00a77ff3-a35d-4fbd-8c5b-7c4d8d50be57"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48472","protocol":"op_msg","durationMillis":1092}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:53] "POST /api/v1/slicer_cli_web/cli/6486c115cb6a65484153c167/run HTTP/1.1" 200 2510 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:12:53] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 60911 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:13:01] "PUT /api/v1/job/64882500a578d247ef8f0202 HTTP/1.1" 200 810 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:13:01,086: WARNING/ForkPoolWorker-2] [2023-06-13 08:13:01,042] INFO: Running container: image: projectmonai/monailabel-dsa@sha256:01dca09ce6ff80aa681af02e7506a915b172ff8012c0c7ed88113f54175e7ca5 args: ['MONAILabelAnnotation', '--analysis_level', '0', '--analysis_roi', '27188, 16448, 2544, 2118', '--analysis_tile_size', '1024', '--api-url', 'http://0.0.0.0:8081/api/v1', '--extra_params', '{}', '--girder-token', 'yLtWJzoCxoo3gEzN1d80Ri3nHPYLf0J8k0p9ryLi3SkwqiYWNXZiRbBAf70EWhjj', '--min_fgnd_frac', '-1', '--min_poly_area', '80', '--model_name', 'segmentation_nuclei', '--server', 'http://0.0.0.0:8000', '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/test-slide.tiff', '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/MONAILabel Annotations-outputAnnotationFile.anot'] runtime: None kwargs: {'tty': False, 'volumes': {'/tmp/tmpg6boeptu': {'bind': '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607', 'mode': 'rw'}}, 'detach': True, 'network_mode': 'host'}
worker_1     | [2023-06-13 08:13:01,042: INFO/ForkPoolWorker-2] Running container: image: projectmonai/monailabel-dsa@sha256:01dca09ce6ff80aa681af02e7506a915b172ff8012c0c7ed88113f54175e7ca5 args: ['MONAILabelAnnotation', '--analysis_level', '0', '--analysis_roi', '27188, 16448, 2544, 2118', '--analysis_tile_size', '1024', '--api-url', 'http://0.0.0.0:8081/api/v1', '--extra_params', '{}', '--girder-token', 'yLtWJzoCxoo3gEzN1d80Ri3nHPYLf0J8k0p9ryLi3SkwqiYWNXZiRbBAf70EWhjj', '--min_fgnd_frac', '-1', '--min_poly_area', '80', '--model_name', 'segmentation_nuclei', '--server', 'http://0.0.0.0:8000', '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/test-slide.tiff', '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/MONAILabel Annotations-outputAnnotationFile.anot'] runtime: None kwargs: {'tty': False, 'volumes': {'/tmp/tmpg6boeptu': {'bind': '/mnt/girder_worker/a841516fb9074fd9a94653e47a64f607', 'mode': 'rw'}}, 'detach': True, 'network_mode': 'host'}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:04] "GET /api/v1/collection?offset=0&limit=50 HTTP/1.1" 200 253 "" "python-requests/2.28.2"
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:13:04] "PUT /api/v1/job/64882500a578d247ef8f0202 HTTP/1.1" 200 810 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:13:04,937: WARNING/ForkPoolWorker-2] INFO:root:CLI Parameters ...
worker_1     | 
worker_1     | INFO:root:USING:: inputImageFile = /mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/test-slide.tiff
worker_1     | INFO:root:USING:: outputAnnotationFile = /mnt/girder_worker/a841516fb9074fd9a94653e47a64f607/MONAILabel Annotations-outputAnnotationFile.anot
worker_1     | INFO:root:USING:: analysis_level = 0
worker_1     | [2023-06-13 08:13:04,937: WARNING/ForkPoolWorker-2] INFO:root:USING:: analysis_roi = [27188.0, 16448.0, 2544.0, 2118.0]
worker_1     | [2023-06-13 08:13:04,937: WARNING/ForkPoolWorker-2] INFO:root:USING:: analysis_tile_size = 1024.0
worker_1     | [2023-06-13 08:13:04,951: WARNING/ForkPoolWorker-2] INFO:root:USING:: girderApiUrl = http://0.0.0.0:8081/api/v1
worker_1     | INFO:root:USING:: extra_params = {}
worker_1     | INFO:root:USING:: girderToken = yLtWJzoCxoo3gEzN1d80Ri3nHPYLf0J8k0p9ryLi3SkwqiYWNXZiRbBAf70EWhjj
worker_1     | INFO:root:USING:: min_fgnd_frac = -1.0
worker_1     | [2023-06-13 08:13:04,951: WARNING/ForkPoolWorker-2] INFO:root:USING:: min_poly_area = 80.0
worker_1     | [2023-06-13 08:13:04,951: WARNING/ForkPoolWorker-2] INFO:root:USING:: model_name = segmentation_nuclei
worker_1     | INFO:root:USING:: server = http://0.0.0.0:8000
worker_1     | [2023-06-13 08:13:04,951: WARNING/ForkPoolWorker-2] INFO:root:>> Reading input image ... 
worker_1     | [2023-06-13 08:13:04,951: WARNING/ForkPoolWorker-2] INFO:root:Run MONAILabel Task... and collect the annotations: [27188.0, 16448.0] => [2544.0, 2118.0]
worker_1     | INFO:root:For Server Logs click/open:  http://0.0.0.0:8000/logs/?refresh=3
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:04] "GET /api/v1/folder?parentId=6486b9d57b5e975a6b9dde8f&parentType=collection&offset=0&limit=50 HTTP/1.1" 200 455 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:04] "GET /api/v1/item?folderId=6486b9d67b5e975a6b9dde90&limit=0 HTTP/1.1" 200 2 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/collection?offset=0&limit=50 HTTP/1.1" 200 253 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/folder?parentId=6486b9d57b5e975a6b9dde8f&parentType=collection&offset=0&limit=50 HTTP/1.1" 200 455 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/item?folderId=6486b9d67b5e975a6b9dde90&limit=0 HTTP/1.1" 200 2 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/annotation?limit=0 HTTP/1.1" 200 2 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/item/test-slide HTTP/1.1" 400 80 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/collection?offset=0&limit=50 HTTP/1.1" 200 253 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/folder?parentId=6486b9d57b5e975a6b9dde8f&parentType=collection&offset=0&limit=50 HTTP/1.1" 200 455 "" "python-requests/2.28.2"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:05] "GET /api/v1/item?folderId=6486b9d67b5e975a6b9dde90&limit=0 HTTP/1.1" 200 2 "" "python-requests/2.28.2"
worker_1     | [2023-06-13 08:13:05,049: WARNING/ForkPoolWorker-2] Traceback (most recent call last):
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 174, in <module>
worker_1     | [2023-06-13 08:13:05,060: WARNING/ForkPoolWorker-2]     main(CLIArgumentParser().parse_args())
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 168, in main
worker_1     | [2023-06-13 08:13:05,061: WARNING/ForkPoolWorker-2]     fetch_annotations(args, tiles)
worker_1     |   File "/opt/monailabel/dsa/cli/MONAILabelAnnotation/MONAILabelAnnotation.py", line 55, in fetch_annotations
worker_1     | [2023-06-13 08:13:05,061: WARNING/ForkPoolWorker-2]     _, res = client.wsi_infer(model=args.model_name, image_in=image, body=body, output=output)
worker_1     |   File "/opt/monailabel/dsa/cli/client.py", line 188, in wsi_infer
worker_1     | [2023-06-13 08:13:05,061: WARNING/ForkPoolWorker-2]     raise MONAILabelClientException(
worker_1     | cli.client.MONAILabelClientException: (2, "Status: 500; Response: b'Internal Server Error'")
mongodb_1    | {"t":{"$date":"2023-06-13T08:13:05.990+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":784}}
mongodb_1    | {"t":{"$date":"2023-06-13T08:13:06.324+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":332}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:13:06] "PUT /api/v1/job/64882500a578d247ef8f0202 HTTP/1.1" 200 810 "" "python-requests/2.31.0"
mongodb_1    | {"t":{"$date":"2023-06-13T08:13:06.776+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.$cmd","command":{"update":"job","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":2},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":444}}
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:07] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 60970 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
mongodb_1    | {"t":{"$date":"2023-06-13T08:13:07.465+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"girder.notification","command":{"insert":"notification","ordered":true,"writeConcern":{"w":"majority"},"lsid":{"id":{"$uuid":"322695ee-a00f-4d90-9549-12ba6e21bd63"}},"$db":"girder","$readPreference":{"mode":"primary"}},"ninserted":1,"keysInserted":6,"numYields":0,"reslen":45,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":1},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"172.19.0.6:48350","protocol":"op_msg","durationMillis":688}}
girder_1     | 172.19.0.5 - - [13/Jun/2023:08:13:07] "PUT /api/v1/job/64882500a578d247ef8f0202 HTTP/1.1" 200 869 "" "python-requests/2.31.0"
worker_1     | [2023-06-13 08:13:07,468: ERROR/ForkPoolWorker-2] Task slicer_cli_web.girder_worker_plugin.direct_docker_run.run[bc05bc6a-327a-4de3-8c41-864a0b077ee6] raised unexpected: DockerException('Non-zero exit code from docker container (1).')
worker_1     | Traceback (most recent call last):
worker_1     |   File "/opt/venv/lib/python3.9/site-packages/celery/app/trace.py", line 477, in trace_task
worker_1     |     R = retval = fun(*args, **kwargs)
worker_1     |   File "/opt/slicer_cli_web/slicer_cli_web/girder_worker_plugin/direct_docker_run.py", line 87, in __call__
worker_1     |     super().__call__(*args, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 337, in __call__
worker_1     |     super(DockerTask, self).__call__(*args, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/task.py", line 154, in __call__
worker_1     |     results = super(Task, self).__call__(*_t_args, **_t_kwargs)
worker_1     |   File "/opt/venv/lib/python3.9/site-packages/celery/app/trace.py", line 760, in __protected_call__
worker_1     |     return self.run(*args, **kwargs)
worker_1     |   File "/opt/slicer_cli_web/slicer_cli_web/girder_worker_plugin/direct_docker_run.py", line 123, in run
worker_1     |     return _docker_run(task, **kwargs)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 405, in _docker_run
worker_1     |     _run_select_loop(task, container, read_streams, write_streams)
worker_1     |   File "/opt/girder_worker/girder_worker/docker/tasks/__init__.py", line 251, in _run_select_loop
worker_1     |     raise DockerException('Non-zero exit code from docker container (%d).' % exit_code)
worker_1     | docker.errors.DockerException: Non-zero exit code from docker container (1).
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:13:07] "GET /api/v1/annotation?limit=10001&offset=0&sort=created&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:18:42] "GET /api/v1/job?limit=51&offset=0&sort=created&sortdir=-1 HTTP/1.1" 200 60970 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:18:42] "GET /api/v1/notification/stream?since=1686643987 HTTP/1.1" 200 - "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
girder_1     | 172.19.0.1 - - [13/Jun/2023:08:18:42] "GET /api/v1/annotation?limit=10001&offset=0&sort=created&sortdir=-1&itemId=648823a5a578d247ef8f01f7 HTTP/1.1" 200 2 "http://localhost:8081/histomics" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
qritive-aahan commented 1 year ago

Also as I reported the problem happened due to: girder_client.HttpError: HTTP error 400: GET http://0.0.0.0:8080/api/v1/item/sample-image

the fetch from DSA server failed.. hence you are seeing this problem.. lets make sure the URI is accessible for MONAI Label server (API Key, access permission etc.. all are correct and configured)

I did set the girder token in the UI (obtained it from the /token/current api endpoint): image

If this is not the right way to configure the permissions, please advise on the best way to set permissions.

SachidanandAlle commented 1 year ago

On the server side.. you have the similar situation.. it could not fetch the image..

The easiest way is create an API key and use the same while starting the monailabel server..

SachidanandAlle commented 1 year ago

https://github.com/Project-MONAI/MONAILabel/tree/main/plugins/dsa#monailabel-server-configs-for-dsa

but actually best practice is to use via ENV variables.

https://github.com/Project-MONAI/MONAILabel/blob/main/monailabel/config.py#L49 MONAI_LABEL_DATASTORE_API_KEY=xyz

qritive-aahan commented 1 year ago

Fantastic, thanks a lot. Setting the api key while starting the monai label server fixes the issue. I'm closing the issue since its fixed. Thanks a lot :)

SachidanandAlle commented 1 year ago

The grider token generated on browser will not be helpful for the MONAI Label server.. it can be only use for the MONAILabel Plugin due to short-lived token..

MONAILabel server should be able to access DSA anytime.. as the REST API can be invoked on Server by anyone.. and the user token won't be helpful to access the required data (depending on the API/function) from DSA...