Log database failures during plugin registration as errors, not warnings - #1332
Merged
Conversation
Closes the remaining part of yeti-docker#29 (empty Feeds page): every plugin registers itself as a Task document in the database as a side effect of being imported (TaskManager.register_task, called from each plugin module's own top-level code). get_plugins_list() wrapped that import in a bare except Exception, logging any failure at WARNING and moving on -- appropriate for a plugin whose own optional dependency isn't installed, but not for a plugin that imported fine and then failed to register itself because the database rejected or couldn't complete the write. Both cases looked identical in the logs, at a level easy to miss, with no operational distinction between "this feed isn't available in this deployment" and "this feed didn't get created and won't until the process restarts." This was the failure mode behind the reported bug: on a fresh install, if the database becomes reachable only partway through the plugin import phase (a startup race independently mitigated in yeti-platform/yeti-docker#30, and made less likely by the connect() retry fix in #1331), every registration attempt made before that point fails and is silently dropped, leaving the Feeds page permanently empty for that process's lifetime with only a WARNING-level trace. Add a dedicated except clause ahead of the generic one, catching the same connectivity/database exception classes as the connect() retry fix (builtin ConnectionError, requests.exceptions.ConnectionError, and arango.exceptions.ArangoError, which covers every server- and client-side python-arango error) and logging them at ERROR with a message that names the actual consequence, instead of folding them into the generic "plugin didn't import" warning. Added a regression test that makes one specific plugin's import raise an ArangoClientError and asserts it's logged at ERROR rather than WARNING -- verified it fails on the pre-fix code (logs WARNING) and passes with the fix.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Closes the remaining part of yeti-docker#29 ("Feed tasks are not
initialized on fresh installation") — the actual mechanism behind the
empty Feeds page.
Every plugin registers itself as a
Taskdocument in the database as aside effect of being imported (
TaskManager.register_task, called fromeach plugin module's own top-level code, e.g.
plugins/feeds/public/urlhaus.py:92).get_plugins_list()(
core/taskscheduler.py) wraps that import in a bareexcept Exception, logging any failure at WARNING and moving on to thenext plugin — the right behavior for a plugin whose own optional
dependency isn't installed (e.g.
pymisp/otxv2/shodanin a minimaldeployment), but not for a plugin that imported fine and then failed to
register because the database rejected or couldn't complete the write.
Both cases currently look identical in the logs, at a level easy to
miss in production, with no way to distinguish "this feed isn't
available in this deployment" from "this feed didn't get created and
won't until the process restarts."
This is the actual failure mode behind the reported bug: on a fresh
install, if the database only becomes reachable partway through the
plugin import phase — a startup race independently mitigated at the
compose level in yeti-platform/yeti-docker#30, and made significantly
less likely by the
connect()retry fix in #1331 — every registrationattempt made before that point fails and is silently dropped, leaving
the Feeds page permanently empty for that process's lifetime with only
a WARNING-level trace buried among (likely legitimate) "plugin X isn't
installed" warnings.
Fix
Add a dedicated
exceptclause ahead of the generic one, catching thesame connectivity/database exception classes as #1331's
connect()fix(builtin
ConnectionError,requests.exceptions.ConnectionError, andarango.exceptions.ArangoError— the common base for every server- andclient-side python-arango error) and logging them at ERROR with a
message that names the actual consequence ("this feed will not appear
until the process is restarted"), instead of folding them into the
generic "plugin didn't import" warning.
This doesn't change whether the collection ends up empty in the
worst case (the deeper fix for that is #1331 + yeti-docker#30) — it
makes the failure loud and diagnosable instead of silent, which is the
main thing standing between "empty Feeds page, no idea why" and "check
the logs, database was unreachable during startup."
Test plan
test_database_error_during_registration_logs_as_error(
tests/core_tests/taskscheduler.py): makes one specific plugin'simport raise
ArangoClientErrorand asserts it's logged at ERRORrather than WARNING.
with the fix.
tests/core_testssuite: 30/30 pass.tests/schemas(190/190) andtests/apiv2(198/200, same 2 knownpre-existing failures) pass unchanged.
ty check(core+yetictl and plugins jobs): 0 errors.ruff check/ruff format --check: clean.