github.com/demonoid81/moby@v0.0.0-20200517203328-62dd8e17c460/daemon/logger/jsonfilelog/jsonfilelog_test.go (about)

     1  package jsonfilelog // import "github.com/demonoid81/moby/daemon/logger/jsonfilelog"
     2  
     3  import (
     4  	"bytes"
     5  	"compress/gzip"
     6  	"encoding/json"
     7  	"fmt"
     8  	"io/ioutil"
     9  	"os"
    10  	"path/filepath"
    11  	"reflect"
    12  	"strconv"
    13  	"testing"
    14  	"time"
    15  
    16  	"github.com/demonoid81/moby/daemon/logger"
    17  	"github.com/demonoid81/moby/daemon/logger/jsonfilelog/jsonlog"
    18  	"gotest.tools/v3/assert"
    19  	is "gotest.tools/v3/assert/cmp"
    20  	"gotest.tools/v3/fs"
    21  )
    22  
    23  func TestJSONFileLogger(t *testing.T) {
    24  	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
    25  	tmp, err := ioutil.TempDir("", "docker-logger-")
    26  	if err != nil {
    27  		t.Fatal(err)
    28  	}
    29  	defer os.RemoveAll(tmp)
    30  	filename := filepath.Join(tmp, "container.log")
    31  	l, err := New(logger.Info{
    32  		ContainerID: cid,
    33  		LogPath:     filename,
    34  	})
    35  	if err != nil {
    36  		t.Fatal(err)
    37  	}
    38  	defer l.Close()
    39  
    40  	if err := l.Log(&logger.Message{Line: []byte("line1"), Source: "src1"}); err != nil {
    41  		t.Fatal(err)
    42  	}
    43  	if err := l.Log(&logger.Message{Line: []byte("line2"), Source: "src2"}); err != nil {
    44  		t.Fatal(err)
    45  	}
    46  	if err := l.Log(&logger.Message{Line: []byte("line3"), Source: "src3"}); err != nil {
    47  		t.Fatal(err)
    48  	}
    49  	res, err := ioutil.ReadFile(filename)
    50  	if err != nil {
    51  		t.Fatal(err)
    52  	}
    53  	expected := `{"log":"line1\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
    54  {"log":"line2\n","stream":"src2","time":"0001-01-01T00:00:00Z"}
    55  {"log":"line3\n","stream":"src3","time":"0001-01-01T00:00:00Z"}
    56  `
    57  
    58  	if string(res) != expected {
    59  		t.Fatalf("Wrong log content: %q, expected %q", res, expected)
    60  	}
    61  }
    62  
    63  func TestJSONFileLoggerWithTags(t *testing.T) {
    64  	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
    65  	cname := "test-container"
    66  	tmp, err := ioutil.TempDir("", "docker-logger-")
    67  
    68  	assert.NilError(t, err)
    69  
    70  	defer os.RemoveAll(tmp)
    71  	filename := filepath.Join(tmp, "container.log")
    72  	l, err := New(logger.Info{
    73  		Config: map[string]string{
    74  			"tag": "{{.ID}}/{{.Name}}", // first 12 characters of ContainerID and full ContainerName
    75  		},
    76  		ContainerID:   cid,
    77  		ContainerName: cname,
    78  		LogPath:       filename,
    79  	})
    80  
    81  	assert.NilError(t, err)
    82  	defer l.Close()
    83  
    84  	err = l.Log(&logger.Message{Line: []byte("line1"), Source: "src1"})
    85  	assert.NilError(t, err)
    86  
    87  	err = l.Log(&logger.Message{Line: []byte("line2"), Source: "src2"})
    88  	assert.NilError(t, err)
    89  
    90  	err = l.Log(&logger.Message{Line: []byte("line3"), Source: "src3"})
    91  	assert.NilError(t, err)
    92  
    93  	res, err := ioutil.ReadFile(filename)
    94  	assert.NilError(t, err)
    95  
    96  	expected := `{"log":"line1\n","stream":"src1","attrs":{"tag":"a7317399f3f8/test-container"},"time":"0001-01-01T00:00:00Z"}
    97  {"log":"line2\n","stream":"src2","attrs":{"tag":"a7317399f3f8/test-container"},"time":"0001-01-01T00:00:00Z"}
    98  {"log":"line3\n","stream":"src3","attrs":{"tag":"a7317399f3f8/test-container"},"time":"0001-01-01T00:00:00Z"}
    99  `
   100  	assert.Check(t, is.Equal(expected, string(res)))
   101  }
   102  
   103  func BenchmarkJSONFileLoggerLog(b *testing.B) {
   104  	tmp := fs.NewDir(b, "bench-jsonfilelog")
   105  	defer tmp.Remove()
   106  
   107  	jsonlogger, err := New(logger.Info{
   108  		ContainerID: "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657",
   109  		LogPath:     tmp.Join("container.log"),
   110  		Config: map[string]string{
   111  			"labels":   "first,second",
   112  			"max-file": "10",
   113  			"compress": "true",
   114  			"max-size": "20m",
   115  		},
   116  		ContainerLabels: map[string]string{
   117  			"first":  "label_value",
   118  			"second": "label_foo",
   119  		},
   120  	})
   121  	assert.NilError(b, err)
   122  	defer jsonlogger.Close()
   123  
   124  	t := time.Now().UTC()
   125  	for _, data := range [][]byte{
   126  		[]byte(""),
   127  		[]byte("a short string"),
   128  		bytes.Repeat([]byte("a long string"), 100),
   129  		bytes.Repeat([]byte("a really long string"), 10000),
   130  	} {
   131  		b.Run(fmt.Sprintf("%d", len(data)), func(b *testing.B) {
   132  			testMsg := &logger.Message{
   133  				Line:      data,
   134  				Source:    "stderr",
   135  				Timestamp: t,
   136  			}
   137  
   138  			buf := bytes.NewBuffer(nil)
   139  			assert.NilError(b, marshalMessage(testMsg, nil, buf))
   140  			b.SetBytes(int64(buf.Len()))
   141  			b.ResetTimer()
   142  			for i := 0; i < b.N; i++ {
   143  				msg := logger.NewMessage()
   144  				msg.Line = testMsg.Line
   145  				msg.Timestamp = testMsg.Timestamp
   146  				msg.Source = testMsg.Source
   147  				if err := jsonlogger.Log(msg); err != nil {
   148  					b.Fatal(err)
   149  				}
   150  			}
   151  		})
   152  	}
   153  }
   154  
   155  func TestJSONFileLoggerWithOpts(t *testing.T) {
   156  	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
   157  	tmp, err := ioutil.TempDir("", "docker-logger-")
   158  	if err != nil {
   159  		t.Fatal(err)
   160  	}
   161  	defer os.RemoveAll(tmp)
   162  	filename := filepath.Join(tmp, "container.log")
   163  	config := map[string]string{"max-file": "3", "max-size": "1k", "compress": "true"}
   164  	l, err := New(logger.Info{
   165  		ContainerID: cid,
   166  		LogPath:     filename,
   167  		Config:      config,
   168  	})
   169  	if err != nil {
   170  		t.Fatal(err)
   171  	}
   172  	defer l.Close()
   173  	for i := 0; i < 36; i++ {
   174  		if err := l.Log(&logger.Message{Line: []byte("line" + strconv.Itoa(i)), Source: "src1"}); err != nil {
   175  			t.Fatal(err)
   176  		}
   177  	}
   178  
   179  	res, err := ioutil.ReadFile(filename)
   180  	if err != nil {
   181  		t.Fatal(err)
   182  	}
   183  
   184  	penUlt, err := ioutil.ReadFile(filename + ".1")
   185  	if err != nil {
   186  		if !os.IsNotExist(err) {
   187  			t.Fatal(err)
   188  		}
   189  
   190  		file, err := os.Open(filename + ".1.gz")
   191  		if err != nil {
   192  			t.Fatal(err)
   193  		}
   194  		defer file.Close()
   195  		zipReader, err := gzip.NewReader(file)
   196  		if err != nil {
   197  			t.Fatal(err)
   198  		}
   199  		defer zipReader.Close()
   200  		penUlt, err = ioutil.ReadAll(zipReader)
   201  		if err != nil {
   202  			t.Fatal(err)
   203  		}
   204  	}
   205  
   206  	file, err := os.Open(filename + ".2.gz")
   207  	if err != nil {
   208  		t.Fatal(err)
   209  	}
   210  	defer file.Close()
   211  	zipReader, err := gzip.NewReader(file)
   212  	if err != nil {
   213  		t.Fatal(err)
   214  	}
   215  	defer zipReader.Close()
   216  	antepenult, err := ioutil.ReadAll(zipReader)
   217  	if err != nil {
   218  		t.Fatal(err)
   219  	}
   220  
   221  	expectedAntepenultimate := `{"log":"line0\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   222  {"log":"line1\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   223  {"log":"line2\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   224  {"log":"line3\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   225  {"log":"line4\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   226  {"log":"line5\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   227  {"log":"line6\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   228  {"log":"line7\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   229  {"log":"line8\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   230  {"log":"line9\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   231  {"log":"line10\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   232  {"log":"line11\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   233  {"log":"line12\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   234  {"log":"line13\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   235  {"log":"line14\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   236  {"log":"line15\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   237  `
   238  	expectedPenultimate := `{"log":"line16\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   239  {"log":"line17\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   240  {"log":"line18\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   241  {"log":"line19\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   242  {"log":"line20\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   243  {"log":"line21\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   244  {"log":"line22\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   245  {"log":"line23\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   246  {"log":"line24\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   247  {"log":"line25\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   248  {"log":"line26\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   249  {"log":"line27\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   250  {"log":"line28\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   251  {"log":"line29\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   252  {"log":"line30\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   253  {"log":"line31\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   254  `
   255  	expected := `{"log":"line32\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   256  {"log":"line33\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   257  {"log":"line34\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   258  {"log":"line35\n","stream":"src1","time":"0001-01-01T00:00:00Z"}
   259  `
   260  
   261  	if string(res) != expected {
   262  		t.Fatalf("Wrong log content: %q, expected %q", res, expected)
   263  	}
   264  	if string(penUlt) != expectedPenultimate {
   265  		t.Fatalf("Wrong log content: %q, expected %q", penUlt, expectedPenultimate)
   266  	}
   267  	if string(antepenult) != expectedAntepenultimate {
   268  		t.Fatalf("Wrong log content: %q, expected %q", antepenult, expectedAntepenultimate)
   269  	}
   270  }
   271  
   272  func TestJSONFileLoggerWithLabelsEnv(t *testing.T) {
   273  	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
   274  	tmp, err := ioutil.TempDir("", "docker-logger-")
   275  	if err != nil {
   276  		t.Fatal(err)
   277  	}
   278  	defer os.RemoveAll(tmp)
   279  	filename := filepath.Join(tmp, "container.log")
   280  	config := map[string]string{"labels": "rack,dc", "labels-regex": "^loc", "env": "environ,debug,ssl", "env-regex": "^dc"}
   281  	l, err := New(logger.Info{
   282  		ContainerID:     cid,
   283  		LogPath:         filename,
   284  		Config:          config,
   285  		ContainerLabels: map[string]string{"rack": "101", "dc": "lhr", "location": "here"},
   286  		ContainerEnv:    []string{"environ=production", "debug=false", "port=10001", "ssl=true", "dc_region=west"},
   287  	})
   288  	if err != nil {
   289  		t.Fatal(err)
   290  	}
   291  	defer l.Close()
   292  	if err := l.Log(&logger.Message{Line: []byte("line"), Source: "src1"}); err != nil {
   293  		t.Fatal(err)
   294  	}
   295  	res, err := ioutil.ReadFile(filename)
   296  	if err != nil {
   297  		t.Fatal(err)
   298  	}
   299  
   300  	var jsonLog jsonlog.JSONLogs
   301  	if err := json.Unmarshal(res, &jsonLog); err != nil {
   302  		t.Fatal(err)
   303  	}
   304  	extra := make(map[string]string)
   305  	if err := json.Unmarshal(jsonLog.RawAttrs, &extra); err != nil {
   306  		t.Fatal(err)
   307  	}
   308  	expected := map[string]string{
   309  		"rack":      "101",
   310  		"dc":        "lhr",
   311  		"location":  "here",
   312  		"environ":   "production",
   313  		"debug":     "false",
   314  		"ssl":       "true",
   315  		"dc_region": "west",
   316  	}
   317  	if !reflect.DeepEqual(extra, expected) {
   318  		t.Fatalf("Wrong log attrs: %q, expected %q", extra, expected)
   319  	}
   320  }