October 26, 2011 at 1:54 pm
In SSIS when you run a package in the designer, you can look at the tab Execution Results and see a list of the tasks your package has performed. At the bottom of all the steps each task takes is a line that reads (for example)
Finished, 2:54:24 PM, Elapsed time: 00:00:02.321
Is there any way to get that elapsed time programmatically? I'd like to capture that number and insert it into a table. If the number is accessable, I could put an Execute SQL Task in the Event Handler and store the information so I can see how long each task takes, even once the SSIS package is compiled and is running as a job.
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
October 27, 2011 at 8:28 am
Look at LoggingMode on the properties tab of the package.
Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
October 27, 2011 at 8:56 am
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
October 27, 2011 at 9:29 am
Stefan Krzywicki (10/27/2011)
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
starttime and endtime are recorded in the table for whatever events you choose to log. We've chosen OnPostExecute as a default marker for a successful task, so for most of our tasks, the elapsed time of the current task is the difference between the end time of the previous task.OnPostExecute and the end time of the current task.OnPostExecute.
You'll find the table in the Systems Tables folder of the db of the chosen connection - it's sysssislog.
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
October 27, 2011 at 9:43 am
ChrisM@Work (10/27/2011)
Stefan Krzywicki (10/27/2011)
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
starttime and endtime are recorded in the table for whatever events you choose to log. We've chosen OnPostExecute as a default marker for a successful task, so for most of our tasks, the elapsed time of the current task is the difference between the end time of the previous task.OnPostExecute and the end time of the current task.OnPostExecute.
You'll find the table in the Systems Tables folder of the db of the chosen connection - it's sysssislog.
Thanks, that'll give me some good things to look at.
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
October 31, 2011 at 1:05 pm
ChrisM@Work (10/27/2011)
Stefan Krzywicki (10/27/2011)
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
starttime and endtime are recorded in the table for whatever events you choose to log. We've chosen OnPostExecute as a default marker for a successful task, so for most of our tasks, the elapsed time of the current task is the difference between the end time of the previous task.OnPostExecute and the end time of the current task.OnPostExecute.
You'll find the table in the Systems Tables folder of the db of the chosen connection - it's sysssislog.
I've had a chance to try this out and it seems like it'll work alright if I only care about longer running tasks. The Start/Stop times don't include milliseconds. Is there any way to enable more accurate time capture?
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
November 1, 2011 at 3:08 am
Stefan Krzywicki (10/31/2011)
ChrisM@Work (10/27/2011)
Stefan Krzywicki (10/27/2011)
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
starttime and endtime are recorded in the table for whatever events you choose to log. We've chosen OnPostExecute as a default marker for a successful task, so for most of our tasks, the elapsed time of the current task is the difference between the end time of the previous task.OnPostExecute and the end time of the current task.OnPostExecute.
You'll find the table in the Systems Tables folder of the db of the chosen connection - it's sysssislog.
I've had a chance to try this out and it seems like it'll work alright if I only care about longer running tasks. The Start/Stop times don't include milliseconds. Is there any way to enable more accurate time capture?
I've implemented something here which might be useful for you too. At the start and end of each package I've included a task which writes a row to a table with the date and time and functional id of the package. Milestone tasks within packages too. This is designed to be easy to report from, so with a single query I can see at a glance which jobs have completed and which are still running or have stalled. When I want more detail, I revert to the native logging table.
It's handy for us because of the structure of typical unit of work - a simple csv file is subjected to various suppressions and other processes to arrive at a printer-ready set of mailing output files with stats and history. This takes 4 SSIS packages, a disconnected application and a disconnected eyeball check. Representing it as left to right progress along the columns of a row is straightforward from our custom logger.
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
November 1, 2011 at 6:51 am
ChrisM@Work (11/1/2011)
Stefan Krzywicki (10/31/2011)
ChrisM@Work (10/27/2011)
Stefan Krzywicki (10/27/2011)
ChrisM@Work (10/27/2011)
Look at LoggingMode on the properties tab of the package.Right-click on the white space of a package, select Logging, select what you want to log.
During dev, log just about everything. Careful because the table grows really fast.
Hmm. I did that, but didn't see elapsed time in the results. I'll try again.
starttime and endtime are recorded in the table for whatever events you choose to log. We've chosen OnPostExecute as a default marker for a successful task, so for most of our tasks, the elapsed time of the current task is the difference between the end time of the previous task.OnPostExecute and the end time of the current task.OnPostExecute.
You'll find the table in the Systems Tables folder of the db of the chosen connection - it's sysssislog.
I've had a chance to try this out and it seems like it'll work alright if I only care about longer running tasks. The Start/Stop times don't include milliseconds. Is there any way to enable more accurate time capture?
I've implemented something here which might be useful for you too. At the start and end of each package I've included a task which writes a row to a table with the date and time and functional id of the package. Milestone tasks within packages too. This is designed to be easy to report from, so with a single query I can see at a glance which jobs have completed and which are still running or have stalled. When I want more detail, I revert to the native logging table.
It's handy for us because of the structure of typical unit of work - a simple csv file is subjected to various suppressions and other processes to arrive at a printer-ready set of mailing output files with stats and history. This takes 4 SSIS packages, a disconnected application and a disconnected eyeball check. Representing it as left to right progress along the columns of a row is straightforward from our custom logger.
Thanks, you've given me some ideas.
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
November 1, 2011 at 6:53 am
You're welcome Stefan. I'd be interested to hear what you come up with.
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
November 1, 2011 at 7:46 am
ChrisM@Work (11/1/2011)
You're welcome Stefan. I'd be interested to hear what you come up with.
Right now I'm probably going to just implement the solution you gave me earlier. The logging into a table works very nicely for everything over a second. I was looking into milliseconds because I have 2 tasks that take well under a second in the package I'm working on right now and I wanted to see a real number for them. After thinking about it a little longer, I realized that for my current purposes I don't need to see milliseconds in the logging. I'm going to log the PreExecute and the PostExecute and find the time difference between.
If I ever do need to see them, and I'm sure I will at some point, I will likely create my own table and log to it using Execute SQL Tasks in the Pre and Post Execute Event Handlers. I'd found some code on-line that used Script tasks and Execute SQL Tasks, but I don't think the Script task is actually needed. If I use GetDate in the Execute SQL, it should give me the time I need. The Script task just uses Now() which doesn't get me the milliseconds either.
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
November 1, 2011 at 7:49 am
And at least trying to figure all of this out has gotten me to explore Logging and Event Handlers. 🙂
--------------------------------------
When you encounter a problem, if the solution isn't readily evident go back to the start and check your assumptions.
--------------------------------------
It’s unpleasantly like being drunk.
What’s so unpleasant about being drunk?
You ask a glass of water. -- Douglas Adams
November 1, 2011 at 7:55 am
Stefan Krzywicki (11/1/2011)
ChrisM@Work (11/1/2011)
You're welcome Stefan. I'd be interested to hear what you come up with....If I use GetDate in the Execute SQL, it should give me the time I need...
That's what I've implemented here. In addition to package and task name, I also post through some some other useful bits and bobs, such as email group or address of interested parties - some of the stuff logged to the table is picked up by a job and sent out.
The email SSIS task is a different beast to database mail and occasionally fails with a server busy error. Database mail logs delivery pass/fail so mail can be resent.
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
Viewing 12 posts - 1 through 11 (of 11 total)
You must be logged in to reply to this topic. Login to reply