Solved

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

Posted on 2004-04-28
36
402 Views
Last Modified: 2009-07-29
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
Comment
Question by:AaronAbend
  • 11
  • 9
  • 7
  • +2
36 Comments
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility

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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
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
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
Can u see open Transactions under the Current Activity in Process info On SQLEM ..


0
 
LVL 13

Expert Comment

by:danblake
Comment Utility
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
 
LVL 69

Expert Comment

by:ScottPletcher
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
Yes, I can see open transactions in EM...
(For the query without the COMMIT/Rollback as given).
0
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
0
 
LVL 13

Expert Comment

by:danblake
Comment Utility
@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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
To non_zero = Can I see open transactions? How can you tell whether a transaction is open? I can see Insert statements.
0
 
LVL 11

Expert Comment

by:rdrunner
Comment Utility
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
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
can u paste the script here
Melih SARICA
0
How to run any project with ease

Manage projects of all sizes how you want. Great for personal to-do lists, project milestones, team priorities and launch plans.
- Combine task lists, docs, spreadsheets, and chat in one
- View and edit from mobile/offline
- Cut down on emails

 
LVL 13

Expert Comment

by:danblake
Comment Utility
DBCC OPENTRAN ('database_name')

Will display if there are any open transactions.
0
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
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
 
LVL 69

Expert Comment

by:ScottPletcher
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
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
 
LVL 69

Expert Comment

by:ScottPletcher
Comment Utility
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
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
but as the Aaron told before
 log become full in 2 hours

so u cant detach/attach db in every 2 hours
0
 
LVL 13

Expert Comment

by:danblake
Comment Utility
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
 
LVL 13

Expert Comment

by:danblake
Comment Utility
And you can't run a dettach/reattach when running a full backup ! D' oh!
0
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
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
 
LVL 69

Accepted Solution

by:
ScottPletcher earned 43 total points
Comment Utility
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
 
LVL 13

Assisted Solution

by:danblake
danblake earned 41 total points
Comment Utility
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
 
LVL 19

Expert Comment

by:Melih SARICA
Comment Utility
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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 11

Expert Comment

by:rdrunner
Comment Utility
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
 
LVL 10

Author Comment

by:AaronAbend
Comment Utility
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
 
LVL 11

Assisted Solution

by:rdrunner
rdrunner earned 41 total points
Comment Utility
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

How to run any project with ease

Manage projects of all sizes how you want. Great for personal to-do lists, project milestones, team priorities and launch plans.
- Combine task lists, docs, spreadsheets, and chat in one
- View and edit from mobile/offline
- Cut down on emails

Join & Write a Comment

JSON is being used more and more, besides XML, and you surely wanted to parse the data out into SQL instead of doing it in some Javascript. The below function in SQL Server can do the job for you, returning a quick table with the parsed data.
Load balancing is the method of dividing the total amount of work performed by one computer between two or more computers. Its aim is to get more work done in the same amount of time, ensuring that all the users get served faster.
This video shows, step by step, how to configure Oracle Heterogeneous Services via the Generic Gateway Agent in order to make a connection from an Oracle session and access a remote SQL Server database table.
This videos aims to give the viewer a basic demonstration of how a user can query current session information by using the SYS_CONTEXT function

763 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question

Need Help in Real-Time?

Connect with top rated Experts

7 Experts available now in Live!

Get 1:1 Help Now