Long tests in ob run

[o1lo01ol1o]

Running the tests on ob run takes a very long time on our app and it's deleterious on our frontend productivity. Is there a way to skip tests?

If there is not, I'm happy to to implement one if someone wants to point me to where it should go.

[alexfmpe]

The tests? Doesn't ob run just launch the backend/frontend?
If you mean you only want to re-compile things most of the time, there's ob watch

[o1lo01ol1o]

On obelisk's master branch, revision, 135bfd7, ob run builds the modules and then runs tests:

Ok, 361 modules loaded.
Loaded GHCi configuration from /private/var/folders/r5/qky9f4nx26jfmc6bpng5125r0000gn/T/ob-ghci-c54a2baa50c1d7f5/.ghci

All good (361 modules, at 10:15:47)
Running test...

% cat /private/var/folders/r5/qky9f4nx26jfmc6bpng5125r0000gn/T/ob-ghci-c54a2baa50c1d7f5/.ghci
:add Prelude
:set -XImplicitPrelude
:load Backend Frontend
import qualified Obelisk.Run
import qualified Frontend
import qualified Backend

At some point in history, these tests were relatively quick (and, iirc, only tested routes for sanity). Hot-reloading seems to usually make them faster but ob frequently crashes on hot reloading:

Interrupted.
gargoyle-nix-postgres-monitor: Network.Socket.shutdown: invalid argument (Socket is not connected)
Static assets being built...
Static assets built and symlinked to static.out
ghcid: user error (Ghcid.exec, computation is already running, must be used single-threaded)

And then the whole testing round is a bit painful.

[alexfmpe]

I expect that Running test... to be from the --test of ghcid which is used here

obelisk/lib/command/src/Obelisk/Command/Run.hs

Line 591 in 135bfd7

, maybe [] (\cmd -> ["--test=" <> cmd]) mcmd

with ob run passing in cmd

obelisk/lib/command/src/Obelisk/Command/Run.hs

Lines 212 to 221 in 135bfd7

	runGhcid root True (ghciArgs <> dotGhciArgs) pkgs $ Just $ unwords
	[ "Obelisk.Run.run (Obelisk.Run.defaultRunApp"
	, "Backend.backend"
	, "Frontend.frontend"
	, "(Obelisk.Run.runServeAsset " ++ show assets ++ ")"
	, ") { Obelisk.Run._runApp_backendPort =", show freePort
	, ", Obelisk.Run._runApp_forceFrontendPort =", show portOverride
	, ", Obelisk.Run._runApp_tlsCertDirectory =", show certDir
	, "}"
	]

Since this shows up after compilation in your logs, I'm guessing the call to Obelisk.Run.run is just taking that much time.

I've noticed before that ghci seems to be faster at evaluation the second time but don't know why. ob repl consistently gives me

*Obelisk.Run Obelisk.Run Frontend Backend> :set +s
*Obelisk.Run Obelisk.Run Frontend Backend> Right a = checkEncoder Common.Route.fullRouteEncoder
(0.03 secs, 0 bytes)
*Obelisk.Run Obelisk.Run Frontend Backend> Right a = checkEncoder Common.Route.fullRouteEncoder
(0.00 secs, 0 bytes)
*Obelisk.Run Obelisk.Run Frontend Backend> :r
[17 of 19] Compiling Common.Route
[18 of 19] Compiling Frontend
Ok, 19 modules loaded.
*Obelisk.Run Obelisk.Run Frontend Backend> Right a = checkEncoder Common.Route.fullRouteEncoder
(0.01 secs, 0 bytes)
*Obelisk.Run Obelisk.Run Frontend Backend> Right a = checkEncoder Common.Route.fullRouteEncoder
(0.00 secs, 0 bytes)

which seems to imply the first-time-initialization delay on evaluation is smaller after a reload, consistent with your results.

So one of these or a combination of them must be slow in your project

1. Obelisk.Run.run
2. Obelisk.Run.defaultRunApp
3. Backend.backend
4. Frontend.frontend
5. Obelisk.Run.runServeAsset

Should be easy to narrow down how much 3/4 are contributing, but the others can be trickier.
First thing that comes to mind is the overlap check from routes taking a long time. Try measuring in ob repl

> set +s
> Right a = checkEncoder Common.Route.fullRouteEncoder

if that's slow, keep doing checkEncoder on smaller bits until you narrow it down.

That has happened to me when using shadowEncoder or enumEncoder with a type that's too large to efficiently enumerate since they both rely on Universe instances. Some combinators rely on Universe (Some k) though there it's much rarer to accidentally trigger. The relevant ones seem to be just pathComponentEncoder / enum1Encoder / dmapEncoder / fieldMapEncoder

[o1lo01ol1o]

I've suspected the encoder tests were to blame, but only today did I learn about the ghci set +s command!

[o1lo01ol1o]

It seems like any choice of encoder takes 5s initially and then 0.01s.

Common.Route Obelisk.Run> Right x = checkEncoder fullRouteEncoder
(5.05 secs, 0 bytes)
*Common.Route Obelisk.Run> Right x = checkEncoder fullRouteEncoder 
(0.01 secs, 0 bytes)

*Common.Route Obelisk.Run> Right x = checkEncoder fileIdEncoder
(4.61 secs, 0 bytes)
*Common.Route Obelisk.Run> Right x = checkEncoder fileIdEncoder
(0.01 secs, 0 bytes)

*Common.Route Obelisk.Run> Right x = checkEncoder fooEncoder
(4.67 secs, 0 bytes)
*Common.Route Obelisk.Run> Right x = checkEncoder fooEncoder
(0.01 secs, 0 bytes)

There are not many large enumerations; most of the size in the routes come from persisted data values and use the equivalent of unsafeTshowEncoder for our domain types.

[alexfmpe]

Do you also observe the startup slowness when running the backend executable which bypasses the ob run machinery?

[o1lo01ol1o]

the backend executable comes up nearly instantly.

[alexfmpe]

It seems like any choice of encoder takes 5s initially and then 0.01s.

Actually there seems to be more lazyness going around than I first thought. In the skeleton:

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> Right !e = checkEncoder $ enumEncoder @(Either Text) $ \x -> (x :: Int16)
(0.01 secs, 0 bytes)

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> encode e 1
1
(0.11 secs, 117,815,456 bytes)

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> encode e 1
1
(0.11 secs, 117,815,456 bytes)

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> encode e 1
1
(0.11 secs, 117,815,456 bytes)

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> Right !e = checkEncoder $ enumEncoder @(Either Text) $ \x -> (x :: Int32)
(0.01 secs, 0 bytes)

*Obelisk.Run Obelisk.Run Frontend Backend Data.Int> encode e 1
(gave up waiting after a few minutes)

Really not sure where your 5s are coming from. Does only the first 'checkEncoder' in the repl take ~5s or each one independently takes 5s the first time around? If so, maybe the sum of all those is what leads to your slowdown? Could it be possible the backend executable doesn't actually force the check until a page is loaded?

Not sure what else actually happens after compiling and before a page load. If the backend executable always reacts instantly and this is ob run specific, maybe it's something in the asset serving bits?

[o1lo01ol1o]

Does only the first 'checkEncoder' in the repl take ~5s or each one independently takes 5s the first time around?

The first call to checkEncoder is 5s. All others are 0.01s.

[alexfmpe]

I'd check whether the frontend executable is also fast when ran under ghc.
$(nix-build -A ghc.frontend)/bin/frontend or cabal run frontend inside ob shell/nix-shell -A shells.ghc.

Maybe try to call Obelisk.Run.runServeAsset manually by taking the assets path from ob run -v ?

Don't really have more ideas.

[alexfmpe]

FWIW I've noticed that the first-eval delay on ghci (and thus ob run) on my own code is much slower on MacOS than on NixOS - that seems to be fixed in 9.8.3: https://gitlab.haskell.org/ghc/ghc/-/issues/23415
I'm seeing a 3x difference on 9.6 and 12x on 8.10