Almost all services need to write to a log for auditing purposes. When these services require high throughput this write to disk can be a real bottleneck.
So, I wrote a simple log package that implements asynchronous logging to standard output. I only ever write to standard out for service logs. For me redirecting to a file from the command line has proven too flexible over the years to even consider named logs.
Here is the ad/log package:
/*
Package log implements standard logging functions for logging to standard out
*/
package log
import (
"log"
"os"
"fmt"
"strings"
"time"
)
var myLog *log.Logger = log.New(os.Stdout, "", log.Ldate+log.Lmicroseconds)
var (
AsyncBuffer = 1000
asyncLogging = false
asyncChannel chan string
)
//Print message to standard out prefixed with date and time
func Print(s string) {
if asyncLogging {
s = "(" + strings.Fields(time.Now().Format(time.StampMicro))[2] + ") " + s
asyncChannel <- s
} else {
myLog.Print(s)
}
}
//Enable / disable asynchronous logging
func EnableAsync(enable bool) {
if enable == asyncLogging {
return
}
if enable {
asyncChannel = make(chan string,AsyncBuffer)
go func() {
for {
message, ok := <-asyncChannel
if ok {
myLog.Print(message)
} else {
asyncLogging = false
return
}
}
}()
} else {
close(asyncChannel)
}
asyncLogging = enable
}
//Returns current asynchronous logging value
func Async() (bool) {
return asyncLogging
}
Here is a simple example:
package main
import (
"fmt"
"time"
"ad/log"
"ad/utl"
)
var i = 0;
func main() {
utl.UseAllCPU()
incAndPrint()
log.EnableAsync(true)
for {
incAndPrint()
incAndPrint()
fmt.Printf("Doing my own thing\n")
incAndPrint()
time.Sleep(1e9)
}
}
func incAndPrint() {
i += 1
log.Print(fmt.Sprintf("%v",i))
}
Output looks like this:
~/go/src/ad/misc$ go run logT.go
2012/05/22 15:39:26.229273 Running log 1.2.1
2012/05/22 15:39:26.229771 Running utl 1.0.0
2012/05/22 15:39:26.229812 Setting UseCPU from 1 to 4
2012/05/22 15:39:26.229874 1
Doing my own thing
2012/05/22 15:39:26.230098 (15:39:26.229989) 2
2012/05/22 15:39:26.230151 (15:39:26.230035) 3
2012/05/22 15:39:26.230163 (15:39:26.230092) 4
Doing my own thing
2012/05/22 15:39:27.230701 (15:39:27.230555) 5
2012/05/22 15:39:27.230761 (15:39:27.230612) 6
2012/05/22 15:39:27.230775 (15:39:27.230696) 7
Doing my own thing
2012/05/22 15:39:28.231295 (15:39:28.231143) 8
2012/05/22 15:39:28.231356 (15:39:28.231203) 9
2012/05/22 15:39:28.231369 (15:39:28.231262) 10
For me the power of this painfully simple package comes when we code log.Print and take the value of the log.asyncLogging flag from a command line switch. This allows you to code in a standard fashion but run individual service instances up with a dedicated logging goroutine if entering a busy period. Alternatively, the log.asyncLogging flag could be set on the fly when the service decided; say when demand is high.
