Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
72 changes: 72 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,78 @@ Estas chamadas criarão arquivos de logs no diretório /applog/service-name/INFO

```

## Envio de logs via UDP (GELF/Graylog)

O logger suporta envio de logs via UDP no formato **GELF 1.1** (Graylog Extended Log Format), compatível com Graylog, Logstash/Kibana, Fluentd e outras plataformas de observabilidade.

### Configuração via código

```go
logger, _ := mchlogtoolkitgo.NewLogger("service-name", "info")
logger.SetUDPTarget("graylog.example.com:12201") // Habilita envio UDP com GZIP
logger.Initialize()

defer logger.Close() // Fecha a conexão UDP ao encerrar
```

Para desabilitar a compressão GZIP ou a saída em arquivo:
```go
logger.SetUDPTargetWithOptions("graylog.example.com:12201", false) // Sem GZIP
logger.DisableFileOutput() // Somente UDP, sem arquivos locais
```

### Configuração via variáveis de ambiente

O logger detecta automaticamente as seguintes variáveis de ambiente durante o `Initialize()`:

| Variável | Descrição | Exemplo |
|---|---|---|
| `MCHLOG_UDP_TARGET` | Endereço do servidor GELF (host:porta) | `graylog.example.com:12201` |
| `MCHLOG_UDP_COMPRESS` | Compressão GZIP (`true`/`false`, padrão: `true`) | `false` |
| `MCHLOG_FILE_OUTPUT` | Saída em arquivo (`true`/`false`, padrão: `true`) | `false` |

Exemplo de uso com variáveis de ambiente:
```bash
export MCHLOG_UDP_TARGET=graylog.example.com:12201
export MCHLOG_UDP_COMPRESS=true
export MCHLOG_FILE_OUTPUT=false
```

Com as variáveis definidas, o `Initialize()` configura o envio UDP automaticamente:
```go
logger, _ := mchlogtoolkitgo.NewLogger("service-name", "info")
logger.Initialize() // Detecta MCHLOG_UDP_TARGET e configura UDP
defer logger.Close()
```

### Formato da mensagem GELF

As mensagens são enviadas no formato GELF 1.1:
```json
{
"version": "1.1",
"host": "nome-do-host",
"short_message": "mensagem de informação",
"timestamp": 1711540800.123,
"level": 6,
"_source": "path/service.go",
"_line": "42",
"_trace": ""
}
```

O campo `level` segue o padrão syslog: Emergency (0), Error (3), Warning (4), Informational (6), Debug (7).

### Modos de operação

| Modo | Arquivo | UDP | Configuração |
|---|---|---|---|
| Somente arquivo (padrão) | sim | nao | Nenhuma configuração adicional |
| Arquivo + UDP | sim | sim | Definir `MCHLOG_UDP_TARGET` |
| Somente UDP | nao | sim | Definir `MCHLOG_UDP_TARGET` e `MCHLOG_FILE_OUTPUT=false` |

---

## Boas práticas de logs
Nesta seção são apresentados exemplos de bons e maus usos de logs.

Expand Down
67 changes: 66 additions & 1 deletion logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,8 @@ package mchlogtoolkitgo
import (
"encoding/json"
"errors"
"log"
"os"
"runtime"
"strconv"
"strings"
Expand All @@ -20,6 +22,18 @@ const (

DebugPath = "./applog/"
ProdPath = "/applog/"

// EnvUDPTarget is the environment variable name for the UDP target address.
// Format: "host:port" (e.g., "graylog.example.com:12201")
EnvUDPTarget = "MCHLOG_UDP_TARGET"

// EnvUDPCompress is the environment variable to enable/disable GZIP compression for UDP.
// Values: "true" or "false" (default: "true")
EnvUDPCompress = "MCHLOG_UDP_COMPRESS"

// EnvFileOutput is the environment variable to enable/disable file output.
// Values: "true" or "false" (default: "true")
EnvFileOutput = "MCHLOG_FILE_OUTPUT"
)

// Logger é a estrutura que encapsula as funcionalidades de log da aplicação
Expand Down Expand Up @@ -50,8 +64,26 @@ func NewLogger(service, level string) (*Logger, error) {
return l, nil
}

// Initialize inicializa o logger
// Initialize inicializa o logger.
// If the environment variable MCHLOG_UDP_TARGET is set, UDP output is automatically configured.
// If MCHLOG_FILE_OUTPUT is set to "false", file output is disabled.
func (l *Logger) Initialize() {
// Check environment variables for UDP configuration
if target := os.Getenv(EnvUDPTarget); target != "" {
compress := true
if v := os.Getenv(EnvUDPCompress); strings.ToLower(v) == "false" {
compress = false
}
if err := mchlogcore.SetUDPTarget(target, compress); err != nil {
log.Printf("[mchlog] failed to configure UDP target %q from environment: %v", target, err)
}
}

// Check environment variable for file output
if v := os.Getenv(EnvFileOutput); strings.ToLower(v) == "false" {
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


SetFileOutput(false) is called before InitializeMchLog (line 87). However, if fileOutputEnabled is set to false here, but Initialize() then calls mchlogcore.InitializeMchLog(...) unconditionally, file structures are still initialized. Additionally, SetFileOutput affects a package-level global, meaning calling Initialize() on a second Logger instance (with file output enabled) would not restore the fileOutputEnabled=true state if another logger had disabled it. This is a pre-existing design concern made worse by the new code path. Document that these are global settings shared across all Logger instances.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


The environment variable MCHLOG_FILE_OUTPUT is only checked for the value "false" (case-insensitive). Any other value — including "0", "no", "off" — is silently treated as true (file output enabled). This is inconsistent with how some users may expect boolean env vars to behave. The doc comment and README only mention "true"/"false", so this is acceptable, but it should be explicitly documented (or "0" should also be accepted) to avoid operator confusion.

mchlogcore.SetFileOutput(false)
}

mchlogcore.InitializeMchLog(l.path + l.service + "/")
l.log = &mchlogcore.MchLog
}
Expand Down Expand Up @@ -80,6 +112,39 @@ func (l *Logger) SetLevel(level string) error {
return nil
}

// SetUDPTarget configures the logger to send GELF messages via UDP to the given address.
// The address should be in "host:port" format (e.g., "graylog.example.com:12201").
// GZIP compression is enabled by default.
//
// Note: UDP target and file output settings are global and shared across all
// Logger instances. Changing them on one instance affects all others.
func (l *Logger) SetUDPTarget(address string) error {
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Suggestion · Architecture / Tight Coupling


SetUDPTarget and SetUDPTargetWithOptions are both thin wrappers that delegate to mchlogcore.SetUDPTarget. They add no value beyond a slightly different API surface, and the comment on SetUDPTarget says 'Must be called before Initialize()' while the Initialize() method itself also calls mchlogcore.SetUDPTarget from env vars. This creates a confusing dual-configuration path. Consider consolidating into a single options struct (e.g., LoggerOptions) passed to NewLogger or Initialize, or at least documenting that calling SetUDPTarget after Initialize() will replace the UDP target.

return mchlogcore.SetUDPTarget(address, true)
}

// SetUDPTargetWithOptions configures the logger to send GELF messages via UDP with explicit options.
// The address should be in "host:port" format (e.g., "graylog.example.com:12201").
// If compress is true, messages will be GZIP compressed before sending.
func (l *Logger) SetUDPTargetWithOptions(address string, compress bool) error {
return mchlogcore.SetUDPTarget(address, compress)
}

// DisableFileOutput disables file-based log output.
// When called, logs are only sent via UDP (if configured).
// This is a global setting shared across all Logger instances.
// When disabled before Initialize(), no log directories or files are created.
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


The doc comment for DisableFileOutput states: 'When disabled before Initialize(), no log directories or files are created.' This is now true given the updated InitializeMchLog guard. However, the comment on Close() (line 140) does not mention that Close() only closes UDP resources — it does not flush or close any file handles. If file logging uses buffered writers, Close() could silently lose buffered log entries. Verify (and document) whether the file backends need their own Close/Flush, or clarify that file handles are not managed by Close().

func (l *Logger) DisableFileOutput() {
mchlogcore.SetFileOutput(false)
}

// Close drains any buffered UDP messages and closes the UDP connection.
// It does NOT close file handles used by the file logging backends (V1/V2),
// as those write directly to unbuffered *os.File handles managed by zerolog
// and are kept open for the lifetime of the process.
func (l *Logger) Close() error {
return mchlogcore.CloseUDP()
}

func (l *Logger) Test(message string) {
if l.level != TestLevel {
return
Expand Down
184 changes: 173 additions & 11 deletions mchlogcore/mchlog.go
Original file line number Diff line number Diff line change
@@ -1,8 +1,13 @@
package mchlogcore

import (
"log"
"sync"
"sync/atomic"

"github.com/gaudiumsoftware/mchlogtoolkitgo/mchlogcorev1"
"github.com/gaudiumsoftware/mchlogtoolkitgo/mchlogcorev2"
"github.com/gaudiumsoftware/mchlogtoolkitgo/mchloggelf"
)

// LogVersion is a type to define which version of the logger to use
Expand All @@ -13,25 +18,178 @@ const (
V1 LogVersion = iota
// V2 refers to the second version of the logger, which has a simpler file structure without IP or timestamps in names
V2

// udpBufferSize is the size of the buffered channel for async UDP sends.
// Messages beyond this buffer are dropped to prevent memory exhaustion.
udpBufferSize = 1000
)

var currentVersion = V1

// udpMu protects udpTransport, udpChan, and udpDone from concurrent access.
// LogSubject holds RLock during the entire channel send to prevent the channel
// from being closed mid-send.
var udpMu sync.RWMutex
var udpTransport *mchloggelf.UDPTransport
var udpChan chan *mchloggelf.GELFMessage
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Suggestion · Architecture / Tight Coupling


Package-level mutable state (udpTransport, udpChan, fileOutputEnabled, etc.) makes this package difficult to test in isolation and prevents multiple logger instances from having independent UDP configurations. Consider encapsulating this state in a struct.

var udpDone chan struct{}

// fileOutputEnabled uses atomic.Bool for lock-free concurrent reads in LogSubject.
var fileOutputEnabled atomic.Bool

func init() {
fileOutputEnabled.Store(true)
}

// SetVersion chooses which version to use (V1 or V2).
// This should ideally be called before InitializeMchLog.
func SetVersion(v LogVersion) {
currentVersion = v
}

// SetUDPTarget configures a UDP transport to send GELF messages to the given address.
// The address should be in "host:port" format (e.g., "graylog.example.com:12201").
// If compress is true, messages will be GZIP compressed.
func SetUDPTarget(address string, compress bool) error {
// Phase 1: under write lock, close the channel and capture references
// to the old worker so we can wait on it without holding the lock.
udpMu.Lock()
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


In SetUDPTarget, Phase 1 detaches the old worker (closes its channel, sets udpChan = nil) and releases the lock. Phase 3 creates a new transport via mchloggelf.NewUDPTransport (a network operation). If this network call fails, the function returns the error and exits — leaving udpChan = nil and udpTransport = nil permanently. This means after a failed SetUDPTarget call, UDP logging is silently disabled with no indication. The caller receives the error, but if they ignore it (as noted in previously-reported issue #9 for the env-var path), logging silently stops. Consider documenting that a failed SetUDPTarget disables UDP output until a successful call is made.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Atenção · Bugs / Race Condition


Entre a Phase 1 (udpMu.Unlock() na linha 58) e a Phase 4 (udpMu.Lock() na linha 71), qualquer chamada a LogSubject verá udpChan == nil e silenciosamente descartará mensagens. Este é um período de 'blackout' de UDP durante a troca de target, que inclui uma operação de rede (NewUDPTransport na linha 65) e a espera pelo drain do worker antigo (waitAndClose na linha 62). Em ambientes de alta taxa de log, mensagens serão perdidas durante esse intervalo. Considere documentar esse comportamento ou usar um padrão que mantenha o worker antigo ativo até que o novo esteja pronto (hot-swap).

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ramon-gaudium Vê esse comentário

oldDone, oldTransport := detachWorkerLocked()
udpMu.Unlock()

// Phase 2: wait for the old worker to drain without holding any lock,
// so LogSubject calls are not blocked during the drain.
waitAndClose(oldDone, oldTransport)

// Phase 3: create new transport (network operation, no lock needed)
t, err := mchloggelf.NewUDPTransport(address, compress)
if err != nil {
return err
}

// Phase 4: install new worker under write lock
udpMu.Lock()
defer udpMu.Unlock()

// If another SetUDPTarget ran between phase 1 and 4 and installed a new
// worker, shut it down first (last caller wins). This wait is bounded:
// the write lock prevents new sends, so the worker only drains what is
// already in the buffer.
innerDone, innerTransport := detachWorkerLocked()
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


In SetUDPTarget, between Phase 2 (waitAndClose) and Phase 4 (acquiring the write lock), another concurrent SetUDPTarget call could also reach Phase 4 and install a new worker. The inner detach on lines 78-84 then tears down that newly-installed worker before the current call installs its own. This means the newly created transport t (built in Phase 3 of this call) is installed while the concurrently-created transport is discarded — but the concurrently-created transport is closed via innerTransport.Close() correctly. The subtle issue is that innerDone is waited on while holding the write lock (line 80: <-innerDone). Because the write lock is held, LogSubject cannot acquire RLock and cannot enqueue new messages, so the worker drains only what is already buffered — which is correct and bounded. However, this is a blocking wait under a write lock and can stall all logging for the entire drain period. Consider documenting this explicitly, or accept the trade-off as intentional since concurrent SetUDPTarget calls are expected to be rare.

if innerDone != nil {
<-innerDone
}
if innerTransport != nil {
_ = innerTransport.Close()
}

udpTransport = t
startWorkerLocked()
return nil
}

// detachWorkerLocked closes the channel and clears the global references,
// returning the old done channel and transport so the caller can wait and
// clean up outside the lock. Must be called with udpMu write lock held.
// After this call, udpChan is nil so LogSubject will skip UDP sends.
func detachWorkerLocked() (<-chan struct{}, *mchloggelf.UDPTransport) {
if udpChan == nil {
return nil, nil
}
close(udpChan)
done := udpDone
transport := udpTransport
udpChan = nil
udpDone = nil
udpTransport = nil
return done, transport
}

// waitAndClose waits for the worker to finish draining and closes the transport.
// Safe to call with nil arguments (no-op).
func waitAndClose(done <-chan struct{}, transport *mchloggelf.UDPTransport) {
if done != nil {
<-done
}
if transport != nil {
_ = transport.Close()
}
}

// startWorkerLocked initializes the buffered channel and starts a single worker
// goroutine that reads messages and sends them over UDP sequentially.
// Must be called with udpMu write lock held.
func startWorkerLocked() {
udpChan = make(chan *mchloggelf.GELFMessage, udpBufferSize)
udpDone = make(chan struct{})

// Capture references for the goroutine so it operates independently
// of the global variables. The worker reads from its own channel ref
// and does not need the mutex.
ch := udpChan
done := udpDone
transport := udpTransport

go func() {
defer close(done)
for msg := range ch {
if err := transport.Send(msg); err != nil {
log.Printf("[mchlog] failed to send GELF message via UDP: %v", err)
}
}
}()
}

// SetFileOutput enables or disables file-based log output.
// When disabled, logs are only sent via UDP (if configured).
func SetFileOutput(enabled bool) {
fileOutputEnabled.Store(enabled)
}

// CloseUDP closes the UDP worker and transport connection if active.
// Waits for the worker to drain remaining buffered messages before returning.
func CloseUDP() error {
udpMu.Lock()
done, transport := detachWorkerLocked()
udpMu.Unlock()

waitAndClose(done, transport)
return nil
}
Comment on lines +151 to +158
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

A função CloseUDP sempre retorna nil, mas a chamada subjacente udpTransport.Close() pode retornar um erro que está sendo ignorado em closeUDPWorker. Isso pode ocultar problemas ao fechar a conexão UDP.

Sugiro refatorar closeUDPWorker para que retorne o erro (o que exigirá alterar sua assinatura) e CloseUDP o propague. A chamada em SetUDPTarget pode continuar ignorando o erro, pois o objetivo é apenas limpar a conexão anterior.

Exemplo de alteração em closeUDPWorker:

func closeUDPWorker() error {
    // ... (código existente)
	if udpTransport != nil {
		err := udpTransport.Close()
		udpTransport = nil
		return err
	}
	return nil
}
func CloseUDP() error {
	return closeUDPWorker()
}


// LogType is the facade structure that delegates calls to either V1 or V2 implementation
type LogType struct{}

// LogSubject records the content to the log file using the selected version
// LogSubject records the content to the log file and/or sends it via UDP using the selected version
func (l *LogType) LogSubject(subject string, content any, errLog error, ascendStackFrame ...int) {
if currentVersion == V1 {
mchlogcorev1.MchLog.LogSubject(subject, content, errLog, ascendStackFrame...)
} else {
mchlogcorev2.MchLog.LogSubject(subject, content, errLog, ascendStackFrame...)
if fileOutputEnabled.Load() {
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


When fileOutputEnabled is false, file logging is completely skipped. However, mchlogcore.InitializeMchLog (called by Logger.Initialize()) still creates the log directories and file handles. This is a minor inconsistency but could confuse operators who set MCHLOG_FILE_OUTPUT=false expecting zero file I/O, only to find directories/files created. Consider conditionally calling InitializeMchLog based on fileOutputEnabled, or documenting this behavior.

if currentVersion == V1 {
mchlogcorev1.MchLog.LogSubject(subject, content, errLog, ascendStackFrame...)
} else {
mchlogcorev2.MchLog.LogSubject(subject, content, errLog, ascendStackFrame...)
}
}

// Hold RLock for the entire nil-check + send to prevent detachWorkerLocked
// from closing the channel between the check and the send. The non-blocking
// select ensures we never block while holding the lock.
udpMu.RLock()
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 Critical · Bugs / Race Condition


There is still a TOCTOU race between reading udpChan under RLock (lines 139-141) and sending to the captured ch variable (line 150). After udpMu.RUnlock() on line 141, closeLocked can run (acquiring the write lock), close the channel, and set udpChan = nil. The local variable ch still holds a reference to the now-closed channel. The subsequent case ch <- msg: at line 150 will then panic with 'send on closed channel'. The read lock must be held for the entire duration of the send — from the nil check through the completion of the channel send — to prevent closeLocked from closing the channel while a send is in progress. Move udpMu.RUnlock() to after the select block (or use defer udpMu.RUnlock() before the send).

defer udpMu.RUnlock()

if udpChan == nil {
return
}

msg, err := mchloggelf.NewGELFMessage(subject, content, errLog)
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Performance / Blocking I/O in Hot Path


mchloggelf.NewGELFMessage (including contentToMap with JSON unmarshaling and map allocation) is called inside LogSubject while holding udpMu.RLock(). JSON unmarshaling can be slow for large payloads. Since RLock is held to prevent the channel from being closed mid-send, any slow NewGELFMessage call extends the duration the read lock is held, delaying any concurrent SetUDPTarget or CloseUDP that needs the write lock. Consider building the GELF message before acquiring the lock, then doing a quick nil-check + send under the lock. You'd need to handle the race where udpChan becomes nil between message creation and the lock, but this is safe since the default case in the select already handles a full buffer, and a closed-channel send is protected by the lock. Example: build message first, then udpMu.RLock(), check nil, send or drop, udpMu.RUnlock().

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Atenção · Performance / Blocking I/O in Hot Path


NewGELFMessage (que inclui JSON unmarshal, alocações de map, etc.) é executado dentro do escopo do udpMu.RLock(). Isso significa que toda chamada a LogSubject que envia via UDP mantém o read lock durante a criação da mensagem GELF, atrasando qualquer SetUDPTarget ou CloseUDP concorrente que precisa do write lock. Considere construir a mensagem GELF antes de adquirir o RLock, e sob o lock fazer apenas o nil-check + send. Nota: este ponto já foi mencionado (#38), mas a severidade aqui é reforçada porque o lock é mantido por toda a operação de marshaling, não apenas o send.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ramon-gaudium Vê esse comentário

if err != nil {
log.Printf("[mchlog] failed to create GELF message for subject %q: %v", subject, err)
return
}
select {
case udpChan <- msg:
// Message queued successfully
default:
log.Printf("[mchlog] UDP send buffer full, dropping GELF message for subject %q", subject)
}
}

Expand All @@ -55,14 +213,18 @@ func (l *LogType) GetIP() string {
// MchLog is the global instance of the log facade
var MchLog LogType

// InitializeMchLog initializes the selected version's backend with the given path
// InitializeMchLog initializes the selected version's backend with the given path.
// If file output is disabled, the file backend is not initialized and no
// directories or files are created.
func InitializeMchLog(path string) {
versionName := "V1"
if currentVersion == V1 {
mchlogcorev1.InitializeMchLog(path)
} else {
versionName = "V2"
mchlogcorev2.InitializeMchLog(path)
if fileOutputEnabled.Load() {
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Attention · Bugs / Logic Error


When fileOutputEnabled is false, the versionName variable stays as "V1" (its default value, set on line 220) regardless of currentVersion. The subsequent log call (after this block) will always print "V1" even if currentVersion == V2 and file output is disabled. The versionName assignment inside the else branch (line 225) is only reached when file output is enabled. Move versionName assignment outside the fileOutputEnabled guard, or replicate the version name logic unconditionally before the guard.

if currentVersion == V1 {
mchlogcorev1.InitializeMchLog(path)
} else {
versionName = "V2"
mchlogcorev2.InitializeMchLog(path)
}
}

// The first log in info should be the version of the logger (v1 or v2)
Expand Down
Loading
Loading