microsoftgraph / msgraph-sdk-python

MIT License
374 stars 55 forks source link

Awaiting a large number of requests raises `ValueError: InvalidMinValue. Delay should not be negative` #450

Closed atenni closed 1 month ago

atenni commented 11 months ago

I'm getting the following InvalidMinValue. Delay should not be negative error while using this library:

Stack trace... ``` InvalidMinValue. Delay should not be negative File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/middleware/options/retry_handler_option.py", line 62, in max_delay raise ValueError('InvalidMinValue. Delay should not be negative') File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/middleware/retry_handler.py", line 97, in send current_options.max_delay -= (end_time - start_time) ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/middleware/middleware.py", line 65, in send return await self.next.send(request, transport) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/middleware/redirect_handler.py", line 77, in send response = await super().send(request, transport) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/middleware/middleware.py", line 38, in send return await self._first_middleware.send(request, self._transport) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/msgraph_core/middleware/async_graph_transport.py", line 21, in handle_async_request response = await self.pipeline.send(request) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/httpx/_client.py", line 1719, in _send_single_request response = await transport.handle_async_request(request) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/httpx/_client.py", line 1682, in _send_handling_redirects response = await self._send_single_request(request) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/httpx/_client.py", line 1645, in _send_handling_auth response = await self._send_handling_redirects( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/httpx/_client.py", line 1617, in send response = await self._send_handling_auth( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/httpx_request_adapter.py", line 511, in get_http_response_message resp = await self._http_client.send(request) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/kiota_http/httpx_request_adapter.py", line 167, in send_async response = await self.get_http_response_message(request_info, parent_span) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/msgraph/generated/sites/item/lists/item/items/items_request_builder.py", line 90, in post return await self.request_adapter.send_async(request_info, ListItem, error_mapping) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/libs/ac3_utils/src/ac3_utils/msgraph.py", line 212, in create_list_item await self.client.sites.by_site_id(self.site_id) File "/workspaces/cast-user-access-level-auditor/libs/ac3_utils/src/ac3_utils/msgraph.py", line 387, in save_audit_results save_result = await asyncio.gather(*save_coroutines) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/index.py", line 99, in async_handler save_audit_results = await graph_client.save_audit_results( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete return future.result() ^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/index.py", line 111, in handler return loop.run_until_complete(async_handler(event, _context)) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/.venv/lib/python3.11/site-packages/aws_lambda_powertools/logging/logger.py", line 451, in decorate return lambda_handler(event, context, *args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/workspaces/cast-user-access-level-auditor/cdk/lambdas/csv_audit/index.py", line 121, in handler(event, TestLambdaContext()) File "/usr/local/lib/python3.11/runpy.py", line 88, in _run_code exec(code, run_globals) File "/usr/local/lib/python3.11/runpy.py", line 198, in _run_module_as_main (Current frame) return _run_code(code, main_globals, None, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ValueError: InvalidMinValue. Delay should not be negative ```

At this point in my code I have a save_coroutines list of about 700 items that I'm saving to a SharePoint List. Each coroutine is via the following method:

graph_client.sites.by_site_id(site_id).lists.by_list_id(list_id).items.post(list_item)

...and I'm await-ing them all to complete in parallel via:

save_result = await asyncio.gather(*save_coroutines)

In the stacktrace above the problem occurs in "kiota_http/middleware/retry_handler.py", in particular on line 97:

# <snip>

# Check if the request needs to be retried based on the response method
# and status code
should_retry = self.should_retry(request, current_options, response)
if all([should_retry, retry_valid, delay < current_options.max_delay]):
    time.sleep(delay)
    end_time = time.time()
    current_options.max_delay -= (end_time - start_time)  # <===== THIS LINE =====
    # increment the count for retries
    retry_count += 1
    request.headers.update({'retry-attempt': f'{retry_count}'})
    _retry_span.set_attribute(SpanAttributes.HTTP_RETRY_COUNT, retry_count)
    continue

# <snip>

If I pause my debugger here I can see the following local variables:

current_options.max_delay: 3.0
end_time: 1699395455.5323932
start_time: 1699395396.5695903

# (end_time - start_time) = 58.96280288696289

...which is where the attempt to set a negative max_delay happens.

I'm not sure if the problem is in kiota-http-python, the way msgraph-sdk-python is using kiota-http-python, or (most likely) the way I'm using msgraph-sdk-python...

Is there a better way to await a large number of async requests created by this library than asyncio.gather()?

Installed package versions... ``` azure-core 1.29.5 azure-identity 1.15.0 microsoft-kiota-abstractions 1.0.0 microsoft-kiota-authentication-azure 1.0.0 microsoft-kiota-http 1.0.0 microsoft-kiota-serialization-json 1.0.0 microsoft-kiota-serialization-text 1.0.0 msal 1.24.1 msal-extensions 1.0.0 msgraph-core 1.0.0a4 msgraph-sdk 1.0.0 ```
tickx-cegeka commented 9 months ago

I have the same issue. Any progress or workaround?

dernstOfExtron commented 9 months ago

I have the same issue as well.

naltimari commented 8 months ago

Obviously this should be addressed properly, but I had a hunch it had to do with rate limiting. Thus I tried inserting a asyncio.sleep(1) between calls to task_group.create_task and it seems to have made a difference.

I used to add 20 tasks to the TaskGroup, and only 3 out of 20 would return successfully, with the others returning the dreaded InvalidMinValue. After I added the 'sleep' call, all 20 are succeeding. Might be a coincidence, though.

shemogumbe commented 2 months ago

Hello @atenni @naltimari Thanks for using the SDK and for raising this.

Preliminary investigation on my side implies this to be around the use of asyncio rather than on the SDK and the HTTP library.

Tried to get this to work, with my simple example which you can replace with your function, I would consider:

  1. Define multiple asyncio functions for different requests.
  2. User create_task scheduler, to scchedule multiple requests
  3. Await all tasks to complete Example:
    
    import asyncio

async def get_access_package_by_current_user(): try: access_packages = await user_client.identity_governance.entitlement_management.access_packages.filter_by_current_user_with_on( 'allowedRequestor').get() print(f"Access Packages: {access_packages.value}") except APIError as api_error: print(f"api error {api_error}")

async def another_request():

Simulate another async request

await asyncio.sleep(1)
print("Another request completed")

async def main(): task1 = asyncio.create_task(get_access_package_by_current_user()) task2 = asyncio.create_task(another_request())

await task1
await task2

asyncio.run(main())



What is the bulk of your individual functions, as in how many requests are you trying to do async?
microsoft-github-policy-service[bot] commented 1 month ago

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.