Effective Logging in ASE

[Former Member]

How do other people do logging in large systems on ASE ?

There are a couple of mechanisms that are commonly used and another less common

1) print messages

     eg           print "%1! %2! Rows affects %3!", @datetime, "LOGLEVEL-DEBUG", 100000

   Pros:

      i) At the simple level print are simple and very effective. Best feature is being able to cope with different datatypes.

      ii) When you run the proc manually, then you see the output immediately without any changes.

   Cons:

     i) Looking through these logs is very awkward. If you're producing a few hundred log files each day each with a few gig of information

2) table logging

    Simply adding message to a table

          insert into LogTable select convert(varchar, @datetime) +  "LOGLEVEL-DEBUG" + convert(varchar, 10000)

     Cons:

          i) Awkward to develop against - datatypes must be converted to char.

          ii) Contention on the log table.

          iii) Performance hit

3) syb_sendmsg

    Sends a message out of the db to a listener for that to log.

     Pros:

     i) No contention

     ii) No performance hit

     Cons:

     1) Awkward to develop against. Datatypes must be converted to char

We wanted to make our logging configurable so that all logging would go through a single proc which could then log in different ways.

However, its really awkward to handle the different datatypes. Either the calling proc must spend ages converting everything to a char or

the proc must access lots of different types of datatypes and then try and form a string based on the inputs.

What we really want is the equivalent of sprintf (select @s = sprint "%1! %2!", @datetime, "STRING" ?

So how do people develop a simple and configurable logging mechanism ?

Does anyone have any good idea on implementing this ?

[Former Member]

> - the dataserver has to make a remote call (small performance hit); probably not something you'll want to do in a high-volume logging situation

True but the performance hit of sending a record over a UDP message is less than a write to the SAN and at least the UDP message isn't likely to content on SAN or cache etc. Besides I don't really want the main db server to hold millions of lines of messages.

> - what happens if the 'listener' is down (syb_sendmsg either errors out or hangs?)

No its a UDP message. Connectionless and "unreliable" which is fine of logging and messages.

In practice I used these messages a lot and so long as you're only a switch away from the server very little is lost.

> - does the 'listener' serialize its incoming messages (eg, what happens if multiple dataserver processes are sending a (relatively) large volume of messages in a short period of time => lengthy delays as messages queue up for the 'listener'?

Its just a UDP message but in general you don't send long message over this. Less than a network packet size and you're ok.

The delivery isn't guarantteed but that fine for our requirements and also that why we want to make it configurable so important message are stored in tables and minor message aren't stored.

Agree with all your other comments except "Writing an OS-level process (eg, shell script) to process the log files should be trivial."  We have a grid of 20 grid machines each running 16 processes, add into that 4 application servers, 2 web servers and spread it all over 2 countries. Trivial it is NOT!!!

And Yes it would be easier if we were developing the application from scratch but most applications we see have been around for years and years. So changing thousands of stored procs isn't a small task.

Even if we were only using print - it would be better to create a wrapper around it to standardize our calls so they call match the same format and all done in the same way.

[former_member182090]

Table logging is transactional, so it won't work as expected when a ROLLBACK is performed. IMO this is therefore not an option.

A non-transactional variation is possible though by using a proxy table mapped to an O/S file. This is non transactional, and you have the logged msgs directly in a file as well. There will likely be some performance overhead though so you'd need to check that for very intensive scenarios.

Another item missing from the list is using dbcc logprint or dbcc printolog (pints strings to the ASE errorlog, this can sometimes be useful).

As for syb_sendmsg, I think I recall there is little overhead as this is pretty lightweight (it's UDP , not TCP). But you need a listener on the other side, which has disadvantages,

[former_member188958]

It is possible to do non-transactional table logging using a traditional (non-CIS) RPC call to a loopback server entry.

[Former Member]

> Table logging is transactional, so it won't work as expected when a ROLLBACK is performed. IMO this is therefore not an option.

Agreed. We only use this for logging successes. We handle errors in the client code.

> A non-transactional variation is possible though by using a proxy table mapped to an O/S file.

These are banned where I work (I've never been anywhere where they're allowed ? Does anyone use them?)

And even if they weren't banned we couldn't use them as we can't log on to the database server.

> Another item missing from the list is using dbcc logprint or dbcc printolog (pints strings to the ASE errorlog, this can sometimes be useful).

Maybe useful for some poeple but we can't really log the number of message we want this way.

> As for syb_sendmsg, I think I recall there is little overhead as this is pretty lightweight (it's UDP , not TCP). But you need a listener on the other side, which has disadvantages,

That's true but there are many logging systems which do this anyway.

In fact syslogd uses this so in theory everyone could get this for free. One place I worked had a team of people who would do overnight call outs if they received a UDP message. Splunk uses UDP. I've seen mindalign connection build using it. (I think this is the one feature that MS-SQL hasn't implemented)

[former_member182090]

True, that should also be in the list. The overhead is probably sizeable though.

[former_member182090]

You can also read such a proxy-table-file though the proxy tab itself.
And yes, I've seen this used in practice.