Each day is experiencing about 1GB sum total of all the transaction log backups that day, while at the end of that week the Full DB backup is about 180MB. For a business database for buying/selling things from/to vendors/customers the total size of a days worth of transaction log backups is at least 10 times larger than I would expect it should be in comparison to the size of the actual database.
How do I find what sql insert/update/delete/etc operations are causing so many / such large transactions? I'm envisioning that there is some bad code somewhere that re-writes an entire table just to update/insert 1 row, or something that is updating the same rows over and over again. I'd like to know what the bad transaction(s) are before going through all the db application code.
Most questions, including Why Does the Transaction Log Keep Growing or Run Out of Space? and other articles deal with people who have a transaction log file that keeps growing, usually due to them never backing it up. That is NOT the case with my problem. My transaction log file is no longer increasing in size, my question is about how to find what transactions are causing the regular large size of each of the backups, not the size of the log file.
We have an MS SQL Server 2012 database where we are
- Using the Full recovery model
- Weekly full backups, on Friday nights. (.bak)
- Nightly differential backups (.dif)
- 3 times per day transaction log backups (.trn) (Edit: it has been pointed out this should be much more often for better RPO)
- all backups use compression.
- DB is only used during regular office hours
- DB has an application to perform a variety of tasks including some scheduled ones
I realise the actual sizes listed below are not large in the scheme of things due to this DB being only a few months old, but if this trend continues as the DB grows, I'm expecting trouble on multiple fronts. Here is the last 2 week's worth of backup file sizes.
14/11/2014 11:05 PM 200,873,984 Production_backup_2014_11_14_230500_8220928.trn 14/11/2014 11:18 PM 173,499,904 Production_backup_2014_11_14_231753_3214232.bak 15/11/2014 06:00 AM 321,033,728 Production_backup_2014_11_15_060001_9915061.trn 15/11/2014 10:00 AM 47,616 Production_backup_2014_11_15_100001_1784634.trn 15/11/2014 02:00 PM 59,392 Production_backup_2014_11_15_140001_0461018.trn 15/11/2014 06:00 PM 62,976 Production_backup_2014_11_15_180001_5854303.trn 15/11/2014 11:05 PM 71,506,432 Production_backup_2014_11_15_230501_3937283.dif 16/11/2014 06:00 AM 12,906,496 Production_backup_2014_11_16_060009_1822596.trn 16/11/2014 10:00 AM 11,776 Production_backup_2014_11_16_100001_2205645.trn 16/11/2014 02:00 PM 12,288 Production_backup_2014_11_16_140000_7731183.trn 16/11/2014 06:00 PM 12,288 Production_backup_2014_11_16_180001_4459573.trn 16/11/2014 11:05 PM 73,329,664 Production_backup_2014_11_16_230501_1010172.dif 17/11/2014 06:00 AM 12,288 Production_backup_2014_11_17_060001_2761826.trn 17/11/2014 10:00 AM 41,998,848 Production_backup_2014_11_17_100004_9331208.trn 17/11/2014 02:00 PM 167,330,304 Production_backup_2014_11_17_140004_6334692.trn 17/11/2014 06:00 PM 161,651,712 Production_backup_2014_11_17_180007_0122447.trn 17/11/2014 11:05 PM 92,433,408 Production_backup_2014_11_17_230501_6387196.dif 18/11/2014 06:00 AM 333,844,480 Production_backup_2014_11_18_060001_5745763.trn 18/11/2014 10:00 AM 126,087,680 Production_backup_2014_11_18_100005_0370500.trn 18/11/2014 02:00 PM 166,028,288 Production_backup_2014_11_18_140005_3971911.trn 18/11/2014 06:00 PM 179,916,288 Production_backup_2014_11_18_180006_2898091.trn 18/11/2014 11:05 PM 96,823,296 Production_backup_2014_11_18_230501_5082355.dif 19/11/2014 06:00 AM 339,789,312 Production_backup_2014_11_19_060002_0077560.trn 19/11/2014 10:00 AM 127,332,352 Production_backup_2014_11_19_100006_4801078.trn 19/11/2014 02:00 PM 174,851,584 Production_backup_2014_11_19_140006_7360844.trn 19/11/2014 06:00 PM 170,896,384 Production_backup_2014_11_19_180006_2771851.trn 19/11/2014 11:05 PM 100,923,904 Production_backup_2014_11_19_230501_2174429.dif 20/11/2014 06:00 AM 341,084,160 Production_backup_2014_11_20_060000_7971034.trn 20/11/2014 10:00 AM 143,212,544 Production_backup_2014_11_20_100005_7464239.trn 20/11/2014 02:00 PM 168,745,472 Production_backup_2014_11_20_140007_3616365.trn 20/11/2014 06:00 PM 169,514,496 Production_backup_2014_11_20_180006_5721553.trn 20/11/2014 11:05 PM 104,629,248 Production_backup_2014_11_20_230501_0945522.dif 21/11/2014 06:00 AM 345,049,088 Production_backup_2014_11_21_060003_5997426.trn 21/11/2014 10:00 AM 131,839,488 Production_backup_2014_11_21_100004_0817301.trn 21/11/2014 02:00 PM 179,260,416 Production_backup_2014_11_21_140006_1959629.trn 21/11/2014 06:00 PM 185,633,280 Production_backup_2014_11_21_180006_0060725.trn 21/11/2014 11:05 PM 211,755,520 Production_backup_2014_11_21_230500_9492206.trn 21/11/2014 11:19 PM 184,960,512 Production_backup_2014_11_21_231900_1599462.bak 22/11/2014 06:00 AM 342,386,688 Production_backup_2014_11_22_060003_6139255.trn 22/11/2014 10:00 AM 114,176 Production_backup_2014_11_22_100003_8050593.trn 22/11/2014 02:00 PM 131,584 Production_backup_2014_11_22_140001_5545860.trn 22/11/2014 06:00 PM 131,584 Production_backup_2014_11_22_180004_6338691.trn 22/11/2014 11:05 PM 74,345,984 Production_backup_2014_11_22_230501_0706925.dif 23/11/2014 06:00 AM 13,621,760 Production_backup_2014_11_23_060005_1215593.trn 23/11/2014 10:00 AM 12,288 Production_backup_2014_11_23_100000_8636227.trn 23/11/2014 02:00 PM 148,992 Production_backup_2014_11_23_140001_5174270.trn 23/11/2014 06:00 PM 12,800 Production_backup_2014_11_23_180001_0560033.trn 23/11/2014 11:05 PM 76,475,904 Production_backup_2014_11_23_230500_6863628.dif 24/11/2014 06:00 AM 24,576 Production_backup_2014_11_24_060002_1207776.trn 24/11/2014 10:00 AM 99,911,168 Production_backup_2014_11_24_100001_6216355.trn 24/11/2014 02:00 PM 161,881,088 Production_backup_2014_11_24_140006_1306524.trn 24/11/2014 06:00 PM 163,761,664 Production_backup_2014_11_24_180001_1006240.trn 24/11/2014 11:05 PM 96,010,752 Production_backup_2014_11_24_230500_8739860.dif 25/11/2014 06:00 AM 333,105,664 Production_backup_2014_11_25_060001_1277451.trn 25/11/2014 10:00 AM 141,830,656 Production_backup_2014_11_25_100004_1112999.trn 25/11/2014 02:00 PM 164,597,248 Production_backup_2014_11_25_140001_6337935.trn 25/11/2014 06:00 PM 176,773,632 Production_backup_2014_11_25_180004_9749028.trn 25/11/2014 11:05 PM 102,029,312 Production_backup_2014_11_25_230500_9038297.dif 26/11/2014 06:00 AM 334,088,704 Production_backup_2014_11_26_060001_1548298.trn 26/11/2014 10:00 AM 127,079,424 Production_backup_2014_11_26_100001_7924674.trn 26/11/2014 02:00 PM 165,528,576 Production_backup_2014_11_26_140005_2202075.trn 26/11/2014 06:00 PM 165,344,256 Production_backup_2014_11_26_180000_9116237.trn 26/11/2014 11:05 PM 104,935,936 Production_backup_2014_11_26_230500_6289926.dif 27/11/2014 06:00 AM 336,645,120 Production_backup_2014_11_27_060000_8290121.trn 27/11/2014 10:00 AM 128,401,920 Production_backup_2014_11_27_100008_6395607.trn 27/11/2014 02:00 PM 163,676,160 Production_backup_2014_11_27_140004_6019843.trn 27/11/2014 06:00 PM 167,849,472 Production_backup_2014_11_27_180005_9136346.trn 27/11/2014 11:05 PM 108,699,136 Production_backup_2014_11_27_230500_8885145.dif 28/11/2014 06:00 AM 338,519,040 Production_backup_2014_11_28_060001_1061047.trn 28/11/2014 10:00 AM 129,424,896 Production_backup_2014_11_28_100005_8038388.trn 28/11/2014 02:00 PM 171,059,712 Production_backup_2014_11_28_140014_1188080.trn
The db application doesn't run between 3am sunday until around 8am on the the Monday, so the .trn files over the weekend are mostly small as I would expect. I think I've mucked up the sequence of the weekly DB shrink and re-index so the backups around that are larger than they should be, but each .trn file after that should be quite small.
Best Answer
You should be able to dump the output from fn_dump_dblog into a table to sort if needed. I'd recommend you decrease your backup interval to maybe every hour or so to make it easier to analyze the data (plus it will improve your ability to recover and reduce the time each backup takes). I tested a 453mb log and it took 10 minutes to read all 6.7 million rows. If you have a small one to test, take a look so you get an idea of which columns you want to look at like Paul Randal does in this post. I found this blog entry that had some good info on the different operations and more on how to analyze the log.
If you want to watch live transactions or get some nice filtering, I'd use an extended events session since you are on 2012. You can use the wizard if you aren't familiar with it and try the query detail sampling template and add corresponding starting events which should give you a good idea of what statements/transactions are executing. A combination of the two methods might help you correlate how much log a transaction makes since the transaction id is exposed to extended events and it is a column returned by the function.