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)
}
// 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
}
// 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
}
