bug#32234: Cuirass: The SQLite built in busy handler might block the Fibers scheduler

[Ludovic Courtès]

Hi,

Clément Lassieur <address@hidden> skribis:

> I'm trying to understand why Berlin web API times out[1].

Just to be clear, it does block on things involving non-trivial database
queries:

--8<---------------cut here---------------start------------->8---
address@hidden ~$ time wget -q -O -  http://localhost:8081/specifications
[{"name" : "core-updates-core-updates","load-path-inputs" : 
["core-updates"],"package-path-inputs" : [],"proc-input" : 
"core-updates","proc-file" : "build-aux/cuirass/gnu-system.scm","proc" : 
"cuirass-jobs","proc-args" : {"subset" : "core","systems" : ["x86_64-linux", 
"i686-linux"]},"inputs" : [{"name" : "core-updates","url" : 
"https://git.savannah.gnu.org/git/guix.git","load-path"; : ".","branch" : 
"core-updates","tag" : false,"commit" : false,"no-compile?" : true}]}, {"name" 
: "staging-staging","load-path-inputs" : ["staging"],"package-path-inputs" : 
[],"proc-input" : "staging","proc-file" : 
"build-aux/cuirass/gnu-system.scm","proc" : "cuirass-jobs","proc-args" : 
{"systems" : ["x86_64-linux", "i686-linux"]},"inputs" : [{"name" : 
"staging","url" : "https://git.savannah.gnu.org/git/guix.git","load-path"; : 
".","branch" : "staging","tag" : false,"commit" : false,"no-compile?" : 
true}]}, {"name" : "guix-modular-master","load-path-inputs" : 
["guix-modular"],"package-path-inputs" : [],"proc-input" : 
"guix-modular","proc-file" : "build-aux/cuirass/guix-modular.scm","proc" : 
"cuirass-jobs","proc-args" : {"systems" : ["x86_64-linux", 
"i686-linux"]},"inputs" : [{"name" : "guix-modular","url" : 
"https://git.savannah.gnu.org/git/guix.git","load-path"; : ".","branch" : 
"master","tag" : false,"commit" : false,"no-compile?" : true}]}, {"name" : 
"guix-master","load-path-inputs" : ["guix"],"package-path-inputs" : 
[],"proc-input" : "guix","proc-file" : 
"build-aux/cuirass/gnu-system.scm","proc" : "cuirass-jobs","proc-args" : 
{"subset" : "all","systems" : ["x86_64-linux", "i686-linux"]},"inputs" : 
[{"name" : "guix","url" : 
"https://git.savannah.gnu.org/git/guix.git","load-path"; : ".","branch" : 
"master","tag" : false,"commit" : false,"no-compile?" : true}]}]
real    0m0.007s
user    0m0.004s
sys     0m0.000s
address@hidden ~$ time wget -q -O -  http://localhost:8081/api/latestbuilds?nr=2
[{"id" : 4484197,"jobset" : "core-updates-core-updates","job" : 
"ghc-alex-3.2.3.i686-linux","timestamp" : 1532336715,"starttime" : 
1532336542,"stoptime" : 1532336715,"derivation" : 
"/gnu/store/b072sfmw44ww9dsm1ahpqafjk05zsl04-ghc-alex-3.2.3.drv","buildoutputs" 
: {"out" : {"path" : 
"/gnu/store/qk79zl1gcg6lh4k2nrp72x8iywy317d2-ghc-alex-3.2.3"}},"system" : 
"i686-linux","nixname" : "ghc-alex-3.2.3","buildstatus" : 0,"busy" : 
0,"priority" : 0,"finished" : 1,"buildproducts" : null,"releasename" : 
null,"buildinputs_builds" : null}, {"id" : 4799156,"jobset" : 
"core-updates-core-updates","job" : "ghc-alex-3.2.3.i686-linux","timestamp" : 
1532336715,"starttime" : 1532336542,"stoptime" : 1532336715,"derivation" : 
"/gnu/store/b072sfmw44ww9dsm1ahpqafjk05zsl04-ghc-alex-3.2.3.drv","buildoutputs" 
: {"out" : {"path" : 
"/gnu/store/qk79zl1gcg6lh4k2nrp72x8iywy317d2-ghc-alex-3.2.3"}},"system" : 
"i686-linux","nixname" : "ghc-alex-3.2.3","buildstatus" : 0,"busy" : 
0,"priority" : 0,"finished" : 1,"buildproducts" : null,"releasename" : 
null,"buildinputs_builds" : null}]
real    0m28.033s
user    0m0.004s
sys     0m0.000s
--8<---------------cut here---------------end--------------->8---

I’m not sure it’s due to locking though; we may lack an index or two,
“explain query plan” should help.

> I think the SQlite built in busy handler may block the Fibers scheduler.
> We use "PRAGMA busy_timeout = 30000;", which is an alternative to
> calling sqlite3_busy_timeout(), whose description[2] is:
>
>     This routine sets a busy handler that sleeps for a specified amount
>     of time when a table is locked. The handler will sleep multiple
>     times until at least "ms" milliseconds of sleeping have
>     accumulated. After at least "ms" milliseconds of sleeping, the
>     handler returns 0 which causes sqlite3_step() to return SQLITE_BUSY.
>
> To me this sounds like non-cooperative and non-resumable code.

Indeed!

> A solution would be to set a custom handler through
> sqlite3_busy_handler[3] that would be Fibers compatible, i.e. it would
> let the scheduler schedule other fibers instead of just sleeping, using
> Fibers 'sleep' procedure[4].

AIUI the handler is called from C, and thus it’s a non-resumable
continuation, so this wouldn’t work.

Perhaps instead we need to set the timeout to a small value and handle
SQLITE_BUSY at the call site in our code.  We could define a macro that
automatically retries upon SQLITE_BUSY.

Thoughts?

Ludo’.