Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue 90: Add additional instrumentation for flash messages. #173

Merged
merged 7 commits into from
Nov 11, 2021

Conversation

jsthomas
Copy link
Contributor

This change addresses #90. It introduces a new debug log point that records the current state of the flash message cookie on every request. Using the custom log levels introduced in #171, developers can easily set the dream.flash log source to debug level to trace their flash messages. The flash message example (w-flash) has been updated to illustrate how to do this.

On some browsers (for example, Firefox) cookies are limited to a maximum of 4096 bytes; above this limit, a browser may drop the cookie. Since this can prevent flash messages from appearing, I've also included a warning log point to alert developers when their message content is too big.

@@ -48,6 +48,8 @@ into cookies and reads them back out:

```ocaml
let () =
Dream.initialize_log ~level:`Info ();
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

AFAIK this call shouldn't be necessary. Is it? If set_log_level requires it, set_log_level should be altered to do a lazy internal initialize_log.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When I tested this against the w-flash example it did appear to be necessary; unfortunately I don't fully understand why. I've updated set_log_level.

| `Ok ["text", text] ->
let () = Dream.put_flash "Info" text request in
| `Ok ["text", text] ->
let () = Dream.put_flash "Info" text request in
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why have these lines had an indentation-only change?

Also, where does this kind of indentation come from? It is wasteful of the left margin.

let existing = Dream.cookie flash_cookie request in
log.debug (fun log ->
let current =
flash request
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't this display the contents of outbox, rather than reading the cookie, which AFAIK is the flash messages returned in the request? If you'd like to display incoming flash messages as I think this is doing, I think it should be done before the call to inner_handler.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the issue, @thangngoc89 wrote that it was "frustrating to debug why flash messages aren't rendered". I thought it made sense to log the flash messages from the current request's cookie because those are the ones available for rendering a response. This also appears to match the behavior of the example code in the issue description.

I've fixed the ordering with inner_handler; that was an oversight on my part.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The question is, in the original ordering, why read the cookie on the request (flash request), rather than reading outbox? Aren't the messages in the outbox the ones that will be put in the response?

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah okay, I understood you. I got double-negative-confused by myself :) Okay, I now think this is doing what #90 was asking, and the ordering makes sense now.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you move the debug print all the way to the top of the middleware? It doesn't seem to depend on any of the values bound before it now, and having them bound there makes it seem like it might depend. It's a clean print of the flash messages being returned to the server. It will especially make it clear that the logging does not depend on the rebinding of request to one that has the outbox attached.

@aantron aantron merged commit b440244 into aantron:master Nov 11, 2021
@aantron
Copy link
Owner

aantron commented Nov 11, 2021

Okay, I realized I have only trivial nits left, so I merged. Thanks for doing this with the several steps it took!

@jsthomas jsthomas deleted the issue-90 branch November 12, 2021 22:18
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants