Feat: config and logger progress

This commit is contained in:
kayos@tcp.direct 2024-05-22 19:45:49 -07:00
parent ba95c9e9e4
commit 651ca95eb3
Signed by: kayos
GPG Key ID: 4B841471B4BEE979
7 changed files with 416 additions and 175 deletions

93
cmd/mully/config.go Normal file

@ -0,0 +1,93 @@
package main
import (
"errors"
"fmt"
"os"
"strings"
"time"
"github.com/rs/zerolog"
)
type Config struct {
Account string
logLevel zerolog.Level
timeout time.Duration
}
func flagConfigVals(conf *Config) error {
badArg := func(arg string) error {
return fmt.Errorf("unknown argument: %s", arg)
}
verbosity := func(arg string) (error, bool) {
if !strings.HasPrefix(arg, "-v") {
return nil, true
}
if strings.Count(arg, "v") == 1 {
conf.logLevel = zerolog.DebugLevel
return nil, false
}
for _, c := range arg[1:] {
if c != 'v' {
return badArg(arg), false
}
}
conf.logLevel = zerolog.TraceLevel
return nil, false
}
for _, arg := range os.Args[1:] {
err, keepGoing := verbosity(arg)
if err != nil {
return err
}
if !keepGoing {
continue
}
switch arg {
case "--debug":
conf.logLevel = zerolog.DebugLevel
case "--trace":
conf.logLevel = zerolog.TraceLevel
default:
}
switch {
case conf.Account != "":
return badArg(arg)
case conf.Account == "" && !strings.HasPrefix(arg, "-"):
conf.Account = arg
case conf.Account == "" && strings.HasPrefix(arg, "-"):
return badArg(arg)
default:
}
}
return nil
}
func getConfig() (*Config, error) {
if len(os.Args) < 2 && os.Getenv("MULLVAD_ACCOUNT") == "" {
return nil, fmt.Errorf("missing mullvad account key")
}
conf := &Config{
logLevel: zerolog.InfoLevel,
timeout: 5 * time.Second,
}
errs := make([]error, 0, 2)
errs = append(errs, flagConfigVals(conf))
if os.Getenv("MULLVAD_ACCOUNT") != "" && conf.Account == "" {
conf.Account = os.Getenv("MULLVAD_ACCOUNT")
}
if conf.Account == "" {
errs = append(errs, fmt.Errorf("missing mullvad account key"))
}
return conf, errors.Join(errs...)
}

132
cmd/mully/logger.go Normal file

@ -0,0 +1,132 @@
package main
import (
"fmt"
"os"
"runtime"
"strings"
"git.tcp.direct/kayos/zwrap"
"github.com/rs/zerolog"
)
var stateColors = map[string]int{
"CONNECTING": 33,
"UNKNOWN": 90,
"DEBUG": 90,
"READY": 32,
"IDLE": 37,
"TRANSIENT_FAILURE": 31,
"SHUTDOWN": 31,
}
var replacer = strings.NewReplacer(
"]", "",
"[", "",
"#", "",
)
func debugFormatPrep(fields map[string]interface{}) error {
fields["state"] = "DEBUG"
if _, ok := fields["caller"]; !ok {
fields["caller"] = "gRPC_internal"
fields["message"] = strings.Replace(fields["message"].(string), "[core]", "", 1)
}
fields["message"] = strings.ReplaceAll(fields["message"].(string), "]", "] ")
msgString := fields["message"].(string)
msgFields := strings.Fields(msgString)
remove := func(i int) {
fields["message"] = strings.TrimSpace(
strings.ReplaceAll(
fields["message"].(string),
strings.Join(msgFields[i:i+2], " "),
"",
),
)
}
for i := range msgFields {
tmp := replacer.Replace(msgFields[i])
_, hasChannel := fields["channel"]
_, hasSubChannel := fields["sub_channel"]
if !hasChannel && strings.EqualFold(tmp, "channel") && len(msgFields) > i+1 {
fields["channel"] = replacer.Replace(msgFields[i+1])
remove(i)
continue
}
if !hasSubChannel && strings.EqualFold(tmp, "subchannel") && len(msgFields) > i+1 {
fields["sub_channel"] = replacer.Replace(msgFields[i+1])
remove(i)
continue
}
}
return nil
}
func formatPrep(fields map[string]interface{}) error {
if _, ok := fields["state"]; !ok {
if err := debugFormatPrep(fields); err != nil {
panic(err)
}
}
colInt, ok := stateColors[fields["state"].(string)]
if !ok {
colInt = 90
}
stateStrTrunc := fields["state"].(string)
if stateStrTrunc == "CONNECTING" {
stateStrTrunc = "START"
}
if len(stateStrTrunc) > 5 {
stateStrTrunc = stateStrTrunc[:5]
}
fields["state"] = fmt.Sprintf("[%s]",
zwrap.Colorize(stateStrTrunc, colInt, runtime.GOOS == "windows"),
)
return nil
}
func initConsoleLogger(hook *logHooker, cs ...*Config) *zwrap.Logger {
if len(cs) > 0 {
zerolog.SetGlobalLevel(cs[0].logLevel)
}
// []string{"time", "level", "caller", "message"},
zlc := zerolog.ConsoleWriter{
Out: os.Stderr,
FormatLevel: zwrap.LogLevelFmt(runtime.GOOS == "windows"),
PartsOrder: []string{"time", "level", "state", "caller", "message"},
FieldsExclude: []string{"state"},
FormatPrepare: formatPrep,
}
zl := zerolog.New(zlc).With().Timestamp().Logger()
if hook != nil {
zl = zerolog.New(zlc).With().Timestamp().Logger()
zl = zl.Hook(hook)
}
return zwrap.Wrap(zl)
}
// because there's no need to export `Run`, this is a hack
type logHooker struct {
rpc *RPCClient
}
func (h *logHooker) Run(e *zerolog.Event, level zerolog.Level, msg string) {
h.rpc.hookRun(e, level, msg)
}
func (r *RPCClient) hookRun(e *zerolog.Event, level zerolog.Level, msg string) {
e.Str("state", r.GetState().String())
e.Str("caller", r.CanonicalTarget())
}

@ -2,203 +2,65 @@ package main
import (
"context"
"fmt"
"os"
"runtime"
"os/signal"
"syscall"
"time"
"git.tcp.direct/kayos/zwrap"
"github.com/rs/zerolog"
"google.golang.org/grpc"
"google.golang.org/grpc/connectivity"
"google.golang.org/grpc/credentials/insecure"
"google.golang.org/grpc/grpclog"
"google.golang.org/protobuf/types/known/emptypb"
"google.golang.org/protobuf/types/known/wrapperspb"
"git.tcp.direct/kayos/mully/pkg/mullvad_mgmt"
)
func initConsoleLogger() *zwrap.Logger {
zl := zerolog.New(zerolog.ConsoleWriter{
Out: os.Stderr,
FormatLevel: zwrap.LogLevelFmt(runtime.GOOS == "windows"),
}).With().Timestamp().Logger()
return zwrap.Wrap(zl)
}
type RPCClient struct {
*grpc.ClientConn
log *zwrap.Logger
hooker zerolog.Hook
config *Config
}
// because there's no need to export `Run`, this is a hack
type logHooker struct {
rpc *RPCClient
}
func (h *logHooker) Run(e *zerolog.Event, level zerolog.Level, msg string) {
h.rpc.hookRun(e, level, msg)
}
func (r *RPCClient) hookRun(e *zerolog.Event, level zerolog.Level, msg string) {
e.Str("state", r.GetState().String())
e.Str("caller", r.CanonicalTarget())
}
func NewRPCClient(c *Config) (*RPCClient, error) {
client, err := grpc.NewClient(
"unix:///var/run/mullvad-vpn",
grpc.WithTransportCredentials(insecure.NewCredentials()),
func printAccountInfo(client *RPCClient) {
/*var (
accountID string
accountExpiry time.Time
err error
)
accountID, accountExpiry, err = client.GetAccountInfo(ctx)
if err != nil {
return nil, fmt.Errorf("failed to connect to the mullvad daemon: %w", err)
client.log.Logger.Fatal().Err(err).Msg("failed to get account info")
}
rpcc := &RPCClient{
ClientConn: client,
}
rpcc.hooker = &logHooker{rpc: rpcc}
rpcc.log = initConsoleLogger().WithForceLevel(zerolog.DebugLevel)
rpcc.log.Hook(rpcc.hooker)
grpclog.SetLoggerV2(rpcc.log)
return rpcc, nil
}
func (r *RPCClient) Close() error {
return r.ClientConn.Close()
}
func (r *RPCClient) stateWatcher(ctx context.Context, states chan<- connectivity.State, readyConn chan<- struct{}) {
log := r.log
last := connectivity.Idle
for {
if ok := r.ClientConn.WaitForStateChange(ctx, last); !ok {
// expired context
return
}
last = r.GetState()
states <- last
switch last {
case connectivity.Ready:
readyConn <- struct{}{}
continue
case connectivity.TransientFailure:
log.Logger.Error().Msg("connection in transient failure state")
case connectivity.Shutdown:
log.Logger.Warn().Msg("connection in shutdown state")
default:
}
time.Sleep(10 * time.Millisecond)
}
}
func (r *RPCClient) connect(ctx context.Context) error {
log := r.log
states := make(chan connectivity.State, 1)
readyConn := make(chan struct{}, 1)
go r.stateWatcher(ctx, states, readyConn)
waitLoop:
for {
select {
case <-ctx.Done():
return ctx.Err()
case <-states:
log.Logger.Debug().Msg("state changed")
case <-readyConn:
log.Logger.Info().Msg("connection ready")
break waitLoop
}
}
return nil
}
func (r *RPCClient) Connect(ctx context.Context) (mullvad_mgmt.ManagementServiceClient, error) {
log := r.log
if err := r.connect(ctx); err != nil {
return nil, fmt.Errorf("failed to connect to the gRPC endpoint: %w", err)
}
serviceClient := mullvad_mgmt.NewManagementServiceClient(r.ClientConn)
verStrPB, err := serviceClient.GetCurrentVersion(ctx, &emptypb.Empty{})
if err != nil {
return nil, fmt.Errorf("failed to get current daemon version: %w", err)
}
log.Logger.Info().Msgf("current daemon version: %s", verStrPB.Value)
verPB, err := serviceClient.GetVersionInfo(ctx, &emptypb.Empty{})
if err != nil {
log.Logger.Fatal().Err(err).Msg("failed to get daemon version info")
}
log.Logger.Info().Msgf("daemon version info: %s", verPB.String())
return serviceClient, nil
}
type Config struct {
Account string
}
func getConfig() (*Config, error) {
if len(os.Args) < 2 && os.Getenv("MULLVAD_ACCOUNT") == "" {
return nil, fmt.Errorf("no command specified")
}
if os.Getenv("MULLVAD_ACCOUNT") != "" {
return &Config{Account: os.Getenv("MULLVAD_ACCOUNT")}, nil
}
return &Config{Account: os.Args[1]}, nil
client.log.Logger.Trace().Msg("got account info")
client.log.Logger.Info().Msgf("account id: %s, expiry: %s", accountID, accountExpiry.String())*/
}
func main() {
checkProto(true)
sigChan := make(chan os.Signal, 1)
signal.Notify(sigChan, os.Interrupt, syscall.SIGTERM)
tmpLog := initConsoleLogger()
tmpLog := initConsoleLogger(nil)
conf, err := getConfig()
if err != nil {
tmpLog.Logger.Fatal().Err(err).Msg("missing mullvad account key")
tmpLog.Logger.Fatal().Err(err).Msg("missing configuration")
}
client, err := NewRPCClient(conf)
checkProto(conf.logLevel == zerolog.TraceLevel)
client, err := NewRPCClient(conf)
if err != nil {
tmpLog.Logger.Fatal().Err(err).Msg("failed to connect to the mullvad daemon")
}
log := client.log
defer func() {
client.log.Logger.Warn().Msg("closing connection to the mullvad daemon (main defer)")
if err = client.Close(); err != nil {
log.Logger.Error().Err(err).Msg("failed to close connection to the mullvad daemon")
client.log.Logger.Error().Err(err).Msg("failed to close connection to the mullvad daemon")
return
}
log.Logger.Debug().Msg("connection closed")
client.log.Logger.Debug().Msg("connection closed")
}()
log.Logger.Debug().Msg("client initialized")
client.log.Logger.Debug().Msg("client initialized")
log.Logger.Debug().Msg("connecting...")
client.log.Logger.Debug().Msg("connecting...")
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
ctx, cancel := context.WithDeadline(context.Background(), time.Now().Add(conf.timeout))
defer cancel()
var serviceClient mullvad_mgmt.ManagementServiceClient
if serviceClient, err = client.Connect(ctx); err != nil {
log.Logger.Fatal().Err(err).Msg("failed to connect to the mullvad daemon")
}
var acct *mullvad_mgmt.AccountData
if acct, err = serviceClient.GetAccountData(ctx, &wrapperspb.StringValue{Value: ""}); err != nil {
log.Logger.Fatal().Err(err).Msg("failed to get account data")
if err = client.Connect(ctx); err != nil {
client.log.Logger.Fatal().Err(err).Msg("failed to connect to the mullvad daemon")
}
<-sigChan
}

@ -5,14 +5,13 @@ import (
"github.com/davecgh/go-spew/spew"
"github.com/rs/zerolog"
"google.golang.org/protobuf/reflect/protoreflect"
"git.tcp.direct/kayos/mully/pkg/mullvad_mgmt"
)
var mProto = mullvad_mgmt.File_management_interface_proto
func checkProto(debug bool) protoreflect.ServiceDescriptor {
func checkProto(debug bool) {
if mProto.Services().Len() == 0 {
panic("mullvad management interface proto has no services, did we forget to generate from pb?")
}
@ -28,11 +27,10 @@ func checkProto(debug bool) protoreflect.ServiceDescriptor {
panic("mullvad management interface proto has no methods, did we forget to generate from pb?")
}
if debug {
log := initConsoleLogger().WithForceLevel(zerolog.DebugLevel)
log := initConsoleLogger(nil).WithForceLevel(zerolog.TraceLevel)
slog := log.Logger.With().Str("caller", string(mProto.Services().Get(0).Name())).Logger()
for n := 0; n < mProto.Services().Get(0).Methods().Len(); n++ {
slog.Debug().Msgf("method %d: %s", n, mProto.Services().Get(0).Methods().Get(n).Name())
}
}
return mProto.Services().Get(0)
}

156
cmd/mully/rpc.go Normal file

@ -0,0 +1,156 @@
package main
import (
"context"
"fmt"
"time"
"git.tcp.direct/kayos/zwrap"
"github.com/rs/zerolog"
"google.golang.org/grpc"
"google.golang.org/grpc/connectivity"
"google.golang.org/grpc/credentials/insecure"
"google.golang.org/grpc/grpclog"
"google.golang.org/protobuf/types/known/emptypb"
"git.tcp.direct/kayos/mully/pkg/mullvad_mgmt"
)
type RPCClient struct {
*grpc.ClientConn
mgmtClient mullvad_mgmt.ManagementServiceClient
log *zwrap.Logger
hooker *logHooker
config *Config
}
func NewRPCClient(c *Config) (*RPCClient, error) {
client, err := grpc.NewClient(
"unix:///var/run/mullvad-vpn",
grpc.WithTransportCredentials(insecure.NewCredentials()),
)
if err != nil {
return nil, fmt.Errorf("failed to connect to the mullvad daemon: %w", err)
}
rpcc := &RPCClient{
ClientConn: client,
}
rpcc.hooker = &logHooker{rpc: rpcc}
rpcc.config = c
rpcc.log = initConsoleLogger(rpcc.hooker, c)
rpcc.log.Logger.Trace().Msg("setting gRPC logger...")
grpclog.SetLoggerV2(initConsoleLogger(nil).WithForceLevel(zerolog.TraceLevel))
rpcc.log.Logger.Trace().Msg("gRPC logger set")
return rpcc, nil
}
func (r *RPCClient) Close() error {
return r.ClientConn.Close()
}
func (r *RPCClient) stateWatcher(ctx context.Context, states chan<- connectivity.State, readyConn chan<- struct{}) {
log := r.log
last := connectivity.Idle
for {
if ok := r.ClientConn.WaitForStateChange(ctx, last); !ok {
// expired context
return
}
last = r.GetState()
states <- last
switch last {
case connectivity.Ready:
readyConn <- struct{}{}
continue
case connectivity.TransientFailure:
log.Logger.Error().Msg("connection in transient failure state")
case connectivity.Shutdown:
log.Logger.Warn().Msg("connection in shutdown state")
default:
}
time.Sleep(10 * time.Millisecond)
}
}
func (r *RPCClient) connect(ctx context.Context) error {
states := make(chan connectivity.State, 1)
readyConn := make(chan struct{}, 1)
go r.stateWatcher(ctx, states, readyConn)
r.ClientConn.Connect()
waitLoop:
for {
select {
case <-ctx.Done():
return ctx.Err()
case <-states:
r.log.Logger.Debug().Msg("state changed")
case <-readyConn:
r.log.Logger.Info().Msg("connection ready")
break waitLoop
}
}
return nil
}
func (r *RPCClient) Connect(ctx context.Context) error {
log := r.log
if err := r.connect(ctx); err != nil {
return fmt.Errorf("failed to connect to the gRPC endpoint: %w", err)
}
r.mgmtClient = mullvad_mgmt.NewManagementServiceClient(r.ClientConn)
verStrPB, err := r.mgmtClient.GetCurrentVersion(ctx, &emptypb.Empty{})
if err != nil {
return fmt.Errorf("failed to get current daemon version: %w", err)
}
log.Logger.Trace().Msgf("current daemon version: %s", verStrPB.Value)
verPB, err := r.mgmtClient.GetVersionInfo(ctx, &emptypb.Empty{})
if err != nil {
log.Logger.Fatal().Err(err).Msg("failed to get daemon version info")
}
log.Logger.Info().Msgf("daemon version info: %s", verPB.String())
return nil
}
/*func (r *RPCClient) GetAccountInfo(ctx context.Context) (ID string, expiry time.Time, err error) {
r.log.Trace("getting account info")
var acct *mullvad_mgmt.AccountData
ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
defer cancel()
if acct, err = r.mgmtClient.
GetAccountData(ctx, wrapperspb.String(r.config.Account)); err != nil || acct == nil {
r.log.Logger.Trace().Err(err).Msg("failed to get account data")
return "", time.Time{}, fmt.Errorf("failed to get account data: %w", err)
}
r.log.Logger.Trace().Msgf("account data: %s", acct.String())
accountID := acct.GetId()
if accountID == "" {
return "", time.Time{}, fmt.Errorf("account id is empty")
}
accountExpiry := acct.GetExpiry()
if accountExpiry.AsTime().IsZero() {
return "", time.Time{}, fmt.Errorf("account expiry is empty")
}
if accountExpiry.AsTime().Before(time.Now()) {
return accountID, accountExpiry.AsTime(), fmt.Errorf("account is expired")
}
return accountID, accountExpiry.AsTime(), nil
}
*/

@ -8413,7 +8413,7 @@ var file_management_interface_proto_depIdxs = []int32{
109, // 154: mullvad_daemon.management_interface.ManagementService.CreateNewAccount:input_type -> google.protobuf.Empty
106, // 155: mullvad_daemon.management_interface.ManagementService.LoginAccount:input_type -> google.protobuf.StringValue
109, // 156: mullvad_daemon.management_interface.ManagementService.LogoutAccount:input_type -> google.protobuf.Empty
106, // 157: mullvad_daemon.management_interface.ManagementService.GetAccountData:input_type -> google.protobuf.StringValue
106, // 157: mullvad_daemon.management_interface.ManagementService.GetAccountInfo:input_type -> google.protobuf.StringValue
109, // 158: mullvad_daemon.management_interface.ManagementService.GetAccountHistory:input_type -> google.protobuf.Empty
109, // 159: mullvad_daemon.management_interface.ManagementService.ClearAccountHistory:input_type -> google.protobuf.Empty
109, // 160: mullvad_daemon.management_interface.ManagementService.GetWwwAuthToken:input_type -> google.protobuf.Empty
@ -8482,7 +8482,7 @@ var file_management_interface_proto_depIdxs = []int32{
106, // 223: mullvad_daemon.management_interface.ManagementService.CreateNewAccount:output_type -> google.protobuf.StringValue
109, // 224: mullvad_daemon.management_interface.ManagementService.LoginAccount:output_type -> google.protobuf.Empty
109, // 225: mullvad_daemon.management_interface.ManagementService.LogoutAccount:output_type -> google.protobuf.Empty
20, // 226: mullvad_daemon.management_interface.ManagementService.GetAccountData:output_type -> mullvad_daemon.management_interface.AccountData
20, // 226: mullvad_daemon.management_interface.ManagementService.GetAccountInfo:output_type -> mullvad_daemon.management_interface.AccountData
21, // 227: mullvad_daemon.management_interface.ManagementService.GetAccountHistory:output_type -> mullvad_daemon.management_interface.AccountHistory
109, // 228: mullvad_daemon.management_interface.ManagementService.ClearAccountHistory:output_type -> google.protobuf.Empty
106, // 229: mullvad_daemon.management_interface.ManagementService.GetWwwAuthToken:output_type -> google.protobuf.StringValue

@ -433,7 +433,7 @@ func (c *managementServiceClient) LogoutAccount(ctx context.Context, in *emptypb
func (c *managementServiceClient) GetAccountData(ctx context.Context, in *wrapperspb.StringValue, opts ...grpc.CallOption) (*AccountData, error) {
out := new(AccountData)
err := c.cc.Invoke(ctx, "/mullvad_daemon.management_interface.ManagementService/GetAccountData", in, out, opts...)
err := c.cc.Invoke(ctx, "/mullvad_daemon.management_interface.ManagementService/GetAccountInfo", in, out, opts...)
if err != nil {
return nil, err
}
@ -980,7 +980,7 @@ func (UnimplementedManagementServiceServer) LogoutAccount(context.Context, *empt
return nil, status.Errorf(codes.Unimplemented, "method LogoutAccount not implemented")
}
func (UnimplementedManagementServiceServer) GetAccountData(context.Context, *wrapperspb.StringValue) (*AccountData, error) {
return nil, status.Errorf(codes.Unimplemented, "method GetAccountData not implemented")
return nil, status.Errorf(codes.Unimplemented, "method GetAccountInfo not implemented")
}
func (UnimplementedManagementServiceServer) GetAccountHistory(context.Context, *emptypb.Empty) (*AccountHistory, error) {
return nil, status.Errorf(codes.Unimplemented, "method GetAccountHistory not implemented")
@ -1692,7 +1692,7 @@ func _ManagementService_GetAccountData_Handler(srv interface{}, ctx context.Cont
}
info := &grpc.UnaryServerInfo{
Server: srv,
FullMethod: "/mullvad_daemon.management_interface.ManagementService/GetAccountData",
FullMethod: "/mullvad_daemon.management_interface.ManagementService/GetAccountInfo",
}
handler := func(ctx context.Context, req interface{}) (interface{}, error) {
return srv.(ManagementServiceServer).GetAccountData(ctx, req.(*wrapperspb.StringValue))
@ -2483,7 +2483,7 @@ var ManagementService_ServiceDesc = grpc.ServiceDesc{
Handler: _ManagementService_LogoutAccount_Handler,
},
{
MethodName: "GetAccountData",
MethodName: "GetAccountInfo",
Handler: _ManagementService_GetAccountData_Handler,
},
{