Skip to content

Catch overflow errors and output a warning #16

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.

Sign up for GitHub

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

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

Catch overflow errors and output a warning #16

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 0 additions & 3 deletions spec/grpc_spec.cr
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,4 @@ require "./spec_helper"
describe GRPC do
# TODO: Write tests

it "works" do
false.should eq(true)
end
end
5 changes: 5 additions & 0 deletions src/http2.cr
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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

@jgaskins jgaskins Jun 29, 2024

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

@bendangelo bendangelo Jun 30, 2024

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.

# window size received is too large, closing connection
@socket.close
@state = State::Closed
rescue ex : IO::EOFError
# The client has closed the connection, so we don't actually need to do
# anything here and we can exit normally.
Expand Down