[tacker][oslo][kolla-ansible] Issue reports for session management in oslo when using kolla-ansible

10 Jul 2023

      Hi, OpenStack Community.

Our Tacker team found an issue with session management in oslo and sqlalchemy when using kolla-ansible.
The following report details the issue.
[Issue details]
- In the case that we build Tacker and other components by using kolla-ansible, an issue with session management in oslo and sqlalchemy occurs when Tacker update the DB with `with context.session.begin(subtransactions=True):`
  - code: https://github.com/openstack/tacker/blob/7eaf841525d7ead30d7883abbde6c4fb86a...
  - error details
    ===
    * cli logs
    tacker@tacker:~/tacker-nic_internal/samples/takt-docker-sample/deployments/tacker$ curl -s -X PATCH http://"10.244.121.249:9890"/vnffm/v1/alarms/f23f39cc-f9a4-45bf-9a87-2f8148541b0a \
    -H "Content-type: application/json" \
    -H "Version: 1.3.0" \
    -d "{\"ackState\": \"ACKNOWLEDGED\"}" \
    -w "\n%{http_code}\n"
    {"status": 500, "detail": "this TransactionFactory is already started"}

    * tacker logs
    2023-06-12 05:28:56.028 1 INFO tacker.service [-] Tacker service started, listening on 0.0.0.0:9890
    2023-06-12 05:28:56.028 1 INFO tacker.wsgi [-] (1) wsgi starting up on http://0.0.0.0:9890
    2023-06-12 05:30:07.021 1 DEBUG tacker.wsgi [-] (1) accepted ('10.100.2.3', 52508) server /usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py:1004
    2023-06-12 05:30:07.027 1 INFO tacker.sol_refactored.api.wsgi [-] PATCH http://10.244.121.249:9890/vnffm/v1/alarms/f23f39cc-f9a4-45bf-9a87-2f8148541...
    2023-06-12 05:30:07.052 1 DEBUG tacker.sol_refactored.common.coordinate [None req-a19d9e85-ba9f-4f6b-938a-3fde04bce62b - - - - - -] resources f23f39cc-f9a4-45bf-9a87-2f8148541b0a locked. wrapper /usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/common/coordinate.py:95
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi [None req-a19d9e85-ba9f-4f6b-938a-3fde04bce62b - - - - - -] Unknown error: oslo_db.sqlalchemy.enginefacade.AlreadyStartedError: this TransactionFactory is already started
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi Traceback (most recent call last):
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/api/wsgi.py", line 134, in __call__
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     result = self._dispatch(request, action, args)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/api/wsgi.py", line 170, in _dispatch
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     return controller_method(request=request, **action_args)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/api/validator.py", line 48, in wrapper
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     return func(*args, **kwargs)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/common/coordinate.py", line 96, in wrapper
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     return func(*args, **kwargs)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/sol_refactored/controller/vnffm_v1.py", line 101, in update
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     with context.session.begin(subtransactions=True):
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/context.py", line 183, in session
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     self._session = db_api.get_session()
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/db/api.py", line 46, in get_session
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     facade = _create_facade_lazily()
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/tacker/db/api.py", line 32, in _create_facade_lazily
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     context_manager.configure(sqlite_fk=True, **cfg.CONF.database)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 812, in configure
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     self._factory.configure(**kw)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 319, in configure
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     self._configure(False, kw)
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi   File "/usr/local/lib/python3.10/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 332, in _configure
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi     raise AlreadyStartedError(
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi oslo_db.sqlalchemy.enginefacade.AlreadyStartedError: this TransactionFactory is already started
    2023-06-12 05:30:07.157 1 ERROR tacker.sol_refactored.api.wsgi 
    2023-06-12 05:30:07.159 1 INFO tacker.sol_refactored.api.wsgi [None req-a19d9e85-ba9f-4f6b-938a-3fde04bce62b - - - - - -] http://10.244.121.249:9890/vnffm/v1/alarms/f23f39cc-f9a4-45bf-9a87-2f8148541... returned with HTTP 500
    2023-06-12 05:30:07.159 1 INFO tacker.wsgi [None req-a19d9e85-ba9f-4f6b-938a-3fde04bce62b - - - - - -] 10.100.2.3 - - [12/Jun/2023 05:30:07] "PATCH /vnffm/v1/alarms/f23f39cc-f9a4-45bf-9a87-2f8148541b0a HTTP/1.1" 500 309 0.135927
    ===

- This issue does not occur with a regular Tacker Deploy (manual deployment or devstack), but kola-ansible or container envs only.

[Temporary solution]
- Remove the codes, but we investigate to check if there are any other impacts.

To solve these problems will require the cooperation of not only Tacker but also oslo and kolla-ansible projects.
We invite your feedback on these problems and especially welcome your share of similar situation info and solutions.

Best Regards,
Yuta

-- 
Yuta Kazato
NTT Network Innovation Center.
   tel: +81-422-59-6754
   mail: yuta.kazato@ntt.com