When something breaks
There are no backtraces in a deployed app. The log line and the route name have to be enough, so write them as you go.
Three places things go wrong, and they need different tools: the build, the request under melee dev, and
the request in production.
The build failed
Every diagnostic is one line: file:line: message, against the file you wrote.
views/broken.erb:2: unexpected end-of-input, assuming it is closing the parent top level context
db/migrations/003_bad.sql:1: near "TABEL": syntax error
app.rb:5: views/index.erb does not declare a local `nots`
app.rb:12: unsupported eval of a runtime string is not supported by AOT compilation (define the code statically)
app.rb:12: unsupported call: node 14591 (CallNode `totally_not_a_method`) recv=-/ty-1 argc=1 arg0ty3
The last one is the compiler’s own voice and the one that reads badly. unsupported call on a name you
recognise almost always means one of three things:
| You called a method that does not exist | a typo in a top-level helper, or one you meant to define |
The file did not require what it uses | add require "json" to the file that calls JSON.parse |
| The construct is not compilable | eval, send with a computed name, define_method, a Proc out of a Hash |
A failed melee push deploys nothing and the previous release keeps serving, so a broken build is never an
outage.
If you cannot tell what the compiler is objecting to, cut the file down until it compiles — the smallest program that still fails is usually the answer, and it is also what an upstream bug report needs.
It is wrong under melee dev
This is where the tools are good. A 500 renders a page with the exception class and message, the request, the params, the session and a CRuby backtrace.
Enjoy it, and do not build a habit on it: production has none of that.
GET /admin -> 500 (1.2 ms)
log.info with fields goes to the terminal:
info msg="refresh requested" feeds=3
And remember the dev server runs your code under CRuby, so it will happily run things the compiler rejects
and behave differently from the deployed binary in the handful of places the dialect differs. melee check
is the cross-check.
It is wrong in production
The visitor gets:
Something went wrong
and you get a line in the log:
undefined method 'qeury' for an instance of Melee::DB class=NoMethodError method=GET path=/ route=GET /
Class, message, HTTP method, path, and the route pattern that matched. No line number and no backtrace —
Exception#backtrace and caller return [] in a compiled app, because the binary does not carry them.
So the route name is often all you have to locate the failure, which has three consequences worth building into how you write:
- Raise with messages that say where you were.
raise ArgumentError, "feed #{id} has no url"rather thanraise ArgumentError. - Log before the risky line, not only after it. A line that says what you were about to do survives the thing that stops you doing it.
- Keep routes short. A route with one call in it and a log line is a route whose failure you can place.
post "/admin/refresh" do
log.info "refresh requested", feeds: db.first("SELECT COUNT(*) AS c FROM feeds")["c"].to_s
Household.get("home").refresh
redirect "/admin"
rescue Durable::RemoteError => e
log.error "refresh failed", remote_class: e.remote_class, message: e.message
halt 502
end
Reading the logs
melee logs # the last 50 lines
melee logs --tail 200
melee logs -f # follow
Lines are HH:MM:SS msg key=value …. Three kinds are mixed together:
- your
log.*events, each carrying the request id; - anything the app wrote to stderr (
$stderr.puts, runtime noise), shown as-is — note thatputsgoes to stdout and is not collected, so uselog; - the server’s own events, tagged
[melee].
The server’s events are the ones that explain a failure with no application line at all:
[melee] warm process started (pid 91129, 4 slots, sandbox off, cgroup off), release 1789257411211-0000
[melee] worker failed to start: bind .../worker.sock: path must be shorter than SUN_LEN; trying again in 60s
[melee] killing warm process group 91129 (environment changed)
[melee] warm process exited: signal: 9 (SIGKILL)
Reading a status code
| Code | What happened |
|---|---|
403 | The CSRF check. A form without csrf_field, or a stale session. |
404 | No route matched, or your own halt 404. |
500 | Your code raised. The log line is the only detail there is. |
502 | The request process died without answering — a crash, or the sandbox killing it for a forbidden syscall. |
503 | Every slot busy and the queue full (Retry-After: 1), or fork failed against the process cap. |
504 | The request took longer than 30 seconds; the process group was killed. |
A 502 with nothing in the log is the sandbox signature: the process was killed before it could say
anything. That means a syscall outside the allow-list, which for app code almost always means trying to do
something the platform does not intend — open a listening socket, run a subprocess.
Durable objects
melee objects # every object: class, id, created, last call, next timer
melee objects Stats # one class
CLASS ID CREATED LAST CALL TIMER
Stats visits 0s ago 0s ago in 23h
The TIMER column is the one to check when scheduled work is not happening: - means nothing is pending,
and re-arming only happens if on_timer completes.
Calls are logged individually:
call method=hit ms=0.16 object=Stats/visits ok=true
An exception inside an object surfaces in the caller as Durable::RemoteError, with remote_class naming
the original exception — or "Melee::Objects::WorkerError" when the worker could not be reached at all.
There is no way to tell those two apart except by that string.
When you suspect the compiler
If CRuby and the deployed binary genuinely disagree, that is a dialect trap, and the project keeps a list of
every one found so far in docs/research/spinel.md in the repository. Reduce it to the smallest program that
shows the difference, run it under both, and check the list.
See also
- Logging — levels, fields, the 500 line.
- The Ruby that compiles — the traps themselves.
- Testing an app.