path: root/networkQuality.go

/*
 * This file is part of Go Responsiveness.
 *
 * Go Responsiveness is free software: you can redistribute it and/or modify it under
 * the terms of the GNU General Public License as published by the Free Software Foundation,
 * either version 3 of the License, or (at your option) any later version.
 * Go Responsiveness is distributed in the hope that it will be useful, but WITHOUT ANY
 * WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A
 * PARTICULAR PURPOSE. See the GNU General Public License for more details.
 *
 * You should have received a copy of the GNU General Public License along
 * with Foobar. If not, see <https://www.gnu.org/licenses/>.
 */

package main

import (
	"context"
	"crypto/tls"
	"flag"
	"fmt"
	_ "io"
	_ "log"
	"net/http"
	"os"
	"runtime/pprof"
	"time"

	"github.com/network-quality/goresponsiveness/ccw"
	"github.com/network-quality/goresponsiveness/config"
	"github.com/network-quality/goresponsiveness/constants"
	"github.com/network-quality/goresponsiveness/debug"
	"github.com/network-quality/goresponsiveness/lgc"
	"github.com/network-quality/goresponsiveness/rpm"
	"github.com/network-quality/goresponsiveness/timeoutat"
	"github.com/network-quality/goresponsiveness/utilities"
	"golang.org/x/net/http2"
)

var (
	// Variables to hold CLI arguments.
	configHost = flag.String(
		"config",
		constants.DefaultConfigHost,
		"name/IP of responsiveness configuration server.",
	)
	configPort = flag.Int(
		"port",
		constants.DefaultPortNumber,
		"port number on which to access responsiveness configuration server.",
	)
	configPath = flag.String(
		"path",
		"config",
		"path on the server to the configuration endpoint.",
	)
	debugCliFlag = flag.Bool(
		"debug",
		constants.DefaultDebug,
		"Enable debugging.",
	)
	strictFlag = flag.Bool(
		"strict",
		constants.DefaultStrict,
		"Whether to run the test in strict mode (measure HTTP get time on load-generating connection)",
	)
	timeout = flag.Int(
		"timeout",
		constants.DefaultTestTime,
		"Maximum time to spend measuring.",
	)
	sslKeyFileName = flag.String(
		"ssl-key-file",
		"",
		"Store the per-session SSL key files in this file.",
	)
	profile = flag.String(
		"profile",
		"",
		"Enable client runtime profiling and specify storage location. Disabled by default.",
	)
)

func main() {
	flag.Parse()

	timeoutDuration := time.Second * time.Duration(*timeout)
	timeoutAbsoluteTime := time.Now().Add(timeoutDuration)
	configHostPort := fmt.Sprintf("%s:%d", *configHost, *configPort)
	operatingCtx, cancelOperatingCtx := context.WithCancel(context.Background())
	saturationCtx, cancelSaturationCtx := context.WithCancel(
		context.Background(),
	)
	config := &config.Config{}
	var debugLevel debug.DebugLevel = debug.Error

	if *debugCliFlag {
		debugLevel = debug.Debug
	}

	if err := config.Get(configHostPort, *configPath); err != nil {
		fmt.Fprintf(os.Stderr, "%s\n", err)
		return
	}
	if err := config.IsValid(); err != nil {
		fmt.Fprintf(
			os.Stderr,
			"Error: Invalid configuration returned from %s: %v\n",
			config.Source,
			err,
		)
		return
	}
	if debug.IsDebug(debugLevel) {
		fmt.Printf("Configuration: %s\n", config)
	}

	timeoutChannel := timeoutat.TimeoutAt(
		operatingCtx,
		timeoutAbsoluteTime,
		debugLevel,
	)
	if debug.IsDebug(debugLevel) {
		fmt.Printf("Test will end earlier than %v\n", timeoutAbsoluteTime)
	}

	// print the banner
	dt := time.Now().UTC()
	fmt.Printf(
		"%s UTC Go Responsiveness to %s...\n",
		dt.Format("01-02-2006 15:04:05"),
		configHostPort,
	)

	if len(*profile) != 0 {
		f, err := os.Create(*profile)
		if err != nil {
			fmt.Fprintf(
				os.Stderr,
				"Error: Profiling requested with storage in %s but that file could not be opened: %v\n",
				*profile,
				err,
			)
			return
		}
		pprof.StartCPUProfile(f)
		defer pprof.StopCPUProfile()
	}

	var sslKeyFileConcurrentWriter *ccw.ConcurrentWriter = nil
	if *sslKeyFileName != "" {
		if sslKeyFileHandle, err := os.OpenFile(*sslKeyFileName, os.O_RDWR|os.O_CREATE, os.FileMode(0600)); err != nil {
			fmt.Printf("Could not open the keyfile for writing: %v!\n", err)
			sslKeyFileConcurrentWriter = nil
		} else {
			if err = utilities.SeekForAppend(sslKeyFileHandle); err != nil {
				fmt.Printf("Could not seek to the end of the key file: %v!\n", err)
				sslKeyFileConcurrentWriter = nil
			} else {
				if debug.IsDebug(debugLevel) {
					fmt.Printf("Doing SSL key logging through file %v\n", *sslKeyFileName)
				}
				sslKeyFileConcurrentWriter = ccw.NewConcurrentFileWriter(sslKeyFileHandle)
				defer sslKeyFileHandle.Close()
			}
		}
	}

	/*
	 * Create (and then, ironically, name) two anonymous functions that, when invoked,
	 * will create load-generating connections for upload/download/
	 */
	generate_lbd := func() lgc.LoadGeneratingConnection {
		return &lgc.LoadGeneratingConnectionDownload{
			Path:      config.Urls.LargeUrl,
			KeyLogger: sslKeyFileConcurrentWriter,
		}
	}
	generate_lbu := func() lgc.LoadGeneratingConnection {
		return &lgc.LoadGeneratingConnectionUpload{
			Path:      config.Urls.UploadUrl,
			KeyLogger: sslKeyFileConcurrentWriter,
		}
	}

	var downloadDebugging *debug.DebugWithPrefix = debug.NewDebugWithPrefix(debugLevel, "download")
	var uploadDebugging *debug.DebugWithPrefix = debug.NewDebugWithPrefix(debugLevel, "upload")

	downloadSaturationChannel := rpm.Saturate(
		saturationCtx,
		operatingCtx,
		generate_lbd,
		downloadDebugging,
	)
	uploadSaturationChannel := rpm.Saturate(
		saturationCtx,
		operatingCtx,
		generate_lbu,
		uploadDebugging,
	)

	saturationTimeout := false
	uploadSaturated := false
	downloadSaturated := false
	downloadSaturation := rpm.SaturationResult{}
	uploadSaturation := rpm.SaturationResult{}

	for !(uploadSaturated && downloadSaturated) {
		select {
		case downloadSaturation = <-downloadSaturationChannel:
			{
				downloadSaturated = true
				if *debugCliFlag {
					fmt.Printf(
						"################# download is %s saturated (%fMBps, %d flows)!\n",
						utilities.Conditional(
							saturationTimeout,
							"(provisionally)",
							"",
						),
						utilities.ToMBps(downloadSaturation.RateBps),
						len(downloadSaturation.LGCs),
					)
				}
			}
		case uploadSaturation = <-uploadSaturationChannel:
			{
				uploadSaturated = true
				if *debugCliFlag {
					fmt.Printf(
						"################# upload is %s saturated (%fMBps, %d flows)!\n",
						utilities.Conditional(
							saturationTimeout,
							"(provisionally)",
							"",
						),
						utilities.ToMBps(uploadSaturation.RateBps),
						len(uploadSaturation.LGCs),
					)
				}
			}
		case <-timeoutChannel:
			{
				if saturationTimeout {
					// We already timedout on saturation. This signal means that
					// we are timedout on getting the provisional saturation. We
					// will exit!
					fmt.Fprint(
						os.Stderr,
						"Error: Saturation could not be completed in time and no provisional rates could be assessed. Test failed.\n",
					)
					cancelOperatingCtx()
					if *debugCliFlag {
						time.Sleep(constants.CooldownPeriod)
					}
					return
				}
				saturationTimeout = true

				// We timed out attempting to saturate the link. So, we will
				// shut down all the saturation xfers
				cancelSaturationCtx()
				// and then we will give ourselves some additional time in order
				// to calculate a provisional saturation.
				timeoutAbsoluteTime = time.Now().
					Add(constants.RPMCalculationTime)
				timeoutChannel = timeoutat.TimeoutAt(
					operatingCtx,
					timeoutAbsoluteTime,
					debugLevel,
				)
				if *debugCliFlag {
					fmt.Printf(
						"################# timeout reaching saturation!\n",
					)
				}
			}
		}
	}

	// Give ourselves no more than 15 seconds to complete the RPM calculation.
	// This is conditional because (above) we may have already added the time.
	// We did it up there so that we could also limit the amount of time waiting
	// for a conditional saturation calculation.
	if !saturationTimeout {
		timeoutAbsoluteTime = time.Now().Add(constants.RPMCalculationTime)
		timeoutChannel = timeoutat.TimeoutAt(
			operatingCtx,
			timeoutAbsoluteTime,
			debugLevel,
		)
	}

	totalMeasurements := uint64(0)
	totalMeasurementTimes := float64(0)
	measurementTimeout := false

	for i := 0; i < constants.MeasurementProbeCount && !measurementTimeout; i++ {
		if len(downloadSaturation.LGCs) == 0 {
			continue
		}
		randomLGCsIndex := utilities.RandBetween(len(downloadSaturation.LGCs))
		if !downloadSaturation.LGCs[randomLGCsIndex].IsValid() {
			if *debugCliFlag {
				fmt.Printf(
					"%v: The randomly selected saturated connection (with id %d) was invalid. Skipping.\n",
					debugCliFlag,
					downloadSaturation.LGCs[randomLGCsIndex].ClientId(),
				)
			}

			// Protect against pathological cases where we continuously select
			// invalid connections and never
			// do the select below
			if time.Since(timeoutAbsoluteTime) > 0 {
				if *debugCliFlag {
					fmt.Printf(
						"Pathologically could not find valid saturated connections use for measurement.\n",
					)
				}
				break
			}
			continue
		}

		unsaturatedMeasurementTransport := http2.Transport{}
		unsaturatedMeasurementTransport.TLSClientConfig = &tls.Config{}
		if sslKeyFileConcurrentWriter != nil {
			unsaturatedMeasurementTransport.TLSClientConfig.KeyLogWriter = sslKeyFileConcurrentWriter
		}
		unsaturatedMeasurementTransport.TLSClientConfig.InsecureSkipVerify = true
		newClient := http.Client{Transport: &unsaturatedMeasurementTransport}

		unsaturatedMeasurementProbe := rpm.NewProbe(&newClient, debugLevel)

		saturatedMeasurementProbe := rpm.NewProbe(
			downloadSaturation.LGCs[randomLGCsIndex].Client(),
			debugLevel,
		)

		select {
		case <-timeoutChannel:
			{
				measurementTimeout = true
			}
		case sequentialMeasurementTimes := <-rpm.CalculateProbeMeasurements(operatingCtx, *strictFlag, saturatedMeasurementProbe, unsaturatedMeasurementProbe, config.Urls.SmallUrl, debugLevel):
			{
				if sequentialMeasurementTimes.Err != nil {
					fmt.Printf(
						"Failed to calculate a time for sequential measurements: %v\n",
						sequentialMeasurementTimes.Err,
					)
					continue
				}

				if debug.IsDebug(debugLevel) {
					fmt.Printf("unsaturatedMeasurementProbe: %v\n", unsaturatedMeasurementProbe)
				}
				// We know that we have a good Sequential measurement.
				totalMeasurements += uint64(sequentialMeasurementTimes.MeasurementCount)
				totalMeasurementTimes += sequentialMeasurementTimes.Delay.Seconds()
				if debug.IsDebug(debugLevel) {
					fmt.Printf(
						"most-recent sequential measurement time: %v; most-recent sequential measurement count: %v\n",
						sequentialMeasurementTimes.Delay.Seconds(),
						sequentialMeasurementTimes.MeasurementCount,
					)
				}
			}
		}
	}

	fmt.Printf(
		"Download: %7.3f Mbps (%7.3f MBps), using %d parallel connections.\n",
		utilities.ToMbps(downloadSaturation.RateBps),
		utilities.ToMBps(downloadSaturation.RateBps),
		len(downloadSaturation.LGCs),
	)
	fmt.Printf(
		"Upload:   %7.3f Mbps (%7.3f MBps), using %d parallel connections.\n",
		utilities.ToMbps(uploadSaturation.RateBps),
		utilities.ToMBps(uploadSaturation.RateBps),
		len(uploadSaturation.LGCs),
	)

	if totalMeasurements != 0 {
		// "... it sums the five time values for each probe, and divides by the
		// total
		// number of probes to compute an average probe duration.  The
		// reciprocal of this, normalized to 60 seconds, gives the Round-trips
		// Per Minute (RPM)."
		// "average probe duration" = totalMeasurementTimes / totalMeasurements.
		// The reciprocol of this = 1 / (totalMeasurementTimes / totalMeasurements) <-
		// semantically the probes-per-second.
		// Normalized to 60 seconds: 60 * (1
		// / ((totalMeasurementTimes / totalMeasurements)))) <- semantically the number of
		// probes per minute.
		rpm := float64(
			time.Minute.Seconds(),
		) / (totalMeasurementTimes / (float64(totalMeasurements)))
		fmt.Printf("Total measurements: %d\n", totalMeasurements)
		fmt.Printf("RPM: %5.0f\n", rpm)
	} else {
		fmt.Printf("Error occurred calculating RPM -- no probe measurements received.\n")
	}

	cancelOperatingCtx()
	if *debugCliFlag {
		fmt.Printf("In debugging mode, we will cool down.\n")
		time.Sleep(constants.CooldownPeriod)
		fmt.Printf("Done cooling down.\n")
	}
}