Add debug logging for endpoints that don't have a user but affect a u…

…ser (#856) * Add debug logging for endpoints that don't have a user but affect a user E.g. this is useful to see if someone is actively trying to reset someone's password. * Put action in field instead of log message
wireapp · Sep 30, 2019 · dbebc7c · dbebc7c
1 parent cfb60bc
commit dbebc7c
Show file tree

Hide file tree

Showing 4 changed files with 24 additions and 14 deletions.
diff --git a/services/brig/src/Brig/API/User.hs b/services/brig/src/Brig/API/User.hs
@@ -155,7 +155,7 @@ createUser new@NewUser{..} = do
     -- Create account
     (account, pw) <- lift $ newAccount new { newUserIdentity = ident } (Team.inInvitation . fst <$> teamInvitation) tid
     let uid = userId (accountUser account)
-
+    Log.debug $ field "user" (toByteString uid) . field "action" (Log.val "User.createUser")
     Log.info $ field "user" (toByteString uid) . msg (val "Creating user")
     activatedTeam <- lift $ do
         Data.insertAccount account Nothing pw False searchable
@@ -514,6 +514,7 @@ preverify tgt code = do
 onActivated :: ActivationEvent -> AppIO (UserId, Maybe UserIdentity, Bool)
 onActivated (AccountActivated account) = do
     let uid = userId (accountUser account)
+    Log.debug $ field "user" (toByteString uid) . field  "action" (Log.val "User.onActivated")
     Log.info $ field "user" (toByteString uid) . msg (val "User activated")
     Intra.onUserEvent uid Nothing $ UserActivated account
     return (uid, userIdentity (accountUser account), True)
@@ -638,6 +639,7 @@ beginPasswordReset :: Either Email Phone -> ExceptT PasswordResetError AppIO (Us
 beginPasswordReset target = do
     let key = either userEmailKey userPhoneKey target
     user <- lift (Data.lookupKey key) >>= maybe (throwE InvalidPasswordResetKey) return
+    Log.debug $ field "user" (toByteString user) . field "action" (Log.val "User.beginPasswordReset")
     status <- lift $ Data.lookupStatus user
     unless (status == Just Active) $
         throwE InvalidPasswordResetKey
@@ -653,6 +655,7 @@ completePasswordReset ident code pw = do
     case muid of
         Nothing  -> throwE InvalidPasswordResetCode
         Just uid -> do
+            Log.debug $ field "user" (toByteString uid) . field "action" (Log.val "User.completePasswordReset")
             checkNewIsDifferent uid pw
             lift $ do
                 Data.updatePassword uid pw

diff --git a/services/brig/src/Brig/User/Auth.hs b/services/brig/src/Brig/User/Auth.hs
@@ -67,6 +67,7 @@ sendLoginCode phone call force = do
     case user of
         Nothing -> throwE $ SendLoginInvalidPhone phone
         Just  u -> do
+            Log.debug $ field "user" (toByteString u) . field "action" (Log.val "User.sendLoginCode")
             pw <- lift $ Data.lookupPassword u
             unless (isNothing pw || force) $
                 throwE SendLoginPasswordExists
@@ -81,11 +82,14 @@ sendLoginCode phone call force = do
 lookupLoginCode :: Phone -> AppIO (Maybe PendingLoginCode)
 lookupLoginCode phone = Data.lookupKey (userPhoneKey phone) >>= \case
     Nothing -> return Nothing
-    Just  u -> Data.lookupLoginCode u
+    Just  u -> do
+      Log.debug $ field "user" (toByteString u) . field "action" (Log.val "User.lookupLoginCode")
+      Data.lookupLoginCode u
 
 login :: Login -> CookieType -> ExceptT LoginError AppIO (Access ZAuth.User)
 login (PasswordLogin li pw label) typ = do
     uid <- resolveLoginId li
+    Log.debug $ field "user" (toByteString uid) . field "action" (Log.val "User.login")
     checkRetryLimit uid
     Data.authenticate uid pw `catchE` \case
         AuthSuspended          -> throwE LoginSuspended
@@ -95,6 +99,7 @@ login (PasswordLogin li pw label) typ = do
     newAccess @ZAuth.User @ZAuth.Access uid typ label
 login (SmsLogin phone code label) typ = do
     uid <- resolveLoginId (LoginByPhone phone)
+    Log.debug $ field "user" (toByteString uid) . field "action" (Log.val "User.login")
     checkRetryLimit uid
     ok <- lift $ Data.verifyLoginCode uid code
     unless ok $
@@ -138,6 +143,7 @@ renewAccess
     -> ExceptT ZAuth.Failure AppIO (Access u)
 renewAccess ut at = do
     (uid, ck) <- validateTokens ut at
+    Log.debug $ field "user" (toByteString uid) . field "action" (Log.val "User.renewAccess")
     catchSuspendInactiveUser uid ZAuth.Expired
     ck' <- lift $ nextCookie ck
     at' <- lift $ newAccessToken (fromMaybe ck ck') at
@@ -150,6 +156,7 @@ revokeAccess
     -> [CookieLabel]
     -> ExceptT AuthError AppIO ()
 revokeAccess u pw cc ll = do
+    Log.debug $ field "user" (toByteString u) . field "action" (Log.val "User.revokeAccess")
     Data.authenticate u pw
     lift $ revokeCookies u cc ll
 

diff --git a/services/galley/src/Galley/API/LegalHold.hs b/services/galley/src/Galley/API/LegalHold.hs
@@ -44,7 +44,7 @@ createSettings (zusr ::: tid ::: req ::: _) = do
     membs <- Data.teamMembers tid
     let zothers = map (view userId) membs
     Log.debug $ Log.field "targets" (toByteString . show $ toByteString <$> zothers)
-              . Log.msg (Log.val "LegalHold.createSettings")
+              . Log.field "action" (Log.val "LegalHold.createSettings")
 
     void $ permissionCheck zusr ChangeLegalHoldTeamSettings membs
 
@@ -78,7 +78,7 @@ removeSettings (zusr ::: tid ::: req ::: _) = do
     membs <- Data.teamMembers tid
     let zothers = map (view userId) membs
     Log.debug $ Log.field "targets" (toByteString . show $ toByteString <$> zothers)
-              . Log.msg (Log.val "LegalHold.removeSettings")
+              . Log.field "action" (Log.val "LegalHold.removeSettings")
 
     void $ permissionCheck zusr ChangeLegalHoldTeamSettings membs
     RemoveLegalHoldSettingsRequest mPassword <- fromJsonBody req
@@ -96,7 +96,7 @@ removeSettings' tid mMembers = do
     membs <- maybe (Data.teamMembers tid) pure mMembers
     let zothers = map (view userId) membs
     Log.debug $ Log.field "targets" (toByteString . show $ toByteString <$> zothers)
-              . Log.msg (Log.val "LegalHold.removeSettings'")
+              . Log.field "action" (Log.val "LegalHold.removeSettings'")
 
     let lhMembers = filter ((== UserLegalHoldEnabled) . view legalHoldStatus) membs
     -- I picked this number by fair dice roll, feel free to change it :P
@@ -141,7 +141,7 @@ requestDevice (zusr ::: tid ::: uid ::: _) = do
     assertLegalHoldEnabled tid
 
     Log.debug $ Log.field "targets" (toByteString uid)
-              . Log.msg (Log.val "LegalHold.requestDevice")
+              . Log.field "action" (Log.val "LegalHold.requestDevice")
     membs <- Data.teamMembers tid
     void $ permissionCheck zusr ChangeLegalHoldUserSettings membs
 
@@ -178,7 +178,7 @@ approveDevice
 approveDevice (zusr ::: tid ::: uid ::: connId ::: req ::: _) = do
     assertLegalHoldEnabled tid
     Log.debug $ Log.field "targets" (toByteString uid)
-              . Log.msg (Log.val "LegalHold.approveDevice")
+              . Log.field "action" (Log.val "LegalHold.approveDevice")
 
     unless (zusr == uid) (throwM accessDenied)
     assertOnTeam uid tid
@@ -220,7 +220,7 @@ disableForUser
   -> Galley Response
 disableForUser (zusr ::: tid ::: uid ::: req ::: _) = do
     Log.debug $ Log.field "targets" (toByteString uid)
-              . Log.msg (Log.val "LegalHold.disableForUser")
+              . Log.field "action" (Log.val "LegalHold.disableForUser")
     membs <- Data.teamMembers tid
     void $ permissionCheck zusr ChangeLegalHoldUserSettings membs
     if userLHNotDisabled membs

diff --git a/services/galley/src/Galley/API/Teams.hs b/services/galley/src/Galley/API/Teams.hs
@@ -114,7 +114,7 @@ createNonBindingTeam (zusr::: zcon ::: req ::: _) = do
     ensureUnboundUsers (zusr : zothers)
     ensureConnected zusr zothers
     Log.debug $ Log.field "targets" (toByteString . show $ toByteString <$> zothers)
-              . Log.msg (Log.val "Teams.createNonBindingTeam")
+              . Log.field "action" (Log.val "Teams.createNonBindingTeam")
     team <- Data.createTeam Nothing zusr (body^.newTeamName) (body^.newTeamIcon) (body^.newTeamIconKey) NonBinding
     finishCreateTeam team owner others (Just zcon)
 
@@ -154,7 +154,7 @@ updateTeam (zusr::: zcon ::: tid ::: req ::: _) = do
     membs <- Data.teamMembers tid
     let zothers = map (view userId) membs
     Log.debug $ Log.field "targets" (toByteString . show $ toByteString <$> zothers)
-              . Log.msg (Log.val "Teams.updateTeam")
+              . Log.field "action" (Log.val "Teams.updateTeam")
     void $ permissionCheck zusr SetTeamData membs
     Data.updateTeam tid body
     now <- liftIO getCurrentTime
@@ -256,7 +256,7 @@ addTeamMember (zusr ::: zcon ::: tid ::: req ::: _) = do
     nmem <- fromJsonBody req
     let uid = nmem^.ntmNewTeamMember.userId
     Log.debug $ Log.field "targets" (toByteString uid)
-              . Log.msg (Log.val "Teams.addTeamMember")
+              . Log.field "action" (Log.val "Teams.addTeamMember")
     mems <- Data.teamMembers tid
     -- verify permissions
     tmem <- permissionCheck zusr AddTeamMember mems
@@ -285,7 +285,7 @@ updateTeamMember (zusr ::: zcon ::: tid ::: req ::: _) = do
         targetPermissions = targetMember^.permissions
 
     Log.debug $ Log.field "targets" (toByteString targetId)
-              . Log.msg (Log.val "Teams.updateTeamMember")
+              . Log.field "action" (Log.val "Teams.updateTeamMember")
 
     -- get the team and verify permissions
     team    <- tdTeam <$> (Data.team tid >>= ifNothing teamNotFound)
@@ -332,7 +332,7 @@ updateTeamMember (zusr ::: zcon ::: tid ::: req ::: _) = do
 deleteTeamMember :: UserId ::: ConnId ::: TeamId ::: UserId ::: Request ::: Maybe JSON ::: JSON -> Galley Response
 deleteTeamMember (zusr::: zcon ::: tid ::: remove ::: req ::: _ ::: _) = do
     Log.debug $ Log.field "targets" (toByteString remove)
-              . Log.msg (Log.val "Teams.deleteTeamMember")
+              . Log.field "action" (Log.val "Teams.deleteTeamMember")
     mems <- Data.teamMembers tid
     void $ permissionCheck zusr RemoveTeamMember mems
     okToDelete <- canBeDeleted [] remove tid
@@ -468,7 +468,7 @@ addTeamMemberInternal :: TeamId -> Maybe UserId -> Maybe ConnId -> NewTeamMember
 addTeamMemberInternal tid origin originConn newMem mems = do
     let new = newMem^.ntmNewTeamMember
     Log.debug $ Log.field "targets" (toByteString (new^.userId))
-              . Log.msg (Log.val "Teams.addTeamMemberInternal")
+              . Log.field "action" (Log.val "Teams.addTeamMemberInternal")
     o <- view options
     unless (length mems < fromIntegral (o^.optSettings.setMaxTeamSize)) $
         throwM tooManyTeamMembers