DEV Community

Dakota Lin
Dakota Lin

Posted on

I Forced Fsync. The Model Looked Fine.

The remote model was not my bottleneck today. The work after the last token was. I kept that waterfall because prettier charts lied.

Why did first token feel like the whole wait? Product dashboards adore that one shiny latency number. Editors feel a later and much heavier stall.

I ran a small local experiment on purpose. I wanted one graph I could actually defend.

Generation received one span on that graph. Apply received five distinct spans beside it.

The setup stayed boring on purpose here. I used a fixture payload and a timer.

I used a printer for the waterfall. There was no production traffic in this run.

I am not claiming a speedup number. I still needed a remote generator for contrast.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

I used MonkeyCode's free model access here. I also used its free server option. Those were the remote side of contrast runs.

They were not a benchmark laboratory for ranking. I will not freeze model names in this note.

I will not publish quotas that drift weekly. Marketing pages change faster than a fixture patch.

The question stayed simpler than any launch post. Where did wall clock actually go then?

Could I see it without buying a tracer? I wrote a Python timer around apply.

It calls perf_counter for each named span. It records those spans in arrival order.

Then it prints a compact ASCII waterfall.

#!/usr/bin/env python3
"""apply_waterfall.py — local spans around patch apply."""
from __future__ import annotations

import argparse
import json
import os
import time
from dataclasses import dataclass, field
from pathlib import Path
from typing import Any, Callable


@dataclass
class Span:
    name: str
    start: float
    end: float = 0.0

    @property
    def ms(self) -> float:
        return (self.end - self.start) * 1000.0


@dataclass
class Clock:
    spans: list[Span] = field(default_factory=list)

    def measure(self, name: str, fn: Callable[[], Any]) -> Any:
        span = Span(name, time.perf_counter())
        try:
            return fn()
        finally:
            span.end = time.perf_counter()
            self.spans.append(span)

    def print_waterfall(self) -> None:
        if not self.spans:
            print("no spans")
            return
        t0 = self.spans[0].start
        t1 = max(span.end for span in self.spans)
        width = 48
        total = t1 - t0 or 1e-9
        print(f"{'span':<18} {'ms':>8}  waterfall")
        for span in self.spans:
            left = int(((span.start - t0) / total) * width)
            bar = max(1, int((span.ms / 1000.0 / total) * width))
            print(f"{span.name:<18} {span.ms:8.1f}  {' ' * left}{'#' * bar}")
        print(f"{'total':<18} {total * 1000:8.1f}")


def apply_files(root: Path, files: list[dict], do_fsync: bool) -> None:
    for item in files:
        path = root / item["path"]
        path.parent.mkdir(parents=True, exist_ok=True)
        with path.open("w", encoding="utf-8") as handle:
            handle.write(item["content"])
            handle.flush()
            if do_fsync:
                os.fsync(handle.fileno())


def main() -> int:
    parser = argparse.ArgumentParser()
    parser.add_argument("--fixture", type=Path, required=True)
    parser.add_argument("--root", type=Path, default=Path("./_apply_tmp"))
    parser.add_argument("--fsync", action="store_true")
    args = parser.parse_args()

    clock = Clock()
    args.root.mkdir(parents=True, exist_ok=True)
    raw = clock.measure("load_fixture", lambda: args.fixture.read_text(encoding="utf-8"))
    files = clock.measure("json_decode", lambda: json.loads(raw))
    label = "write_and_fsync" if args.fsync else "write_nofsync"
    clock.measure(label, lambda: apply_files(args.root, files, args.fsync))
    clock.measure("post_write_idle", lambda: time.sleep(0.02))
    clock.print_waterfall()
    return 0


if __name__ == "__main__":
    raise SystemExit(main())
Enter fullscreen mode Exit fullscreen mode

I fed the timer a tiny JSON fixture. Two files landed in a throwaway root.

Nothing in that fixture payload was clever. That boredom was the entire measurement point.

[
  {"path": "hello.py", "content": "def hello():\n    return \"ok\"\n"},
  {"path": "notes.txt", "content": "notes\none more line\n"}
]
Enter fullscreen mode Exit fullscreen mode

Sample output from my machine follows below. Treat these numbers as one local capture. Do not paste them into a vendor slide.

$ python apply_waterfall.py --fixture fixture.json
span                     ms  waterfall
load_fixture            0.4  #
json_decode             0.8  #
write_nofsync           3.9  ##
post_write_idle        20.1       ###########
total                  25.2
Enter fullscreen mode Exit fullscreen mode

I ran it again with fsync forced on. The write span stopped pretending to be cheap.

$ python apply_waterfall.py --fixture fixture.json --fsync
span                     ms  waterfall
load_fixture            0.4  #
json_decode             0.7  #
write_and_fsync        41.6  #####################
post_write_idle        20.0            ##########
total                  62.7
Enter fullscreen mode Exit fullscreen mode

Look at that write span on the second run. Generation would have looked almost polite beside it. Does that match the story in your gut?

Mine did not match that story at all. I had blamed the free server first.

I had blamed the model right after. The disk was laughing under both takes.

Real editors make the same stall worse. A write wakes the recursive file watcher.

The watcher then wakes the language server. The server rereads more files than you touched.

I did not trace the editor this time. That cut needs a different knife entirely.

This note stops at process-local apply work. Editor guts can wait for another night.

Then I wrapped a remote call in the same clock. I did not do that to crown a vendor.

I wanted generation on the same printed axis. First byte and last byte stay separate.

import os
import time
import urllib.request

url = os.environ["CODE_ENDPOINT"]  # your endpoint, not a brand claim
body = b'{"prompt":"fixture only"}'
req = urllib.request.Request(
    url,
    data=body,
    headers={"Content-Type": "application/json"},
    method="POST",
)
start = time.perf_counter()
with urllib.request.urlopen(req, timeout=60) as resp:
    first = time.perf_counter()
    payload = resp.read()
done = time.perf_counter()
print(
    f"ttfb_ms={(first - start) * 1000:.1f} "
    f"body_ms={(done - first) * 1000:.1f} "
    f"bytes={len(payload)}"
)
Enter fullscreen mode Exit fullscreen mode

If your endpoint streams tokens as chunks, listen. Close the stream span on the last chunk.

First byte is a different story altogether. Do not merge those two into one bar.

I almost merged them on the first draft. That merge would have repeated a popular mistake.

First token is a headline for dashboards. Last token is the actual completed job.

The waterfall I kept contains seven named rows. dns_and_connect sits at the far left.

first_byte follows if the handshake was cheap. stream_body holds the model while it talks.

json_decode and path writes live on my laptop. write_and_fsync is the span people skip.

post_write_idle catches formatter and watcher wakeups. Only two of those rows live remotely.

The rest live right beside your chair. That split is the whole practical lesson.

How do you decide what to fix next? I used a crude fence instead of statistics.

If generation is over two thirds, change remotes. If apply is over one third, stop shopping models.

That fence is not a scientific result. It exists to stop a common panic buy.

Do not swap GPUs for a slow open call. Have you bought compute to hide a flush?

I watched one run invert my whole plan. I was ready to switch the remote server.

Apply was already eating about forty percent. The writes were not flushed to disk.

The next run dropped that bar again. So I forced fsync inside the measurement path.

The write bar came back immediately then. Hidden buffering remains a very talented liar.

Have you timed a write that never landed? Python write can return before disk agrees.

Your editor may still wait on the file. Your tests may wait on mtime updates.

Those clocks disagree with each other on purpose. Measurement has to pick a clock and stay.

The command I keep beside the script is plain. I save the ASCII output somewhere boring.

python apply_waterfall.py --fixture fixture.json --fsync > waterfall.txt
Enter fullscreen mode Exit fullscreen mode

Then I argue with it again tomorrow morning. Feelings fade. The file still has bars.

If you add formatting, give it a named span. If you add tests, give them a named span.

Do not hide extra work under a misc label. Misc is where slow code goes to sulk.

I tried a repo formatter once during apply. It walked far beyond the touched files.

The waterfall grew a brand new villain. Generation still looked small beside that walk.

Should you fsync in the assistant happy path? Probably not for an interactive coding loop.

Assistants usually want the write to return. Crash safety is a separate product choice.

I fsync during measurement on purpose only. I do not fsync the daily happy path.

Mixing those modes ruined an earlier graph. The graph I kept is the honest one.

Limitations are not a polite footnote here. This method ignores editor thread internals on purpose.

It ignores GPU scheduling on the remote host. It ignores prompt cache warmth between turns.

It also ignores neighbors on a free server. Shared queues move without warning or apology.

One capture is not a climate report. Do not rank vendors with this teaching script.

Who should skip this whole approach then? Anyone shipping a latency SLA tomorrow morning.

Anyone without a fixture they actually trust. Anyone hoping a chart will pick models.

If you need capacity numbers, run load tests. If you need quality, read the produced diff.

This waterfall answers one rude question only. The rude question is still worth asking weekly.

Is the model slow or is apply theatrical? Most weeks the local theater still wins.

I still like remote generation for draft work. I still use a free server while iterating timers.

Paying for tokens to debug disk is comedy. The graph I kept is not pretty at all.

It is a monospace waterfall in a text file. I open it when someone says models got worse.

Sometimes they are right about the remote side. Sometimes the node_modules tree simply grew overnight.

Sometimes the formatter started checking ignored files. The waterfall does not care about our feelings.

Run the script against your own fixture patch. Change the files until a span surprises you.

Keep the first graph that argues back. That surprise is the artifact worth saving.

Need a free remote target for generation spans? MonkeyCode's free server covered my contrast runs.

I will not turn that into a slogan. The open source repo is there if you want the same contrast.

What would I refuse to add next week? A live dashboard with three green arrows.

A public ranking table of unnamed models. A weekly score that pretends at climate.

Those extras invite a very fake precision. I may add one more span later on.

lsp_idle could come from a watcher log. Not today though, and not in this gist.

Today the disk was already loud enough. That is the whole performance note then.

Keep the waterfall when arguments get loud. Blame apply when the bar earns blame.

Leave the model alone when it already finished.

Top comments (0)