Fix orbit and osqueryd logging on Windows (#3521)

* Fix orbit and osqueryd logging on Windows

* Add functionality to test the change and use systemprofile app data

* Add centos syslog to README.md

* Add wait on orbit for osquery extension socket to exist (#3571)

* Wait for osquery extension socket to exist

* Amend changes

* Fix lint

* Restore timeout

changes/issue-3100-add-windows-orbit-osquery-logging

@@ -0,0 +1 @@
+* Fix logging of orbit and osqueryd on Windows.

changes/issue-3522-increase-extension-register-timeout

@@ -0,0 +1 @@
+* Add wait on orbit for osquery extension socket.

orbit/README.md

@@ -167,6 +167,33 @@ This process may take several minutes to complete as the Notarization process co
 
 After successful notarization, the generated "ticket" is automatically stapled to the package.
 
+#### Orbit Development
+
+For ease of development of Orbit, `fleetctl package` allows the generation of a package with a
+custom orbit executable using the `FLEETCTL_ORBIT_DEV_BUILD_PATH` environment variable:
+```sh
+FLEETCTL_ORBIT_DEV_BUILD_PATH=$(pwd)/orbit.exe ./build/fleetctl package --type=msi --fleet-url=https://localhost:8080 --enroll-secret=the_secret_value
+Generating your osquery installer...
+2022/01/03 20:31:10 root pinning is not supported in Spec 1.0.19
+WARNING: You are attempting to override orbit with a dev build.
+Press Enter to continue, or Control-c to exit.
+[...]
+```
+
+### Troubleshooting
+
+#### Logs
+
+Orbit captures and streams osqueryd's stdout/stderr into its own stdout/stderr output.
+Following are the destination of logs for each platform (to access such locations the user will need administrative permissions on the host):
+- Linux: Orbit and osqueryd stdout/stderr output is sent to syslog (`/var/log/syslog` on Debian systems and `/var/log/messages` on CentOS).
+- macOS: `/private/var/log/orbit/orbit.std{out|err}.log`.
+- Windows: `C:\Windows\system32\config\systemprofile\AppData\Local\FleetDM\Orbit\Logs\orbit-osquery.lg` (the log file is rotated).
+
+#### Debug
+
+You can use the `--debug` option in `fleetctl package` to generate installers in "debug mode". Such mode increases the verbosity of logging for orbit and osqueryd (log DEBUG level).
+
 ### Uninstall
 #### Windows
 

orbit/cmd/orbit/orbit.go

@@ -4,11 +4,13 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"io"
 	"io/fs"
 	"io/ioutil"
 	"net/url"
 	"os"
 	"path/filepath"
+	"runtime"
 	"strings"
 	"time"
 
@@ -25,6 +27,7 @@ import (
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
 	"github.com/urfave/cli/v2"
+	"gopkg.in/natefinch/lumberjack.v2"
 )
 
 var (
@@ -112,17 +115,33 @@ func main() {
 			return nil
 		}
 
-		log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339Nano, NoColor: true})
-		if logfile := c.String("log-file"); logfile != "" {
-			f, err := secure.OpenFile(logfile, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o600)
-			if err != nil {
-				return fmt.Errorf("open logfile: %w", err)
+		var logFile io.Writer
+		if logf := c.String("log-file"); logf != "" {
+			if logDir := filepath.Dir(logf); logDir != "." {
+				if err := secure.MkdirAll(logDir, constant.DefaultDirMode); err != nil {
+					panic(err)
+				}
 			}
-			log.Logger = log.Output(zerolog.MultiLevelWriter(
-				zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339Nano, NoColor: true},
-				zerolog.ConsoleWriter{Out: f, TimeFormat: time.RFC3339Nano, NoColor: true},
-			))
+			logFile = &lumberjack.Logger{
+				Filename:   logf,
+				MaxSize:    25, // megabytes
+				MaxBackups: 3,
+				MaxAge:     28, // days
+			}
+			if runtime.GOOS == "windows" {
+				// On Windows, Orbit runs as a "Windows Service", which fails to write to os.Stderr with
+				// "write /dev/stderr: The handle is invalid" (see #3100). Thus, we log to the logFile only.
+				log.Logger = log.Output(zerolog.ConsoleWriter{Out: logFile, TimeFormat: time.RFC3339Nano, NoColor: true})
+			} else {
+				log.Logger = log.Output(zerolog.MultiLevelWriter(
+					zerolog.ConsoleWriter{Out: logFile, TimeFormat: time.RFC3339Nano, NoColor: true},
+					zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339Nano, NoColor: true},
+				))
+			}
+		} else {
+			log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339Nano, NoColor: true})
 		}
+
 		zerolog.SetGlobalLevel(zerolog.InfoLevel)
 
 		if c.Bool("debug") {
@@ -210,6 +229,11 @@ func main() {
 		var options []func(*osquery.Runner) error
 		options = append(options, osquery.WithDataPath(c.String("root-dir")))
 
+		if logFile != nil {
+			// If set, redirect osqueryd's stderr to the logFile.
+			options = append(options, osquery.WithStderr(logFile))
+		}
+
 		fleetURL := c.String("fleet-url")
 		if !strings.HasPrefix(fleetURL, "http") {
 			fleetURL = "https://" + fleetURL
@@ -342,7 +366,6 @@ func main() {
 		r, _ := osquery.NewRunner(osquerydPath, options...)
 		g.Add(r.Execute, r.Interrupt)
 
-		// Extension tables not yet supported on Windows.
 		ext := table.NewRunner(r.ExtensionSocketPath())
 		g.Add(ext.Execute, ext.Interrupt)
 

orbit/cmd/orbit/shell.go

@@ -79,7 +79,6 @@ var shellCommand = &cli.Command{
 		)
 		g.Add(r.Execute, r.Interrupt)
 
-		// Extension tables not yet supported on Windows.
 		ext := table.NewRunner(r.ExtensionSocketPath())
 		g.Add(ext.Execute, ext.Interrupt)
 

orbit/pkg/osquery/osquery.go

@@ -4,6 +4,7 @@ package osquery
 import (
 	"context"
 	"fmt"
+	"io"
 	"os"
 	"os/exec"
 	"path/filepath"
@@ -81,7 +82,7 @@ func WithDataPath(path string) func(*Runner) error {
 	return func(r *Runner) error {
 		r.dataPath = path
 
-		if err := secure.MkdirAll(filepath.Join(path, "logs"), constant.DefaultDirMode); err != nil {
+		if err := secure.MkdirAll(path, constant.DefaultDirMode); err != nil {
 			return fmt.Errorf("initialize osquery data path: %w", err)
 		}
 
@@ -94,6 +95,14 @@ func WithDataPath(path string) func(*Runner) error {
 	}
 }
 
+// WithStderr sets the runner's cmd's stderr to the given writer.
+func WithStderr(w io.Writer) func(*Runner) error {
+	return func(r *Runner) error {
+		r.cmd.Stderr = w
+		return nil
+	}
+}
+
 func WithLogPath(path string) func(*Runner) error {
 	return func(r *Runner) error {
 		if err := secure.MkdirAll(path, constant.DefaultDirMode); err != nil {

orbit/pkg/packaging/macos.go

@@ -85,15 +85,6 @@ func BuildPkg(opt Options) (string, error) {
 		}
 	}
 
-	// TODO gate behind a flag and allow copying a local orbit
-	// if err := file.Copy(
-	// 	"./orbit",
-	// 	filepath.Join(orbitRoot, "bin", "orbit", "macos", "current", "orbit"),
-	// 	0755,
-	// ); err != nil {
-	// 	return errors.Wrap(err, "write orbit")
-	// }
-
 	// Build package
 
 	if err := xarBom(opt, tmpDir); err != nil {

orbit/pkg/packaging/packaging.go

@@ -94,6 +94,10 @@ func InitializeUpdates(updateOpt update.Options) error {
 	}
 	log.Debug().Str("path", orbitPath).Msg("got orbit")
 
+	if devBuildPath := os.Getenv("FLEETCTL_ORBIT_DEV_BUILD_PATH"); devBuildPath != "" {
+		updater.CopyDevBuild("orbit", updateOpt.OrbitChannel, devBuildPath)
+	}
+
 	return nil
 }
 

orbit/pkg/packaging/windows_templates.go

@@ -52,7 +52,7 @@ var windowsWixTemplate = template.Must(template.New("").Option("missingkey=error
                   ErrorControl="ignore"
                   Start="auto"
                   Type="ownProcess"
-                  Arguments='--root-dir "[ORBITROOT]." --log-file "[ORBITROOT]orbit-log.txt" {{ if .FleetURL }}--fleet-url "{{ .FleetURL }}"{{ end }} {{ if .FleetCertificate }}--fleet-certificate "[ORBITROOT]fleet.pem"{{ end }} {{ if .EnrollSecret }}--enroll-secret-path "[ORBITROOT]secret.txt"{{ end }} {{if .Insecure }}--insecure{{ end }} {{ if .UpdateURL }}--update-url "{{ .UpdateURL }}" {{ end }} --orbit-channel "{{ .OrbitChannel }}" --osqueryd-channel "{{ .OsquerydChannel }}"'
+                  Arguments='--root-dir "[ORBITROOT]." --log-file "[System64Folder]config\systemprofile\AppData\Local\FleetDM\Orbit\Logs\orbit-osquery.log" {{ if .FleetURL }}--fleet-url "{{ .FleetURL }}"{{ end }} {{ if .FleetCertificate }}--fleet-certificate "[ORBITROOT]fleet.pem"{{ end }} {{ if .EnrollSecret }}--enroll-secret-path "[ORBITROOT]secret.txt"{{ end }} {{if .Insecure }}--insecure{{ end }} {{ if .Debug }}--debug{{ end }} {{ if .UpdateURL }}--update-url "{{ .UpdateURL }}" {{ end }} --orbit-channel "{{ .OrbitChannel }}" --osqueryd-channel "{{ .OsquerydChannel }}"'
                 >
                   <util:ServiceConfig
                     FirstFailureActionType="restart"

orbit/pkg/table/extension.go

@@ -2,6 +2,8 @@ package table
 
 import (
 	"context"
+	"fmt"
+	"os"
 	"time"
 
 	"github.com/kolide/osquery-go"
@@ -27,6 +29,10 @@ func NewRunner(socket string) *Runner {
 
 // Execute creates an osquery extension manager server and registers osquery plugins.
 func (r *Runner) Execute() error {
+	if err := waitForSocket(r.socket, 1*time.Minute); err != nil {
+		return err
+	}
+
 	ctx, cancel := context.WithCancel(context.Background())
 	r.cancel = cancel
 
@@ -76,3 +82,29 @@ func (r *Runner) Interrupt(err error) {
 		r.srv.Shutdown(context.Background())
 	}
 }
+
+// waitForSocket waits for the osquery socket to exist.
+//
+// This method was copied from osquery-go because we can't rely on option.ServerTimeout.
+// Such timeout is used both for waiting for the socket and for the thrift transport.
+func waitForSocket(sockPath string, timeout time.Duration) error {
+	ticker := time.NewTicker(200 * time.Millisecond)
+	defer ticker.Stop()
+	ctx, cancel := context.WithTimeout(context.Background(), timeout)
+	defer cancel()
+	for {
+		select {
+		case <-ctx.Done():
+			return ctx.Err()
+		case <-ticker.C:
+			switch _, err := os.Stat(sockPath); {
+			case err == nil:
+				return nil
+			case os.IsNotExist(err):
+				continue
+			default:
+				return fmt.Errorf("stat socket %s failed: %w", sockPath, err)
+			}
+		}
+	}
+}

orbit/pkg/update/update.go

@@ -2,15 +2,18 @@
 package update
 
 import (
+	"bufio"
 	"crypto/tls"
 	"encoding/json"
 	"errors"
 	"fmt"
+	"io"
 	"os"
 	"os/exec"
 	"path"
 	"path/filepath"
 
+	"github.com/fatih/color"
 	"github.com/fleetdm/fleet/v4/orbit/pkg/constant"
 	"github.com/fleetdm/fleet/v4/orbit/pkg/platform"
 	"github.com/fleetdm/fleet/v4/pkg/fleethttp"
@@ -183,6 +186,46 @@ func (u *Updater) Get(target, channel string) (string, error) {
 	return localPath, nil
 }
 
+func writeDevWarningBanner(w io.Writer) {
+	warningColor := color.New(color.FgWhite, color.Bold, color.BgRed)
+	warningColor.Fprintf(w, "WARNING: You are attempting to override orbit with a dev build.\nPress Enter to continue, or Control-c to exit.")
+	// We need to disable color and print a new line to make it look somewhat neat, otherwise colors continue to the
+	// next line
+	warningColor.DisableColor()
+	warningColor.Fprintln(w)
+	bufio.NewScanner(os.Stdin).Scan()
+}
+
+// CopyDevBuilds uses a development build for the given target+channel.
+//
+// This is just for development, must not be used in production.
+func (u *Updater) CopyDevBuild(target, channel, devBuildPath string) {
+	writeDevWarningBanner(os.Stderr)
+
+	localPath := u.LocalPath(target, channel)
+	if err := secure.MkdirAll(filepath.Dir(localPath), constant.DefaultDirMode); err != nil {
+		panic(err)
+	}
+	dst, err := secure.OpenFile(localPath, os.O_CREATE|os.O_WRONLY, constant.DefaultExecutableMode)
+	if err != nil {
+		panic(err)
+	}
+	defer dst.Close()
+
+	src, err := secure.OpenFile(devBuildPath, os.O_RDONLY, constant.DefaultExecutableMode)
+	if err != nil {
+		panic(err)
+	}
+	defer src.Close()
+
+	if _, err := src.Stat(); err != nil {
+		panic(err)
+	}
+	if _, err := io.Copy(dst, src); err != nil {
+		panic(err)
+	}
+}
+
 // Download downloads the target to the provided path. The file is deleted and
 // an error is returned if the hash does not match.
 func (u *Updater) Download(repoPath, localPath string) error {