// TestFiltering tests the filtering of the logging.
func TestFiltering(t *testing.T) {
	assert := audit.NewTestingAssertion(t, true)

	ownLogger := &testLogger{}
	logger.SetLogger(ownLogger)
	logger.SetLevel(logger.LevelDebug)
	logger.SetFilter(func(level logger.LogLevel, info, msg string) bool {
		return level >= logger.LevelWarning && level <= logger.LevelError
	})

	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
	assert.Length(ownLogger.logs, 3)

	logger.UnsetFilter()

	ownLogger = &testLogger{}
	logger.SetLogger(ownLogger)
	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
	assert.Length(ownLogger.logs, 5)
}

func main() {
	config := cachet.Config
	// TODO support log path
	logger.SetLogger(logger.NewTimeformatLogger(os.Stderr, "2006-01-02 15:04:05"))
	logger.SetLevel(logger.LevelDebug)

	logger.Infof("System: %s, API: %s", config.SystemName, config.APIUrl)
	logger.Infof("Starting %d monitors", len(config.MonitorConfigs))

	// initialize monitors
	var allMonitors []*cachet.Monitor
	for _, monconf := range config.MonitorConfigs {
		err, mon := cachet.NewMonitor(&monconf)
		if err == nil {
			err = cachet.SyncMonitor(mon)
			if err != nil {
				logger.Errorf("%v", err)
			}
			allMonitors = append(allMonitors, mon)
		} else {
			logger.Errorf("Parsing monitor error, skipping: %v", err)
		}
	}

	ticker := time.NewTicker(time.Second * time.Duration(config.CheckInterval))
	for range ticker.C {
		for _, m := range allMonitors {
			go m.Check()
		}
	}
}

// logError finally checks logging and formatting before logging an error.
func (d *defaulter) logError(format string, err error) {
	if !d.log {
		return
	}
	format += ": %v"
	if len(d.id) > 0 {
		logger.Infof("(%s) "+format, d.id, err)
	} else {
		logger.Infof(format, err)
	}
}

func (th *TestHandler) Get(ctx web.Context) (bool, error) {
	data := TestRequestData{ctx.Domain(), ctx.Resource(), ctx.ResourceID()}
	switch {
	case ctx.AcceptsContentType(web.ContentTypeXML):
		logger.Infof("get XML")
		ctx.WriteXML(data)
	case ctx.AcceptsContentType(web.ContentTypeJSON):
		logger.Infof("get JSON")
		ctx.WriteJSON(data, true)
	default:
		logger.Infof("get HTML")
		ctx.RenderTemplate("test:context:html", data)
	}
	return true, nil
}

func (i *FileIndex) Save() error {
	i.m.RLock()
	defer i.m.RUnlock()
	idxFile := i.file
	if idxFile == "" {
		err := fmt.Errorf("Yikes! Cannot save index to disk because no file was specified.")
		return err
	}
	if !i.updated {
		return nil
	}
	logger.Infof("Index has changed, saving to disk")
	fp, err := ioutil.TempFile(path.Dir(idxFile), "idx-build")
	if err != nil {
		return err
	}
	zfp := zlib.NewWriter(fp)

	i.updated = false
	enc := gob.NewEncoder(zfp)
	err = enc.Encode(i)
	zfp.Close()
	if err != nil {
		fp.Close()
		return err
	}
	err = fp.Close()
	if err != nil {
		return err
	}
	return os.Rename(fp.Name(), idxFile)
}

func startNodeMonitor() {
	// Never do this if serf isn't set up
	if !config.Config.UseSerf {
		return
	}
	go func() {
		// wait 1 minute before starting to check for nodes being up
		time.Sleep(1 * time.Minute)
		ticker := time.NewTicker(time.Minute)
		for _ = range ticker.C {
			unseen, err := node.UnseenNodes()
			if err != nil {
				logger.Errorf(err.Error())
				continue
			}
			for _, n := range unseen {
				logger.Infof("Haven't seen %s for a while, marking as down", n.Name)
				err = n.UpdateStatus("down")
				if err != nil {
					logger.Errorf(err.Error())
					continue
				}
			}
		}
	}()
	return
}

// logCommand logs a command and its execution status.
func logCommand(cmd string, args []interface{}, err error, log bool) {
	// Format the command for the log entry.
	formatArgs := func() string {
		if args == nil || len(args) == 0 {
			return "(none)"
		}
		output := make([]string, len(args))
		for i, arg := range args {
			output[i] = string(valueToBytes(arg))
		}
		return strings.Join(output, " / ")
	}
	logOutput := func() string {
		format := "CMD %s ARGS %s %s"
		if err == nil {
			return fmt.Sprintf(format, cmd, formatArgs(), "OK")
		}
		return fmt.Sprintf(format, cmd, formatArgs(), "ERROR "+err.Error())
	}
	// Log positive commands only if wanted, errors always.
	if err != nil {
		if errors.IsError(err, ErrServerResponse) || errors.IsError(err, ErrTimeout) {
			return
		}
		logger.Errorf(logOutput())
	} else if log {
		logger.Infof(logOutput())
	}
}

// ProcessEvent reads, validates and emits a configuration.
func (b *configuratorBehavior) ProcessEvent(event cells.Event) error {
	switch event.Topic() {
	case ReadConfigurationTopic:
		// Read configuration
		filename, ok := event.Payload().GetString(ConfigurationFilenamePayload)
		if !ok {
			logger.Errorf("cannot read configuration without filename payload")
			return nil
		}
		logger.Infof("reading configuration from %q", filename)
		cfg, err := etc.ReadFile(filename)
		if err != nil {
			return errors.Annotate(err, ErrCannotReadConfiguration, errorMessages)
		}
		// If wanted then validate it.
		if b.validate != nil {
			err = b.validate(cfg)
			if err != nil {
				return errors.Annotate(err, ErrCannotValidateConfiguration, errorMessages)
			}
		}
		// All done, emit it.
		pvs := cells.PayloadValues{
			ConfigurationPayload: cfg,
		}
		b.cell.EmitNewContext(ConfigurationTopic, pvs, event.Context())
	}
	return nil
}

// Stop implements the Environment interface.
func (env *environment) Stop() error {
	runtime.SetFinalizer(env, nil)
	if err := env.cells.stop(); err != nil {
		return err
	}
	logger.Infof("cells environment %q terminated", env.ID())
	return nil
}

// stop terminates the cell.
func (c *cell) stop() error {
	c.emitTimeoutTicker.Stop()
	err := c.loop.Stop()
	if err != nil {
		logger.Errorf("cell %q terminated with error: %v", c.id, err)
	} else {
		logger.Infof("cell %q terminated", c.id)
	}
	return err
}

func jsonErrorReport(w http.ResponseWriter, r *http.Request, errorStr string, status int) {
	logger.Infof(errorStr)
	jsonError := map[string][]string{"error": []string{errorStr}}
	w.WriteHeader(status)
	enc := json.NewEncoder(w)
	if err := enc.Encode(&jsonError); err != nil {
		logger.Errorf(err.Error())
	}
	return
}

// newCell create a new cell around a behavior.
func newCell(env *environment, id string, behavior Behavior) (*cell, error) {
	logger.Infof("cell '%s' starts", id)
	// Init cell runtime.
	c := &cell{
		env:               env,
		id:                id,
		measuringID:       identifier.Identifier("cells", env.id, "cell", id),
		behavior:          behavior,
		emitters:          newConnections(),
		subscribers:       newConnections(),
		emitTimeoutTicker: time.NewTicker(5 * time.Second),
	}
	// Set configuration.
	if bebs, ok := behavior.(BehaviorEventBufferSize); ok {
		size := bebs.EventBufferSize()
		if size < minEventBufferSize {
			size = minEventBufferSize
		}
		c.eventc = make(chan Event, size)
	} else {
		c.eventc = make(chan Event, minEventBufferSize)
	}
	if brf, ok := behavior.(BehaviorRecoveringFrequency); ok {
		number, duration := brf.RecoveringFrequency()
		if duration.Seconds()/float64(number) < 0.1 {
			number = minRecoveringNumber
			duration = minRecoveringDuration
		}
		c.recoveringNumber = number
		c.recoveringDuration = duration
	} else {
		c.recoveringNumber = minRecoveringNumber
		c.recoveringDuration = minRecoveringDuration
	}
	if bet, ok := behavior.(BehaviorEmitTimeout); ok {
		timeout := bet.EmitTimeout()
		switch {
		case timeout < minEmitTimeout:
			timeout = minEmitTimeout
		case timeout > maxEmitTimeout:
			timeout = maxEmitTimeout
		}
		c.emitTimeout = int(timeout.Seconds() / 5)
	} else {
		c.emitTimeout = int(maxEmitTimeout.Seconds() / 5)
	}
	// Init behavior.
	if err := behavior.Init(c); err != nil {
		return nil, errors.Annotate(err, ErrCellInit, errorMessages, id)
	}
	// Start backend.
	c.loop = loop.GoRecoverable(c.backendLoop, c.checkRecovering, id)
	return c, nil
}

// Test logging with the go logger.
func TestGoLogger(t *testing.T) {
	log.SetOutput(os.Stdout)

	logger.SetLevel(logger.LevelDebug)
	logger.SetLogger(logger.NewGoLogger())

	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
}

// Save freezes and saves the data store to disk.
func (ds *DataStore) Save(dsFile string) error {
	if !ds.updated {
		return nil
	}
	logger.Infof("Data has changed, saving data store to disk")
	if dsFile == "" {
		err := fmt.Errorf("Yikes! Cannot save data store to disk because no file was specified.")
		return err
	}
	fp, err := ioutil.TempFile(path.Dir(dsFile), "ds-store")
	if err != nil {
		return err
	}
	zfp := zlib.NewWriter(fp)

	fstore := new(dsFileStore)
	dscache := new(bytes.Buffer)
	objList := new(bytes.Buffer)
	ds.m.RLock()
	defer ds.m.RUnlock()
	ds.updated = false

	err = ds.dsc.Save(dscache)
	if err != nil {
		fp.Close()
		return err
	}
	enc := gob.NewEncoder(objList)
	defer func() {
		if x := recover(); x != nil {
			err = fmt.Errorf("Something went wrong encoding the data store with Gob")
		}
	}()
	err = enc.Encode(ds.objList)
	if err != nil {
		fp.Close()
		return err
	}
	fstore.Cache = dscache.Bytes()
	fstore.ObjList = objList.Bytes()
	enc = gob.NewEncoder(zfp)
	err = enc.Encode(fstore)
	zfp.Close()
	if err != nil {
		fp.Close()
		return err
	}
	err = fp.Close()
	if err != nil {
		return err
	}
	return os.Rename(fp.Name(), dsFile)
}

// Test log level filtering.
func TestLogLevelFiltering(t *testing.T) {
	assert := audit.NewTestingAssertion(t, true)

	ownLogger := &testLogger{}
	logger.SetLogger(ownLogger)
	logger.SetLevel(logger.LevelDebug)
	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
	assert.Length(ownLogger.logs, 5)

	ownLogger = &testLogger{}
	logger.SetLogger(ownLogger)
	logger.SetLevel(logger.LevelError)
	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
	assert.Length(ownLogger.logs, 2)
}

func handleSignals() {
	c := make(chan os.Signal, 1)
	// SIGTERM is not exactly portable, but Go has a fake signal for it
	// with Windows so it being there should theoretically not break it
	// running on windows
	signal.Notify(c, os.Interrupt, syscall.SIGTERM, syscall.SIGHUP)

	// if we receive a SIGINT or SIGTERM, do cleanup here.
	go func() {
		for sig := range c {
			if sig == os.Interrupt || sig == syscall.SIGTERM {
				logger.Infof("cleaning up...")
				if config.Config.FreezeData {
					if config.Config.DataStoreFile != "" {
						ds := datastore.New()
						if err := ds.Save(config.Config.DataStoreFile); err != nil {
							logger.Errorf(err.Error())
						}
					}
					if err := indexer.SaveIndex(); err != nil {
						logger.Errorf(err.Error())
					}
				}
				if config.UsingDB() {
					datastore.Dbh.Close()
				}
				if config.Config.UseSerf {
					serfin.Serfer.Close()
				}
				os.Exit(0)
			} else if sig == syscall.SIGHUP {
				logger.Infof("Reloading configuration...")
				config.ParseConfigOptions()
			}
		}
	}()
}

// NewEnvironment creates a new environment.
func NewEnvironment(idParts ...interface{}) Environment {
	var id string
	if len(idParts) == 0 {
		id = identifier.NewUUID().String()
	} else {
		id = identifier.Identifier(idParts...)
	}
	env := &environment{
		id:    id,
		cells: newRegistry(),
	}
	runtime.SetFinalizer(env, (*environment).Stop)
	logger.Infof("cells environment %q started", env.ID())
	return env
}

// Test logging with the syslogger.
func TestSysLogger(t *testing.T) {
	assert := audit.NewTestingAssertion(t, true)

	logger.SetLevel(logger.LevelDebug)

	sl, err := logger.NewSysLogger("GOAS")
	assert.Nil(err)
	logger.SetLogger(sl)

	logger.Debugf("Debug.")
	logger.Infof("Info.")
	logger.Warningf("Warning.")
	logger.Errorf("Error.")
	logger.Criticalf("Critical.")
}

// New creates a new sandbox, given a map of null values with file checksums as
// keys.
func New(checksumHash map[string]interface{}) (*Sandbox, error) {
	/* For some reason the checksums come in a JSON hash that looks like
	 * this:
	 * { "checksums": {
	 * "385ea5490c86570c7de71070bce9384a":null,
	 * "f6f73175e979bd90af6184ec277f760c":null,
	 * "2e03dd7e5b2e6c8eab1cf41ac61396d5":null
	 * } } --- per the chef server api docs. Not sure why it comes in that
	 * way rather than as an array, since those nulls are apparently never
	 * anything but nulls. */

	/* First generate an id for this sandbox. Collisions are certainly
	 * possible, so we'll give it five tries to make a unique one before
	 * bailing. This may later turn out not to be the ideal sandbox creation
	 * method, but we'll see. */
	var sandboxID string
	var err error
	for i := 0; i < 5; i++ {
		sandboxID, err = generateSandboxID()
		if err != nil {
			/* Something went very wrong. */
			return nil, err
		}
		if s, _ := Get(sandboxID); s != nil {
			logger.Infof("Collision! Somehow %s already existed as a sandbox id on attempt %d. Trying again.", sandboxID, i)
			sandboxID = ""
		}
	}

	if sandboxID == "" {
		err = fmt.Errorf("Somehow every attempt to create a unique sandbox id failed. Bailing.")
		return nil, err
	}
	checksums := make([]string, len(checksumHash))
	j := 0
	for k := range checksumHash {
		checksums[j] = k
		j++
	}

	sbox := &Sandbox{
		ID:           sandboxID,
		CreationTime: time.Now(),
		Completed:    false,
		Checksums:    checksums,
	}
	return sbox, nil
}

// handle handles a request.
func (m *mapping) handle(ctx *context) error {
	// Find handler.
	location := m.location(ctx.Domain(), ctx.Resource())
	hl, ok := m.handlers[location]
	if !ok {
		defaultLocation := m.location(ctx.DefaultDomain(), ctx.DefaultResource())
		hl, ok = m.handlers[defaultLocation]
		if !ok {
			return errors.New(ErrNoHandler, errorMessages, location, defaultLocation)
		}
		location = defaultLocation
	}
	// Dispatch by method.
	logger.Infof("handling %s", ctx)
	return hl.handle(ctx)
}