Implement a logging module. (#77)

* Implement a logging module.

This can safely set the logging verbosity level on a server using stdr package.

Implement basic unit tests and client/integration tests.

All client side support in sanssh to do this on the proxy itself.

Wire into proxy as an RPC it'll serve in addition to /Proxy.Proxy
This means we need to add interceptors for unary RPCs here now too.

* Rename from logging to sansshell as the service breakdown so it's obvious this is internal state.

* Fix client command to be sansshell instead of logging

cmd/proxy-server/server/server.go

@@ -40,6 +40,7 @@ import (
 	_ "github.com/Snowflake-Labs/sansshell/services/localfile"
 	_ "github.com/Snowflake-Labs/sansshell/services/packages"
 	_ "github.com/Snowflake-Labs/sansshell/services/process"
+	ss "github.com/Snowflake-Labs/sansshell/services/sansshell/server"
 	_ "github.com/Snowflake-Labs/sansshell/services/service"
 )
 
@@ -112,12 +113,18 @@ func Run(ctx context.Context, rs RunState, hooks ...rpcauth.RPCAuthzHook) {
 
 	serverOpts := []grpc.ServerOption{
 		grpc.Creds(serverCreds),
+		// Even though the proxy RPC is streaming we have unary RPCs (logging, reflection) we
+		// also need to properly auth and log.
+		grpc.ChainUnaryInterceptor(telemetry.UnaryServerLogInterceptor(rs.Logger), authz.Authorize),
 		grpc.ChainStreamInterceptor(telemetry.StreamServerLogInterceptor(rs.Logger), authz.AuthorizeStream),
 	}
 	g := grpc.NewServer(serverOpts...)
 
 	server.Register(g)
 	reflection.Register(g)
+	// Create a an instance of logging for the proxy server itself.
+	s := &ss.Server{}
+	s.Register(g)
 	rs.Logger.Info("initialized proxy service", "credsource", rs.CredSource)
 	rs.Logger.Info("serving..")
 

cmd/sanssh/client/client.go

@@ -38,6 +38,7 @@ import (
 	_ "github.com/Snowflake-Labs/sansshell/services/localfile/client"
 	_ "github.com/Snowflake-Labs/sansshell/services/packages/client"
 	_ "github.com/Snowflake-Labs/sansshell/services/process/client"
+	_ "github.com/Snowflake-Labs/sansshell/services/sansshell/client"
 	_ "github.com/Snowflake-Labs/sansshell/services/service/client"
 	"github.com/Snowflake-Labs/sansshell/services/util"
 )

cmd/sansshell-server/server/server.go

@@ -35,6 +35,7 @@ import (
 	_ "github.com/Snowflake-Labs/sansshell/services/localfile/server"
 	_ "github.com/Snowflake-Labs/sansshell/services/packages/server"
 	_ "github.com/Snowflake-Labs/sansshell/services/process/server"
+	_ "github.com/Snowflake-Labs/sansshell/services/sansshell/server"
 	_ "github.com/Snowflake-Labs/sansshell/services/service/server"
 )
 

proxy/proxy/proxy.go

@@ -62,6 +62,13 @@ func (p *Conn) Direct() bool {
 	return p.direct
 }
 
+// Proxy will return the ClientConn which connects directly to the proxy rather
+// than wrapped as proxy.Conn normally does. This allows callers to invoke direct RPCs
+// against the proxy as needed (such as services/logging).
+func (p *Conn) Proxy() *grpc.ClientConn {
+	return p.cc
+}
+
 // proxyStream provides all the context for send/receive in a grpc stream sense then translated to the streaming connection
 // we hold to the proxy. It also implements a fully functional grpc.ClientStream interface.
 type proxyStream struct {

services/sansshell/client/client.go

@@ -0,0 +1,214 @@
+/* Copyright (c) 2019 Snowflake Inc. All rights reserved.
+
+   Licensed under the Apache License, Version 2.0 (the
+   "License"); you may not use this file except in compliance
+   with the License.  You may obtain a copy of the License at
+
+     http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing,
+   software distributed under the License is distributed on an
+   "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+   KIND, either express or implied.  See the License for the
+   specific language governing permissions and limitations
+   under the License.
+*/
+
+// Package client provides the client interface for 'Logging'
+package client
+
+import (
+	"context"
+	"flag"
+	"fmt"
+	"os"
+	"time"
+
+	"github.com/google/subcommands"
+	"google.golang.org/protobuf/types/known/emptypb"
+
+	"github.com/Snowflake-Labs/sansshell/client"
+	pb "github.com/Snowflake-Labs/sansshell/services/sansshell"
+	"github.com/Snowflake-Labs/sansshell/services/util"
+)
+
+const subPackage = "sansshell"
+
+func init() {
+	subcommands.Register(&sansshellCmd{}, subPackage)
+}
+
+func setup(f *flag.FlagSet) *subcommands.Commander {
+	c := client.SetupSubpackage(subPackage, f)
+	c.Register(&setVerbosityCmd{}, "")
+	c.Register(&getVerbosityCmd{}, "")
+	c.Register(&setProxyVerbosityCmd{}, "")
+	c.Register(&getProxyVerbosityCmd{}, "")
+	return c
+}
+
+type sansshellCmd struct{}
+
+func (*sansshellCmd) Name() string { return subPackage }
+func (p *sansshellCmd) Synopsis() string {
+	return client.GenerateSynopsis(setup(flag.NewFlagSet("", flag.ContinueOnError)))
+}
+func (p *sansshellCmd) Usage() string {
+	return client.GenerateUsage(subPackage, p.Synopsis())
+}
+func (*sansshellCmd) SetFlags(f *flag.FlagSet) {}
+
+func (p *sansshellCmd) Execute(ctx context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
+	c := setup(f)
+	return c.Execute(ctx, args...)
+}
+
+type setVerbosityCmd struct {
+	level int
+}
+
+func (*setVerbosityCmd) Name() string     { return "set-verbosity" }
+func (*setVerbosityCmd) Synopsis() string { return "Set the logging verbosity level." }
+func (*setVerbosityCmd) Usage() string {
+	return `set-verbosity:
+  Sends an integer logging level and returns the previous integer logging level.
+`
+}
+
+func (s *setVerbosityCmd) SetFlags(f *flag.FlagSet) {
+	f.IntVar(&s.level, "verbosity", 0, "The logging verbosity level to set")
+}
+
+func (s *setVerbosityCmd) Execute(ctx context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
+	state := args[0].(*util.ExecuteState)
+	c := pb.NewLoggingClientProxy(state.Conn)
+
+	ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
+	defer cancel()
+	resp, err := c.SetVerbosityOneMany(ctx, &pb.SetVerbosityRequest{Level: int32(s.level)})
+	if err != nil {
+		// Emit this to every error file as it's not specific to a given target.
+		for _, e := range state.Err {
+			fmt.Fprintf(e, "Could not set logging: %v\n", err)
+		}
+		return subcommands.ExitFailure
+	}
+
+	retCode := subcommands.ExitSuccess
+	for r := range resp {
+		if r.Error != nil {
+			fmt.Fprintf(state.Err[r.Index], "Setting logging verbosity for target %s (%d) returned error: %v\n", r.Target, r.Index, r.Error)
+			retCode = subcommands.ExitFailure
+			continue
+		}
+		fmt.Fprintf(state.Out[r.Index], "Target %s (%d) previous logging level %d\n", r.Target, r.Index, r.Resp.Level)
+	}
+	return retCode
+}
+
+type getVerbosityCmd struct {
+}
+
+func (*getVerbosityCmd) Name() string     { return "get-verbosity" }
+func (*getVerbosityCmd) Synopsis() string { return "Get logging level verbosity" }
+func (*getVerbosityCmd) Usage() string {
+	return `get-verbosity:
+  Sends an empty request and expects to get back an integer level for the current logging verbosity.
+`
+}
+
+func (*getVerbosityCmd) SetFlags(f *flag.FlagSet) {}
+
+func (g *getVerbosityCmd) Execute(ctx context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
+	state := args[0].(*util.ExecuteState)
+	c := pb.NewLoggingClientProxy(state.Conn)
+
+	ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
+	defer cancel()
+	resp, err := c.GetVerbosityOneMany(ctx, &emptypb.Empty{})
+	if err != nil {
+		// Emit this to every error file as it's not specific to a given target.
+		for _, e := range state.Err {
+			fmt.Fprintf(e, "Could not set logging: %v\n", err)
+		}
+		return subcommands.ExitFailure
+	}
+
+	retCode := subcommands.ExitSuccess
+	for r := range resp {
+		if r.Error != nil {
+			fmt.Fprintf(state.Err[r.Index], "Getting logging verbosity for target %s (%d) returned error: %v\n", r.Target, r.Index, r.Error)
+			retCode = subcommands.ExitFailure
+			continue
+		}
+		fmt.Fprintf(state.Out[r.Index], "Target %s (%d) current logging level %d\n", r.Target, r.Index, r.Resp.Level)
+	}
+	return retCode
+}
+
+type setProxyVerbosityCmd struct {
+	level int
+}
+
+func (*setProxyVerbosityCmd) Name() string     { return "set-proxy-verbosity" }
+func (*setProxyVerbosityCmd) Synopsis() string { return "Set the proxy logging verbosity level." }
+func (*setProxyVerbosityCmd) Usage() string {
+	return `set-proxy-verbosity:
+  Sends an integer logging level for the proxy server and returns the previous integer logging level.
+`
+}
+
+func (s *setProxyVerbosityCmd) SetFlags(f *flag.FlagSet) {
+	f.IntVar(&s.level, "verbosity", 0, "The logging verbosity level to set")
+}
+
+func (s *setProxyVerbosityCmd) Execute(ctx context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
+	state := args[0].(*util.ExecuteState)
+	if len(state.Out) > 1 {
+		fmt.Fprintf(os.Stderr, "can't call proxy logging with multiple targets")
+	}
+	// Get a real connection to the proxy
+	c := pb.NewLoggingClient(state.Conn.Proxy())
+
+	ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
+	defer cancel()
+	resp, err := c.SetVerbosity(ctx, &pb.SetVerbosityRequest{Level: int32(s.level)})
+	if err != nil {
+		fmt.Fprintf(state.Err[0], "Could not set proxy logging: %v\n", err)
+		return subcommands.ExitFailure
+	}
+	fmt.Fprintf(state.Out[0], "Proxy previous logging level %d\n", resp.Level)
+	return subcommands.ExitSuccess
+}
+
+type getProxyVerbosityCmd struct {
+}
+
+func (*getProxyVerbosityCmd) Name() string     { return "get-proxy-verbosity" }
+func (*getProxyVerbosityCmd) Synopsis() string { return "Get the proxy logging level verbosity" }
+func (*getProxyVerbosityCmd) Usage() string {
+	return `get-proxy-verbosity:
+  Sends an empty request and expects to get back an integer level for the current proxy logging verbosity.
+`
+}
+
+func (*getProxyVerbosityCmd) SetFlags(f *flag.FlagSet) {}
+
+func (g *getProxyVerbosityCmd) Execute(ctx context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
+	state := args[0].(*util.ExecuteState)
+	if len(state.Out) > 1 {
+		fmt.Fprintf(os.Stderr, "can't call proxy logging with multiple targets")
+	}
+	// Get a real connection to the proxy
+	c := pb.NewLoggingClient(state.Conn.Proxy())
+
+	ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
+	defer cancel()
+	resp, err := c.GetVerbosity(ctx, &emptypb.Empty{})
+	if err != nil {
+		fmt.Fprintf(state.Err[0], "Could not get proxy logging: %v\n", err)
+		return subcommands.ExitFailure
+	}
+	fmt.Fprintf(state.Out[0], "Proxy current logging level %d\n", resp.Level)
+	return subcommands.ExitSuccess
+}

services/sansshell/sansshell.go

@@ -0,0 +1,24 @@
+/* Copyright (c) 2019 Snowflake Inc. All rights reserved.
+
+   Licensed under the Apache License, Version 2.0 (the
+   "License"); you may not use this file except in compliance
+   with the License.  You may obtain a copy of the License at
+
+     http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing,
+   software distributed under the License is distributed on an
+   "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+   KIND, either express or implied.  See the License for the
+   specific language governing permissions and limitations
+   under the License.
+*/
+
+// Package sansshell defines the RPC interface for internal Sansshell operations.
+// This differs from other sansshell services as it is only changing internal state and not
+// otherwise interacting with the host OS.
+package sansshell
+
+// To regenerate the proto headers if the .proto changes, just run go generate
+// and this encodes the necessary magic:
+//go:generate protoc --go_out=. --go_opt=paths=source_relative --go-grpc_out=require_unimplemented_servers=false:. --go-grpc_opt=paths=source_relative --go-grpcproxy_out=. --go-grpcproxy_opt=paths=source_relative sansshell.proto