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

Padrino integration creates two transactions? #289

Closed
tombruijn opened this issue May 9, 2017 · 4 comments
Closed

Padrino integration creates two transactions? #289

tombruijn opened this issue May 9, 2017 · 4 comments
Labels

Comments

@tombruijn
Copy link
Member

Which means that the events of the first one are ignored resulting in the missing "process_action.padrino" event.

This happens because Padrino calls route! in its own route! method again, this time with the base.superclass argument: https://github.com/padrino/padrino-framework/blob/4a80dca4ec0c52a9c7daa2e28d17c1d8cb024e4b/padrino-core/lib/padrino-core/application/routing.rb#L974

@tombruijn
Copy link
Member Author

tombruijn commented May 9, 2017

That we don't track the perform_action.padrino event comes from a throw :halt Padrino uses. Changing the instrument method to use an ensure rather than a "soft" value capture would fix this.

Should be changed in Appsignal.instrument and Appsignal::Transaction#instrument, or just once in the proposed PR #288

class Foo
  def exits_too_early
    catch :halt do
      puts "instrument:"
      instrument "foo" do
        instrumented_method
      end
    end
  end

  def exits_fine
    catch :halt do
      puts "ensure_instrument:"
      ensure_instrument "foo" do
        instrumented_method
      end
    end
  end

  def instrumented_method
    puts "hello!"
    throw :halt
  end

  def instrument(name)
    puts "-- start #{name}"
    r = yield if block_given?
    puts "-- end #{name}"
    r
  end

  def ensure_instrument(name)
    puts "-- start #{name}"
    yield if block_given?
  ensure
    puts "-- end #{name}"
  end
end

Foo.new.exits_too_early
puts "\n"
Foo.new.exits_fine

# $ ruby foo.rb
# instrument:
# -- start foo
# hello!
#
# ensure_instrument:
# -- start foo
# hello!
# -- end foo

@tombruijn tombruijn changed the title Padrino integration creates two transactions Padrino integration creates two transactions? May 10, 2017
@tombruijn
Copy link
Member Author

Looks like the original problem: "2 transactions being started for a request to a Padrino app", only occurs when the route doesn't exist. When the route doesn't exist in Padrino, it gets asked to a Sinatra app (through the Padrino route! method for some reason).

@tombruijn tombruijn added this to the 2.3 milestone May 10, 2017
@tombruijn tombruijn modified the milestones: Ruby gem 2.4, Ruby gem 2.3 Jun 16, 2017
@tombruijn
Copy link
Member Author

Should be fixed with the standardized middleware in #329

@tombruijn tombruijn removed their assignment Aug 11, 2017
@tombruijn tombruijn changed the title Padrino integration creates two transactions? 🐞 Padrino integration creates two transactions? Oct 27, 2017
@tombruijn tombruijn changed the title 🐞 Padrino integration creates two transactions? Padrino integration creates two transactions? May 30, 2018
@tombruijn tombruijn removed this from the The next minor Ruby gem version milestone Jan 7, 2019
@tombruijn
Copy link
Member Author

tombruijn added a commit that referenced this issue May 31, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

TODO: SPLIT COMMIT:
We can now report the response status as a `response_status` tag and
metric. Previously, due to the position of the Rails middleware, this
was unreliable and wouldn't always report the real status code if other
middleware in the stack returned another status.

This is part of issue
#183, but only
implements it now for Rails apps and apps using the
`Appsignal::Rack::EventHandler` manually. We'll need to update other
instrumentations for Rack, Sinatra, Padrino, Grape, etc. to use this new
EventHandler, so they can also benefit from this new response status tag
and metric.

TODO:

- How to report the request_id? Can't overwrite the tag
- Remove the `request_id2` tag
tombruijn added a commit that referenced this issue May 31, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

One downside of having the Rack EventHandler create the transaction is
that we can no longer use the ActionDispatch (Rails) request ID as the
transaction ID. I tried overwriting the `request_id` tag by setting it
manually, but this doesn't work. If we merge this as-is we might break
any linking we do in our frontend between the request id tag and logs.
I'll start working on a change in our processor for this.

Part of #329
tombruijn added a commit that referenced this issue May 31, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

One downside of having the Rack EventHandler create the transaction is
that we can no longer use the ActionDispatch (Rails) request ID as the
transaction ID. I tried overwriting the `request_id` tag by setting it
manually, but this doesn't work. If we merge this as-is we might break
any linking we do in our frontend between the request id tag and logs.
I'll start working on a change in our processor for this.

Part of #329
tombruijn added a commit that referenced this issue May 31, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

One downside of having the Rack EventHandler create the transaction is
that we can no longer use the ActionDispatch (Rails) request ID as the
transaction ID. I tried overwriting the `request_id` tag by setting it
manually, but this doesn't work. If we merge this as-is we might break
any linking we do in our frontend between the request id tag and logs.
I'll start working on a change in our processor for this.

Part of #329
tombruijn added a commit that referenced this issue May 31, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

Instead of the transaction ID being the request ID, set a new
`request_id` tag to not break existing behavior.

Part of #329
tombruijn added a commit that referenced this issue Jun 3, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

Instead of the transaction ID being the request ID, set a new
`request_id` tag to not break existing behavior.

Part of #329
tombruijn added a commit that referenced this issue Jun 3, 2024
Rework the Rails instrumentation to use the Rack::Events module to start
and complete the transaction at the very start and end of the request.
A new middleware is added at the very top of the middleware stack to
start and complete the transaction.

This allows us to instrument more of the request's duration, as we're
now at the very start and end of the request handling. We will now
report the time the request has spend handling any other middleware.
This will be visible with a new `process_request.rack` event.

To make sure we always close the transaction, listen for the `on_finish`
event, but also register a last resort "after_reply" callback. This
callback is supported by web servers like Puma and Unicorn. If it's
called when a transaction is active, it will close it, preventing
transactions to span multiple requests. If no transaction is active, it
will do nothing.

Moving forward, I'd like to update our Rack, Sinatra, Padrino, Grape,
etc. instrumentations to use this EventHandler middleware too, which
will be a bit more work, because some require users to manually add
middleware. When they all use the same EventHandler, we have one place
to start and complete transactions, and issues like
#289 cannot happen
again in the future.

Previously, our only Rails instrumentation was positioned after the
DebugExceptions middleware, just in time to catch any errors before the
Rails error middleware showed a nice error/debug page. This wouldn't
show the complete picture in request duration.

The original Rails instrumentation middleware will remain to report
errors and Rails specific metadata. This cannot be part of the
EventHandler, without overloading it with responsibilities, and for
Rails error reporting we need to be right after the DebugExceptions
middleware before errors are no longer bubbled up in the stack.

Instead of the transaction ID being the request ID, set a new
`request_id` tag to not break existing behavior.

Part of #329
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants