What is the Performance Cost of Logging?

So, I’m trying go back through a large program and optimize it as much as I can. One thing I am looking at is logging.

When I first launched the program, I had it logging info from most routines so that I could find bugs more easily. That certainly did it’s job, but after 3 years of use, I’ve identified 99% of the potential problems.

So, I reduced the logging quite a bit, but even after that, it still logs about 400,000 entries a day because many more users have begun using it.

I plan on making another round of logs optional, but I began to wonder how much actual CPU/hard drive overhead logging takes in terms of server performance.

Anybody thoughts?

the biggest slow down for logging is the writing of the data to the disk(s). other things facture in to but that is the biggest one.

I would put all the login in an if Debugging then …. block so you can turn debugging back on by flipping a variable (boolean false to true). that way you can have all the logging when you need it and have it off for everyeone else.

I like to take this a step further: I wrote a logging class that handles all my logging, and it has several different levels of logging: info, error, warning, critical, etc. That way I can set up a preference to expose as much or as little logging as I like. While I’m writing the app, if I’m in an area that may generate a nasty problem, I’ll mark those messages as critical. If I’m just handling a normal event that I want to keep track of, that would only log at the info level.

YMMV, but you may want to consider consolidating all your logging through a central system such as this.

[quote=411731:@Kimball Larsen]I like to take this a step further: I wrote a logging class that handles all my logging, and it has several different levels of logging: info, error, warning, critical, etc. That way I can set up a preference to expose as much or as little logging as I like. While I’m writing the app, if I’m in an area that may generate a nasty problem, I’ll mark those messages as critical. If I’m just handling a normal event that I want to keep track of, that would only log at the info level.

YMMV, but you may want to consider consolidating all your logging through a central system such as this.[/quote]
I have a centralized logging class myself. but I wrap everytime I might log something in a If Debugging Then… clause so I can turn on/off the debugging at will.

Thanks. I created a ‘verbose’ level a while back that I can turn off, but I may consider adding additional levels to it like you mentioned so I can increase it again if needed.

I figured out that at 400-500K logs a day, with most of them during daylight hours, it’s probably writing 10+ statements a second. That seems to be a lot of hard drive access. I’m definitely going to address it.

[quote=411730:@scott boss]the biggest slow down for logging is the writing of the data to the disk(s). other things facture in to but that is the biggest one.

I would put all the login in an if Debugging then …. block so you can turn debugging back on by flipping a variable (boolean false to true). that way you can have all the logging when you need it and have it off for everyeone else.[/quote]

Hmm But maybe you want an end user to log if an issue arises… So maybe a preference might be best?

And in those cases I wonder if using IPC with a helper App that does the actually writing to disk might alleviate the slowdown when it is needed…

Probably overkill…

Anyway just musing on possibilities as its not something I need.

That is quite a bit of disk access. Why not log to a data structure in memory, which is periodically flushed to disk?

Yeah, that’s fantastic for when I’m running the app on my development machine, but I needed something that was more robust so I could turn logging on / off on my customer’s computers without providing them a new build or remote debugger session.

My logging levels are progressively more verbose: Info logs everything, warn only warnings and higher, error only errors and higher, and so on.

Additionally, I can turn the output from the logger completely on or off, and I can have it log only to the system log utilities, or log to its own file (at different levels as needed). Since I can dynamically change the logging levels, my users can turn it up and down (or I can log into their computers and do it for them) which is helpful in isolating bugs I cannot reproduce on my own.

I wish that I had implemented something with that level of detail from the beginning. It would have made it much easier. Someone needs to write a Xojo book that includes example routines for all the really practical things like this

That is why the pay us the big bucks ;-). If only…

My dream would be a version of SmartImspect or CodeSite for XOJO. Both of which I have used before in the day job.

Unfortunately these things takes years to mature and requires a significant time investment to become commercial.

Another option is to use a computed property so you can set an environment variable and use a computed property to read that env var and enable debug logging or not without even having to recompile. And it can be set once at app start up and just reused from then on as follows:

Computed Property Debugging as Boolean
    Get
           static setOnce as boolean
            static retValue as boolean
           if  not setOnce then
                setOnce = true
                retValue = System.EnvironmentVariable("Debug") = "True"
           end if
           return retValue
   end get

And you could set the debuglog level similarly.