Log user id and token id when applicable.

In rust-lang/rfcs#2947 (comment),
@pietroalbini says, with regards to restricting the default
authorization of API tokens:
> this would break everyone using the token to authenticate to endpoints
> not used by Cargo. Even though we're not providing stability guarantees
> for them I'd be wary of blindly breaking them. At least I'd like some
> stats on which endpoints are accessed with the cookie and which are used
> with tokens.

This change attempts to provide those stats via the logs. All
authenticated requests receive a `uid` field in the log output. If the
request was authenticated via an API token, the log output additionally
contains a `tokenid` field.

Because the method I used, log_request::add_custom_metadata, requires a
mutable request, I had to make req.authenticate() take a mutable ref.
Since that conflicted with many call sites that were already holding an
immutable ref to the request's DB connection, I moved the taking of the
DB connection reference after the authenticate call.

In crate_owner_invitations.rs and follow.rs, this also meant removing
duplicate authenticate calls and passing through the
already-authenticated user ID from a calling function instead.

In a few places, `req.authenticate(&conn)?.find_user(&conn)?` has been
replaced with two lines, one to do the authentication, and one to do the
database lookup for the user object, after `let conn = req.db_conn()?`

Author: jsha

src/controllers.rs

@@ -26,7 +26,7 @@ mod prelude {
     use serde::Serialize;
 
     pub trait UserAuthenticationExt {
-        fn authenticate(&self, conn: &PgConnection) -> AppResult<super::util::AuthenticatedUser>;
+        fn authenticate(&mut self) -> AppResult<super::util::AuthenticatedUser>;
     }
 
     pub trait RequestUtils {

src/controllers/crate_owner_invitation.rs

@@ -6,8 +6,8 @@ use crate::views::{EncodableCrateOwnerInvitation, InvitationResponse};
 
 /// Handles the `GET /me/crate_owner_invitations` route.
 pub fn list(req: &mut dyn RequestExt) -> EndpointResult {
+    let user_id = { req.authenticate()? }.user_id();
     let conn = &*req.db_conn()?;
-    let user_id = req.authenticate(conn)?.user_id();
 
     let crate_owner_invitations = crate_owner_invitations::table
         .filter(crate_owner_invitations::invited_user_id.eq(user_id))
@@ -35,18 +35,17 @@ pub fn handle_invite(req: &mut dyn RequestExt) -> EndpointResult {
     let mut body = String::new();
     req.body().read_to_string(&mut body)?;
 
-    let conn = &*req.db_conn()?;
-
     let crate_invite: OwnerInvitation =
         serde_json::from_str(&body).map_err(|_| bad_request("invalid json request"))?;
 
     let crate_invite = crate_invite.crate_owner_invite;
-    let user_id = req.authenticate(conn)?.user_id();
+    let user_id = req.authenticate()?.user_id();
+    let conn = &*req.db_conn()?;
 
     if crate_invite.accepted {
         accept_invite(req, conn, crate_invite, user_id)
     } else {
-        decline_invite(req, conn, crate_invite)
+        decline_invite(req, conn, crate_invite, user_id)
     }
 }
 
@@ -113,10 +112,10 @@ fn decline_invite(
     req: &dyn RequestExt,
     conn: &PgConnection,
     crate_invite: InvitationResponse,
+    user_id: i32,
 ) -> EndpointResult {
     use diesel::delete;
 
-    let user_id = req.authenticate(conn)?.user_id();
     delete(crate_owner_invitations::table.find((user_id, crate_invite.crate_id))).execute(conn)?;
 
     #[derive(Serialize)]

src/controllers/krate/follow.rs

@@ -7,8 +7,11 @@ use crate::db::DieselPooledConn;
 use crate::models::{Crate, Follow};
 use crate::schema::*;
 
-fn follow_target(req: &dyn RequestExt, conn: &DieselPooledConn<'_>) -> AppResult<Follow> {
-    let user_id = req.authenticate(conn)?.user_id();
+fn follow_target(
+    req: &dyn RequestExt,
+    conn: &DieselPooledConn<'_>,
+    user_id: i32,
+) -> AppResult<Follow> {
     let crate_name = &req.params()["crate_id"];
     let crate_id = Crate::by_name(crate_name)
         .select(crates::id)
@@ -18,8 +21,9 @@ fn follow_target(req: &dyn RequestExt, conn: &DieselPooledConn<'_>) -> AppResult
 
 /// Handles the `PUT /crates/:crate_id/follow` route.
 pub fn follow(req: &mut dyn RequestExt) -> EndpointResult {
+    let user_id = req.authenticate()?.user_id();
     let conn = req.db_conn()?;
-    let follow = follow_target(req, &conn)?;
+    let follow = follow_target(req, &conn, user_id)?;
     diesel::insert_into(follows::table)
         .values(&follow)
         .on_conflict_do_nothing()
@@ -30,8 +34,9 @@ pub fn follow(req: &mut dyn RequestExt) -> EndpointResult {
 
 /// Handles the `DELETE /crates/:crate_id/follow` route.
 pub fn unfollow(req: &mut dyn RequestExt) -> EndpointResult {
+    let user_id = req.authenticate()?.user_id();
     let conn = req.db_conn()?;
-    let follow = follow_target(req, &conn)?;
+    let follow = follow_target(req, &conn, user_id)?;
     diesel::delete(&follow).execute(&*conn)?;
 
     ok_true()
@@ -41,8 +46,9 @@ pub fn unfollow(req: &mut dyn RequestExt) -> EndpointResult {
 pub fn following(req: &mut dyn RequestExt) -> EndpointResult {
     use diesel::dsl::exists;
 
+    let user_id = req.authenticate()?.user_id();
     let conn = req.db_conn()?;
-    let follow = follow_target(req, &conn)?;
+    let follow = follow_target(req, &conn, user_id)?;
     let following = diesel::select(exists(follows::table.find(follow.id()))).get_result(&*conn)?;
 
     #[derive(Serialize)]

src/controllers/krate/owners.rs

@@ -88,12 +88,13 @@ fn parse_owners_request(req: &mut dyn RequestExt) -> AppResult<Vec<String>> {
 }
 
 fn modify_owners(req: &mut dyn RequestExt, add: bool) -> EndpointResult {
+    let authenticated_user = req.authenticate()?;
     let logins = parse_owners_request(req)?;
     let app = req.app();
     let crate_name = &req.params()["crate_id"];
 
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
 
     conn.transaction(|| {
         let krate = Crate::by_name(crate_name).first::<Crate>(&*conn)?;

src/controllers/krate/publish.rs

@@ -45,7 +45,7 @@ pub fn publish(req: &mut dyn RequestExt) -> EndpointResult {
     req.log_metadata("crate_version", new_crate.vers.to_string());
 
     let conn = app.primary_database.get()?;
-    let ids = req.authenticate(&conn)?;
+    let ids = req.authenticate()?;
     let user = ids.find_user(&conn)?;
 
     let verified_email_address = user.verified_email(&conn)?;

src/controllers/krate/search.rs

@@ -5,6 +5,7 @@ use diesel_full_text_search::*;
 
 use crate::controllers::cargo_prelude::*;
 use crate::controllers::helpers::Paginate;
+use crate::controllers::util::AuthenticatedUser;
 use crate::models::{Crate, CrateBadge, CrateOwner, CrateVersions, OwnerKind, Version};
 use crate::schema::*;
 use crate::util::errors::{bad_request, ChainError};
@@ -36,6 +37,9 @@ use crate::models::krate::{canon_crate_name, ALL_COLUMNS};
 pub fn search(req: &mut dyn RequestExt) -> EndpointResult {
     use diesel::sql_types::{Bool, Text};
 
+    // Don't require that authentication succeed, because it's only necessary
+    // if the "following" param is set.
+    let authenticated_user: AppResult<AuthenticatedUser> = req.authenticate();
     let conn = req.db_read_only()?;
     let params = req.query();
     let sort = params.get("sort").map(|s| &**s);
@@ -154,7 +158,7 @@ pub fn search(req: &mut dyn RequestExt) -> EndpointResult {
             ),
         );
     } else if params.get("following").is_some() {
-        let user_id = req.authenticate(&conn)?.user_id();
+        let user_id = authenticated_user?.user_id();
         query = query.filter(
             crates::id.eq_any(
                 follows::table

src/controllers/token.rs

@@ -9,8 +9,9 @@ use serde_json as json;
 
 /// Handles the `GET /me/tokens` route.
 pub fn list(req: &mut dyn RequestExt) -> EndpointResult {
+    let authenticated_user = req.authenticate()?;
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
 
     let tokens = ApiToken::belonging_to(&user)
         .filter(api_tokens::revoked.eq(false))
@@ -60,16 +61,16 @@ pub fn new(req: &mut dyn RequestExt) -> EndpointResult {
         return Err(bad_request("name must have a value"));
     }
 
-    let conn = req.db_conn()?;
-    let ids = req.authenticate(&conn)?;
-    let user = ids.find_user(&conn)?;
-
-    if ids.api_token_id().is_some() {
+    let authenticated_user = req.authenticate()?;
+    if authenticated_user.api_token_id().is_some() {
         return Err(bad_request(
             "cannot use an API token to create a new API token",
         ));
     }
 
+    let conn = req.db_conn()?;
+    let user = authenticated_user.find_user(&conn)?;
+
     let max_token_per_user = 500;
     let count = ApiToken::belonging_to(&user)
         .count()
@@ -98,8 +99,9 @@ pub fn revoke(req: &mut dyn RequestExt) -> EndpointResult {
         .parse::<i32>()
         .map_err(|e| bad_request(&format!("invalid token id: {:?}", e)))?;
 
+    let authenticated_user = req.authenticate()?;
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
     diesel::update(ApiToken::belonging_to(&user).find(id))
         .set(api_tokens::revoked.eq(true))
         .execute(&*conn)?;

src/controllers/user/me.rs

@@ -13,8 +13,8 @@ use crate::views::{EncodableMe, EncodableVersion, OwnedCrate};
 
 /// Handles the `GET /me` route.
 pub fn me(req: &mut dyn RequestExt) -> EndpointResult {
+    let user_id = req.authenticate()?.user_id();
     let conn = req.db_conn()?;
-    let user_id = req.authenticate(&conn)?.user_id();
 
     let (user, verified, email, verification_sent) = users::table
         .find(user_id)
@@ -53,8 +53,9 @@ pub fn me(req: &mut dyn RequestExt) -> EndpointResult {
 pub fn updates(req: &mut dyn RequestExt) -> EndpointResult {
     use diesel::dsl::any;
 
+    let authenticated_user = req.authenticate()?;
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
 
     let followed_crates = Follow::belonging_to(&user).select(follows::crate_id);
     let data = versions::table
@@ -104,12 +105,14 @@ pub fn update_user(req: &mut dyn RequestExt) -> EndpointResult {
     use self::emails::user_id;
     use diesel::insert_into;
 
-    let mut body = String::new();
+    let authenticated_user = req.authenticate()?;
 
+    let mut body = String::new();
     req.body().read_to_string(&mut body)?;
+
     let param_user_id = &req.params()["user_id"];
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
 
     // need to check if current user matches user to be updated
     if &user.id.to_string() != param_user_id {
@@ -187,8 +190,9 @@ pub fn regenerate_token_and_send(req: &mut dyn RequestExt) -> EndpointResult {
     let param_user_id = req.params()["user_id"]
         .parse::<i32>()
         .chain_error(|| bad_request("invalid user_id"))?;
+    let authenticated_user = req.authenticate()?;
     let conn = req.db_conn()?;
-    let user = req.authenticate(&conn)?.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
 
     // need to check if current user matches user to be updated
     if user.id != param_user_id {
@@ -227,8 +231,8 @@ pub fn update_email_notifications(req: &mut dyn RequestExt) -> EndpointResult {
         .map(|c| (c.id, c.email_notifications))
         .collect();
 
+    let user_id = req.authenticate()?.user_id();
     let conn = req.db_conn()?;
-    let user_id = req.authenticate(&conn)?.user_id();
 
     // Build inserts from existing crates belonging to the current user
     let to_insert = CrateOwner::by_owner_kind(OwnerKind::User)

src/controllers/util.rs

@@ -1,6 +1,7 @@
 use super::prelude::*;
 
 use crate::middleware::current_user::TrustedUserId;
+use crate::middleware::log_request;
 use crate::models::{ApiToken, User};
 use crate::util::errors::{
     forbidden, internal, AppError, AppResult, ChainError, InsecurelyGeneratedTokenRevoked,
@@ -29,28 +30,40 @@ impl AuthenticatedUser {
 
 impl<'a> UserAuthenticationExt for dyn RequestExt + 'a {
     /// Obtain `AuthenticatedUser` for the request or return an `Forbidden` error
-    fn authenticate(&self, conn: &PgConnection) -> AppResult<AuthenticatedUser> {
-        if let Some(id) = self.extensions().find::<TrustedUserId>() {
-            // A trusted user_id was provided by a signed cookie (or a test `MockCookieUser`)
+    fn authenticate(&mut self) -> AppResult<AuthenticatedUser> {
+        if let Some(id) = self.extensions().find::<TrustedUserId>().map(|x| x.0) {
+            log_request::add_custom_metadata(self, "uid", id);
             Ok(AuthenticatedUser {
-                user_id: id.0,
+                user_id: id,
                 token_id: None,
             })
         } else {
             // Otherwise, look for an `Authorization` header on the request
-            if let Some(headers) = self.headers().get(header::AUTHORIZATION) {
-                ApiToken::find_by_api_token(conn, headers.to_str().unwrap_or_default())
-                    .map(|token| AuthenticatedUser {
-                        user_id: token.user_id,
-                        token_id: Some(token.id),
-                    })
-                    .map_err(|e| {
-                        if e.is::<InsecurelyGeneratedTokenRevoked>() {
-                            e
-                        } else {
-                            e.chain(internal("invalid token")).chain(forbidden())
-                        }
-                    })
+            let maybe_authorization: Option<String> = {
+                self.headers()
+                    .get(header::AUTHORIZATION)
+                    .and_then(|h| h.to_str().ok())
+                    .map(|h| h.to_string())
+            };
+            if let Some(header_value) = maybe_authorization {
+                let user = {
+                    let conn = self.db_conn()?;
+                    ApiToken::find_by_api_token(&conn, &header_value)
+                        .map(|token| AuthenticatedUser {
+                            user_id: token.user_id,
+                            token_id: Some(token.id),
+                        })
+                        .map_err(|e| {
+                            if e.is::<InsecurelyGeneratedTokenRevoked>() {
+                                e
+                            } else {
+                                e.chain(internal("invalid token")).chain(forbidden())
+                            }
+                        })?
+                };
+                log_request::add_custom_metadata(self, "uid", user.user_id);
+                log_request::add_custom_metadata(self, "tokenid", user.token_id.unwrap_or(0));
+                Ok(user)
             } else {
                 // Unable to authenticate the user
                 Err(internal("no cookie session or auth header found")).chain_error(forbidden)

src/controllers/version/yank.rs

@@ -28,9 +28,9 @@ pub fn unyank(req: &mut dyn RequestExt) -> EndpointResult {
 
 /// Changes `yanked` flag on a crate version record
 fn modify_yank(req: &mut dyn RequestExt, yanked: bool) -> EndpointResult {
+    let authenticated_user = req.authenticate()?;
     let (conn, version, krate) = version_and_crate(req)?;
-    let ids = req.authenticate(&conn)?;
-    let user = ids.find_user(&conn)?;
+    let user = authenticated_user.find_user(&conn)?;
     let owners = krate.owners(&conn)?;
 
     if user.rights(req.app(), &owners)? < Rights::Publish {
@@ -42,7 +42,13 @@ fn modify_yank(req: &mut dyn RequestExt, yanked: bool) -> EndpointResult {
         VersionAction::Unyank
     };
 
-    insert_version_owner_action(&conn, version.id, user.id, ids.api_token_id(), action)?;
+    insert_version_owner_action(
+        &conn,
+        version.id,
+        user.id,
+        authenticated_user.api_token_id(),
+        action,
+    )?;
 
     git::yank(krate.name, version, yanked).enqueue(&conn)?;