How to work with concurrent logs in golang?

Question

I've searched for it and only found here and here, but it does not solve my problem.

How can I, using a standard way, identify the log separating the concurrent logs like JAVA does with thread ID? Because if I have a concurrent method then the logs will be printed mixed at the output, so I think that the LOGGER needs to have a way of identifying each request "thread"

Ex:

package main

import "log"

func main() {

    /* simulating 10000 users requests  */
    for i:=1; i < 10000; i++ {
        go getHello(i)
    }
}

func getHello(d int){
    log.Printf("m=getHello, i=%d,begin", d)
    log.Println("m=getHello, processing the hello message")
    log.Printf("m=getHello, i=%d, end", d)
}

output

2016/07/29 15:59:46 m=getHello, i=1017,begin
2016/07/29 15:59:46 m=getHello, processing the hello message
2016/07/29 15:59:46 m=getHello, i=1017, end
2016/07/29 15:59:46 m=getHello, processing the hello message
2016/07/29 15:59:46 m=getHello, i=1038, end
2016/07/29 15:59:46 m=getHello, i=311,begin
2016/07/29 15:59:46 m=getHello, processing the hello message
2016/07/29 15:59:46 m=getHello, i=311, end
2016/07/29 15:59:46 m=getHello, i=1023,begin

As you can see, without using an int flag, it is impossible to know which request logged a message. In Java and C for example you can use thread id for this purpose.

How to achieve this in Golang? Thanks.

Answer 1

There's no goroutine ID available from the runtime. Goroutines are used more liberally than threads in other languages, so the idea of which goroutine is handling a particular request or item may be less well-defined in a larger program.

So somehow you need to pass through an ID yourself for logging. You could just pass through an int yourself, but the context module is handy for this: apart from allowing user-defined values, it can handle item cancellation and deadlines which are also likely to be useful to you.

Here's a rough example of how it might be used. I've added a simple logging object that can be used as a context-aware logger. It logs the ID the context was created with. Probably this logger would go in its own package in a real program and support more of the log package's functions rather than just Printf and Println.

package main

import (
    "fmt"
    "log"
    "sync"
    "context"
)

type logger int
const loggerID = "logger_id"

func (l logger) Printf(s string, args ...interface{}) {
    log.Printf("[id=%d] %s", l, fmt.Sprintf(s, args...))
}

func (l logger) Println(s string) {
    log.Printf("[id=%d] %s\n", l, s)
}

func ctxWithLoggerID(ctx context.Context, id int) context.Context {
    return context.WithValue(ctx, loggerID, id)
}

func getLogger(ctx context.Context) logger {
    return logger(ctx.Value(loggerID).(int))
}

func main() {
    ctx := context.Background()
    var wg sync.WaitGroup
    for i := 0; i < 10; i++ {
        wg.Add(1)
        go hello(ctxWithLoggerID(ctx, i), &wg)
    }
    wg.Wait()
}

func hello(ctx context.Context, wg *sync.WaitGroup) {
    defer wg.Done()
    log := getLogger(ctx)
    log.Printf("hello begin")
    log.Println("hello, processing the hello message")
    log.Printf("hello, end")
}

It's incidental to your question, but I added a sync.WaitGroup to your program so that main will wait until all of the workers are finished before exiting. That allows the code to be tested with a smaller number of workers (10 rather than the original 10000).

Answer 2

goroutines are very different from threads or even processes. They are managed by the go runtime and not your operating system. If you do some really heavy lifting it is even possible that the same goroutine jump between processes, therefore it is hard to give them unique IDs.

For you example using the given int is perfectly fine, since every goroutine only processes one number.

Answer 3

If you don't want to pass some int in every goroutine, then you can try to generate random number in it with math/rand package inside goroutine iself. If number will be high enough (depends on your load), then you'll get some kind of goroutine ID.

You can find examples of random number generating here.

You can also print it in hex, so it will be easy to distinguish that id from other int values you may have in program.

This should do the trick:

log.Printf("m=getHello, i=%#x,begin", d)

EDIT: Also if you want to be sure your id is unique in each goroutine, then you can add some global counter and increment it in each goroutine.

import sync

var txCounter int
var counterMutex = &sync.Mutex{}

for {
    go func() {
        id := txCounter
        counterMutex.Lock()
        txCounter++
        counterMutex.Unlock()
        log.Printf("m=getHello, i=%#x,begin", id)
    }() 
}