Docker Service Logs --tail and --since Not Working as Expected

[afrazkhan]

---

BUG REPORT INFORMATION

Description
Using the --since and --tail flags with the command line tool, or the since or tail parameters via the API, does not yield expected results.

Steps to reproduce the issue:
The following is true for either the cli or the API, but I'll describe it for the cli to keep things simple:

1. Run docker service logs --tail 1 [SERVICE] or docker service logs [1491249483 || 1m10s etc.] [SERVICE]

Describe the results you received:
Many lines returned, and in the case of failing services which are retrying every n seconds, this is thousands of lines.

Describe the results you expected:
With --tail 1, only 1 line returned. With --since [TIMESTAMP] only lines returned since that timestamp.

Additional information you deem important (e.g. issue happens only occasionally):
It seems that the extra lines are the result of grabbing logs from all service tasks, though I could be wrong.

Querying the individual containers created by the docker service command, the --tail and --since options work as expected.

Output of docker version:

Output is from my Mac, but the same thing happens for the same version on Linux:

Client:
 Version:      17.03.1-ce
 API version:  1.27
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Tue Mar 28 00:40:02 2017
 OS/Arch:      darwin/amd64

Server:
 Version:      17.03.1-ce
 API version:  1.27 (minimum version 1.12)
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Fri Mar 24 00:00:50 2017
 OS/Arch:      linux/amd64
 Experimental: true

Output of docker info:

Again this is from my Mac, but the tests were also performed on Linux with a proper swarm, with the same results:

Containers: 6                                                                                                                                                             [25/4682]
 Running: 1
 Paused: 0
 Stopped: 5
Images: 350
Server Version: 17.03.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins: 
 Volume: local
 Network: bridge host ipvlan macvlan null overlay
Swarm: active
 NodeID: mp9up3hu4ik275i4nl23hx1zv
 Is Manager: true
 ClusterID: flbky82mvb51ngvbmb3a0pvqn
 Managers: 1
 Nodes: 1
 Orchestration:
  Task History Retention Limit: 5
 Raft:
  Snapshot Interval: 10000
  Number of Old Snapshots to Retain: 0
  Heartbeat Tick: 1
  Election Tick: 3
 Dispatcher:
  Heartbeat Period: 5 seconds
 CA Configuration:
  Expiry Duration: 3 months
 Node Address: 192.168.65.2
 Manager Addresses:
  192.168.65.2:2377
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 4ab9917febca54791c5f071a9d1f404867857fcc
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
init version: N/A (expected: 949e6facb77383876aeff8a6944dde66b3089574)
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.9.13-moby
Operating System: Alpine Linux v3.5
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 1.952 GiB
Name: moby
ID: IJXO:PQVJ:Z5IQ:AV2T:PNJX:B5IK:L3FW:EOFM:TLUX:WM56:GTBA:GH4W
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 39
 Goroutines: 143
 System Time: 2017-04-03T19:46:12.33482745Z
 EventsListeners: 2
No Proxy: *.local, 169.254/16
Username: afrazkhan
Registry: https://index.docker.io/v1/
Experimental: true
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

[thaJeztah]

The docker service logs feature is still experimental, and the --tail and --since options were not yet enabled for the 17.03.0/17.03.1 release; this PR enables them, which will be in the 17.04 release; #31500

[afrazkhan]

Cools, thanks. Perhaps the v27 API docs should reflect that?

[thaJeztah]

Hm, yes, we may have to find a way to distinguish "experimental" (i.e., still able to change) from "stable" endpoints as well.

Perhaps you're interested in opening a pull request against the 17.03.x branch; https://github.com/docker/docker/blob/17.03.x/api/swagger.yaml for the tail/since options

[khba]

Facing the same problem on this version:

Client:
Version: 18.02.0-ce
API version: 1.36
Go version: go1.9.3
Git commit: fc4de44
Built: Wed Feb 7 21:16:33 2018
OS/Arch: linux/amd64
Experimental: false
Orchestrator: swarm

Server:
Engine:
Version: 18.02.0-ce
API version: 1.36 (minimum version 1.12)
Go version: go1.9.3
Git commit: fc4de44
Built: Wed Feb 7 21:15:05 2018
OS/Arch: linux/amd64
Experimental: false

[Flame239]

Facing the same issue on 18.09.
As for #32462 - service logs are no longer experimental, but 'stable'.
@thaJeztah Is it expected behaviour?

[danielbraun89]

the "since" functionality in the SDK is still broken 2 years later

[fruch]

19.03.3 and still isn't working with specific timestamps

[Radiergummi]

Just chiming in five and a half years later, and it's still not working. Does anyone at Docker even actually still work on Swarm Mode, or has it silently been abandoned..?

[vlcinsky]

--since is simply ignored.

--tail N returns twice as many records as asked for, e.g. for

docker service logs --tail 10 [service]

returns 20 records

to count it, one can:

docker service logs --tail 10 --raw your-service-name 2>&1 | wc -l

[thaJeztah]

--tail N returns twice as many records as asked for,

Curious (I'm not deeply familiar with the implementation in swarm); in your case could it be that there's 2 instances of the service? (i.e., could it be using 10 records per task ?)

[vlcinsky]

@thaJeztah good catch.
Yes, the service I have observed twice as many log records has replicas: 2

I did not expect that.

Another service, where I have just single replica, provides expected number of records.

It is a bit surprising, but I can understand the reasons. Fetching logs from multiple services, sorting them and finally limiting output only to defined number is too much hassle and would make the code much more complex.