Documentation error in start_p(), or simply not understanding the docs?

[rmanfredi]

• Mojolicious version: current git (eeef1e2)
• Perl version: perl 5, version 28, subversion 1 (v5.28.1)
• Operating system: Debian GNU/Linux 10 (buster)

I wanted to try the low-level promises, but apparently they do not work as expected (as is documented, that is), whereas async/await do.

Here is a sample script that does NOT work as expected, call it bug-promise.pl:

#!/usr/bin/perl

use Mojolicious::Lite -signatures;

app->log->level("debug");
app->log->info("starting " . app->moniker);

any '/test' => sub ($c) {
        $c->render(text => "got there\n" . $c->req->build_body)
};

any '/wrap' => sub ($c) {
        my $req = $c->req;
        my $log = $c->app->log;
        my $ua = Mojo::UserAgent->new;
        $ua = $ua->max_redirects(0)->connect_timeout(3)->request_timeout(5);
        my $url = "http://localhost:12080/test";
        my $tx = $ua->build_tx($req->method, $url, $req->headers->to_hash);
        $tx->req->headers->add('X-Forwarded-For' => $c->tx->original_remote_address);
        $tx->req->body($req->build_body) if $req->body_size;
        my $res;
        $c->render_later;               # Going async
        $log->debug(sprintf "async mapping to %s %s", $req->method, $url);
        $log->debug(sprintf "body length: %d bytes", $req->body_size);
        # This is the asynchronous part
        eval {
                # Use promise chaining code instead of await for better error logging
                # However this code  DOES NOT WORK: it returns immediately?
                $ua->start_p($tx)->then(sub ($tx) {
                        $log->info("got result");
                        $res = $tx->result;
                })->catch(sub ($err) {
                        $log->warn("relaying error: $err");
                })->wait;
        };
        $log->debug("back to synchronous");
        # Back to synchronous
        if ($@ || !defined $res) {
                $log->warn("exception: $@") if $@;
                $log->warn("no result") unless defined $res;
                return $c->rendered(503);
        }
        # Propagate result
        my $type;
        $type = $res->headers->content_type if $res->headers->content_length;
        $c->res->headers->content_type($type) if $type;
        $c->res->body($res->body);
        my $code = $res->code;
        $c->res->headers->location($res->headers->location) if $res->is_redirect;
        $c->rendered($code);
};

app->start;

# vi: set syn=perl ts=4 sw=4:

Running it with ./bug-promise.pl daemon -l http://localhost:12080,

From another terminal, running curl -D - http://localhost:12080/wrap yields the unexpected 503 error.

The debugging output is:

[2021-04-10 16:43:09.07101] [17008] [info] Listening at "http://localhost:12080"
Web application available at http://localhost:12080
[2021-04-10 16:43:11.11518] [17008] [debug] [FzRRiKOvbl60] GET "/wrap"
[2021-04-10 16:43:11.11565] [17008] [debug] [FzRRiKOvbl60] Routing to a callback
[2021-04-10 16:43:11.11596] [17008] [debug] async mapping to GET http://localhost:12080/test
[2021-04-10 16:43:11.11602] [17008] [debug] body length: 0 bytes
[2021-04-10 16:43:11.11648] [17008] [debug] back to synchronous
[2021-04-10 16:43:11.11653] [17008] [warn] no result
[2021-04-10 16:43:11.11670] [17008] [debug] [FzRRiKOvbl60] 503 Service Unavailable (0.001508s, 663.130/s)
[2021-04-10 16:43:11.11737] [17008] [warn] relaying error: Premature connection close

Rewriting using async / await yields the following bug.pl script (which is working):

#!/usr/bin/perl

use Mojolicious::Lite -signatures, -async_await;

app->log->level("debug");
app->log->info("starting " . app->moniker);

any '/test' => sub ($c) {
        $c->render(text => "got there\n" . $c->req->build_body)
};

any '/wrap' => async sub ($c) {
        my $req = $c->req;
        my $log = $c->app->log;
        my $ua = Mojo::UserAgent->new;
        $ua = $ua->max_redirects(0)->connect_timeout(3)->request_timeout(5);
        my $url = "http://localhost:12080/test";
        my $tx = $ua->build_tx($req->method, $url, $req->headers->to_hash);
        $tx->req->headers->add('X-Forwarded-For' => $c->tx->original_remote_address);
        $tx->req->body($req->build_body) if $req->body_size;
        my $res;
        $c->render_later;               # Going async
        $log->debug(sprintf "async mapping to %s %s", $req->method, $url);
        $log->debug(sprintf "body length: %d bytes", $req->body_size)
                if $req->body_size;
        # This is the asynchronous part
        eval {
                await $ua->start_p($tx);
                $log->info("got result");
                $res = $tx->result;
        };
        $log->debug("back to synchronous");
        # Back to synchronous
        if ($@ || !defined $res) {
                $log->warn("exception: $@") if $@;
                $log->warn("no result") unless defined $res;
                return $c->rendered(503);
        }
        # Propagate result
        my $type;
        $type = $res->headers->content_type if $res->headers->content_length;
        $c->res->headers->content_type($type) if $type;
        $c->res->body($res->body);
        my $code = $res->code;
        $c->res->headers->location($res->headers->location) if $res->is_redirect;
        $c->rendered($code);
};

app->start;

# vi: set syn=perl ts=4 sw=4:

Running it with ./bug.pl daemon -l http://localhost:12080,

From another terminal, running curl -D - http://localhost:12080/wrap yields the expected output:

HTTP/1.1 200 OK
Date: Sat, 10 Apr 2021 14:51:07 GMT
Content-Length: 10
Content-Type: text/html;charset=UTF-8
Server: Mojolicious (Perl)

got there

And the debugging logs are:

[2021-04-10 16:51:03.42252] [22459] [info] starting bug
[2021-04-10 16:51:03.42527] [22459] [info] Listening at "http://localhost:12080"
Web application available at http://localhost:12080
[2021-04-10 16:51:07.68746] [22459] [debug] [s711apriTj9b] GET "/wrap"
[2021-04-10 16:51:07.68787] [22459] [debug] [s711apriTj9b] Routing to a callback
[2021-04-10 16:51:07.68812] [22459] [debug] async mapping to GET http://localhost:12080/test
[2021-04-10 16:51:07.69015] [22459] [debug] [b3rQORei7z_k] GET "/test"
[2021-04-10 16:51:07.69043] [22459] [debug] [b3rQORei7z_k] Routing to a callback
[2021-04-10 16:51:07.69070] [22459] [debug] [b3rQORei7z_k] 200 OK (0.000537s, 1862.197/s)
[2021-04-10 16:51:07.69145] [22459] [info] got result
[2021-04-10 16:51:07.69156] [22459] [debug] back to synchronous
[2021-04-10 16:51:07.69172] [22459] [debug] [s711apriTj9b] 200 OK (0.004265s, 234.467/s)

Why is the promise code not working? Obviously, I'm totally new to Mojolicious and following the documentation blindly, so I must have been missing something, or there is a documentation bug, or there is a code bug.

BTW: there is a problem with the $req>body() routine which returns an empty string despite $req->body_size being non-zero. Looking at the code, I figured I would have to use $req->build_body() to pass in the original body (when testing the above example with a POST and a few "form" parameters, as in curl -X POST -F foo=bar ...) because the body content was obviously multipart. But not having:

$req->body_size == length $req->body

surprised me a lot.

[kraih]

Which part of the documentation are you referring to?

[kraih]

Your problem is probably that ->wait doesn't do what you think it does. That's pretty common. It's best to pretend ->wait does not exist at all while you're still learning.

[rmanfredi]

I'm referring to that bit in Mojo::UserAgent:

start_p
      my $promise = $ua->start_p(Mojo::Transaction::HTTP->new);

    Same as "start", but performs all requests non-blocking and returns a
    Mojo::Promise object instead of accepting a callback.

      my $tx = $ua->build_tx(GET => 'http://example.com');
      $ua->start_p($tx)->then(sub ($tx) {
        say $tx->result->body;
      })->catch(sub ($err) {
        warn "Connection error: $err";
      })->wait;

So how does one prevent the code from continuing until the promise is either satisfied or in error? With await it is particularly obvious, but with promises, I would have expected wait to be the synchronization barrier.

Hence, how can I make the code work properly if wait does nothing?

[kraih]

And await has to do some very advanced magic to make it work.

[Grinnz]

Aside from async/await, the usual practice is to chain any successive behavior with ->then and ->catch, either directly or on the promise object when returned to somewhere else, since you cannot "wait for synchronization". async/await allows it to appear to wait for such though it is actually just deferring to the event loop.

[rmanfredi]

Yes, I understand all of that.

Since the Mojo::Promise documentations says:

  wait
      $promise->wait;

    Start "ioloop" and stop it again once the promise has been fulfilled or
    rejected, does nothing when "ioloop" is already running.

Does it mean that, in my code, wait() simply falls through because the ioloop is already running?

Is there a blocking call that I could invoke on the promise to return to the event loop and only return when the promise is resolved or in error? (which is certainly what await achieves somehow`)?

[Grinnz]

No, the event reactor cannot recurse. await achieves this by suspending the interpreter context so the already-running event loop can continue to run.

[rmanfredi]

I see, so then await is the way to go because it makes the code more natural (and that's the point of that syntaxic sugar).

Now how do you handle exceptions with await? The code dies and you trap it in eval {} as I did in my example. Or what?

[rmanfredi]

I found out how to fix the promise code I wrote above.

Instead of wrongly saying:

                $ua->start_p($tx)->then(sub ($tx) {
                        $log->info("got result");
                        $res = $tx->result;
                })->catch(sub ($err) {
                        $log->warn("relaying error: $err");
                })->wait;

I need to write:

                Mojo::Promise->all(
                        $ua->start_p($tx)
                )->then(sub ($tx) {
                        $log->info("got result");
                        $res = $tx->result;
                })->catch(sub ($err) {
                        $log->warn("relaying error: $err");
                })->wait;

to make sure the flow does not go past ->wait until the promise started by start_p() is dealt with.

[rmanfredi]

Perfect demonstration that the docs are really unclear. What is the proper way to achieve the await semantics with Mojo::Promise then?

[kraih]

Let me repeat that one last time, you can't.

[rmanfredi]

So what you are really saying is that the above code is working because it simply blocks the process?

[kraih]

Yes, you somehow created a bug that blocks the whole process.

[kraih]

That's all wait can do even under the best circumstances. The only way to do what you want to achieve is to use async/await.

[rmanfredi]

Got it, thanks.