tone down disquieting error messages on routine redirects and task ca…

aries_cloudagent/admin/server.py

@@ -61,7 +61,11 @@ class AdminResponder(BaseResponder):
     """Handle outgoing messages from message handlers."""
 
     def __init__(
-        self, context: InjectionContext, send: Coroutine, webhook: Coroutine, **kwargs,
+        self,
+        context: InjectionContext,
+        send: Coroutine,
+        webhook: Coroutine,
+        **kwargs,
     ):
         """
         Initialize an instance of `AdminResponder`.
@@ -128,10 +132,15 @@ def topic_filter(self, val: Sequence[str]):
 async def ready_middleware(request: web.BaseRequest, handler: Coroutine):
     """Only continue if application is ready to take work."""
 
-    if str(request.rel_url).rstrip("/") in (
-        "/status/live",
-        "/status/ready",
-    ) or request.app._state.get("ready"):
+    print(f'\n\n== ready 1 {request.rel_url}, ready={request.app._state.get("ready")}')
+    if (
+        str(request.rel_url).rstrip("/")
+        in (
+            "/status/live",
+            "/status/ready",
+        )
+        or request.app._state.get("ready")
+    ):
         try:
             return await handler(request)
         except (LedgerConfigError, LedgerTransactionError) as e:
@@ -140,11 +149,20 @@ async def ready_middleware(request: web.BaseRequest, handler: Coroutine):
             request.app._state["ready"] = False
             request.app._state["alive"] = False
             raise
+        except web.HTTPFound as e:
+            # redirect, typically / -> /api/doc
+            LOGGER.info("Handler redirect to: %s", e.location)
+            raise
+        except asyncio.CancelledError:
+            # redirection spawns new task and cancels old
+            LOGGER.debug("Task cancelled")
+            raise
         except Exception as e:
             # some other error?
             LOGGER.error("Handler error with exception: %s", str(e))
-            raise e
+            raise
 
+    print(".. ready N")
     raise web.HTTPServiceUnavailable(reason="Shutdown in progress")
 
 
@@ -205,7 +223,9 @@ def __init__(
 
         self.context = context.start_scope("admin")
         self.responder = AdminResponder(
-            self.context, outbound_message_router, self.send_webhook,
+            self.context,
+            outbound_message_router,
+            self.send_webhook,
         )
         self.context.injector.bind_instance(BaseResponder, self.responder)
 
@@ -220,12 +240,16 @@ async def make_application(self) -> web.Application:
         assert self.admin_insecure_mode ^ bool(self.admin_api_key)
 
         def is_unprotected_path(path: str):
-            return path in [
-                "/api/doc",
-                "/api/docs/swagger.json",
-                "/favicon.ico",
-                "/ws",  # ws handler checks authentication
-            ] or path.startswith("/static/swagger/")
+            return (
+                path
+                in [
+                    "/api/doc",
+                    "/api/docs/swagger.json",
+                    "/favicon.ico",
+                    "/ws",  # ws handler checks authentication
+                ]
+                or path.startswith("/static/swagger/")
+            )
 
         # If admin_api_key is None, then admin_insecure_mode must be set so
         # we can safely enable the admin server with no security

aries_cloudagent/admin/tests/test_admin_server.py

@@ -55,6 +55,51 @@ async def test_debug_middleware(self):
             mock_logger.isEnabledFor.assert_called_once()
             assert mock_logger.debug.call_count == 3
 
+    async def test_ready_middleware(self):
+        with async_mock.patch.object(
+            test_module, "LOGGER", async_mock.MagicMock()
+        ) as mock_logger:
+            mock_logger.isEnabledFor = async_mock.MagicMock(return_value=True)
+            mock_logger.debug = async_mock.MagicMock()
+            mock_logger.info = async_mock.MagicMock()
+            mock_logger.error = async_mock.MagicMock()
+
+            request = async_mock.MagicMock(
+                rel_url="/", app=async_mock.MagicMock(_state={"ready": False})
+            )
+            handler = async_mock.CoroutineMock(return_value="OK")
+            with self.assertRaises(test_module.web.HTTPServiceUnavailable):
+                await test_module.ready_middleware(request, handler)
+
+            request.app._state["ready"] = True
+            assert await test_module.ready_middleware(request, handler) == "OK"
+
+            request.app._state["ready"] = True
+            handler = async_mock.CoroutineMock(
+                side_effect=test_module.LedgerConfigError("Bad config")
+            )
+            with self.assertRaises(test_module.LedgerConfigError):
+                await test_module.ready_middleware(request, handler)
+
+            request.app._state["ready"] = True
+            handler = async_mock.CoroutineMock(
+                side_effect=test_module.web.HTTPFound(location="/api/doc")
+            )
+            with self.assertRaises(test_module.web.HTTPFound):
+                await test_module.ready_middleware(request, handler)
+
+            request.app._state["ready"] = True
+            handler = async_mock.CoroutineMock(
+                side_effect=test_module.asyncio.CancelledError("Cancelled")
+            )
+            with self.assertRaises(test_module.asyncio.CancelledError):
+                await test_module.ready_middleware(request, handler)
+
+            request.app._state["ready"] = True
+            handler = async_mock.CoroutineMock(side_effect=KeyError("No such thing"))
+            with self.assertRaises(KeyError):
+                await test_module.ready_middleware(request, handler)
+
     def get_admin_server(
         self, settings: dict = None, context: InjectionContext = None
     ) -> AdminServer:

aries_cloudagent/config/argparse.py

@@ -579,7 +579,9 @@ def add_arguments(self, parser: ArgumentParser):
             help="Write timing information to a given log file.",
         )
         parser.add_argument(
-            "--trace", action="store_true", help="Generate tracing events.",
+            "--trace",
+            action="store_true",
+            help="Generate tracing events.",
         )
         parser.add_argument(
             "--trace-target",

aries_cloudagent/config/default_context.py

@@ -122,7 +122,9 @@ async def bind_providers(self, context: InjectionContext):
         )
         context.injector.bind_provider(
             BaseTailsServer,
-            ClassProvider("aries_cloudagent.tails.indy_tails_server.IndyTailsServer",),
+            ClassProvider(
+                "aries_cloudagent.tails.indy_tails_server.IndyTailsServer",
+            ),
         )
 
         # Register default pack format

aries_cloudagent/core/dispatcher.py

@@ -146,7 +146,9 @@ async def handle_message(
             message = None
 
         trace_event(
-            self.context.settings, message, outcome="Dispatcher.handle_message.START",
+            self.context.settings,
+            message,
+            outcome="Dispatcher.handle_message.START",
         )
 
         context = RequestContext(base_context=self.context)

aries_cloudagent/holder/routes.py

@@ -82,11 +82,21 @@ class CredentialsListSchema(OpenAPISchema):
 class CredentialsListQueryStringSchema(OpenAPISchema):
     """Parameters and validators for query string in credentials list query."""
 
-    start = fields.Int(description="Start index", required=False, **WHOLE_NUM,)
+    start = fields.Int(
+        description="Start index",
+        required=False,
+        **WHOLE_NUM,
+    )
     count = fields.Int(
-        description="Maximum number to retrieve", required=False, **NATURAL_NUM,
+        description="Maximum number to retrieve",
+        required=False,
+        **NATURAL_NUM,
+    )
+    wql = fields.Str(
+        description="(JSON) WQL query",
+        required=False,
+        **INDY_WQL,
     )
-    wql = fields.Str(description="(JSON) WQL query", required=False, **INDY_WQL,)
 
 
 class CredIdMatchInfoSchema(OpenAPISchema):
@@ -173,7 +183,8 @@ async def credentials_remove(request: web.BaseRequest):
 
 
 @docs(
-    tags=["credentials"], summary="Fetch credentials from wallet",
+    tags=["credentials"],
+    summary="Fetch credentials from wallet",
 )
 @querystring_schema(CredentialsListQueryStringSchema())
 @response_schema(CredentialsListSchema(), 200)

aries_cloudagent/holder/tests/test_indy.py

@@ -304,7 +304,10 @@ async def test_get_credentials_for_presentation_request_by_referent_default_reft
         }
 
         credentials = await holder.get_credentials_for_presentation_request_by_referent(
-            PRES_REQ, None, 2, 3,
+            PRES_REQ,
+            None,
+            2,
+            3,
         )
 
         mock_prover_search_credentials_for_proof_req.assert_called_once_with(

aries_cloudagent/issuer/indy.py

@@ -64,7 +64,10 @@ async def create_and_store_schema(
 
         with IndyErrorHandler("Error when creating schema", IssuerError):
             schema_id, schema_json = await indy.anoncreds.issuer_create_schema(
-                origin_did, schema_name, schema_version, json.dumps(attribute_names),
+                origin_did,
+                schema_name,
+                schema_version,
+                json.dumps(attribute_names),
             )
         return (schema_id, schema_json)
 

aries_cloudagent/issuer/tests/test_indy.py

@@ -157,7 +157,11 @@ async def test_create_revoke_credentials(
         test_cred_rev_ids = ["42", "54"]
         test_rr_delta = TEST_RR_DELTA
         mock_indy_create_credential.side_effect = [
-            (json.dumps(test_cred), cr_id, test_rr_delta,)
+            (
+                json.dumps(test_cred),
+                cr_id,
+                test_rr_delta,
+            )
             for cr_id in test_cred_rev_ids
         ]
 
@@ -232,7 +236,11 @@ async def test_create_revoke_credentials_x(
         test_cred_rev_ids = ["42", "54", "103"]
         test_rr_delta = TEST_RR_DELTA
         mock_indy_create_credential.side_effect = [
-            (json.dumps(test_cred), cr_id, test_rr_delta,)
+            (
+                json.dumps(test_cred),
+                cr_id,
+                test_rr_delta,
+            )
             for cr_id in test_cred_rev_ids
         ]
 

aries_cloudagent/ledger/indy.py

@@ -368,7 +368,10 @@ async def create_and_send_schema(
 
             try:
                 schema_id, schema_json = await issuer.create_and_store_schema(
-                    public_info.did, schema_name, schema_version, attribute_names,
+                    public_info.did,
+                    schema_name,
+                    schema_version,
+                    attribute_names,
                 )
             except IssuerError as err:
                 raise LedgerError(err.message) from err
@@ -620,7 +623,11 @@ async def create_and_send_credential_definition(
                     credential_definition_id,
                     credential_definition_json,
                 ) = await issuer.create_and_store_credential_definition(
-                    public_info.did, schema, signature_type, tag, support_revocation,
+                    public_info.did,
+                    schema,
+                    signature_type,
+                    tag,
+                    support_revocation,
                 )
             except IssuerError as err:
                 raise LedgerError(err.message) from err

aries_cloudagent/ledger/routes.py

@@ -65,11 +65,19 @@ class TAAAcceptSchema(OpenAPISchema):
 class RegisterLedgerNymQueryStringSchema(OpenAPISchema):
     """Query string parameters and validators for register ledger nym request."""
 
-    did = fields.Str(description="DID to register", required=True, **INDY_DID,)
+    did = fields.Str(
+        description="DID to register",
+        required=True,
+        **INDY_DID,
+    )
     verkey = fields.Str(
         description="Verification key", required=True, **INDY_RAW_PUBLIC_KEY
     )
-    alias = fields.Str(description="Alias", required=False, example="Barry",)
+    alias = fields.Str(
+        description="Alias",
+        required=False,
+        example="Barry",
+    )
     role = fields.Str(
         description="Role",
         required=False,
@@ -99,7 +107,8 @@ class QueryStringEndpointSchema(OpenAPISchema):
 
 
 @docs(
-    tags=["ledger"], summary="Send a NYM registration to the ledger.",
+    tags=["ledger"],
+    summary="Send a NYM registration to the ledger.",
 )
 @querystring_schema(RegisterLedgerNymQueryStringSchema())
 async def register_ledger_nym(request: web.BaseRequest):
@@ -143,7 +152,8 @@ async def register_ledger_nym(request: web.BaseRequest):
 
 
 @docs(
-    tags=["ledger"], summary="Get the role from the NYM registration of a public DID.",
+    tags=["ledger"],
+    summary="Get the role from the NYM registration of a public DID.",
 )
 @querystring_schema(QueryStringDIDSchema)
 async def get_nym_role(request: web.BaseRequest):
@@ -202,7 +212,8 @@ async def rotate_public_did_keypair(request: web.BaseRequest):
 
 
 @docs(
-    tags=["ledger"], summary="Get the verkey for a DID from the ledger.",
+    tags=["ledger"],
+    summary="Get the verkey for a DID from the ledger.",
 )
 @querystring_schema(QueryStringDIDSchema())
 async def get_did_verkey(request: web.BaseRequest):
@@ -236,7 +247,8 @@ async def get_did_verkey(request: web.BaseRequest):
 
 
 @docs(
-    tags=["ledger"], summary="Get the endpoint for a DID from the ledger.",
+    tags=["ledger"],
+    summary="Get the endpoint for a DID from the ledger.",
 )
 @querystring_schema(QueryStringEndpointSchema())
 async def get_did_endpoint(request: web.BaseRequest):