When fibers hang: the deadline report and the fiber trace
🤖 Generated with [ECA](https://eca.dev) (anthropic/claude-opus-4-5) Co-Authored-By: eca-agent <git@eca.dev>
This commit is contained in:
parent
4d29d7b7b6
commit
623b68513c
1 changed files with 93 additions and 0 deletions
|
|
@ -1199,6 +1199,99 @@ A scope also owns resources. @code{(own! thunk)} registers a release on the inne
|
|||
|
||||
Do not park a bjoroutine's thread by accident. A scope in an ordinary @code{(fun ...)} that a bjoroutine calls parks the thread of that bjoroutine, and the compiler warns about it. Write the scope in the bjoroutine itself. Or, if the function the lambda is given to takes a @code{-?->} parameter, write the lambda as a @code{(bjoroutine ...)}.
|
||||
|
||||
@subsubsection{When fibers hang}
|
||||
|
||||
A scope does not return until its fibers have ended, so a fiber that waits forever makes its scope wait forever too. Two things show you where the fibers wait.
|
||||
|
||||
@strong{A deadline says where the others were.} When @code{with-deadline} stops the body, the @code{Cancelled} that the body raises tells where every other fiber of the scope was waiting. Fibers in nested scopes are counted too:
|
||||
|
||||
@codeblock[#:lang "bjolang"]|{
|
||||
(: worker (-bjo-> (Chan int) void))
|
||||
(defbjo (worker jobs)
|
||||
(let go ()
|
||||
(ignore (sync (chan-recv jobs)))
|
||||
(go)))
|
||||
|
||||
(defbjo (main)
|
||||
(def jobs (make-chan))
|
||||
(match (try (with-deadline (milliseconds 100)
|
||||
(spawn (worker jobs))
|
||||
(spawn (worker jobs))
|
||||
(sync (timeout (minutes 1))))
|
||||
#:catch (System.Exception))
|
||||
((Ok v) (println "done"))
|
||||
((Err e) (println (.-Message e))))
|
||||
0)
|
||||
}|
|
||||
|
||||
@codeblock[#:lang "text"]|{
|
||||
cancelled: (Deadline)
|
||||
When the deadline passed, 2 other fibers were waiting:
|
||||
2 fibers at app.bjo:4 (ignore (sync (chan-recv jobs)))
|
||||
}|
|
||||
|
||||
This is always on and costs nothing until a deadline stops a fiber. A deadline that stops only children, after the body has returned, is not a failure, so then nothing is raised.
|
||||
|
||||
@strong{The fiber trace.} Start the program with @code{BJO_FIBER_TRACE} set in the environment:
|
||||
|
||||
@codeblock[#:lang "text"]|{
|
||||
BJO_FIBER_TRACE=1 bjo run
|
||||
}|
|
||||
|
||||
The program then keeps a record of every fiber that waits, and you get it as a report in three ways:
|
||||
|
||||
@itemlist{
|
||||
@item{@code{(fiber-trace)} returns the report as a string.}
|
||||
@item{SIGQUIT (Ctrl-\ in the terminal, or @code{kill -QUIT pid}) writes it to standard error. The program goes on.}
|
||||
@item{When the program looks deadlocked, it writes the report once by itself: nothing has run for two seconds, and every fiber waits on a channel, on another fiber or on the close of a scope.}
|
||||
}
|
||||
|
||||
Here are two philosophers. Each takes one fork and then waits for the other one:
|
||||
|
||||
@codeblock[#:lang "bjolang"]|{
|
||||
(: philosopher (-bjo-> (Chan int) (Chan int) void))
|
||||
(defbjo (philosopher left right)
|
||||
(def l (sync (chan-recv left)))
|
||||
(sync (timeout (milliseconds 50)))
|
||||
(def r (sync (chan-recv right)))
|
||||
(println "ate"))
|
||||
|
||||
(: fork-keeper (-bjo-> (Chan int) void))
|
||||
(defbjo (fork-keeper fork)
|
||||
(sync (chan-send fork 1)))
|
||||
|
||||
(defbjo (main)
|
||||
(def f1 (make-chan))
|
||||
(def f2 (make-chan))
|
||||
(with-scope
|
||||
(spawn (fork-keeper f1))
|
||||
(spawn (fork-keeper f2))
|
||||
(spawn (philosopher f1 f2))
|
||||
(spawn (philosopher f2 f1)))
|
||||
0)
|
||||
}|
|
||||
|
||||
@codeblock[#:lang "text"]|{
|
||||
Bjolang fiber trace: nothing has run for 2 s, and every fiber waits on a channel or on another fiber. This looks like a deadlock.
|
||||
Bjolang fiber trace: 3 fibers waiting.
|
||||
|
||||
main
|
||||
|
||||
scope, opened at app.bjo:15 (with-scope
|
||||
1 fiber closing this scope, waiting for its children, for 2.5 s
|
||||
at app.bjo:15 (with-scope
|
||||
1 fiber waiting in chan-recv on channel #1, for 2.4 s
|
||||
at app.bjo:5 (def r (sync (chan-recv right)))
|
||||
1 fiber waiting in chan-recv on channel #2, for 2.4 s
|
||||
at app.bjo:5 (def r (sync (chan-recv right)))
|
||||
}|
|
||||
|
||||
Each fiber is under the scope it waits in, and the scopes are in a tree. The @code{at} line is the @code{sync}. For a fiber that waits inside a bjoroutine it called, @code{from} lines follow with the callers, innermost first. Fibers that wait at the same place on the same thing are counted together. Each channel has a number, so you can see which fibers wait on the same channel.
|
||||
|
||||
The deadlock check reports only a program that cannot go on. A wait on a timer, a @code{choose}, an inbox or a .NET task can end without help from a fiber, so a program with such a wait is not reported. Use SIGQUIT to see where that program waits.
|
||||
|
||||
With the trace off, the program runs the same code as without it: the JIT removes the tests. With the trace on, every wait costs more (a channel rendezvous takes about four times as long), so use it to find where a program is stuck, not in production.
|
||||
|
||||
@subsubsection{Work that is not a fiber}
|
||||
|
||||
Performing long CPU-bound computations or calling legacy blocking .NET APIs directly inside a fiber can monopolize thread pool threads, preventing other fibers from running. To avoid blocking the pool, you can offload such operations onto dedicated background threads; both helpers return synchronization events:
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue