Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue with 'New airlock import request': Error submitting airlock request - Unable to process request - Status Code 500 #3836

Closed
BiologyGeek opened this issue Feb 3, 2024 · 8 comments
Labels
question Further information is requested

Comments

@BiologyGeek
Copy link

BiologyGeek commented Feb 3, 2024

Hi team,

I deployed a fresh Azure TRE. I can create and run new Virtual Machines without issue. But when I tried to create a 'New airlock import request' for the first time, I faced with this error message:

Error submitting airlock request
Unable to process request

Endpoint	workspaces/<an ID Was Here>/requests
Status Code	500
Stack Trace	Error: Unable to process request at https://metreid.eastus.cloudapp.azure.com/static/js/main.30bb114c.js:2:721552 at async Object.onClick (https://mytreid.eastus.cloudapp.azure.com/static/js/main.30bb114c.js:2:1212320)
Exception

2024-02-03_075309

Azure TRE release version:
UI Version: 0.5.17
API Version: 0.16.9
Cosmos DB: OK
Service Bus: OK
Resource Processor: OK

Deployed Azure TRE components:

  1. tre-shared-service-firewall (1.1.5)
  2. tre-shared-service-certs (0.5.1)
  3. tre-shared-service-sonatype-nexus (2.8.13)
  4. tre-shared-service-gitea (0.6.10)
  5. tre-workspace-base (1.5.3)

I cheeked these GitHub Issues as well:

  1. Airlock Processor Unable to Start #3664
    When I sent same query described here to 'Application rule log data' of the AzureTRE Firewall to find sebnet IP related to 'functionscdn.azureedge.net', returned result was empty.
    Airlock Processor Unable to Start #3664 (comment)

  2. airlock request failed due to an unknown reason  #3705 (comment)

I can confirm in my case there is an application rule called 'functions-runtime' allow-listed the 'functionscdn.azureedge.net' endpoint.
Also there is an another application rule called 'arc_nexus' allow-listed the 'pypi.org' as well.

I checked these GutHub issues as well but nor sure which one is more close to my case:

  1. Airlock fails due to DNS timeout - returns "Request failed due to an unknown reason." #3767

  2. Airlock: Creating an import/export request causes a routing error #3830

  3. Unable to create import/export Airlock requests #3713

  4. airlock function runtime version & container creation fail #3725

Additional Information: I used my primary Microsoft Entra ID Tenant account to attempt a 'New Airlock Import Request.' This account, on one Base Workspace, has the roles 'Workspace Owner,' 'Airlock Manager,' and 'Workspace Researcher' assigned. On another Base Workspace, the account has only the 'Workspace Researcher' role assigned, yet the result was the same.
(Azure Portal --> (Switch to) My dedicated Microsoft Entra ID for TRE --> Enterprise applications --> All applications)

Would you kindly take a moment to review this and share your insights with me, please? @marrobi @martinpeck

@BiologyGeek BiologyGeek added the question Further information is requested label Feb 3, 2024
@BiologyGeek BiologyGeek changed the title [Issue with 'New airlock import request']: Error submitting airlock request - Unable to process request - Status Code 500 Issue with 'New airlock import request': Error submitting airlock request - Unable to process request - Status Code 500 Feb 3, 2024
@marrobi
Copy link
Member

marrobi commented Feb 7, 2024

Hello @BiologyGeek . Can you take a look at the API logs to find out the reason for the 500 error. Can use either of the below methods:

https://microsoft.github.io/AzureTRE/latest/troubleshooting-faq/app-insights-logs/
https://microsoft.github.io/AzureTRE/latest/troubleshooting-faq/api-logs-deployment-center/

Thank you.

@BiologyGeek
Copy link
Author

Hello @marrobi, thanks for your response,

To check the 'TRE API Logs', I followed these steps:
I navigated to the Azure Portal → My TRE Resource Group → log-mytreid → Logs (from the right side blade) → Searched 'TRE API' in the Queries Category search box → found 'TRE API Logs' and clicked the 'Run' white button → Set the time range to 'Last 7 days' and filled the Query box with the query below, then clicked the 'Run' blue button.

Query:

let tracking_id="The Workspace ID where I attempted to import the file via Airlock was here";
AppTraces
| where Message has tracking_id or OperationId == tracking_id | sort by TimeGenerated desc

I replaced 'tracking_id="The Workspace ID where I attempted to import the file via Airlock was here"' with my own workspace ID, which appears after 'https://mytreid.eastus.cloudapp.azure.com/workspaces/' in the web browser's URL bar.

However, when I clicked the 'Run' blue button on the Azure Portal, the result was 'No results found from the last 7 days'. Note that before running that query, I attempted to import a file draft using Airlock on that workspace to ensure that some new logs would be generated.

I'm not sure if that is the appropriate query for this situation. Could you please provide guidance on it?

2024-02-11_201306-2


After this attempt, I went to this path:
Azure Portal → My TRE Resource Group → api-mytreid → Deployment Center (from the right side blade) → Logs (Tab).

I pressed Ctrl + F in the browser to be able to find some keywords within the logs. I searched for 'airlock', and these results appeared that contain this word:

2024_02_12_<A File Name Was Here>_easyauth_docker.log:


2024_02_12_<A File Name Was Here>_default_docker.log:
2024-02-12T08:20:42.986812293Z [2024-02-12 08:20:42 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:15)
2024-02-12T08:20:44.147450001Z [2024-02-12 08:20:44 +0000] [1] [ERROR] Worker (pid:15) was sent SIGKILL! Perhaps out of memory?
2024-02-12T08:20:44.331339961Z [2024-02-12 08:20:44 +0000] [5140] [INFO] Booting worker with pid: 5140

2024-02-12T08:20:49.749144003Z [2024-02-12 08:20:49 +0000] [5140] [INFO] Started server process [5140]
2024-02-12T08:20:49.750731209Z [2024-02-12 08:20:49 +0000] [5140] [INFO] Waiting for application startup.

2024-02-12T08:20:51.433903443Z [2024-02-12 08:20:51 +0000] [5140] [INFO] Application startup complete.



2024-02-12T11:16:21.938665900Z [2024-02-12 11:16:21 +0000] [5140] [ERROR] Exception in ASGI application
2024-02-12T11:16:21.941687814Z Traceback (most recent call last):
2024-02-12T11:16:21.941700014Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 98, in receive
2024-02-12T11:16:21.941704414Z return self.receive_nowait()
2024-02-12T11:16:21.941708014Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 93, in receive_nowait
2024-02-12T11:16:21.941712214Z raise WouldBlock
2024-02-12T11:16:21.941715814Z anyio.WouldBlock
2024-02-12T11:16:21.941719314Z
2024-02-12T11:16:21.941722614Z During handling of the above exception, another exception occurred:
2024-02-12T11:16:21.941726415Z
2024-02-12T11:16:21.941729815Z Traceback (most recent call last):
2024-02-12T11:16:21.941733315Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 78, in call_next
2024-02-12T11:16:21.941736815Z message = await recv_stream.receive()
2024-02-12T11:16:21.941740315Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 118, in receive
2024-02-12T11:16:21.941743815Z raise EndOfStream
2024-02-12T11:16:21.941747115Z anyio.EndOfStream
2024-02-12T11:16:21.941751415Z
2024-02-12T11:16:21.941754715Z During handling of the above exception, another exception occurred:
2024-02-12T11:16:21.941758115Z
2024-02-12T11:16:21.941761415Z Traceback (most recent call last):
2024-02-12T11:16:21.941764715Z File "/usr/local/lib/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 426, in run_asgi
2024-02-12T11:16:21.941768315Z result = await app( # type: ignore[func-returns-value]
2024-02-12T11:16:21.941771615Z File "/usr/local/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
2024-02-12T11:16:21.941775215Z return await self.app(scope, receive, send)
2024-02-12T11:16:21.941778515Z File "/usr/local/lib/python3.8/site-packages/fastapi/applications.py", line 1115, in __call__
2024-02-12T11:16:21.941782015Z await super().__call__(scope, receive, send)
2024-02-12T11:16:21.941785415Z File "/usr/local/lib/python3.8/site-packages/starlette/applications.py", line 122, in __call__
2024-02-12T11:16:21.941788915Z await self.middleware_stack(scope, receive, send)
2024-02-12T11:16:21.941805215Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:16:21.941809415Z raise exc
2024-02-12T11:16:21.941812815Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:16:21.941816315Z await self.app(scope, receive, _send)
2024-02-12T11:16:21.941819615Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:16:21.941823115Z raise exc
2024-02-12T11:16:21.941826315Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:16:21.941829815Z await self.app(scope, receive, _send)
2024-02-12T11:16:21.941835615Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 108, in __call__
2024-02-12T11:16:21.941839415Z response = await self.dispatch_func(request, call_next)
2024-02-12T11:16:21.941842815Z File "/api/services/tracing.py", line 83, in dispatch
2024-02-12T11:16:21.941846215Z response = await call_next(request)
2024-02-12T11:16:21.941849615Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 84, in call_next
2024-02-12T11:16:21.941853415Z raise app_exc
2024-02-12T11:16:21.941856715Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 70, in coro
2024-02-12T11:16:21.941860315Z await self.app(scope, receive_or_disconnect, send_no_error)
2024-02-12T11:16:21.941863715Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
2024-02-12T11:16:21.941867215Z raise exc
2024-02-12T11:16:21.941870415Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
2024-02-12T11:16:21.941874015Z await self.app(scope, receive, sender)
2024-02-12T11:16:21.941877315Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 20, in __call__
2024-02-12T11:16:21.941880715Z raise e
2024-02-12T11:16:21.941884015Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 17, in __call__
2024-02-12T11:16:21.941887615Z await self.app(scope, receive, send)
2024-02-12T11:16:21.941890915Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 718, in __call__
2024-02-12T11:16:21.941894415Z await route.handle(scope, receive, send)
2024-02-12T11:16:21.941897715Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 276, in handle
2024-02-12T11:16:21.941901315Z await self.app(scope, receive, send)
2024-02-12T11:16:21.941904615Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 66, in app
2024-02-12T11:16:21.941908015Z response = await func(request)
2024-02-12T11:16:21.941915115Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 274, in app
2024-02-12T11:16:21.941918815Z raw_response = await run_endpoint_function(
2024-02-12T11:16:21.941931215Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 191, in run_endpoint_function
2024-02-12T11:16:21.941934715Z return await dependant.call(**values)
2024-02-12T11:16:21.941938015Z File "/api/api/routes/airlock.py", line 45, in create_draft_request
2024-02-12T11:16:21.941941615Z await save_and_publish_event_airlock_request(airlock_request, airlock_request_repo, user, workspace)
2024-02-12T11:16:21.941945116Z File "/api/services/airlock.py", line 277, in save_and_publish_event_airlock_request
2024-02-12T11:16:21.941948516Z role_assignment_details = access_service.get_workspace_role_assignment_details(workspace)
2024-02-12T11:16:21.941952316Z File "/api/services/aad_authentication.py", line 284, in get_workspace_role_assignment_details
2024-02-12T11:16:21.941956116Z msgraph_token = self._get_msgraph_token()
2024-02-12T11:16:21.941959516Z File "/api/services/aad_authentication.py", line 212, in _get_msgraph_token
2024-02-12T11:16:21.941967516Z raise Exception(result.get('error'))
2024-02-12T11:16:21.941971016Z Exception: invalid_client
2024-02-12T11:16:25.071927810Z [2024-02-12 11:16:25 +0000] [18] [ERROR] Exception in ASGI application
2024-02-12T11:16:25.075169525Z Traceback (most recent call last):
2024-02-12T11:16:25.075176625Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 98, in receive
2024-02-12T11:16:25.075180725Z return self.receive_nowait()
2024-02-12T11:16:25.075184225Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 93, in receive_nowait
2024-02-12T11:16:25.075188225Z raise WouldBlock
2024-02-12T11:16:25.075208025Z anyio.WouldBlock
2024-02-12T11:16:25.075211425Z
2024-02-12T11:16:25.075214725Z During handling of the above exception, another exception occurred:
2024-02-12T11:16:25.075217925Z
2024-02-12T11:16:25.075221225Z Traceback (most recent call last):
2024-02-12T11:16:25.075224625Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 78, in call_next
2024-02-12T11:16:25.075228125Z message = await recv_stream.receive()
2024-02-12T11:16:25.075231625Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 118, in receive
2024-02-12T11:16:25.075235325Z raise EndOfStream
2024-02-12T11:16:25.075238825Z anyio.EndOfStream
2024-02-12T11:16:25.075242025Z
2024-02-12T11:16:25.075245725Z During handling of the above exception, another exception occurred:
2024-02-12T11:16:25.075249025Z
2024-02-12T11:16:25.075252125Z Traceback (most recent call last):
2024-02-12T11:16:25.075267526Z File "/usr/local/lib/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 426, in run_asgi
2024-02-12T11:16:25.075271526Z result = await app( # type: ignore[func-returns-value]
2024-02-12T11:16:25.075274826Z File "/usr/local/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
2024-02-12T11:16:25.075278226Z return await self.app(scope, receive, send)
2024-02-12T11:16:25.075281526Z File "/usr/local/lib/python3.8/site-packages/fastapi/applications.py", line 1115, in __call__
2024-02-12T11:16:25.075284826Z await super().__call__(scope, receive, send)
2024-02-12T11:16:25.075288026Z File "/usr/local/lib/python3.8/site-packages/starlette/applications.py", line 122, in __call__
2024-02-12T11:16:25.075291426Z await self.middleware_stack(scope, receive, send)
2024-02-12T11:16:25.075294626Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:16:25.075298226Z raise exc
2024-02-12T11:16:25.075301626Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:16:25.075305026Z await self.app(scope, receive, _send)
2024-02-12T11:16:25.075308126Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:16:25.075311526Z raise exc
2024-02-12T11:16:25.075314726Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:16:25.075318126Z await self.app(scope, receive, _send)
2024-02-12T11:16:25.075324926Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 108, in __call__
2024-02-12T11:16:25.075328626Z response = await self.dispatch_func(request, call_next)
2024-02-12T11:16:25.075331926Z File "/api/services/tracing.py", line 83, in dispatch
2024-02-12T11:16:25.075335226Z response = await call_next(request)
2024-02-12T11:16:25.075338426Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 84, in call_next
2024-02-12T11:16:25.075341926Z raise app_exc
2024-02-12T11:16:25.075345026Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 70, in coro
2024-02-12T11:16:25.075365726Z await self.app(scope, receive_or_disconnect, send_no_error)
2024-02-12T11:16:25.075369326Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
2024-02-12T11:16:25.075373026Z raise exc
2024-02-12T11:16:25.075376226Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
2024-02-12T11:16:25.075379626Z await self.app(scope, receive, sender)
2024-02-12T11:16:25.075382926Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 20, in __call__
2024-02-12T11:16:25.075390626Z raise e
2024-02-12T11:16:25.075393926Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 17, in __call__
2024-02-12T11:16:25.075397426Z await self.app(scope, receive, send)
2024-02-12T11:16:25.075400726Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 718, in __call__
2024-02-12T11:16:25.075404226Z await route.handle(scope, receive, send)
2024-02-12T11:16:25.075407626Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 276, in handle
2024-02-12T11:16:25.075411026Z await self.app(scope, receive, send)
2024-02-12T11:16:25.075414326Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 66, in app
2024-02-12T11:16:25.075417826Z response = await func(request)
2024-02-12T11:16:25.075421126Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 274, in app
2024-02-12T11:16:25.075424526Z raw_response = await run_endpoint_function(
2024-02-12T11:16:25.075427826Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 191, in run_endpoint_function
2024-02-12T11:16:25.075431326Z return await dependant.call(**values)
2024-02-12T11:16:25.075434726Z File "/api/api/routes/airlock.py", line 45, in create_draft_request
2024-02-12T11:16:25.075438126Z await save_and_publish_event_airlock_request(airlock_request, airlock_request_repo, user, workspace)
2024-02-12T11:16:25.075441626Z File "/api/services/airlock.py", line 277, in save_and_publish_event_airlock_request
2024-02-12T11:16:25.075445026Z role_assignment_details = access_service.get_workspace_role_assignment_details(workspace)
2024-02-12T11:16:25.075448926Z File "/api/services/aad_authentication.py", line 284, in get_workspace_role_assignment_details
2024-02-12T11:16:25.075452426Z msgraph_token = self._get_msgraph_token()
2024-02-12T11:16:25.075455726Z File "/api/services/aad_authentication.py", line 212, in _get_msgraph_token
2024-02-12T11:16:25.075459226Z raise Exception(result.get('error'))
2024-02-12T11:16:25.075462626Z Exception: invalid_client

2024-02-12T11:17:17.833858150Z [2024-02-12 11:17:17 +0000] [18] [ERROR] Exception in ASGI application
2024-02-12T11:17:17.833892850Z Traceback (most recent call last):
2024-02-12T11:17:17.833898450Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 98, in receive
2024-02-12T11:17:17.833902750Z return self.receive_nowait()
2024-02-12T11:17:17.833906250Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 93, in receive_nowait
2024-02-12T11:17:17.833910550Z raise WouldBlock
2024-02-12T11:17:17.833913950Z anyio.WouldBlock
2024-02-12T11:17:17.833917450Z
2024-02-12T11:17:17.833920850Z During handling of the above exception, another exception occurred:
2024-02-12T11:17:17.840500780Z
2024-02-12T11:17:17.840514080Z Traceback (most recent call last):
2024-02-12T11:17:17.840518180Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 78, in call_next
2024-02-12T11:17:17.840532180Z message = await recv_stream.receive()
2024-02-12T11:17:17.840537080Z File "/usr/local/lib/python3.8/site-packages/anyio/streams/memory.py", line 118, in receive
2024-02-12T11:17:17.840540680Z raise EndOfStream
2024-02-12T11:17:17.840543980Z anyio.EndOfStream
2024-02-12T11:17:17.840547180Z
2024-02-12T11:17:17.840550380Z During handling of the above exception, another exception occurred:
2024-02-12T11:17:17.840553680Z
2024-02-12T11:17:17.840556980Z Traceback (most recent call last):
2024-02-12T11:17:17.840560180Z File "/usr/local/lib/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 426, in run_asgi
2024-02-12T11:17:17.840563780Z result = await app( # type: ignore[func-returns-value]
2024-02-12T11:17:17.840566980Z File "/usr/local/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
2024-02-12T11:17:17.840570380Z return await self.app(scope, receive, send)
2024-02-12T11:17:17.840573680Z File "/usr/local/lib/python3.8/site-packages/fastapi/applications.py", line 1115, in __call__
2024-02-12T11:17:17.840577380Z await super().__call__(scope, receive, send)
2024-02-12T11:17:17.840580580Z File "/usr/local/lib/python3.8/site-packages/starlette/applications.py", line 122, in __call__
2024-02-12T11:17:17.840583980Z await self.middleware_stack(scope, receive, send)
2024-02-12T11:17:17.840587180Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:17:17.840590580Z raise exc
2024-02-12T11:17:17.840593780Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:17:17.840597180Z await self.app(scope, receive, _send)
2024-02-12T11:17:17.840600280Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
2024-02-12T11:17:17.840603780Z raise exc
2024-02-12T11:17:17.840606880Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
2024-02-12T11:17:17.840610280Z await self.app(scope, receive, _send)
2024-02-12T11:17:17.840615580Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 108, in __call__
2024-02-12T11:17:17.840619880Z response = await self.dispatch_func(request, call_next)
2024-02-12T11:17:17.840623180Z File "/api/services/tracing.py", line 83, in dispatch
2024-02-12T11:17:17.840626480Z response = await call_next(request)
2024-02-12T11:17:17.840629680Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 84, in call_next
2024-02-12T11:17:17.840641180Z raise app_exc
2024-02-12T11:17:17.840644680Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/base.py", line 70, in coro
2024-02-12T11:17:17.840648180Z await self.app(scope, receive_or_disconnect, send_no_error)
2024-02-12T11:17:17.840651480Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
2024-02-12T11:17:17.840654980Z raise exc
2024-02-12T11:17:17.840658180Z File "/usr/local/lib/python3.8/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
2024-02-12T11:17:17.840661480Z await self.app(scope, receive, sender)
2024-02-12T11:17:17.840664680Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 20, in __call__
2024-02-12T11:17:17.840667980Z raise e
2024-02-12T11:17:17.840671180Z File "/usr/local/lib/python3.8/site-packages/fastapi/middleware/asyncexitstack.py", line 17, in __call__
2024-02-12T11:17:17.840674581Z await self.app(scope, receive, send)
2024-02-12T11:17:17.840677781Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 718, in __call__
2024-02-12T11:17:17.840681181Z await route.handle(scope, receive, send)
2024-02-12T11:17:17.840684481Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 276, in handle
2024-02-12T11:17:17.840687781Z await self.app(scope, receive, send)
2024-02-12T11:17:17.840690981Z File "/usr/local/lib/python3.8/site-packages/starlette/routing.py", line 66, in app
2024-02-12T11:17:17.840694281Z response = await func(request)
2024-02-12T11:17:17.840697481Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 274, in app
2024-02-12T11:17:17.840700881Z raw_response = await run_endpoint_function(
2024-02-12T11:17:17.840703981Z File "/usr/local/lib/python3.8/site-packages/fastapi/routing.py", line 191, in run_endpoint_function
2024-02-12T11:17:17.840707481Z return await dependant.call(**values)
2024-02-12T11:17:17.840710681Z File "/api/api/routes/airlock.py", line 45, in create_draft_request
2024-02-12T11:17:17.840714081Z await save_and_publish_event_airlock_request(airlock_request, airlock_request_repo, user, workspace)
2024-02-12T11:17:17.840717381Z File "/api/services/airlock.py", line 277, in save_and_publish_event_airlock_request
2024-02-12T11:17:17.840720681Z role_assignment_details = access_service.get_workspace_role_assignment_details(workspace)
2024-02-12T11:17:17.840724581Z File "/api/services/aad_authentication.py", line 284, in get_workspace_role_assignment_details
2024-02-12T11:17:17.840728081Z msgraph_token = self._get_msgraph_token()
2024-02-12T11:17:17.840731281Z File "/api/services/aad_authentication.py", line 212, in _get_msgraph_token
2024-02-12T11:17:17.840734581Z raise Exception(result.get('error'))
2024-02-12T11:17:17.840740581Z Exception: invalid_client

2024_02_12_<A File Name Was Here>_docker.log:
2024-02-12T04:49:05.000Z INFO -

@marrobi
Copy link
Member

marrobi commented Feb 12, 2024

Hmm, not seen this before, this is the line causing the issue -

raise Exception(result.get('error'))

Can you enable debug logging on the API, try again, and get the logs as you have via deployment center?

https://microsoft.github.io/AzureTRE/latest/troubleshooting-faq/debug-api/

Looking at #1674, could be an issue with the client id and/or secret in the env vars.

(FWIW - there is better logging in this bit of code now in main, which will be in the next release)

@BiologyGeek
Copy link
Author

Thank you for your response @marrobi

Based on your mention of issue #1674, it raises a question: Is the Airlock error 500 a result of a mistake during deployment and the provision of parameters to the config.yaml file, or is it due to something else?

Since DEBUG mode generated a significant amount of data, some of which may contain confidential information, could you please suggest a method for sending this information privately?

@marrobi
Copy link
Member

marrobi commented Feb 16, 2024

Email me - my github username @microsoft.com

Thanks.

@marrobi
Copy link
Member

marrobi commented Feb 16, 2024

From the email:

AADSTS7000215: Invalid client secret provided. Ensure the secret being sent in the request is the client secret value, not the client secret ID, for a secret added to app

@BiologyGeek
Copy link
Author

From the email:

AADSTS7000215: Invalid client secret provided. Ensure the secret being sent in the request is the client secret value, not the client secret ID, for a secret added to app

Thank you for your investigation.

Could the root cause of this issue stem from incorrect credentials or a mistake made during deployment? or might it be related to a step that should have been manually completed after deployment but has yet to be executed? If the issue pertains to the latter, could you please direct me to the relevant documentation?

@marrobi
Copy link
Member

marrobi commented Feb 19, 2024

So the ID and password live in KeyVault. They are generated and put into the config.yaml via make auth or manually.

After updating config.yaml, make deploy-core or any of the commands that include this, such as make all must be run. This copies the ID and password from the config.yaml to KeyVault.

Hope that helps. I will close the issue, but if you continue to have issues let us know.

@marrobi marrobi closed this as completed Feb 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
question Further information is requested
Projects
None yet
Development

No branches or pull requests

2 participants