Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

I am using event notifications to capture data and log file autogrowth events for all databases on my servers. I'm using the data to for analysis of database storage configuration.

In looking at the data I've noticed that the average duration for transaction log growth is well above anything I would expect which leads me to think that I'm either misinterpreting the data or overlooking something related to how transaction log autogrowth works.

This is an example of a log file growth event that was captured today:

<EVENT_INSTANCE>
  <EventType>LOG_FILE_AUTO_GROW</EventType>
  <PostTime>2013-08-29T11:14:26.447</PostTime>
  <SPID>97</SPID>
  <DatabaseID>32</DatabaseID>
  <NTDomainName />
  <HostName>[cleansed]</HostName>
  <ClientProcessID>4884</ClientProcessID>
  <ApplicationName>.Net SqlClient Data Provider</ApplicationName>
  <LoginName>[cleansed]</LoginName>
  <Duration>4173000</Duration>
  <StartTime>2013-08-29T11:14:22.263</StartTime>
  <EndTime>2013-08-29T11:14:26.437</EndTime>
  <IntegerData>64000</IntegerData>
  <ServerName>[cleansed]</ServerName>
  <DatabaseName>MyDB</DatabaseName>
  <FileName>MyDB_log</FileName>
  <LoginSid>[cleansed]</LoginSid>
  <EventSequence>14637017</EventSequence>
  <IsSystem />
  <SessionLoginName>[cleansed]</SessionLoginName>
</EVENT_INSTANCE>

Since duration is reported in miliseconds I'm reading this as it taking 69.54 minutes to grow the file. Autogrowth for this log file is set to 512MB (limited to 2TB)

SELECT
    growth AS GrowthPages,
    growth*8/1000 AS GrowthMB,
    max_size,
    is_percent_growth
FROM MyDB.sys.database_files
WHERE type=1

GrowthPages GrowthMB        max_size        is_percent_growth
64000       512             268435456       0

All of the databases log to the same volume which is connected to a SAN via fiberchannel. (I'd have to get with our SAN admin for more details on the storage config if needed).

The instance is SQL 2012 Enterprise, server is Windows 2008 R2 Enterprise.

Why would it take over an hour to grow the log by 512MB? We're not noticing a delay in operations on any of these databases (unless we're just overlooking it). There are a handful of other databases with similar duration; their autogrowth settings are the same. Other databases with smaller autogrowth settings have proportionally smaller durations.

share|improve this question

1 Answer 1

up vote 4 down vote accepted

You're looking at SQL Trace. Extended Events records duration in microseconds (though some data is reported in milliseconds, duration isn't affected). You can see that the event took less than 5 seconds:

<StartTime>2013-08-29T11:14:22.263</StartTime>
<EndTime>2013-08-29T11:14:26.437</EndTime>

And also just to confirm (though it's off a bit due to millisecond rounding in the datetime data type):

SELECT DATEDIFF(MICROSECOND,'2013-08-29T11:14:22.263','2013-08-29T11:14:26.437');

----------
4174000
share|improve this answer
    
Great, that's what I was hoping it was. I could only find that reference where it said ms. I completely had the blinders on and didn't even think to validate against the start/end time fields. I still can't find a reference for XE to confirm, but this proof vs. the start/endtime fields works for me. Thanks, Aaron! –  squillman Aug 29 '13 at 18:59
    
@squillman yeah, I couldn't find any documentation on it, only empirical evidence. –  Aaron Bertrand Aug 29 '13 at 19:07
4  
Upvoted that connect item, also. –  squillman Aug 29 '13 at 19:11
2  
@squillman me, too! This stuff should be documented. And if it is already documented, it should be much easier to find. And if it is inconsistent between different events, it needs to be fixed. Maybe that's why they're hesitant to document it. In my experience Extended Events is a fantastic and powerful feature with a lot of bumbling in the implementation. –  Aaron Bertrand Aug 29 '13 at 19:13

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.