pulsar-client-go icon indicating copy to clipboard operation
pulsar-client-go copied to clipboard

[feat] added a slog wrapper of the logger interface

Open ivan-penchev opened this issue 1 year ago • 4 comments

Hi 👋, first time contributor here

Motivation

My team uses log/slog package from the standard library to control the level and output type of our logs in our services. In order for us to not have to import logrus as a direct dependency for part of our testing suit, it would be nice if we can use slog package instead, and wrap that in the provided by pulsar/log interfaces.

This ties in a bit with issue #1078 because it opens the door for users who are already working with log/slog in their projects. Plus, it's a gives more time for the Pulsar team to evaluate incorporating slog into the SDK.

Explain here the context, and why you're making that change. What is the problem you're trying to solve.

Modifications

One additional file /pulsar/log/wrapper_slog.go is added. One additional function in the pulsar/log package, NewLoggerWithSlog , is exposed.

Verifying this change

  • [x] Make sure that the change passes the CI checks.

This change is a trivial rework / code cleanup without any test coverage.

Does this pull request potentially affect one of the following parts:

If yes was chosen, please highlight the changes

  • Dependencies (does it add or upgrade a dependency): (no)
  • The public API: (no)
  • The schema: (no)
  • The default values of configurations: (no)
  • The wire protocol: (no)

Documentation

  • Does this pull request introduce a new feature? (no)
  • If yes, how is the feature documented? (not applicable / docs / GoDocs / not documented)
  • If a feature is not applicable for documentation, explain why?
  • If a feature is not documented yet in this PR, please create a followup issue for adding the documentation

Notes

Please direct me if I'm missing something 😄.

I attempted to include a meaningful test to enhance the quality of this pull request. Regrettably, I was unsuccessful, as none of the scenarios I considered seemed appropriate.

Throughout the development process, I utilized testcontainers, which I recognize cannot be added because it would introduce an unnecessary dependency. As well as it creates a circular dependacy between pulsar and pulsar/log. However in order to verify the changes I am submitting I created a file named log_test.go in the root directory of the repository. Within this file, I initiated an Apache Pulsar testcontainer, then set up both a logrus logger and an slog logger. These were utilized to establish a client and a producer. Subsequently, I compared the length of the output from both loggers to ensure the keys corresponded.

Below is the test for those interested in confirming that this change functions correctly:

Integration test code, must run go mod tidy before you run
package logtest

import (
	"bytes"
	"context"
	"encoding/json"
	"fmt"
	"io"
	"log/slog"
	"sort"
	"strings"
	"testing"
	"time"

	"github.com/apache/pulsar-client-go/pulsar"
	plog "github.com/apache/pulsar-client-go/pulsar/log"
	"github.com/sirupsen/logrus"
	"github.com/stretchr/testify/require"
	"github.com/testcontainers/testcontainers-go"
	"github.com/testcontainers/testcontainers-go/wait"
)

func TestSlogWrapper_Integration(t *testing.T) {
	pulsarC, pulsarUrl, _ := createPulsarContainer(t, context.Background())
	topic := createPulsarTopic(t, pulsarC, "test", "test-topic")

	var logBufferLogrus bytes.Buffer
	loggerLogrus := logrus.New()
	loggerLogrus.Out = &logBufferLogrus
	loggerLogrus.Level = logrus.DebugLevel
	loggerLogrus.SetFormatter(&logrus.JSONFormatter{})

	clientLogrus, err := pulsar.NewClient(pulsar.ClientOptions{
		URL:               pulsarUrl,
		ConnectionTimeout: 15 * time.Second,
		Logger:            plog.NewLoggerWithLogrus(loggerLogrus),
	})
	require.NoError(t, err, "Failed to create Logrus Pulsar client")

	producerLogrus, err := clientLogrus.CreateProducer(pulsar.ProducerOptions{
		Topic: topic,
	})
	require.NoError(t, err, "Failed to create Logrus producer")

	_, err = producerLogrus.Send(context.Background(), &pulsar.ProducerMessage{
		Payload: []byte("test"),
	})
	require.NoError(t, err, "Failed to send message with Logrus producer")

	producerLogrus.Close()
	clientLogrus.Close()

	var logBufferSlog bytes.Buffer
	loggerSlog := slog.New(slog.NewJSONHandler(&logBufferSlog, &slog.HandlerOptions{Level: slog.LevelDebug}))

	clientSlog, err := pulsar.NewClient(pulsar.ClientOptions{
		URL:               pulsarUrl,
		ConnectionTimeout: 15 * time.Second,
		Logger:            plog.NewLoggerWithSlog(loggerSlog),
	})
	require.NoError(t, err, "Failed to create Slog Pulsar client")

	producerSlog, err := clientSlog.CreateProducer(pulsar.ProducerOptions{
		Topic: topic,
	})
	require.NoError(t, err, "Failed to create Slog producer")

	_, err = producerSlog.Send(context.Background(), &pulsar.ProducerMessage{
		Payload: []byte("test"),
	})
	require.NoError(t, err, "Failed to send message with Slog producer")

	producerSlog.Close()
	clientSlog.Close()

	logOutputLogrus := logBufferLogrus.String()
	logOutputSlog := logBufferSlog.String()

	logrusLines := strings.Split(strings.TrimSpace(logOutputLogrus), "\n")
	slogLines := strings.Split(strings.TrimSpace(logOutputSlog), "\n")

	require.Equal(t, len(logrusLines), len(slogLines), "Log outputs have different number of lines")
	for i, logrusLine := range logrusLines {
		var logrusJSON, slogJSON map[string]interface{}

		err := json.Unmarshal([]byte(logrusLine), &logrusJSON)
		require.NoError(t, err, "Logrus line %d is not valid JSON: %s", i+1, logrusLine)

		err = json.Unmarshal([]byte(slogLines[i]), &slogJSON)
		require.NoError(t, err, "Slog line %d is not valid JSON: %s", i+1, slogLines[i])

		logrusKeys := getKeys(logrusJSON)
		slogKeys := getKeys(slogJSON)
		require.Equal(t, logrusKeys, slogKeys, "JSON keys do not match on line %d\nLogrus: %v\nSlog: %v", i+1, logrusKeys, slogKeys)
	}

}

func getKeys(m map[string]interface{}) []string {
	keys := make([]string, 0, len(m))
	for k := range m {
		keys = append(keys, k)
	}
	sort.Strings(keys)
	return keys
}

func createPulsarContainer(t *testing.T, ctx context.Context) (pulsarC testcontainers.Container, pulsarUrl, pulsarAdminUrl string) {
	pulsarC, err := testcontainers.GenericContainer(ctx, testcontainers.GenericContainerRequest{
		ContainerRequest: testcontainers.ContainerRequest{
			Image:        "apachepulsar/pulsar:3.3.0",
			Cmd:          []string{"bin/pulsar", "standalone"},
			Name:         "shared-pulsar-testcontainer",
			ExposedPorts: []string{"6650/tcp", "8080/tcp"},
			SkipReaper:   true,
			WaitingFor: wait.ForAll(
				wait.ForExposedPort(),
				wait.ForHTTP("/admin/v2/brokers/health").WithPort("8080/tcp").WithPollInterval(10*time.Second).WithResponseMatcher(func(r io.Reader) bool {
					respBytes, _ := io.ReadAll(r)
					resp := string(respBytes)
					isReady := strings.Contains(resp, `ok`)
					return isReady
				}),
			),
		},
		Reuse:   true,
		Started: true,
	})
	require.NoError(t, err)

	timeout := 60 * time.Second
	pollInterval := 10 * time.Second
	require.Eventually(t, func() bool {
		pulsarUrl, err = pulsarC.PortEndpoint(ctx, "6650/tcp", "pulsar")
		if err != nil {
			return false
		}
		pulsarAdminUrl, err = pulsarC.PortEndpoint(ctx, "8080/tcp", "http")
		//nolint:all
		if err != nil {
			return false
		}
		return true
	}, timeout, pollInterval, "The Pulsar container did not start within the expected time")
	return pulsarC, pulsarUrl, pulsarAdminUrl
}

func createPulsarTopic(t *testing.T, pulsarContainer testcontainers.Container, namespace, topicName string) (topic string) {
	tenant := "pulsar"
	fullTopicName := fmt.Sprintf("persistent://%s/%s/%s", tenant, namespace, topicName)
	namespaceCommand := fmt.Sprintf("bin/pulsar-admin namespaces create %s/%s || true", tenant, namespace)
	topicCommand := fmt.Sprintf("bin/pulsar-admin topics create %s", fullTopicName)

	exitCodeNamespace, _, errNamespace := pulsarContainer.Exec(context.Background(), []string{
		"/bin/sh", "-c", namespaceCommand,
	})
	if errNamespace != nil {
		t.Fatalf("Error creating namespace: %s", errNamespace)
	}
	if exitCodeNamespace != 0 {
		t.Fatalf("failed to create namespace, exit code: %d", exitCodeNamespace)
	}

	exitCodeTopic, _, errTopic := pulsarContainer.Exec(context.Background(), []string{
		"/bin/sh", "-c", topicCommand,
	})
	if errTopic != nil {
		t.Fatalf("Error creating topic: %s", errTopic)
	}
	if exitCodeTopic != 0 {
		t.Fatalf("failed to create topic, exit code: %d", exitCodeTopic)
	}

	return fullTopicName
}

ivan-penchev avatar Jul 02 '24 20:07 ivan-penchev

Appologies for tagging you @crossoverJie , @RobertIndie , @nodece , but I noticed that the v0.13.0 milestone has a deadline in 2 days. And was wondering, due to the nature of the change, if it would be feasible to review it with the goal of including it in that release? No pressure to rush the review is intended by this question, I am just curious.

ivan-penchev avatar Jul 03 '24 19:07 ivan-penchev

@ivan-penchev In this PR, the Go version is upgraded to a minimum of 1.20, but the slog package is officially used in 1.21.

This change requires upgrading the Go version to 1.21+.

crossoverJie avatar Jul 04 '24 02:07 crossoverJie

@ivan-penchev In this PR, the Go version is upgraded to a minimum of 1.20, but the slog package is officially used in 1.21.

This change requires upgrading the Go version to 1.21+.

Upgrading the Go version looks to be a clear and well defined step. Is it practical to consider a minimum version upgrade for this PR?

I mean Go is considered feature-complete and lacks an LTS version, it's generally expected to maintain compatibility with the last two minor versions, as seen on their download page (https://go.dev/dl/). But I've read some issues here indicating a more conservative update strategy for this SDK. Is that the case? Do I have to wait til Go 1.23 before we can merge this?

Edit: @crossoverJie I decided to give the upgrade a chance, after reading go's release policy. I hope I haven't done anything bad.

ivan-penchev avatar Jul 04 '24 07:07 ivan-penchev

Edit: @crossoverJie I decided to give the upgrade a chance, after reading go's release policy. I hope I haven't done anything bad.

I have no objections to upgrading to 1.21. We've already skipped 1.18 to 1.19, so skipping 1.20 as well doesn't seem problematic.

cc @nodece @RobertIndie

crossoverJie avatar Jul 04 '24 08:07 crossoverJie

@ivan-penchev I noticed this PR doesn't add a test, could you add a test for the producer and consumer with this logger?

nodece avatar Jul 04 '24 11:07 nodece

@ivan-penchev I noticed this PR doesn't add a test, could you add a test for the producer and consumer with this logger?

@nodece I appreciate the need for a test to accompany this update. I'm willing to try writing one, but I could use some assistance, given that the current test suite doesn't cover the logger.

  1. Where should I place the test?
  2. What should I be testing? (that producer and consumer do not throw error when using Slog?)
  3. How do I ensure my test is run only when we build for with go 1.21

For 2 you could see - in my PR description, I did an integration test where I started a producer with logrus, and producer with slog - and then I compared the output of both loggers, in terms of length and keys (since I was doing json). But this seems too complicated and not needed for what I was trying to test.

So I would be provocative and ask, do we even need a test?

ivan-penchev avatar Jul 04 '24 11:07 ivan-penchev

  1. Where should I place the test?

You can write a test in the pulsar/client_impl_with_slog_test.go.

  1. What should I be testing? (that producer and consumer do not throw error when using Slog?)

All right.

  1. How do I ensure my test is run only when we build for with go 1.21
/// Licensed to the Apache Software Foundation (ASF) under one
// or more contributor license agreements.  See the NOTICE file
// distributed with this work for additional information
// regarding copyright ownership.  The ASF licenses this file
// to you under the Apache License, Version 2.0 (the
// "License"); you may not use this file except in compliance
// with the License.  You may obtain a copy of the License at
//
//   http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing,
// software distributed under the License is distributed on an
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
// KIND, either express or implied.  See the License for the
// specific language governing permissions and limitations
// under the License.

//go:build go1.21

package pulsar

import "testing"

func TestClientWithSlog(t *testing.T) {
	
}

For 2 you could see - in my PR description, I did an integration test where I started a producer with logrus, and producer with slog - and then I compared the output of both loggers, in terms of length and keys (since I was doing json). But this seems too complicated and not needed for what I was trying to test.

So I would be provocative and ask, do we even need a test?

You only need to verify the client with slog works fine.

You can also verify the log output:

// Licensed to the Apache Software Foundation (ASF) under one
// or more contributor license agreements.  See the NOTICE file
// distributed with this work for additional information
// regarding copyright ownership.  The ASF licenses this file
// to you under the Apache License, Version 2.0 (the
// "License"); you may not use this file except in compliance
// with the License.  You may obtain a copy of the License at
//
//   http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing,
// software distributed under the License is distributed on an
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
// KIND, either express or implied.  See the License for the
// specific language governing permissions and limitations
// under the License.

//go:build go1.21

package log

import (
	"context"
	"log/slog"
	"testing"

	"github.com/stretchr/testify/assert"
)

type defaultHandle struct {
	records []slog.Record
}

func (d *defaultHandle) Enabled(ctx context.Context, level slog.Level) bool {
	return true
}

func (d *defaultHandle) Handle(ctx context.Context, record slog.Record) error {
	d.records = append(d.records, record)
	return nil
}

func (d *defaultHandle) WithAttrs(attrs []slog.Attr) slog.Handler {
	panic("implement me")
}

func (d *defaultHandle) WithGroup(name string) slog.Handler {
	panic("implement me")
}

var _ slog.Handler = &defaultHandle{}

func TestSlog(t *testing.T) {
	handler := &defaultHandle{}
	logger := slog.New(handler)
	logger.Info("1")
	assert.Equal(t, handler.records[0].Level, slog.LevelInfo)
	assert.Equal(t, handler.records[0].Message, "1")
}

Thanks for your time!

nodece avatar Jul 04 '24 15:07 nodece

If everyone is OK with the suggested changes, would someone be able to merge this in? cc @nodece @crossoverJie @RobertIndie

ivan-penchev avatar Jul 05 '24 07:07 ivan-penchev

but I noticed that the v0.13.0 milestone has a deadline in 2 days. And was wondering, due to the nature of the change, if it would be feasible to review it with the goal of including it in that release?

Yes. We can include this in v0.13.0. And regarding the v0.13.0 release, we found a critical bug in the Go transaction, and I want to include that fix in the release as well. Therefore, the ETA for v0.13.0 will be at the end of next week.

RobertIndie avatar Jul 05 '24 09:07 RobertIndie