InMemoryAccountInfo is not threadsafe

[ehossack]

Hi,

My application has thrown this exception and the cause or mitigation is unclear. This did not occur at application startup. Nothing has changed with regards to access for that key.

I have used the InMemoryAccountInfo class, so my guess is that this is the result of a stale entry?

But am unsure how to diagnose. The documentation is sparse on this respect.

Any insight on what this could mean is appreciated :-)

MissingAccountData: Missing account data: allowed (3 additional frame(s) were not displayed) ... File "django_backblaze_b2/storage.py", line 74, in _getOrCreateBucket self._bucket = self.b2Api.get_bucket_by_name(self._bucketName) File "b2sdk/api.py", line 251, in get_bucket_by_name self.check_bucket_restrictions(bucket_name) File "logfury/v0_1/trace_call.py", line 84, in wrapper return function(*wrapee_args, **wrapee_kwargs) File "b2sdk/api.py", line 445, in check_bucket_restrictions allowed = self.account_info.get_allowed() File "b2sdk/account_info/in_memory.py", line 28, in inner raise MissingAccountData(function.__name__[4:])

[ppolewicz]

InMemoryAccountInfo only stores the information in memory, so you need to authorize_account before you can start using it. If you don't do that, you'll get an exception saying that there is some account data missing.

[ehossack]

Hmmm that makes sense, except this b2 api instance was previously authorized.

[ppolewicz]

I see. It might be a bug then. Could you please turn on the logs and share them so that we can see what is going on?

[ehossack]

Debug logging is enabled. Will report back when this error re-occurs.

[ehossack]

Unfortunately, the logs don't seem too helpful...

   self._bucket = self.b2Api.get_bucket_by_name(self._bucketName)
 File "/path/.venv/lib/python3.9/site-packages/b2sdk/api.py", line 251, in get_bucket_by_name
   self.check_bucket_restrictions(bucket_name)
 File "/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py", line 84, in wrapper
   return function(*wrapee_args, **wrapee_kwargs)
 File "/path/.venv/lib/python3.9/site-packages/b2sdk/api.py", line 445, in check_bucket_restrictions
   allowed = self.account_info.get_allowed()
 File "/path/.venv/lib/python3.9/site-packages/b2sdk/account_info/in_memory.py", line 28, in inner
   raise MissingAccountData(function.__name__[4:])

and then

2021-01-02 22:18:06,718 - [DEBUG]: calling B2Api.authorize_account(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, realm='production') (hidden args: application_key_id, application_key)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:06,818 - [DEBUG]: calling AbstractAccountInfo.set_auth_data(self=<b2sdk.account_info.in_memory.InMemoryAccountInfo object at 0x7f336a6de700>, api_url='https://api000.backblazeb2.com', download_url='https://f000.backblazeb2.com', minimum_part_size=100000000, realm='production') (hidden args: account_id, auth_token, application_key, allowed, application_key_id)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:06,818 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:06,818 - [DEBUG]: calling B2Api.list_buckets(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:06,818 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:06,818 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:07,510 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:08,129 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:10,069 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6def10>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,903 - [DEBUG]: calling B2Api.authorize_account(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, realm='production') (hidden args: application_key_id, application_key)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,904 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,965 - [DEBUG]: calling AbstractAccountInfo.set_auth_data(self=<b2sdk.account_info.in_memory.InMemoryAccountInfo object at 0x7fdc22631d00>, api_url='https://api000.backblazeb2.com', download_url='https://f000.backblazeb2.com', minimum_part_size=100000000, realm='production') (hidden args: account_id, auth_token, application_key, allowed, application_key_id)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,965 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,965 - [DEBUG]: calling B2Api.list_buckets(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
2021-01-02 22:18:30,965 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:30,965 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:31,096 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22631be0>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,119 - [DEBUG]: calling B2Api.authorize_account(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, realm='production') (hidden args: application_key_id, application_key)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,176 - [DEBUG]: calling AbstractAccountInfo.set_auth_data(self=<b2sdk.account_info.in_memory.InMemoryAccountInfo object at 0x7fdc22642790>, api_url='https://api000.backblazeb2.com', download_url='https://f000.backblazeb
2.com', minimum_part_size=100000000, realm='production') (hidden args: account_id, auth_token, application_key, allowed, application_key_id)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,176 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,176 - [DEBUG]: calling B2Api.list_buckets(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,177 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,177 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,225 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,226 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,544 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:33,544 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7fdc22642700>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,463 - [DEBUG]: calling B2Api.authorize_account(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, realm='production') (hidden args: application_key_id, application_key)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,520 - [DEBUG]: calling AbstractAccountInfo.set_auth_data(self=<b2sdk.account_info.in_memory.InMemoryAccountInfo object at 0x7f336a6e8460>, api_url='https://api000.backblazeb2.com', download_url='https://f000.backblazeb
2.com', minimum_part_size=100000000, realm='production') (hidden args: account_id, auth_token, application_key, allowed, application_key_id)
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,520 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
2021-01-02 22:18:45,520 - [DEBUG]: calling B2Api.list_buckets(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,521 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,521 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,673 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,737 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:45,790 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:46,097 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py
2021-01-02 22:18:46,163 - [DEBUG]: calling B2Api.check_bucket_restrictions(self=<b2sdk.api.B2Api object at 0x7f336a6e8a90>, bucket_name='my-public-bucket')
/path/.venv/lib/python3.9/site-packages/logfury/v0_1/trace_call.py

[ppolewicz]

It's a bug. InMemoryAccountInfo is not thread safe - your code is interacting with it from two threads in the same millisecond and it's causing issues.

[mszumocki-reef]

@ehossack : After looking at the logs in more detail, it seems you're using a different B2Api object (and InMemoryAccount info) for each thread, so it's probably not thread safety issue but uninitialized object in one of threads after all. We'll fix InMemoryAccountInfo to be thread safe but it's not likely to fix your issue.

[ehossack]

To follow up, I updated my code to use the sqlite3 account info and no longer see any errors :)

[ppolewicz]

We are planning to rewrite InMemoryAccountInfo to use sqlite3 :memory: mode to make it threadsafe in apiver v2.