Go Premium for a chance to win a PS4. Enter to Win

x
  • Status: Solved
  • Priority: Medium
  • Security: Public
  • Views: 427
  • Last Modified:

Transaction Log Filling up - Why? Is TSQL the problem (follow up to earlier question)

Note: This is a continuation of a question that was asked last week. I am adding more points because we still do not have an actual solution though earlier comments were useful. So here we go...

Our transaction log is filling up - 2.5 gigs in 2 hours with a 6gb file. The end result of this has been failure of backups (the database is in simple recovery but during backup it cannot truncate the log so it fills up).

The process that seems to be the problem only appears to be writing about 20,000 records a DAY. So, 1000 records per hour, and while they are wide  - about 100 columns - I cannot figure out why a 6gb log should be filling up.

We are running a profiler during the backup right now and have seen 17 MILLION log writes in 2 hours. What does the profiler think a "transactionlog write is? How could there be 17 M writes when only 20,000 records are being created?

The procedure that is running is a procedure that calls a procedure that calls a procedure - I know that this can cause performance problems if variables are being passed, but I have resolved those from a performance perspective. Is there some reason that this "stacking" of procedures would be a problem for transactions?

0
AaronAbend
Asked:
AaronAbend
  • 11
  • 9
  • 7
  • +2
3 Solutions
 
Melih SARICACommented:

Try to backup log to a in every one hour...

An i ve told u before..

Backuping the Log file with a batch/shedule ,if u ave lots of transactions, increase the log space
/* log backup */
create procedure _BackupOnlyLog
as
declare @DeviceName char(50)
declare @DevicePATH char(50)

set nocount on
SET @DeviceName = 'Temp_Log'
SET @DevicePATH = 'd:\sql.backup\Temp_Log.BCK'

EXEC sp_addumpdevice 'disk', @DeviceName, @DevicePATH

BACKUP LOG Planungen TO @DeviceName WITH  NOUNLOAD ,  SKIP ,  STATS = 10,  FORMAT

go
/* End of Procedure */

It ll delete all closed transactions... and increase the unused space of ur log file..
0
 
AaronAbendAuthor Commented:
non_zero - we are in simple recover mode. We do not backup the log at all. I am not even sure it is possible to back up a log while a database backup is ongoing.

0
 
AaronAbendAuthor Commented:
Response to Dan Blake -
Multiple logs sounds interesting, but since the log is actually filling up (ACCORDing to the error messages) I am not sure how it would help (we can afford the 6GB if that solves the problem.

At this moment, the log is 3.5 G full with 3.5 G available (we actually have 7GB in the log, not 6GB). The backup has "completed" (showing 100%) but the job has not finished. What does this mean? How long before it "finishes". Also, we are puzzled since earlier backups caused the log failure in just 2 hours. We are 3.5 hours into the backup with no errors and a log only half full. Why the difference.

Obvious next step is to profile overnight activity to see if there is something during those times that would make this backup different (the backups failed at 9pm, 1am, and 4am start times, this one started at 7am, which should have been busier if anything).

The TSQL programs are several thousand lines long. Not really practical to send it at this point, but if it becomes useful I will post it.

AA

0
NFR key for Veeam Agent for Linux

Veeam is happy to provide a free NFR license for one year.  It allows for the non‑production use and valid for five workstations and two servers. Veeam Agent for Linux is a simple backup tool for your Linux installations, both on‑premises and in the public cloud.

 
Melih SARICACommented:
it wont matter.. if db is running  or not

it ll be a dummy file backup.. we ll just use to empty our log file ...



0
 
danblakeCommented:
Your problem with the T/Log definition to what a Transaction Log Write is:
http://msdn.microsoft.com/library/default.asp?url=/library/en-us/adminsql/ad_mon_perf_79tf.asp


The number of I/Os issued to perform the log entry.

This number will probably not directly relate to the number of records being processed.
0
 
AaronAbendAuthor Commented:
Response to Non_Zero  - I don't understand. If the log is truncated, the database will lose data, right?

Response to Dan: Our transactionlog profile entries have no end time - does that mean anything?  

By the way, our backup finally finished successfully (for the first time in 3 weeks), using less than 4GB of space in the log. Now we are going to profile overnight activity to see if there is something happening that we do not know about.

Is it possible that the SQL Server parameter "programmer_is_watching" is set to true? Just kidding! I will post new learnings as we come by them for anyone interested. I will probably award the points next week after we have a chance to gather an overnight profile and run the backup a few more times.



0
 
danblakeCommented:
Our transactionlog profile entries have no end time - does that mean anything?
Its meant to indicate when a transaction has finished (or finished with rollback) so you can identify a process still runnning in the background...

Testing with two seperate processes in Query analyser:

Process A:
GO
BEGIN TRANSACTION
select top 1000 * from Test_Table

Process B: /*Implicit transaction that automatically completes upon finish*/
Select * from Test_Table2

Whats weird is that I do not get any transaction log end times on either of these, I'm pretty certain that I'm meant to get a transaction log end time.

Maybe a good one for MS PSS ?
0
 
Melih SARICACommented:
Can u see open Transactions under the Current Activity in Process info On SQLEM ..


0
 
danblakeCommented:
If I reread the trace I have here on that little run ...
They are logged with EndTimes under the SQLTransaction not TransactionLog event class.

So the simple answer to this is  I'm confused to why its not writing the endtime in the TransactionLog event class...

Looks like according to the MS article there should be some data there.

0
 
Scott PletcherSenior DBACommented:
How large is the db itself?

It almost sounds as if there is some type of "log thrashing" going on.  With the db in simple recovery mode, you shouldn't normally have a very large log.  

If the db can be made unavailable for a couple of minutes, personally I would "start over" by creating a new log -- detach the db, rename the log, re-attach the db, forcing a new log to be created (using QA: *NEVER EVER* use EM to do an attach or detach).  If the db is large, it's most efficient to do this immediately after the normal daily backup, so that you have a good recovery point automatically.  

Also, run a script *immediately* to change the increment on the log from 10% to a (generous) fixed amount, say 50M or 100M.  I've seen big performance improvements from that on all sizes of dbs.

Once the db is re-attached and functioning normally for a while, you can go back and delete the original log.
0
 
danblakeCommented:
Yes, I can see open transactions in EM...
(For the query without the COMMIT/Rollback as given).
0
 
Melih SARICACommented:
Ok .. When u backup db .. nothing happens to ur Open tnasactions...

Cuz Backup db clears the finished transaction logs only ..

any time u start a transacation .. it tooks some place to work on it.. and mark the place ...

thats where we ll start.. if a transaction closed cancelled or others.. i mean not working anymore.... this is mark ll no longer stay.. so.. when u backup the log..

only running transactions ll stay in ur log file.. and this ll increase the unused space
0
 
danblakeCommented:
0
 
danblakeCommented:
@non-zero yes...

And if the transactions are logged, as given in my example where the first transaction does not complete the log file decides that it cannot shrink, even though later transactions finish.

Hence why I was a bit baffled why the transactionlog end time is not indicated (even in my simple test example)...

What I normally do when there are open transactions and finished transactions in a higgle-piggle in the logs is use the following script (better than dropping any logs-- works well when there are two logs around, to keep the size down on a more perm basis):
http://www.sqlservercentral.com/scripts/contributions/26.asp
0
 
AaronAbendAuthor Commented:
To non_zero = Can I see open transactions? How can you tell whether a transaction is open? I can see Insert statements.
0
 
rdrunnerCommented:
Is there any DB reorganisation going on in the night?

If so this could cause your Log to grow by quite an amount. Or do you import any Tables overnight?

Those are things that could cause your log to blow up. You can also backup your Log with the option truncateonly.... You wont loose any Data with this but it will remove all non needed parts from the log

BACKUP LOG { database_name | @database_name_var }
{
    [WITH
        { NO_LOG | TRUNCATE_ONLY } ]
}

0
 
Melih SARICACommented:
can u paste the script here
Melih SARICA
0
 
danblakeCommented:
DBCC OPENTRAN ('database_name')

Will display if there are any open transactions.
0
 
Melih SARICACommented:
To AaronBend  =
  On SQLEM. Under Ur server -> Management-> Current Avtivity -> Process Info
  u ll see Open transactions for each Process

... and

RdRunner thanx... Im traying to tell that for 2 days..
Backup the Log file...
0
 
Scott PletcherSenior DBACommented:
This link appears to be blank:

http://www.sqlservercentral.com/scripts/contributions/26.asp

Although I've seen similar-function scripts on the web.  Some of them write additional data and iteratively shrink the log further.  This will be considerable overhead on a db and log that size vs. a quick detach and attach.
0
 
danblakeCommented:
Let me, just re-post this..
(This also has the script..)
http://www.sql-server-performance.com/forum/topic.asp?TOPIC_ID=1867

But the overhead of this is better than dropping the database, and making it unavailable...
(Safer 100% uptime operations sometimes do take a little longer)
0
 
Scott PletcherSenior DBACommented:
It depends on what you think is better -- hours of poor performance or a minute of unavailability, take your choice.  I have to admit that we have no databases that we can't take down for a least a few minutes a month (some no more than that, though).
0
 
Melih SARICACommented:
but as the Aaron told before
 log become full in 2 hours

so u cant detach/attach db in every 2 hours
0
 
danblakeCommented:
Ive tested the script on systems, it hasn't generated any really bad poor performance when running and has actually been really fast to complete on this log file < 6 GB this will take hardly any time at all...
(its been bit of a godsend, when the backups of a log havn't worked and the db cannot be brought down because users need to view data : web based 24x7 envs..)
0
 
danblakeCommented:
And you can't run a dettach/reattach when running a full backup ! D' oh!
0
 
Melih SARICACommented:
if u check the script above...

&#305;ts backing up the Log...

Thats the point.. as im saying 4 2 days....

And also its adviced in Ms Articles....

0
 
Scott PletcherSenior DBACommented:
I'm suggesting that cleaning up the existing log and then immediately changing the allocation may solve the problem, at least for a while, especially if followed by frequent backups/truncations of the types you've described.  But I suspect that some type of initial clean up will be required at least once *first*, at least that is my experience.
0
 
danblakeCommented:
Have you noticed that the script also includes a DBCC SHRINKFILE ?
The backup of the log alone will not reduce the size of the T-Log file....
it has to be used in conjunction with DBCC SHRINKFILE (Log_Name)
.

Otherwise your T-Log will continue to grow bigger and bigger, but the space in the T-log available will get bigger if using the Backup log only.
0
 
Melih SARICACommented:
Wot about trying it..

try only backup log command see wot happnes..

u ll see that the usage of the log file decreased...  

thats wot we r talking...

of course if u wanna free space on ur drives .. u ave to shrink the log file..

Backup only decrase the usage of the log file..  and keep the log file size same.. dont give unused space to operating system..

if u wanna give unused space to the operating system u ave to shrink the file..
0
 
AaronAbendAuthor Commented:
Too much to read carefully. Thanks to all. Here are some clarifications (some of this is in my earlier question)

1) The database is in simple recovery mode, so normally the 7GB log has 100MB of transactions that appear and disappear every few seconds as the database checkpoints. No problem.

2) When we start the backup, the log fills, as it must, since transactions cannot be written to the database file during the backup and must remain in the log until the backup is done and they can be written to the database (and then the log would truncate).

3). We used to reindex overnight but should not be doing so any longer (in fact, there is not enough space to reindex the main table, which has 170 million records). We will run a profiler to make sure.

4). Scott, given that the log is virtually clear after each checkpoint during normal operation, is there any reason to recreate the log file?

5) non_zero, I cannot see open transactions in SQLEM (I know where you are looking and if you check you will see nothing about transactions - only the current statement, unless you are running a different version of EM).

6) Dan, DBCC OPENTRAN does give info - but only if I run it 5 or six times. Then I see a DML transaction. None of the DML statements takes very long in itself. We are inserting one record at a time into the main table (no way around that).

Thanks for your comments. I am continuing to work on this. We are going to run another backup tonight to see if we can reproduce the original failure. (and run a profiler as well)

Aaron
0
 
AaronAbendAuthor Commented:
Here may be the answer to the 17 million transaction question:  It appears that a "transaction" is logged for each index that must be updated as well as for the record. So, update 20,000 records on a table with 5 indexes means that there will be 100,000 transactions logged.

I dropped 2 unnecessary indexes (why were they there? to support the "older" version of the program, which was changed to the "new" version on April 15th - the day that our problems began. It was always the prime suspect, but we could not figure out why).

0
 
rdrunnerCommented:
Hmm... Ok during Backups you cant shrink to log... But there still could be querries that update to many rows...

Are there any updates that update more then they should?

Example: User opens his Emails and you mark ALL his emails as "not new"... Only mark the "new emails" as not "new"....

This is just a really wild guess ;)

Get a Log viewer and check the logs whats using so much space there.... I am not sure where to get a good one Maybe try Apexsql i think they have one as a trialware

0
 
AaronAbendAuthor Commented:
RDRunner - good guess. In fact, there was an update that was doing much more than it should have due to a missing constraint (eerily like what you described. I was marking a "Done" flag but was not bothering to see whether I had already marked them (which would dramatically reduce the number of affected records).  According to my calculations, it was updating 20000 rows every time the program ran (which was about every 10 seconds). Not good! (The reason for this error was that this table is normally cleared out after each run of the program - ironcally, I was not clearing out the table because I wanted to make sure the program was running properly before I cleared out the data (which is actually just moved to an archive table anyway)).

I Fixed that. But I have a question. Wouldn't a single statement that updates 10,000 rows be written to the log as a single statement? Would it do 10,000 writes to the log? I know that Oracle only does the latter during a log switch. Normally, Oracle only writes the Update statement. I assumed SQL did the same thing.

Insights on this anyone?
0
 
rdrunnerCommented:
Well the log needs to write one entry for every row updated... If it would only write the update statement it wouldnt be exact....

You could not say which data you modified after you did a board update... And a transaction log needs to record every transaction
0

Featured Post

VIDEO: THE CONCERTO CLOUD FOR HEALTHCARE

Modern healthcare requires a modern cloud. View this brief video to understand how the Concerto Cloud for Healthcare can help your organization.

  • 11
  • 9
  • 7
  • +2
Tackle projects and never again get stuck behind a technical roadblock.
Join Now