NatLibFi / Annif

Annif is a multi-algorithm automated subject indexing tool for libraries, archives and museums.
https://annif.org
Other
195 stars 41 forks source link

Add log message indicating finishing projects initialization #671

Closed juhoinkinen closed 1 year ago

juhoinkinen commented 1 year ago

By looking at the logs from e.g. OpenShift environment it can be hard to see if Annif pod/container has booted or models are still being loaded. In error situations while Annif is in boot loop (or it seems so) it would be good to easily know from the logs if/when Annif has started.

This PR adds an info level message finished initializing projects to log stream for addressing the mentioned concern. For this, it was necessary to also do the basic configuration for the root logger and set log level to "info" (was "unset") for "annif" logger. This makes all log messages from Annif to show also the level and the logger name.

For example:

[2023-02-07 16:12:22 +0200] [460823] [INFO] Starting gunicorn 20.1.0
[2023-02-07 16:12:22 +0200] [460823] [INFO] Listening at: http://0.0.0.0:8000 (460823)
[2023-02-07 16:12:22 +0200] [460823] [INFO] Using worker: sync
[2023-02-07 16:12:22 +0200] [460825] [INFO] Booting worker with pid: 460825
2023-02-07T14:12:26.030Z INFO [omikuji::model] Loading model from data/projects/omikuji-parabel-fi/omikuji-model...
2023-02-07T14:12:26.030Z INFO [omikuji::model] Loading model settings from data/projects/omikuji-parabel-fi/omikuji-model/settings.json...
2023-02-07T14:12:26.030Z INFO [omikuji::model] Loaded model settings Settings { n_features: 329277, classifier_loss_type: Hinge }...
2023-02-07T14:12:26.030Z INFO [omikuji::model] Loading tree from data/projects/omikuji-parabel-fi/omikuji-model/tree2.cbor...
2023-02-07T14:12:28.830Z INFO [omikuji::model] Loading tree from data/projects/omikuji-parabel-fi/omikuji-model/tree0.cbor...
2023-02-07T14:12:31.534Z INFO [omikuji::model] Loading tree from data/projects/omikuji-parabel-fi/omikuji-model/tree1.cbor...
2023-02-07T14:12:34.281Z INFO [omikuji::model] Loaded model with 3 trees; it took 8.25s
WARNING:annif:Couldn't initialize backend 'omikuji': vectorizer file 'data/projects/omikuji-parabel-sv/vectorizer' not found
WARNING:annif:Couldn't initialize backend 'omikuji': vectorizer file 'data/projects/omikuji-parabel-en/vectorizer' not found
INFO:annif:finished initializing projects

The gunicorn and Omikuji log messages have also timestamps, but they are actually more distracting than helpful when logs are read in Kibana (especially), because there is a dedicated timestamp field for every message.

sonarcloud[bot] commented 1 year ago

SonarCloud Quality Gate failed.    Quality Gate failed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot E 1 Security Hotspot
Code Smell A 0 Code Smells

No Coverage information No Coverage information
0.0% 0.0% Duplication

codecov[bot] commented 1 year ago

Codecov Report

Base: 99.56% // Head: 99.12% // Decreases project coverage by -0.44% :warning:

Coverage data is based on head (2ed3f03) compared to base (1c587bd). Patch coverage: 100.00% of modified lines in pull request are covered.

Additional details and impacted files ```diff @@ Coverage Diff @@ ## master #671 +/- ## ========================================== - Coverage 99.56% 99.12% -0.44% ========================================== Files 87 87 Lines 6142 6145 +3 ========================================== - Hits 6115 6091 -24 - Misses 27 54 +27 ``` | [Impacted Files](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi) | Coverage Δ | | |---|---|---| | [annif/\_\_init\_\_.py](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi#diff-YW5uaWYvX19pbml0X18ucHk=) | `89.65% <100.00%> (+1.19%)` | :arrow_up: | | [tests/test\_backend\_fasttext.py](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi#diff-dGVzdHMvdGVzdF9iYWNrZW5kX2Zhc3R0ZXh0LnB5) | `100.00% <100.00%> (ø)` | | | [annif/analyzer/voikko.py](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi#diff-YW5uaWYvYW5hbHl6ZXIvdm9pa2tvLnB5) | `10.52% <0.00%> (-89.48%)` | :arrow_down: | | [tests/test\_analyzer\_voikko.py](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi#diff-dGVzdHMvdGVzdF9hbmFseXplcl92b2lra28ucHk=) | `25.00% <0.00%> (-75.00%)` | :arrow_down: | | [annif/analyzer/\_\_init\_\_.py](https://codecov.io/gh/NatLibFi/Annif/pull/671?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi#diff-YW5uaWYvYW5hbHl6ZXIvX19pbml0X18ucHk=) | `90.32% <0.00%> (-3.23%)` | :arrow_down: | Help us with your feedback. Take ten seconds to tell us [how you rate us](https://about.codecov.io/nps?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi). Have a feature suggestion? [Share it here.](https://app.codecov.io/gh/feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=NatLibFi)

:umbrella: View full report at Codecov.
:loudspeaker: Do you have feedback about the report comment? Let us know in this issue.