$c->log

[Stefan Adams]

In Mojolicious::Plugin::DefaultHelpers#og

I suspect there is a good, fundamental reason behind this decision in the documents, but I'm not sure what it is.

Why is $log passed to the model method

# Pass logger with context to model
my $log = $c->log;
$c->some_model->create({foo => $foo}, $log);

Instead of $c->log

# Pass logger with context to model
$c->some_model->create({foo => $foo}, $c->log);

[Dan Book]

I don't believe there would be any difference.

-Dan

--
You received this message because you are subscribed to the Google Groups "Mojolicious" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mojolicious...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CACyQ%2BFTSncQ%3D2ff9wf5Q6wOOH0RQp96-LPMbNyv2sGoJNri1eg%40mail.gmail.com.

[Stefan Adams]

Excellent!  I'm not finding there to be any difference, either.  Thank you for the reply!

As precise as the documentation is, I thought I would check to make sure there wasn't a good reason for it.

The documentation shows that the controller log helper can be passed to a model in this way...  Rather than passing the log helper to each method as shown in the documentation, could we store it in the model object so that all methods would be able to use it and not need to have the log helper called explicitly each time?

Here's an example gist.

To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CABMkAVV%2BOE7OERWzmc0-h7OhobvAteKqVAhWQJkK1kxyQY8ZqA%40mail.gmail.com.

[Dan Book]

No, the purpose of passing the log from each request is that it includes the context of the request ID (using the new context feature of Mojo::Log).

-Dan

To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CACyQ%2BFTpazf5vzBE7wVr0tadTt%3DxXKTCBN5NvWMRFJv4Wi46Dg%40mail.gmail.com.

[Stefan Adams]

Hmm...  But isn't this below including the context of the request ID for each request?

$self->helper(model => sub {$model->log(shift->log)});

Each request will have a different context.

Using apachebench to concurrently send requests to the preforking application, we get this:

$ perl script/my_app prefork & ab -n 100 -c 100 http://localhost:3000/

[2020-04-09 23:28:01.39904] [12961] [debug] [3457c2a0] GET "/"
[2020-04-09 23:28:01.39820] [12962] [debug] [c759c8bd] Routing to a callback
[2020-04-09 23:28:01.39929] [12962] [debug] [c759c8bd] got: model logged with request id
[2020-04-09 23:28:01.39940] [12959] [debug] [b0ba4af8] GET "/"
[2020-04-09 23:28:01.39953] [12959] [debug] [b0ba4af8] Routing to a callback
[2020-04-09 23:28:01.39959] [12959] [debug] [b0ba4af8] got: model logged with request id
[2020-04-09 23:28:01.39967] [12962] [debug] [c759c8bd] 204 No Content (0.002487s, 402.091/s)
[2020-04-09 23:28:01.39969] [12959] [debug] [b0ba4af8] 204 No Content (0.000277s, 3610.108/s)
[2020-04-09 23:28:01.40082] [12962] [debug] [b38bd53f] GET "/"
[2020-04-09 23:28:01.40088] [12960] [debug] [b0ba4af8] GET "/"
[2020-04-09 23:28:01.40102] [12961] [debug] [3457c2a0] Routing to a callback
[2020-04-09 23:28:01.40118] [12960] [debug] [b0ba4af8] Routing to a callback
[2020-04-09 23:28:01.40118] [12961] [debug] [3457c2a0] got: model logged with request id
[2020-04-09 23:28:01.40125] [12960] [debug] [b0ba4af8] got: model logged with request id
[2020-04-09 23:28:01.40139] [12960] [debug] [b0ba4af8] 204 No Content (0.000497s, 2012.072/s)
[2020-04-09 23:28:01.40148] [12961] [debug] [3457c2a0] 204 No Content (0.002434s, 410.846/s)
[2020-04-09 23:28:01.40207] [12962] [debug] [b38bd53f] Routing to a callback
[2020-04-09 23:28:01.40221] [12962] [debug] [b38bd53f] got: model logged with request id
[2020-04-09 23:28:01.40239] [12962] [debug] [b38bd53f] 204 No Content (0.001559s, 641.437/s)

It shows that the logging context used in the model's get method has the same context as in the routing action that renders the response.

To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CABMkAVVqT%3DTYO2rMY_NSSPC8v4m9R-S_Ckz1LoEkxvCdHgfTVw%40mail.gmail.com.

[Dan Book]

Yes...? That is passing $c->log each time the helper is called, which is what was suggested.

-Dan

To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CACyQ%2BFQFbyxoQZfT2XejzGHx4ZhX8u3AY9FpQz18Phux43%2BnVw%40mail.gmail.com.

[Dan Book]

Oh I see, setting it in the model attribute. No, that won't work in an asynchronous application, because two requests may share a model object.

-Dan

[Stefan Adams]

Ah excellent -- very clear explanation, thank you.  Do you have any suggestions, or is there absolutely no way to do this without passing the object to each method call on the model object?

To view this discussion on the web visit https://groups.google.com/d/msgid/mojolicious/CABMkAVVhn47kGR9fy39HeQ8kgUN1FHddmWuYgXB5OeOU61AXOw%40mail.gmail.com.