Movatterモバイル変換


[0]ホーム

URL:


Skip to main content
More atrubyonrails.org:

Active Support Instrumentation

Active Support is a part of core Rails that provides Ruby language extensions, utilities, and other things. One of the things it includes is an instrumentation API that can be used inside an application to measure certain actions that occur within Ruby code, such as those inside a Rails application or the framework itself. It is not limited to Rails, however. It can be used independently in other Ruby scripts if desired.

In this guide, you will learn how to use the Active Support's instrumentation API to measure events inside of Rails and other Ruby code.

After reading this guide, you will know:

  • What instrumentation can provide.
  • How to add a subscriber to a hook.
  • The hooks inside the Rails framework for instrumentation.
  • How to build a custom instrumentation implementation.

1. Introduction to Instrumentation

The instrumentation API provided by Active Support allows developers to provide hooks which other developers may hook into. There areseveral of these within the Rails framework. With this API, developers can choose to be notified when certain events occur inside their application or another piece of Ruby code.

For example, there isa hook provided within Active Record that is called every time Active Record uses an SQL query on a database. This hook could besubscribed to, and used to track the number of queries during a certain action. There'sanother hook around the processing of an action of a controller. This could be used, for instance, to track how long a specific action has taken.

You are even able tocreate your own events inside your application which you can later subscribe to.

2. Subscribing to an Event

UseActiveSupport::Notifications.subscribe with a block to listen to any notification. Depending on the amount ofarguments the block takes, you will receive different data.

The first way to subscribe to an event is to use a block with a single argument. The argument will be an instance ofActiveSupport::Notifications::Event.

ActiveSupport::Notifications.subscribe"process_action.action_controller"do|event|event.name# => "process_action.action_controller"event.duration# => 10 (in milliseconds)event.allocations# => 1826event.payload# => {:extra=>information}Rails.logger.info"#{event} Received!"end

If you don't need all the data recorded by an Event object, you can also specify ablock that takes the following five arguments:

  • Name of the event
  • Time when it started
  • Time when it finished
  • A unique ID for the instrumenter that fired the event
  • The payload for the event
ActiveSupport::Notifications.subscribe"process_action.action_controller"do|name,started,finished,unique_id,payload|# your own custom stuffRails.logger.info"#{name} Received! (started:#{started}, finished:#{finished})"# process_action.action_controller Received! (started: 2019-05-05 13:43:57 -0800, finished: 2019-05-05 13:43:58 -0800)end

If you are concerned about the accuracy ofstarted andfinished to compute a precise elapsed time, then useActiveSupport::Notifications.monotonic_subscribe. The given block would receive the same arguments as above, but thestarted andfinished will have values with an accurate monotonic time instead of wall-clock time.

ActiveSupport::Notifications.monotonic_subscribe"process_action.action_controller"do|name,started,finished,unique_id,payload|# your own custom stuffduration=finished-started# 1560979.429234 - 1560978.425334Rails.logger.info"#{name} Received! (duration:#{duration})"# process_action.action_controller Received! (duration: 1.0039)end

You may also subscribe to events matching a regular expression. This enables you to subscribe tomultiple events at once. Here's how to subscribe to everything fromActionController:

ActiveSupport::Notifications.subscribe(/action_controller/)do|event|# inspect all ActionController eventsend

3. Rails Framework Hooks

Within the Ruby on Rails framework, there are a number of hooks provided for common events. These events and their payloads are detailed below.

3.1. Action Cable

3.1.1.perform_action.action_cable

KeyValue
:channel_className of the channel class
:actionThe action
:dataA hash of data

3.1.2.transmit.action_cable

KeyValue
:channel_className of the channel class
:dataA hash of data
:viaVia

3.1.3.transmit_subscription_confirmation.action_cable

KeyValue
:channel_className of the channel class

3.1.4.transmit_subscription_rejection.action_cable

KeyValue
:channel_className of the channel class

3.1.5.broadcast.action_cable

KeyValue
:broadcastingA named broadcasting
:messageA hash of message
:coderThe coder

3.2. Action Controller

3.2.1.start_processing.action_controller

KeyValue
:controllerThe controller name
:actionThe action
:requestTheActionDispatch::Request object
:paramsHash of request parameters without any filtered parameter
:headersRequest headers
:formathtml/js/json/xml etc
:methodHTTP request verb
:pathRequest path
{controller:"PostsController",action:"new",params:{"action"=>"new","controller"=>"posts"},headers:#<ActionDispatch::Http::Headers:0x0055a67a519b88>,format: :html,method:"GET",path:"/posts/new"}

3.2.2.process_action.action_controller

KeyValue
:controllerThe controller name
:actionThe action
:paramsHash of request parameters without any filtered parameter
:headersRequest headers
:formathtml/js/json/xml etc
:methodHTTP request verb
:pathRequest path
:requestTheActionDispatch::Request object
:responseTheActionDispatch::Response object
:statusHTTP status code
:view_runtimeAmount spent in view in ms
:db_runtimeAmount spent executing database queries in ms
{controller:"PostsController",action:"index",params:{"action"=>"index","controller"=>"posts"},headers:#<ActionDispatch::Http::Headers:0x0055a67a519b88>,format: :html,method:"GET",path:"/posts",request:#<ActionDispatch::Request:0x00007ff1cb9bd7b8>,response:#<ActionDispatch::Response:0x00007f8521841ec8>,status:200,view_runtime:46.848,db_runtime:0.157}

3.2.3.send_file.action_controller

KeyValue
:pathComplete path to the file

Additional keys may be added by the caller.

3.2.4.send_data.action_controller

ActionController does not add any specific information to the payload. All options are passed through to the payload.

3.2.5.redirect_to.action_controller

KeyValue
:statusHTTP response code
:locationURL to redirect to
:requestTheActionDispatch::Request object
{status:302,location:"http://localhost:3000/posts/new",request:<ActionDispatch::Request:0x00007ff1cb9bd7b8>}

3.2.6.halted_callback.action_controller

KeyValue
:filterFilter that halted the action
{filter:":halting_filter"}

3.2.7.unpermitted_parameters.action_controller

KeyValue
:keysThe unpermitted keys
:contextHash with the following keys::controller,:action,:params,:request

3.2.8.send_stream.action_controller

KeyValue
:filenameThe filename
:typeHTTP content type
:dispositionHTTP content disposition
{filename:"subscribers.csv",type:"text/csv",disposition:"attachment"}

3.2.9.rate_limit.action_controller

KeyValue
:requestTheActionDispatch::Request object
:countNumber of requests made
:toMaximum number of requests allowed
:withinTime window for the rate limit
:byIdentifier for the rate limit (e.g. IP)
:nameName of the rate limit
:scopeScope of the rate limit
:cache_keyThe cache key used for storing the rate limit

3.3. Action Controller: Caching

3.3.1.write_fragment.action_controller

KeyValue
:keyThe complete key
{key:'posts/1-dashboard-view'}

3.3.2.read_fragment.action_controller

KeyValue
:keyThe complete key
{key:'posts/1-dashboard-view'}

3.3.3.expire_fragment.action_controller

KeyValue
:keyThe complete key
{key:'posts/1-dashboard-view'}

3.3.4.exist_fragment?.action_controller

KeyValue
:keyThe complete key
{key:'posts/1-dashboard-view'}

3.4. Action Dispatch

3.4.1.process_middleware.action_dispatch

KeyValue
:middlewareName of the middleware

3.4.2.redirect.action_dispatch

KeyValue
:statusHTTP response code
:locationURL to redirect to
:requestTheActionDispatch::Request object
:source_locationSource location of redirect in routes

3.4.3.request.action_dispatch

KeyValue
:requestTheActionDispatch::Request object

3.5. Action Mailbox

3.5.1.process.action_mailbox

KeyValue
:mailboxInstance of the Mailbox class inheriting fromActionMailbox::Base
:inbound_emailHash with data about the inbound email being processed
{mailbox:#<RepliesMailbox:0x00007f9f7a8388>,inbound_email:{id:1,message_id:"0CB459E0-0336-41DA-BC88-E6E28C697DDB@37signals.com",status:"processing"}}

3.6. Action Mailer

3.6.1.deliver.action_mailer

KeyValue
:mailerName of the mailer class
:message_idID of the message, generated by the Mail gem
:subjectSubject of the mail
:toTo address(es) of the mail
:fromFrom address of the mail
:bccBCC addresses of the mail
:ccCC addresses of the mail
:dateDate of the mail
:mailThe encoded form of the mail
:perform_deliveriesWhether delivery of this message is performed or not
{mailer:"Notification",message_id:"4f5b5491f1774_181b23fc3d4434d38138e5@mba.local.mail",subject:"Rails Guides",to:["users@rails.com","dhh@rails.com"],from:["me@rails.com"],date:Sat,10Mar201214:18:09+0100,mail:"...",# omitted for brevityperform_deliveries:true}

3.6.2.process.action_mailer

KeyValue
:mailerName of the mailer class
:actionThe action
:argsThe arguments
{mailer:"Notification",action:"welcome_email",args:[]}

3.7. Action View

3.7.1.render_template.action_view

KeyValue
:identifierFull path to template
:layoutApplicable layout
:localsLocal variables passed to template
{identifier:"/Users/adam/projects/notifications/app/views/posts/index.html.erb",layout:"layouts/application",locals:{foo:"bar"}}

3.7.2.render_partial.action_view

KeyValue
:identifierFull path to template
:localsLocal variables passed to template
{identifier:"/Users/adam/projects/notifications/app/views/posts/_form.html.erb",locals:{foo:"bar"}}

3.7.3.render_collection.action_view

KeyValue
:identifierFull path to template
:countSize of collection
:cache_hitsNumber of partials fetched from cache

The:cache_hits key is only included if the collection is rendered withcached: true.

{identifier:"/Users/adam/projects/notifications/app/views/posts/_post.html.erb",count:3,cache_hits:0}

3.7.4.render_layout.action_view

KeyValue
:identifierFull path to template
{identifier:"/Users/adam/projects/notifications/app/views/layouts/application.html.erb"}

3.8. Active Job

3.8.1.enqueue_at.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object

3.8.2.enqueue.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object

3.8.3.enqueue_retry.active_job

KeyValue
:jobJob object
:adapterQueueAdapter object processing the job
:errorThe error that caused the retry
:waitThe delay of the retry

3.8.4.enqueue_all.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobsAn array of Job objects

3.8.5.perform_start.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object

3.8.6.perform.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object
:db_runtimeAmount spent executing database queries in ms

3.8.7.retry_stopped.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object
:errorThe error that caused the retry

3.8.8.discard.active_job

KeyValue
:adapterQueueAdapter object processing the job
:jobJob object
:errorThe error that caused the discard

3.9. Active Record

3.9.1.sql.active_record

KeyValue
:sqlSQL statement
:nameName of the operation
:bindsBind parameters
:type_casted_bindsTypecasted bind parameters
:asynctrue if query is loaded asynchronously
:allow_retrytrue if the query can be automatically retried
:connectionConnection object
:transactionCurrent transaction, if any
:affected_rowsNumber of rows affected by the query
:row_countNumber of rows returned by the query
:cachedtrue is added when result comes from the query cache
:statement_nameSQL Statement name (Postgres only)

Adapters may add their own data as well.

{sql:"SELECT\"posts\".* FROM\"posts\" ",name:"Post Load",binds:[<ActiveModel::Attribute::WithCastValue:0x00007fe19d15dc00>],type_casted_binds:[11],async:false,allow_retry:true,connection:<ActiveRecord::ConnectionAdapters::SQLite3Adapter:0x00007f9f7a838850>,transaction:<ActiveRecord::ConnectionAdapters::RealTransaction:0x0000000121b5d3e0>affected_rows:0row_count:5,statement_name:nil,}

If the query is not executed in the context of a transaction,:transaction isnil.

3.9.2.strict_loading_violation.active_record

This event is only emitted whenconfig.active_record.action_on_strict_loading_violation is set to:log.

KeyValue
:ownerModel withstrict_loading enabled
:reflectionReflection of the association that tried to load

3.9.3.instantiation.active_record

KeyValue
:record_countNumber of records that instantiated
:class_nameRecord's class
{record_count:1,class_name:"User"}

3.9.4.start_transaction.active_record

This event is emitted when a transaction has been started.

KeyValue
:transactionTransaction object
:connectionConnection object

Please, note that Active Record does not create the actual database transactionuntil needed:

ActiveRecord::Base.transactiondo# We are inside the block, but no event has been triggered yet.# The following line makes Active Record start the transaction.User.count# Event fired here.end

Remember that ordinary nested calls do not create new transactions:

ActiveRecord::Base.transactiondo|t1|User.count# Fires an event for t1.ActiveRecord::Base.transactiondo|t2|# The next line fires no event for t2, because the only# real database transaction in this example is t1.User.first.touchendend

However, ifrequires_new: true is passed, you get an event for the nestedtransaction too. This might be a savepoint under the hood:

ActiveRecord::Base.transactiondo|t1|User.count# Fires an event for t1.ActiveRecord::Base.transaction(requires_new:true)do|t2|User.first.touch# Fires an event for t2.endend

3.9.5.transaction.active_record

This event is emitted when a database transaction finishes. The state of thetransaction can be found in the:outcome key.

KeyValue
:transactionTransaction object
:outcome:commit,:rollback,:restart, or:incomplete
:connectionConnection object

In practice, you cannot do much with the transaction object, but it may still behelpful for tracing database activity. For example, by trackingtransaction.uuid.

3.9.6.deprecated_association.active_record

This event is emitted when a deprecated association is accessed, and theconfigured deprecated associations mode is:notify.

KeyValue
:reflectionThe reflection of the association
:messageA descriptive message about the access
:locationThe application-level location of the access
:backtraceOnly present if the option:backtrace is true

The:location is aThread::Backtrace::Location object, and:backtrace, ifpresent, is an array ofThread::Backtrace::Location objects. These arecomputed using the Active Record backtrace cleaner. In Rails applications, thisis the same asRails.backtrace_cleaner.

3.10. Active Storage

3.10.1.preview.active_storage

KeyValue
:keySecure token

3.10.2.transform.active_storage

3.10.3.analyze.active_storage

KeyValue
:analyzerName of analyzer e.g., ffprobe

3.11. Active Storage: Storage Service

3.11.1.service_upload.active_storage

KeyValue
:keySecure token
:serviceName of the service
:checksumChecksum to ensure integrity

3.11.2.service_streaming_download.active_storage

KeyValue
:keySecure token
:serviceName of the service

3.11.3.service_download_chunk.active_storage

KeyValue
:keySecure token
:serviceName of the service
:rangeByte range attempted to be read

3.11.4.service_download.active_storage

KeyValue
:keySecure token
:serviceName of the service

3.11.5.service_delete.active_storage

KeyValue
:keySecure token
:serviceName of the service

3.11.6.service_delete_prefixed.active_storage

KeyValue
:prefixKey prefix
:serviceName of the service

3.11.7.service_exist.active_storage

KeyValue
:keySecure token
:serviceName of the service
:existFile or blob exists or not

3.11.8.service_url.active_storage

KeyValue
:keySecure token
:serviceName of the service
:urlGenerated URL

3.11.9.service_update_metadata.active_storage

This event is only emitted when using the Google Cloud Storage service.

KeyValue
:keySecure token
:serviceName of the service
:content_typeHTTPContent-Type field
:dispositionHTTPContent-Disposition field

3.12. Active Support: Caching

3.12.1.cache_read.active_support

KeyValue
:keyKey used in the store
:storeName of the store class
:hitIf this read is a hit
:super_operation:fetch if a read is done withfetch

3.12.2.cache_read_multi.active_support

KeyValue
:keyKeys used in the store
:storeName of the store class
:hitsKeys of cache hits
:super_operation:fetch_multi if a read is done withfetch_multi

3.12.3.cache_generate.active_support

This event is only emitted whenfetch is called with a block.

KeyValue
:keyKey used in the store
:storeName of the store class

Options passed tofetch will be merged with the payload when writing to the store.

{key:"name-of-complicated-computation",store:"ActiveSupport::Cache::MemCacheStore"}

3.12.4.cache_fetch_hit.active_support

This event is only emitted whenfetch is called with a block.

KeyValue
:keyKey used in the store
:storeName of the store class

Options passed tofetch will be merged with the payload.

{key:"name-of-complicated-computation",store:"ActiveSupport::Cache::MemCacheStore"}

3.12.5.cache_write.active_support

KeyValue
:keyKey used in the store
:storeName of the store class

Cache stores may add their own data as well.

{key:"name-of-complicated-computation",store:"ActiveSupport::Cache::MemCacheStore"}

3.12.6.cache_write_multi.active_support

KeyValue
:keyKeys and values written to the store
:storeName of the store class

3.12.7.cache_increment.active_support

KeyValue
:keyKey used in the store
:storeName of the store class
:amountIncrement amount
{key:"bottles-of-beer",store:"ActiveSupport::Cache::RedisCacheStore",amount:99}

3.12.8.cache_decrement.active_support

KeyValue
:keyKey used in the store
:storeName of the store class
:amountDecrement amount
{key:"bottles-of-beer",store:"ActiveSupport::Cache::RedisCacheStore",amount:1}

3.12.9.cache_delete.active_support

KeyValue
:keyKey used in the store
:storeName of the store class
{key:"name-of-complicated-computation",store:"ActiveSupport::Cache::MemCacheStore"}

3.12.10.cache_delete_multi.active_support

KeyValue
:keyKeys used in the store
:storeName of the store class

3.12.11.cache_delete_matched.active_support

This event is only emitted when usingRedisCacheStore,FileStore, orMemoryStore.

KeyValue
:keyKey pattern used
:storeName of the store class
{key:"posts/*",store:"ActiveSupport::Cache::RedisCacheStore"}

3.12.12.cache_cleanup.active_support

This event is only emitted when usingMemoryStore.

KeyValue
:storeName of the store class
:sizeNumber of entries in the cache before cleanup
{store:"ActiveSupport::Cache::MemoryStore",size:9001}

3.12.13.cache_prune.active_support

This event is only emitted when usingMemoryStore.

KeyValue
:storeName of the store class
:keyTarget size (in bytes) for the cache
:fromSize (in bytes) of the cache before prune
{store:"ActiveSupport::Cache::MemoryStore",key:5000,from:9001}

3.12.14.cache_exist?.active_support

KeyValue
:keyKey used in the store
:storeName of the store class
{key:"name-of-complicated-computation",store:"ActiveSupport::Cache::MemCacheStore"}

3.13. Active Support: Messages

3.13.1.message_serializer_fallback.active_support

KeyValue
:serializerPrimary (intended) serializer
:fallbackFallback (actual) serializer
:serializedSerialized string
:deserializedDeserialized value
{serializer: :json_allow_marshal,fallback: :marshal,serialized:"\x04\b{\x06I\"\nHello\x06:\x06ETI\"\nWorld\x06;\x00T",deserialized:{"Hello"=>"World"},}

3.14. Rails

3.14.1.deprecation.rails

KeyValue
:messageThe deprecation warning
:callstackWhere the deprecation came from
:gem_nameName of the gem reporting the deprecation
:deprecation_horizonVersion where the deprecated behavior will be removed

3.15. Railties

3.15.1.load_config_initializer.railties

KeyValue
:initializerPath of loaded initializer inconfig/initializers

4. Exceptions

If an exception happens during any instrumentation, the payload will includeinformation about it.

KeyValue
:exceptionAn array of two elements. Exception class name and the message
:exception_objectThe exception object

5. Creating Custom Events

Adding your own events is easy as well. Active Support will take care ofall the heavy lifting for you. Simply callActiveSupport::Notifications.instrument with aname,payload, and a block.The notification will be sent after the block returns. Active Support will generate the start and end times,and add the instrumenter's unique ID. All data passed into theinstrument call will makeit into the payload.

Here's an example:

ActiveSupport::Notifications.instrument"my.custom.event",this: :datado# do your custom stuff hereend

Now you can listen to this event with:

ActiveSupport::Notifications.subscribe"my.custom.event"do|name,started,finished,unique_id,data|putsdata.inspect# {:this=>:data}end

You may also callinstrument without passing a block. This lets you leverage theinstrumentation infrastructure for other messaging uses.

ActiveSupport::Notifications.instrument"my.custom.event",this: :dataActiveSupport::Notifications.subscribe"my.custom.event"do|name,started,finished,unique_id,data|putsdata.inspect# {:this=>:data}end

You should follow Rails conventions when defining your own events. The format is:event.library.If your application is sending Tweets, you should create an event namedtweet.twitter.



Back to top
[8]ページ先頭

©2009-2025 Movatter.jp