feat: extend logging in db.py and dbview.py

[thinkh]

Developer Checklist (Definition of Done)

Issue

• All acceptance criteria from the issue are met
• Tested in latest Chrome/Firefox

UI/UX/Vis

• Requires UI/UX/Vis review
  • Reviewer(s) are notified (tag assignees)
  • Review has occurred (link to notes)
  • Feedback is included in this PR
  • Reviewer(s) approve of concept and design

Code

• Branch is up-to-date with the branch to be merged with, i.e., develop
• Code is cleaned up and formatted
• Unit tests are written (frontend/backend if applicable)
• Integration tests are written (if applicable)

PR

• Descriptive title for this pull request is provided (will be used for release notes later)
• Reviewer and assignees are defined
• Add type label (e.g., bug, feature) to this pull request
• Add release label (e.g., release: minor) to this PR following semver
• The PR is connected to the corresponding issue (via Closes #...)
• Summary of changes is written

Summary of changes

• Add further logging to db.py and dbview.py

Enable the debug logs via env variable VISYN_CORE__LOG_LEVEL=DEBUG or in visyn_core.log_level the config.json:

{
    "visyn_core": {
        "log_level": "DEBUG"
    }
}

Screenshots

Example:

ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - engine status before: Pool size: 30  Connections in pool: 1 Current Overflow: -27 Current Checked out connections: 2
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - creating session
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - session created
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - supports array parameter: True
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - GET DATA with session
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | set statement_timeout to '5min'
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - replace array parameter in sql query: set statement_timeout to '5min'
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | a8c85c7d-2e97-4e91-8dd7-31ed5628cb39 - execute the given query with the given args: set statement_timeout to '5min'
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | set statement_timeout to '5min' ({})
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | d6ff6071-f63c-4921-9567-709fcff69e00 - ran sql statement: 
ordino_public-api-1          |   SELECT panel as id, paneldescription as description, species
ordino_public-api-1          |   FROM cellline.tdp_panel ORDER BY panel ASC
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | d6ff6071-f63c-4921-9567-709fcff69e00 - GET DATA after run
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | d6ff6071-f63c-4921-9567-709fcff69e00 - removing session
ordino_public-api-1          | DEBUG:    2023-07-24 12:29:57 |                    tdp_core.db | d6ff6071-f63c-4921-9567-709fcff69e00 - removed session

Additional notes for the reviewer(s)

@puehringer I added my logs with the log level DEBUG. Is it ok like this or should I add a separate flag to the tdp_core settings to enable the very specific case of logging db.py and dbview.py?

---

Thanks for creating this pull request 🤗

[thinkh]

@puehringer Is there a way to enable debug logging without passing the whole logging config?

Setting VISYN_CORE__LOGGING__ROOT__LEVEL=DEBUG gives me this error:

ordino_public-api-1          | INFO:     2023-07-24 12:32:46 |      visyn_core.settings.utils | Loading workspace config.json from /phovea/config.json
ordino_public-api-1          | Traceback (most recent call last):
ordino_public-api-1          |   File "/usr/local/lib/python3.10/runpy.py", line 196, in _run_module_as_main
ordino_public-api-1          |     return _run_code(code, main_globals, None,
ordino_public-api-1          |   File "/usr/local/lib/python3.10/runpy.py", line 86, in _run_code
ordino_public-api-1          |     exec(code, run_globals)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/__main__.py", line 4, in <module>
ordino_public-api-1          |     uvicorn.main()
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/click/core.py", line 1157, in __call__
ordino_public-api-1          |     return self.main(*args, **kwargs)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/click/core.py", line 1078, in main
ordino_public-api-1          |     rv = self.invoke(ctx)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/click/core.py", line 1434, in invoke
ordino_public-api-1          |     return ctx.invoke(self.callback, **ctx.params)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/click/core.py", line 783, in invoke
ordino_public-api-1          |     return __callback(*args, **kwargs)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/main.py", line 404, in main
ordino_public-api-1          |     run(
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/main.py", line 569, in run
ordino_public-api-1          |     server.run()
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/server.py", line 60, in run
ordino_public-api-1          |     return asyncio.run(self.serve(sockets=sockets))
ordino_public-api-1          |   File "/usr/local/lib/python3.10/asyncio/runners.py", line 44, in run
ordino_public-api-1          |     return loop.run_until_complete(main)
ordino_public-api-1          |   File "uvloop/loop.pyx", line 1517, in uvloop.loop.Loop.run_until_complete
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/server.py", line 67, in serve
ordino_public-api-1          |     config.load()
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/config.py", line 477, in load
ordino_public-api-1          |     self.loaded_app = import_from_string(self.app)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/uvicorn/importer.py", line 21, in import_from_string
ordino_public-api-1          |     module = importlib.import_module(module_str)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/importlib/__init__.py", line 126, in import_module
ordino_public-api-1          |     return _bootstrap._gcd_import(name[level:], package, level)
ordino_public-api-1          |   File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
ordino_public-api-1          |   File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
ordino_public-api-1          |   File "<frozen importlib._bootstrap>", line 1006, in _find_and_load_unlocked
ordino_public-api-1          |   File "<frozen importlib._bootstrap>", line 688, in _load_unlocked
ordino_public-api-1          |   File "<frozen importlib._bootstrap_external>", line 883, in exec_module
ordino_public-api-1          |   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
ordino_public-api-1          |   File "/phovea/tdp_core/tdp_core/server/main.py", line 4, in <module>
ordino_public-api-1          |     app: FastAPI = create_visyn_server()
ordino_public-api-1          |   File "/usr/local/lib/python3.10/site-packages/visyn_core/server/visyn_server.py", line 45, in create_visyn_server
ordino_public-api-1          |     logging.config.dictConfig(manager.settings.visyn_core.logging)
ordino_public-api-1          |   File "/usr/local/lib/python3.10/logging/config.py", line 811, in dictConfig
ordino_public-api-1          |     dictConfigClass(config).configure()
ordino_public-api-1          |   File "/usr/local/lib/python3.10/logging/config.py", line 498, in configure
ordino_public-api-1          |     raise ValueError("dictionary doesn't specify a version")
ordino_public-api-1          | ValueError: dictionary doesn't specify a version
ordino_public-api-1 exited with code 1

[puehringer]

@thinkh

Currently failing python build

We maybe should pin pyright, as it often comes to these patch version which break the build: https://github.com/datavisyn/tdp_core/blob/develop/requirements_dev.txt#L2

VISYN_CORE__LOGGING__ROOT__LEVEL=DEBUG doesn't work ...

because the logging key is typed as dict: https://github.com/datavisyn/visyn_core/blob/develop/visyn_core/settings/model.py#L169
It would only work if you provide a proper Pydantic model for the entire logging config (have fun...). Therefore, it's simply not possible to do these "partial" overrides.

However, we could think about adding a second setting (like log_level, default None), and if it is set we "inject"/merge it into the logging setting? Or we add a second setting which is deep-merged. How does that sound?

[thinkh]

Thanks for the hint for the pyright dependency.

Yes, good idea. The most common change is probably the debug level. So let's add an option to it and merge/override it into the default logging config if set. I'll file a PR in visyn_core.

[thinkh]

Here you go: datavisyn/visyn_core#69