September 9, 2010 at 9:34 pm
Comments posted to this topic are about the item Instrumentation
September 9, 2010 at 11:27 pm
Yes - I work in data warehousing/Business Intelligence and in every system we log each
dimension and fact table stored proc.
This entails tracking:
Batch, Job, datetime, object running, step in object (txt), rows added/updated, time to complete.
This allows us to:
a) Monitor performance and analyze performance issues.
b) Track any record back to its source (each record has a jobid field)
c) Trace errors to 'last successful' procedure
September 10, 2010 at 1:23 am
In our system on the DB level we only monitor few stored procedures that are crucial for our business. Ex. one of the sp always has to be executed in less then 30 seconds so when the execution time reaches near 25 seconds we know it is time to clean the database.
For monitoring other parts of the system we created "control center". It is basically application which listens to messages from other parts of the system an logs them.
Mandatory massages for every app are process start and end. That way we monitor overall execution time of applications.
September 10, 2010 at 2:17 am
In a lot of apps I did and look after (and not just in SQL code and not just in SQL Server), I create this 'general purpose' logging table for whatever I want to log. All logging is always done in such a way that it can easily be turned off (or back on again). In some cases, this information has been a life saver.
CREATE TABLE [dbo].[trx_eventlog](
[eventid] [int] IDENTITY(1,1) NOT NULL,
[process_name] [varchar](50) NULL,
[computer_name] [varchar](50) NULL,
[network_user] [varchar](50) NULL,
[app_user] [varchar](50) NULL,
[time_started] [datetime] NULL,
[time_ended] [datetime] NULL,
[elapsed_minutes] [decimal](10, 2) NULL,
[event_info1] [varchar](1000) NULL,
[event_info2] [varchar](1000) NULL,
[event_info3] [varchar](1000) NULL
) ON [PRIMARY]
September 10, 2010 at 2:33 am
As a freelance developer (Solutions Architect etc) I always recommend it is implemented, however, even before unit tests proper logging/diagnostics/monitoring (including performance measuring) is the first thing to go into the "we'll do it later" category i.e. never.
It is funny how many times the same person who insist it is not crucial and MUST not be done to maintain a satisfactory rate of progress then later on states that we should be able to see into the logs to diagnose issue X in a timely manner.
As usual pure Muppetry in our industry.
Thank goodness for TDD as at least unit testing is accepted as essential nowadays. CI is an indispensable technique. Now we need to extend it to consider performance testing is included alongside unit testing.
Gaz
-- Stop your grinnin' and drop your linen...they're everywhere!!!
September 10, 2010 at 2:40 am
We log duration and rowcount of virtually every sql statement within a stored proc. This allows to see exactly how long each bit takes, and also where the stored procedure is up to whilst it's running.
If you have a problem, you can track back through the log and recreate what happened whilst the procedure was running. Invaluable for investigating problems.
I did a similar thing in my previous job (Teradata).
We don't do as much analysis as we could/should do on the logged data. Maybe one day I'll get round to it...
September 10, 2010 at 2:46 am
Not SQL specific, but on all of our servers I long ago setup MRTG to monitor all of the standard metics (cpu, memory, disk space) plus a few specific ones relating to the individual servers, and then send that data back to a central server where they can be viewed on our intranet. Very simple solution, but it's really come in handy at times when you want to see if the current usage is normal, how it has changed over the last day / week / month / year, approximately when something may have changed (like a sudden drop in available disk space), and of course in terms of estimating when an upgrade may be required.
I keep meaning to do more with it, since essentially if you can use some variety of script (doesn't matter what it is) to return 1 or 2 numbers that you want to graph, you can feed it into MRTG.
September 10, 2010 at 6:11 am
Instrumentation into the TSQL code itself? Heck no. But we do use trace events to monitor our apps & databases & servers in development, qa and production, in order to underestand how fast they are running. We also will do performance testing for mission critical apps so we know how much load they can take and how they behave under load prior to letting them loose in production.
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt
Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning
September 10, 2010 at 6:53 am
Nothing fancy, but within our rather large .NET WinForms application, for some of the longer running processes we use a Stopwatch object and Debug.Print statements to show how long the processes run. We can run the app against development or even live data if users are complaining to see what's happening. Again, nothing fancy but it definitely helps us figure out where some time bottlenecks are.
September 10, 2010 at 8:02 am
We generally log start and end information on processes to a table, including what the process is (sproc, web service, etc) when it started, when it ended, how it ended (success, failure, error, return code), who kicked it off, error information if applicable, and free form other info (params passed, etc). With this we can easily see if the average times for a process have been creeping up over time, have been remaining steady, if a performance issue is actually a "one-off" due to unusual params or some other reason. It provides a good starting place for further analysis when needed.
September 10, 2010 at 9:32 am
On our BI system we have to deliver 95 reponses in 5 seconds or less. I wrote an app called KeepTicking which has its own performance database. I am getting daily summaries of the previous day's performance. For a more detailed analysis, we download raw measurements data into an Excel pivot table and take it from there.
September 10, 2010 at 10:31 am
YES, absolutely, in one of our Web-based 3-tier systems, we have a table that records the start and end time of EACH stored procedure that's called, the timestamp of the call, and the total elapsed time for the entire procedure (START and END records are written to the common table by each proc, at the start and end of each stored procedure). Some of the procedures record a few other columns that are specific to our application, such as how many records it is processing.
This helps us find weird bugs in other layers, like if certain stored procedures were always called twice in a row from the middle tier, how else would you know this?
And we know which procs seem to be fast, per call, but are called thousands of times in production, and which procs take a lot of time to run at each call. From that information, you can decide which procs are taking most of the time (either because they are slow, or because they are called way more often that you thought they would be). Obviously those procs are the ones to tune. Writing a few records to a table in order to tune the entire system is well worth the small amount of time it takes to write those records to the table.
For a few of the larger procs that were dealing with a lot of data, and were running slowly, we added some intermediate timing records to narrow down the part of the proc that was slow, and we focused on performance-tuning that part, looking for missing indexes, incorrectly written queries, etc.
It has been a very valuable technique. I think that all large production systems where you are worried about how long it takes the user's web page to refresh, should have this kind of "instrumentation" built in. And, you should build it in from the start.
September 10, 2010 at 10:55 am
I've been doing this for about 10 years; currently with SQL Server 2008/SSIS.
Most systems I built are basically ETL + Reporting, and are scheduled to run daily to load new data as it comes in. I consider it essential to log what happens, both to track problems and to check if performance is suffering. If it is, knowing that it took 90 minutes to do everything instead of 60 is useless UNLESS you know how long each step took. I add calls to a ToLog proc (which writes a record to a LOG table) both in the script tasks in my SSIS data load, and in each of the several SQL procs it uses. That way I can see where the error or slowdown happened. SSIS has built in logging of course, but I find putting what I want into a table lets me record lots that SSIS by itself does not, and also makes it easy to report on the status.
Here's my LOG table definition - obviously YMMV
CREATE TABLE [dbo].[LOG](
[ID] [int] IDENTITY(1,1) NOT NULL,
[EventTime] [datetime] NULL,
[RunStartTime] [datetime] NULL,
[Level] [tinyint] NULL,
[Status] AS (case [Level] when (0) then 'Debug' when (1) then 'Info' when (2) then 'NewData' when (4) then '#WARNING' when (6) then '##ERROR' when (8) then '###FATAL' else CONVERT([nvarchar],[Level],0) end),
[Client_Id] [nchar](2) NULL,
[Task] [nvarchar](50) NULL,
[Message] [nvarchar](500) NULL,
[TimeFromStart] AS (CONVERT([time],[EventTime]-[RunStartTime],(0))),
CONSTRAINT [PK_LOG] PRIMARY KEY CLUSTERED
([ID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY];
Setting the Level means that I can easily (by auto email) report just success and/or errors to my customer, while still having much more detail at Debug level for my own use when needed.
September 10, 2010 at 11:55 am
Does anyone know of a good method to instrument tsql code. Google searches don't provide any good primers. I know of methods to instrument pl/sql and Hotsos ILO. Curious if there is something similar for SQL Server.
Russ
September 10, 2010 at 12:52 pm
russ960 (9/10/2010)
Does anyone know of a good method to instrument tsql code. Google searches don't provide any good primers. I know of methods to instrument pl/sql and Hotsos ILO. Curious if there is something similar for SQL Server.
The simplest way is to measure wall clock time (which is what users care about).
Start of proc:
Declare @StartTime DateTime
Set @StartTime = GetDate()
End of proc:
Insert Into TimingTable (ProcName, StartTime, Seconds, <other column names>)
Select Object_Name(@@ProcId), @StartTime,
Cast(86400.0*Cast(GetDate()-@StartTime As Decimal(14, 8)) As Decimal(8,2)),
<other data>
I have another column for intermediate elapsed time, but this is a very basic outline.
Viewing 15 posts - 1 through 15 (of 17 total)
You must be logged in to reply to this topic. Login to reply