Print Error on Permission Denied

[UB18Aux]

Taskwarrior gave me some "Failed to synchronize with server" while trying to sync. Turns out it failed because the server had no permission to write in the default data directory.

The server itself did not show any error unfortunately. The only time it does print an error is when you run it the first time and it cannot initialize the data directory. Running it once with sudo creates the directory / files, but if you run it again without sudo, and syncing fails due to lack of permissions, the server keeps quiet.

Thought it would be helpful to print an error or have some server logs.

[djmitche]

I suspect this could be accomplished generally using the actix-web framework. If not, some "manual" logging could be added to each API method implementation.

[Necior]

The only time it does print an error is when you run it the first time and it cannot initialize the data directory.

Indeed. What's more, the error is barely helpful in this case:

$ cargo run --release
[...]

Error: Permission denied (os error 13)

I created a tiny PR to at least print the path in this case, see https://github.com/GothenburgBitFactory/taskchampion-sync-server/pull/28.

[Necior]

The server itself did not show any error unfortunately.

That's correct. From my understanding there would be a log with the error only when run with RUST_LOG=debug (plus a general info log that the server returned 500):

$ RUST_LOG=debug cargo run
[...]

[2024-07-21T00:33:08Z DEBUG actix_web::middleware::logger] Error in response: Error adding version

    Caused by:
        0: attempt to write a readonly database
        1: Error code 8: Attempt to write a readonly database
[2024-07-21T00:33:08Z INFO  actix_web::middleware::logger] 127.0.0.1 "POST /v1/client/add-version/7e488a84-0a0d-4047-89bd-504cc735e5df HTTP/1.1" 500 20 "-" "ureq/2.9.7" 0.000976

I suspect this could be accomplished generally using the actix-web framework.

It looks like Actix Web does log errors but at the debug level. See https://docs.rs/actix-web/4.8.0/src/actix_web/middleware/logger.rs.html#366-368.

Based on https://github.com/actix/actix-web/issues/1557#issuecomment-1092969047 and https://github.com/actix/actix-web/issues/2637 I understand that it is by design.

IMO TaskChampion Sync-Server should:

1) be more verbose by default and print messages logged at info or above;

• that includes printing an info-level log per request; 2) log 5xx at the error level; 3) log 4xx at the warn level.

@djmitche, what are your thoughts on this?

---

Implementation-wise, a low-hanging fruit is to add logging directly to failure_to_ise:

diff --git a/src/api/mod.rs b/src/api/mod.rs
index bb5001f..e25ad6a 100644
--- a/src/api/mod.rs
+++ b/src/api/mod.rs
@@ -43,6 +43,7 @@ pub(crate) fn api_scope() -> Scope {

 /// Convert a failure::Error to an Actix ISE
 fn failure_to_ise(err: anyhow::Error) -> impl actix_web::ResponseError {
+    log::error!("{err:?}");
     error::InternalError::new(err, StatusCode::INTERNAL_SERVER_ERROR)
 }

but that depends on various places to use this specific function. And it only deals with internal server errors.

Alternatively, an Actix middleware could be implemented. It could log when it observes that a response is in fact an error. I think it could also log at different levels based on the specific error.