Run logging asynchronously (with a longer timeout)

server/devices.go

@@ -20,7 +20,9 @@ type deviceFilter struct {
 	client checkDeviceClient
 }
 
-var usermetadbTimeout = 3 * time.Second
+// The timeout for this RPC is very short, as it needs to be performed
+// synchronously with the authentication request.
+var deviceCheckTimeout = 3 * time.Second
 
 func newDeviceFilter(config *clientutil.BackendConfig) (*deviceFilter, error) {
 	c, err := client.New(config)
@@ -43,11 +45,11 @@ func (f *deviceFilter) Filter(user *User, req *auth.Request, resp *auth.Response
 
 	// Check if the device is known already, in which case we're
 	// OK and don't need to do anything else.
-	ctx, cancel := context.WithTimeout(context.Background(), usermetadbTimeout)
+	ctx, cancel := context.WithTimeout(context.Background(), deviceCheckTimeout)
 	defer cancel()
 	seen, err := f.client.CheckDevice(ctx, user.Shard, user.Name, req.DeviceInfo)
 	if err != nil {
-		log.Printf("usermetadb error for %s: %v", user.Name, err)
+		log.Printf("usermetadb.CheckDevice error for %s: %v", user.Name, err)
 		return resp
 	}
 

server/userlog.go

@@ -27,6 +27,8 @@ func newUserActivityLogFilter(config *clientutil.BackendConfig) (*logFilter, err
 	return &logFilter{c}, nil
 }
 
+var userLogTimeout = 30 * time.Second
+
 func (f *logFilter) Filter(user *User, req *auth.Request, resp *auth.Response) *auth.Response {
 	if resp.Status != auth.StatusOK {
 		return resp
@@ -50,11 +52,14 @@ func (f *logFilter) Filter(user *User, req *auth.Request, resp *auth.Response) *
 		DeviceInfo:  req.DeviceInfo,
 	}
 
-	ctx, cancel := context.WithTimeout(context.Background(), usermetadbTimeout)
-	defer cancel()
-	if err := f.client.AddLog(ctx, user.Shard, &entry); err != nil {
-		log.Printf("usermetadb.AddLog error for %s: %v", user.Name, err)
-	}
+	// Make the log RPC in the background, no need to wait for it to complete.
+	go func() {
+		ctx, cancel := context.WithTimeout(context.Background(), userLogTimeout)
+		defer cancel()
+		if err := f.client.AddLog(ctx, user.Shard, &entry); err != nil {
+			log.Printf("usermetadb.AddLog error for %s: %v", user.Name, err)
+		}
+	}()
 
 	return resp
 }