Repository: moby/moby (language: go)

Issue:
Improving logging level for "not found" log message
### Description

Currently the logging level for for "not found" log message is `error` level. E.g.

`Jan 23 20:33:17 localhost dockerd: time="2022-01-23T20:33:17.023933784Z" level=error msg="Error getting service <service-name>: service <service-name> not found"`

This is regarded as spam logs if an application periodically checks the existence of that service to determine the next steps, in this case, "the service does not exist" is not a real error for users.

Is it possible to change the logging level to `info` for this kind of log messages?

### Reproduce

1. docker service inspect non-existing-service
2. check docker daemon logs.

### Expected behavior

_No response_

### docker version

```bash
Client: Docker Engine - Community
 Version:           20.10.16
 API version:       1.41
 Go version:        go1.17.10
 Git commit:        aa7e414
 Built:             Thu May 12 09:19:22 2022
 OS/Arch:           linux/arm64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.17
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.17.11
  Git commit:       a89b842
  Built:            Mon Jun  6 23:00:41 2022
  OS/Arch:          linux/arm64
  Experimental:     false
 containerd:
  Version:          1.6.6
  GitCommit:        10c12954828e7c7c9b6e0ea9b0c02b01407d3ae1
 runc:
  Version:          1.1.2
  GitCommit:        v1.1.2-0-ga916309
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0
```


### docker info

```bash
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Docker Buildx (Docker Inc., v0.8.2-docker)
  compose: Docker Compose (Docker Inc., v2.5.0)

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 13
 Server Version: 20.10.17
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: systemd
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: active
  NodeID: b1v407d5gvfayxd1w1vrfl628
  Is Manager: true
  ClusterID: zpxv6kidrdhea3s40v5360whs
  Managers: 1
  Nodes: 1
  Default Address Pool: 10.0.0.0/8  
  SubnetSize: 24
  Data Path Port: 4789
  Orchestration:
   Task History Retention Limit: 5
  Raft:
   Snapshot Interval: 10000
   Number of Old Snapshots to Retain: 0
   Heartbeat Tick: 1
   Election Tick: 10
  Dispatcher:
   Heartbeat Period: 5 seconds
  CA Configuration:
   Expiry Duration: 3 months
   Force Rotate: 0
  Autolock Managers: false
  Root Rotation In Progress: false
  Node Address: 192.168.64.3
  Manager Addresses:
   192.168.64.3:2377
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 10c12954828e7c7c9b6e0ea9b0c02b01407d3ae1
 runc version: v1.1.2-0-ga916309
 init version: de40ad0
 Security Options:
  apparmor
  seccomp
   Profile: default
  cgroupns
 Kernel Version: 5.15.0-27-generic
 Operating System: Ubuntu 22.04 LTS
 OSType: linux
 Architecture: aarch64
 CPUs: 2
 Total Memory: 1.921GiB
 Name: ub2204-1
 ID: NE3Y:POXM:GQW6:PWQZ:36IY:T2K6:DQJM:S4A7:MPVF:NA5E:EZYX:ND44
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
  cicd=true
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false
```


### Additional Info

_No response_


Discussion / hints:
The offending code: https://github.com/moby/moby/blob/c910e47f5311f2129fb6dc54d4aee739e0a2b5e6/api/server/router/swarm/cluster_routes.go#L195-L199

`swarm/cluster_routes.go` is the only file in the `api/server/router` tree which logs errors before returning them to the client. Given that precedent those log messages definitely shouldn't exist, let alone be logged at Error level. If they are kept, I'd go further than Info and demote the logs' level all the way down to Debug.
Yes, debug would probably be fine for this.


Probably quite off-topic (and orthogonal), but I'm almost inclined to remove (some of? haven't looked what other logs there are) these altogether. That said, at times when debugging, I would've loved for an option that logged both requests and responses (or at least status of responses). Wondering if something like that could be part of (or similar to); https://github.com/moby/moby/blob/b8b68e6ea9598e1e0a582b05a9b77eee3e50410f/api/server/middleware/debug.go#L17

Fix patch:
diff --git a/api/server/router/swarm/cluster_routes.go b/api/server/router/swarm/cluster_routes.go
index 05c10082a1c8b..17cb9ad4638e3 100644
--- a/api/server/router/swarm/cluster_routes.go
+++ b/api/server/router/swarm/cluster_routes.go
@@ -35,7 +35,7 @@ func (sr *swarmRouter) initCluster(ctx context.Context, w http.ResponseWriter, r
 	}
 	nodeID, err := sr.backend.Init(req)
 	if err != nil {
-		logrus.Errorf("Error initializing swarm: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error initializing swarm")
 		return err
 	}
 	return httputils.WriteJSON(w, http.StatusOK, nodeID)
@@ -61,7 +61,7 @@ func (sr *swarmRouter) leaveCluster(ctx context.Context, w http.ResponseWriter,
 func (sr *swarmRouter) inspectCluster(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
 	swarm, err := sr.backend.Inspect()
 	if err != nil {
-		logrus.Errorf("Error getting swarm: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error getting swarm")
 		return err
 	}
 
@@ -113,7 +113,7 @@ func (sr *swarmRouter) updateCluster(ctx context.Context, w http.ResponseWriter,
 	}
 
 	if err := sr.backend.Update(version, swarm, flags); err != nil {
-		logrus.Errorf("Error configuring swarm: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error configuring swarm")
 		return err
 	}
 	return nil
@@ -126,7 +126,7 @@ func (sr *swarmRouter) unlockCluster(ctx context.Context, w http.ResponseWriter,
 	}
 
 	if err := sr.backend.UnlockSwarm(req); err != nil {
-		logrus.Errorf("Error unlocking swarm: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error unlocking swarm")
 		return err
 	}
 	return nil
@@ -135,7 +135,7 @@ func (sr *swarmRouter) unlockCluster(ctx context.Context, w http.ResponseWriter,
 func (sr *swarmRouter) getUnlockKey(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
 	unlockKey, err := sr.backend.GetUnlockKey()
 	if err != nil {
-		logrus.WithError(err).Errorf("Error retrieving swarm unlock key")
+		logrus.WithContext(ctx).WithError(err).Debug("Error retrieving swarm unlock key")
 		return err
 	}
 
@@ -167,7 +167,7 @@ func (sr *swarmRouter) getServices(ctx context.Context, w http.ResponseWriter, r
 
 	services, err := sr.backend.GetServices(basictypes.ServiceListOptions{Filters: filter, Status: status})
 	if err != nil {
-		logrus.Errorf("Error getting services: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error getting services")
 		return err
 	}
 
@@ -193,7 +193,10 @@ func (sr *swarmRouter) getService(ctx context.Context, w http.ResponseWriter, r
 
 	service, err := sr.backend.GetService(vars["id"], insertDefaults)
 	if err != nil {
-		logrus.Errorf("Error getting service %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":      err,
+			"service-id": vars["id"],
+		}).Debug("Error getting service")
 		return err
 	}
 
@@ -217,7 +220,10 @@ func (sr *swarmRouter) createService(ctx context.Context, w http.ResponseWriter,
 	}
 	resp, err := sr.backend.CreateService(service, encodedAuth, queryRegistry)
 	if err != nil {
-		logrus.Errorf("Error creating service %s: %v", service.Name, err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":        err,
+			"service-name": service.Name,
+		}).Debug("Error creating service")
 		return err
 	}
 
@@ -253,7 +259,10 @@ func (sr *swarmRouter) updateService(ctx context.Context, w http.ResponseWriter,
 
 	resp, err := sr.backend.UpdateService(vars["id"], version, service, flags, queryRegistry)
 	if err != nil {
-		logrus.Errorf("Error updating service %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":      err,
+			"service-id": vars["id"],
+		}).Debug("Error updating service")
 		return err
 	}
 	return httputils.WriteJSON(w, http.StatusOK, resp)
@@ -261,7 +270,10 @@ func (sr *swarmRouter) updateService(ctx context.Context, w http.ResponseWriter,
 
 func (sr *swarmRouter) removeService(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
 	if err := sr.backend.RemoveService(vars["id"]); err != nil {
-		logrus.Errorf("Error removing service %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":      err,
+			"service-id": vars["id"],
+		}).Debug("Error removing service")
 		return err
 	}
 	return nil
@@ -302,7 +314,7 @@ func (sr *swarmRouter) getNodes(ctx context.Context, w http.ResponseWriter, r *h
 
 	nodes, err := sr.backend.GetNodes(basictypes.NodeListOptions{Filters: filter})
 	if err != nil {
-		logrus.Errorf("Error getting nodes: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error getting nodes")
 		return err
 	}
 
@@ -312,7 +324,10 @@ func (sr *swarmRouter) getNodes(ctx context.Context, w http.ResponseWriter, r *h
 func (sr *swarmRouter) getNode(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
 	node, err := sr.backend.GetNode(vars["id"])
 	if err != nil {
-		logrus.Errorf("Error getting node %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":   err,
+			"node-id": vars["id"],
+		}).Debug("Error getting node")
 		return err
 	}
 
@@ -333,7 +348,10 @@ func (sr *swarmRouter) updateNode(ctx context.Context, w http.ResponseWriter, r
 	}
 
 	if err := sr.backend.UpdateNode(vars["id"], version, node); err != nil {
-		logrus.Errorf("Error updating node %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":   err,
+			"node-id": vars["id"],
+		}).Debug("Error updating node")
 		return err
 	}
 	return nil
@@ -347,7 +365,10 @@ func (sr *swarmRouter) removeNode(ctx context.Context, w http.ResponseWriter, r
 	force := httputils.BoolValue(r, "force")
 
 	if err := sr.backend.RemoveNode(vars["id"], force); err != nil {
-		logrus.Errorf("Error removing node %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":   err,
+			"node-id": vars["id"],
+		}).Debug("Error removing node")
 		return err
 	}
 	return nil
@@ -364,7 +385,7 @@ func (sr *swarmRouter) getTasks(ctx context.Context, w http.ResponseWriter, r *h
 
 	tasks, err := sr.backend.GetTasks(basictypes.TaskListOptions{Filters: filter})
 	if err != nil {
-		logrus.Errorf("Error getting tasks: %v", err)
+		logrus.WithContext(ctx).WithError(err).Debug("Error getting tasks")
 		return err
 	}
 
@@ -374,7 +395,10 @@ func (sr *swarmRouter) getTasks(ctx context.Context, w http.ResponseWriter, r *h
 func (sr *swarmRouter) getTask(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
 	task, err := sr.backend.GetTask(vars["id"])
 	if err != nil {
-		logrus.Errorf("Error getting task %s: %v", vars["id"], err)
+		logrus.WithContext(ctx).WithFields(logrus.Fields{
+			"error":   err,
+			"task-id": vars["id"],
+		}).Debug("Error getting task")
 		return err
 	}
 


Test patch: