| View previous topic :: View next topic |
| Author |
Message |
RobertWright
Experienced
Joined: 13 Feb 2006
Posts: 131
|
 Posted: Wed Sep 19, 2012 1:50 am Post subject: Power Purge log review |
 |
|
When I last mentioned the amount of time that a power purge is taking you said I should look at the power purge log for answers. I had just over 200,000 headers in the trash so I started a power purge using both the check for orphaned data and optimize data settings at 9:53:35 AM. The process finished at 6:32:38 PM.
Can you take a look at the log below and let me know what I can know to speed up this process.
PowerPurge started: 9/18/2012 9:53:35 AM
9/18/2012 9:53:35 AM: Initializing new database session...
9/18/2012 9:53:35 AM: Gathering Workgroups...
9/18/2012 9:53:35 AM: Found 5 Workgroups...
9/18/2012 9:53:35 AM: Purging wgparts00...
9/18/2012 9:53:35 AM: Counting records in wgparts00...
9/18/2012 9:53:35 AM: 5415 records found...
9/18/2012 9:53:35 AM: Counting records to be purged in wgparts00...
9/18/2012 9:53:36 AM: 5415 records found...
9/18/2012 9:53:36 AM: Purging records for wgparts00 using TRUNCATE method...
9/18/2012 9:53:36 AM: Purge complete for wgparts00...
9/18/2012 9:53:36 AM: Purging wgparts01...
9/18/2012 9:53:36 AM: Counting records in wgparts01...
9/18/2012 9:53:36 AM: 17090686 records found...
9/18/2012 9:53:36 AM: Counting records to be purged in wgparts01...
9/18/2012 10:03:45 AM: 10100841 records found...
9/18/2012 10:03:45 AM: Purging records for wgparts01 using DIRECT method...
9/18/2012 3:47:59 PM: Purge complete for wgparts01...
9/18/2012 3:47:59 PM: Checking for orphaned records in wgparts01...
9/18/2012 3:56:37 PM: Check for orphaned records complete for wgparts01...
9/18/2012 3:56:37 PM: Purging wgparts02...
9/18/2012 3:56:37 PM: Counting records in wgparts02...
9/18/2012 3:56:37 PM: 377898 records found...
9/18/2012 3:56:37 PM: Counting records to be purged in wgparts02...
9/18/2012 3:56:45 PM: 146124 records found...
9/18/2012 3:56:45 PM: Purging records for wgparts02 using DIRECT method...
9/18/2012 3:56:58 PM: Purge complete for wgparts02...
9/18/2012 3:56:58 PM: Checking for orphaned records in wgparts02...
9/18/2012 3:57:07 PM: Check for orphaned records complete for wgparts02...
9/18/2012 3:57:07 PM: Purging wgparts04...
9/18/2012 3:57:07 PM: Counting records in wgparts04...
9/18/2012 3:57:07 PM: 432607 records found...
9/18/2012 3:57:07 PM: Counting records to be purged in wgparts04...
9/18/2012 3:57:11 PM: 201749 records found...
9/18/2012 3:57:11 PM: Purging records for wgparts04 using DIRECT method...
9/18/2012 4:01:45 PM: Purge complete for wgparts04...
9/18/2012 4:01:45 PM: Checking for orphaned records in wgparts04...
9/18/2012 4:01:45 PM: Check for orphaned records complete for wgparts04...
9/18/2012 4:01:45 PM: Purging wgparts05...
9/18/2012 4:01:45 PM: Counting records in wgparts05...
9/18/2012 4:01:45 PM: 382881 records found...
9/18/2012 4:01:45 PM: Counting records to be purged in wgparts05...
9/18/2012 4:01:49 PM: 171231 records found...
9/18/2012 4:01:49 PM: Purging records for wgparts05 using DIRECT method...
9/18/2012 4:02:10 PM: Purge complete for wgparts05...
9/18/2012 4:02:10 PM: Checking for orphaned records in wgparts05...
9/18/2012 4:02:11 PM: Check for orphaned records complete for wgparts05...
9/18/2012 4:02:11 PM: Purging wgmessage...
9/18/2012 4:02:12 PM: Purge complete for wgmessage...
9/18/2012 4:02:12 PM: Checking for orphaned records in wgmessage...
9/18/2012 4:02:12 PM: Check for orphaned records completed for wgmessage...
9/18/2012 4:02:12 PM: Purging wgattach...
9/18/2012 4:02:12 PM: Purge completed for wgattach...
9/18/2012 4:02:12 PM: Checking for orphaned records in wgattach...
9/18/2012 4:02:12 PM: Orphaned record check completed for wgattach...
9/18/2012 4:02:12 PM: Checking for invalid post-processing sets...
9/18/2012 4:02:12 PM: Invalid record check completed for post-processing sets...
9/18/2012 4:02:12 PM: Deleting bodies from disk...
9/18/2012 4:04:00 PM: Purging wgheaders...
9/18/2012 4:08:13 PM: Purge completed for wgheaders...
9/18/2012 4:08:13 PM: Truncating purgedata...
9/18/2012 4:08:13 PM: Truncate completed for purgedata...
9/18/2012 4:08:14 PM: Optimizing database started...
9/18/2012 6:32:38 PM: Optimizing database finished...
PowerPurge finished: 9/18/2012 6:32:38 PM |
|
| Back to top |
|
 |
administrator
Developer
Joined: 24 Jul 2004
Posts: 4750
Location: King William, VA
|
| Posted: Wed Sep 19, 2012 2:09 am Post subject: |
|
|
What do you get when you run this query:
| Code: | | SELECT SERVERPROPERTY('productversion') AS SQLVersion |
Regards |
|
| Back to top |
|
|
RobertWright
Experienced
Joined: 13 Feb 2006
Posts: 131
|
| Posted: Wed Sep 19, 2012 3:30 am Post subject: |
|
|
| 10.50.2500 |
|
| Back to top |
|
|
administrator
Developer
Joined: 24 Jul 2004
Posts: 4750
Location: King William, VA
|
| Posted: Wed Sep 19, 2012 10:49 am Post subject: |
|
|
Most of the purge was spent doing this:
| Code: | 9/18/2012 9:53:36 AM: Purging wgparts01...
9/18/2012 9:53:36 AM: Counting records in wgparts01...
9/18/2012 9:53:36 AM: 17090686 records found...
9/18/2012 9:53:36 AM: Counting records to be purged in wgparts01...
9/18/2012 10:03:45 AM: 10100841 records found...
9/18/2012 10:03:45 AM: Purging records for wgparts01 using DIRECT method...
9/18/2012 3:47:59 PM: Purge complete for wgparts01... |
Currently, NMP uses a joined delete to remove records that need to be purged. Unfortunately, SQL Server logs every record and so the delete becomes extremely disk-bound. I've been thinking of trying a select into for the records to keep, then drop the old table and rename the new as old. It should be much faster in cases like this where the table is large and you are deleting more than half of the records.
I also owe you an update for the size filter. It isn't quite as simple as I'd hoped, but I'll get these both into the next beta.
Regards |
|
| Back to top |
|
|
administrator
Developer
Joined: 24 Jul 2004
Posts: 4750
Location: King William, VA
|
| Posted: Fri Sep 21, 2012 12:17 am Post subject: |
|
|
The new PowerPurge code really speeds up deletes from large tables. I think you'll find it makes a huge difference.
Regards |
|
| Back to top |
|
|
administrator
Developer
Joined: 24 Jul 2004
Posts: 4750
Location: King William, VA
|
| Posted: Tue Oct 23, 2012 10:13 pm Post subject: |
|
|
The new beta is available for download.
Regards |
|
| Back to top |
|
|
RobertWright
Experienced
Joined: 13 Feb 2006
Posts: 131
|
| Posted: Tue Oct 23, 2012 10:40 pm Post subject: |
|
|
I'll download it tonight and see what happens.
Thanks. |
|
| Back to top |
|
|
RobertWright
Experienced
Joined: 13 Feb 2006
Posts: 131
|
| Posted: Wed Oct 24, 2012 10:04 pm Post subject: |
|
|
I'm very impressed with the new powerpurge changes. Here's the powerpurge log file.
PowerPurge started: 10/24/2012 4:51:55 PM
10/24/2012 4:51:55 PM: Initializing new database session...
10/24/2012 4:51:55 PM: Gathering Workgroups...
10/24/2012 4:51:55 PM: Found 5 Workgroups...
10/24/2012 4:51:55 PM: Purging wgparts00...
10/24/2012 4:51:55 PM: Counting records in wgparts00...
10/24/2012 4:51:55 PM: 0 records found...
10/24/2012 4:51:55 PM: Purging wgparts01...
10/24/2012 4:51:55 PM: Counting records in wgparts01...
10/24/2012 4:51:55 PM: 4572500 records found...
10/24/2012 4:51:55 PM: Counting records to be purged in wgparts01...
10/24/2012 4:51:57 PM: 3565482 records found...
10/24/2012 4:51:57 PM: Purging records for wgparts01 using COPY method...
10/24/2012 4:52:33 PM: Purge complete for wgparts01...
10/24/2012 4:52:33 PM: Checking for orphaned records in wgparts01...
10/24/2012 4:52:33 PM: Check for orphaned records complete for wgparts01...
10/24/2012 4:52:33 PM: Purging wgparts02...
10/24/2012 4:52:33 PM: Counting records in wgparts02...
10/24/2012 4:52:33 PM: 277390 records found...
10/24/2012 4:52:33 PM: Counting records to be purged in wgparts02...
10/24/2012 4:52:34 PM: 0 records found...
10/24/2012 4:52:34 PM: Purging wgparts03...
10/24/2012 4:52:34 PM: Counting records in wgparts03...
10/24/2012 4:52:34 PM: 16285 records found...
10/24/2012 4:52:34 PM: Counting records to be purged in wgparts03...
10/24/2012 4:52:34 PM: 0 records found...
10/24/2012 4:52:34 PM: Purging wgparts04...
10/24/2012 4:52:34 PM: Counting records in wgparts04...
10/24/2012 4:52:34 PM: 42677 records found...
10/24/2012 4:52:34 PM: Counting records to be purged in wgparts04...
10/24/2012 4:52:34 PM: 0 records found...
10/24/2012 4:52:34 PM: Purging wgmessage...
10/24/2012 4:52:34 PM: Purge complete for wgmessage...
10/24/2012 4:52:34 PM: Checking for orphaned records in wgmessage...
10/24/2012 4:52:34 PM: Check for orphaned records completed for wgmessage...
10/24/2012 4:52:34 PM: Purging wgattach...
10/24/2012 4:52:34 PM: Purge completed for wgattach...
10/24/2012 4:52:34 PM: Checking for orphaned records in wgattach...
10/24/2012 4:52:34 PM: Orphaned record check completed for wgattach...
10/24/2012 4:52:34 PM: Checking for invalid post-processing sets...
10/24/2012 4:52:34 PM: Invalid record check completed for post-processing sets...
10/24/2012 4:52:34 PM: Deleting bodies from disk...
10/24/2012 4:52:36 PM: Purging wgheaders...
10/24/2012 4:54:15 PM: Purge completed for wgheaders...
10/24/2012 4:54:15 PM: Truncating purgedata...
10/24/2012 4:54:15 PM: Truncate completed for purgedata...
10/24/2012 4:54:15 PM: Optimizing database started...
10/24/2012 4:55:44 PM: Optimizing database finished...
PowerPurge finished: 10/24/2012 4:55:44 PM |
|
| Back to top |
|
|
administrator
Developer
Joined: 24 Jul 2004
Posts: 4750
Location: King William, VA
|
| Posted: Wed Oct 24, 2012 10:29 pm Post subject: |
|
|
The combination of restructuring the parts tables as well as the copy/swap process makes all the difference. SQL Server is very good at a lot of things, but deleting data from a table isn't one of them. 
Regards |
|
| Back to top |
|
|
|
