TT Lab
Get started
Learn Learning paths Courses

Designing a Log Pipeline

Logs stopped at midnight and a restart made them flow again

Continue in TT Lab

Goal

Build a collector that keeps reading a file from where it left off, cause an append, a rotation, and a truncation in turn, and confirm by sequence number that not a single line is lost or duplicated.

Why it matters

A collector's first job is to remember "how far I have read." But if it remembers only a single byte position, it stops quietly at the midnight log rotation — the new file is small, while the position it remembered is large. Hours go empty with no error and no alert, and since it flows again after a restart, the cause leaves no trace. You detect a rotation by the inode changing, and a truncation by the size becoming smaller than the place you read up to. The reason you have to watch for both is that there are two rotation methods. You also have to decide in advance the policy for when the position record is gone — which one to accept, duplication or loss, is not decided for free.

Steps

  1. In /root/lp-tail, create logs for seq 1 to 200 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 200 "$(date +%s)" 1. Then build a collector that keeps reading app.log, appends to /root/lp-tail/collected.log, and leaves the position it has read in /root/lp-tail/pos.txt, and run it once. pos.txt holds two lines, inode=<정수> and offset=<정수> (each placeholder is an integer).
  2. Append seq 201 to 300 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 201 and run the collector again. When collection finishes, collected.log must have 300 lines and no seq may appear twice.
  3. Cause a rotation with mv /root/lp-tail/app.log /root/lp-tail/app.log.1, and write seq 301 to 400 to the new file with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 301. Then run the collector so that collected.log reaches 400 lines.
  4. Simulate the copytruncate method — copy with cp /root/lp-tail/app.log /root/lp-tail/app.log.2, truncate the original to 0 with : > /root/lp-tail/app.log, and then run the collector once. Then write seq 401 to 500 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 401 and run the collector again so that range comes in without a gap.
  5. Check that the inode in pos.txt now equals the actual inode of app.log and that offset equals the file size. Then write three lines in /root/lp-tail/05-pos.txt — pos_inode=<정수>, file_inode=<정수>, offset_equals_size=<yes|no> (the first two placeholders are integers, and the last is yes or no).
  6. Copy the current directory whole to /root/lp-tail-nopos, delete pos.txt there, and run the collector once. Then write three lines in /root/lp-tail/06-nopos.txt — before=<복사 시점의 collected.log 줄 수>, after=<다시 돌린 뒤 줄 수>, duplicated=<두 값의 차> (the placeholders are the line count of collected.log at the time of the copy, the line count after the rerun, and the difference between the two). Do not touch the original directory.
  7. Compare the set of seq values in all the original files (app.log and the rotated copies) with the set of seq values in collected.log, and write four lines in /root/lp-tail/tally.txt — source=<원본 줄 수>, collected=<수집본 줄 수>, missing=<원본에만 있는 seq 수>, duplicated=<수집본에서 두 번 이상 나온 seq 수> (the placeholders are the number of lines in the source, the number of lines in the collected file, the number of seq values only in the source, and the number of seq values that appear two or more times in the collected file).
  8. Create /root/lp-tail/chaos.sh so that it does the following in order — (1) rotation (move app.log to app.log.3 and write seq 501 to 550 to a new file), (2) collection, (3) copy then truncation (cp app.log app.log.4, then : > app.log) and the collection right after it, (4) write seq 551 to 600 and collect again. After running the script, seq 1 to 600 must each appear in collected.log exactly once with none missing. Write the result in /root/lp-tail/08-chaos.txt as three lines, collected=<정수>, missing=0, and duplicated=0 (the placeholder is an integer).

Notes

Create the app log and collect once for the first time

In /root/lp-tail, create logs for seq 1 to 200 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 200 "$(date +%s)" 1. Then build a collector that keeps reading app.log, appends to /root/lp-tail/collected.log, and leaves the position it has read in /root/lp-tail/pos.txt, and run it once. pos.txt holds two lines, inode=<정수> and offset=<정수> (each placeholder is an integer).

The language is up to you. The key is to remember two things — which file it was (inode) and how far you read (offset). You can see the inode with stat -c %i and the size with wc -c. Even if you run the collector many times, it must not write the same line twice.

Keep reading only the appended lines

Append seq 201 to 300 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 201 and run the collector again. When collection finishes, collected.log must have 300 lines and no seq may appear twice.

A collector that rereads the whole file here produces 600 lines. To check whether you are using offset correctly, compare pos.txt with wc -c app.log — the two values must be equal.

Rotation — a different file with the same name

Cause a rotation with mv /root/lp-tail/app.log /root/lp-tail/app.log.1, and write seq 301 to 400 to the new file with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 301. Then run the collector so that collected.log reaches 400 lines.

A collector that remembers only the position cannot find anything to read in the new file. It has to notice that it has become a different file with the same name — a single value reported by stat tells you. Once it notices, it reads the new file from the beginning.

Truncation — the inode stays the same but the file got smaller

Simulate the copytruncate method — copy with cp /root/lp-tail/app.log /root/lp-tail/app.log.2, truncate the original to 0 with : > /root/lp-tail/app.log, and then run the collector once. Then write seq 401 to 500 with python3 /opt/lab/d5/applog.py logfmt /root/lp-tail/app.log 100 "$(date +%s)" 401 and run the collector again so that range comes in without a gap.

This time the inode stays the same. A collector that looks only at the inode feels no change and tries to read from the old position. The only clue is that the file size has become smaller than the remembered position. There is a reason to run once right after the truncation — the collector runs periodically, and if new lines pile up and the size passes the old position again, even that clue disappears.

What the memory must contain

Check that the inode in pos.txt now equals the actual inode of app.log and that offset equals the file size. Then write three lines in /root/lp-tail/05-pos.txt — pos_inode=<정수>, file_inode=<정수>, offset_equals_size=<yes|no> (the first two placeholders are integers, and the last is yes or no).

Use stat -c %i app.log and wc -c < app.log. If the two values are out of step, the collector has not updated its position properly, and you will lose lines at the next rotation.

What happens when the position record disappears

Copy the current directory whole to /root/lp-tail-nopos, delete pos.txt there, and run the collector once. Then write three lines in /root/lp-tail/06-nopos.txt — before=<복사 시점의 collected.log 줄 수>, after=<다시 돌린 뒤 줄 수>, duplicated=<두 값의 차> (the placeholders are the line count of collected.log at the time of the copy, the line count after the rerun, and the difference between the two). Do not touch the original directory.

Copy with cp -a . /root/lp-tail-nopos. Without a position record, the collector has to choose either "from the beginning" or "from the end," and the sample collector reads from the beginning. So lines that were already sent come in again — counting them is this step.

Application 1 — count loss and duplication by number

Compare the set of seq values in all the original files (app.log and the rotated copies) with the set of seq values in collected.log, and write four lines in /root/lp-tail/tally.txt — source=<원본 줄 수>, collected=<수집본 줄 수>, missing=<원본에만 있는 seq 수>, duplicated=<수집본에서 두 번 이상 나온 seq 수> (the placeholders are the number of lines in the source, the number of lines in the collected file, the number of seq values only in the source, and the number of seq values that appear two or more times in the collected file).

The seq appears in every line in the form seq=00123. Extract it with grep -o 'seq=[0-9]*' and count with sort and uniq. Only when both loss and duplication are 0 can you trust the collector.

Application 2 — lose not a single line even when rotation and truncation are mixed

Create /root/lp-tail/chaos.sh so that it does the following in order — (1) rotation (move app.log to app.log.3 and write seq 501 to 550 to a new file), (2) collection, (3) copy then truncation (cp app.log app.log.4, then : > app.log) and the collection right after it, (4) write seq 551 to 600 and collect again. After running the script, seq 1 to 600 must each appear in collected.log exactly once with none missing. Write the result in /root/lp-tail/08-chaos.txt as three lines, collected=<정수>, missing=0, and duplicated=0 (the placeholder is an integer).

This bundles what you did in the earlier steps into a script. You must put one collection between the rotation and the truncation — that is your only chance to read the tail of the rotated file. It is also the reason a real collector holds its file descriptor a little longer.