Opinionated Trace

The problem with trace-debug-loggers (I’ll call it trace from now on) is that anything goes. I’m going to try to use the System.Diagnostics namespace with the extensions on codeplex.

Trace is a story, it is the moment to moment diary of the application. The audience of trace is a developer. They want to know what the application is doing. Computers do a lot, so trace volume will have to be carefully managed.

Thou shall not trace in production, unless you have to.
Trace can be expensive. I took a representative 1000 repetition integration test that ran in 1/2 second and turned on verbose logging with DebugView running, and it took 17 seconds. This is why there should be some thought put into logging levels and why there should be multiple trace sources, so that most of them can be off most of the time.

Thou shall be very wary of logging to the same transactional database as the application.
Jeff had a bad experience with this kind of logging and decided to throw the baby & bath water out. I think they just needed to rethink what trace’s promise and possibilities really are.

Thou shall use a TraceSource per class.
There should be a trace source per class. Typically we’re debugging a few classes at a time and turning off the other trace by commenting it out isn’t a practical solution.

Thou shall not use System.Diagnostics.Trace or System.Diagnostics.Debug
Use TraceSource instead. You can’t turn off these sources as easily as a TraceSource

Thou shall not reinvent System.Diagnostics. Extend it. Resist using other people’s re-inventions. Do use other people’s extensions
Trace is for maintenance developers. A maintenance developer shows up on the scene and the last thing they want to see is yet another custom solution for a solved problem. How excited would you be to find a code base that shunned System.IO’s file system API and used an entirely custom one? Your app has a bug. You have one problem. You find out all the trace is written using a odd ball trace infrastructure. Now you have two problems.

Thou shall not do start/end trace with nothing inbetween
Entry exit should be recorded for things that have multiple traced steps. If there is nothing in between start/end, it shouldn’t be added to the story *unless* you are doing performance. If you are recording enter/exit, you should also record the amount of time. You should use a Dispose patter to ensure that the End is written.

Thou shall write a unit/integration test that is has been tuned for a good trace story.
The trace story should be shorter than a novel, longer than a flippant comment.

Thou shall not write a Error trace unless we know it will also be error logged via Elmah or the like
Trace is not error logging. The maintenance developer is obliged to look at the error log, Trace is only on occasionally and even after tuning could have too much info.

Thou shall educate the maintenance developer on how to use the existing trace
The .NET framework has a couple of trace sources. To get at them, you have to just know that they exist. There isn’t an easy way to query an assembly and ask it what trace sources are there and what switches it takes to activate them.

Thou shall look for opportunities to replace comments with trace
We don’t want code to become less readable because of trace. So apply the same reasoning about deciding when to comment to when to log (don’t log the obvious, like most variable assignments)

Thou shall not focus on domain specific events
These would be things like “John editing record B”, or “Sold book to customer Q”.

Thou shall use trace as sort of a poor mans Method-was-called Assertion
For example, if you are caching an expensive value, then on first call, there should be a trace message from the CreateExpensiveValue method and on the second go round there shouldn’t be any trace message. But unlike a unit test, the assertion is verified by a developer reading code. This shouldn’t be a substitute for using mockign frameworks.

Thou shall not bother with Warn. Just use Error and throw an Exception.
Warnings need to have an audience and trace doesn’t always have an audience. Exceptions have an audience. And when an exception is thrown, we may want to add that to the story, since trace and error logs aren’t necessarily going to be together.

Thou shall not bother with Verbose. Just use Info
Lets say I write a trace and I call it information. Years later it is in a tight loop that is executed 10 times a millisecond. You can’t control or predict in advance if a given message is info or verbose.

Thou shall see the link between Trace and step through
Ever step through code that kept going throw a 3rd class and you though, I wish this would stop stepping through that class? You could add attributes (and remember to remove them later) or you could switch to a trace strategy that allows you to turn off trace for the likely-just-fine class.

Rude and Passive Aggressive SQL Error Messages

First off, some people are just “rude-deaf” It doesn’t matter what rude language or actions one complains about and they say, “No that wasn’t rude, the error message only said ‘Fuck you and your grandmother’”

Second, you don’t have to have an error message that says “Fuck you and your grandmother” to be rude. Most error messages crimes are being unhelpful and passive aggressive (i.e. hostility through doing nothing, like just watching someone on crutch struggling to open a door)

Incorrect syntax near ‘%.*ls’.
This message typically is filled in with something like , or ‘ A typical query is choc full of commas. Only a passive aggressive human would tell someone, “There is a spelling mistake in your term paper near one of the spaces” SQL error messages tend to identify the location of a syntax error by a chunky measure, maybe the statement, so the error could be anywhere inside a 1000 line SQL statement. And if the syntax error could provide the previous 100 and succeeding 100 non-blank characters with a pointer at where SQL first realized something went wrong, that would be helpful.

Warning: Fatal error %d occurred at %S_DATE. Note the error and time, and contact your system administrator.
First off, the people who read this either are the administrator, or there isn’t an administrator. You might as well swap in some other imaginary figure, like god. “Fatal error. Pray to your gods, fucktard”

The type ‘%.*ls’ already exists, or you do not have permission to create it.
Oh SQL, you know why this failed. Surely there isn’t a single method called ExistsOrLacksPermissions and the implementers just can’t decide why that exception was thrown. I think this error is rude or fucked up. You decide.

Finally, be helpful.
Is it really so hard to write a suggested fix? “Permission denied, execute “GRANT” command to grant permissions”

Google exists, who ever is working on MS-SQL ought to google all their own messages and just put a sentence worth of the internet’s collective advice into their error message.