Lwt: Lwt_io.eprintf blocks forever (used with ocsigen and eliom)

[lebotlan]

Hi,

(Sequel to a discussion on gitter)
Here is a short program which uses lwt and ocsigen/eliom (see README in attached tgz).

In short:

make
./ocsigen (it launches ocsigen with the expected config file)

On my computer, it hangs forever on the first Lwt_io.eprintf line.
Curiously, if I lift all the Lwt_io.printf to top-level let%lwt lets, then it hangs earlier, on Lwt_io.printf (so it seems to block on stderr or stdout, depending on code layout).

ocaml 4.08.1
ocsigenserver 2.15.0
glibc 2.23
and the current git-clone version of lwt (apparently 2.4.3-1208-gf1fe076).

lwt-ocsigen-debug.tar.gz

Also, note that I have tested the code given at the beginning of master: ocsigen/lwt#704, which seems to succeed:
loop 0 of 10
...
loop 9 of 10
loop 10 of 10

Finally, I can try to look into Lwt_io, but what is the most efficient way to hack Lwt_io without having to recompile all dependent libraries? (as does opam update when a pinned repository changes)

[aantron]

@lebotlan I haven't looked at the dependencies of the project, but generally you would create a directory with this structure:

root_directory/
|--- dune-workspace
|--- lwt/
|--- your_project/
|--- other_dep1/
|--- other_dep2/

The dune-workspace file turns root_directory/ into a Dune workspace. When linking, Dune will favor sibling projects in the workspace over anything installed in opam, and it will do the minimum recompilation needed to satisfy whatever command you are using to build or test. This does require all deps between your project and Lwt, though.

[aantron]

Also, the easiest way to get the Lwt commit you are using, is to cd into lwt, and do git log. Look at the hash on the first line. I'm not familiar with 2.4.3-1208-gf1fe076, where did that string come from?

[lebotlan]

2.4.3-1208-gf1fe076 comes from git describe --tags

I am using commit f1fe076202eff1cd27de478b20939a0ef8a710fc

OK to include lwt in the dune workspace. I had tried it earlier, but the code used to depend on many libraries and dune complained about inconsistent modules... It should be easier now that the code is minimal.

By the way, I could reproduce the bug on glibc 2.27, lwt 4.3.0.

[aantron]

I see several extensions in your site.conf, like dbm. Can you remove them and still reproduce the bug? This should greatly reduce the amount of code we are searching.

You should be able to proceed efficiently by moving your code right into ocsigenserver. Begin by doing git clone https://github.com/ocsigen/ocsigenserver, then put your site right into the ocsigenserver directory. Working directly from ocsigenserver will give you fast rebuilds as you simplify the server away.

One thing you might look into is linking your program directly into the server. You'll probably want to replace calls to Dynlink or Ocsigen_loader, or just make sure the server can load a config that doesn't mention a cma file. In site.ml, you'll want to scope all the code in a function, so you can delay its execution until when the server would have loaded the module, and then run that function when the cma file would have been loaded. You'll need to call Lwt_main.run there.

[aantron]

If you can inline this example into ocsigenserver, and then simplify ocsigenserver + your example until ocsigenserver is no longer using a command pipe, pid files, or reading an external config, I should be able to take over from there. Right now, I am having trouble running the example on my system, because ocsigenserver is having some permissions issue with the command pipe. Once ocsigenserver is more self-contained, it should be pretty straightforward (if tedious) for me to simplify the rest.

[lebotlan]

Hi,

Something interesting:

Before compacting ocsigenserver+mysite into a single executable, I have tried to simplify my code as you suggest.

Hence, as above, my current setup is still : official ocsigenserver.2.15 & my own dynamically-loaded site.cma.

Version A (blocking)

site.ml contains

let go () =
 ...many printfs and Lwt_io.printf, eprintf, exactly as above

let%lwt () = go ()

Version B (non blocking, all fine)

Similar, but replace the last line by:

let _ = go ()

Version A blocks on the first Lwt.eprintf (and CTRL+C hangs), whereas Version B runs correctly, all the expected messages being printed (and CTRL+C stops the running program).

site.ml.gz

I'll now try to simplify ocsigenserver (might take some time)...

[aantron]

The top-level let%lwt becomes a call to Lwt_main.run, which makes me think this might be another instance of https://github.com/ocsigen/lwt/issues/607. Try pinning the branch nested-lwt-main-run from https://github.com/ocsigen/lwt/pull/609. Do you still have the problem if you do that?

[lebotlan]

Indeed, I was investigating nested calls to Lwt_main.run too (having discovered how top-level let%lwt calls were transformed).

Just for the record, here is a way to block Lwt_io.eprintf calls using a nested Lwt_main.run (and using a fifo that we saturate first). Without the nested call, everything is fine.

nested.tar.gz

I'll check asap the branch from #609 as you suggest.

[lebotlan]

git checkout origin/nested-lwt-main-run
opam pin add lwt

Compilation fails with ocaml.4.08.1 :

File "src/unix/lwt_bytes.ml", line 208, characters 2-17:
# 208 |   Array1.map_file fd ?pos char c_layout shared size
#         ^^^^^^^^^^^^^^^
# Error: Unbound value Array1.map_file

Looks like an API change in Bigarray. I may try to fix it (but not tonight, and probably not tomorrow either).

[aantron]

The #609 branch only needed a rebase, which I've just done. It should now work on 4.08.1. The Array1.map_file problem was fixed in https://github.com/ocsigen/lwt/issues/658#issuecomment-463689502, which came long after #609.

[lebotlan]

That's it!
Using #609 both bugs disappear (the small piece of code above, as well as the very original ocsigen+eliom code). Lwt no longer blocks, but, of course, an exception is raised
Failure("Nested calls to Lwt_main.run are not allowed")

(If this is ok with you, you may close this issue.)

Two suggestions, though (I can create new feature requests, if you think they are worth it.)
1 - People using lwt_ppx do not necessarily see the relation between top-level let%lwt and Lwt_main.run. Hence, the failure above can be hard to understand.
2 - Nested Lwt_main.run would be handy in some situations. It allows programs to arbitrarily mix lwt-code and classic non-lwt code. Is there any hope that nested calls would be accepted and work transparently?

Anyway, thanks for the help, it is much better to know exactly why something goes wrong.

[aantron]

1. I've thought about deprecating top-level let%lwt, and emitting a warning when someone is using it. I think it's better to force people to use Lwt_main.run explicitly. When I last looked at it in the PPX, I was just hoping nobody is actually using it at the top level, but clearly that's not the case :) @Drup, any opinion on this? @lebotlan you're welcome to open an issue about that, or about doing anything else with top-level let%lwt; otherwise, I will open an issue later.

2. Can you suggest a specific situation that has occurred, where a nested Lwt_main.run is truly useful? Generally, if there is an outer Lwt_main.run, it's not necessary to have an inner one at all. The rule so far has been to only introduce Lwt_main.run at the absolute top level of the application, by the final user (or, in the case of ocsigenserver, apparently, the framework), who is composing the entire program, and knows when is the right time and the right stack frame to block (after application initialization, including any long-lived blocking calls). This rule has been good enough for compositionality so far. If you (or someone) can offer a compelling use case for nesting Lwt_main.run, that isn't served by the current convention, we can look into making it safe to nest the call somehow. But otherwise, it's probably not worth any complexity that may be introduced.

   Suppose there is a top-level stack frame, which has blocked by calling Lwt_main.run, and that Lwt_main.run has decided to call a list of callbacks that will resolve promises.

   If one of those callbacks also calls Lwt_main.run, it will block, and the outer Lwt_main.run will never finish calling all the other callbacks that it needed to call. If one of those callbacks would have resolved the promise that the inner Lwt_main.run is waiting on, the result is partial deadlock between the Lwt_main.runs. This kind of interaction is probably what led to the behavior you observed.

   I wouldn't want to try to sort all possible variations of this kind of behavior :) Besides lists of callbacks to call, there might be chained callbacks (promises depending on each other in sequence). There might be book-keeping that the outer Lwt_main.run is expecting to be able to do after a callback returns, and so on.

   I haven't thought through all consequences in detail, but it's possible that there is even no truly good way to fully resolve this, so I think we would need a very good reason for trying :)

[lebotlan]

1. The need for nested Lwt_main.run has occurred sometimes when using a non-lwt library and trying to register a lwt-callback :
   Classicallib.register_callback (fun () -> e.g.lwt-code-which-reads-a-file)

In lablgtk, for instance, callbacks are usually of type unit -> unit. The obvious solution to include lwt-code is to use Lwt.async and launch an asynchronous promise.

A problematic case occurs when the callback must be synchronous (it expects an answer). As a typical example, when one closes a window, a callback of type (unit -> bool) is invoked. The boolean indicates if the window should really be closed or not. Such a callback may open a popup and asks if you really want to quit, if you want to save, etc.
It is natural to write the callback in lwt-style (the popup can be arbitrarily complex asynchronous code). However, the callback type (unit -> bool) is not lwt-compatible.

My personal solution consists in providing a callback which always returns false (that means ignore closing) BUT which also launches an asynchronous popup that will eventually close the window using the appropriate API call.

So, for the moment, I can perfectly live without nested Lwt_main.run.

As a conclusion, if nested Lwt_main.run introduce any kind of complexity, then I would definitely forbid them. I totally prefer a library which forbids well-identified situations to a more expressive library whose behavior is untractable.

[lebotlan]

As for top-level let%lwt, I am not sure if I can really live without them.

When possible, I'll try to examine all the ml files I have written so far and look for such top-level lets (assuming the code is well-indented, they should occur at the beginning of line).

[aantron]

A callback of type unit -> bool is not a good place for Lwt_main.run, because Lwt_main.run can insert arbitrary processing into the callback (when it calls callbacks of its own, which may be completely unrelated, may do a huge amount of work, etc). In general, Lwt_main.run isn't for converting asynchronous code to synchronous, but for picking a place in the program where it makes sense to drive the program's main loop. Ultimately, the problem is the lablgtk API. The signature of a callback that allows asynchronous processing should be (bool -> unit) -> unit or unit -> bool M.t, not unit -> bool.

As for top-level let%lwt, I am not sure if I can really live without them.

You should be able to, since, in each case, you can either write Lwt_main.run explicitly, or turn them into expressions, converting module side effects into functions that have to be explicitly called, or promises that have to be explicitly waited on.

[aantron]

I opened https://github.com/ocsigen/lwt/issues/728 about top-level let%lwt.