Skip to content

Custom receivers

goodsign edited this page Jun 11, 2015 · 15 revisions

Seelog tries to provide you with the most popular receiver options like: file (simple/rolling), console, network connection, etc.

But sometimes you run into a situation where you either have non-seelog logging system and want to use them together (e.g. Google App Engine) or you want to implement another receiver (e.g. syslog).

To provide you with a possibility to implement another receiver or create an adapter for another logging system, seelog has several techniques:

  • seelog.LoggerFromWriterWithMinLevelAndFormat without xml config (Scenario 1.1)
  • seelog.LoggerFromCustomReceiver without xml config (Scenario 1.2)
  • seelog.LoggerFromConfigAs... with xml config and seelog.RegisterReceiver called for custom receivers (Scenario 3.1)
  • seelog.LoggerFromParamConfigAs... with xml config and CfgParseParams.CustomReceiverProducers set before parsing (Scenario 3.2)

Each of these techniques is best used in a typical scenario. There are several such scenarios, that are described below.

Custom scenarios

Scenario 1: seelog as a proxy

This is the scenario when you use seelog in all your code, but under some circumstances, want to just redirect all its output to another logging system. For example, you'd like to leave seelog calls there to be able to return to its functionality later, but currently you would like to just use it as a proxy.

In this scenario, seelog doesn't use any of its filter/dispatching functionality and just stands as a proxy.

There are two sub-cases of this scenario:

Scenario 1.1: Proxy to a simple writer

In this scenario, you redirect all seelog output to something really simple, that can be fully described by the io.Writer interface. For such cases, you should use seelog.LoggerFromWriterWithMinLevelAndFormat. It takes an io.Writer, format, and a minimal log level as the only parameters. Minimal log level gives you the possibility to have production/development builds with minimal level set to 'info' or 'trace' accordingly.

Example:

In this example we have a simple io.Writer and just proxy all seelog output to it. Here we emulate the 'production' situation, so minimal level is set to 'info'.

package main

import (
	"fmt"
	seelog "github.com/cihub/seelog"
)

type SomeWriter struct{}

func (sw *SomeWriter) Write(p []byte) (n int, err error) {
	fmt.Println(string(p))
	return len(p), nil
}

func main() {
	log, err := seelog.LoggerFromWriterWithMinLevelAndFormat(&SomeWriter{}, seelog.InfoLvl, "%Ns [%Level] %Msg")
	if err != nil {
		panic(err)
	}
	defer log.Flush()
	log.Debug("Test")
	log.Info("Test2")
}

Output:

1381334355481209992 [Info] Test2

Scenario 1.2: Proxy to a more complex log system

This scenario is similar to the previous one, but here you need to log to a logging subsystem that has its own levels, rules, or special actions.

In this situation you use LoggerFromCustomReceiver that takes a custom receiver which implements seelog.CustomReceiver interface.

Example:

Let's pretend that we use a logging subsystem that logs using 3 log levels and a function info:

type SomeLogger struct{}

func (sw *SomeLogger) Debug(fromFunc, s string) {
	fmt.Printf("DEBUG from %s: %s\n", fromFunc, s)
}
func (sw *SomeLogger) Info(fromFunc, s string) {
	fmt.Printf("INFO from %s: %s\n", fromFunc, s)
}
func (sw *SomeLogger) Error(fromFunc, s string) {
	fmt.Printf("ERROR from %s: %s\n", fromFunc, s)
}

Now we want to proxy seelog to it somehow. So we need to redirect seelog.Trace + seelog.Debug to SomeLogger.Debug, seelog.Info to SomeLogger.Info, and seelog.Warn + seelog.Error + seelog.Critical to SomeLogger.Error. Also we want to pass the caller function information.

To do this we create a custom receiver which implements seelog.CustomReceiver and proxies everything to SomeLogger in a way that is required:

type SomeCustomReceiver struct {
	l *SomeLogger
}

func (ar *SomeCustomReceiver) ReceiveMessage(message string, level seelog.LogLevel, context seelog.LogContextInterface) error {
	switch level {
	case seelog.TraceLvl:
		fallthrough
	case seelog.DebugLvl:
		ar.l.Debug(context.Func(), message)
	case seelog.InfoLvl:
		ar.l.Info(context.Func(), message)
	case seelog.WarnLvl:
		fallthrough
	case seelog.ErrorLvl:
		fallthrough
	case seelog.CriticalLvl:
		ar.l.Error(context.Func(), message)
	}
	return nil
}

/* NOTE: NOT called when LoggerFromCustomReceiver is used */
func (ar *SomeCustomReceiver) AfterParse(initArgs seelog.CustomReceiverInitArgs) error {
	return nil
}
func (ar *SomeCustomReceiver) Flush() {

}
func (ar *SomeCustomReceiver) Close() error {
	return nil
}

func main() {
	log, err := seelog.LoggerFromCustomReceiver(&SomeCustomReceiver{&SomeLogger{}})
	if err != nil {
		panic(err)
	}
	defer log.Flush()
	log.Debug("Test")
	log.Info("Test2")
}

Output:

DEBUG from main.main: Test
INFO from main.main: Test2

Scenario 2: seelog as a 'receiver'

This is the scenario when you have your own logging subsystem/component and you want to redirect its log stream to seelog. This is the opposite situation to Scenario 1.

In this scenario you just call seelog functions from your other logging subsystem and call SetAdditionalStackDepth to detect actual caller func (not the subsystem one). The latter will be explained using the following example.

Example:

package main

import (
	seelog "github.com/cihub/seelog"
)

type SomeLogger struct {
	inner seelog.LoggerInterface
}

func (sw *SomeLogger) Debug(s string) {
	sw.inner.Debug(s)

}
func (sw *SomeLogger) Info(s string) {
	sw.inner.Info(s)
}
func (sw *SomeLogger) Error(s string) {
	sw.inner.Error(s)
}

var log = &SomeLogger{}

func init() {
	var err error
	log.inner, err = seelog.LoggerFromConfigAsString(
		`<seelog>
			<outputs>
				<console formatid="fmt"/>
			</outputs>
			<formats>
				<format id="fmt" format="[%Func] [%Lev] %Msg%n"/>
			</formats>
		</seelog>
		`)
	if err != nil {
		panic(err)
	}
	log.inner.SetAdditionalStackDepth(1)
}

func main() {
	defer log.inner.Flush()
	log.Debug("Test")
	log.Info("Test2")
}

Output:

[main.main] [Dbg] Test
[main.main] [Inf] Test2

To get the idea of SetAdditionalStackDepth lets pretend that it is not called or is called with argument = 0 instead of 1. In that case the output is:

[main.(*SomeLogger).Debug] [Dbg] Test
[main.(*SomeLogger).Info] [Inf] Test2

It is actually valid output because these are the functions where seelog was called. But in current scenario you are actually redirecting your subsystem log messages to seelog, so actually you need to know where your subsystem func was called, not the seelog one. That's why SetAdditionalStackDepth is used. Its argument is set to the additional number of caller stack frames to skip to get to the actual caller func.

Scenario 3: Custom receivers inside seelog

In this scenario you utilize all the capabilities of seelog AND you add additional custom receivers which may be used in seelog config alongside others.

There are two sub-scenarios here.

Scenario 3.1: Custom receivers without context/with fixed context

This is the case when custom receiver doesn't depend on any other variables/parameters in code or if those dependencies are set one time and doesn't change. However it may depend on attributes in config. This will be explained by the following example.

Example:

Let's try to create a custom receiver that logs everything using fmt.Printf, but adds a custom prefix. We need to implement seelog.CustomReceiver to describe this type of receiver.

type CustomReceiver struct { // implements seelog.CustomReceiver
	prefix string // Just an example. Any data may be present
}

func (ar *CustomReceiver) ReceiveMessage(message string, level log.LogLevel, context log.LogContextInterface) error {
	fmt.Printf("[%s].%s", ar.prefix, message) // Just log message, but prepend a prefix
	return nil
}
func (ar *CustomReceiver) AfterParse(initArgs log.CustomReceiverInitArgs) error {
	var ok bool
	ar.prefix, ok = initArgs.XmlCustomAttrs["prefix"]
	if !ok {
		ar.prefix = "No prefix"
	}
	return nil
}
func (ar *CustomReceiver) Flush() {

}
func (ar *CustomReceiver) Close() error {
	return nil
}

Check the AfterParse implementation. Unlike Scenario 1.2, here it is going to be called, because here we are actually going to parse a config. initArgs.XmlCustomAttrs contains map of values of <custom> attributes beginning with data-.

Now we should register this type:

log.RegisterReceiver("myreceiver", &CustomReceiver{})

And we are ready to use it. Let's create a couple of these receivers with different prefixes!

	testConfig := `
<seelog>
	<outputs>
		<custom name="myreceiver" formatid="test"/>
		<custom name="myreceiver" formatid="test" data-prefix="CustomPrefix"/>
		<console formatid="test"/>
	</outputs>
	<formats>
		<format id="test" format="%Func %LEV %Msg%n"/>
	</formats>
</seelog>
`
	logger, err := log.LoggerFromConfigAsBytes([]byte(testConfig))
	if err != nil {
		panic(err)
	}
	defer logger.Flush()
	err = log.ReplaceLogger(logger)
	if err != nil {
		panic(err)
	}

After this, two instances of CustomReceiver will be created and AfterParse will be called for both of them.

Now we have 3 receivers: console, myreceiver (mapped to CustomReceiver) without prefix and myreceiver with prefix="CustomPrefix". So, if we log something:

log.Debug("Test1")
log.Info("Test2")

we get the following output:

main.main DBG Test1
[No prefix].main.main DBG Test1
[CustomPrefix].main.main DBG Test1
main.main INF Test2
[No prefix].main.main INF Test2
[CustomPrefix].main.main INF Test2

Note that now we are actually a part of seelog infrastructure (unlike Scenario 1, where seelog was just a proxy), so all formatting/filtering/other rules are applied. For instance, CustomReceiver gets message = "main.main DBG Test1" because its format id in config was set to 'test', defined as:

<format id="test" format="%Func %LEV %Msg%n"/>

Scenario 3.2: Custom receivers with context

Unlike Scenario 3.1, in this case our receivers are dependent on some kind of variable or parameter in code, that is needed for their creation and that may change. This case is different from Scenario 3.1 in the fact that you cannot call RegisterReceiver just once, you need to call something like that every time logger is created.

Example:

This case is best illustrated when we have custom receivers which use some kind of context to log messages. Let's pretend that we need to use the following struct as our custom receiver:

type SomeContext struct {
	id string
}

type SomeContextDependentLogger struct{}

func (l *SomeContextDependentLogger) Log(msg string, context SomeContext) {
	fmt.Printf("[%s] %s", context.id, msg)
}

var ctxLogger = &SomeContextDependentLogger{}

As we see, it needs some context as a parameter to the log func itself. Thus, our CustomReceiver that is going to be wrapping this struct needs to store the context data to be able to pass it to this specific logger:

type CustomReceiver struct {
	context SomeContext
}

func (cr *CustomReceiver) ReceiveMessage(message string, level log.LogLevel, context log.LogContextInterface) error {
	ctxLogger.Log(message, cr.context)
	return nil
}
func (cr *CustomReceiver) AfterParse(initArgs log.CustomReceiverInitArgs) error {
	return nil
}
func (cr *CustomReceiver) Flush() {

}
func (cr *CustomReceiver) Close() error {
	return nil
}

Here comes the difference between Scenario 3.1 and 3.2: instead of using package-level seelog.RegisterReceiver (Scenario 3.1), here we are going to use parser options to register receiver locally, for the time of parsing only:

func testLogWithContext(c SomeContext) {
	testConfig := `
<seelog>
	<outputs>
		<custom name="myreceiver" formatid="test"/>
		<console formatid="test"/>
	</outputs>
	<formats>
		<format id="test" format="%Func %LEV %Msg%n"/>
	</formats>
</seelog>
`
	parserParams := &log.CfgParseParams{
		CustomReceiverProducers: map[string]log.CustomReceiverProducer{
			"myreceiver": func(log.CustomReceiverInitArgs) (log.CustomReceiver, error) {
				return &CustomReceiver{c}, nil
			},
		},
	}
	logger, err := log.LoggerFromParamConfigAsString(testConfig, parserParams)
	if err != nil {
		panic(err)
	}
	defer logger.Flush()
	err = log.ReplaceLogger(logger)
	if err != nil {
		panic(err)
	}
	log.Debug("Test1")
	log.Info("Test2")
}

Here we use another flavor of logger creation funcs that uses parser parameters, that tell the parser how to create the custom receiver, when it meets the 'myreceiver' element. Let's test it and create two different loggers with different contexts for each of them:

func main() {
	testLogWithContext(SomeContext{"#1"})
	testLogWithContext(SomeContext{"#2"})
}

Output:

main.testLogWithContext DBG Test1
[#1] main.testLogWithContext DBG Test1
main.testLogWithContext INF Test2
[#1] main.testLogWithContext INF Test2
main.testLogWithContext DBG Test1
[#2] main.testLogWithContext DBG Test1
main.testLogWithContext INF Test2
[#2] main.testLogWithContext INF Test2

Note about Google App Engine integration:

At the time of this wiki article creation, Google App Engine used exactly the same approach as mentioned in the Scenario 3.2. To log something you needed a context:

    c := appengine.NewContext(r)
    c.Infof("Requested URL: %v", r.URL)

This is a typical case where you have a 'logger-per-request' approach (because you have appengine.Context per request) and this is a typical example of Scenario 3.2 usage. Code of a simple appengine wrapper and its usage may look like:

type AppEngineReceiver struct {
	c *appengine.Context
}

func (cr *AppEngineReceiver) ReceiveMessage(message string, level log.LogLevel, context log.LogContextInterface) error {
	switch level {
	case log.TraceLvl:
		fallthrough
	case log.DebugLvl:
		cr.c.Debugf(message)
	case log.InfoLvl:
		cr.c.Infof(message)
	case log.WarnLvl:
		cr.c.Warningf(message)
	case log.ErrorLvl:
		cr.c.Errorf(message)
	case log.CriticalLvl:
		cr.c.Criticalf(message)
	}
	return nil
}
func (cr *AppEngineReceiver) AfterParse(initArgs log.CustomReceiverInitArgs) error {
	return nil
}
func (cr *AppEngineReceiver) Flush() {

}
func (cr *AppEngineReceiver) Close() error {
	return nil
}

func Logger(w http.ResponseWriter, r *http.Request) (log.LoggerInterface, error) {
	testConfig := `
<seelog>
	<outputs>
		<custom name="appengine" formatid="test"/>
	</outputs>
	<formats>
		<format id="test" format="%Func %LEV %Msg%n"/>
	</formats>
</seelog>
`
	parserParams := &log.CfgParseParams{
		CustomReceiverProducers: map[string]log.CustomReceiverProducer{
			"appengine": func(log.CustomReceiverInitArgs) (log.AppEngineReceiver, error) {
				return &AppEngineReceiver{appengine.NewContext(r)}, nil
			},
		},
	}
	logger, err := log.LoggerFromParamConfigAsString(testConfig, parserParams)
	if err != nil {
		return nil, err
	}
	return logger, nil
}

func HttpHandler(rw http.ResponseWriter, req *http.Request) {
	l, err := Logger(rw, req)
	if err != nil {
		// do something
	}
	defer l.Close()

	l.Debugf("Test %d", 12345)
	l.Info("Test")

	// ...
}