While debugging an internal issue, the create_router() from the ovn_l3/plugin.py was raising an exception and as part of the handling of this exception it was logging an ERROR but, there was no traceback which makes it really hard to figure out where this error is being raised even in with debug mode enabled. For example, that's the logs:
['neutron.services.ovn_l3.plugin.RouterAvailabilityZoneMixin._process_az_request-13770945', 'neutron.services.ovn_l3.plugin.OVNL3RouterPlugin.create_router_precommit-181103'] for router, precommit_create _notify_loop /usr/lib/python3.9/site-packages/neutron_lib/callbacks/manager.py:192
2023-06-26 10:11:39.037 30 DEBUG neutron.db.ovn_revision_numbers_db [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] create_initial_revision uuid=9969c69e-ca2f-4f6d-bdfd-74cf1febda83, type=routers, rev=-1 create_initial_revision /usr/lib/python3.9/site-packages/neutron/db/ovn_revision_numbers_db.py:104
2023-06-26 10:11:39.159 30 DEBUG neutron_lib.callbacks.manager [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Notify callbacks [] for router, after_create _notify_loop /usr/lib/python3.9/site-packages/neutron_lib/callbacks/manager.py:192
2023-06-26 10:11:39.160 30 INFO neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.extensions.qos [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Starting OVNClientQosExtension
2023-06-26 10:11:39.210 30 ERROR neutron.services.ovn_l3.plugin [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Unable to create lrouter for 9969c69e-ca2f-4f6d-bdfd-74cf1febda83: neutron_lib.exceptions.l3.RouterNotFound: Router 9969c69e-ca2f-4f6d-bdfd-74cf1febda83 could not be found
2023-06-26 10:11:39.219 30 DEBUG neutron_lib.callbacks.manager [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Notify callbacks [] for router, before_delete _notify_loop /usr/lib/python3.9/site-packages/neutron_lib/callbacks/manager.py:192
2023-06-26 10:11:39.386 32 DEBUG neutron.wsgi [-] (32) accepted ('fd00:fd00:fd00:2000::399', 33076, 0, 0) server /usr/lib/python3.9/site-packages/eventlet/wsgi.py:992
2023-06-26 10:11:39.389 32 INFO neutron.wsgi [-] fd00:fd00:fd00:2000::399 "GET / HTTP/1.1" status: 200 len: 244 time: 0.0014989
2023-06-26 10:11:39.406 30 DEBUG neutron_lib.callbacks.manager [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Notify callbacks [] for router, precommit_delete _notify_loop /usr/lib/python3.9/site-packages/neutron_lib/callbacks/manager.py:192
2023-06-26 10:11:39.471 30 DEBUG neutron_lib.callbacks.manager [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Notify callbacks [] for router, after_delete _notify_loop /usr/lib/python3.9/site-packages/neutron_lib/callbacks/manager.py:192
2023-06-26 10:11:39.472 30 DEBUG neutron.api.rpc.agentnotifiers.l3_rpc_agent_api [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Fanout notify agent at l3_agent the message router_deleted on router 9969c69e-ca2f-4f6d-bdfd-74cf1febda83 _notification_fanout /usr/lib/python3.9/site-packages/neutron/api/rpc/agentnotifiers/l3_rpc_agent_api.py:118
2023-06-26 10:11:39.549 30 INFO neutron.api.v2.resource [req-18ddc15b-8b4e-4c3c-a360-1d6c10680b39 46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] create failed (client error): The resource could not be found.
As you can see the error is:
46d4bcf86b0a4de691d824308920146c b867c3a5edc8442c946948014a351985 - default default] Unable to create lrouter for 9969c69e-ca2f-4f6d-bdfd-74cf1febda83: neutron_lib.exceptions.l3.RouterNotFound: Router 9969c69e-ca2f-4f6d-bdfd-74cf1febda83 could not be found
But there's no traceback to know where this error has originally being raised. The create_router() method does a many things and it's very difficult to figure this out without the traceback.
This LP is about improving the logs for that module in general as I see other parts where nothing is being logged when things goes bad.
Patch: https:/