0

I need to track failed remote procedure calls (RPC started/completed events).

  • exact procedure call statement with all in/out params
  • exception thrown by procedure

What I tried:

  • Its easy to track exact RPC started/completed event

  • Its easy to track errors using error_reported event

But, I cant find way how to track both in one place.

P.S. I cannot use output params to return error and track it using RPC completed event.

Juozas
  • 916
  • 10
  • 17

1 Answers1

2

If you add the TRACK_CAUSALITY option on the event session, it will add an action that allows you to correlate events that were generated by the same thing happening. Here's a sample event session I just made:

CREATE EVENT SESSION [sp errors] ON SERVER 
ADD EVENT sqlserver.error_reported,
ADD EVENT sqlserver.module_end(SET collect_statement=(1)),
ADD EVENT sqlserver.rpc_completed(SET collect_statement=(1))
ADD TARGET package0.ring_buffer
WITH (
    MAX_MEMORY=4096 KB,
    EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
    MAX_DISPATCH_LATENCY=30 SECONDS,
    MAX_EVENT_SIZE=0 KB,
    MEMORY_PARTITION_MODE=NONE,
    TRACK_CAUSALITY=ON,
    STARTUP_STATE=OFF
)
GO

I then created a stored procedure with a divide-by-zero error and called it. Here's what I got in the ring buffer (truncated to the relevant events):

<event name="error_reported" package="sqlserver" timestamp="2018-01-26T15:44:58.652Z">
    <data name="error_number">
      <type name="int32" package="package0"></type>
      <value>8134</value>
    </data>
    <data name="severity">
      <type name="int32" package="package0"></type>
      <value>16</value>
    </data>
    <data name="state">
      <type name="int32" package="package0"></type>
      <value>1</value>
    </data>
    <data name="user_defined">
      <type name="boolean" package="package0"></type>
      <value>false</value>
    </data>
    <data name="category">
      <type name="error_category" package="sqlserver"></type>
      <value>2</value>
      <text><![CDATA[SERVER]]></text>
    </data>
    <data name="destination">
      <type name="error_destination" package="sqlserver"></type>
      <value>0x00000002</value>
      <text><![CDATA[USER]]></text>
    </data>
    <data name="is_intercepted">
      <type name="boolean" package="package0"></type>
      <value>false</value>
    </data>
    <data name="message">
      <type name="unicode_string" package="package0"></type>
      <value><![CDATA[Divide by zero error encountered.]]></value>
    </data>
    <action name="attach_activity_id_xfer" package="package0">
      <type name="activity_id_xfer" package="package0"></type>
      <value>110CE72A-3B30-4086-BD7E-9E2E3734C803-0</value>
    </action>
    <action name="attach_activity_id" package="package0">
      <type name="activity_id" package="package0"></type>
      <value>A3050AC2-36EF-493F-9E37-BF7884EF55DC-1</value>
    </action>
  </event>
  <event name="module_end" package="sqlserver" timestamp="2018-01-26T15:44:58.657Z">
    <data name="source_database_id">
      <type name="uint32" package="package0"></type>
      <value>2</value>
    </data>
    <data name="object_id">
      <type name="int32" package="package0"></type>
      <value>-1530582118</value>
    </data>
    <data name="duration">
      <type name="uint64" package="package0"></type>
      <value>6025</value>
    </data>
    <data name="row_count">
      <type name="uint64" package="package0"></type>
      <value>0</value>
    </data>
    <data name="line_number">
      <type name="int32" package="package0"></type>
      <value>1</value>
    </data>
    <data name="offset">
      <type name="int32" package="package0"></type>
      <value>0</value>
    </data>
    <data name="offset_end">
      <type name="int32" package="package0"></type>
      <value>-1</value>
    </data>
    <data name="object_type">
      <type name="ansi_string" package="package0"></type>
      <value><![CDATA[P ]]></value>
    </data>
    <data name="object_name">
      <type name="unicode_string" package="package0"></type>
      <value><![CDATA[#foo____________________________________________________________________________________________________________________00005935]]></value>
    </data>
    <data name="statement">
      <type name="xml" package="package0"></type>
      <value>exec #foo</value>
    </data>
    <action name="attach_activity_id" package="package0">
      <type name="activity_id" package="package0"></type>
      <value>A3050AC2-36EF-493F-9E37-BF7884EF55DC-2</value>
    </action>
  </event>

Each of those events has an attach_activity_id node with mostly the same value. The value is the same if you cast it as a uniqueidentifier, though!

Godspeed. You're going to need it for the XML shredding that's in your future. :)

Ben Thul
  • 31,080
  • 4
  • 45
  • 68
  • Thanks! As I see, need to log both events separately, and then join them using uid and custom query, as you mentioned. No simple way, such as using one event. But, not the worst situation :) – Juozas Jan 26 '18 at 20:57
  • Yeah. The events in Extended Events are kept thin by design. But you're a couple of joins away from getting what you need. – Ben Thul Jan 26 '18 at 21:08