Search code examples
gosarama

Testing log output from GitHub.com/Shopify/sarama


I'm trying to write a unit test for a functional option that configure's github.com/Shopify/sarama's Logger. After running a Docker container with Kafka like so,

docker run -p 2181:2181 -p 9092:9092 -e ADVERTISED_HOST=127.0.0.1  -e NUM_PARTITIONS=10 johnnypark/kafka-zookeeper

I'm trying to run this program:

package main

import (
    "bufio"
    "bytes"
    "io/ioutil"
    "log"

    "github.com/Shopify/sarama"
)

func main() {
    var b bytes.Buffer
    out := bufio.NewWriter(&b)

    sarama.Logger = log.New(out, "[Sarama] ", log.LstdFlags)

    if _, err := sarama.NewClient([]string{"localhost:9092"}, sarama.NewConfig()); err != nil {
        log.Fatalln("NewClient:", err)
    }

    output, err := ioutil.ReadAll(&b)
    if err != nil {
        log.Fatalln("ReadAll:", err)
    }

    log.Printf("output: %s", output)
}

and I would expect to see some output. However, the printed output is empty:

> go run main.go
2020/09/25 16:44:58 output: 

By contrast, if I set the output to os.Stderr,

package main

import (
    "log"
    "os"

    "github.com/Shopify/sarama"
)

func main() {
    sarama.Logger = log.New(os.Stderr, "[Sarama] ", log.LstdFlags)

    if _, err := sarama.NewClient([]string{"localhost:9092"}, sarama.NewConfig()); err != nil {
        log.Fatalln("NewClient:", err)
    }
}

I see the expected output printed to the terminal:

> go run main.go
[Sarama] 2020/09/25 16:46:04 Initializing new client
[Sarama] 2020/09/25 16:46:04 ClientID is the default of 'sarama', you should consider setting it to something application-specific.
[Sarama] 2020/09/25 16:46:04 ClientID is the default of 'sarama', you should consider setting it to something application-specific.
[Sarama] 2020/09/25 16:46:04 client/metadata fetching metadata for all topics from broker localhost:9092
[Sarama] 2020/09/25 16:46:04 Connected to broker at localhost:9092 (unregistered)
[Sarama] 2020/09/25 16:46:04 client/brokers registered new broker #0 at 127.0.0.1:9092
[Sarama] 2020/09/25 16:46:04 Successfully initialized new client

It seems that the *bytes.Buffer is not getting 'flushed' by ioutil.ReadAll()? How can I fix the previous example so that output is non-empty?


Solution

  • It turns out I just needed to call

    out.Flush()
    

    before ioutil.ReadAll(). Now the output is as expected:

    > go run main.go
    2020/09/25 16:58:26 output: [Sarama] 2020/09/25 16:58:26 Initializing new client
    [Sarama] 2020/09/25 16:58:26 ClientID is the default of 'sarama', you should consider setting it to something application-specific.
    [Sarama] 2020/09/25 16:58:26 ClientID is the default of 'sarama', you should consider setting it to something application-specific.
    [Sarama] 2020/09/25 16:58:26 client/metadata fetching metadata for all topics from broker localhost:9092
    [Sarama] 2020/09/25 16:58:26 Connected to broker at localhost:9092 (unregistered)
    [Sarama] 2020/09/25 16:58:26 client/brokers registered new broker #0 at 127.0.0.1:9092
    [Sarama] 2020/09/25 16:58:26 Successfully initialized new client