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

Catch overflow errors and output a warning #16

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

bendangelo
Copy link
Contributor

@bendangelo bendangelo commented Jun 25, 2024

Addresses #15 . This prevents the server from crashing cause of the frame size.

Not sure if it should do a log call instead of a puts.

@@ -376,6 +376,11 @@ module HTTP2
@state = State::Closed
next
end
rescue ex : OverflowError
puts "[WARN] Incoming frame size exceeds local window size of (#{@initial_window_size.get}). Conection closed."
Copy link
Owner

Choose a reason for hiding this comment

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

I agree we should use a Log here over puts for a few reasons:

  • Log levels can be used to filter out log entries
  • Log backends let the application determine where the logs will be outputted, so if your app doesn't use STDOUT you can send them to whatever log sink you like without configuring infrastructure to do it
  • Log metadata lets you structure the logs, making them more searchable[1]
  • puts performs the I/O immediately whereas Log coalesces multiple log writes across fibers into a single I/O call, making the Log call more performant

The hard part is that I don't yet have a logger setup other than in the LogHandler.


[1]

For example, my apps on GCP use a custom JSON log formatter in production and the default Crystal log formatter in development. Here is an example of some logging output using that formatter. This is not from my actual production logs, it's just an example of what this could look like with Log instead of puts:

{
  "timestamp": "2024-06-29T15:01:42.468267000Z",
  "severity": "warn",
  "source": "http2",
  "message": "oops",
  "error": {
    "type": "OverflowError",
    "message": "insert error message here",
    "trace": [
      "log_json_formatter.cr:20:3 in '__crystal_main'",
      ".../crystal/1.12.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code'",
      ".../crystal/1.12.2/share/crystal/src/crystal/main.cr:115:7 in 'main'",
      ".../crystal/1.12.2/share/crystal/src/crystal/main.cr:141:3 in 'main'"
    ]
  },
  "data": {
    "initial_window_size": 65535,
    "frame_size": 1234567890
  }
}

The code to generate this logging looks like this:

  Log.for("http2").warn exception: ex, &.emit "oops",
    initial_window_size: initial_window_size,
    frame_size: actual_data_size

And my log query to find all occurrences of it could look like this:

jsonPayload.source = "http2"
jsonPayload.error.type = "OverflowError"

Some log processors also allow you to aggregate these logs so you can do things like find what a common size_sent looks like, show where the invalid HTTP2 connections are coming from (a borked internal service), etc.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I know a logger should be used but one wasn't setup. So I'm looking for how you wanted to handle it.

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