Skip to main content

Poking around SQL Server's Transaction Log

I recently had the opportunity to try and figure out why SQL Server was doing certain things in one of my applications. This application was using CursorAdapters and for some strange reason, data was being cleared out (for no apparent reason, of course).

But in my searches, I started looking for a tool that would let me read SQL Server's Transaction Log. Sure, you can always restore it to a certain point - but when your customer has run their system for several days and then comes back and says "there was a problem a few days ago", you really don't want to suggest they re-enter all their data. I just wanted to know what the heck was going on with those SQL statements.

Now, you might expect (as I did), that Microsoft would offer such a tool directly within the SQL Server 2005 Manager but no - their "logs" are all about "Login Failed" or "Starting the service". Useless if you really want to see what's going on.

Now, if you Google SQL Server Transaction Logs, you'll see all kinds of tools available. Red-Gate and Apex were two that I looked at. Unfortunately, even though it's 2007, only one of them has access to the SQL 2005 logs and that was Apex. Red-Gate even has a funny story as to why they don't have SQL 2005 support. Red-Gate's product is only $195 while Apex's is considerably more but both offered eval versions which I thought would be enough to see what was going on.

I tried using Apex's and while it looked like it was showing me tons of information, it didn't actually show me the SQL that was being executed. Every now and then, I would see a record with a bit of data but for the most part, the log was empty. I've kept on trying to look at it to see if there's anything I can pull out - but for the most part, when looking at the way SQL tables are updated with VFP Cursor adapters , it wasn't very useful. (I don't know if it works better with direct SQL Pass through).

So today, I had the scenario where a field in a table was blanked out on the 5th even though it had been filled in earlier in the day. How could this have happened? I took a look in the ApexLog and it shed no information. I played with database backups and was able to identify exactly when the problem took place but without access to the log, how could I see what happened?

As luck would have it, I did another google search and came across an undocumented command and function that's been around since SQL 7.0 (so why it's not documented is beyond me except this posting explains that MS won't support it). DBCC LOG or more importantly

SELECT * FROM ::fn_dblog(null,null)

which returns a cursor that is the essence of the transaction log.

It's not very readable but let me share a few things I did learn about it and how I was able to use it (if someone has more information, please let me know) - I tried googling for more details but in the end , it was simpler to find it myself).

The table has a messy structure - and it's changed from SQL 2000 to SQL 2005 so I won't bother putting it in here.

The OPERATION field tells you what it was trying to do. The key entries here are LOP_BEGIN_XACT (which tells you when the transaction was started - and fills in a valuable field named begin_time). There's also a LOP_COMMIT_XACT which fills in end_time.
In between those two records is the actual work which unfortunately doesn't have its own begin_time or end_time. So you can actually fill it in by doing a quick little program like this:


curls = "X"
ldb='x'
scan
if operation='LOP_BEGIN_XACT '
ldB = begin_time
curls = current_ls
else
if previous_l=curls and ISNULL(begin_time)
replace begin_time with ldb
endif
endif

endscan


The current_ls is a unique identifier for the transactions. The Preview_l is really previous_ls but when you copy it to a table, you'll lose all of the nice field names.

At any rate, another key field I found was allocunitn which if you STRTRAN(allocunitn,CHR(0)), you'll find the name of the table that is being updated.

Then you can look specifically for rows with an Operation field of LOP_MODIFY_ROWS, LOP_INSERT_ROWS or LOP_DELETE_ROWS.

The final field that I found useful was at the end of the field list and is named log_recor3. This field has a bunch of binary data in it but when you look at it, you can see the data that is being modified or added.

I couldn't really figure out the best way to determine which field was being updated, except by looking at the data that was in there. If a field is being updated, it will show the OLD value and then the new value. For deletes, it shows the data it is deleting and for inserts, it shows the actual field values.

It would be great if it was documented somewhere - but I imagine this is one of those proprietary things for Microsoft. The strange thing for me though is why I was able to find it in the Transaction Logs but ApexLog couldn't. Go figure.

If you are working with SQL Server and have a need to look at the log, I hope this post helps - if you have some more ideas as to how to figure out what the heck is going on in there, let me know.

At the end of the day, it turned out it wasn't the SQL Update at all - the user had blanked out the value by accident and we weren't trapping for it. Four hours of trying read the gibberish of the SQL log - but hey! I found out I don't really need to spend the money on a log tool persay (Apex is about $600) because I could find it all with one little "undocumented" feature, that definitely deserves more page ranks because the noise when you search for Transaction log reading makes it harder to find the things you need.

Simple-Talk - transaction log

powered by performancing firefox

Comments

Ivan Erceg said…
Hi Andrew,

Thanks for evaluating ApexSQL Log. I'm Chief Server Architect over at ApexSQL and directly responsible for what works and doesn't work in the product. I'm sorry that the product didn't work for you. We are at your full disposal to try to figure out the problem if you wish to do so (admittedly at this point it would probably be more help to us than to you.) In any case, if the need ever arises again, I invite you to try new version and see if it works better for you (version 2005.04 has a whole bunch of fixes and improvements over 2005.03 which is the one you tested.) If you have suggestions for us or anything else in fact - please don't hesitate to contact us at log_team@apexsql.com.

Thanks,
Ivan Erceg

Popular posts from this blog

Programmers vs. Developers vs. Architects

I received an email this morning from Brandon Savage's newsletter. Brandon's a PHP guru (works at Mozilla) but his newsletter and books have some great overall perspectives for developers of all languages. However, this last one (What's the difference between developers and architects?) kind of rubs me the wrong way. Either that, or I've just missed the natural inflation of job descriptions. (maybe, it's like the change in terminology between Garbage man and Waste Engineer or Secretary and Office Administrator)

So maybe it's just me - but I think there's still a big difference between Programmer, Developer and then of course, architect. The key thing here is that every role has a different perspective and every one of those perspectives has value. The original MSF create roles like Product Manager, Program Manager, Developer, Tester, etc - so every concept may pigeon hole people into different roles. But the statements Brandon makes are often distinctions I…

Security in Windows 10

http://www.slate.com/articles/technology/bitwise/2015/08/windows_10_privacy_problems_here_s_how_bad_they_are_and_how_to_plug_them.single.html

 discusses some Windows 10 privacy settings and their implications.

"Finally, we will access, disclose and preserve personal data, including your content (such as the content of your emails, other private communications or files in private folders), when we have a good faith belief that doing so is necessary." "In other words, Microsoft won't treat your local data with any more privacy than it treats your data on its servers and may upload your local data to its servers arbitrarily"
I did a quick install on a VM choosing the Express settings. When I fully deploy this on a real workstation, I will likely choose to wade through all of the individual pages, as David recommends.

Of course, losing one's privacy is nothing new - it's happening all over the place (despite Santa Ana's police force's lawsu…

AppleSoft

I'm not TRYING to be "fanboy-flame bait" but what I saw yesterday was a typical "Do it this way, now do it this way and then we'll go back to this way" all over again.... a move similar to what Microsoft does to developers on an ongoing basis.

Remember the first iPhone? Smooth and curved, at least as far as it could be back then. I still pull out my 3G and can see the curves on it.

Then the 4 came out and "boxy" was all the rage. Everything should be "tight with corners"

Now iPhone 6.... smooth and curvy is back. Granted I don't have the actual device yet, but that's the message.

Guess that means the iPhone 8 will be back to boxy.

And honestly, Apple Watch is not worth "one more thing" --- especially when everyone knows it's going to be shown. "One more thing" would be something no one saw coming.  The device itself ? Very interesting and yes, definitely lots of potential but "one more thing" wor…