func logServerLoad(server *TunnelServer) {

	// golang runtime stats

	var memStats runtime.MemStats
	runtime.ReadMemStats(&memStats)
	fields := LogFields{
		"event_name":    "server_load",
		"build_rev":     common.GetBuildInfo().BuildRev,
		"host_id":       server.sshServer.support.Config.HostID,
		"num_goroutine": runtime.NumGoroutine(),
		"mem_stats": map[string]interface{}{
			"alloc":           memStats.Alloc,
			"total_alloc":     memStats.TotalAlloc,
			"sys":             memStats.Sys,
			"pause_total_ns":  memStats.PauseTotalNs,
			"pause_ns":        memStats.PauseNs,
			"num_gc":          memStats.NumGC,
			"gc_cpu_fraction": memStats.GCCPUFraction,
		},
	}

	// tunnel server stats

	fields["establish_tunnels"] = server.GetEstablishTunnels()

	for tunnelProtocol, stats := range server.GetLoadStats() {
		fields[tunnelProtocol] = stats
	}

	log.LogRawFieldsWithTimestamp(fields)
}
Example #2
0
// NoticeBuildInfo reports build version info.
func NoticeBuildInfo() {
	outputNotice("BuildInfo", 0, "buildInfo", common.GetBuildInfo())
}
// RunServices initializes support functions including logging and GeoIP services;
// and then starts the server components and runs them until os.Interrupt or
// os.Kill signals are received. The config determines which components are run.
func RunServices(configJSON []byte) error {

	rand.Seed(int64(time.Now().Nanosecond()))

	config, err := LoadConfig(configJSON)
	if err != nil {
		log.WithContextFields(LogFields{"error": err}).Error("load config failed")
		return common.ContextError(err)
	}

	err = InitLogging(config)
	if err != nil {
		log.WithContextFields(LogFields{"error": err}).Error("init logging failed")
		return common.ContextError(err)
	}

	supportServices, err := NewSupportServices(config)
	if err != nil {
		log.WithContextFields(LogFields{"error": err}).Error("init support services failed")
		return common.ContextError(err)
	}

	log.WithContextFields(*common.GetBuildInfo().ToMap()).Info("startup")

	waitGroup := new(sync.WaitGroup)
	shutdownBroadcast := make(chan struct{})
	errors := make(chan error)

	tunnelServer, err := NewTunnelServer(supportServices, shutdownBroadcast)
	if err != nil {
		log.WithContextFields(LogFields{"error": err}).Error("init tunnel server failed")
		return common.ContextError(err)
	}

	supportServices.TunnelServer = tunnelServer

	if config.RunLoadMonitor() {
		waitGroup.Add(1)
		go func() {
			waitGroup.Done()
			ticker := time.NewTicker(time.Duration(config.LoadMonitorPeriodSeconds) * time.Second)
			defer ticker.Stop()
			for {
				select {
				case <-shutdownBroadcast:
					return
				case <-ticker.C:
					logServerLoad(tunnelServer)
				}
			}
		}()
	}

	if config.RunWebServer() {
		waitGroup.Add(1)
		go func() {
			defer waitGroup.Done()
			err := RunWebServer(supportServices, shutdownBroadcast)
			select {
			case errors <- err:
			default:
			}
		}()
	}

	// The tunnel server is always run; it launches multiple
	// listeners, depending on which tunnel protocols are enabled.
	waitGroup.Add(1)
	go func() {
		defer waitGroup.Done()
		err := tunnelServer.Run()
		select {
		case errors <- err:
		default:
		}
	}()

	// Shutdown doesn't wait for the outputProcessProfiles goroutine
	// to complete, as it may be sleeping while running a "block" or
	// CPU profile.
	signalProcessProfiles := make(chan struct{}, 1)
	go func() {
		for {
			select {
			case <-signalProcessProfiles:
				outputProcessProfiles(supportServices.Config)
			case <-shutdownBroadcast:
				return
			}
		}
	}()

	// An OS signal triggers an orderly shutdown
	systemStopSignal := make(chan os.Signal, 1)
	signal.Notify(systemStopSignal, os.Interrupt, os.Kill, syscall.SIGTERM)

	// SIGUSR1 triggers a reload of support services
	reloadSupportServicesSignal := make(chan os.Signal, 1)
	signal.Notify(reloadSupportServicesSignal, syscall.SIGUSR1)

	// SIGUSR2 triggers an immediate load log and optional process profile output
	logServerLoadSignal := make(chan os.Signal, 1)
	signal.Notify(logServerLoadSignal, syscall.SIGUSR2)

	// SIGTSTP triggers tunnelServer to stop establishing new tunnels
	stopEstablishingTunnelsSignal := make(chan os.Signal, 1)
	signal.Notify(stopEstablishingTunnelsSignal, syscall.SIGTSTP)

	// SIGCONT triggers tunnelServer to resume establishing new tunnels
	resumeEstablishingTunnelsSignal := make(chan os.Signal, 1)
	signal.Notify(resumeEstablishingTunnelsSignal, syscall.SIGCONT)

	err = nil

loop:
	for {
		select {
		case <-stopEstablishingTunnelsSignal:
			tunnelServer.SetEstablishTunnels(false)

		case <-resumeEstablishingTunnelsSignal:
			tunnelServer.SetEstablishTunnels(true)

		case <-reloadSupportServicesSignal:
			supportServices.Reload()
			// Reset traffic rules for established clients to reflect reloaded config
			// TODO: only update when traffic rules config has changed
			tunnelServer.ResetAllClientTrafficRules()

		case <-logServerLoadSignal:
			// Signal profiles writes first to ensure some diagnostics are
			// available in case logServerLoad hangs (which has happened
			// in the past due to a deadlock bug).
			select {
			case signalProcessProfiles <- *new(struct{}):
			default:
			}
			logServerLoad(tunnelServer)

		case <-systemStopSignal:
			log.WithContext().Info("shutdown by system")
			break loop

		case err = <-errors:
			log.WithContextFields(LogFields{"error": err}).Error("service failed")
			break loop
		}
	}

	close(shutdownBroadcast)
	waitGroup.Wait()

	return err
}
Example #4
0
// getRequestLogFields makes LogFields to log the API event following
// the legacy psi_web and current ELK naming conventions.
func getRequestLogFields(
	support *SupportServices,
	eventName string,
	geoIPData GeoIPData,
	params requestJSONObject,
	expectedParams []requestParamSpec) LogFields {

	logFields := make(LogFields)

	logFields["event_name"] = eventName
	logFields["host_id"] = support.Config.HostID
	logFields["build_rev"] = common.GetBuildInfo().BuildRev

	// In psi_web, the space replacement was done to accommodate space
	// delimited logging, which is no longer required; we retain the
	// transformation so that stats aggregation isn't impacted.
	logFields["client_region"] = strings.Replace(geoIPData.Country, " ", "_", -1)
	logFields["client_city"] = strings.Replace(geoIPData.City, " ", "_", -1)
	logFields["client_isp"] = strings.Replace(geoIPData.ISP, " ", "_", -1)

	if params == nil {
		return logFields
	}

	for _, expectedParam := range expectedParams {

		if expectedParam.flags&requestParamNotLogged != 0 {
			continue
		}

		value := params[expectedParam.name]
		if value == nil {

			// Special case: older clients don't send this value,
			// so log a default.
			if expectedParam.name == "tunnel_whole_device" {
				value = "0"
			} else {
				// Skip omitted, optional params
				continue
			}
		}

		switch v := value.(type) {
		case string:
			strValue := v

			// Special cases:
			// - Number fields are encoded as integer types.
			// - For ELK performance we record these domain-or-IP
			//   fields as one of two different values based on type;
			//   we also omit port from host:port fields for now.
			switch expectedParam.name {
			case "client_version":
				intValue, _ := strconv.Atoi(strValue)
				logFields[expectedParam.name] = intValue
			case "meek_dial_address":
				host, _, _ := net.SplitHostPort(strValue)
				if isIPAddress(support, host) {
					logFields["meek_dial_ip_address"] = host
				} else {
					logFields["meek_dial_domain"] = host
				}
			case "meek_host_header":
				host, _, _ := net.SplitHostPort(strValue)
				logFields[expectedParam.name] = host
			case "upstream_proxy_type":
				// Submitted value could be e.g., "SOCKS5" or "socks5"; log lowercase
				logFields[expectedParam.name] = strings.ToLower(strValue)
			default:
				logFields[expectedParam.name] = strValue
			}

		case []interface{}:
			// Note: actually validated as an array of strings
			logFields[expectedParam.name] = v

		default:
			// This type assertion should be checked already in
			// validateRequestParams, so failure is unexpected.
			continue
		}
	}

	return logFields
}