Be Paranoid. Be Very Paranoid.

Do you maintain an application with a backend database? Does that application ever write to the database? Be afraid.

The worst situation to be in with respect to the above is when a customer mails you and says: “Why is my data gone?”

99% of the time, it’s because they clicked on the “Delete” button; but sometimes you need proof – this is what I want to discuss.

Log every interesting write to the database. There are various levels at which you can do this:

• Application logic level: This gives you the most context, the most usable logs, and in fact gives you data which can generally be exposed directly to the customer, preventing lots of questions. The problem is that it’s not reliable: The app could succeed in writing then fail in logging. Alternatively, a dev on the app might forget to add logging to a new feature.
• Application object model level: A little less context/readability than above, a little more reliability.
• Data-Access-Layer level: Less context than above, more reliability.
• Sproc level: Same tradeoff.
• Table level (triggers): And same again.

As you can see, the lower you go, the less chance for error and the less value a log entry gives you. You can increase the value of a “deep” log entry by forcing a set of arguments up the stack. For example, you can force every sproc which writes data to require username/machine/reason arguments – but this can become costly to maintain.

So which is right? Depends on your app, your level of paranoia, your customer’s needs, etc. Generally I stay away from triggers and try to add logging at the sproc level for critical sprocs, and at the app/OM level for extra context; better to have too much logging than too little.

Here’s a nice trick for creating a footprint log table that your sprocs (or triggers) can use quite easily - Create a simple table with the following columns (at least):

 

Name	Default value	Comment
LogEntry		The text you want to log.
TimeStamp	getdate()	Automatically fills in the current datetime.
User	system_user	Automatically inserts the logged in user’s ID.
Machine	host_name()	Automatically inserts the user’s client machine name.
Application	app_name()	Automatically inserts the name of the application running this code (provided you set it in the connection string, which you should!)

 

Inserting into this table requires only the one column, but you capture lots of extra data for free. If this is done from a trigger, then you’ll even catch slackers with access to the DB who are updating it manually.

 

Oh, don’t forget to age off old entries before the table ends up at 50GB ;)

 

Avi

Comments

• Anonymous
  December 03, 2008
  PingBack from http://www.alvinashcraft.com/2008/12/03/dew-drop-december-3-2008/
• Anonymous
  December 04, 2008
  Having some type is also mandatory. I tend to have the following:Debug/Verbose, Informational, Warning, Error, Fatal (V, I, W, E, F)Just for logging and the following auditing messages:Allowed, Denied (A, D)So there you see why I use the V for debug/verbose ;-)Keep in mind that your table does not have a unique column and that datetime values can have conflicts depending on how fast errors occur.