// Copyright 2018 The Fuchsia Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

//go:build !build_with_native_toolchain
// +build !build_with_native_toolchain

package syslog_test

import (
	"bytes"
	"context"
	"encoding/binary"
	"errors"
	"fmt"
	"io/ioutil"
	"os"
	"path/filepath"
	"strings"
	"syscall/zx"
	"syscall/zx/fidl"
	"syscall/zx/zxwait"
	"testing"
	"unicode/utf8"

	"fidl/fuchsia/diagnostics"
	"fidl/fuchsia/logger"

	"go.fuchsia.dev/fuchsia/src/lib/component"
	syslog "go.fuchsia.dev/fuchsia/src/lib/syslog/go"
)

const format = "integer: %d"

var pid = uint64(os.Getpid())

var _ logger.LogSinkWithCtx = (*logSinkImpl)(nil)

type logSinkImpl struct {
	onConnect             func(fidl.Context, zx.Socket)
	waitForInterestChange <-chan logger.LogSinkWaitForInterestChangeResult
}

func (impl *logSinkImpl) Connect(ctx fidl.Context, socket zx.Socket) error {
	impl.onConnect(ctx, socket)
	return nil
}

func (*logSinkImpl) ConnectStructured(fidl.Context, zx.Socket) error {
	return nil
}

func (impl *logSinkImpl) WaitForInterestChange(fidl.Context) (logger.LogSinkWaitForInterestChangeResult, error) {
	if result := <-impl.waitForInterestChange; result != (logger.LogSinkWaitForInterestChangeResult{}) {
		return result, nil
	}
	return logger.LogSinkWaitForInterestChangeResult{}, &zx.Error{Status: zx.ErrCanceled}
}

func TestLogSimple(t *testing.T) {
	actual := bytes.Buffer{}
	var options syslog.LogInitOptions
	options.MinSeverityForFileAndLineInfo = syslog.ErrorLevel
	options.Writer = &actual
	log, err := syslog.NewLogger(options)
	if err != nil {
		t.Fatal(err)
	}
	if err := log.Infof(format, 10); err != nil {
		t.Fatal(err)
	}
	expected := "INFO: integer: 10\n"
	got := string(actual.Bytes())
	if !strings.HasSuffix(got, expected) {
		t.Errorf("%q should have ended in %q", got, expected)
	}
	if !strings.Contains(got, fmt.Sprintf("[%d]", pid)) {
		t.Errorf("%q should contains %d", got, pid)
	}
}

func setup(t *testing.T, tags ...string) (chan<- logger.LogSinkWaitForInterestChangeResult, zx.Socket, *syslog.Logger) {
	req, logSink, err := logger.NewLogSinkWithCtxInterfaceRequest()
	if err != nil {
		t.Fatal(err)
	}

	ctx, cancel := context.WithCancel(context.Background())
	ch := make(chan struct{})
	t.Cleanup(func() {
		cancel()
		<-ch
	})

	waitForInterestChange := make(chan logger.LogSinkWaitForInterestChangeResult)
	t.Cleanup(func() { close(waitForInterestChange) })

	sinChan := make(chan zx.Socket, 1)
	defer close(sinChan)
	go func() {
		defer close(ch)

		component.Serve(ctx, &logger.LogSinkWithCtxStub{
			Impl: &logSinkImpl{
				onConnect: func(_ fidl.Context, socket zx.Socket) {
					sinChan <- socket
				},
				waitForInterestChange: waitForInterestChange,
			},
		}, req.Channel, component.ServeOptions{
			OnError: func(err error) {
				var zxError *zx.Error
				if errors.As(err, &zxError) {
					if zxError.Status == zx.ErrCanceled {
						return
					}
				}
				t.Error(err)
			},
		})
	}()

	options := syslog.LogInitOptions{
		LogLevel: syslog.InfoLevel,
	}
	options.LogSink = logSink
	options.MinSeverityForFileAndLineInfo = syslog.ErrorLevel
	options.Tags = tags
	log, err := syslog.NewLogger(options)
	if err != nil {
		t.Fatal(err)
	}

	s := <-sinChan

	// Throw away system-generated messages.
	for i := 0; i < 1; i++ {
		if _, err := zxwait.WaitContext(context.Background(), zx.Handle(s), zx.SignalSocketReadable); err != nil {
			t.Fatal(err)
		}
		var data [logger.MaxDatagramLenBytes]byte
		if _, err := s.Read(data[:], 0); err != nil {
			t.Fatal(err)
		}
	}

	return waitForInterestChange, s, log
}

func checkoutput(t *testing.T, sin zx.Socket, expectedMsg string, severity syslog.LogLevel, tags ...string) {
	var data [logger.MaxDatagramLenBytes]byte
	n, err := sin.Read(data[:], 0)
	if err != nil {
		t.Fatal(err)
	}
	if n <= 32 {
		t.Fatalf("got invalid data: %x", data[:n])
	}
	gotpid := binary.LittleEndian.Uint64(data[0:8])
	gotTid := binary.LittleEndian.Uint64(data[8:16])
	gotTime := binary.LittleEndian.Uint64(data[16:24])
	gotSeverity := int32(binary.LittleEndian.Uint32(data[24:28]))
	gotDroppedLogs := int32(binary.LittleEndian.Uint32(data[28:32]))

	if pid != gotpid {
		t.Errorf("pid error, got: %d, want: %d", gotpid, pid)
	}

	if 0 != gotTid {
		t.Errorf("tid error, got: %d, want: %d", gotTid, 0)
	}

	if int32(severity) != gotSeverity {
		t.Errorf("severity error, got: %d, want: %d", gotSeverity, severity)
	}

	if gotTime <= 0 {
		t.Errorf("time %d should be greater than zero", gotTime)
	}

	if 0 != gotDroppedLogs {
		t.Errorf("dropped logs error, got: %d, want: %d", gotDroppedLogs, 0)
	}
	pos := 32
	for i, tag := range tags {
		length := len(tag)
		if data[pos] != byte(length) {
			t.Fatalf("tag iteration %d: expected data to be %d at pos %d, got %d", i, length, pos, data[pos])
		}
		pos = pos + 1
		gotTag := string(data[pos : pos+length])
		if tag != gotTag {
			t.Fatalf("tag iteration %d: expected tag %q , got %q", i, tag, gotTag)
		}
		pos = pos + length
	}

	if data[pos] != 0 {
		t.Fatalf("byte before msg start should be zero, got: %d, %x", data[pos], data[pos:n])
	}

	msgGot := string(data[pos+1 : n-1])
	if expectedMsg != msgGot {
		t.Fatalf("expected msg:%q, got %q", expectedMsg, msgGot)
	}
	if data[n-1] != 0 {
		t.Fatalf("last byte should be zero, got: %d, %x", data[pos], data[32:n])
	}
}

func TestLog(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()

	if err := log.Infof(format, 10); err != nil {
		t.Fatal(err)
	}
	checkoutput(t, sin, fmt.Sprintf(format, 10), syslog.InfoLevel)
}

func TestLogWithLocalTag(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	if err := log.InfoTf("local_tag", format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel, "local_tag")
}

func TestLogWithGlobalTags(t *testing.T) {
	_, sin, log := setup(t, "gtag1", "gtag2")
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	if err := log.InfoTf("local_tag", format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel, "gtag1", "gtag2", "local_tag")
}

func TestLoggerSeverity(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	log.SetSeverity(diagnostics.Severity(syslog.WarningLevel))
	if err := log.Infof(format, 10); err != nil {
		t.Fatal(err)
	}
	_, err := sin.Read(nil, 0)
	if err, ok := err.(*zx.Error); !ok || err.Status != zx.ErrShouldWait {
		t.Fatal(err)
	}
	if err := log.Warnf(format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.WarningLevel)
}

func TestLoggerVerbosity(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	if err := log.VLogf(syslog.DebugVerbosity, format, 10); err != nil {
		t.Fatal(err)
	}
	_, err := sin.Read(nil, 0)
	if err, ok := err.(*zx.Error); !ok || err.Status != zx.ErrShouldWait {
		t.Fatal(err)
	}
	log.SetVerbosity(syslog.DebugVerbosity)
	if err := log.VLogf(syslog.DebugVerbosity, format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel-1)
}

func TestLoggerRegisterInterest(t *testing.T) {
	ch, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()

	registerInterest := func(interest diagnostics.Interest) {
		t.Helper()

		ch <- logger.LogSinkWaitForInterestChangeResultWithResponse(logger.LogSinkWaitForInterestChangeResponse{
			Data: interest,
		})

		// Consume the system-generated messages.
		for i := 0; i < 2; i++ {
			if _, err := zxwait.WaitContext(context.Background(), zx.Handle(sin), zx.SignalSocketReadable); err != nil {
				t.Fatal(err)
			}
			var data [logger.MaxDatagramLenBytes]byte
			if _, err := sin.Read(data[:], 0); err != nil {
				t.Fatal(err)
			}
		}
	}

	// Register interest and observe that the log is emitted.
	{
		var interest diagnostics.Interest
		interest.SetMinSeverity(diagnostics.SeverityDebug)
		registerInterest(interest)
	}
	if err := log.VLogf(syslog.DebugVerbosity, format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel-1)

	// Register empty interest and observe that severity resets to initial.
	registerInterest(diagnostics.Interest{})
	if err := log.VLogf(syslog.DebugVerbosity, format, 10); err != nil {
		t.Fatal(err)
	}
	_, err := sin.Read(nil, 0)
	if err, ok := err.(*zx.Error); !ok || err.Status != zx.ErrShouldWait {
		t.Fatal(err)
	}
}

func TestGlobalTagLimits(t *testing.T) {
	var options syslog.LogInitOptions
	options.Writer = os.Stdout
	var tags [logger.MaxTags + 1]string
	for i := 0; i < len(tags); i++ {
		tags[i] = "a"
	}
	options.Tags = tags[:]
	if _, err := syslog.NewLogger(options); err == nil || !strings.Contains(err.Error(), "too many tags") {
		t.Fatalf("unexpected error: %s", err)
	}
	options.Tags = tags[:logger.MaxTags]
	var tag [logger.MaxTagLenBytes + 1]byte
	for i := 0; i < len(tag); i++ {
		tag[i] = 65
	}
	options.Tags[1] = string(tag[:])
	if _, err := syslog.NewLogger(options); err == nil || !strings.Contains(err.Error(), "tag too long") {
		t.Fatalf("unexpected error: %s", err)
	}
}

func TestLocalTagLimits(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	var tag [logger.MaxTagLenBytes + 1]byte
	for i := 0; i < len(tag); i++ {
		tag[i] = 65
	}
	if err := log.InfoTf(string(tag[:]), format, 10); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf(format, 10)
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel, string(tag[:logger.MaxTagLenBytes]))
}

func TestLogToWriterWhenSocketCloses(t *testing.T) {
	_, sin, log := setup(t, "gtag1", "gtag2")
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
	}()
	if err := sin.Close(); err != nil {
		t.Fatal(err)
	}
	old := os.Stderr
	defer func() {
		os.Stderr = old
	}()

	f, err := os.Create(filepath.Join(t.TempDir(), "syslog-test"))
	if err != nil {
		t.Fatal(err)
	}
	defer func() {
		if err := f.Close(); err != nil {
			t.Error(err)
		}
	}()
	os.Stderr = f
	if err := log.InfoTf("local_tag", format, 10); err != nil {
		t.Fatal(err)
	}
	if err := f.Sync(); err != nil {
		t.Fatal(err)
	}
	expectedMsg := fmt.Sprintf("[0][gtag1, gtag2, local_tag] INFO: %s\n", fmt.Sprintf(format, 10))
	content, err := ioutil.ReadFile(f.Name())
	os.Stderr = old
	if err != nil {
		t.Fatal(err)
	}
	got := string(content)
	if !strings.HasSuffix(got, expectedMsg) {
		t.Fatalf("%q should have ended in %q", got, expectedMsg)
	}
}

func TestMessageLenLimit(t *testing.T) {
	_, sin, log := setup(t)
	defer func() {
		if err := log.Close(); err != nil {
			t.Error(err)
		}
		if err := sin.Close(); err != nil {
			t.Error(err)
		}
	}()
	// 1 for starting and ending null bytes.
	msgLen := int(logger.MaxDatagramLenBytes) - 32 - 1 - 1

	const stripped = '𠜎'
	// Ensure only part of stripped fits.
	msg := strings.Repeat("x", msgLen-(utf8.RuneLen(stripped)-1)) + string(stripped)
	switch err := log.Infof(msg).(type) {
	case *syslog.ErrMsgTooLong:
		if err.Msg != string(stripped) {
			t.Fatalf("unexpected truncation: %s", err.Msg)
		}
	default:
		t.Fatalf("unexpected error: %#v", err)
	}

	const ellipsis = "..."
	expectedMsg := msg[:msgLen-len(ellipsis)] + ellipsis
	checkoutput(t, sin, expectedMsg, syslog.InfoLevel)
}