hashicorp / hashicorp/nomad

Client fs streaming API loses data when a file is rotated and a log line is split between two files

Open
#11,653 5 comments 1 reaction 0 assignees View on GitHub
stage/accepted theme/allocation API theme/logging type/bug
Dominant language
Go
Stars
17k
Forks
2.1k
Avg merge
1d 9h
Merged PRs (30d)
105

Description

### Nomad version
`Nomad v1.2.2 (78b8c171a211f967a8b297a88a7e844b3543f2b0)`

### Operating system and Environment details
`Ubuntu 20.04.3 LTS 4.19.128-microsoft-standard`

### Issue
When you stream the contents of a log file using `/client/fs/stream/:alloc_id` or logs with `/client/fs/logs/:alloc_id` a data loss occurs. This happens when a log line is being split between two files and the contents are streamed from a file that is currently being rotated. Both files in the file system have the data but the API only sends a frame with the data from the next file, so we lose the first part of the split log line. This makes it very hard to reliably ship logs to a log aggregation system.

Files in `alloc/logs`:
```sh
983044 httpd.stdout.0
41000 httpd.stdout.1
```

Captured frames:
```sh
{ File: "alloc/logs/httpd.stdout.0", Offset: 65536, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 131072, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 196608, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 262144, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 270337, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 335873, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 401409, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 466945, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 475138, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 540674, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 606210, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 671746, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 679939, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 745475, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 811011, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 876547, ... }
{ File: "alloc/logs/httpd.stdout.0", Offset: 819204, ... }
-> MISSING FRAMES
{ File: "alloc/logs/httpd.stdout.1", Offset: 40961, ... }
{ File: "alloc/logs/httpd.stdout.1", Offset: 41000, ... }
```

In my case, every log line is 204800 bytes (+1 for EOL). Log lines are never batched before being flushed if the frame size has not been hit.

1. How much data did we lose?
`204801 - 40961 (second part of the split log line in "httpd.stdout.1") = 163840`
2. How do we know that frames were not sent for "httpd.stdout.0"?
`163840 + 819204 (last streamed offset) = 983044 (file size)`

### Reproduction steps
1. Create a task that outputs lines longer than `lineScanLimit = 32 * 1024`.
2. Start capturing log frames, e.g., using curl.
```sh
curl -sSN "http://localhost:4646/v1/client/fs/logs/:alloc_id?task=:task&type=stdout&follow=true" > nomad.stream
```
3. Create enough logs to force rotation.

#### Expected Result
The stream should contain complete logs.

#### Actual Result
Missing frames.

### Job file (if appropriate)

### Nomad Server logs (if appropriate)

### Nomad Client logs (if appropriate)

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with the /client/fs/stream/:alloc_id and /client/fs/logs/:alloc_id streaming entry points, then reproduce rotation with lines longer than the 32 KiB lineScanLimit. Verify that frames preserve the complete split log line across httpd.stdout.0 and httpd.stdout.1 without missing data.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
api, backend, observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.