core_test.go

package zap

import (
	"context"
	"reflect"
	"slices"
	"sync"
	"testing"
	"time"

	"git.perx.ru/perxis/perxis-go/pkg/log"
	logmocks "git.perx.ru/perxis/perxis-go/pkg/log/mocks"
	"github.com/stretchr/testify/assert"
	"github.com/stretchr/testify/mock"
	"github.com/stretchr/testify/require"
	"go.uber.org/zap"
)

func TestCore_Write(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Twice()

	logger, stop := LoggerWithLogService(zap.NewNop(), service)
	logger.Debug("debug сообщение") // будет проигнорировано

	logger = logger.With(
		Component("Items.Service"),
	)

	logger.Info("создан элемент коллекции",
		zap.String("key", "val"), // будет проигнорировано
		Category("create"),
		Event("Items.Create"),
		Object("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl"),
		CallerFromContext(ContextWithCaller(context.Background(), "/users/PHVz")),
		Attr(nil),
		Tags("tag1", "tag2", "tag3"),
	)
	logger.Warn("изменен элемент коллекции",
		Category("update"),
		Event("Items.Update"),
		Object("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl/revs/cmV2"),
		CallerFromContext(ContextWithCaller(context.Background(), "/users/UEhW")),
	)

	err := stop()
	require.NoError(t, err)

	wantEntries := []*log.Entry{
		{
			LogLevel:  log.Level(zap.InfoLevel),
			Message:   "создан элемент коллекции",
			Category:  "create",
			Component: "Items.Service",
			Event:     "Items.Create",
			Object:    "/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl",
			Caller:    "/users/PHVz",
			Attr:      nil,
			Tags:      []string{"tag1", "tag2", "tag3"},
		},
		{
			LogLevel:  log.Level(zap.WarnLevel),
			Message:   "изменен элемент коллекции",
			Category:  "update",
			Component: "Items.Service",
			Event:     "Items.Update",
			Object:    "/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl/revs/cmV2",
			Caller:    "/users/UEhW",
			Attr:      nil,
			Tags:      nil,
		},
	}

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 2 && slices.EqualFunc(wantEntries, entries, func(entryA *log.Entry, entryB *log.Entry) bool {
			entryA.ID = entryB.ID               // игнорируем ID, потому что он генерируется случайно
			entryA.Timestamp = entryB.Timestamp // игнорируем Timestamp
			return reflect.DeepEqual(entryA, entryB)
		})
	}))
}

func TestCore_ConcurrentWrite(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Once()

	logger, stop := LoggerWithLogService(zap.NewNop(), service)

	var wg sync.WaitGroup
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func(wg *sync.WaitGroup) {
			defer wg.Done()
			logger.Warn("msg")
		}(&wg)
	}

	wg.Wait()

	err := stop()
	require.NoError(t, err)

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 100
	}))
}

func TestCore_ConcurrentWrite_WithMaxBufferSize(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Times(10)

	logger, stop := LoggerWithLogService(zap.NewNop(), service, WithMaxBufferSize(10))

	var wg sync.WaitGroup
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func(wg *sync.WaitGroup) {
			defer wg.Done()
			logger.Info("msg")
		}(&wg)
	}

	wg.Wait()

	err := stop()
	require.NoError(t, err)

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 10
	}))
}

func TestCore_Write_WithMaxBufferSize(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Times(10)

	logger, stop := LoggerWithLogService(zap.NewNop(), service, WithMaxBufferSize(10))

	for i := 0; i < 100; i++ {
		logger.Info("msg")
	}

	err := stop()
	require.NoError(t, err)

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 10
	}))
}

func TestCore_Write_WithFlushInterval(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Once()

	// в данном случае stop нам не нужен
	logger, _ := LoggerWithLogService(zap.NewNop(), service, WithFlushInterval(1*time.Second))

	for j := 0; j < 10; j++ {
		logger.Info("msg")
	}

	time.Sleep(3 * time.Second) // ждем, пока сработает интервал

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 10
	}))
}

func TestCore_Write_Sync(t *testing.T) {
	service := &logmocks.Service{}
	service.On("Log", mock.Anything, mock.Anything).
		Return(nil).Times(10)

	logger, stop := LoggerWithLogService(zap.NewNop(), service)

	for i := 0; i < 10; i++ {
		for j := 0; j < 10; j++ {
			logger.Info("msg")
		}
		err := logger.Sync()
		assert.NoError(t, err)
	}

	err := stop()
	require.NoError(t, err)

	service.AssertCalled(t, "Log", mock.Anything, mock.MatchedBy(func(entries []*log.Entry) bool {
		return len(entries) == 10
	}))
}