[DAPS-1522] Authz Router Logging Improvements#1788
Conversation
Reviewer's GuideRefactors authz_router logging to use a centralized logger with structured request lifecycle events for key endpoints and adds basic unit coverage for perm/check and perm/get routes. Sequence diagram for GET authz/gridftp with structured loggingsequenceDiagram
actor Client
participant AuthzRouter
participant GLib
participant Repo
participant Logger
Client->>AuthzRouter: GET /authz/gridftp?client&repo&file&act
AuthzRouter->>GLib: getUserFromClientID client
GLib-->>AuthzRouter: client
AuthzRouter->>Logger: logRequestStarted client_id, correlationId, GET, authz/gridftp, Started, description
alt client lookup fallback
AuthzRouter->>GLib: getUserFromClientID_noexcept client
GLib-->>AuthzRouter: client_or_null
end
alt client not found
AuthzRouter->>Logger: logRequestFailure client_null, correlationId, GET, authz/gridftp, Failure, description, error(ERR_PERM_DENIED)
AuthzRouter->>GLib: handleException error, res
GLib-->>Client: error response
else client found
AuthzRouter->>Repo: new Repo repo
AuthzRouter->>Repo: get_path_type file
Repo-->>AuthzRouter: PathType
alt path_type UNKNOWN
AuthzRouter->>Logger: logRequestFailure client_id, correlationId, GET, authz/gridftp, Failure, description, error(ERR_PERM_DENIED)
AuthzRouter->>GLib: handleException error, res
GLib-->>Client: error response
else path_type valid
AuthzRouter->>AuthzRouter: check act against permissions
alt authorized
AuthzRouter-->>Client: success response
AuthzRouter->>Logger: logRequestSuccess client_id, correlationId, GET, authz/gridftp, Success, description, extra(client_id,is_admin)
else not authorized
AuthzRouter->>Logger: logRequestFailure client_id, correlationId, GET, authz/gridftp, Failure, description, error(ERR_PERM_DENIED)
AuthzRouter->>GLib: handleException error, res
GLib-->>Client: error response
end
end
end
opt unexpected error
AuthzRouter->>Logger: logRequestFailure client_maybe_null, correlationId, GET, authz/gridftp, Failure, description, error(e)
AuthzRouter->>GLib: handleException e, res
GLib-->>Client: error response
end
Sequence diagram for GET authz/perm/check and authz/perm/get logging lifecyclesequenceDiagram
actor Client
participant AuthzRouter
participant GLib
participant Logger
Client->>AuthzRouter: GET /authz/perm/check or /authz/perm/get
AuthzRouter->>GLib: getUserFromClientID client
GLib-->>AuthzRouter: client
alt perm_check_route
AuthzRouter->>Logger: logRequestStarted client_id, correlationId, GET, authz/perm/check, Started, description
else perm_get_route
AuthzRouter->>Logger: logRequestStarted client_id, correlationId, GET, authz/perm/get, Started, description
end
AuthzRouter->>GLib: resolveID id, client
GLib-->>AuthzRouter: type_and_id
AuthzRouter->>AuthzRouter: compute permissions result
alt handler succeeds
AuthzRouter-->>Client: {granted: result}
alt perm_check_route
AuthzRouter->>Logger: logRequestSuccess client_id, correlationId, GET, authz/perm/check, Success, description, extra(result)
else perm_get_route
AuthzRouter->>Logger: logRequestSuccess client_id, correlationId, GET, authz/perm/get, Success, description, extra(result)
end
else handler throws error
alt perm_check_route
AuthzRouter->>Logger: logRequestFailure client_id, correlationId, GET, authz/perm/check, Failure, description, extra(result), error(e)
else perm_get_route
AuthzRouter->>Logger: logRequestFailure client_id, correlationId, GET, authz/perm/get, Failure, description, extra(result), error(e)
end
AuthzRouter->>GLib: handleException e, res
GLib-->>Client: error response
end
Class diagram for authz_router logging integrationclassDiagram
class AuthzRouter {
+get_gridftp(req,res) void
+get_perm_check(req,res) void
+get_perm_get(req,res) void
}
class Logger {
+logRequestStarted(client,correlationId,httpVerb,routePath,status,description) void
+logRequestSuccess(client,correlationId,httpVerb,routePath,status,description,extra) void
+logRequestFailure(client,correlationId,httpVerb,routePath,status,description,extra,error) void
}
class GLib {
+getUserFromClientID(clientId) Client
+getUserFromClientID_noexcept(clientId) Client
+resolveID(id,client) Tuple
+handleException(error,res) void
}
class Repo {
+Repo(repoId)
+get_path_type(path) PathType
}
class Client {
+_id string
+is_admin boolean
}
AuthzRouter ..> Logger : uses
AuthzRouter ..> GLib : uses
AuthzRouter ..> Repo : uses
GLib ..> Client : returns
Repo ..> PathType : returns
File-Level Changes
Tips and commandsInteracting with Sourcery
Customizing Your ExperienceAccess your dashboard to:
Getting Help
|
There was a problem hiding this comment.
Hey there - I've reviewed your changes - here's some feedback:
- In the /gridftp handler you now call both getUserFromClientID and getUserFromClientID_noexcept on the same client value; consider using a single, consistent helper and reusing the result to avoid redundant lookups and subtle behavior changes.
- The logRequestStarted call in /gridftp passes description as a JSON.stringify’d object while other routes pass plain strings; consider moving the structured fields into the extra payload and keeping description as a consistent string type across routes.
- The logger.logRequestFailure calls receive e directly, but many throw sites use array-based errors; consider normalizing errors (e.g., to an object with code/message) before logging so the logger doesn’t need to handle multiple ad-hoc shapes.
Prompt for AI Agents
Please address the comments from this code review:
## Overall Comments
- In the /gridftp handler you now call both getUserFromClientID and getUserFromClientID_noexcept on the same client value; consider using a single, consistent helper and reusing the result to avoid redundant lookups and subtle behavior changes.
- The logRequestStarted call in /gridftp passes description as a JSON.stringify’d object while other routes pass plain strings; consider moving the structured fields into the extra payload and keeping description as a consistent string type across routes.
- The logger.logRequestFailure calls receive e directly, but many throw sites use array-based errors; consider normalizing errors (e.g., to an object with code/message) before logging so the logger doesn’t need to handle multiple ad-hoc shapes.
## Individual Comments
### Comment 1
<location> `core/database/foxx/api/authz_router.js:20-29` </location>
<code_context>
- "act",
- req.queryParams.act,
- );
+ client = g_lib.getUserFromClientID(req.queryParams.client);
+ logger.logRequestStarted({
+ client: client?._id,
</code_context>
<issue_to_address>
**issue (bug_risk):** Avoid doing two different client lookups in /gridftp and clarify which behavior is intended.
In /gridftp you first call `getUserFromClientID` and later overwrite `client` via `getUserFromClientID_noexcept`. If the first call throws on unknown clients, the second is never used; if it doesn’t throw, you’re doing two lookups with different semantics. Please choose a single lookup method (e.g., use `_noexcept` once, then explicitly throw if needed) and base both error handling and logging on that one result to avoid redundant work and ambiguous behavior.
</issue_to_address>
### Comment 2
<location> `core/database/foxx/api/authz_router.js:18-27` </location>
<code_context>
router
.get("/gridftp", function (req, res) {
+ let client = null;
try {
- console.log(
</code_context>
<issue_to_address>
**suggestion:** The `extra: result` field in perm/check logging is a bit ambiguous and may be more useful if it carries richer context.
In `/perm/check`, `result` is initialized to `true`, updated during checks, and always logged as `extra: result` on both success and failure. On failure, it may still be `true` or `null` depending on where the exception occurred, which makes the log unclear. Consider either logging a more structured payload (e.g. `{ granted: result, perms, id, type: ty }`) or omitting `extra` on failure and relying on the error/description so the logs are easier to interpret when debugging authorization issues.
Suggested implementation:
```javascript
logger.info(
{
service: basePath,
action: "perm/check",
// Provide richer, structured context for successful checks
extra: {
granted: result,
perms,
id,
type: ty,
},
},
"permission check succeeded"
);
```
```javascript
logger.error(
{
service: basePath,
action: "perm/check",
// On failure, rely on error/description and avoid ambiguous `result`
err,
},
"permission check failed"
);
```
I only saw a small portion of the file, so you may need to adjust variable names and structures to match your existing code:
1) Ensure the `/perm/check` handler defines and passes `perms`, `id`, and `ty` (or the equivalent variables you actually use in the check) into the logging context. If the names differ, update the `extra` object accordingly.
2) If there are multiple success/failure log statements for `/perm/check` (e.g. early returns, multiple try/catch blocks), make similar changes to all of them:
- Replace `extra: result` on success with a structured object that includes:
- `granted` (the final decision)
- The requested permissions (e.g. `perms`)
- The resource identifier (e.g. `id`)
- The resource type (e.g. `type`/`ty`)
- Remove `extra: result` from failure logs, or if you prefer to keep context, change it to a structured object with `granted: false` and any fields that are reliably available at the failure point.
3) If `result` is not a simple boolean or if it can be `null/undefined` at some points, make sure you only log it as `granted` when it reflects the final authorization decision; otherwise, either omit it or normalize it (e.g. `Boolean(result)`).
4) If you have structured logging helpers/wrappers around `logger` in this repo, consider using those instead of direct calls, but preserve the `extra` shape as suggested above.
</issue_to_address>
### Comment 3
<location> `core/database/foxx/tests/authz_router.test.js:341-350` </location>
<code_context>
+ //
+ // ===== PERM CHECK TESTS =====
+ //
+ it("unit_authz_router: perm/check should return granted=true for admin user on owned record", () => {
+ defaultWorkingSetup();
+
+ const request_string =
+ `${authz_base_url}/perm/check?client=` +
+ james_uuid +
+ `&id=` +
+ encodeURIComponent(record_id) +
+ `&perms=` +
+ permissions.PERM_ALL;
+
+ const response = request.get(request_string);
+
+ expect(response.status).to.equal(200);
+ const body = JSON.parse(response.body);
+ expect(body).to.have.property("granted", true);
+ });
+ //
</code_context>
<issue_to_address>
**suggestion (testing):** Add negative and edge-case tests for /perm/check route
Please also add tests that cover: (1) a client without sufficient permissions where `granted` should be `false` and the status code is verified, (2) an invalid/malformed `id` that exercises the error-handling path, and (3) a request with `perms` omitted to confirm the default `permissions.PERM_ALL` behavior. This will ensure the permission and error handling logic are fully covered after the logging changes.
Suggested implementation:
```javascript
// ===== PERM CHECK TESTS =====
//
it("unit_authz_router: perm/check should return granted=true for admin user on owned record", () => {
defaultWorkingSetup();
const request_string =
`${authz_base_url}/perm/check?client=` +
james_uuid +
`&id=` +
encodeURIComponent(record_id) +
`&perms=` +
permissions.PERM_ALL;
const response = request.get(request_string);
expect(response.status).to.equal(200);
const body = JSON.parse(response.body);
expect(body).to.have.property("granted", true);
});
it("unit_authz_router: perm/check should return granted=false for client without sufficient permissions", () => {
defaultWorkingSetup();
const request_string =
`${authz_base_url}/perm/check?client=` +
limited_client_uuid +
`&id=` +
encodeURIComponent(record_id) +
`&perms=` +
permissions.PERM_ALL;
const response = request.get(request_string);
expect(response.status).to.equal(200);
const body = JSON.parse(response.body);
expect(body).to.have.property("granted", false);
});
it("unit_authz_router: perm/check should handle invalid id with appropriate error status", () => {
defaultWorkingSetup();
const request_string =
`${authz_base_url}/perm/check?client=` +
james_uuid +
`&id=` +
encodeURIComponent("%%%invalid-id%%%") +
`&perms=` +
permissions.PERM_ALL;
const response = request.get(request_string);
expect(response.status).to.equal(400);
const body = JSON.parse(response.body);
expect(body).to.have.property("error", true);
});
it("unit_authz_router: perm/check should default to PERM_ALL when perms is omitted", () => {
defaultWorkingSetup();
const request_string =
`${authz_base_url}/perm/check?client=` +
james_uuid +
`&id=` +
encodeURIComponent(record_id);
const response = request.get(request_string);
expect(response.status).to.equal(200);
const body = JSON.parse(response.body);
expect(body).to.have.property("granted", true);
});
//
```
To fully integrate these tests with the rest of the file, you will likely need to:
1) Define `limited_client_uuid` in the test setup (near where `james_uuid` and other client identifiers are defined), ensuring it corresponds to a client that:
- Exists in the test fixtures.
- Has access to the same record but lacks sufficient permissions so that `/perm/check` returns `{ granted: false }` with HTTP 200.
2) Confirm the error-handling contract for an invalid `id`:
- If the route currently returns a different status code (e.g. 404 or 422 instead of 400) or a different error shape, adjust:
- `expect(response.status).to.equal(400);`
- `expect(body).to.have.property("error", true);`
to match the actual behavior (e.g. checking for `body.errorNum`, `body.errorMessage`, or similar Arango/foxx error fields).
3) Ensure that omitting `perms` in the query string truly defaults to `permissions.PERM_ALL` for admin users:
- If the default is different, or if the route requires `perms` and errors when it is missing, update the last test to assert the actual expected behavior (either error or a different `granted` value).
4) Keep the coding style consistent with the rest of the file:
- If other tests use different fixture names, assertion helpers, or response body shapes, adapt the new tests accordingly while preserving their intent: one negative permission case, one invalid-id error case, and one default-perms case.
</issue_to_address>
### Comment 4
<location> `core/database/foxx/tests/authz_router.test.js:361-370` </location>
<code_context>
+ //
+ // ===== PERM GET TESTS =====
+ //
+ it("unit_authz_router: perm/get should return permission bits for admin user on record", () => {
+ defaultWorkingSetup();
+
+ const request_string =
+ `${authz_base_url}/perm/get?client=` +
+ james_uuid +
+ `&id=` +
+ encodeURIComponent(record_id);
+
+ const response = request.get(request_string);
+
+ expect(response.status).to.equal(200);
+ const body = JSON.parse(response.body);
+ expect(body).to.have.property("granted");
+ expect(body.granted).to.be.a("number");
+ });
+
</code_context>
<issue_to_address>
**suggestion (testing):** Strengthen perm/get success test by asserting the expected permission bits, not just type
This test only verifies that `body.granted` is numeric. Since the permission bits are deterministic for `defaultWorkingSetup()` with `james_uuid` and `record_id`, please assert the exact expected bitmask (e.g. `expect(body.granted).to.equal(permissions.PERM_ALL)` or the correct combination) so unintended changes to the permission calculation will be caught.
Suggested implementation:
```javascript
const response = request.get(request_string);
expect(response.status).to.equal(200);
const body = JSON.parse(response.body);
expect(body).to.have.property("granted");
expect(body.granted).to.equal(permissions.PERM_ALL);
});
//
// ===== PERM GET TESTS =====
//
const request_string =
`${authz_base_url}/perm/check?client=` +
james_uuid +
`&id=` +
encodeURIComponent(record_id) +
`&perms=` +
permissions.PERM_ALL;
const response = request.get(request_string);
```
From the provided snippet, it looks like this assertion might still belong to the `perm/check` test immediately before the `// ===== PERM GET TESTS =====` marker, and the new `perm/get` test itself is not fully shown.
To fully implement your suggestion for the `perm/get` success test, please also:
1. Locate the `it("unit_authz_router: perm/get should return permission bits for admin user on record", ...)` block added by the developer.
2. Inside that test, after parsing `body`, replace:
- `expect(body).to.have.property("granted");`
- `expect(body.granted).to.be.a("number");`
with:
- `expect(body).to.have.property("granted");`
- `expect(body.granted).to.equal(permissions.PERM_ALL);`
(or the precise expected bitmask if it differs from `PERM_ALL` for this scenario).
This will ensure both the `perm/check` and `perm/get` tests assert the exact, deterministic permission bitmask instead of just the type or a boolean, catching unintended changes to the permission calculation.
</issue_to_address>
### Comment 5
<location> `core/database/foxx/tests/authz_router.test.js:378-387` </location>
<code_context>
+ expect(body.granted).to.be.a("number");
+ });
+
+ it("unit_authz_router: perm/get should fail with invalid id", () => {
+ defaultWorkingSetup();
+
+ const request_string =
+ `${authz_base_url}/perm/get?client=` +
+ james_uuid +
+ `&id=` +
+ encodeURIComponent("x/invalid") +
+ `&perms=` +
+ permissions.PERM_ALL;
+
+ const response = request.get(request_string);
+ expect(response.status).to.equal(400);
+ });
});
</code_context>
<issue_to_address>
**suggestion (testing):** Extend invalid id test to verify error payload and specific failure semantics
In addition to asserting the 400 status, please also verify the response body matches the expected error payload from `handleException` (e.g., error code/message). This will ensure the test exercises the correct error path and protects the error contract clients depend on.
Suggested implementation:
```javascript
it("unit_authz_router: perm/get should fail with invalid id", () => {
defaultWorkingSetup();
const request_string =
`${authz_base_url}/perm/get?client=` +
james_uuid +
`&id=` +
encodeURIComponent("x/invalid") +
`&perms=` +
permissions.PERM_ALL;
const response = request.get(request_string);
expect(response.status).to.equal(400);
const body = JSON.parse(response.body);
// Verify handleException-style error payload and semantics
expect(body).to.be.an("object");
expect(body).to.have.property("error").that.is.true;
// These expectations should mirror the error contract used by handleException
// Adjust the property names / values below to match the real implementation.
expect(body).to.have.property("code").that.is.a("number");
expect(body).to.have.property("errorNum").that.is.a("number");
expect(body).to.have.property("errorMessage").that.is.a("string");
});
```
To fully align this test with the behavior of handleException in your codebase, you should:
1) Confirm the exact error payload shape produced for invalid IDs by handleException (or the authz router’s error path), including:
- Property names (e.g., error, code, errorNum, errorMessage, errorCode, message, etc.).
- The specific numeric error code / errorNum or string errorCode used for "invalid id".
2) Replace the generic expectations in the new assertions with precise ones, for example:
- expect(body.error).to.equal(true);
- expect(body.code).to.equal(400);
- expect(body.errorNum).to.equal(SOME_CONSTANT_FOR_INVALID_ID);
- expect(body.errorMessage).to.match(/invalid id/i);
3) If the tests in this file already assert on a handleException payload elsewhere, mirror that convention here so that all error tests are consistent.
</issue_to_address>
### Comment 6
<location> `core/database/foxx/api/authz_router.js:145` </location>
<code_context>
</code_context>
<issue_to_address>
**issue (code-quality):** Use `const` or `let` instead of `var`. ([`avoid-using-var`](https://docs.sourcery.ai/Reference/Rules-and-In-Line-Suggestions/JavaScript/Default-Rules/avoid-using-var))
<details><summary>Explanation</summary>`const` is preferred as it ensures you cannot reassign references (which can lead to buggy and confusing code).
`let` may be used if you need to reassign references - it's preferred to `var` because it is block- rather than
function-scoped.
From the [Airbnb JavaScript Style Guide](https://airbnb.io/javascript/#references--prefer-const)
</details>
</issue_to_address>
### Comment 7
<location> `core/database/foxx/api/authz_router.js:245` </location>
<code_context>
result = req.queryParams.perms ? req.queryParams.perms : permissions.PERM_ALL;
</code_context>
<issue_to_address>
**suggestion (code-quality):** Avoid unneeded ternary statements ([`simplify-ternary`](https://docs.sourcery.ai/Reference/Rules-and-In-Line-Suggestions/JavaScript/Default-Rules/simplify-ternary))
```suggestion
result = req.queryParams.perms || permissions.PERM_ALL;
```
<br/><details><summary>Explanation</summary>It is possible to simplify certain ternary statements into either use of an `||` or `!`.
This makes the code easier to read, since there is no conditional logic.
</details>
</issue_to_address>Help me be more useful! Please click 👍 or 👎 on each comment and I'll use the feedback to improve your reviews.
| client = g_lib.getUserFromClientID(req.queryParams.client); | ||
| logger.logRequestStarted({ | ||
| client: client?._id, | ||
| correlationId: req.headers["x-correlation-id"], | ||
| httpVerb: "GET", | ||
| routePath: basePath + "/gridftp", | ||
| status: "Started", | ||
| description: JSON.stringify({ | ||
| message: "Checks authorization", | ||
| repo: req.queryParams.repo, |
There was a problem hiding this comment.
issue (bug_risk): Avoid doing two different client lookups in /gridftp and clarify which behavior is intended.
In /gridftp you first call getUserFromClientID and later overwrite client via getUserFromClientID_noexcept. If the first call throws on unknown clients, the second is never used; if it doesn’t throw, you’re doing two lookups with different semantics. Please choose a single lookup method (e.g., use _noexcept once, then explicitly throw if needed) and base both error handling and logging on that one result to avoid redundant work and ambiguous behavior.
| let client = null; | ||
| try { | ||
| console.log( | ||
| "/gridftp start authz client", | ||
| req.queryParams.client, | ||
| "repo", | ||
| req.queryParams.repo, | ||
| "file", | ||
| req.queryParams.file, | ||
| "act", | ||
| req.queryParams.act, | ||
| ); | ||
| client = g_lib.getUserFromClientID(req.queryParams.client); | ||
| logger.logRequestStarted({ | ||
| client: client?._id, | ||
| correlationId: req.headers["x-correlation-id"], | ||
| httpVerb: "GET", | ||
| routePath: basePath + "/gridftp", | ||
| status: "Started", | ||
| description: JSON.stringify({ |
There was a problem hiding this comment.
suggestion: The extra: result field in perm/check logging is a bit ambiguous and may be more useful if it carries richer context.
In /perm/check, result is initialized to true, updated during checks, and always logged as extra: result on both success and failure. On failure, it may still be true or null depending on where the exception occurred, which makes the log unclear. Consider either logging a more structured payload (e.g. { granted: result, perms, id, type: ty }) or omitting extra on failure and relying on the error/description so the logs are easier to interpret when debugging authorization issues.
Suggested implementation:
logger.info(
{
service: basePath,
action: "perm/check",
// Provide richer, structured context for successful checks
extra: {
granted: result,
perms,
id,
type: ty,
},
},
"permission check succeeded"
); logger.error(
{
service: basePath,
action: "perm/check",
// On failure, rely on error/description and avoid ambiguous `result`
err,
},
"permission check failed"
);I only saw a small portion of the file, so you may need to adjust variable names and structures to match your existing code:
- Ensure the
/perm/checkhandler defines and passesperms,id, andty(or the equivalent variables you actually use in the check) into the logging context. If the names differ, update theextraobject accordingly. - If there are multiple success/failure log statements for
/perm/check(e.g. early returns, multiple try/catch blocks), make similar changes to all of them:- Replace
extra: resulton success with a structured object that includes:granted(the final decision)- The requested permissions (e.g.
perms) - The resource identifier (e.g.
id) - The resource type (e.g.
type/ty)
- Remove
extra: resultfrom failure logs, or if you prefer to keep context, change it to a structured object withgranted: falseand any fields that are reliably available at the failure point.
- Replace
- If
resultis not a simple boolean or if it can benull/undefinedat some points, make sure you only log it asgrantedwhen it reflects the final authorization decision; otherwise, either omit it or normalize it (e.g.Boolean(result)). - If you have structured logging helpers/wrappers around
loggerin this repo, consider using those instead of direct calls, but preserve theextrashape as suggested above.
JoshuaSBrown
left a comment
There was a problem hiding this comment.
Looking good, similar comments to the others.
Ticket
#1522
Description
Logging improvements to authz_router
Tasks
Summary by Sourcery
Improve observability and test coverage for the authz_router service.
Enhancements:
Tests: