Code

Back on the trail…. #sqlsatnash

I realize that I should probably be blogging about my New Year’s resolutions, but meh… I’ve been super busy surviving the holidays.  So busy in fact that I’ve failed to mention that I’ll be presenting at the SQLSaturday in Nashville on January 18, 2014.  I actually got selected to present TWO topics, which is HUGE for me.  Hoping that I can refine a presentation, and get ready for our own SQLSaturday in Atlanta.

Working with “Biggish Data”

Most database professionals know (from firsthand experience) that there continues to be a “data explosion”, and there’s been a lot of focus lately on “big data”. But what do you do when your data’s just kind of “biggish”? You’re managing Terabytes, not Petabytes, and you’re trying to squeeze out as much performance out of your aging servers as possible. The focus of this session is to identify some key guidelines for the design, management, and ongoing optimization of “larger-than-average” databases. Special attention will be paid to the following areas: * query design * logical and physical data structures * maintenance & backup strategies

Managing a Technical Team: Lessons Learned

I got promoted to management a year ago, and despite what I previously believed, there were no fluffy pillows and bottles of champagne awaiting me. My team liked me, but they didn’t exactly stoop and bow when I entered the room. I’ve spent the last year relearning everything I thought I knew about management, and what it means to be a manager of a technical team. This session is intended for new managers, especially if you’ve come from a database (or other technical) background; topics we’ll cover will include:*How to let go of your own solutions. *Why you aren’t the model you think you are, and *Why Venn diagrams are an effective tool for management.

SQL Server XQuery: Functions (sql:variable() & sql:column())

 

Like most query languages, XQuery has several functions that can be used to manipulate and query data.  SQL Server’s implementation supports a limited subset of the XQuery specification, but there’s a lot of power in the functions provided.  I hope to cover some of those functions in more detail at a later date, but for now I’d like to focus on a couple of very specific functions (sql:variable() & sql:column()).  These are proprietary extensions to XQuery, and they (like the xml methods I previously discussed) provide a bridge between the SQL engine and the XQuery engine.

For example, if you wanted to find the value of the third node of a simple XML document in SQL Server, you could do the following:

DECLARE @x XML ='<alpha>a</alpha><alpha>b</alpha><alpha>c</alpha>'
SELECT @x.value('(//alpha)[3]', 'varchar(1)')

The .value() method would return the letter “c” in the form of a varchar to the SQL engine.  However, if you wanted to do this dynamically, and specify which node to return based on a parameter, you would use the sql:variable() function, like so:

DECLARE @x XML ='<alpha>a</alpha><alpha>b</alpha><alpha>c</alpha>'

DECLARE @node INT = 3
SELECT @x.value('(//alpha)[sql:variable("@node")][1]', 'varchar(1)')

The sql:variable() function uses a string literal (a value surrounded by double quotes) to reference a SQL parameter (in this case, @node) and concatenates it to the XQuery string.  The above query is seen as:

(//alpha)[3][1]

by the XQuery engine.  In English, we are looking for the 3rd node named alpha.  You may wonder about the extra positional reference (“[1]”) ; the .value() method requires that a positional reference be explicitly defined.  In this situation, we are telling the XQuery engine to return the first instance of the third node of the alpha node.  Seems a bit clunky, but it works.  Looking at the execution plan, we can see that this is a relatively complex process, with multiple calls between the two sides of the query processor:

image

The sql:column() function is similar, but is used to refer to a column instead of a parameter; this allows for the dynamic querying of an XML column on a row by row basis.  For example:

DECLARE @T TABLE ( ID INT, x XML )

INSERT  INTO @T
        ( ID, x )
VALUES  ( 1, '<alpha>a</alpha><alpha>b</alpha><alpha>c</alpha>' ),
        ( 2, '<alpha>a</alpha><alpha>b</alpha><alpha>c</alpha>' ),
        ( 3, '<alpha>a</alpha><alpha>b</alpha><alpha>c</alpha>' )

SELECT  ID, v=x.value('(//alpha)[sql:column("ID")][1]', 'varchar(1)')
FROM    @T

The above query will return a dataset like so:

image

Summary

SQL Server provides two functions for sharing information from the SQL engine to the XQuery engine: sql:variable() & sql:column().  The nature of these functions is pretty straight-forward; you pass the value of either a parameter or a column to an XML method, and it builds an XQuery string using the values of these functions. 

SQL Server XQuery: .modify() method

Continuing with XQuery, today’s post addresses the .modify() method against the xml data type; this method is used to update XML documents by applying one of three XML DML statements (insert, delete, or replace) via the use of a SQL SET statement.  Again, the idea is hand off the work between the XML engine and the SQL engine.  For example, given the following example:

DECLARE @X XML
SET @x = '<root><id>1</id></root>'

SET  @x.modify('insert <splat>hello world </splat>
                into /root[1]')

SELECT @x

the output of this SQL is the following XML:

<root>
  <id>1</id>
  <splat>hello world </splat>
</root>

So what happened?  We took a very simple XML document, and passed XML DML into the .modify() method which stated that we should:

  1. insert a new node “<splat>hello world </splat>” into the XML document
  2. into the first instance of the root node (/root[1]).

That’s it; welcome to the world of XML DML (Data Manipulation Language).  The syntax pattern for insert is pretty simple; action (insert) followed by an XML expression (<splat>hello world </splat> followed by the location of a second XML expression (into /root[1])With some minor variation in pattern, these elements hold true for the other two XML DDL statements (delete; replace value of):

action XML expression (1) XML expression (2) Sample
insert node {as first | as last}

into | after | before

XQuery

SET @x.modify(‘insert <splat>hello world!</splat>

                before (/root/id)[1]’)

delete node **not used** SET @x.modify(‘delete /root/splat[1]’)
replace value of node/value with value SET @x.modify(‘replace value of (/root/id/text())[1] with "2"’)

 

Of course, the variation in the pattern is what makes this set of commands a challenge to keep straight, so I’ll try to briefly explain the patterns in order of increasing complexity:

  • the delete pattern requires that a node singleton be identified for deletion.  The XML expression must evaluate to a node in the XML document that is being updated.
  • the insert pattern identifies a node to be added either into, before, or after a specific location path.  If an instance of that node already exists, you should specify as first or as last in order to place the new node in the correct sequence.
  • the replace value of requires two XML expressions; the first must evaluate to an existing value (as either an attribute or a text() value of an element).  The second must evaluate to a specific value; a later blog post will show how to use XQuery to dynamically set that value.

One more thing; these examples all use a single XML variable, and issue the SET command against it.  If you’re dealing with a table of XML documents, you can use the SQL UPDATE command to SET the XML column using this XQuery method and XML DML like so:

DECLARE @T TABLE (x XML)
INSERT INTO @T
VALUES ('<id>1</id>'), ('<id>2</id>')

UPDATE @T
SET x.modify('insert <new>sample</new>
                into /id[1]')

SELECT *
FROM @T

will return a result set like so:

image

Summary

To sum up:

  1. the .modify() method may be used either against an XML variable or an XML column in a table by using the SET statement (alone or in an UPDATE command, respectively), and
  2. there are three basic patterns for XML DML that are passed to the .modify() method, and
  3. the syntax can be confusing but allows for a great deal of fine-grained manipulation of the XML document when needed.

Cleaning up orphaned users in SQL Server

Short blog post here; I’m working with my team to clean up some older SQL Servers, and we’re removing several logins that have been dormant or disabled for some time.  Removing the logins is easy, but it leaves orphaned users in several of our databases.  I created the script below to cycle through each of the databases on the server and generate a series of DROP USER commands for each database.

DECLARE @t TABLE
    (
      db VARCHAR(100)
    , u VARCHAR(1000)
    , s INT
    )

DECLARE @sql NVARCHAR(4000)
SET @sql = 'USE [?];

SELECT  DB_NAME()
      , dp.name
      , s = CASE WHEN s.Schema_id IS NOT NULL THEN 1
                 ELSE 0
            END
FROM    sys.database_principals AS dp
        LEFT JOIN sys.server_principals AS sp ON dp.sid = sp.sid
        LEFT JOIN sys.schemas s ON s.principal_id = dp.principal_id
WHERE   dp.type IN ( ''U'', ''S'' )
        AND sp.sid IS NULL
        AND dp.authentication_type IN ( 1,  3 )
        AND dp.name <> ''dbo'''

INSERT  INTO @t
        EXEC sp_msforeachdb @sql

SELECT  'USE [' + db + ']; '
        + CASE WHEN s = 1
               THEN 'ALTER AUTHORIZATION ON SCHEMA::[' + u + '] TO dbo; '
               ELSE ''
          END + ' DROP USER [' + u + ']'
FROM    @t

If the script discovers an orphaned user, the output will look something like:

USE [AdventureWorks2012]; DROP USER [olduser]

If that user owns a schema in the database, an ALTER AUTHORIZATION step is added to first transfer the schema to dbo, and then drop the user:

USE [AdventureWorks2012]; ALTER AUTHORIZATION ON SCHEMA::[olduser] TO dbo; DROP USER [olduser]

I’m sure there are other ways to accomplish the same thing, but it works well for this task.

SQL Server XQuery: .value() method

Back to XQuery; the third method I wanted to discuss in this series is the .value() method. Like the .query() method, .value() bridges the SQL Server database engines and XQuery engines by extracting information from an XML document.  The difference is that while .query() returns XML, .value() translates the specific information requested into a scalar SQL value.  For example:

DECLARE @T TABLE ( ID INT, x XML )

INSERT  INTO @T
        ( ID, x )
VALUES  ( 1, '<root><plant><fruit>tomato</fruit></plant></root>' )
,       ( 2, '<root><plant><fruit>banana</fruit></plant></root>' )
,       ( 3, '<root><plant><vegetable>tomato</vegetable></plant></root>' )

SELECT ID, x.value('(.)[1]', 'varchar(max)')
FROM @T t

Note that the .value() method has two parameters, an XQuery statement and a string representing the expected SQL Server type for the scalar value returned.  The results are as follows:

image

So, what is the XQuery statement requesting?  The axis is referring to the self-node of the XML fragment (and remember that in SQL Server’s implementation of XQuery, the query begins at the top of the document), there is no node test (so any node will satisfy the test), and the predicate is referring to the first position [1] of the path.  The .value() function returns the value found at that location, and converts it to a sql value of type varchar(max).  So what happens if there’s more than one value at a given XPath?

INSERT  INTO @T
        ( ID, x )
VALUES    ( 4, '<root><plant><fruit>tomato</fruit><fruit>banana</fruit><vegetable>tomato</vegetable></plant></root>' )


SELECT ID, x.value('(.)[1]', 'varchar(max)')
FROM @T t

The above script inserts a slightly more complex XML document than used before; there are now multiple nodes under the <plant> node (in addition to the three rows we already have); the output looks like:

image 

Note how row 4 has a single string that represents all of the values of the XML document.  Without a specific XQuery, the value() function returns the values that satisfy the request; in this case, all of them.  In the case where the XQuery cannot be satisfied, .value() will return a NULL value to the SQL Server engine, as illustrated by the following code examples:

SELECT ID, x.value('(//plant/fruit)[1]', 'varchar(max)')
FROM @T t 

SELECT ID, x.value('(//plant/fruit)[2]', 'varchar(max)')
FROM @T t 

The output should look like:

image

In the first query, we are looking for an axis of any node in the document, a node test of fruit under the <plant> node, and a positional predicate of 1.  Rows 1,2, and 4 satisfy this query; the XML document in row 3 doesn’t have a <fruit node>, and thus returns a NULL.  The second query is similar in that several of the XML documents in our table don’t satisfy the query; only the document in row 4 has node in the second [2] position of the <fruit> node.

Summary

Key takeaways:

  1. The .value() function allows you to specify an XQuery statement against an XML datatype looking for a specific value, and
  2. that returned value is cast to a SQL datatype.

Next up: .nodes()

SQL Server XQuery: .query() method

Continuing in my discussion of XQuery in SQL Server, let me discuss another XML data type method: .query().  The .query() method is a great illustration of the bridging concept I discussed earlier.  Simply put, this method allows you to run an XQuery against the XML data type, and return the results of that query as an XML document to SQL Server.  Using our example from the .exists() post:

DECLARE @T TABLE ( ID INT, x XML )

INSERT  INTO @T
        ( ID, x )
VALUES  ( 1, '<root><plant><fruit>tomato</fruit></plant></root>' )
,       ( 2, '<root><plant><fruit>banana</fruit></plant></root>' )
,       ( 3, '<root><plant><vegetable>tomato</vegetable></plant></root>' )

SELECT x.query('.') 
FROM @T 

Note that the parameter supplied to the method is an XQuery statement consisting of a single axis (.), which refers to the current node.  Since SQL Server’s implementation of XQuery starts at the top and works it’s way down the document, the current node is the entire document.  Running that query will give you the following output:

image

which isn’t very exciting.  However, if we begin to build out a XPath statement with a node test and a predicate, we can begin to narrow down the results quickly:

SELECT ID, x.query('.//fruit[text()="banana"]')
FROM @T t

And here’s the results:

image

While the results may be simple, there’s a lot going on behind the scenes, and it may have returned something different than what you expected.  Remember that when you execute an XQuery method against an XML column, there’s actually two queries happening:

For the XQuery portion, the XPath axis, node test, and predicate specified that we were looking for an XML node that was a fruit and had a value of a banana; this only existed in the XML in row 2, so the node was returned for row 2, but row 1 and row 3 were empty.  The SQL query then ran, and returned all rows in the table because there was no WHERE clause filtering the results.  If we only wanted to return the results where the XQuery returned a node, we could move the .query() method to the where clause.

One thing to always remember is that regardless of how specific your XQuery is, the type of the data being returned will always be XML.  For example, if you specify the text() function as part of the axis, and not the predicate:

SELECT ID, x.query('.//text()')
FROM @T t 

You’ll get what looks like a table with a column of character values representing the values of the various nodes:

image

However, the visual representation of the result set uses hyperlinks to indicate that it’s an XML column; if you click on the value (banana), the XML explorer will open up, showing you that it is an XML fragment, albeit one that has no tags.  If you need to return the data as the actual datatype, you’ll either need to use a SQL method (like CAST or CONVERT), or the .value() method (to be discussed soon).

Summary

Wrapping up with a few key points:

  1. The query() method allows you to specify an XQuery statement against an XML document, and
  2. It always returns an XML document.

SQL Server & XQuery: XPath Axes, Node Tests, and Predicates

In order to really get a grasp on what’s going on within an XQuery method in SQL Server (like .exist()), we need to examine the relationship between XQuery and XPath.  Semantically, there’s little difference in the usage of the two names, since XQuery as a language uses XPath to navigate through an XML fragment; however, strictly speaking, XPath is a subset of XQuery. 

XPath expressions contain one or more of three elements: an axis, a node test, and a predicate.  An axis refers to the locational reference of a path when navigating an xml structure.  For example consider the following XML:

<root>
  <plant>
    <fruit>tomato</fruit>
    <fruit>banana</fruit>
    <vegetable>tomato</vegetable>
  </plant>
  <animal>
    <canine>Doberman</canine>
  </animal>
</root>

and the XQuery below:

/root/plant/fruit

based on the axis (path) supplied above, the results will be the two <fruit> nodes in the XML document.  It’s important to remember that in the SQL Server implementation of XPath, axis expressions always start at the top of an XML document and work down, but there are some navigational shortcuts.  Below is a small table describing the axes supported:

Abbreviation Full Syntax Notes
/ / steps through nodes
// // steps through all descendant nodes
  child returns a specific child of a given node; e.g. /root/child::plant is the same as /root/plant
.. parent steps up a node; .. equivalent to parent::node()
@ attribute identified attribute-based XML
. self refers to the current node
* * refers to all nodes at the current level; e.g. /root/* will return both the <plant> and <animal> nodes from our previous example.

A node test is a part of the location path that when used with an axis restricts the XQuery to return only the results of interest. Taking our same XQuery from above:

/root/plant/fruit

The axis is the “/” symbol which tells XQuery to walk down a node at a time, and there are two node tests: plant, and fruit.  The first node test tells XQuery to only look at the plant nodes, and the second node test restricts it to just the fruit nodes.  The above XQuery could be shortened to:

//fruit

All nodes would be considered, and all fruit nodes would be returned, regardless of where they live in the XML hierarchy. 

The final expression in XPath is the predicate; a predicate limits the results of an XPath expression through evaluation (much like the WHERE clause of a SQL statement).  Predicates are specified using square brackets, and allow for the use of several functions to return either a positional reference or an evaluation of a value or node.  For example, the results of the following two XQuery expressions against our test XML document:

//fruit[2]

//fruit[last()]

would return the same positional results:

<fruit>banana</fruit>

likewise, the XQuery expression below:

//fruit[text()="banana"]

also returns the same results.  last() and text() are both XPath supported functions, and are part of the subset supported by Microsoft SQL Server.

Summary

Why is all of this important?  It’s dry, I know. However, the foundations of XPath allow us to do some pretty powerful querying of XML before handing the results “across the bridge” to SQL Server.  Now that we’ve got the basics identified, we can continue our previous discussion of the XML methods in SQL Server.

SQL Server XQuery: .exist() method

I’m trying to beef up my writing about XQuery in advance of the upcoming PASS Summit 2013; I got accepted to present, and I want to make sure that I start covering a lot of topics related to XML so that I’ve honed my focus a bit.  Unfortunately, blogging doesn’t come easy to me these days, and while I would generally start a session from the beginning and move forward, I think it would be best for me to start with something easy for me to write about, even though it means I’ll be doing a bit of backtracking later.

A little bit of background

As you may already know, SQL Server supports XQuery against an XML data type through the use of five basic methods:

  • .query()
  • .value()
  • .exist()
  • .modify()
  • .nodes()

Conceptually, each of these methods act a bridge between the the SQL processing engine and the xml parser baked into SQL Server.  This concept of a bridge allows me to think about where query work is being performed; is it being done as a SQL statement against the table containing the XML fragment of interest, or is it being performed by XQuery before bubbling up to the SQL level? 

image

.exist()

I want to focus on probably the easiest method against the xml datatype: .exist().  Simply put, this method checks to see whether or not the results of an XQuery expression against the supplied XML value are nonempty; it returns 1 if true, and 0 if false.  Let’s start with a simple sample:

DECLARE @T TABLE ( ID INT, x XML )

INSERT  INTO @T
        ( ID, x )
VALUES  ( 1, '<root><plant><fruit>tomato</fruit></plant></root>' )
,       ( 2, '<root><plant><fruit>banana</fruit></plant></root>' )
,       ( 3, '<root><plant><vegetable>tomato</vegetable></plant></root>' )


SELECT ID, X, x.exist('//root') AS "Does It Exist?" 
FROM @T 

Running this query will return the following results:

image

Every row has an XML value in the X column which contains a node named <root>.  We can change the output to identify rows which have vegetable nodes like so:

SELECT ID, X, x.exist('//root/plant/vegetable') AS "Does It Exist?" 
FROM @T 

The results then change to the following:

image

.exist() can also be used in the WHERE clause of a SQL statement; if we want to identify only the rows which have an XML fragment containing a tomato, we can alter the SQL statement like so:

SELECT ID, X  
FROM @T 
WHERE  x.exist('//.[text()="tomato"]') = 1

image

Note that the .exist() method interpreted an XQuery statement to look for nodes which had a text() value of “tomato”; two rows matched that requirement, so .exist() returned a 1 for those two rows to the calling SQL statement, and the WHERE clause identified those two rows.

Wrap-up

So, I’ve covered a few basic concepts while talking about the .exist() method:

  1. The xml methods act as a bridge between XQuery and SQL for the xml data types.
  2. The .exist() method supports XQuery expressions including both simple paths (//<node name>) and XQuery functions (e.g, text()).  This will become important later when I get around to discussing FLWOR.

What’s your mantra?

I worked really hard to line up the window so I could get that nice illumination look.I’ve been busy lately making the shift from “hands-on engineer” to “hands-off manager”; it’s been tough, because I’m not accustomed to stepping away from a problem and letting someone else figure it out.  Even though I’ve got an education background, and have been (inconsistently) involved in technical communities helping other people solve problems, I’ve never had to balance the responsibility of making sure that a job gets done with the responsibility of allowing someone to “learn from their mistakes”.  It’s harder than I thought.

As part of my management training, however, I’ve been focusing on laying out principles and guidelines rather than specifics; for example, instead of saying something like:

We need to make sure that John Smith has limited access to that database; can you do that for me?

I’m trying to say something like:

Our databases need to be secure, and that includes differentiation in access based on job roles.  Can you verify that all accounts are set up using that model?  If there are exceptions, can you document why?

The idea is that a) I need to trust that the people that work for me know how to do their jobs, and b) I need them to start aligning their practices with the principles that I think should drive our work.  I realize that last statement sounds a bit tyrannical, but in reality, I trust my team to help me develop those principles.  However, it’s my job to provide the direction, and their job to keep the boat afloat.

As part of this exercise, I’ve begun to realize that I’ve had a worldview for several years that I’ve always fallen back on when it comes to solving problems.  I’ve never thought of it as a mantra before, but the truth is that the following statement sums up my approach to most problems.

Simple is best.

When I encounter a challenge, and am forced to figure out a solution, I always fall back on the thought that a simple solution is usually the best one.  When I’m face with deciding between option A and option B, I’m usually going to lean toward the one with the fewest moving parts, even if it doesn’t address every possible outcome.  I’m a big fan of things like the 80/20 rule, and Occam’s Razor; it’s far easier for me to tackle problems in bite-sized chunks.  It’s the first principle by which I evaluate any solution that my team presents; if it’s not simple, it’s not manageable in my opinion.

Not everyone I work with is oriented toward simplicity; one of my best friends (I’ve worked with him for 9 years) often chooses beautiful and thoroughly complex solutions to problems.  I don’t know if could express what his mantra is, but I’d bet it would involve something about slicing and dicing problems into small pieces.   I also work with another guy who loses me in jargon in every discussion; he’s very passionate about writing code that covers every scenario, even if it takes 6 months to a year to do so.  I have a tough time thinking like that.

Mantra’s can be positive or negative.  For example, two of my former managers had different mantras that they relied on; one manager used to say:

Never make a person do what a computer can do for them. 

That helped guide us when making a decision on work priorities; if you’ve got someone cutting-and-pasting information from your application so that they can send an email, and they have to do that on a consistent basis, then you probably need to write some sort of hook into your application to let them use their email program from your app.  If you’re hiring staff because of the uptick in workload, then you should probably figure out ways to reduce the amount of work using computing power.

The other manager (different company; different time in my career) used to chant:

Whoa, whoa, whoa; that’ll delay the project.

which made us all think that that the project was more important than actual details.  It was a joke; the slightest interruption or shift in perspective would tip the entire apple cart.  His inflexibility was legendary, and ultimately led to the loss of his entire staff (before he was eventually sent packing).

What’s your mantra? Do your teammates or employees know it? Does it contribute to the work effort, or has it become a tired joke among your colleagues?

#TSQL2sDay.. For Whom Do You Log?

This month’s T-SQL Tuesday is being hosted by Aaron Nelson [blog | twitter]; since I’m posting this late in the day, I got a chance to sneak a peek at some of the other entries, and most of them were great technical discussions on how to log, what to log, and why you should log.  I’m not feeling technical today; today’s a conceptual day.  So, rather than write about the pros and cons of logging, I thought I would ask you to step back and consider who is your audience?

At my company, we monitor logs for our customers; I’ve had to reverse engineer a bunch of different log formats in my day, and there are some basic principles behind good logging practices; here’s my stab at them:

1. Logging without analysis is useless storage of information.

I realize that our jobs as data professionals have gotten more exciting because of policy requirements that insist upon the storage of all kinds of information for exceedingly long periods of time.  I recently read a requirement that said a company must maintain source code for 20 years; that’s a heckuva long time to keep a log of changes around.  Unfortunately, if no one ever looks at the log, then why store it?  If you’re going to be storing information, you need to have some process that consumes that information in order to get the most value out of it.  Good logging processes assume that someone will be reviewing the log at some point, and using that information to act. 

2. Logging structures should be flexible.

If you are logging information with the mindset that someone will be reviewing the log in the future, then you need to balance precision (i.e, gathering adequate information to describe the logged event) with saturation (don’t over-log; not every event is always important).  For example, if you’re building an audit log to track changes to a customer account, you want to be able to isolate “risky” behavior from normal account maintenance.  If your logs become lengthy result-sets filled with change statements, it’s easy to overlook important events such as a bad command.

Most logging structures attempt to overcome this by having some sort of categorical typing appended to the log; in other words, if we think in tabular terms, the columns of a log dataset might look like:

  • DateOfEvent – datetime
  • Category – Classification of the event (Error, Information, etc)
  • Severity – Some warning of how important the event is
  • ErrorCode – Some short (usually numeric) code that has meaning extrensic to the system
  • Message – The payload; a string description of what happened.

It becomes relatively easy to isolate the error messages from informational messages; however, how do you search non-categorical information with the message itself?  For example, if you want to determine that there was a specific error code associated with a specific logon, and that logon information is embedded in the message of your log file, how do you search it?  The easy answer is to use wildcards, but is there a better way?  In my experience, good logs use some form of intra-message tagging to isolate key elements within the message; the log file remains simple for quick searches, but can easily be adapted for more in-depth searches.  I like XML attributes for payload logging; it’s easy to implement, and can be parsed quickly.  For example:

acct=”Stuart Ainsworth” msg=”Access Denied” object=”SuperSecretPage.aspx”

is an easy message to shred and look for all denied attempts on SuperSecretPage.aspx.  If I wanted to look for all activity by Stuart Ainsworth, I could do that as well.

3.  Logging should have a maintenance plan.

If you log a lot, you know that logs fill up quickly.  How long do you retain your logs (and the answer shouldn’t be “until the drive fills up”)?  Too much information that is easily accessible is both a security risk and a distraction; if you’re trying to find out about a recent transaction by a user, do you really need to know that they’ve been active for the last 10 years?  Also, if your log file does fill up, is your only option to “nuke it” in order to keep it running and collecting new information?

A good logging strategy will have some sort of retention plan, and a method of maintaining older log records separately from new ones.  Look at SQL Server error logs, for example; every time the service starts, a new log file is created.   Is that the best strategy?  I don’t think so, but it does isolate older logs from newer ones.   If you’re designing a logging method, be sure to figure out a way to keep old records separate from new ones; periodically archive your logs, and find a way to focus your resources on the most recent and relevant information.