b2-sdk-python
b2-sdk-python copied to clipboard
Backblaze
InMemoryAccountInfo is not threadsafe
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:])
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.
Hmmm that makes sense, except this b2 api instance was previously authorized.
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?
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
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.
@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.
To follow up, I updated my code to use the sqlite3 account info and no longer see any errors :)
We are planning to rewrite InMemoryAccountInfo to use sqlite3 :memory: mode to make it threadsafe in apiver v2.
Okay, so an update to this issue -> I switched to a database-backed storage system and still have this issue. It's plausible that there is a concurrency issue; however, the greater problem here I would argue is that the MissingAccountData data exception isn't useful to any client.
I'm wondering if perhaps session should just treat this exception as InvalidAuthToken ~Unauthorized~ https://github.com/Backblaze/b2-sdk-python/blob/ce5e86e350431e2e7c3a54b188a2ca3a2274734b/b2sdk/session.py#L460
Really the only course of action here is to clear the account data (in case it's partially stored) and do a full re-auth, so why not handle that in the SDK?
I don't think the SDK should help automatically recover from situation that is never supposed to happen. MissingAccountData from perspective of the sdk is a bug in the code - caller should never have called the method that has been just called before properly authorizing the account.
Making InMemoryAccountInfo threadsafe seems to be fairly easy: try SqliteAccountInfo(file_name=":memory:")
To follow up, I updated my code to use the sqlite3 account info and no longer see any errors :)
How did you pass this as an argument to InMemoryAccountInfo()?
I believe InMemoryAccountInfo() was swapped with SqliteAccountInfo(file_name=":memory:")