From 8fe4e52ff59fbce3a9b99c0645d0cdcec56683f3 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Wed, 7 Feb 2024 16:49:28 +0100 Subject: [PATCH 01/39] feat: add ability to trace handshake In order to do that, we refactor the configuration handling. We move options to openvpn options, and we create a config object that is broader in scope. This commit also updates the binary entrypoint to test this functionality. Since I was here, I added the pinger too to exercise the pinger over the tunnel. --- cmd/minivpn2/iface.go | 30 +++ cmd/minivpn2/log.go | 79 +++++++ cmd/minivpn2/main.go | 206 ++++++++++++++++++ internal/controlchannel/controlchannel.go | 4 +- internal/datachannel/controller.go | 4 +- internal/datachannel/read.go | 2 +- internal/datachannel/service.go | 9 +- internal/model/config.go | 93 ++++++++ internal/model/packet.go | 7 +- internal/model/trace.go | 160 ++++++++++++++ internal/model/{options.go => vpn_options.go} | 56 ++--- internal/networkio/service.go | 4 +- internal/packetmuxer/service.go | 4 +- internal/reliabletransport/packets.go | 2 +- internal/reliabletransport/receiver.go | 6 + internal/reliabletransport/sender.go | 1 + internal/reliabletransport/service.go | 36 +-- internal/tlssession/controlmsg.go | 2 +- internal/tlssession/tlshandshake.go | 2 +- internal/tlssession/tlssession.go | 11 +- internal/tracex/trace.go | 143 ++++++++++++ internal/tun/setup.go | 19 +- internal/tun/tun.go | 11 +- 23 files changed, 804 insertions(+), 87 deletions(-) create mode 100644 cmd/minivpn2/iface.go create mode 100644 cmd/minivpn2/log.go create mode 100644 cmd/minivpn2/main.go create mode 100644 internal/model/config.go create mode 100644 internal/model/trace.go rename internal/model/{options.go => vpn_options.go} (89%) create mode 100644 internal/tracex/trace.go diff --git a/cmd/minivpn2/iface.go b/cmd/minivpn2/iface.go new file mode 100644 index 00000000..4102d938 --- /dev/null +++ b/cmd/minivpn2/iface.go @@ -0,0 +1,30 @@ +package main + +import ( + "fmt" + "net" +) + +func getInterfaceByIP(ipAddr string) (*net.Interface, error) { + interfaces, err := net.Interfaces() + if err != nil { + return nil, err + } + + for _, iface := range interfaces { + addrs, err := iface.Addrs() + if err != nil { + return nil, err + } + + for _, addr := range addrs { + if ipNet, ok := addr.(*net.IPNet); ok && !ipNet.IP.IsLoopback() { + if ipNet.IP.String() == ipAddr { + return &iface, nil + } + } + } + } + + return nil, fmt.Errorf("interface with IP %s not found", ipAddr) +} diff --git a/cmd/minivpn2/log.go b/cmd/minivpn2/log.go new file mode 100644 index 00000000..bf4a5c22 --- /dev/null +++ b/cmd/minivpn2/log.go @@ -0,0 +1,79 @@ +package main + +import ( + "fmt" + "io" + "os" + "sync" + "time" + + "github.com/apex/log" +) + +// Default handler outputting to stderr. +var Default = NewHandler(os.Stderr) + +// start time. +var start = time.Now() + +// colors. +const ( + none = 0 + red = 31 + green = 32 + yellow = 33 + blue = 34 + gray = 37 +) + +// Colors mapping. +var Colors = [...]int{ + log.DebugLevel: gray, + log.InfoLevel: blue, + log.WarnLevel: yellow, + log.ErrorLevel: red, + log.FatalLevel: red, +} + +// Strings mapping. +var Strings = [...]string{ + log.DebugLevel: "DEBUG", + log.InfoLevel: "INFO", + log.WarnLevel: "WARN", + log.ErrorLevel: "ERROR", + log.FatalLevel: "FATAL", +} + +// Handler implementation. +type Handler struct { + mu sync.Mutex + Writer io.Writer +} + +// New handler. +func NewHandler(w io.Writer) *Handler { + return &Handler{ + Writer: w, + } +} + +// HandleLog implements log.Handler. +func (h *Handler) HandleLog(e *log.Entry) error { + color := Colors[e.Level] + level := Strings[e.Level] + names := e.Fields.Names() + + h.mu.Lock() + defer h.mu.Unlock() + + ts := time.Since(start) + fmt.Fprintf(h.Writer, "\033[%dm%6s\033[0m[%10v] %-25s", color, level, ts, e.Message) + + for _, name := range names { + fmt.Fprintf(h.Writer, " \033[%dm%s\033[0m=%v", color, name, e.Fields.Get(name)) + } + + fmt.Fprintln(h.Writer) + + return nil +} diff --git a/cmd/minivpn2/main.go b/cmd/minivpn2/main.go new file mode 100644 index 00000000..a61d56ea --- /dev/null +++ b/cmd/minivpn2/main.go @@ -0,0 +1,206 @@ +package main + +import ( + "context" + "encoding/json" + "flag" + "fmt" + "net" + "os" + "os/exec" + "time" + + "github.com/Doridian/water" + "github.com/apex/log" + "github.com/jackpal/gateway" + + "github.com/ooni/minivpn/extras/ping" + "github.com/ooni/minivpn/internal/model" + "github.com/ooni/minivpn/internal/networkio" + "github.com/ooni/minivpn/internal/runtimex" + "github.com/ooni/minivpn/internal/tracex" + "github.com/ooni/minivpn/internal/tun" +) + +func runCmd(binaryPath string, args ...string) { + cmd := exec.Command(binaryPath, args...) + cmd.Stderr = os.Stderr + cmd.Stdout = os.Stdout + cmd.Stdin = os.Stdin + err := cmd.Run() + if nil != err { + log.WithError(err).Warn("error running /sbin/ip") + } +} + +func runIP(args ...string) { + runCmd("/sbin/ip", args...) +} + +func runRoute(args ...string) { + runCmd("/sbin/route", args...) +} + +type config struct { + configPath string + doPing bool + doTrace bool + skipRoute bool + timeout int +} + +func main() { + log.SetLevel(log.DebugLevel) + + cfg := &config{} + flag.StringVar(&cfg.configPath, "config", "", "config file to load") + flag.BoolVar(&cfg.doPing, "ping", false, "if true, do ping and exit (for testing)") + flag.BoolVar(&cfg.doTrace, "trace", false, "if true, do a trace of the handshake and exit (for testing)") + flag.BoolVar(&cfg.skipRoute, "skip-route", false, "if true, exit without setting routes (for testing)") + flag.IntVar(&cfg.timeout, "timeout", 60, "timeout in seconds (default=60)") + flag.Parse() + + if cfg.configPath == "" { + fmt.Println("[error] need config path") + os.Exit(1) + } + + log.SetHandler(NewHandler(os.Stderr)) + log.SetLevel(log.DebugLevel) + + opts := []model.Option{ + model.WithConfigFile(cfg.configPath), + model.WithLogger(log.Log), + } + + start := time.Now() + + if cfg.doTrace { + opts = append(opts, model.WithHandshakeTracer(tracex.NewTracer(start))) + } + + config := model.NewConfig(opts...) + + // connect to the server + dialer := networkio.NewDialer(log.Log, &net.Dialer{}) + ctx := context.Background() + + proto := config.Remote().Protocol + addr := config.Remote().AddrPort + + conn, err := dialer.DialContext(ctx, proto, addr) + if err != nil { + log.WithError(err).Fatal("dialer.DialContext") + } + + // The TLS will expire in 60 seconds by default, but we can pass + // a shorter timeout. + ctx, cancel := context.WithTimeout(ctx, time.Duration(cfg.timeout)*time.Second) + defer cancel() + + // create a vpn tun Device + tunnel, err := tun.StartTUN(ctx, conn, config) + if err != nil { + log.WithError(err).Fatal("init error") + return + } + log.Infof("Local IP: %s\n", tunnel.LocalAddr()) + log.Infof("Gateway: %s\n", tunnel.RemoteAddr()) + + fmt.Println("initialization-sequence-completed") + fmt.Printf("elapsed: %v\n", time.Since(start)) + + if cfg.doTrace { + trace := config.Tracer().Trace() + jsonData, err := json.MarshalIndent(trace, "", " ") + runtimex.PanicOnError(err, "cannot serialize trace") + fileName := "handshake-trace.json" + os.WriteFile(fileName, jsonData, 0644) + fmt.Println("trace written to", fileName) + os.Exit(0) + } + + if cfg.doPing { + pinger := ping.New("8.8.8.8", tunnel) + count := 5 + pinger.Count = count + + err = pinger.Run(context.Background()) + if err != nil { + pinger.PrintStats() + log.WithError(err).Fatal("ping error") + } + pinger.PrintStats() + os.Exit(0) + } + + if cfg.skipRoute { + os.Exit(0) + } + + // create a tun interface on the OS + iface, err := water.New(water.Config{DeviceType: water.TUN}) + runtimex.PanicOnError(err, "unable to open tun interface") + + // TODO: investigate what's the maximum working MTU, additionally get it from flag. + MTU := 1420 + iface.SetMTU(MTU) + + localAddr := tunnel.LocalAddr().String() + remoteAddr := tunnel.RemoteAddr().String() + netMask := tunnel.NetMask() + + // discover local gateway IP, we need it to add a route to our remote via our network gw + defaultGatewayIP, err := gateway.DiscoverGateway() + if err != nil { + log.Warn("could not discover default gateway IP, routes might be broken") + } + defaultInterfaceIP, err := gateway.DiscoverInterface() + if err != nil { + log.Warn("could not discover default route interface IP, routes might be broken") + } + defaultInterface, err := getInterfaceByIP(defaultInterfaceIP.String()) + if err != nil { + log.Warn("could not get default route interface, routes might be broken") + } + + if defaultGatewayIP != nil && defaultInterface != nil { + log.Infof("route add %s gw %v dev %s", config.Remote().IPAddr, defaultGatewayIP, defaultInterface.Name) + runRoute("add", config.Remote().IPAddr, "gw", defaultGatewayIP.String(), defaultInterface.Name) + } + + // we want the network CIDR for setting up the routes + network := &net.IPNet{ + IP: net.ParseIP(localAddr).Mask(netMask), + Mask: netMask, + } + + // configure the interface and bring it up + runIP("addr", "add", localAddr, "dev", iface.Name()) + runIP("link", "set", "dev", iface.Name(), "up") + runRoute("add", remoteAddr, "gw", localAddr) + runRoute("add", "-net", network.String(), "dev", iface.Name()) + runIP("route", "add", "default", "via", remoteAddr, "dev", iface.Name()) + + go func() { + for { + packet := make([]byte, 2000) + n, err := iface.Read(packet) + if err != nil { + log.WithError(err).Fatal("error reading from tun") + } + tunnel.Write(packet[:n]) + } + }() + go func() { + for { + packet := make([]byte, 2000) + n, err := tunnel.Read(packet) + if err != nil { + log.WithError(err).Fatal("error reading from tun") + } + iface.Write(packet[:n]) + } + }() + select {} +} diff --git a/internal/controlchannel/controlchannel.go b/internal/controlchannel/controlchannel.go index 22c1ab44..9627a1b6 100644 --- a/internal/controlchannel/controlchannel.go +++ b/internal/controlchannel/controlchannel.go @@ -36,12 +36,12 @@ type Service struct { // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md func (svc *Service) StartWorkers( - logger model.Logger, + config *model.Config, workersManager *workers.Manager, sessionManager *session.Manager, ) { ws := &workersState{ - logger: logger, + logger: config.Logger(), notifyTLS: *svc.NotifyTLS, controlToReliable: *svc.ControlToReliable, reliableToControl: svc.ReliableToControl, diff --git a/internal/datachannel/controller.go b/internal/datachannel/controller.go index 40b5ec8a..addcb2c5 100644 --- a/internal/datachannel/controller.go +++ b/internal/datachannel/controller.go @@ -25,7 +25,7 @@ type dataChannelHandler interface { // DataChannel represents the data "channel", that will encrypt and decrypt the tunnel payloads. // data implements the dataHandler interface. type DataChannel struct { - options *model.Options + options *model.OpenVPNOptions sessionManager *session.Manager state *dataChannelState decodeFn func(model.Logger, []byte, *session.Manager, *dataChannelState) (*encryptedData, error) @@ -39,7 +39,7 @@ var _ dataChannelHandler = &DataChannel{} // Ensure that we implement dataChanne // NewDataChannelFromOptions returns a new data object, initialized with the // options given. it also returns any error raised. func NewDataChannelFromOptions(log model.Logger, - opt *model.Options, + opt *model.OpenVPNOptions, sessionManager *session.Manager) (*DataChannel, error) { runtimex.Assert(opt != nil, "openvpn datachannel: opts cannot be nil") runtimex.Assert(opt != nil, "openvpn datachannel: opts cannot be nil") diff --git a/internal/datachannel/read.go b/internal/datachannel/read.go index 4d25be2d..75992c20 100644 --- a/internal/datachannel/read.go +++ b/internal/datachannel/read.go @@ -97,7 +97,7 @@ func decodeEncryptedPayloadNonAEAD(log model.Logger, buf []byte, session *sessio // modes are supported at the moment, so no real decompression is done. It // returns a byte array, and an error if the operation could not be completed // successfully. -func maybeDecompress(b []byte, st *dataChannelState, opt *model.Options) ([]byte, error) { +func maybeDecompress(b []byte, st *dataChannelState, opt *model.OpenVPNOptions) ([]byte, error) { if st == nil || st.dataCipher == nil { return []byte{}, fmt.Errorf("%w:%s", errBadInput, "bad state") } diff --git a/internal/datachannel/service.go b/internal/datachannel/service.go index 00837a9b..32d81aea 100644 --- a/internal/datachannel/service.go +++ b/internal/datachannel/service.go @@ -50,14 +50,13 @@ type Service struct { // 3. keyWorker BLOCKS on keyUp to read a dataChannelKey and // initializes the internal state with the resulting key; func (s *Service) StartWorkers( - logger model.Logger, + config *model.Config, workersManager *workers.Manager, sessionManager *session.Manager, - options *model.Options, ) { - dc, err := NewDataChannelFromOptions(logger, options, sessionManager) + dc, err := NewDataChannelFromOptions(config.Logger(), config.OpenVPNOptions(), sessionManager) if err != nil { - logger.Warnf("cannot initialize channel %v", err) + config.Logger().Warnf("cannot initialize channel %v", err) return } ws := &workersState{ @@ -65,7 +64,7 @@ func (s *Service) StartWorkers( dataOrControlToMuxer: *s.DataOrControlToMuxer, dataToTUN: s.DataToTUN, keyReady: s.KeyReady, - logger: logger, + logger: config.Logger(), muxerToData: s.MuxerToData, sessionManager: sessionManager, tunToData: s.TUNToData, diff --git a/internal/model/config.go b/internal/model/config.go new file mode 100644 index 00000000..a7736872 --- /dev/null +++ b/internal/model/config.go @@ -0,0 +1,93 @@ +package model + +import ( + "net" + + "github.com/apex/log" + "github.com/ooni/minivpn/internal/runtimex" +) + +// Config contains options to initialize the OpenVPN tunnel. +type Config struct { + // openVPNOptions contains options related to openvpn. + openvpnOptions *OpenVPNOptions + + // logger will be used to log events. + logger Logger + + // if a tracer is provided, it will be used to trace the openvpn handshake. + tracer HandshakeTracer +} + +// NewConfig returns a Config ready to intialize a vpn tunnel. +func NewConfig(options ...Option) *Config { + // TODO(ainghazal): provide a nop-tracer. + cfg := &Config{ + openvpnOptions: &OpenVPNOptions{}, + logger: log.Log, + tracer: &dummyTracer{}, + } + for _, opt := range options { + opt(cfg) + } + return cfg +} + +// Option is an option you can pass to initialize minivpn. +type Option func(config *Config) + +// WithConfigFile configures OpenVPNOptions parsed from the given file. +func WithConfigFile(configPath string) Option { + return func(config *Config) { + openvpnOpts, err := ReadConfigFile(configPath) + runtimex.PanicOnError(err, "cannot parse config file") + runtimex.PanicIfFalse(openvpnOpts.HasAuthInfo(), "missing auth info") + config.openvpnOptions = openvpnOpts + } + +} + +// WithLogger configures the passed [Logger]. +func WithLogger(logger Logger) Option { + return func(config *Config) { + config.logger = logger + } +} + +// WithHandshakeTracer configures the passed [HandshakeTracer]. +func WithHandshakeTracer(tracer HandshakeTracer) Option { + return func(config *Config) { + config.tracer = tracer + } +} + +// Logger returns the configured logger. +func (c *Config) Logger() Logger { + return c.logger +} + +// OpenVPNOptions returns the configured openvpn options. +func (c *Config) OpenVPNOptions() *OpenVPNOptions { + return c.openvpnOptions +} + +// Remote returns the openvpn remote. +func (c *Config) Remote() *Remote { + return &Remote{ + IPAddr: c.openvpnOptions.Remote, + AddrPort: net.JoinHostPort(c.openvpnOptions.Remote, c.openvpnOptions.Port), + Protocol: c.openvpnOptions.Proto.String(), + } +} + +// Tracer returns the handshake tracer. +func (c *Config) Tracer() HandshakeTracer { + return c.tracer +} + +// Remote has info about the OpenVPNRemote. +type Remote struct { + IPAddr string + AddrPort string + Protocol string +} diff --git a/internal/model/packet.go b/internal/model/packet.go index f1256a4b..51409db1 100644 --- a/internal/model/packet.go +++ b/internal/model/packet.go @@ -334,13 +334,8 @@ func (p *Packet) IsData() bool { return p.Opcode.IsData() } -const ( - DirectionIncoming = iota - DirectionOutgoing -) - // Log writes an entry in the passed logger with a representation of this packet. -func (p *Packet) Log(logger Logger, direction int) { +func (p *Packet) Log(logger Logger, direction Direction) { var dir string switch direction { case DirectionIncoming: diff --git a/internal/model/trace.go b/internal/model/trace.go new file mode 100644 index 00000000..570f76a0 --- /dev/null +++ b/internal/model/trace.go @@ -0,0 +1,160 @@ +package model + +import ( + "encoding/json" + "fmt" + "time" + + "github.com/ooni/minivpn/internal/optional" +) + +// HandshakeTracer allows to collect traces for a given OpenVPN handshake. A HandshakeTracer can be optionally +// added to the top-level TUN constructor, and it will be propagated to any layer that needs to register an event. +type HandshakeTracer interface { + // TimeNow allows to inject time for deterministic tests. + TimeNow() time.Time + + // OnStateChange is called for each transition in the state machine. + OnStateChange(state int) + + // OnIncomingPacket is called when a packet is received. + OnIncomingPacket(packet *Packet) + + // OnOutgoingPacket is called when a packet is about to be sent. + OnOutgoingPacket(packet *Packet, retries int) + + // OnDroppedPacket is called whenever a packet is dropped (in/out) + OnDroppedPacket(direction Direction, packet *Packet) + + // OnHandshakeDone is called when we have completed a handshake. + OnHandshakeDone(remoteAddr string) + + // Trace returns an array of [HandshakeEvent]s. + Trace() []HandshakeEvent +} + +const ( + HandshakeEventStateChange = iota + HandshakeEventPacketIn + HandshakeEventPacketOut + HandshakeEventPacketDropped +) + +// HandshakeEventType indicates which event we logged. +type HandshakeEventType int + +// Ensure that it implements the Stringer interface. +var _ fmt.Stringer = HandshakeEventType(0) + +// String implements fmt.Stringer +func (e HandshakeEventType) String() string { + switch e { + case HandshakeEventStateChange: + return "state" + case HandshakeEventPacketIn: + return "packet_in" + case HandshakeEventPacketOut: + return "packet_out" + case HandshakeEventPacketDropped: + return "packet_dropped" + default: + return "unknown" + } +} + +// HandshakeEvent must implement the event annotation methods, plus json serialization. +type HandshakeEvent interface { + Type() HandshakeEventType + Time() time.Time + Packet() optional.Value[LoggedPacket] + json.Marshaler +} + +// LoggedPacket tracks metadata about a packet useful to build traces. +type LoggedPacket struct { + Direction Direction + + // the only fields of the packet we want to log. + Opcode Opcode + ID PacketID + ACKs []PacketID + + // PayloadSize is the size of the payload in bytes + PayloadSize int + + // Retries keeps track of packet retransmission (only for outgoing packets). + Retries int +} + +// MarshalJSON implements json.Marshaler. +func (lp LoggedPacket) MarshalJSON() ([]byte, error) { + j := struct { + Opcode string `json:"opcode"` + ID PacketID `json:"id"` + ACKs []PacketID `json:"acks"` + Direction string `json:"direction"` + PayloadSize int `json:"payload_size"` + Retries int `json:"send_attempts"` + }{ + Opcode: lp.Opcode.String(), + ID: lp.ID, + ACKs: lp.ACKs, + Direction: lp.Direction.String(), + PayloadSize: lp.PayloadSize, + Retries: lp.Retries, + } + return json.Marshal(j) +} + +// Direction is one of two directions on a packet. +type Direction int + +const ( + // DirectionIncoming marks received packets. + DirectionIncoming = iota + + // DirectionOutgoing marks packets to be sent. + DirectionOutgoing +) + +var _ fmt.Stringer = Direction(0) + +// String implements fmt.Stringer +func (d Direction) String() string { + switch d { + case DirectionIncoming: + return "recv" + case 1: + return "send" + default: + return "undefined" + } +} + +// dummyTracer is a no-op implementation of [model.HandshakeTracer] that does nothing +// but can be safely passed as a default implementation. +type dummyTracer struct{} + +// TimeNow allows to manipulate time for deterministic tests. +func (dt *dummyTracer) TimeNow() time.Time { return time.Now() } + +// OnStateChange is called for each transition in the state machine. +func (dt *dummyTracer) OnStateChange(state int) {} + +// OnIncomingPacket is called when a packet is received. +func (dt *dummyTracer) OnIncomingPacket(packet *Packet) {} + +// OnOutgoingPacket is called when a packet is about to be sent. +func (dt *dummyTracer) OnOutgoingPacket(packet *Packet, retries int) {} + +// OnDroppedPacket is called whenever a packet is dropped (in/out) +func (dt *dummyTracer) OnDroppedPacket(direction Direction, packet *Packet) { +} + +func (dt *dummyTracer) OnHandshakeDone(remoteAddr string) {} + +// Trace returns a structured log containing an array of [model.HandshakeEvent]. +func (dt *dummyTracer) Trace() []HandshakeEvent { return []HandshakeEvent{} } + +// Assert that dummyTracer implements [model.HandshakeTracer]. +var _ HandshakeTracer = &dummyTracer{} diff --git a/internal/model/options.go b/internal/model/vpn_options.go similarity index 89% rename from internal/model/options.go rename to internal/model/vpn_options.go index bd46c6e5..c10e8ddc 100644 --- a/internal/model/options.go +++ b/internal/model/vpn_options.go @@ -5,7 +5,7 @@ package model // // Mostly, this file conforms to the format in the reference implementation. // However, there are some additions that are specific. To avoid feature creep -// and fat dependencies, the main `vpn` module only supports mainline +// and fat dependencies, the internal implementation only supports mainline // capabilities. It is still useful to carry all options in a single type, // so it's up to the user of this library to do something useful with // such options. The `extra` package provides some of these extra features, like @@ -92,10 +92,10 @@ var SupportedAuth = []string{ "SHA512", } -// Options make all the relevant configuration options accessible to the +// OpenVPNOptions make all the relevant openvpn configuration options accessible to the // different modules that need it. -type Options struct { - // These options have the same name of OpenVPN options: +type OpenVPNOptions struct { + // These options have the same name of OpenVPN options referenced in the official documentation: Remote string Port string Proto Proto @@ -111,7 +111,9 @@ type Options struct { Auth string TLSMaxVer string - // Below are options that do not conform to the OpenVPN configuration format: + // Below are options that do not conform strictly to the OpenVPN configuration format, but still can + // be understood by us in a configuration file: + Compress Compression ProxyOBFS4 string } @@ -119,7 +121,7 @@ type Options struct { // ReadConfigFile expects a string with a path to a valid config file, // and returns a pointer to a Options struct after parsing the file, and an // error if the operation could not be completed. -func ReadConfigFile(filePath string) (*Options, error) { +func ReadConfigFile(filePath string) (*OpenVPNOptions, error) { lines, err := getLinesFromFile(filePath) dir, _ := filepath.Split(filePath) if err != nil { @@ -130,7 +132,7 @@ func ReadConfigFile(filePath string) (*Options, error) { // ShouldLoadCertsFromPath returns true when the options object is configured to load // certificates from paths; false when we have inline certificates. -func (o *Options) ShouldLoadCertsFromPath() bool { +func (o *OpenVPNOptions) ShouldLoadCertsFromPath() bool { return o.CertPath != "" && o.KeyPath != "" && o.CAPath != "" } @@ -138,7 +140,7 @@ func (o *Options) ShouldLoadCertsFromPath() bool { // - we have paths for cert, key and ca; or // - we have inline byte arrays for cert, key and ca; or // - we have username + password info. -func (o *Options) HasAuthInfo() bool { +func (o *OpenVPNOptions) HasAuthInfo() bool { if o.CertPath != "" && o.KeyPath != "" && o.CAPath != "" { return true } @@ -156,7 +158,7 @@ const clientOptions = "V4,dev-type tun,link-mtu 1549,tun-mtu 1500,proto %sv4,cip // ServerOptionsString produces a comma-separated representation of the options, in the same // order and format that the OpenVPN server expects from us. -func (o *Options) ServerOptionsString() string { +func (o *OpenVPNOptions) ServerOptionsString() string { if o.Cipher == "" { return "" } @@ -258,7 +260,7 @@ func PushedOptionsAsMap(pushedOptions []byte) map[string][]string { return optMap } -func parseProto(p []string, o *Options) error { +func parseProto(p []string, o *OpenVPNOptions) error { if len(p) != 1 { return fmt.Errorf("%w: %s", ErrBadConfig, "proto needs one arg") } @@ -277,7 +279,7 @@ func parseProto(p []string, o *Options) error { // TODO(ainghazal): all these little functions can be better tested if we return the options object too -func parseRemote(p []string, o *Options) error { +func parseRemote(p []string, o *OpenVPNOptions) error { if len(p) != 2 { return fmt.Errorf("%w: %s", ErrBadConfig, "remote needs two args") } @@ -285,7 +287,7 @@ func parseRemote(p []string, o *Options) error { return nil } -func parseCipher(p []string, o *Options) error { +func parseCipher(p []string, o *OpenVPNOptions) error { if len(p) != 1 { return fmt.Errorf("%w: %s", ErrBadConfig, "cipher expects one arg") } @@ -297,7 +299,7 @@ func parseCipher(p []string, o *Options) error { return nil } -func parseAuth(p []string, o *Options) error { +func parseAuth(p []string, o *OpenVPNOptions) error { if len(p) != 1 { return fmt.Errorf("%w: %s", ErrBadConfig, "invalid auth entry") } @@ -309,7 +311,7 @@ func parseAuth(p []string, o *Options) error { return nil } -func parseCA(p []string, o *Options, basedir string) error { +func parseCA(p []string, o *OpenVPNOptions, basedir string) error { e := fmt.Errorf("%w: %s", ErrBadConfig, "ca expects a valid file") if len(p) != 1 { return e @@ -325,7 +327,7 @@ func parseCA(p []string, o *Options, basedir string) error { return nil } -func parseCert(p []string, o *Options, basedir string) error { +func parseCert(p []string, o *OpenVPNOptions, basedir string) error { e := fmt.Errorf("%w: %s", ErrBadConfig, "cert expects a valid file") if len(p) != 1 { return e @@ -341,7 +343,7 @@ func parseCert(p []string, o *Options, basedir string) error { return nil } -func parseKey(p []string, o *Options, basedir string) error { +func parseKey(p []string, o *OpenVPNOptions, basedir string) error { e := fmt.Errorf("%w: %s", ErrBadConfig, "key expects a valid file") if len(p) != 1 { return e @@ -360,7 +362,7 @@ func parseKey(p []string, o *Options, basedir string) error { // parseAuthUser reads credentials from a given file, according to the openvpn // format (user and pass on a line each). To avoid path traversal / LFI, the // credentials file is expected to be in a subdirectory of the base dir. -func parseAuthUser(p []string, o *Options, basedir string) error { +func parseAuthUser(p []string, o *OpenVPNOptions, basedir string) error { e := fmt.Errorf("%w: %s", ErrBadConfig, "auth-user-pass expects a valid file") if len(p) != 1 { return e @@ -380,7 +382,7 @@ func parseAuthUser(p []string, o *Options, basedir string) error { return nil } -func parseCompress(p []string, o *Options) error { +func parseCompress(p []string, o *OpenVPNOptions) error { if len(p) > 1 { return fmt.Errorf("%w: %s", ErrBadConfig, "compress: only empty/stub options supported") } @@ -395,7 +397,7 @@ func parseCompress(p []string, o *Options) error { return fmt.Errorf("%w: %s", ErrBadConfig, "compress: only empty/stub options supported") } -func parseCompLZO(p []string, o *Options) error { +func parseCompLZO(p []string, o *OpenVPNOptions) error { if p[0] != "no" { return fmt.Errorf("%w: %s", ErrBadConfig, "comp-lzo: compression not supported") } @@ -405,7 +407,7 @@ func parseCompLZO(p []string, o *Options) error { // parseTLSVerMax sets the maximum TLS version. This is currently ignored // because we're using uTLS to parrot the Client Hello. -func parseTLSVerMax(p []string, o *Options) error { +func parseTLSVerMax(p []string, o *OpenVPNOptions) error { if len(p) == 0 { o.TLSMaxVer = "1.3" return nil @@ -416,7 +418,7 @@ func parseTLSVerMax(p []string, o *Options) error { return nil } -func parseProxyOBFS4(p []string, o *Options) error { +func parseProxyOBFS4(p []string, o *OpenVPNOptions) error { if len(p) != 1 { return fmt.Errorf("%w: %s", ErrBadConfig, "proto-obfs4: need a properly configured proxy") } @@ -443,15 +445,15 @@ var pMapDir = map[string]interface{}{ "auth-user-pass": parseAuthUser, } -func parseOption(o *Options, dir, key string, p []string, lineno int) error { +func parseOption(o *OpenVPNOptions, dir, key string, p []string, lineno int) error { switch key { case "proto", "remote", "cipher", "auth", "compress", "comp-lzo", "tls-version-max", "proxy-obfs4": - fn := pMap[key].(func([]string, *Options) error) + fn := pMap[key].(func([]string, *OpenVPNOptions) error) if e := fn(p, o); e != nil { return e } case "ca", "cert", "key", "auth-user-pass": - fn := pMapDir[key].(func([]string, *Options, string) error) + fn := pMapDir[key].(func([]string, *OpenVPNOptions, string) error) if e := fn(p, o, dir); e != nil { return e } @@ -464,8 +466,8 @@ func parseOption(o *Options, dir, key string, p []string, lineno int) error { // getOptionsFromLines tries to parse all the lines coming from a config file // and raises validation errors if the values do not conform to the expected // format. The config file supports inline file inclusion for , and . -func getOptionsFromLines(lines []string, dir string) (*Options, error) { - opt := &Options{} +func getOptionsFromLines(lines []string, dir string) (*OpenVPNOptions, error) { + opt := &OpenVPNOptions{} // tag and inlineBuf are used to parse inline files. // these follow the format used by the reference openvpn implementation. @@ -561,7 +563,7 @@ func parseTag(tag string) string { } // parseInlineTag -func parseInlineTag(o *Options, tag string, buf *bytes.Buffer) error { +func parseInlineTag(o *OpenVPNOptions, tag string, buf *bytes.Buffer) error { b := buf.Bytes() if len(b) == 0 { return fmt.Errorf("%w: empty inline tag: %d", ErrBadConfig, len(b)) diff --git a/internal/networkio/service.go b/internal/networkio/service.go index f10d5bf4..19ae5c4b 100644 --- a/internal/networkio/service.go +++ b/internal/networkio/service.go @@ -26,13 +26,13 @@ type Service struct { // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md func (svc *Service) StartWorkers( - logger model.Logger, + config *model.Config, manager *workers.Manager, conn FramingConn, ) { ws := &workersState{ conn: conn, - logger: logger, + logger: config.Logger(), manager: manager, muxerToNetwork: svc.MuxerToNetwork, networkToMuxer: *svc.NetworkToMuxer, diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index c67d3c53..e0dc74be 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -50,12 +50,12 @@ type Service struct { // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md func (s *Service) StartWorkers( - logger model.Logger, + config *model.Config, workersManager *workers.Manager, sessionManager *session.Manager, ) { ws := &workersState{ - logger: logger, + logger: config.Logger(), hardReset: s.HardReset, // initialize to a sufficiently long time from now hardResetTicker: time.NewTicker(longWakeup), diff --git a/internal/reliabletransport/packets.go b/internal/reliabletransport/packets.go index 1cb3991a..1e6893d0 100644 --- a/internal/reliabletransport/packets.go +++ b/internal/reliabletransport/packets.go @@ -19,7 +19,7 @@ type inFlightPacket struct { packet *model.Packet // retries is a monotonically increasing counter for retransmission. - retries uint8 + retries int } func newInFlightPacket(p *model.Packet) *inFlightPacket { diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index 9c2a927b..4b7f163e 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -30,6 +30,8 @@ func (ws *workersState) moveUpWorker() { // or POSSIBLY BLOCK waiting for notifications select { case packet := <-ws.muxerToReliable: + ws.tracer.OnIncomingPacket(packet) + if packet.Opcode != model.P_CONTROL_HARD_RESET_SERVER_V2 { // the hard reset has already been logged by the layer below // TODO: move logging here? @@ -58,11 +60,15 @@ func (ws *workersState) moveUpWorker() { // we only want to insert control packets going to the tls layer if packet.Opcode != model.P_CONTROL_V1 { + // TODO: add reason + ws.tracer.OnDroppedPacket(model.DirectionIncoming, packet) continue } if inserted := receiver.MaybeInsertIncoming(packet); !inserted { // this packet was not inserted in the queue: we drop it + // TODO: add reason + ws.tracer.OnDroppedPacket(model.DirectionIncoming, packet) ws.logger.Debugf("Dropping packet: %v", packet.ID) continue } diff --git a/internal/reliabletransport/sender.go b/internal/reliabletransport/sender.go index 989e81f9..f3cda823 100644 --- a/internal/reliabletransport/sender.go +++ b/internal/reliabletransport/sender.go @@ -84,6 +84,7 @@ func (ws *workersState) blockOnTryingToSend(sender *reliableSender, ticker *time // log the packet p.packet.Log(ws.logger, model.DirectionOutgoing) + ws.tracer.OnOutgoingPacket(p.packet, int(p.retries)) select { case ws.dataOrControlToMuxer <- p.packet: diff --git a/internal/reliabletransport/service.go b/internal/reliabletransport/service.go index b2a1bd75..a5bc9510 100644 --- a/internal/reliabletransport/service.go +++ b/internal/reliabletransport/service.go @@ -31,21 +31,22 @@ type Service struct { // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md func (s *Service) StartWorkers( - logger model.Logger, + config *model.Config, workersManager *workers.Manager, sessionManager *session.Manager, ) { ws := &workersState{ - logger: logger, + controlToReliable: s.ControlToReliable, + dataOrControlToMuxer: *s.DataOrControlToMuxer, + incomingSeen: make(chan incomingPacketSeen, 100), + logger: config.Logger(), // incomingSeen is a buffered channel to avoid losing packets if we're busy // processing in the sender goroutine. - incomingSeen: make(chan incomingPacketSeen, 100), - dataOrControlToMuxer: *s.DataOrControlToMuxer, - controlToReliable: s.ControlToReliable, - muxerToReliable: s.MuxerToReliable, - reliableToControl: *s.ReliableToControl, - sessionManager: sessionManager, - workersManager: workersManager, + muxerToReliable: s.MuxerToReliable, + reliableToControl: *s.ReliableToControl, + sessionManager: sessionManager, + tracer: config.Tracer(), + workersManager: workersManager, } workersManager.StartWorker(ws.moveUpWorker) workersManager.StartWorker(ws.moveDownWorker) @@ -53,17 +54,17 @@ func (s *Service) StartWorkers( // workersState contains the reliable workers state type workersState struct { - // logger is the logger to use - logger model.Logger - - // incomingSeen ins the shared channel to connect sender and receiver goroutines. - incomingSeen chan incomingPacketSeen + // controlToReliable is the channel from which we read packets going down the stack. + controlToReliable <-chan *model.Packet // dataOrControlToMuxer is the channel where we write packets going down the stack. dataOrControlToMuxer chan<- *model.Packet - // controlToReliable is the channel from which we read packets going down the stack. - controlToReliable <-chan *model.Packet + // incomingSeen ins the shared channel to connect sender and receiver goroutines. + incomingSeen chan incomingPacketSeen + + // logger is the logger to use + logger model.Logger // muxerToReliable is the channel from which we read packets going up the stack. muxerToReliable <-chan *model.Packet @@ -74,6 +75,9 @@ type workersState struct { // sessionManager manages the OpenVPN session. sessionManager *session.Manager + // tracer is a handshake tracer. + tracer model.HandshakeTracer + // workersManager controls the workers lifecycle. workersManager *workers.Manager } diff --git a/internal/tlssession/controlmsg.go b/internal/tlssession/controlmsg.go index d59ad945..8fd84546 100644 --- a/internal/tlssession/controlmsg.go +++ b/internal/tlssession/controlmsg.go @@ -23,7 +23,7 @@ import ( // encodeClientControlMessage returns a byte array with the payload for a control channel packet. // This is the packet that the client sends to the server with the key // material, local options and credentials (if username+password authentication is used). -func encodeClientControlMessageAsBytes(k *session.KeySource, o *model.Options) ([]byte, error) { +func encodeClientControlMessageAsBytes(k *session.KeySource, o *model.OpenVPNOptions) ([]byte, error) { opt, err := bytesx.EncodeOptionStringToBytes(o.ServerOptionsString()) if err != nil { return nil, err diff --git a/internal/tlssession/tlshandshake.go b/internal/tlssession/tlshandshake.go index 3f3bbfb0..dfdc9e26 100644 --- a/internal/tlssession/tlshandshake.go +++ b/internal/tlssession/tlshandshake.go @@ -118,7 +118,7 @@ type certConfig struct { // newCertConfigFromOptions is a constructor that returns a certConfig object initialized // from the paths specified in the passed Options object, and an error if it // could not be properly built. -func newCertConfigFromOptions(o *model.Options) (*certConfig, error) { +func newCertConfigFromOptions(o *model.OpenVPNOptions) (*certConfig, error) { var cfg *certConfig var err error if o.ShouldLoadCertsFromPath() { diff --git a/internal/tlssession/tlssession.go b/internal/tlssession/tlssession.go index 95016bfa..def3c809 100644 --- a/internal/tlssession/tlssession.go +++ b/internal/tlssession/tlssession.go @@ -42,16 +42,15 @@ type Service struct { // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md func (svc *Service) StartWorkers( - logger model.Logger, + config *model.Config, workersManager *workers.Manager, sessionManager *session.Manager, - options *model.Options, ) { ws := &workersState{ - logger: logger, - notifyTLS: svc.NotifyTLS, - options: options, keyUp: *svc.KeyUp, + logger: config.Logger(), + notifyTLS: svc.NotifyTLS, + options: config.OpenVPNOptions(), tlsRecordDown: *svc.TLSRecordDown, tlsRecordUp: svc.TLSRecordUp, sessionManager: sessionManager, @@ -64,7 +63,7 @@ func (svc *Service) StartWorkers( type workersState struct { logger model.Logger notifyTLS <-chan *model.Notification - options *model.Options + options *model.OpenVPNOptions tlsRecordDown chan<- []byte tlsRecordUp <-chan []byte keyUp chan<- *session.DataChannelKey diff --git a/internal/tracex/trace.go b/internal/tracex/trace.go new file mode 100644 index 00000000..05793874 --- /dev/null +++ b/internal/tracex/trace.go @@ -0,0 +1,143 @@ +// Package tracex implements a [model.HandshakeTracer] that can be passed to the TUN constructor to +// observe handshake events. +package tracex + +import ( + "encoding/json" + "sync" + "time" + + "github.com/ooni/minivpn/internal/model" + "github.com/ooni/minivpn/internal/optional" +) + +// event implements [model.HandshakeEvent] +type event struct { + // EventType is the type for this event. + eventType model.HandshakeEventType + + // AtTime is the time for this event, relative to the start time. + atTime time.Time + + // TODO: discuss: do we want both? + deltaTime time.Duration + + // loggedPacket is an optional packet metadata. + loggedPacket optional.Value[model.LoggedPacket] +} + +func newEvent(etype model.HandshakeEventType, t time.Time, t0 time.Time) *event { + return &event{ + eventType: etype, + atTime: t, + deltaTime: t.Sub(t0), + loggedPacket: optional.None[model.LoggedPacket](), + } +} + +// Type returns the type for the event. +func (e event) Type() model.HandshakeEventType { + return e.eventType +} + +// Time returns the event timestamp. +func (e event) Time() time.Time { + return e.atTime +} + +// Packet returns an optional logged packet. +func (e event) Packet() optional.Value[model.LoggedPacket] { + return e.loggedPacket +} + +// MarshalJSON implements json.Marshaler +func (e event) MarshalJSON() ([]byte, error) { + j := struct { + Type string `json:"type"` + Time time.Time `json:"t"` + Packet model.LoggedPacket `json:"packet"` + }{ + Type: e.Type().String(), + Time: e.Time(), + Packet: e.Packet().Unwrap(), + } + return json.Marshal(j) +} + +var _ model.HandshakeEvent = event{} + +// Tracer implements [model.HandshakeTracer]. +type Tracer struct { + // events is an array of handshake events. + events []model.HandshakeEvent + + // mu guards access to the events. + mu sync.Mutex + + // zeroTime is the time when we started a packet trace. + zeroTime time.Time +} + +// NewTracer returns a Tracer with the passed start time. +func NewTracer(start time.Time) *Tracer { + return &Tracer{ + zeroTime: start, + } +} + +// TimeNow allows to manipulate time for deterministic tests. +func (t *Tracer) TimeNow() time.Time { + return time.Now() +} + +// OnStateChange is called for each transition in the state machine. +func (t *Tracer) OnStateChange(state int) { + panic("not implemented") // TODO: Implement +} + +// OnIncomingPacket is called when a packet is received. +func (t *Tracer) OnIncomingPacket(packet *model.Packet) { + t.mu.Lock() + defer t.mu.Unlock() + + e := newEvent(model.HandshakeEventPacketIn, t.TimeNow(), t.zeroTime) + e.loggedPacket = logPacket(packet, -1, model.DirectionIncoming) + t.events = append(t.events, e) +} + +// OnOutgoingPacket is called when a packet is about to be sent. +func (t *Tracer) OnOutgoingPacket(packet *model.Packet, retries int) { + t.mu.Lock() + defer t.mu.Unlock() + + e := newEvent(model.HandshakeEventPacketOut, t.TimeNow(), t.zeroTime) + e.loggedPacket = logPacket(packet, retries, model.DirectionOutgoing) + t.events = append(t.events, e) +} + +// OnDroppedPacket is called whenever a packet is dropped (in/out) +func (t *Tracer) OnDroppedPacket(direction model.Direction, packet *model.Packet) { + // panic("not implemented") // TODO: Implement +} + +func (t *Tracer) OnHandshakeDone(remoteAddr string) { + panic("not implemented") // TODO: Implement +} + +// Trace returns a structured log containing an array of [model.HandshakeEvent]. +func (t *Tracer) Trace() []model.HandshakeEvent { + t.mu.Lock() + defer t.mu.Unlock() + return t.events +} + +func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[model.LoggedPacket] { + return optional.Some(model.LoggedPacket{ + Opcode: p.Opcode, + ID: p.ID, + ACKs: p.ACKs, + Direction: direction, + PayloadSize: len(p.Payload), + Retries: retries, + }) +} diff --git a/internal/tun/setup.go b/internal/tun/setup.go index 11e9d0bd..073d1258 100644 --- a/internal/tun/setup.go +++ b/internal/tun/setup.go @@ -25,10 +25,11 @@ func connectChannel[T any](signal chan T, slot **chan T) { // file for more information about the workers. // // [ARCHITECTURE]: https://github.com/ooni/minivpn/blob/main/ARCHITECTURE.md -func startWorkers(logger model.Logger, sessionManager *session.Manager, - tunDevice *TUN, conn networkio.FramingConn, options *model.Options) *workers.Manager { +func startWorkers(config *model.Config, conn networkio.FramingConn, + sessionManager *session.Manager, tunDevice *TUN) *workers.Manager { + // create a workers manager - workersManager := workers.NewManager(logger) + workersManager := workers.NewManager(config.Logger()) // create the networkio service. nio := &networkio.Service{ @@ -109,12 +110,12 @@ func startWorkers(logger model.Logger, sessionManager *session.Manager, connectChannel(tlsx.NotifyTLS, &muxer.NotifyTLS) // start all the workers - nio.StartWorkers(logger, workersManager, conn) - muxer.StartWorkers(logger, workersManager, sessionManager) - rel.StartWorkers(logger, workersManager, sessionManager) - ctrl.StartWorkers(logger, workersManager, sessionManager) - datach.StartWorkers(logger, workersManager, sessionManager, options) - tlsx.StartWorkers(logger, workersManager, sessionManager, options) + nio.StartWorkers(config, workersManager, conn) + muxer.StartWorkers(config, workersManager, sessionManager) + rel.StartWorkers(config, workersManager, sessionManager) + ctrl.StartWorkers(config, workersManager, sessionManager) + datach.StartWorkers(config, workersManager, sessionManager) + tlsx.StartWorkers(config, workersManager, sessionManager) // tell the packetmuxer that it should handshake ASAP muxer.HardReset <- true diff --git a/internal/tun/tun.go b/internal/tun/tun.go index 5d4ff7b2..b6c31db4 100644 --- a/internal/tun/tun.go +++ b/internal/tun/tun.go @@ -9,7 +9,6 @@ import ( "sync" "time" - "github.com/apex/log" "github.com/ooni/minivpn/internal/model" "github.com/ooni/minivpn/internal/networkio" "github.com/ooni/minivpn/internal/session" @@ -22,18 +21,18 @@ var ( // StartTUN initializes and starts the TUN device over the vpn. // If the passed context expires before the TUN device is ready, -func StartTUN(ctx context.Context, conn networkio.FramingConn, options *model.Options, logger model.Logger) (*TUN, error) { +func StartTUN(ctx context.Context, conn networkio.FramingConn, config *model.Config) (*TUN, error) { // create a session - sessionManager, err := session.NewManager(logger) + sessionManager, err := session.NewManager(config.Logger()) if err != nil { return nil, err } // create the TUN that will OWN the connection - tunnel := newTUN(logger, conn, sessionManager) + tunnel := newTUN(config.Logger(), conn, sessionManager) // start all the workers - workers := startWorkers(log.Log, sessionManager, tunnel, conn, options) + workers := startWorkers(config, conn, sessionManager, tunnel) tunnel.whenDone(func() { workers.StartShutdown() workers.WaitWorkersShutdown() @@ -50,7 +49,7 @@ func StartTUN(ctx context.Context, conn networkio.FramingConn, options *model.Op return tunnel, nil case <-tlsTimeout.C: defer func() { - log.Log.Info("tls timeout") + config.Logger().Info("tls timeout") tunnel.Close() }() return nil, errors.New("tls timeout") From d4ef98bc510ba0731448bb2bf3789c51b334ec40 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Thu, 8 Feb 2024 18:49:31 +0100 Subject: [PATCH 02/39] remove binary --- cmd/minivpn2/iface.go | 30 ------ cmd/minivpn2/log.go | 79 ---------------- cmd/minivpn2/main.go | 206 ------------------------------------------ 3 files changed, 315 deletions(-) delete mode 100644 cmd/minivpn2/iface.go delete mode 100644 cmd/minivpn2/log.go delete mode 100644 cmd/minivpn2/main.go diff --git a/cmd/minivpn2/iface.go b/cmd/minivpn2/iface.go deleted file mode 100644 index 4102d938..00000000 --- a/cmd/minivpn2/iface.go +++ /dev/null @@ -1,30 +0,0 @@ -package main - -import ( - "fmt" - "net" -) - -func getInterfaceByIP(ipAddr string) (*net.Interface, error) { - interfaces, err := net.Interfaces() - if err != nil { - return nil, err - } - - for _, iface := range interfaces { - addrs, err := iface.Addrs() - if err != nil { - return nil, err - } - - for _, addr := range addrs { - if ipNet, ok := addr.(*net.IPNet); ok && !ipNet.IP.IsLoopback() { - if ipNet.IP.String() == ipAddr { - return &iface, nil - } - } - } - } - - return nil, fmt.Errorf("interface with IP %s not found", ipAddr) -} diff --git a/cmd/minivpn2/log.go b/cmd/minivpn2/log.go deleted file mode 100644 index bf4a5c22..00000000 --- a/cmd/minivpn2/log.go +++ /dev/null @@ -1,79 +0,0 @@ -package main - -import ( - "fmt" - "io" - "os" - "sync" - "time" - - "github.com/apex/log" -) - -// Default handler outputting to stderr. -var Default = NewHandler(os.Stderr) - -// start time. -var start = time.Now() - -// colors. -const ( - none = 0 - red = 31 - green = 32 - yellow = 33 - blue = 34 - gray = 37 -) - -// Colors mapping. -var Colors = [...]int{ - log.DebugLevel: gray, - log.InfoLevel: blue, - log.WarnLevel: yellow, - log.ErrorLevel: red, - log.FatalLevel: red, -} - -// Strings mapping. -var Strings = [...]string{ - log.DebugLevel: "DEBUG", - log.InfoLevel: "INFO", - log.WarnLevel: "WARN", - log.ErrorLevel: "ERROR", - log.FatalLevel: "FATAL", -} - -// Handler implementation. -type Handler struct { - mu sync.Mutex - Writer io.Writer -} - -// New handler. -func NewHandler(w io.Writer) *Handler { - return &Handler{ - Writer: w, - } -} - -// HandleLog implements log.Handler. -func (h *Handler) HandleLog(e *log.Entry) error { - color := Colors[e.Level] - level := Strings[e.Level] - names := e.Fields.Names() - - h.mu.Lock() - defer h.mu.Unlock() - - ts := time.Since(start) - fmt.Fprintf(h.Writer, "\033[%dm%6s\033[0m[%10v] %-25s", color, level, ts, e.Message) - - for _, name := range names { - fmt.Fprintf(h.Writer, " \033[%dm%s\033[0m=%v", color, name, e.Fields.Get(name)) - } - - fmt.Fprintln(h.Writer) - - return nil -} diff --git a/cmd/minivpn2/main.go b/cmd/minivpn2/main.go deleted file mode 100644 index a61d56ea..00000000 --- a/cmd/minivpn2/main.go +++ /dev/null @@ -1,206 +0,0 @@ -package main - -import ( - "context" - "encoding/json" - "flag" - "fmt" - "net" - "os" - "os/exec" - "time" - - "github.com/Doridian/water" - "github.com/apex/log" - "github.com/jackpal/gateway" - - "github.com/ooni/minivpn/extras/ping" - "github.com/ooni/minivpn/internal/model" - "github.com/ooni/minivpn/internal/networkio" - "github.com/ooni/minivpn/internal/runtimex" - "github.com/ooni/minivpn/internal/tracex" - "github.com/ooni/minivpn/internal/tun" -) - -func runCmd(binaryPath string, args ...string) { - cmd := exec.Command(binaryPath, args...) - cmd.Stderr = os.Stderr - cmd.Stdout = os.Stdout - cmd.Stdin = os.Stdin - err := cmd.Run() - if nil != err { - log.WithError(err).Warn("error running /sbin/ip") - } -} - -func runIP(args ...string) { - runCmd("/sbin/ip", args...) -} - -func runRoute(args ...string) { - runCmd("/sbin/route", args...) -} - -type config struct { - configPath string - doPing bool - doTrace bool - skipRoute bool - timeout int -} - -func main() { - log.SetLevel(log.DebugLevel) - - cfg := &config{} - flag.StringVar(&cfg.configPath, "config", "", "config file to load") - flag.BoolVar(&cfg.doPing, "ping", false, "if true, do ping and exit (for testing)") - flag.BoolVar(&cfg.doTrace, "trace", false, "if true, do a trace of the handshake and exit (for testing)") - flag.BoolVar(&cfg.skipRoute, "skip-route", false, "if true, exit without setting routes (for testing)") - flag.IntVar(&cfg.timeout, "timeout", 60, "timeout in seconds (default=60)") - flag.Parse() - - if cfg.configPath == "" { - fmt.Println("[error] need config path") - os.Exit(1) - } - - log.SetHandler(NewHandler(os.Stderr)) - log.SetLevel(log.DebugLevel) - - opts := []model.Option{ - model.WithConfigFile(cfg.configPath), - model.WithLogger(log.Log), - } - - start := time.Now() - - if cfg.doTrace { - opts = append(opts, model.WithHandshakeTracer(tracex.NewTracer(start))) - } - - config := model.NewConfig(opts...) - - // connect to the server - dialer := networkio.NewDialer(log.Log, &net.Dialer{}) - ctx := context.Background() - - proto := config.Remote().Protocol - addr := config.Remote().AddrPort - - conn, err := dialer.DialContext(ctx, proto, addr) - if err != nil { - log.WithError(err).Fatal("dialer.DialContext") - } - - // The TLS will expire in 60 seconds by default, but we can pass - // a shorter timeout. - ctx, cancel := context.WithTimeout(ctx, time.Duration(cfg.timeout)*time.Second) - defer cancel() - - // create a vpn tun Device - tunnel, err := tun.StartTUN(ctx, conn, config) - if err != nil { - log.WithError(err).Fatal("init error") - return - } - log.Infof("Local IP: %s\n", tunnel.LocalAddr()) - log.Infof("Gateway: %s\n", tunnel.RemoteAddr()) - - fmt.Println("initialization-sequence-completed") - fmt.Printf("elapsed: %v\n", time.Since(start)) - - if cfg.doTrace { - trace := config.Tracer().Trace() - jsonData, err := json.MarshalIndent(trace, "", " ") - runtimex.PanicOnError(err, "cannot serialize trace") - fileName := "handshake-trace.json" - os.WriteFile(fileName, jsonData, 0644) - fmt.Println("trace written to", fileName) - os.Exit(0) - } - - if cfg.doPing { - pinger := ping.New("8.8.8.8", tunnel) - count := 5 - pinger.Count = count - - err = pinger.Run(context.Background()) - if err != nil { - pinger.PrintStats() - log.WithError(err).Fatal("ping error") - } - pinger.PrintStats() - os.Exit(0) - } - - if cfg.skipRoute { - os.Exit(0) - } - - // create a tun interface on the OS - iface, err := water.New(water.Config{DeviceType: water.TUN}) - runtimex.PanicOnError(err, "unable to open tun interface") - - // TODO: investigate what's the maximum working MTU, additionally get it from flag. - MTU := 1420 - iface.SetMTU(MTU) - - localAddr := tunnel.LocalAddr().String() - remoteAddr := tunnel.RemoteAddr().String() - netMask := tunnel.NetMask() - - // discover local gateway IP, we need it to add a route to our remote via our network gw - defaultGatewayIP, err := gateway.DiscoverGateway() - if err != nil { - log.Warn("could not discover default gateway IP, routes might be broken") - } - defaultInterfaceIP, err := gateway.DiscoverInterface() - if err != nil { - log.Warn("could not discover default route interface IP, routes might be broken") - } - defaultInterface, err := getInterfaceByIP(defaultInterfaceIP.String()) - if err != nil { - log.Warn("could not get default route interface, routes might be broken") - } - - if defaultGatewayIP != nil && defaultInterface != nil { - log.Infof("route add %s gw %v dev %s", config.Remote().IPAddr, defaultGatewayIP, defaultInterface.Name) - runRoute("add", config.Remote().IPAddr, "gw", defaultGatewayIP.String(), defaultInterface.Name) - } - - // we want the network CIDR for setting up the routes - network := &net.IPNet{ - IP: net.ParseIP(localAddr).Mask(netMask), - Mask: netMask, - } - - // configure the interface and bring it up - runIP("addr", "add", localAddr, "dev", iface.Name()) - runIP("link", "set", "dev", iface.Name(), "up") - runRoute("add", remoteAddr, "gw", localAddr) - runRoute("add", "-net", network.String(), "dev", iface.Name()) - runIP("route", "add", "default", "via", remoteAddr, "dev", iface.Name()) - - go func() { - for { - packet := make([]byte, 2000) - n, err := iface.Read(packet) - if err != nil { - log.WithError(err).Fatal("error reading from tun") - } - tunnel.Write(packet[:n]) - } - }() - go func() { - for { - packet := make([]byte, 2000) - n, err := tunnel.Read(packet) - if err != nil { - log.WithError(err).Fatal("error reading from tun") - } - iface.Write(packet[:n]) - } - }() - select {} -} From 4a2404aa82688fe9c987ed2d161e58fb7b5e1486 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Thu, 8 Feb 2024 20:11:01 +0100 Subject: [PATCH 03/39] comments after review --- internal/model/trace.go | 2 ++ internal/model/{vpn_options.go => vpnoptions.go} | 0 internal/tracex/trace.go | 2 +- 3 files changed, 3 insertions(+), 1 deletion(-) rename internal/model/{vpn_options.go => vpnoptions.go} (100%) diff --git a/internal/model/trace.go b/internal/model/trace.go index 570f76a0..3a8ecb0f 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -30,6 +30,7 @@ type HandshakeTracer interface { OnHandshakeDone(remoteAddr string) // Trace returns an array of [HandshakeEvent]s. + // TODO -- remove the Trace() method ------------------------------- Trace() []HandshakeEvent } @@ -63,6 +64,7 @@ func (e HandshakeEventType) String() string { } // HandshakeEvent must implement the event annotation methods, plus json serialization. +// TODO: this is easier as a struct type HandshakeEvent interface { Type() HandshakeEventType Time() time.Time diff --git a/internal/model/vpn_options.go b/internal/model/vpnoptions.go similarity index 100% rename from internal/model/vpn_options.go rename to internal/model/vpnoptions.go diff --git a/internal/tracex/trace.go b/internal/tracex/trace.go index 05793874..c3f5ebb0 100644 --- a/internal/tracex/trace.go +++ b/internal/tracex/trace.go @@ -128,7 +128,7 @@ func (t *Tracer) OnHandshakeDone(remoteAddr string) { func (t *Tracer) Trace() []model.HandshakeEvent { t.mu.Lock() defer t.mu.Unlock() - return t.events + return append([]model.HandshakeEvent{}, t.events...) } func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[model.LoggedPacket] { From 9b96d659804db95b1ee09f1686a2a90231c0fd97 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 14:45:05 +0100 Subject: [PATCH 04/39] tests: update tests after config refactor --- internal/reliabletransport/model.go | 12 ------------ internal/reliabletransport/packets_test.go | 2 +- internal/reliabletransport/reliable_ack_test.go | 2 +- internal/reliabletransport/reliable_loss_test.go | 2 +- internal/reliabletransport/reliable_reorder_test.go | 2 +- internal/reliabletransport/service_test.go | 6 +++--- 6 files changed, 7 insertions(+), 19 deletions(-) diff --git a/internal/reliabletransport/model.go b/internal/reliabletransport/model.go index b121eee0..b04d23e2 100644 --- a/internal/reliabletransport/model.go +++ b/internal/reliabletransport/model.go @@ -4,18 +4,6 @@ import ( "github.com/ooni/minivpn/internal/model" ) -// sequentialPacket is a packet that can return a [model.PacketID]. -type sequentialPacket interface { - ID() model.PacketID - ExtractACKs() []model.PacketID - Packet() *model.Packet -} - -// retransmissionPacket is a packet that can be scheduled for retransmission. -type retransmissionPacket interface { - ScheduleForRetransmission() -} - type outgoingPacketWriter interface { // TryInsertOutgoingPacket attempts to insert a packet into the // inflight queue. If return value is false, insertion was not successful (e.g., too many diff --git a/internal/reliabletransport/packets_test.go b/internal/reliabletransport/packets_test.go index 4b071dc4..298387cc 100644 --- a/internal/reliabletransport/packets_test.go +++ b/internal/reliabletransport/packets_test.go @@ -10,7 +10,7 @@ import ( func Test_inFlightPacket_backoff(t *testing.T) { type fields struct { - retries uint8 + retries int } tests := []struct { name string diff --git a/internal/reliabletransport/reliable_ack_test.go b/internal/reliabletransport/reliable_ack_test.go index 59767974..93fa9089 100644 --- a/internal/reliabletransport/reliable_ack_test.go +++ b/internal/reliabletransport/reliable_ack_test.go @@ -128,7 +128,7 @@ func TestReliable_ACK(t *testing.T) { t0 := time.Now() // let the workers pump up the jam! - s.StartWorkers(log.Log, workers, session) + s.StartWorkers(model.NewConfig(model.WithLogger(log.Log)), workers, session) writer := vpntest.NewPacketWriter(dataIn) diff --git a/internal/reliabletransport/reliable_loss_test.go b/internal/reliabletransport/reliable_loss_test.go index 7b429bf7..330c55a3 100644 --- a/internal/reliabletransport/reliable_loss_test.go +++ b/internal/reliabletransport/reliable_loss_test.go @@ -250,7 +250,7 @@ func TestReliable_WithLoss(t *testing.T) { t0 := time.Now() // let the workers pump up the jam! - s.StartWorkers(log.Log, workers, session) + s.StartWorkers(model.NewConfig(model.WithLogger(log.Log)), workers, session) writer := vpntest.NewPacketWriter(dataIn) go writer.WriteSequenceWithFixedPayload(tt.args.inputSequence, tt.args.inputPayload, 3) diff --git a/internal/reliabletransport/reliable_reorder_test.go b/internal/reliabletransport/reliable_reorder_test.go index bd28a096..b50d0cf9 100644 --- a/internal/reliabletransport/reliable_reorder_test.go +++ b/internal/reliabletransport/reliable_reorder_test.go @@ -123,7 +123,7 @@ func TestReliable_Reordering_UP(t *testing.T) { t0 := time.Now() // let the workers pump up the jam! - s.StartWorkers(log.Log, workers, session) + s.StartWorkers(model.NewConfig(model.WithLogger(log.Log)), workers, session) writer := vpntest.NewPacketWriter(dataIn) diff --git a/internal/reliabletransport/service_test.go b/internal/reliabletransport/service_test.go index 3555fd7f..bde1f0d0 100644 --- a/internal/reliabletransport/service_test.go +++ b/internal/reliabletransport/service_test.go @@ -18,7 +18,7 @@ func TestService_StartWorkers(t *testing.T) { ReliableToControl *chan *model.Packet } type args struct { - logger model.Logger + config *model.Config workersManager *workers.Manager sessionManager *session.Manager } @@ -42,7 +42,7 @@ func TestService_StartWorkers(t *testing.T) { }(), }, args: args{ - logger: log.Log, + config: model.NewConfig(model.WithLogger(log.Log)), workersManager: workers.NewManager(log.Log), sessionManager: func() *session.Manager { m, _ := session.NewManager(log.Log) @@ -59,7 +59,7 @@ func TestService_StartWorkers(t *testing.T) { MuxerToReliable: tt.fields.MuxerToReliable, ReliableToControl: tt.fields.ReliableToControl, } - s.StartWorkers(tt.args.logger, tt.args.workersManager, tt.args.sessionManager) + s.StartWorkers(tt.args.config, tt.args.workersManager, tt.args.sessionManager) tt.args.workersManager.StartShutdown() tt.args.workersManager.WaitWorkersShutdown() }) From 420c9f88b46cb064416082bd3c2f1f64ef51cc77 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 14:48:38 +0100 Subject: [PATCH 05/39] add documentation to package --- internal/controlchannel/controlchannel.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/internal/controlchannel/controlchannel.go b/internal/controlchannel/controlchannel.go index 9627a1b6..95648efe 100644 --- a/internal/controlchannel/controlchannel.go +++ b/internal/controlchannel/controlchannel.go @@ -1,3 +1,5 @@ +// Package controlchannel implements the control channel logic. The control channel sits +// above the reliable transport and below the TLS layer. package controlchannel import ( From 4a06e7e7516a60dad3e726f851ff1c910426e931 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 14:56:05 +0100 Subject: [PATCH 06/39] typo --- internal/reliabletransport/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/reliabletransport/service.go b/internal/reliabletransport/service.go index a5bc9510..8080383d 100644 --- a/internal/reliabletransport/service.go +++ b/internal/reliabletransport/service.go @@ -60,7 +60,7 @@ type workersState struct { // dataOrControlToMuxer is the channel where we write packets going down the stack. dataOrControlToMuxer chan<- *model.Packet - // incomingSeen ins the shared channel to connect sender and receiver goroutines. + // incomingSeen is the shared channel to connect sender and receiver goroutines. incomingSeen chan incomingPacketSeen // logger is the logger to use From 81232cc976e9ba0df51d82d5afaeeb544322010f Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Thu, 8 Feb 2024 14:26:53 +0100 Subject: [PATCH 07/39] bug: fix incoming session check I'm reverting a recent "fix" that was inverting the local-remote session id check - the error in that commit was to change the check to match the description in the comment. In reality, it was the comment that was wrong. The reason why we cannot check remote session id in all packets is because remote-session-id only present if the packet has an ack array. The handshake was broken by the previous change, but I did not catch it because the integration tests were not running for the refactored codebase. Also, this commit enables integration tests for the new internal path to avoid this kind of errors in the future. Some test code was removed, because the script to parse certs etc was written before minivpn could parse inline credentials. not needed anymore. --- .github/workflows/build.yml | 12 --- extras/ping/ping.go | 6 +- internal/reliabletransport/common_test.go | 8 ++ internal/reliabletransport/receiver.go | 42 ++++++++--- .../reliabletransport/reliable_ack_test.go | 6 +- .../reliable_reorder_test.go | 4 +- internal/vpntest/packetio.go | 1 - tests/integration/extract.sh | 55 -------------- .../integration/{openvpn_test.go => main.go} | 74 +++++++------------ 9 files changed, 75 insertions(+), 133 deletions(-) delete mode 100755 tests/integration/extract.sh rename tests/integration/{openvpn_test.go => main.go} (70%) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index f86ab5c9..4995f6a8 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -42,15 +42,3 @@ jobs: go-version: '1.20' - name: Ensure coverage threshold run: make test-coverage-threshold - - integration: - runs-on: ubuntu-latest - steps: - - uses: actions/checkout@v2 - - name: setup go - uses: actions/setup-go@v2 - with: - go-version: '1.20' - - name: run integration tests - run: go test -v ./tests/integration - diff --git a/extras/ping/ping.go b/extras/ping/ping.go index 652693fe..455e8dc1 100644 --- a/extras/ping/ping.go +++ b/extras/ping/ping.go @@ -396,6 +396,7 @@ func (p *Pinger) runLoop(recvCh <-chan *packet) error { } if p.Count > 0 && p.PacketsRecv >= p.Count { + p.done <- true return nil } } @@ -483,13 +484,16 @@ func (p *Pinger) recvICMP(recv chan<- *packet) error { case <-p.done: return nil default: + if p.PacketsRecv >= p.Count { + return nil + } buf := make([]byte, 512) if err := p.conn.SetReadDeadline(time.Now().Add(delay)); err != nil { return fmt.Errorf("%w: %s", errCannotSetReadDeadline, err) } n, err := p.conn.Read(buf) if err != nil { - var netErr *net.OpError + var netErr net.Error if errors.As(err, &netErr) && netErr.Timeout() { // Read timeout delay = expBackoff.Get() diff --git a/internal/reliabletransport/common_test.go b/internal/reliabletransport/common_test.go index 63581f48..d724c57b 100644 --- a/internal/reliabletransport/common_test.go +++ b/internal/reliabletransport/common_test.go @@ -6,6 +6,7 @@ import ( "github.com/ooni/minivpn/internal/model" "github.com/ooni/minivpn/internal/runtimex" "github.com/ooni/minivpn/internal/session" + "github.com/ooni/minivpn/internal/vpntest" "github.com/ooni/minivpn/internal/workers" ) @@ -45,3 +46,10 @@ func ackSetFromRange(start, total int) *ackSet { } return newACKSet(acks...) } + +func initializeSessionIDForWriter(writer *vpntest.PacketWriter, session *session.Manager) { + peerSessionID := newRandomSessionID() + writer.RemoteSessionID = model.SessionID(session.LocalSessionID()) + writer.LocalSessionID = peerSessionID + session.SetRemoteSessionID(peerSessionID) +} diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index 4b7f163e..d7c9511e 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -7,6 +7,7 @@ import ( "github.com/ooni/minivpn/internal/model" "github.com/ooni/minivpn/internal/optional" + "github.com/ooni/minivpn/internal/session" ) // moveUpWorker moves packets up the stack (receiver). @@ -34,7 +35,6 @@ func (ws *workersState) moveUpWorker() { if packet.Opcode != model.P_CONTROL_HARD_RESET_SERVER_V2 { // the hard reset has already been logged by the layer below - // TODO: move logging here? packet.Log(ws.logger, model.DirectionIncoming) } @@ -42,17 +42,11 @@ func (ws *workersState) moveUpWorker() { // I'm not sure that's a valid behavior for a server. // We should be able to deterministically test how this affects the state machine. - // drop a packet that is not for our session - if !bytes.Equal(packet.RemoteSessionID[:], ws.sessionManager.LocalSessionID()) { - ws.logger.Warnf( - "%s: packet with invalid RemoteSessionID: expected %x; got %x", - workerName, - ws.sessionManager.LocalSessionID(), - packet.RemoteSessionID, - ) + if ok := incomingSanityChecks(ws.logger, workerName, packet, ws.sessionManager); !ok { continue } + // notify seen packet to the sender using the lateral channel. seen := receiver.newIncomingPacketSeen(packet) ws.incomingSeen <- seen @@ -89,6 +83,36 @@ func (ws *workersState) moveUpWorker() { } } +func incomingSanityChecks(logger model.Logger, workerName string, packet *model.Packet, session *session.Manager) bool { + // drop a packet from a remote session we don't know about. + if !bytes.Equal(packet.LocalSessionID[:], session.RemoteSessionID()) { + logger.Warnf( + "%s: packet with invalid LocalSessionID: got %x; expected %x", + workerName, + packet.LocalSessionID, + session.RemoteSessionID(), + ) + return false + } + + if len(packet.ACKs) == 0 { + return true + } + + // only if we get incoming ACKs we can also check that the remote session id matches our own + // (packets with no ack array do not include remoteSessionID) + if !bytes.Equal(packet.RemoteSessionID[:], session.LocalSessionID()) { + logger.Warnf( + "%s: packet with invalid RemoteSessionID: got %x; expected %x", + workerName, + packet.RemoteSessionID, + session.LocalSessionID(), + ) + return false + } + return true +} + // // incomingPacketHandler implementation. // diff --git a/internal/reliabletransport/reliable_ack_test.go b/internal/reliabletransport/reliable_ack_test.go index 93fa9089..f0be8548 100644 --- a/internal/reliabletransport/reliable_ack_test.go +++ b/internal/reliabletransport/reliable_ack_test.go @@ -133,11 +133,7 @@ func TestReliable_ACK(t *testing.T) { writer := vpntest.NewPacketWriter(dataIn) // initialize a mock session ID for our peer - peerSessionID := newRandomSessionID() - - writer.RemoteSessionID = model.SessionID(session.LocalSessionID()) - writer.LocalSessionID = peerSessionID - session.SetRemoteSessionID(peerSessionID) + initializeSessionIDForWriter(writer, session) go writer.WriteSequence(tt.args.inputSequence) diff --git a/internal/reliabletransport/reliable_reorder_test.go b/internal/reliabletransport/reliable_reorder_test.go index b50d0cf9..3f49cbd7 100644 --- a/internal/reliabletransport/reliable_reorder_test.go +++ b/internal/reliabletransport/reliable_reorder_test.go @@ -126,9 +126,7 @@ func TestReliable_Reordering_UP(t *testing.T) { s.StartWorkers(model.NewConfig(model.WithLogger(log.Log)), workers, session) writer := vpntest.NewPacketWriter(dataIn) - - writer.RemoteSessionID = model.SessionID(session.LocalSessionID()) - writer.LocalSessionID = newRandomSessionID() + initializeSessionIDForWriter(writer, session) go writer.WriteSequence(tt.args.inputSequence) diff --git a/internal/vpntest/packetio.go b/internal/vpntest/packetio.go index 1e53a03d..f2e74ccb 100644 --- a/internal/vpntest/packetio.go +++ b/internal/vpntest/packetio.go @@ -46,7 +46,6 @@ func (pw *PacketWriter) WriteSequence(seq []string) { // possibly expand a input sequence in range notation for the packet ids [1..10] func maybeExpand(input string) []string { - fmt.Println("maybe expand") items := []string{} pattern := `^\[(\d+)\.\.(\d+)\] (.+)` regexpPattern := regexp.MustCompile(pattern) diff --git a/tests/integration/extract.sh b/tests/integration/extract.sh deleted file mode 100755 index 9c1ec31d..00000000 --- a/tests/integration/extract.sh +++ /dev/null @@ -1,55 +0,0 @@ -#!/bin/sh -# (c) Ain Ghazal 2022 -# this file converts an inline openvpn config file into -# a standalone config plus separate files for the ca.crt, -# cert.pem and key.pem. - -FILE=$1 -tail=0 - -# first lets extract the inline blocks -# ca block -tag=ca -f=ca.crt -sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f -n=$(wc -l $f | cut -f 1 -d ' ') -tail=$(($tail+n)) -cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null - -# key block -tag=key -f=key.pem -sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f -n=$(wc -l $f | cut -f 1 -d ' ') -tail=$(($tail+n)) -cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null - -# cert block -tag=cert -f=cert.pem -sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f -n=$(wc -l $f | cut -f 1 -d ' ') -tail=$(($tail+n)) -cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null - -# tls-auth (ignored) -tag=tls-auth -f=ta.pem -sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f -n=$(wc -l $f | cut -f 1 -d ' ') -tail=$(($tail+n)) -cat $f | tail -n $(($n-4)) | head -n $(($n-5)) | tee $f >/dev/null - -all=$(wc -l $FILE | cut -f -1 -d ' ') -cp $FILE config.bk - -echo "------------------------" -echo "Config file:" -echo "------------------------" -head -n $(($all-$tail)) $FILE | tee config -echo "------------------------" - -# now enable the paths for ca, cert and key -sed -i "s/;ca ca.crt/ca ca.crt/g" config -sed -i "s/;cert cert.pem/cert cert.pem/g" config -sed -i "s/;key key.pem/key key.pem/g" config diff --git a/tests/integration/openvpn_test.go b/tests/integration/main.go similarity index 70% rename from tests/integration/openvpn_test.go rename to tests/integration/main.go index 07060139..6b144ba0 100644 --- a/tests/integration/openvpn_test.go +++ b/tests/integration/main.go @@ -1,29 +1,27 @@ -//build: +integration package main import ( "bufio" - "bytes" "context" "fmt" - "io/ioutil" - "log" + "io" + "net" "net/http" "os" - "os/exec" "path/filepath" "testing" - "time" + "github.com/apex/log" "github.com/ory/dockertest/v3" dc "github.com/ory/dockertest/v3/docker" "github.com/ooni/minivpn/extras/ping" - "github.com/ooni/minivpn/vpn" + "github.com/ooni/minivpn/internal/model" + "github.com/ooni/minivpn/internal/networkio" + "github.com/ooni/minivpn/internal/tun" ) const ( - parseConfig = "extract.sh" dockerImage = "ainghazal/openvpn" dockerTag = "latest" ) @@ -34,14 +32,14 @@ var ( ) func copyFile(src, dst string) error { - input, err := ioutil.ReadFile(src) + input, err := os.ReadFile(src) if err != nil { fmt.Println(err) return nil } dstFile := filepath.Join(dst, src) - err = ioutil.WriteFile(dstFile, input, 0744) + err = os.WriteFile(dstFile, input, 0744) if err != nil { fmt.Println("Error creating", dstFile) return err @@ -73,7 +71,7 @@ func launchDocker(cipher, auth string) ([]byte, *dockertest.Pool, *dockertest.Re // the minio client does not do service discovery for you (i.e. it does not check if connection can be established), so we have to use the health check var config []byte if err := pool.Retry(func() error { - url := fmt.Sprintf("http://localhost:8080/") + url := "http://localhost:8080/" resp, err := http.Get(url) if err != nil { return err @@ -81,7 +79,7 @@ func launchDocker(cipher, auth string) ([]byte, *dockertest.Pool, *dockertest.Re if resp.StatusCode != http.StatusOK { return fmt.Errorf("status code not OK") } - config, err = ioutil.ReadAll(resp.Body) + config, err = io.ReadAll(resp.Body) if err != nil { panic(err) } @@ -94,9 +92,9 @@ func launchDocker(cipher, auth string) ([]byte, *dockertest.Pool, *dockertest.Re } func stopContainer(p *dockertest.Pool, res *dockertest.Resource) { - fmt.Println("Stopping container") + fmt.Println("[!] Stopping container") if err := p.Purge(res); err != nil { - log.Printf("Could not purge resource: %s\n", err) + log.Warnf("Could not purge resource: %s\n", err) } } @@ -106,60 +104,42 @@ func TestClientAES256GCM(t *testing.T) { } tmp := t.TempDir() - copyFile(parseConfig, tmp) - os.Chdir(tmp) - err := os.Chmod(parseConfig, 0700) - if err != nil { - log.Fatal(err) - } - + fmt.Println("launching docker") config, pool, resource, err := launchDocker("AES-256-GCM", "SHA256") - if err != nil { - log.Fatal(err) + t.Errorf("cannot start docker: %v", err) } // when all test done, time to kill and remove the container defer stopContainer(pool, resource) - cfgFile, err := ioutil.TempFile(tmp, "minivpn-e2e-") - defer cfgFile.Close() + cfgFile, err := os.CreateTemp(tmp, "minivpn-e2e-") if err != nil { - log.Fatal("Cannot create temporary file", err) + t.Errorf("Cannot create temporary file: %v", err) } + defer cfgFile.Close() fmt.Println("Config written to: " + cfgFile.Name()) if _, err = cfgFile.Write(config); err != nil { - log.Fatal("Failed to write config to temporary file", err) + t.Errorf("Failed to write config to temporary file: %v", err) } - // execute the extract.sh shell script, to process key blocks piecewise - cmd := exec.Command("./"+parseConfig, cfgFile.Name()) - cmd.Dir = tmp - var out bytes.Buffer - cmd.Stdout = &out - cmd.Run() + // actual test begins + vpnConfig := model.NewConfig(model.WithConfigFile(cfgFile.Name())) + dialer := networkio.NewDialer(log.Log, &net.Dialer{}) + conn, err := dialer.DialContext(context.TODO(), vpnConfig.Remote().Protocol, vpnConfig.Remote().AddrPort) if err != nil { - log.Fatal(err) + t.Errorf("dial error: %v", err) } - c, err := readLines("config") - fmt.Println("Remote:", c[len(c)-1]) - // can assert that this is a remote line - - // actual test begins - opt, err := vpn.NewOptionsFromFilePath(filepath.Join(tmp, "config")) + tunnel, err := tun.StartTUN(context.TODO(), conn, vpnConfig) if err != nil { - log.Fatalf("Could not parse file: %s", err) + t.Errorf("cannot start tunnel: %v", err) } - ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) - defer cancel() - tunnel := vpn.NewClientFromOptions(opt) - tunnel.Start(ctx) pinger := ping.New(target, tunnel) pinger.Count = count - err = pinger.Run(ctx) + err = pinger.Run(context.Background()) defer pinger.Stop() if err != nil { log.Fatalf("VPN Error: %s", err) @@ -174,10 +154,10 @@ func TestClientAES256GCM(t *testing.T) { func readLines(f string) ([]string, error) { var ll []string rf, err := os.Open(f) - defer rf.Close() if err != nil { return ll, err } + defer rf.Close() fs := bufio.NewScanner(rf) fs.Split(bufio.ScanLines) for fs.Scan() { From e8eaeaf75db1d4295e2ed5ead86a873a19d05fb4 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 15:56:49 +0100 Subject: [PATCH 08/39] make tracer public --- internal/model/trace.go | 84 ----------------- internal/tracex/trace.go | 143 ----------------------------- pkg/README.md | 1 + pkg/tracex/trace.go | 192 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 193 insertions(+), 227 deletions(-) delete mode 100644 internal/tracex/trace.go create mode 100644 pkg/README.md create mode 100644 pkg/tracex/trace.go diff --git a/internal/model/trace.go b/internal/model/trace.go index 3a8ecb0f..79fce3f8 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -1,11 +1,8 @@ package model import ( - "encoding/json" "fmt" "time" - - "github.com/ooni/minivpn/internal/optional" ) // HandshakeTracer allows to collect traces for a given OpenVPN handshake. A HandshakeTracer can be optionally @@ -28,84 +25,6 @@ type HandshakeTracer interface { // OnHandshakeDone is called when we have completed a handshake. OnHandshakeDone(remoteAddr string) - - // Trace returns an array of [HandshakeEvent]s. - // TODO -- remove the Trace() method ------------------------------- - Trace() []HandshakeEvent -} - -const ( - HandshakeEventStateChange = iota - HandshakeEventPacketIn - HandshakeEventPacketOut - HandshakeEventPacketDropped -) - -// HandshakeEventType indicates which event we logged. -type HandshakeEventType int - -// Ensure that it implements the Stringer interface. -var _ fmt.Stringer = HandshakeEventType(0) - -// String implements fmt.Stringer -func (e HandshakeEventType) String() string { - switch e { - case HandshakeEventStateChange: - return "state" - case HandshakeEventPacketIn: - return "packet_in" - case HandshakeEventPacketOut: - return "packet_out" - case HandshakeEventPacketDropped: - return "packet_dropped" - default: - return "unknown" - } -} - -// HandshakeEvent must implement the event annotation methods, plus json serialization. -// TODO: this is easier as a struct -type HandshakeEvent interface { - Type() HandshakeEventType - Time() time.Time - Packet() optional.Value[LoggedPacket] - json.Marshaler -} - -// LoggedPacket tracks metadata about a packet useful to build traces. -type LoggedPacket struct { - Direction Direction - - // the only fields of the packet we want to log. - Opcode Opcode - ID PacketID - ACKs []PacketID - - // PayloadSize is the size of the payload in bytes - PayloadSize int - - // Retries keeps track of packet retransmission (only for outgoing packets). - Retries int -} - -// MarshalJSON implements json.Marshaler. -func (lp LoggedPacket) MarshalJSON() ([]byte, error) { - j := struct { - Opcode string `json:"opcode"` - ID PacketID `json:"id"` - ACKs []PacketID `json:"acks"` - Direction string `json:"direction"` - PayloadSize int `json:"payload_size"` - Retries int `json:"send_attempts"` - }{ - Opcode: lp.Opcode.String(), - ID: lp.ID, - ACKs: lp.ACKs, - Direction: lp.Direction.String(), - PayloadSize: lp.PayloadSize, - Retries: lp.Retries, - } - return json.Marshal(j) } // Direction is one of two directions on a packet. @@ -155,8 +74,5 @@ func (dt *dummyTracer) OnDroppedPacket(direction Direction, packet *Packet) { func (dt *dummyTracer) OnHandshakeDone(remoteAddr string) {} -// Trace returns a structured log containing an array of [model.HandshakeEvent]. -func (dt *dummyTracer) Trace() []HandshakeEvent { return []HandshakeEvent{} } - // Assert that dummyTracer implements [model.HandshakeTracer]. var _ HandshakeTracer = &dummyTracer{} diff --git a/internal/tracex/trace.go b/internal/tracex/trace.go deleted file mode 100644 index c3f5ebb0..00000000 --- a/internal/tracex/trace.go +++ /dev/null @@ -1,143 +0,0 @@ -// Package tracex implements a [model.HandshakeTracer] that can be passed to the TUN constructor to -// observe handshake events. -package tracex - -import ( - "encoding/json" - "sync" - "time" - - "github.com/ooni/minivpn/internal/model" - "github.com/ooni/minivpn/internal/optional" -) - -// event implements [model.HandshakeEvent] -type event struct { - // EventType is the type for this event. - eventType model.HandshakeEventType - - // AtTime is the time for this event, relative to the start time. - atTime time.Time - - // TODO: discuss: do we want both? - deltaTime time.Duration - - // loggedPacket is an optional packet metadata. - loggedPacket optional.Value[model.LoggedPacket] -} - -func newEvent(etype model.HandshakeEventType, t time.Time, t0 time.Time) *event { - return &event{ - eventType: etype, - atTime: t, - deltaTime: t.Sub(t0), - loggedPacket: optional.None[model.LoggedPacket](), - } -} - -// Type returns the type for the event. -func (e event) Type() model.HandshakeEventType { - return e.eventType -} - -// Time returns the event timestamp. -func (e event) Time() time.Time { - return e.atTime -} - -// Packet returns an optional logged packet. -func (e event) Packet() optional.Value[model.LoggedPacket] { - return e.loggedPacket -} - -// MarshalJSON implements json.Marshaler -func (e event) MarshalJSON() ([]byte, error) { - j := struct { - Type string `json:"type"` - Time time.Time `json:"t"` - Packet model.LoggedPacket `json:"packet"` - }{ - Type: e.Type().String(), - Time: e.Time(), - Packet: e.Packet().Unwrap(), - } - return json.Marshal(j) -} - -var _ model.HandshakeEvent = event{} - -// Tracer implements [model.HandshakeTracer]. -type Tracer struct { - // events is an array of handshake events. - events []model.HandshakeEvent - - // mu guards access to the events. - mu sync.Mutex - - // zeroTime is the time when we started a packet trace. - zeroTime time.Time -} - -// NewTracer returns a Tracer with the passed start time. -func NewTracer(start time.Time) *Tracer { - return &Tracer{ - zeroTime: start, - } -} - -// TimeNow allows to manipulate time for deterministic tests. -func (t *Tracer) TimeNow() time.Time { - return time.Now() -} - -// OnStateChange is called for each transition in the state machine. -func (t *Tracer) OnStateChange(state int) { - panic("not implemented") // TODO: Implement -} - -// OnIncomingPacket is called when a packet is received. -func (t *Tracer) OnIncomingPacket(packet *model.Packet) { - t.mu.Lock() - defer t.mu.Unlock() - - e := newEvent(model.HandshakeEventPacketIn, t.TimeNow(), t.zeroTime) - e.loggedPacket = logPacket(packet, -1, model.DirectionIncoming) - t.events = append(t.events, e) -} - -// OnOutgoingPacket is called when a packet is about to be sent. -func (t *Tracer) OnOutgoingPacket(packet *model.Packet, retries int) { - t.mu.Lock() - defer t.mu.Unlock() - - e := newEvent(model.HandshakeEventPacketOut, t.TimeNow(), t.zeroTime) - e.loggedPacket = logPacket(packet, retries, model.DirectionOutgoing) - t.events = append(t.events, e) -} - -// OnDroppedPacket is called whenever a packet is dropped (in/out) -func (t *Tracer) OnDroppedPacket(direction model.Direction, packet *model.Packet) { - // panic("not implemented") // TODO: Implement -} - -func (t *Tracer) OnHandshakeDone(remoteAddr string) { - panic("not implemented") // TODO: Implement -} - -// Trace returns a structured log containing an array of [model.HandshakeEvent]. -func (t *Tracer) Trace() []model.HandshakeEvent { - t.mu.Lock() - defer t.mu.Unlock() - return append([]model.HandshakeEvent{}, t.events...) -} - -func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[model.LoggedPacket] { - return optional.Some(model.LoggedPacket{ - Opcode: p.Opcode, - ID: p.ID, - ACKs: p.ACKs, - Direction: direction, - PayloadSize: len(p.Payload), - Retries: retries, - }) -} diff --git a/pkg/README.md b/pkg/README.md new file mode 100644 index 00000000..6fbe1f04 --- /dev/null +++ b/pkg/README.md @@ -0,0 +1 @@ +This folder contains public go packages. diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go new file mode 100644 index 00000000..cadee243 --- /dev/null +++ b/pkg/tracex/trace.go @@ -0,0 +1,192 @@ +// Package tracex implements a handshake tracer that can be passed to the TUN constructor to +// observe handshake events. +package tracex + +import ( + "encoding/json" + "fmt" + "sync" + "time" + + "github.com/ooni/minivpn/internal/model" + "github.com/ooni/minivpn/internal/optional" +) + +// event is one handshake event collected by this [model.HandshakeTracer]. +type event struct { + // EventType is the type for this event. + EventType HandshakeEventType + + // AtTime is the time for this event, relative to the start time. + AtTime time.Time + + DeltaTime time.Duration + + // LoggedPacket is an optional packet metadata. + LoggedPacket optional.Value[LoggedPacket] +} + +func newEvent(etype HandshakeEventType, t time.Time, t0 time.Time) *event { + return &event{ + EventType: etype, + AtTime: t, + DeltaTime: t.Sub(t0), + LoggedPacket: optional.None[LoggedPacket](), + } +} + +// MarshalJSON implements json.Marshaler +func (e event) MarshalJSON() ([]byte, error) { + j := struct { + Type string `json:"type"` + Time time.Time `json:"t"` + Packet LoggedPacket `json:"packet"` + }{ + Type: e.EventType.String(), + Time: e.AtTime, + Packet: e.LoggedPacket.Unwrap(), + } + return json.Marshal(j) +} + +// Tracer implements [model.HandshakeTracer]. +type Tracer struct { + // events is the array of handshake events. + events []*event + + // mu guards access to the events. + mu sync.Mutex + + // zeroTime is the time when we started a packet trace. + zeroTime time.Time +} + +// NewTracer returns a Tracer with the passed start time. +func NewTracer(start time.Time) *Tracer { + return &Tracer{ + zeroTime: start, + } +} + +// TimeNow allows to manipulate time for deterministic tests. +func (t *Tracer) TimeNow() time.Time { + return time.Now() +} + +// OnStateChange is called for each transition in the state machine. +func (t *Tracer) OnStateChange(state int) { + panic("not implemented") // TODO: Implement +} + +// OnIncomingPacket is called when a packet is received. +func (t *Tracer) OnIncomingPacket(packet *model.Packet) { + t.mu.Lock() + defer t.mu.Unlock() + + e := newEvent(handshakeEventPacketIn, t.TimeNow(), t.zeroTime) + e.LoggedPacket = logPacket(packet, -1, model.DirectionIncoming) + t.events = append(t.events, e) +} + +// OnOutgoingPacket is called when a packet is about to be sent. +func (t *Tracer) OnOutgoingPacket(packet *model.Packet, retries int) { + t.mu.Lock() + defer t.mu.Unlock() + + e := newEvent(handshakeEventPacketOut, t.TimeNow(), t.zeroTime) + e.LoggedPacket = logPacket(packet, retries, model.DirectionOutgoing) + t.events = append(t.events, e) +} + +// OnDroppedPacket is called whenever a packet is dropped (in/out) +func (t *Tracer) OnDroppedPacket(direction model.Direction, packet *model.Packet) { + // panic("not implemented") // TODO: Implement +} + +func (t *Tracer) OnHandshakeDone(remoteAddr string) { + panic("not implemented") // TODO: Implement +} + +// Trace returns a structured log containing a copy of the array of [model.HandshakeEvent]. +func (t *Tracer) Trace() []*event { + t.mu.Lock() + defer t.mu.Unlock() + return append([]*event{}, t.events...) +} + +func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[LoggedPacket] { + return optional.Some(LoggedPacket{ + Opcode: p.Opcode, + ID: p.ID, + ACKs: p.ACKs, + Direction: direction, + PayloadSize: len(p.Payload), + Retries: retries, + }) +} + +const ( + handshakeEventStateChange = iota + handshakeEventPacketIn + handshakeEventPacketOut + handshakeEventPacketDropped +) + +// HandshakeEventType indicates which event we logged. +type HandshakeEventType int + +// Ensure that it implements the Stringer interface. +var _ fmt.Stringer = HandshakeEventType(0) + +// String implements fmt.Stringer +func (e HandshakeEventType) String() string { + switch e { + case handshakeEventStateChange: + return "state" + case handshakeEventPacketIn: + return "packet_in" + case handshakeEventPacketOut: + return "packet_out" + case handshakeEventPacketDropped: + return "packet_dropped" + default: + return "unknown" + } +} + +// LoggedPacket tracks metadata about a packet useful to build traces. +type LoggedPacket struct { + Direction model.Direction + + // the only fields of the packet we want to log. + Opcode model.Opcode + ID model.PacketID + ACKs []model.PacketID + + // PayloadSize is the size of the payload in bytes + PayloadSize int + + // Retries keeps track of packet retransmission (only for outgoing packets). + // TODO: use optional here. + Retries int +} + +// MarshalJSON implements json.Marshaler. +func (lp LoggedPacket) MarshalJSON() ([]byte, error) { + j := struct { + Direction string `json:"direction"` + Opcode string `json:"opcode"` + ID model.PacketID `json:"id"` + ACKs []model.PacketID `json:"acks"` + PayloadSize int `json:"payload_size"` + Retries int `json:"send_attempts"` + }{ + Direction: lp.Direction.String(), + Opcode: lp.Opcode.String(), + ID: lp.ID, + ACKs: lp.ACKs, + PayloadSize: lp.PayloadSize, + Retries: lp.Retries, + } + return json.Marshal(j) +} From 6bd35837fb5fcdc6c5726e7fbfb62c6561add814 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 17:35:09 +0100 Subject: [PATCH 09/39] iterate on tracer --- internal/model/trace.go | 12 +- internal/optional/optional.go | 42 ++++++ internal/reliabletransport/common_test.go | 2 +- internal/reliabletransport/receiver.go | 12 +- internal/reliabletransport/sender.go | 8 +- internal/reliabletransport/service_test.go | 2 +- internal/session/manager.go | 7 +- internal/tun/tun.go | 2 +- pkg/tracex/trace.go | 149 ++++++++++++--------- 9 files changed, 160 insertions(+), 76 deletions(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index 79fce3f8..40958764 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -15,13 +15,13 @@ type HandshakeTracer interface { OnStateChange(state int) // OnIncomingPacket is called when a packet is received. - OnIncomingPacket(packet *Packet) + OnIncomingPacket(packet *Packet, stage int) // OnOutgoingPacket is called when a packet is about to be sent. - OnOutgoingPacket(packet *Packet, retries int) + OnOutgoingPacket(packet *Packet, stage int, retries int) // OnDroppedPacket is called whenever a packet is dropped (in/out) - OnDroppedPacket(direction Direction, packet *Packet) + OnDroppedPacket(direction Direction, stage int, packet *Packet) // OnHandshakeDone is called when we have completed a handshake. OnHandshakeDone(remoteAddr string) @@ -63,13 +63,13 @@ func (dt *dummyTracer) TimeNow() time.Time { return time.Now() } func (dt *dummyTracer) OnStateChange(state int) {} // OnIncomingPacket is called when a packet is received. -func (dt *dummyTracer) OnIncomingPacket(packet *Packet) {} +func (dt *dummyTracer) OnIncomingPacket(*Packet, int) {} // OnOutgoingPacket is called when a packet is about to be sent. -func (dt *dummyTracer) OnOutgoingPacket(packet *Packet, retries int) {} +func (dt *dummyTracer) OnOutgoingPacket(*Packet, int, int) {} // OnDroppedPacket is called whenever a packet is dropped (in/out) -func (dt *dummyTracer) OnDroppedPacket(direction Direction, packet *Packet) { +func (dt *dummyTracer) OnDroppedPacket(Direction, int, *Packet) { } func (dt *dummyTracer) OnHandshakeDone(remoteAddr string) {} diff --git a/internal/optional/optional.go b/internal/optional/optional.go index f330b812..39c63f2f 100644 --- a/internal/optional/optional.go +++ b/internal/optional/optional.go @@ -1,6 +1,8 @@ package optional import ( + "bytes" + "encoding/json" "reflect" "github.com/ooni/minivpn/internal/runtimex" @@ -56,3 +58,43 @@ func (v Value[T]) UnwrapOr(fallback T) T { } return v.Unwrap() } + +var _ json.Unmarshaler = &Value[int]{} + +// UnmarshalJSON implements json.Unmarshaler. Note that a `null` JSON +// value always leads to an empty Value. +func (v *Value[T]) UnmarshalJSON(data []byte) error { + // A `null` underlying value should always be equivalent to + // invoking the None constructor of for T. While this is not + // what the [json] package recommends doing for this case, + // it is consistent with initializing an optional. + if bytes.Equal(data, []byte(`null`)) { + v.indirect = nil + return nil + } + + // Otherwise, let's try to unmarshal into a real value + var value T + if err := json.Unmarshal(data, &value); err != nil { + return err + } + + // Enforce the same semantics of the Some constructor: treat + // pointer types specially to avoid the case where we have + // a Value that is wrapping a nil pointer but for which the + // IsNone check actually returns false. (Maybe this check is + // redundant but it seems better to enforce it anyway.) + maybeSetFromValue(v, value) + return nil +} + +var _ json.Marshaler = Value[int]{} + +// MarshalJSON implements json.Marshaler. An empty value serializes +// to `null` and otherwise we serialize the underluing value. +func (v Value[T]) MarshalJSON() ([]byte, error) { + if v.indirect == nil { + return json.Marshal(nil) + } + return json.Marshal(*v.indirect) +} diff --git a/internal/reliabletransport/common_test.go b/internal/reliabletransport/common_test.go index d724c57b..bd3f3f9b 100644 --- a/internal/reliabletransport/common_test.go +++ b/internal/reliabletransport/common_test.go @@ -17,7 +17,7 @@ import ( // initManagers initializes a workers manager and a session manager. func initManagers() (*workers.Manager, *session.Manager) { w := workers.NewManager(log.Log) - s, err := session.NewManager(log.Log) + s, err := session.NewManager(model.NewConfig(model.WithLogger(log.Log))) runtimex.PanicOnError(err, "cannot create session manager") return w, s } diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index d7c9511e..38bd829b 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -31,7 +31,7 @@ func (ws *workersState) moveUpWorker() { // or POSSIBLY BLOCK waiting for notifications select { case packet := <-ws.muxerToReliable: - ws.tracer.OnIncomingPacket(packet) + ws.tracer.OnIncomingPacket(packet, int(ws.sessionManager.NegotiationState())) if packet.Opcode != model.P_CONTROL_HARD_RESET_SERVER_V2 { // the hard reset has already been logged by the layer below @@ -55,14 +55,20 @@ func (ws *workersState) moveUpWorker() { // we only want to insert control packets going to the tls layer if packet.Opcode != model.P_CONTROL_V1 { // TODO: add reason - ws.tracer.OnDroppedPacket(model.DirectionIncoming, packet) + ws.tracer.OnDroppedPacket( + model.DirectionIncoming, + int(ws.sessionManager.NegotiationState()), + packet) continue } if inserted := receiver.MaybeInsertIncoming(packet); !inserted { // this packet was not inserted in the queue: we drop it // TODO: add reason - ws.tracer.OnDroppedPacket(model.DirectionIncoming, packet) + ws.tracer.OnDroppedPacket( + model.DirectionIncoming, + int(ws.sessionManager.NegotiationState()), + packet) ws.logger.Debugf("Dropping packet: %v", packet.ID) continue } diff --git a/internal/reliabletransport/sender.go b/internal/reliabletransport/sender.go index f3cda823..c3dae808 100644 --- a/internal/reliabletransport/sender.go +++ b/internal/reliabletransport/sender.go @@ -82,9 +82,13 @@ func (ws *workersState) blockOnTryingToSend(sender *reliableSender, ticker *time // append any pending ACKs p.packet.ACKs = sender.NextPacketIDsToACK() - // log the packet + // log and trace the packet p.packet.Log(ws.logger, model.DirectionOutgoing) - ws.tracer.OnOutgoingPacket(p.packet, int(p.retries)) + ws.tracer.OnOutgoingPacket( + p.packet, + int(ws.sessionManager.NegotiationState()), + int(p.retries), + ) select { case ws.dataOrControlToMuxer <- p.packet: diff --git a/internal/reliabletransport/service_test.go b/internal/reliabletransport/service_test.go index bde1f0d0..aeb4bc49 100644 --- a/internal/reliabletransport/service_test.go +++ b/internal/reliabletransport/service_test.go @@ -45,7 +45,7 @@ func TestService_StartWorkers(t *testing.T) { config: model.NewConfig(model.WithLogger(log.Log)), workersManager: workers.NewManager(log.Log), sessionManager: func() *session.Manager { - m, _ := session.NewManager(log.Log) + m, _ := session.NewManager(model.NewConfig(model.WithLogger(log.Log))) return m }(), }, diff --git a/internal/session/manager.go b/internal/session/manager.go index 1e74dae2..0bffcaf2 100644 --- a/internal/session/manager.go +++ b/internal/session/manager.go @@ -84,6 +84,7 @@ type Manager struct { negState SessionNegotiationState remoteSessionID optional.Value[model.SessionID] tunnelInfo model.TunnelInfo + tracer model.HandshakeTracer // Ready is a channel where we signal that we can start accepting data, because we've // successfully generated key material for the data channel. @@ -91,7 +92,7 @@ type Manager struct { } // NewManager returns a [Manager] ready to be used. -func NewManager(logger model.Logger) (*Manager, error) { +func NewManager(config *model.Config) (*Manager, error) { key0 := &DataChannelKey{} sessionManager := &Manager{ keyID: 0, @@ -99,11 +100,12 @@ func NewManager(logger model.Logger) (*Manager, error) { // localControlPacketID should be initialized to 1 because we handle hard-reset as special cases localControlPacketID: 1, localSessionID: [8]byte{}, - logger: logger, + logger: config.Logger(), mu: sync.Mutex{}, negState: 0, remoteSessionID: optional.None[model.SessionID](), tunnelInfo: model.TunnelInfo{}, + tracer: config.Tracer(), // empirically, it seems that the reference OpenVPN server misbehaves if we initialize // the data packet ID counter to zero. @@ -272,6 +274,7 @@ func (m *Manager) SetNegotiationState(sns SessionNegotiationState) { defer m.mu.Unlock() m.mu.Lock() m.logger.Infof("[@] %s -> %s", m.negState, sns) + m.tracer.OnStateChange(int(sns)) m.negState = sns if sns == S_GENERATED_KEYS { m.Ready <- true diff --git a/internal/tun/tun.go b/internal/tun/tun.go index b6c31db4..8b7878db 100644 --- a/internal/tun/tun.go +++ b/internal/tun/tun.go @@ -23,7 +23,7 @@ var ( // If the passed context expires before the TUN device is ready, func StartTUN(ctx context.Context, conn networkio.FramingConn, config *model.Config) (*TUN, error) { // create a session - sessionManager, err := session.NewManager(config.Logger()) + sessionManager, err := session.NewManager(config) if err != nil { return nil, err } diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index cadee243..e3f46ffa 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -10,27 +10,58 @@ import ( "github.com/ooni/minivpn/internal/model" "github.com/ooni/minivpn/internal/optional" + "github.com/ooni/minivpn/internal/session" ) +const ( + handshakeEventStateChange = iota + handshakeEventPacketIn + handshakeEventPacketOut + handshakeEventPacketDropped +) + +// HandshakeEventType indicates which event we logged. +type HandshakeEventType int + +// Ensure that it implements the Stringer interface. +var _ fmt.Stringer = HandshakeEventType(0) + +// String implements fmt.Stringer +func (e HandshakeEventType) String() string { + switch e { + case handshakeEventStateChange: + return "state" + case handshakeEventPacketIn: + return "packet_in" + case handshakeEventPacketOut: + return "packet_out" + case handshakeEventPacketDropped: + return "packet_dropped" + default: + return "unknown" + } +} + // event is one handshake event collected by this [model.HandshakeTracer]. type event struct { // EventType is the type for this event. EventType HandshakeEventType - // AtTime is the time for this event, relative to the start time. - AtTime time.Time + // Stage is the stage of the handshake negotiation we're in. + Stage session.SessionNegotiationState - DeltaTime time.Duration + // AtTime is the time for this event, relative to the start time. + AtTime time.Duration // LoggedPacket is an optional packet metadata. LoggedPacket optional.Value[LoggedPacket] } -func newEvent(etype HandshakeEventType, t time.Time, t0 time.Time) *event { +func newEvent(etype HandshakeEventType, st session.SessionNegotiationState, t time.Time, t0 time.Time) *event { return &event{ EventType: etype, - AtTime: t, - DeltaTime: t.Sub(t0), + Stage: st, + AtTime: t.Sub(t0), LoggedPacket: optional.None[LoggedPacket](), } } @@ -38,13 +69,15 @@ func newEvent(etype HandshakeEventType, t time.Time, t0 time.Time) *event { // MarshalJSON implements json.Marshaler func (e event) MarshalJSON() ([]byte, error) { j := struct { - Type string `json:"type"` - Time time.Time `json:"t"` - Packet LoggedPacket `json:"packet"` + Type string `json:"operation"` + Stage string `json:"stage"` + Time float64 `json:"t"` + Packet optional.Value[LoggedPacket] `json:"packet"` }{ Type: e.EventType.String(), - Time: e.AtTime, - Packet: e.LoggedPacket.Unwrap(), + Stage: e.Stage.String()[2:], + Time: e.AtTime.Seconds(), + Packet: e.LoggedPacket, } return json.Marshal(j) } @@ -75,36 +108,48 @@ func (t *Tracer) TimeNow() time.Time { // OnStateChange is called for each transition in the state machine. func (t *Tracer) OnStateChange(state int) { - panic("not implemented") // TODO: Implement + t.mu.Lock() + defer t.mu.Unlock() + stg := session.SessionNegotiationState(state) + e := newEvent(handshakeEventStateChange, stg, t.TimeNow(), t.zeroTime) + t.events = append(t.events, e) } // OnIncomingPacket is called when a packet is received. -func (t *Tracer) OnIncomingPacket(packet *model.Packet) { +func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage int) { t.mu.Lock() defer t.mu.Unlock() - e := newEvent(handshakeEventPacketIn, t.TimeNow(), t.zeroTime) + stg := session.SessionNegotiationState(stage) + e := newEvent(handshakeEventPacketIn, stg, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, -1, model.DirectionIncoming) t.events = append(t.events, e) } // OnOutgoingPacket is called when a packet is about to be sent. -func (t *Tracer) OnOutgoingPacket(packet *model.Packet, retries int) { +func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage int, retries int) { t.mu.Lock() defer t.mu.Unlock() - e := newEvent(handshakeEventPacketOut, t.TimeNow(), t.zeroTime) + stg := session.SessionNegotiationState(stage) + e := newEvent(handshakeEventPacketOut, stg, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, retries, model.DirectionOutgoing) t.events = append(t.events, e) } // OnDroppedPacket is called whenever a packet is dropped (in/out) -func (t *Tracer) OnDroppedPacket(direction model.Direction, packet *model.Packet) { - // panic("not implemented") // TODO: Implement +func (t *Tracer) OnDroppedPacket(direction model.Direction, stage int, packet *model.Packet) { + t.mu.Lock() + defer t.mu.Unlock() + + stg := session.SessionNegotiationState(stage) + e := newEvent(handshakeEventPacketDropped, stg, t.TimeNow(), t.zeroTime) + e.LoggedPacket = logPacket(packet, -1, direction) + t.events = append(t.events, e) } func (t *Tracer) OnHandshakeDone(remoteAddr string) { - panic("not implemented") // TODO: Implement + panic("not implemented") // TODO: Implement - when received IP from server. } // Trace returns a structured log containing a copy of the array of [model.HandshakeEvent]. @@ -115,43 +160,22 @@ func (t *Tracer) Trace() []*event { } func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[LoggedPacket] { - return optional.Some(LoggedPacket{ + retriesValue := optional.None[int]() + if retries != -1 { + retriesValue = optional.Some(retries) + } + logged := LoggedPacket{ Opcode: p.Opcode, ID: p.ID, - ACKs: p.ACKs, + ACKs: optional.None[[]model.PacketID](), Direction: direction, PayloadSize: len(p.Payload), - Retries: retries, - }) -} - -const ( - handshakeEventStateChange = iota - handshakeEventPacketIn - handshakeEventPacketOut - handshakeEventPacketDropped -) - -// HandshakeEventType indicates which event we logged. -type HandshakeEventType int - -// Ensure that it implements the Stringer interface. -var _ fmt.Stringer = HandshakeEventType(0) - -// String implements fmt.Stringer -func (e HandshakeEventType) String() string { - switch e { - case handshakeEventStateChange: - return "state" - case handshakeEventPacketIn: - return "packet_in" - case handshakeEventPacketOut: - return "packet_out" - case handshakeEventPacketDropped: - return "packet_dropped" - default: - return "unknown" + Retries: retriesValue, + } + if len(p.ACKs) != 0 { + logged.ACKs = optional.Some(p.ACKs) } + return optional.Some(logged) } // LoggedPacket tracks metadata about a packet useful to build traces. @@ -161,27 +185,27 @@ type LoggedPacket struct { // the only fields of the packet we want to log. Opcode model.Opcode ID model.PacketID - ACKs []model.PacketID + ACKs optional.Value[[]model.PacketID] // PayloadSize is the size of the payload in bytes PayloadSize int // Retries keeps track of packet retransmission (only for outgoing packets). // TODO: use optional here. - Retries int + Retries optional.Value[int] } // MarshalJSON implements json.Marshaler. func (lp LoggedPacket) MarshalJSON() ([]byte, error) { j := struct { - Direction string `json:"direction"` - Opcode string `json:"opcode"` - ID model.PacketID `json:"id"` - ACKs []model.PacketID `json:"acks"` - PayloadSize int `json:"payload_size"` - Retries int `json:"send_attempts"` + Direction string `json:"operation"` + Opcode string `json:"opcode"` + ID model.PacketID `json:"id"` + ACKs optional.Value[[]model.PacketID] `json:"acks"` + PayloadSize int `json:"payload_size"` + Retries optional.Value[int] `json:"send_attempts"` }{ - Direction: lp.Direction.String(), + Direction: dirMap[lp.Direction.String()], Opcode: lp.Opcode.String(), ID: lp.ID, ACKs: lp.ACKs, @@ -190,3 +214,8 @@ func (lp LoggedPacket) MarshalJSON() ([]byte, error) { } return json.Marshal(j) } + +var dirMap = map[string]string{ + "recv": "read", + "send": "write", +} From 79c9cf0cdc23bbd3640d15b70bf3d25d2c61d59f Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 17:45:29 +0100 Subject: [PATCH 10/39] x --- internal/reliabletransport/receiver.go | 5 ----- 1 file changed, 5 deletions(-) diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index 38bd829b..44655bc1 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -54,11 +54,6 @@ func (ws *workersState) moveUpWorker() { // we only want to insert control packets going to the tls layer if packet.Opcode != model.P_CONTROL_V1 { - // TODO: add reason - ws.tracer.OnDroppedPacket( - model.DirectionIncoming, - int(ws.sessionManager.NegotiationState()), - packet) continue } From b2fcbfd90d7f2c9b5986a89ddcaea3ba48a24275 Mon Sep 17 00:00:00 2001 From: ain ghazal Date: Fri, 9 Feb 2024 17:51:39 +0100 Subject: [PATCH 11/39] trace outgoing hard reset too --- internal/packetmuxer/service.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index e0dc74be..36b16b7b 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -66,6 +66,7 @@ func (s *Service) StartWorkers( muxerToNetwork: *s.MuxerToNetwork, networkToMuxer: s.NetworkToMuxer, sessionManager: sessionManager, + tracer: config.Tracer(), workersManager: workersManager, } workersManager.StartWorker(ws.moveUpWorker) @@ -107,6 +108,9 @@ type workersState struct { // sessionManager manages the OpenVPN session. sessionManager *session.Manager + // tracer is a [model.HandshakeTracer]. + tracer model.HandshakeTracer + // workersManager controls the workers lifecycle. workersManager *workers.Manager } @@ -289,6 +293,12 @@ func (ws *workersState) serializeAndEmit(packet *model.Packet) error { return err } + ws.tracer.OnOutgoingPacket( + packet, + int(ws.sessionManager.NegotiationState()), + ws.hardResetCount, + ) + // emit the packet. Possibly BLOCK writing to the networkio layer. select { case ws.muxerToNetwork <- rawPacket: From 8e6e3913254c4132405a604f3984458980ea2fac Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sat, 10 Feb 2024 17:46:31 +0100 Subject: [PATCH 12/39] change state before sending hard reset packet --- cmd/minivpn/iface.go | 30 ++++ cmd/minivpn/log.go | 79 ++++++++++ cmd/minivpn/main.go | 261 ++++++++++++++++++++------------ internal/packetmuxer/service.go | 9 +- 4 files changed, 276 insertions(+), 103 deletions(-) create mode 100644 cmd/minivpn/iface.go create mode 100644 cmd/minivpn/log.go diff --git a/cmd/minivpn/iface.go b/cmd/minivpn/iface.go new file mode 100644 index 00000000..4102d938 --- /dev/null +++ b/cmd/minivpn/iface.go @@ -0,0 +1,30 @@ +package main + +import ( + "fmt" + "net" +) + +func getInterfaceByIP(ipAddr string) (*net.Interface, error) { + interfaces, err := net.Interfaces() + if err != nil { + return nil, err + } + + for _, iface := range interfaces { + addrs, err := iface.Addrs() + if err != nil { + return nil, err + } + + for _, addr := range addrs { + if ipNet, ok := addr.(*net.IPNet); ok && !ipNet.IP.IsLoopback() { + if ipNet.IP.String() == ipAddr { + return &iface, nil + } + } + } + } + + return nil, fmt.Errorf("interface with IP %s not found", ipAddr) +} diff --git a/cmd/minivpn/log.go b/cmd/minivpn/log.go new file mode 100644 index 00000000..bf4a5c22 --- /dev/null +++ b/cmd/minivpn/log.go @@ -0,0 +1,79 @@ +package main + +import ( + "fmt" + "io" + "os" + "sync" + "time" + + "github.com/apex/log" +) + +// Default handler outputting to stderr. +var Default = NewHandler(os.Stderr) + +// start time. +var start = time.Now() + +// colors. +const ( + none = 0 + red = 31 + green = 32 + yellow = 33 + blue = 34 + gray = 37 +) + +// Colors mapping. +var Colors = [...]int{ + log.DebugLevel: gray, + log.InfoLevel: blue, + log.WarnLevel: yellow, + log.ErrorLevel: red, + log.FatalLevel: red, +} + +// Strings mapping. +var Strings = [...]string{ + log.DebugLevel: "DEBUG", + log.InfoLevel: "INFO", + log.WarnLevel: "WARN", + log.ErrorLevel: "ERROR", + log.FatalLevel: "FATAL", +} + +// Handler implementation. +type Handler struct { + mu sync.Mutex + Writer io.Writer +} + +// New handler. +func NewHandler(w io.Writer) *Handler { + return &Handler{ + Writer: w, + } +} + +// HandleLog implements log.Handler. +func (h *Handler) HandleLog(e *log.Entry) error { + color := Colors[e.Level] + level := Strings[e.Level] + names := e.Fields.Names() + + h.mu.Lock() + defer h.mu.Unlock() + + ts := time.Since(start) + fmt.Fprintf(h.Writer, "\033[%dm%6s\033[0m[%10v] %-25s", color, level, ts, e.Message) + + for _, name := range names { + fmt.Fprintf(h.Writer, " \033[%dm%s\033[0m=%v", color, name, e.Fields.Get(name)) + } + + fmt.Fprintln(h.Writer) + + return nil +} diff --git a/cmd/minivpn/main.go b/cmd/minivpn/main.go index 1ecff11a..a61d56ea 100644 --- a/cmd/minivpn/main.go +++ b/cmd/minivpn/main.go @@ -2,140 +2,205 @@ package main import ( "context" + "encoding/json" + "flag" "fmt" - "io" + "net" "os" + "os/exec" "time" + "github.com/Doridian/water" "github.com/apex/log" - "github.com/pborman/getopt/v2" + "github.com/jackpal/gateway" "github.com/ooni/minivpn/extras/ping" - "github.com/ooni/minivpn/vpn" + "github.com/ooni/minivpn/internal/model" + "github.com/ooni/minivpn/internal/networkio" + "github.com/ooni/minivpn/internal/runtimex" + "github.com/ooni/minivpn/internal/tracex" + "github.com/ooni/minivpn/internal/tun" ) -var ( - startTime = time.Now() - extraTimeoutSeconds = 10 * time.Second -) +func runCmd(binaryPath string, args ...string) { + cmd := exec.Command(binaryPath, args...) + cmd.Stderr = os.Stderr + cmd.Stdout = os.Stdout + cmd.Stdin = os.Stdin + err := cmd.Run() + if nil != err { + log.WithError(err).Warn("error running /sbin/ip") + } +} -func printUsage() { - fmt.Println("valid commands: ping, proxy") - getopt.Usage() - os.Exit(0) +func runIP(args ...string) { + runCmd("/sbin/ip", args...) } -func timeoutSecondsFromCount(count int) time.Duration { - waitOnLastOne := 2 * time.Second - return time.Duration(count)*time.Second + waitOnLastOne +func runRoute(args ...string) { + runCmd("/sbin/route", args...) +} +type config struct { + configPath string + doPing bool + doTrace bool + skipRoute bool + timeout int } -// RunPinger takes an Option object, starts a Client, and runs a Pinger against -// the passed target, for a number count of packets. -func RunPinger(opt *vpn.Options, target string, count uint32) error { - c := int(count) - ctx, cancel := context.WithTimeout(context.Background(), timeoutSecondsFromCount(c)+extraTimeoutSeconds) - defer cancel() +func main() { + log.SetLevel(log.DebugLevel) + + cfg := &config{} + flag.StringVar(&cfg.configPath, "config", "", "config file to load") + flag.BoolVar(&cfg.doPing, "ping", false, "if true, do ping and exit (for testing)") + flag.BoolVar(&cfg.doTrace, "trace", false, "if true, do a trace of the handshake and exit (for testing)") + flag.BoolVar(&cfg.skipRoute, "skip-route", false, "if true, exit without setting routes (for testing)") + flag.IntVar(&cfg.timeout, "timeout", 60, "timeout in seconds (default=60)") + flag.Parse() + + if cfg.configPath == "" { + fmt.Println("[error] need config path") + os.Exit(1) + } - tunnel := vpn.NewClientFromOptions(opt) - err := tunnel.Start(ctx) - if err != nil { - return err + log.SetHandler(NewHandler(os.Stderr)) + log.SetLevel(log.DebugLevel) + + opts := []model.Option{ + model.WithConfigFile(cfg.configPath), + model.WithLogger(log.Log), } - pinger := ping.New(target, tunnel) - pinger.Count = c - pinger.Timeout = timeoutSecondsFromCount(c) - err = pinger.Run(ctx) - if err != nil { - return err + start := time.Now() + + if cfg.doTrace { + opts = append(opts, model.WithHandshakeTracer(tracex.NewTracer(start))) } - pinger.PrintStats() - return nil -} + config := model.NewConfig(opts...) -func main() { - optConfig := getopt.StringLong("config", 'c', "", "Configuration file") - optServer := getopt.StringLong("server", 's', "", "VPN Server to connect to") - optTarget := getopt.StringLong("target", 't', "8.8.8.8", "Target for ICMP Ping") - optCount := getopt.Uint32Long("count", 'n', uint32(3), "Stop after sending these many ECHO_REQUEST packets") - optVerbosity := getopt.Uint16Long("verbosity", 'v', uint16(4), "Verbosity level (1 to 5, 1 is lowest)") + // connect to the server + dialer := networkio.NewDialer(log.Log, &net.Dialer{}) + ctx := context.Background() - helpFlag := getopt.Bool('h', "Display help") + proto := config.Remote().Protocol + addr := config.Remote().AddrPort - getopt.Parse() - args := getopt.Args() + conn, err := dialer.DialContext(ctx, proto, addr) + if err != nil { + log.WithError(err).Fatal("dialer.DialContext") + } - if len(args) != 1 { - printUsage() + // The TLS will expire in 60 seconds by default, but we can pass + // a shorter timeout. + ctx, cancel := context.WithTimeout(ctx, time.Duration(cfg.timeout)*time.Second) + defer cancel() + // create a vpn tun Device + tunnel, err := tun.StartTUN(ctx, conn, config) + if err != nil { + log.WithError(err).Fatal("init error") + return + } + log.Infof("Local IP: %s\n", tunnel.LocalAddr()) + log.Infof("Gateway: %s\n", tunnel.RemoteAddr()) + + fmt.Println("initialization-sequence-completed") + fmt.Printf("elapsed: %v\n", time.Since(start)) + + if cfg.doTrace { + trace := config.Tracer().Trace() + jsonData, err := json.MarshalIndent(trace, "", " ") + runtimex.PanicOnError(err, "cannot serialize trace") + fileName := "handshake-trace.json" + os.WriteFile(fileName, jsonData, 0644) + fmt.Println("trace written to", fileName) + os.Exit(0) } - if *helpFlag || (*optServer == "" && *optConfig == "") { - printUsage() + if cfg.doPing { + pinger := ping.New("8.8.8.8", tunnel) + count := 5 + pinger.Count = count + + err = pinger.Run(context.Background()) + if err != nil { + pinger.PrintStats() + log.WithError(err).Fatal("ping error") + } + pinger.PrintStats() + os.Exit(0) } - var opts *vpn.Options - - verbosityLevel := log.InfoLevel - switch *optVerbosity { - case uint16(1): - verbosityLevel = log.FatalLevel - case uint16(2): - verbosityLevel = log.ErrorLevel - case uint16(3): - verbosityLevel = log.WarnLevel - case uint16(4): - verbosityLevel = log.InfoLevel - case uint16(5): - verbosityLevel = log.DebugLevel - default: - verbosityLevel = log.DebugLevel + if cfg.skipRoute { + os.Exit(0) } - logger := &log.Logger{Level: verbosityLevel, Handler: &logHandler{Writer: os.Stderr}} - logger.Debugf("config file: %s", *optConfig) + // create a tun interface on the OS + iface, err := water.New(water.Config{DeviceType: water.TUN}) + runtimex.PanicOnError(err, "unable to open tun interface") + + // TODO: investigate what's the maximum working MTU, additionally get it from flag. + MTU := 1420 + iface.SetMTU(MTU) + + localAddr := tunnel.LocalAddr().String() + remoteAddr := tunnel.RemoteAddr().String() + netMask := tunnel.NetMask() - opts, err := vpn.NewOptionsFromFilePath(*optConfig) + // discover local gateway IP, we need it to add a route to our remote via our network gw + defaultGatewayIP, err := gateway.DiscoverGateway() if err != nil { - fmt.Println("fatal: " + err.Error()) - os.Exit(1) + log.Warn("could not discover default gateway IP, routes might be broken") } - opts.Log = logger - - switch args[0] { - case "ping": - err = RunPinger(opts, *optTarget, *optCount) - if err != nil { - logger.Error(err.Error()) - } - case "proxy": - // not actively tested at the moment - ListenAndServeSocks(opts) - default: - printUsage() + defaultInterfaceIP, err := gateway.DiscoverInterface() + if err != nil { + log.Warn("could not discover default route interface IP, routes might be broken") + } + defaultInterface, err := getInterfaceByIP(defaultInterfaceIP.String()) + if err != nil { + log.Warn("could not get default route interface, routes might be broken") } -} - -type logHandler struct { - io.Writer -} -func (h *logHandler) HandleLog(e *log.Entry) (err error) { - var s string - if e.Level == log.DebugLevel { - s = fmt.Sprintf("%s", e.Message) - } else if e.Level == log.ErrorLevel { - s = fmt.Sprintf("[%14.6f] %s", time.Since(startTime).Seconds(), e.Message) - } else { - s = fmt.Sprintf("[%14.6f] <%s> %s", time.Since(startTime).Seconds(), e.Level, e.Message) + if defaultGatewayIP != nil && defaultInterface != nil { + log.Infof("route add %s gw %v dev %s", config.Remote().IPAddr, defaultGatewayIP, defaultInterface.Name) + runRoute("add", config.Remote().IPAddr, "gw", defaultGatewayIP.String(), defaultInterface.Name) } - if len(e.Fields) > 0 { - s += fmt.Sprintf(": %+v", e.Fields) + + // we want the network CIDR for setting up the routes + network := &net.IPNet{ + IP: net.ParseIP(localAddr).Mask(netMask), + Mask: netMask, } - s += "\n" - _, err = h.Writer.Write([]byte(s)) - return + + // configure the interface and bring it up + runIP("addr", "add", localAddr, "dev", iface.Name()) + runIP("link", "set", "dev", iface.Name(), "up") + runRoute("add", remoteAddr, "gw", localAddr) + runRoute("add", "-net", network.String(), "dev", iface.Name()) + runIP("route", "add", "default", "via", remoteAddr, "dev", iface.Name()) + + go func() { + for { + packet := make([]byte, 2000) + n, err := iface.Read(packet) + if err != nil { + log.WithError(err).Fatal("error reading from tun") + } + tunnel.Write(packet[:n]) + } + }() + go func() { + for { + packet := make([]byte, 2000) + n, err := tunnel.Read(packet) + if err != nil { + log.WithError(err).Fatal("error reading from tun") + } + iface.Write(packet[:n]) + } + }() + select {} } diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index 36b16b7b..004cb7fe 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -194,8 +194,12 @@ func (ws *workersState) moveDownWorker() { // startHardReset is invoked when we need to perform a HARD RESET. func (ws *workersState) startHardReset() error { + // increment the hard reset counter for retries ws.hardResetCount += 1 + // reset the state to become initial again. + ws.sessionManager.SetNegotiationState(session.S_PRE_START) + // emit a CONTROL_HARD_RESET_CLIENT_V2 pkt packet := ws.sessionManager.NewHardResetPacket() if err := ws.serializeAndEmit(packet); err != nil { @@ -205,11 +209,6 @@ func (ws *workersState) startHardReset() error { // resend if not received the server's reply in 2 seconds. ws.hardResetTicker.Reset(time.Second * 2) - // reset the state to become initial again. - ws.sessionManager.SetNegotiationState(session.S_PRE_START) - - // TODO: any other change to apply in this case? - return nil } From c36b7f1b8a66c2bdedb6e590252248ff5edc6747 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:06:23 +0100 Subject: [PATCH 13/39] annotate tls client hello & server hello --- pkg/tracex/trace.go | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index e3f46ffa..b10ae564 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -53,6 +53,9 @@ type event struct { // AtTime is the time for this event, relative to the start time. AtTime time.Duration + // Tags is an array of tags that can be useful to interpret this event, like the contents of the packet. + Tags []string + // LoggedPacket is an optional packet metadata. LoggedPacket optional.Value[LoggedPacket] } @@ -62,6 +65,7 @@ func newEvent(etype HandshakeEventType, st session.SessionNegotiationState, t ti EventType: etype, Stage: st, AtTime: t.Sub(t0), + Tags: make([]string, 0), LoggedPacket: optional.None[LoggedPacket](), } } @@ -72,11 +76,13 @@ func (e event) MarshalJSON() ([]byte, error) { Type string `json:"operation"` Stage string `json:"stage"` Time float64 `json:"t"` + Tags []string `json:"tags"` Packet optional.Value[LoggedPacket] `json:"packet"` }{ Type: e.EventType.String(), Stage: e.Stage.String()[2:], Time: e.AtTime.Seconds(), + Tags: e.Tags, Packet: e.LoggedPacket, } return json.Marshal(j) @@ -123,6 +129,7 @@ func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage int) { stg := session.SessionNegotiationState(stage) e := newEvent(handshakeEventPacketIn, stg, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, -1, model.DirectionIncoming) + maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } @@ -134,6 +141,7 @@ func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage int, retries int) stg := session.SessionNegotiationState(stage) e := newEvent(handshakeEventPacketOut, stg, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, retries, model.DirectionOutgoing) + maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } @@ -219,3 +227,20 @@ var dirMap = map[string]string{ "recv": "read", "send": "write", } + +// maybeAddTagsFromPacket attempts to derive meaningful tags from +// the packet payload, and adds it to the tag array in the passed event. +func maybeAddTagsFromPacket(e *event, packet *model.Packet) { + if len(packet.Payload) <= 0 { + return + } + p := packet.Payload + if p[0] == 0x16 && p[5] == 0x01 { + e.Tags = append(e.Tags, "client_hello") + return + } + if p[0] == 0x16 && p[5] == 0x02 { + e.Tags = append(e.Tags, "server_hello") + return + } +} From 5ac4cde25c67c7a45241e29a325bb98d981829a2 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:15:45 +0100 Subject: [PATCH 14/39] bug: continue if received malformed input should not return in the presence of malformed packets. we still need to properly log & trace these events, but this is a first defensive reaction to malformed input. - Related: #67 --- internal/packetmuxer/service.go | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index 004cb7fe..b1dda9e6 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -132,7 +132,8 @@ func (ws *workersState) moveUpWorker() { case rawPacket := <-ws.networkToMuxer: if err := ws.handleRawPacket(rawPacket); err != nil { // error already printed - return + // TODO: trace malformed input + continue } case <-ws.hardResetTicker.C: @@ -242,8 +243,15 @@ func (ws *workersState) handleRawPacket(rawPacket []byte) error { // before we have a working session. Under normal operations, the // connection in the client side should pick a different port, // so that data sent from previous sessions will not be delivered. - // However, it does not harm to be defensive here. - return errors.New("not ready to handle data") + // However, it does not harm to be defensive here. One such case + // is that we get injected packets intended to mess with the handshake. + // In this case we should drop and log/trace the event. + if packet.IsData() { + ws.logger.Warnf("packetmuxer: moveUpWorker: cannot handle data yet") + return errors.New("not ready to handle data") + } + ws.logger.Warnf("malformed input") + return errors.New("malformed input") } select { case ws.muxerToData <- packet: From fef4a84df6f1c22627029958de855ba6899a7344 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:18:51 +0100 Subject: [PATCH 15/39] remove todo --- internal/model/config.go | 1 - 1 file changed, 1 deletion(-) diff --git a/internal/model/config.go b/internal/model/config.go index a7736872..bb615fcb 100644 --- a/internal/model/config.go +++ b/internal/model/config.go @@ -21,7 +21,6 @@ type Config struct { // NewConfig returns a Config ready to intialize a vpn tunnel. func NewConfig(options ...Option) *Config { - // TODO(ainghazal): provide a nop-tracer. cfg := &Config{ openvpnOptions: &OpenVPNOptions{}, logger: log.Log, From 93331def827ba28d22674dd7280057e8031f5dbe Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:24:49 +0100 Subject: [PATCH 16/39] remove on handshake done from interface --- internal/model/trace.go | 3 --- pkg/tracex/trace.go | 5 ----- 2 files changed, 8 deletions(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index 40958764..673c82cf 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -22,9 +22,6 @@ type HandshakeTracer interface { // OnDroppedPacket is called whenever a packet is dropped (in/out) OnDroppedPacket(direction Direction, stage int, packet *Packet) - - // OnHandshakeDone is called when we have completed a handshake. - OnHandshakeDone(remoteAddr string) } // Direction is one of two directions on a packet. diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index b10ae564..de5463d1 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -156,10 +156,6 @@ func (t *Tracer) OnDroppedPacket(direction model.Direction, stage int, packet *m t.events = append(t.events, e) } -func (t *Tracer) OnHandshakeDone(remoteAddr string) { - panic("not implemented") // TODO: Implement - when received IP from server. -} - // Trace returns a structured log containing a copy of the array of [model.HandshakeEvent]. func (t *Tracer) Trace() []*event { t.mu.Lock() @@ -199,7 +195,6 @@ type LoggedPacket struct { PayloadSize int // Retries keeps track of packet retransmission (only for outgoing packets). - // TODO: use optional here. Retries optional.Value[int] } From 3233f5a070c7afdd26bb0d615782cf835d9cca98 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:32:42 +0100 Subject: [PATCH 17/39] revert binary to main --- cmd/minivpn/main.go | 261 +++++++++++++++++--------------------------- 1 file changed, 98 insertions(+), 163 deletions(-) diff --git a/cmd/minivpn/main.go b/cmd/minivpn/main.go index a61d56ea..1ecff11a 100644 --- a/cmd/minivpn/main.go +++ b/cmd/minivpn/main.go @@ -2,205 +2,140 @@ package main import ( "context" - "encoding/json" - "flag" "fmt" - "net" + "io" "os" - "os/exec" "time" - "github.com/Doridian/water" "github.com/apex/log" - "github.com/jackpal/gateway" + "github.com/pborman/getopt/v2" "github.com/ooni/minivpn/extras/ping" - "github.com/ooni/minivpn/internal/model" - "github.com/ooni/minivpn/internal/networkio" - "github.com/ooni/minivpn/internal/runtimex" - "github.com/ooni/minivpn/internal/tracex" - "github.com/ooni/minivpn/internal/tun" + "github.com/ooni/minivpn/vpn" ) -func runCmd(binaryPath string, args ...string) { - cmd := exec.Command(binaryPath, args...) - cmd.Stderr = os.Stderr - cmd.Stdout = os.Stdout - cmd.Stdin = os.Stdin - err := cmd.Run() - if nil != err { - log.WithError(err).Warn("error running /sbin/ip") - } -} +var ( + startTime = time.Now() + extraTimeoutSeconds = 10 * time.Second +) -func runIP(args ...string) { - runCmd("/sbin/ip", args...) +func printUsage() { + fmt.Println("valid commands: ping, proxy") + getopt.Usage() + os.Exit(0) } -func runRoute(args ...string) { - runCmd("/sbin/route", args...) -} +func timeoutSecondsFromCount(count int) time.Duration { + waitOnLastOne := 2 * time.Second + return time.Duration(count)*time.Second + waitOnLastOne -type config struct { - configPath string - doPing bool - doTrace bool - skipRoute bool - timeout int } -func main() { - log.SetLevel(log.DebugLevel) - - cfg := &config{} - flag.StringVar(&cfg.configPath, "config", "", "config file to load") - flag.BoolVar(&cfg.doPing, "ping", false, "if true, do ping and exit (for testing)") - flag.BoolVar(&cfg.doTrace, "trace", false, "if true, do a trace of the handshake and exit (for testing)") - flag.BoolVar(&cfg.skipRoute, "skip-route", false, "if true, exit without setting routes (for testing)") - flag.IntVar(&cfg.timeout, "timeout", 60, "timeout in seconds (default=60)") - flag.Parse() - - if cfg.configPath == "" { - fmt.Println("[error] need config path") - os.Exit(1) - } - - log.SetHandler(NewHandler(os.Stderr)) - log.SetLevel(log.DebugLevel) +// RunPinger takes an Option object, starts a Client, and runs a Pinger against +// the passed target, for a number count of packets. +func RunPinger(opt *vpn.Options, target string, count uint32) error { + c := int(count) + ctx, cancel := context.WithTimeout(context.Background(), timeoutSecondsFromCount(c)+extraTimeoutSeconds) + defer cancel() - opts := []model.Option{ - model.WithConfigFile(cfg.configPath), - model.WithLogger(log.Log), + tunnel := vpn.NewClientFromOptions(opt) + err := tunnel.Start(ctx) + if err != nil { + return err } - start := time.Now() - - if cfg.doTrace { - opts = append(opts, model.WithHandshakeTracer(tracex.NewTracer(start))) + pinger := ping.New(target, tunnel) + pinger.Count = c + pinger.Timeout = timeoutSecondsFromCount(c) + err = pinger.Run(ctx) + if err != nil { + return err } + pinger.PrintStats() - config := model.NewConfig(opts...) + return nil +} - // connect to the server - dialer := networkio.NewDialer(log.Log, &net.Dialer{}) - ctx := context.Background() +func main() { + optConfig := getopt.StringLong("config", 'c', "", "Configuration file") + optServer := getopt.StringLong("server", 's', "", "VPN Server to connect to") + optTarget := getopt.StringLong("target", 't', "8.8.8.8", "Target for ICMP Ping") + optCount := getopt.Uint32Long("count", 'n', uint32(3), "Stop after sending these many ECHO_REQUEST packets") + optVerbosity := getopt.Uint16Long("verbosity", 'v', uint16(4), "Verbosity level (1 to 5, 1 is lowest)") - proto := config.Remote().Protocol - addr := config.Remote().AddrPort + helpFlag := getopt.Bool('h', "Display help") - conn, err := dialer.DialContext(ctx, proto, addr) - if err != nil { - log.WithError(err).Fatal("dialer.DialContext") - } + getopt.Parse() + args := getopt.Args() - // The TLS will expire in 60 seconds by default, but we can pass - // a shorter timeout. - ctx, cancel := context.WithTimeout(ctx, time.Duration(cfg.timeout)*time.Second) - defer cancel() + if len(args) != 1 { + printUsage() - // create a vpn tun Device - tunnel, err := tun.StartTUN(ctx, conn, config) - if err != nil { - log.WithError(err).Fatal("init error") - return - } - log.Infof("Local IP: %s\n", tunnel.LocalAddr()) - log.Infof("Gateway: %s\n", tunnel.RemoteAddr()) - - fmt.Println("initialization-sequence-completed") - fmt.Printf("elapsed: %v\n", time.Since(start)) - - if cfg.doTrace { - trace := config.Tracer().Trace() - jsonData, err := json.MarshalIndent(trace, "", " ") - runtimex.PanicOnError(err, "cannot serialize trace") - fileName := "handshake-trace.json" - os.WriteFile(fileName, jsonData, 0644) - fmt.Println("trace written to", fileName) - os.Exit(0) } - if cfg.doPing { - pinger := ping.New("8.8.8.8", tunnel) - count := 5 - pinger.Count = count - - err = pinger.Run(context.Background()) - if err != nil { - pinger.PrintStats() - log.WithError(err).Fatal("ping error") - } - pinger.PrintStats() - os.Exit(0) + if *helpFlag || (*optServer == "" && *optConfig == "") { + printUsage() } - if cfg.skipRoute { - os.Exit(0) + var opts *vpn.Options + + verbosityLevel := log.InfoLevel + switch *optVerbosity { + case uint16(1): + verbosityLevel = log.FatalLevel + case uint16(2): + verbosityLevel = log.ErrorLevel + case uint16(3): + verbosityLevel = log.WarnLevel + case uint16(4): + verbosityLevel = log.InfoLevel + case uint16(5): + verbosityLevel = log.DebugLevel + default: + verbosityLevel = log.DebugLevel } - // create a tun interface on the OS - iface, err := water.New(water.Config{DeviceType: water.TUN}) - runtimex.PanicOnError(err, "unable to open tun interface") - - // TODO: investigate what's the maximum working MTU, additionally get it from flag. - MTU := 1420 - iface.SetMTU(MTU) - - localAddr := tunnel.LocalAddr().String() - remoteAddr := tunnel.RemoteAddr().String() - netMask := tunnel.NetMask() + logger := &log.Logger{Level: verbosityLevel, Handler: &logHandler{Writer: os.Stderr}} + logger.Debugf("config file: %s", *optConfig) - // discover local gateway IP, we need it to add a route to our remote via our network gw - defaultGatewayIP, err := gateway.DiscoverGateway() + opts, err := vpn.NewOptionsFromFilePath(*optConfig) if err != nil { - log.Warn("could not discover default gateway IP, routes might be broken") - } - defaultInterfaceIP, err := gateway.DiscoverInterface() - if err != nil { - log.Warn("could not discover default route interface IP, routes might be broken") - } - defaultInterface, err := getInterfaceByIP(defaultInterfaceIP.String()) - if err != nil { - log.Warn("could not get default route interface, routes might be broken") + fmt.Println("fatal: " + err.Error()) + os.Exit(1) } + opts.Log = logger - if defaultGatewayIP != nil && defaultInterface != nil { - log.Infof("route add %s gw %v dev %s", config.Remote().IPAddr, defaultGatewayIP, defaultInterface.Name) - runRoute("add", config.Remote().IPAddr, "gw", defaultGatewayIP.String(), defaultInterface.Name) + switch args[0] { + case "ping": + err = RunPinger(opts, *optTarget, *optCount) + if err != nil { + logger.Error(err.Error()) + } + case "proxy": + // not actively tested at the moment + ListenAndServeSocks(opts) + default: + printUsage() } +} - // we want the network CIDR for setting up the routes - network := &net.IPNet{ - IP: net.ParseIP(localAddr).Mask(netMask), - Mask: netMask, - } +type logHandler struct { + io.Writer +} - // configure the interface and bring it up - runIP("addr", "add", localAddr, "dev", iface.Name()) - runIP("link", "set", "dev", iface.Name(), "up") - runRoute("add", remoteAddr, "gw", localAddr) - runRoute("add", "-net", network.String(), "dev", iface.Name()) - runIP("route", "add", "default", "via", remoteAddr, "dev", iface.Name()) - - go func() { - for { - packet := make([]byte, 2000) - n, err := iface.Read(packet) - if err != nil { - log.WithError(err).Fatal("error reading from tun") - } - tunnel.Write(packet[:n]) - } - }() - go func() { - for { - packet := make([]byte, 2000) - n, err := tunnel.Read(packet) - if err != nil { - log.WithError(err).Fatal("error reading from tun") - } - iface.Write(packet[:n]) - } - }() - select {} +func (h *logHandler) HandleLog(e *log.Entry) (err error) { + var s string + if e.Level == log.DebugLevel { + s = fmt.Sprintf("%s", e.Message) + } else if e.Level == log.ErrorLevel { + s = fmt.Sprintf("[%14.6f] %s", time.Since(startTime).Seconds(), e.Message) + } else { + s = fmt.Sprintf("[%14.6f] <%s> %s", time.Since(startTime).Seconds(), e.Level, e.Message) + } + if len(e.Fields) > 0 { + s += fmt.Sprintf(": %+v", e.Fields) + } + s += "\n" + _, err = h.Writer.Write([]byte(s)) + return } From 9e245c9367ce608c7b612436879d71d8e4611459 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:33:26 +0100 Subject: [PATCH 18/39] remove binary from this branch --- cmd/minivpn/iface.go | 30 ----------------- cmd/minivpn/log.go | 79 -------------------------------------------- 2 files changed, 109 deletions(-) delete mode 100644 cmd/minivpn/iface.go delete mode 100644 cmd/minivpn/log.go diff --git a/cmd/minivpn/iface.go b/cmd/minivpn/iface.go deleted file mode 100644 index 4102d938..00000000 --- a/cmd/minivpn/iface.go +++ /dev/null @@ -1,30 +0,0 @@ -package main - -import ( - "fmt" - "net" -) - -func getInterfaceByIP(ipAddr string) (*net.Interface, error) { - interfaces, err := net.Interfaces() - if err != nil { - return nil, err - } - - for _, iface := range interfaces { - addrs, err := iface.Addrs() - if err != nil { - return nil, err - } - - for _, addr := range addrs { - if ipNet, ok := addr.(*net.IPNet); ok && !ipNet.IP.IsLoopback() { - if ipNet.IP.String() == ipAddr { - return &iface, nil - } - } - } - } - - return nil, fmt.Errorf("interface with IP %s not found", ipAddr) -} diff --git a/cmd/minivpn/log.go b/cmd/minivpn/log.go deleted file mode 100644 index bf4a5c22..00000000 --- a/cmd/minivpn/log.go +++ /dev/null @@ -1,79 +0,0 @@ -package main - -import ( - "fmt" - "io" - "os" - "sync" - "time" - - "github.com/apex/log" -) - -// Default handler outputting to stderr. -var Default = NewHandler(os.Stderr) - -// start time. -var start = time.Now() - -// colors. -const ( - none = 0 - red = 31 - green = 32 - yellow = 33 - blue = 34 - gray = 37 -) - -// Colors mapping. -var Colors = [...]int{ - log.DebugLevel: gray, - log.InfoLevel: blue, - log.WarnLevel: yellow, - log.ErrorLevel: red, - log.FatalLevel: red, -} - -// Strings mapping. -var Strings = [...]string{ - log.DebugLevel: "DEBUG", - log.InfoLevel: "INFO", - log.WarnLevel: "WARN", - log.ErrorLevel: "ERROR", - log.FatalLevel: "FATAL", -} - -// Handler implementation. -type Handler struct { - mu sync.Mutex - Writer io.Writer -} - -// New handler. -func NewHandler(w io.Writer) *Handler { - return &Handler{ - Writer: w, - } -} - -// HandleLog implements log.Handler. -func (h *Handler) HandleLog(e *log.Entry) error { - color := Colors[e.Level] - level := Strings[e.Level] - names := e.Fields.Names() - - h.mu.Lock() - defer h.mu.Unlock() - - ts := time.Since(start) - fmt.Fprintf(h.Writer, "\033[%dm%6s\033[0m[%10v] %-25s", color, level, ts, e.Message) - - for _, name := range names { - fmt.Fprintf(h.Writer, " \033[%dm%s\033[0m=%v", color, name, e.Fields.Get(name)) - } - - fmt.Fprintln(h.Writer) - - return nil -} From 39a9c9a362600e156f6320a89e7e966cfd8fab81 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:37:15 +0100 Subject: [PATCH 19/39] revert changes to pinger --- extras/ping/ping.go | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/extras/ping/ping.go b/extras/ping/ping.go index 455e8dc1..652693fe 100644 --- a/extras/ping/ping.go +++ b/extras/ping/ping.go @@ -396,7 +396,6 @@ func (p *Pinger) runLoop(recvCh <-chan *packet) error { } if p.Count > 0 && p.PacketsRecv >= p.Count { - p.done <- true return nil } } @@ -484,16 +483,13 @@ func (p *Pinger) recvICMP(recv chan<- *packet) error { case <-p.done: return nil default: - if p.PacketsRecv >= p.Count { - return nil - } buf := make([]byte, 512) if err := p.conn.SetReadDeadline(time.Now().Add(delay)); err != nil { return fmt.Errorf("%w: %s", errCannotSetReadDeadline, err) } n, err := p.conn.Read(buf) if err != nil { - var netErr net.Error + var netErr *net.OpError if errors.As(err, &netErr) && netErr.Timeout() { // Read timeout delay = expBackoff.Get() From 882725bf65973d990ab2d418467a6ee2863ef351 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:42:25 +0100 Subject: [PATCH 20/39] revert integration tests, they are on their own pr --- tests/integration/extract.sh | 55 +++++++++ tests/integration/openvpn_test.go | 187 ++++++++++++++++++++++++++++++ 2 files changed, 242 insertions(+) create mode 100755 tests/integration/extract.sh create mode 100644 tests/integration/openvpn_test.go diff --git a/tests/integration/extract.sh b/tests/integration/extract.sh new file mode 100755 index 00000000..9c1ec31d --- /dev/null +++ b/tests/integration/extract.sh @@ -0,0 +1,55 @@ +#!/bin/sh +# (c) Ain Ghazal 2022 +# this file converts an inline openvpn config file into +# a standalone config plus separate files for the ca.crt, +# cert.pem and key.pem. + +FILE=$1 +tail=0 + +# first lets extract the inline blocks +# ca block +tag=ca +f=ca.crt +sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f +n=$(wc -l $f | cut -f 1 -d ' ') +tail=$(($tail+n)) +cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null + +# key block +tag=key +f=key.pem +sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f +n=$(wc -l $f | cut -f 1 -d ' ') +tail=$(($tail+n)) +cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null + +# cert block +tag=cert +f=cert.pem +sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f +n=$(wc -l $f | cut -f 1 -d ' ') +tail=$(($tail+n)) +cat $f | tail -n $(($n-1)) | head -n $(($n-2)) | tee $f >/dev/null + +# tls-auth (ignored) +tag=tls-auth +f=ta.pem +sed -n "/<$tag>/,/<\/$tag>/p" $FILE > $f +n=$(wc -l $f | cut -f 1 -d ' ') +tail=$(($tail+n)) +cat $f | tail -n $(($n-4)) | head -n $(($n-5)) | tee $f >/dev/null + +all=$(wc -l $FILE | cut -f -1 -d ' ') +cp $FILE config.bk + +echo "------------------------" +echo "Config file:" +echo "------------------------" +head -n $(($all-$tail)) $FILE | tee config +echo "------------------------" + +# now enable the paths for ca, cert and key +sed -i "s/;ca ca.crt/ca ca.crt/g" config +sed -i "s/;cert cert.pem/cert cert.pem/g" config +sed -i "s/;key key.pem/key key.pem/g" config diff --git a/tests/integration/openvpn_test.go b/tests/integration/openvpn_test.go new file mode 100644 index 00000000..07060139 --- /dev/null +++ b/tests/integration/openvpn_test.go @@ -0,0 +1,187 @@ +//build: +integration +package main + +import ( + "bufio" + "bytes" + "context" + "fmt" + "io/ioutil" + "log" + "net/http" + "os" + "os/exec" + "path/filepath" + "testing" + "time" + + "github.com/ory/dockertest/v3" + dc "github.com/ory/dockertest/v3/docker" + + "github.com/ooni/minivpn/extras/ping" + "github.com/ooni/minivpn/vpn" +) + +const ( + parseConfig = "extract.sh" + dockerImage = "ainghazal/openvpn" + dockerTag = "latest" +) + +var ( + target = "172.17.0.1" + count = 3 +) + +func copyFile(src, dst string) error { + input, err := ioutil.ReadFile(src) + if err != nil { + fmt.Println(err) + return nil + } + + dstFile := filepath.Join(dst, src) + err = ioutil.WriteFile(dstFile, input, 0744) + if err != nil { + fmt.Println("Error creating", dstFile) + return err + } + return nil +} + +func launchDocker(cipher, auth string) ([]byte, *dockertest.Pool, *dockertest.Resource, error) { + pool, err := dockertest.NewPool("") + if err != nil { + log.Fatalf("Could not connect to docker: %s", err) + } + + options := &dockertest.RunOptions{ + Repository: dockerImage, + Tag: dockerTag, + PortBindings: map[dc.Port][]dc.PortBinding{ + "1194/udp": {{HostPort: "1194"}}, + "8080/tcp": {{HostPort: "8080"}}, + }, + Env: []string{"OPENVPN_CIPHER=" + cipher, "OPENVPN_AUTH=" + auth}, + CapAdd: []string{"NET_ADMIN"}, + } + resource, err := pool.RunWithOptions(options) + if err != nil { + log.Fatalf("Could not start resource: %s", err) + } + // exponential backoff-retry, because the application in the container might not be ready to accept connections yet + // the minio client does not do service discovery for you (i.e. it does not check if connection can be established), so we have to use the health check + var config []byte + if err := pool.Retry(func() error { + url := fmt.Sprintf("http://localhost:8080/") + resp, err := http.Get(url) + if err != nil { + return err + } + if resp.StatusCode != http.StatusOK { + return fmt.Errorf("status code not OK") + } + config, err = ioutil.ReadAll(resp.Body) + if err != nil { + panic(err) + } + fmt.Println("Got OpenVPN client config") + return nil + }); err != nil { + log.Fatalf("Could not connect to docker: %s", err) + } + return config, pool, resource, nil +} + +func stopContainer(p *dockertest.Pool, res *dockertest.Resource) { + fmt.Println("Stopping container") + if err := p.Purge(res); err != nil { + log.Printf("Could not purge resource: %s\n", err) + } +} + +func TestClientAES256GCM(t *testing.T) { + if testing.Short() { + t.Skip("skipping test in short mode.") + } + tmp := t.TempDir() + + copyFile(parseConfig, tmp) + os.Chdir(tmp) + err := os.Chmod(parseConfig, 0700) + if err != nil { + log.Fatal(err) + } + + config, pool, resource, err := launchDocker("AES-256-GCM", "SHA256") + + if err != nil { + log.Fatal(err) + } + // when all test done, time to kill and remove the container + defer stopContainer(pool, resource) + + cfgFile, err := ioutil.TempFile(tmp, "minivpn-e2e-") + defer cfgFile.Close() + if err != nil { + log.Fatal("Cannot create temporary file", err) + } + fmt.Println("Config written to: " + cfgFile.Name()) + + if _, err = cfgFile.Write(config); err != nil { + log.Fatal("Failed to write config to temporary file", err) + } + + // execute the extract.sh shell script, to process key blocks piecewise + cmd := exec.Command("./"+parseConfig, cfgFile.Name()) + cmd.Dir = tmp + var out bytes.Buffer + cmd.Stdout = &out + cmd.Run() + + if err != nil { + log.Fatal(err) + } + + c, err := readLines("config") + fmt.Println("Remote:", c[len(c)-1]) + // can assert that this is a remote line + + // actual test begins + opt, err := vpn.NewOptionsFromFilePath(filepath.Join(tmp, "config")) + if err != nil { + log.Fatalf("Could not parse file: %s", err) + } + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + defer cancel() + + tunnel := vpn.NewClientFromOptions(opt) + tunnel.Start(ctx) + pinger := ping.New(target, tunnel) + pinger.Count = count + err = pinger.Run(ctx) + defer pinger.Stop() + if err != nil { + log.Fatalf("VPN Error: %s", err) + } + if pinger.PacketLoss() != 0 { + log.Fatalf("packet loss is not zero") + } + // let's assert something wise about the pings + // can we parse the logs? get initialization etc +} + +func readLines(f string) ([]string, error) { + var ll []string + rf, err := os.Open(f) + defer rf.Close() + if err != nil { + return ll, err + } + fs := bufio.NewScanner(rf) + fs.Split(bufio.ScanLines) + for fs.Scan() { + ll = append(ll, fs.Text()) + } + return ll, nil +} From 866cdb41ab63b19666c9b54542273957520c5973 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:44:04 +0100 Subject: [PATCH 21/39] delete main.go --- tests/integration/main.go | 167 -------------------------------------- 1 file changed, 167 deletions(-) delete mode 100644 tests/integration/main.go diff --git a/tests/integration/main.go b/tests/integration/main.go deleted file mode 100644 index 6b144ba0..00000000 --- a/tests/integration/main.go +++ /dev/null @@ -1,167 +0,0 @@ -package main - -import ( - "bufio" - "context" - "fmt" - "io" - "net" - "net/http" - "os" - "path/filepath" - "testing" - - "github.com/apex/log" - "github.com/ory/dockertest/v3" - dc "github.com/ory/dockertest/v3/docker" - - "github.com/ooni/minivpn/extras/ping" - "github.com/ooni/minivpn/internal/model" - "github.com/ooni/minivpn/internal/networkio" - "github.com/ooni/minivpn/internal/tun" -) - -const ( - dockerImage = "ainghazal/openvpn" - dockerTag = "latest" -) - -var ( - target = "172.17.0.1" - count = 3 -) - -func copyFile(src, dst string) error { - input, err := os.ReadFile(src) - if err != nil { - fmt.Println(err) - return nil - } - - dstFile := filepath.Join(dst, src) - err = os.WriteFile(dstFile, input, 0744) - if err != nil { - fmt.Println("Error creating", dstFile) - return err - } - return nil -} - -func launchDocker(cipher, auth string) ([]byte, *dockertest.Pool, *dockertest.Resource, error) { - pool, err := dockertest.NewPool("") - if err != nil { - log.Fatalf("Could not connect to docker: %s", err) - } - - options := &dockertest.RunOptions{ - Repository: dockerImage, - Tag: dockerTag, - PortBindings: map[dc.Port][]dc.PortBinding{ - "1194/udp": {{HostPort: "1194"}}, - "8080/tcp": {{HostPort: "8080"}}, - }, - Env: []string{"OPENVPN_CIPHER=" + cipher, "OPENVPN_AUTH=" + auth}, - CapAdd: []string{"NET_ADMIN"}, - } - resource, err := pool.RunWithOptions(options) - if err != nil { - log.Fatalf("Could not start resource: %s", err) - } - // exponential backoff-retry, because the application in the container might not be ready to accept connections yet - // the minio client does not do service discovery for you (i.e. it does not check if connection can be established), so we have to use the health check - var config []byte - if err := pool.Retry(func() error { - url := "http://localhost:8080/" - resp, err := http.Get(url) - if err != nil { - return err - } - if resp.StatusCode != http.StatusOK { - return fmt.Errorf("status code not OK") - } - config, err = io.ReadAll(resp.Body) - if err != nil { - panic(err) - } - fmt.Println("Got OpenVPN client config") - return nil - }); err != nil { - log.Fatalf("Could not connect to docker: %s", err) - } - return config, pool, resource, nil -} - -func stopContainer(p *dockertest.Pool, res *dockertest.Resource) { - fmt.Println("[!] Stopping container") - if err := p.Purge(res); err != nil { - log.Warnf("Could not purge resource: %s\n", err) - } -} - -func TestClientAES256GCM(t *testing.T) { - if testing.Short() { - t.Skip("skipping test in short mode.") - } - tmp := t.TempDir() - - fmt.Println("launching docker") - config, pool, resource, err := launchDocker("AES-256-GCM", "SHA256") - if err != nil { - t.Errorf("cannot start docker: %v", err) - } - // when all test done, time to kill and remove the container - defer stopContainer(pool, resource) - - cfgFile, err := os.CreateTemp(tmp, "minivpn-e2e-") - if err != nil { - t.Errorf("Cannot create temporary file: %v", err) - } - defer cfgFile.Close() - fmt.Println("Config written to: " + cfgFile.Name()) - - if _, err = cfgFile.Write(config); err != nil { - t.Errorf("Failed to write config to temporary file: %v", err) - } - - // actual test begins - vpnConfig := model.NewConfig(model.WithConfigFile(cfgFile.Name())) - - dialer := networkio.NewDialer(log.Log, &net.Dialer{}) - conn, err := dialer.DialContext(context.TODO(), vpnConfig.Remote().Protocol, vpnConfig.Remote().AddrPort) - if err != nil { - t.Errorf("dial error: %v", err) - } - - tunnel, err := tun.StartTUN(context.TODO(), conn, vpnConfig) - if err != nil { - t.Errorf("cannot start tunnel: %v", err) - } - - pinger := ping.New(target, tunnel) - pinger.Count = count - err = pinger.Run(context.Background()) - defer pinger.Stop() - if err != nil { - log.Fatalf("VPN Error: %s", err) - } - if pinger.PacketLoss() != 0 { - log.Fatalf("packet loss is not zero") - } - // let's assert something wise about the pings - // can we parse the logs? get initialization etc -} - -func readLines(f string) ([]string, error) { - var ll []string - rf, err := os.Open(f) - if err != nil { - return ll, err - } - defer rf.Close() - fs := bufio.NewScanner(rf) - fs.Split(bufio.ScanLines) - for fs.Scan() { - ll = append(ll, fs.Text()) - } - return ll, nil -} From 90e333a6f46f9aa172598220478eed7c76943177 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 20:55:09 +0100 Subject: [PATCH 22/39] document public methods --- internal/tun/tun.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/internal/tun/tun.go b/internal/tun/tun.go index 8b7878db..5e6c9dc6 100644 --- a/internal/tun/tun.go +++ b/internal/tun/tun.go @@ -127,6 +127,8 @@ func (t *TUN) whenDone(fn func()) { t.whenDoneFn = fn } +// Close is an idempotent method that closes the underlying connection (owned by us) and +// potentially executes any registed callback. func (t *TUN) Close() error { t.closeOnce.Do(func() { close(t.hangup) @@ -138,6 +140,7 @@ func (t *TUN) Close() error { return nil } +// Read implements net.Conn func (t *TUN) Read(data []byte) (int, error) { for { count, _ := t.readBuffer.Read(data) @@ -159,6 +162,7 @@ func (t *TUN) Read(data []byte) (int, error) { } } +// Write implements net.Conn func (t *TUN) Write(data []byte) (int, error) { if isClosedChan(t.writeDeadline.wait()) { return 0, os.ErrDeadlineExceeded @@ -173,27 +177,32 @@ func (t *TUN) Write(data []byte) (int, error) { } } +// LocalAddr implements net.Conn func (t *TUN) LocalAddr() net.Addr { ip := t.session.TunnelInfo().IP return &tunBioAddr{ip, t.network} } +// RemoteAddr implements net.Conn func (t *TUN) RemoteAddr() net.Addr { gw := t.session.TunnelInfo().GW return &tunBioAddr{gw, t.network} } +// SetDeadline implements net.Conn func (t *TUN) SetDeadline(tm time.Time) error { t.readDeadline.set(tm) t.writeDeadline.set(tm) return nil } +// SetReadDeadline implements net.Conn func (t *TUN) SetReadDeadline(tm time.Time) error { t.readDeadline.set(tm) return nil } +// SetWriteDeadline implements net.Conn func (t *TUN) SetWriteDeadline(tm time.Time) error { t.writeDeadline.set(tm) return nil @@ -218,6 +227,7 @@ func (t *tunBioAddr) String() string { return t.addr } +// NetMask returns the configured net mask for the TUN interface. func (t *TUN) NetMask() net.IPMask { return net.IPMask(net.ParseIP(t.session.TunnelInfo().NetMask)) } From a3dba3430cb4ec65db12eef2186387815ded7100 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Sun, 11 Feb 2024 21:08:46 +0100 Subject: [PATCH 23/39] linter --- internal/packetmuxer/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index b1dda9e6..b1f32b7b 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -196,7 +196,7 @@ func (ws *workersState) moveDownWorker() { // startHardReset is invoked when we need to perform a HARD RESET. func (ws *workersState) startHardReset() error { // increment the hard reset counter for retries - ws.hardResetCount += 1 + ws.hardResetCount++ // reset the state to become initial again. ws.sessionManager.SetNegotiationState(session.S_PRE_START) From b37696ba4c9b5cca4dc8db322a3c4ff0d8f2176b Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 11:23:45 +0100 Subject: [PATCH 24/39] Update internal/model/config.go Co-authored-by: Simone Basso --- internal/model/config.go | 1 - 1 file changed, 1 deletion(-) diff --git a/internal/model/config.go b/internal/model/config.go index bb615fcb..39f91b10 100644 --- a/internal/model/config.go +++ b/internal/model/config.go @@ -43,7 +43,6 @@ func WithConfigFile(configPath string) Option { runtimex.PanicIfFalse(openvpnOpts.HasAuthInfo(), "missing auth info") config.openvpnOptions = openvpnOpts } - } // WithLogger configures the passed [Logger]. From d7a931bbbef46bfeb9fc3843d449de65e8d5af15 Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 11:23:58 +0100 Subject: [PATCH 25/39] Update internal/model/config.go Co-authored-by: Simone Basso --- internal/model/config.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/model/config.go b/internal/model/config.go index 39f91b10..b31cd674 100644 --- a/internal/model/config.go +++ b/internal/model/config.go @@ -83,7 +83,7 @@ func (c *Config) Tracer() HandshakeTracer { return c.tracer } -// Remote has info about the OpenVPNRemote. +// Remote has info about the OpenVPN remote. type Remote struct { IPAddr string AddrPort string From a149648ebb57e159f38e68ccd5c385150f6154fd Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 11:25:43 +0100 Subject: [PATCH 26/39] Update internal/model/trace.go Co-authored-by: Simone Basso --- internal/model/trace.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index 673c82cf..fad30e58 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -29,7 +29,7 @@ type Direction int const ( // DirectionIncoming marks received packets. - DirectionIncoming = iota + DirectionIncoming = Direction(iota) // DirectionOutgoing marks packets to be sent. DirectionOutgoing From dd3d3e8caf44a8eabe0e44fd4623aeb3117846b5 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:10:41 +0100 Subject: [PATCH 27/39] document remote fields --- internal/model/config.go | 23 ++++++++++++++--------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/internal/model/config.go b/internal/model/config.go index b31cd674..d050e388 100644 --- a/internal/model/config.go +++ b/internal/model/config.go @@ -64,28 +64,33 @@ func (c *Config) Logger() Logger { return c.logger } +// Tracer returns the handshake tracer. +func (c *Config) Tracer() HandshakeTracer { + return c.tracer +} + // OpenVPNOptions returns the configured openvpn options. func (c *Config) OpenVPNOptions() *OpenVPNOptions { return c.openvpnOptions } -// Remote returns the openvpn remote. +// Remote returns the OpenVPN remote. func (c *Config) Remote() *Remote { return &Remote{ IPAddr: c.openvpnOptions.Remote, - AddrPort: net.JoinHostPort(c.openvpnOptions.Remote, c.openvpnOptions.Port), + Endpoint: net.JoinHostPort(c.openvpnOptions.Remote, c.openvpnOptions.Port), Protocol: c.openvpnOptions.Proto.String(), } } -// Tracer returns the handshake tracer. -func (c *Config) Tracer() HandshakeTracer { - return c.tracer -} - // Remote has info about the OpenVPN remote. type Remote struct { - IPAddr string - AddrPort string + // IPAddr is the IP Address for the remote. + IPAddr string + + // Endpoint is in the form ip:port. + Endpoint string + + // Protocol is either "tcp" or "udp" Protocol string } From c05ba964686844a1e73d63e0535c43eee1fd6b20 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:18:47 +0100 Subject: [PATCH 28/39] fix direction serialization --- internal/model/trace.go | 6 +++--- pkg/tracex/trace.go | 7 +------ 2 files changed, 4 insertions(+), 9 deletions(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index fad30e58..39e8c46e 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -41,9 +41,9 @@ var _ fmt.Stringer = Direction(0) func (d Direction) String() string { switch d { case DirectionIncoming: - return "recv" - case 1: - return "send" + return "read" + case DirectionOutgoing: + return "write" default: return "undefined" } diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index de5463d1..73d36209 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -208,7 +208,7 @@ func (lp LoggedPacket) MarshalJSON() ([]byte, error) { PayloadSize int `json:"payload_size"` Retries optional.Value[int] `json:"send_attempts"` }{ - Direction: dirMap[lp.Direction.String()], + Direction: lp.Direction.String(), Opcode: lp.Opcode.String(), ID: lp.ID, ACKs: lp.ACKs, @@ -218,11 +218,6 @@ func (lp LoggedPacket) MarshalJSON() ([]byte, error) { return json.Marshal(j) } -var dirMap = map[string]string{ - "recv": "read", - "send": "write", -} - // maybeAddTagsFromPacket attempts to derive meaningful tags from // the packet payload, and adds it to the tag array in the passed event. func maybeAddTagsFromPacket(e *event, packet *model.Packet) { From 514adf25eee86a45be488f1d7c85f886f9f0a16f Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:29:59 +0100 Subject: [PATCH 29/39] remove marshaling, cast fields into strings --- pkg/tracex/trace.go | 85 +++++++++++---------------------------------- 1 file changed, 21 insertions(+), 64 deletions(-) diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index 73d36209..97140a82 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -3,7 +3,6 @@ package tracex import ( - "encoding/json" "fmt" "sync" "time" @@ -45,49 +44,31 @@ func (e HandshakeEventType) String() string { // event is one handshake event collected by this [model.HandshakeTracer]. type event struct { // EventType is the type for this event. - EventType HandshakeEventType + EventType string `json:"operation"` // Stage is the stage of the handshake negotiation we're in. - Stage session.SessionNegotiationState + Stage string `json:"stage"` // AtTime is the time for this event, relative to the start time. - AtTime time.Duration + AtTime float64 `json:"t"` // Tags is an array of tags that can be useful to interpret this event, like the contents of the packet. - Tags []string + Tags []string `json:"tags"` // LoggedPacket is an optional packet metadata. - LoggedPacket optional.Value[LoggedPacket] + LoggedPacket optional.Value[LoggedPacket] `json:"packet"` } func newEvent(etype HandshakeEventType, st session.SessionNegotiationState, t time.Time, t0 time.Time) *event { return &event{ - EventType: etype, - Stage: st, - AtTime: t.Sub(t0), + EventType: etype.String(), + Stage: st.String()[2:], + AtTime: t.Sub(t0).Seconds(), Tags: make([]string, 0), LoggedPacket: optional.None[LoggedPacket](), } } -// MarshalJSON implements json.Marshaler -func (e event) MarshalJSON() ([]byte, error) { - j := struct { - Type string `json:"operation"` - Stage string `json:"stage"` - Time float64 `json:"t"` - Tags []string `json:"tags"` - Packet optional.Value[LoggedPacket] `json:"packet"` - }{ - Type: e.EventType.String(), - Stage: e.Stage.String()[2:], - Time: e.AtTime.Seconds(), - Tags: e.Tags, - Packet: e.LoggedPacket, - } - return json.Marshal(j) -} - // Tracer implements [model.HandshakeTracer]. type Tracer struct { // events is the array of handshake events. @@ -128,7 +109,7 @@ func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage int) { stg := session.SessionNegotiationState(stage) e := newEvent(handshakeEventPacketIn, stg, t.TimeNow(), t.zeroTime) - e.LoggedPacket = logPacket(packet, -1, model.DirectionIncoming) + e.LoggedPacket = logPacket(packet, optional.None[int](), model.DirectionIncoming) maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } @@ -140,7 +121,7 @@ func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage int, retries int) stg := session.SessionNegotiationState(stage) e := newEvent(handshakeEventPacketOut, stg, t.TimeNow(), t.zeroTime) - e.LoggedPacket = logPacket(packet, retries, model.DirectionOutgoing) + e.LoggedPacket = logPacket(packet, optional.Some(retries), model.DirectionOutgoing) maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } @@ -152,7 +133,7 @@ func (t *Tracer) OnDroppedPacket(direction model.Direction, stage int, packet *m stg := session.SessionNegotiationState(stage) e := newEvent(handshakeEventPacketDropped, stg, t.TimeNow(), t.zeroTime) - e.LoggedPacket = logPacket(packet, -1, direction) + e.LoggedPacket = logPacket(packet, optional.None[int](), direction) t.events = append(t.events, e) } @@ -163,18 +144,14 @@ func (t *Tracer) Trace() []*event { return append([]*event{}, t.events...) } -func logPacket(p *model.Packet, retries int, direction model.Direction) optional.Value[LoggedPacket] { - retriesValue := optional.None[int]() - if retries != -1 { - retriesValue = optional.Some(retries) - } +func logPacket(p *model.Packet, retries optional.Value[int], direction model.Direction) optional.Value[LoggedPacket] { logged := LoggedPacket{ - Opcode: p.Opcode, + Opcode: p.Opcode.String(), ID: p.ID, ACKs: optional.None[[]model.PacketID](), - Direction: direction, + Direction: direction.String(), PayloadSize: len(p.Payload), - Retries: retriesValue, + Retries: retries, } if len(p.ACKs) != 0 { logged.ACKs = optional.Some(p.ACKs) @@ -184,38 +161,18 @@ func logPacket(p *model.Packet, retries int, direction model.Direction) optional // LoggedPacket tracks metadata about a packet useful to build traces. type LoggedPacket struct { - Direction model.Direction + Direction string `json:"operation"` // the only fields of the packet we want to log. - Opcode model.Opcode - ID model.PacketID - ACKs optional.Value[[]model.PacketID] + Opcode string `json:"opcode"` + ID model.PacketID `json:"id"` + ACKs optional.Value[[]model.PacketID] `json:"acks"` // PayloadSize is the size of the payload in bytes - PayloadSize int + PayloadSize int `json:"payload_size"` // Retries keeps track of packet retransmission (only for outgoing packets). - Retries optional.Value[int] -} - -// MarshalJSON implements json.Marshaler. -func (lp LoggedPacket) MarshalJSON() ([]byte, error) { - j := struct { - Direction string `json:"operation"` - Opcode string `json:"opcode"` - ID model.PacketID `json:"id"` - ACKs optional.Value[[]model.PacketID] `json:"acks"` - PayloadSize int `json:"payload_size"` - Retries optional.Value[int] `json:"send_attempts"` - }{ - Direction: lp.Direction.String(), - Opcode: lp.Opcode.String(), - ID: lp.ID, - ACKs: lp.ACKs, - PayloadSize: lp.PayloadSize, - Retries: lp.Retries, - } - return json.Marshal(j) + Retries optional.Value[int] `json:"send_attempts"` } // maybeAddTagsFromPacket attempts to derive meaningful tags from From 46fb370fcced872104527b5edc22c198320616e6 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:31:48 +0100 Subject: [PATCH 30/39] grammar --- pkg/tracex/trace.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index 97140a82..ae148d2d 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -41,7 +41,7 @@ func (e HandshakeEventType) String() string { } } -// event is one handshake event collected by this [model.HandshakeTracer]. +// event is a handshake event collected by this [model.HandshakeTracer]. type event struct { // EventType is the type for this event. EventType string `json:"operation"` From 66762e0ac0cbfd5190773ae1247b3c5bc9944fbb Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:37:24 +0100 Subject: [PATCH 31/39] minor fixes --- internal/model/trace.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index 39e8c46e..f0b8587c 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -57,7 +57,7 @@ type dummyTracer struct{} func (dt *dummyTracer) TimeNow() time.Time { return time.Now() } // OnStateChange is called for each transition in the state machine. -func (dt *dummyTracer) OnStateChange(state int) {} +func (dt *dummyTracer) OnStateChange(_ int) {} // OnIncomingPacket is called when a packet is received. func (dt *dummyTracer) OnIncomingPacket(*Packet, int) {} From 07bcd61ecc923546a69496afa87e1df98cfbb4c0 Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 12:39:43 +0100 Subject: [PATCH 32/39] Update internal/optional/optional.go Co-authored-by: Simone Basso --- internal/optional/optional.go | 1 + 1 file changed, 1 insertion(+) diff --git a/internal/optional/optional.go b/internal/optional/optional.go index 39c63f2f..8c479c54 100644 --- a/internal/optional/optional.go +++ b/internal/optional/optional.go @@ -1,3 +1,4 @@ +// Package optional implements optional values. package optional import ( From dc5b90d10350bf9dd9b3f44288bb3f5a46f3de82 Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 12:40:15 +0100 Subject: [PATCH 33/39] Update internal/packetmuxer/service.go Co-authored-by: Simone Basso --- internal/packetmuxer/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index b1f32b7b..fd0110dc 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -132,7 +132,7 @@ func (ws *workersState) moveUpWorker() { case rawPacket := <-ws.networkToMuxer: if err := ws.handleRawPacket(rawPacket); err != nil { // error already printed - // TODO: trace malformed input + // TODO(ainghazal): trace malformed input continue } From 06b74889e3ad19a3d09d09cb4884d7152943e88c Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 12:41:48 +0100 Subject: [PATCH 34/39] Update internal/packetmuxer/service.go Co-authored-by: Simone Basso --- internal/packetmuxer/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index fd0110dc..7f3e3222 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -245,7 +245,7 @@ func (ws *workersState) handleRawPacket(rawPacket []byte) error { // so that data sent from previous sessions will not be delivered. // However, it does not harm to be defensive here. One such case // is that we get injected packets intended to mess with the handshake. - // In this case we should drop and log/trace the event. + // In this case, the caller will drop and log/trace the event. if packet.IsData() { ws.logger.Warnf("packetmuxer: moveUpWorker: cannot handle data yet") return errors.New("not ready to handle data") From c4fc44aa2ef677dc7cb8433d2532304d5123eed7 Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 12:42:45 +0100 Subject: [PATCH 35/39] Update internal/reliabletransport/receiver.go Co-authored-by: Simone Basso --- internal/reliabletransport/receiver.go | 1 + 1 file changed, 1 insertion(+) diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index 44655bc1..c3249d4c 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -42,6 +42,7 @@ func (ws *workersState) moveUpWorker() { // I'm not sure that's a valid behavior for a server. // We should be able to deterministically test how this affects the state machine. + // sanity check incoming packet if ok := incomingSanityChecks(ws.logger, workerName, packet, ws.sessionManager); !ok { continue } From 23539c7e54b96034ebb9955d89bc4c600d2a5d61 Mon Sep 17 00:00:00 2001 From: Ain Ghazal <99027643+ainghazal@users.noreply.github.com> Date: Tue, 13 Feb 2024 12:46:30 +0100 Subject: [PATCH 36/39] Update pkg/tracex/trace.go Co-authored-by: Simone Basso --- pkg/tracex/trace.go | 1 + 1 file changed, 1 insertion(+) diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index ae148d2d..22fd2339 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -97,6 +97,7 @@ func (t *Tracer) TimeNow() time.Time { func (t *Tracer) OnStateChange(state int) { t.mu.Lock() defer t.mu.Unlock() + stg := session.SessionNegotiationState(state) e := newEvent(handshakeEventStateChange, stg, t.TimeNow(), t.zeroTime) t.events = append(t.events, e) From e9c54b3c42498861d20416ca1e629305335592c5 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:37:24 +0100 Subject: [PATCH 37/39] minor fixes --- internal/model/trace.go | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/internal/model/trace.go b/internal/model/trace.go index f0b8587c..fc564ea7 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -57,7 +57,7 @@ type dummyTracer struct{} func (dt *dummyTracer) TimeNow() time.Time { return time.Now() } // OnStateChange is called for each transition in the state machine. -func (dt *dummyTracer) OnStateChange(_ int) {} +func (dt *dummyTracer) OnStateChange(int) {} // OnIncomingPacket is called when a packet is received. func (dt *dummyTracer) OnIncomingPacket(*Packet, int) {} @@ -66,10 +66,7 @@ func (dt *dummyTracer) OnIncomingPacket(*Packet, int) {} func (dt *dummyTracer) OnOutgoingPacket(*Packet, int, int) {} // OnDroppedPacket is called whenever a packet is dropped (in/out) -func (dt *dummyTracer) OnDroppedPacket(Direction, int, *Packet) { -} - -func (dt *dummyTracer) OnHandshakeDone(remoteAddr string) {} +func (dt *dummyTracer) OnDroppedPacket(Direction, int, *Packet) {} // Assert that dummyTracer implements [model.HandshakeTracer]. var _ HandshakeTracer = &dummyTracer{} From 5c1f86af1cd9a706849d86d815a25b5be0d86971 Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 12:49:56 +0100 Subject: [PATCH 38/39] move comment out of the struct --- internal/reliabletransport/service.go | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/internal/reliabletransport/service.go b/internal/reliabletransport/service.go index 8080383d..6ef12708 100644 --- a/internal/reliabletransport/service.go +++ b/internal/reliabletransport/service.go @@ -35,18 +35,18 @@ func (s *Service) StartWorkers( workersManager *workers.Manager, sessionManager *session.Manager, ) { + // incomingSeen is a buffered channel to avoid losing packets if we're busy + // processing in the sender goroutine. ws := &workersState{ controlToReliable: s.ControlToReliable, dataOrControlToMuxer: *s.DataOrControlToMuxer, incomingSeen: make(chan incomingPacketSeen, 100), logger: config.Logger(), - // incomingSeen is a buffered channel to avoid losing packets if we're busy - // processing in the sender goroutine. - muxerToReliable: s.MuxerToReliable, - reliableToControl: *s.ReliableToControl, - sessionManager: sessionManager, - tracer: config.Tracer(), - workersManager: workersManager, + muxerToReliable: s.MuxerToReliable, + reliableToControl: *s.ReliableToControl, + sessionManager: sessionManager, + tracer: config.Tracer(), + workersManager: workersManager, } workersManager.StartWorker(ws.moveUpWorker) workersManager.StartWorker(ws.moveDownWorker) From b16e276904ae7614c6ac8077fa9446f21ba26a5b Mon Sep 17 00:00:00 2001 From: Ain Ghazal Date: Tue, 13 Feb 2024 13:24:05 +0100 Subject: [PATCH 39/39] move session negotiation states to model to avoid circular import --- internal/controlchannel/controlchannel.go | 4 +- internal/datachannel/service.go | 2 +- internal/model/session.go | 59 ++++++++++++++++++++ internal/model/trace.go | 16 +++--- internal/packetmuxer/service.go | 10 ++-- internal/reliabletransport/receiver.go | 4 +- internal/reliabletransport/sender.go | 4 +- internal/session/manager.go | 68 ++--------------------- internal/tlssession/tlssession.go | 6 +- pkg/tracex/trace.go | 39 ++++++------- 10 files changed, 105 insertions(+), 107 deletions(-) create mode 100644 internal/model/session.go diff --git a/internal/controlchannel/controlchannel.go b/internal/controlchannel/controlchannel.go index 95648efe..b13a6087 100644 --- a/internal/controlchannel/controlchannel.go +++ b/internal/controlchannel/controlchannel.go @@ -92,10 +92,10 @@ func (ws *workersState) moveUpWorker() { // even if after the first key generation we receive two SOFT_RESET requests // back to back. - if ws.sessionManager.NegotiationState() < session.S_GENERATED_KEYS { + if ws.sessionManager.NegotiationState() < model.S_GENERATED_KEYS { continue } - ws.sessionManager.SetNegotiationState(session.S_INITIAL) + ws.sessionManager.SetNegotiationState(model.S_INITIAL) // TODO(ainghazal): revisit this step. // when we implement key rotation. OpenVPN has // the concept of a "lame duck", i.e., the diff --git a/internal/datachannel/service.go b/internal/datachannel/service.go index 32d81aea..23354f87 100644 --- a/internal/datachannel/service.go +++ b/internal/datachannel/service.go @@ -192,7 +192,7 @@ func (ws *workersState) keyWorker(firstKeyReady chan<- any) { ws.logger.Warnf("error on key derivation: %v", err) continue } - ws.sessionManager.SetNegotiationState(session.S_GENERATED_KEYS) + ws.sessionManager.SetNegotiationState(model.S_GENERATED_KEYS) once.Do(func() { close(firstKeyReady) }) diff --git a/internal/model/session.go b/internal/model/session.go new file mode 100644 index 00000000..5e181737 --- /dev/null +++ b/internal/model/session.go @@ -0,0 +1,59 @@ +package model + +// NegotiationState is the state of the session negotiation. +type NegotiationState int + +const ( + // S_ERROR means there was some form of protocol error. + S_ERROR = NegotiationState(iota) - 1 + + // S_UNDER is the undefined state. + S_UNDEF + + // S_INITIAL means we're ready to begin the three-way handshake. + S_INITIAL + + // S_PRE_START means we're waiting for acknowledgment from the remote. + S_PRE_START + + // S_START means we've done the three-way handshake. + S_START + + // S_SENT_KEY means we have sent the local part of the key_source2 random material. + S_SENT_KEY + + // S_GOT_KEY means we have got the remote part of key_source2. + S_GOT_KEY + + // S_ACTIVE means the control channel was established. + S_ACTIVE + + // S_GENERATED_KEYS means the data channel keys have been generated. + S_GENERATED_KEYS +) + +// String maps a [SessionNegotiationState] to a string. +func (sns NegotiationState) String() string { + switch sns { + case S_UNDEF: + return "S_UNDEF" + case S_INITIAL: + return "S_INITIAL" + case S_PRE_START: + return "S_PRE_START" + case S_START: + return "S_START" + case S_SENT_KEY: + return "S_SENT_KEY" + case S_GOT_KEY: + return "S_GOT_KEY" + case S_ACTIVE: + return "S_ACTIVE" + case S_GENERATED_KEYS: + return "S_GENERATED_KEYS" + case S_ERROR: + return "S_ERROR" + default: + return "S_INVALID" + } +} diff --git a/internal/model/trace.go b/internal/model/trace.go index fc564ea7..ff14cfaf 100644 --- a/internal/model/trace.go +++ b/internal/model/trace.go @@ -12,16 +12,16 @@ type HandshakeTracer interface { TimeNow() time.Time // OnStateChange is called for each transition in the state machine. - OnStateChange(state int) + OnStateChange(state NegotiationState) // OnIncomingPacket is called when a packet is received. - OnIncomingPacket(packet *Packet, stage int) + OnIncomingPacket(packet *Packet, stage NegotiationState) // OnOutgoingPacket is called when a packet is about to be sent. - OnOutgoingPacket(packet *Packet, stage int, retries int) + OnOutgoingPacket(packet *Packet, stage NegotiationState, retries int) // OnDroppedPacket is called whenever a packet is dropped (in/out) - OnDroppedPacket(direction Direction, stage int, packet *Packet) + OnDroppedPacket(direction Direction, stage NegotiationState, packet *Packet) } // Direction is one of two directions on a packet. @@ -57,16 +57,16 @@ type dummyTracer struct{} func (dt *dummyTracer) TimeNow() time.Time { return time.Now() } // OnStateChange is called for each transition in the state machine. -func (dt *dummyTracer) OnStateChange(int) {} +func (dt *dummyTracer) OnStateChange(NegotiationState) {} // OnIncomingPacket is called when a packet is received. -func (dt *dummyTracer) OnIncomingPacket(*Packet, int) {} +func (dt *dummyTracer) OnIncomingPacket(*Packet, NegotiationState) {} // OnOutgoingPacket is called when a packet is about to be sent. -func (dt *dummyTracer) OnOutgoingPacket(*Packet, int, int) {} +func (dt *dummyTracer) OnOutgoingPacket(*Packet, NegotiationState, int) {} // OnDroppedPacket is called whenever a packet is dropped (in/out) -func (dt *dummyTracer) OnDroppedPacket(Direction, int, *Packet) {} +func (dt *dummyTracer) OnDroppedPacket(Direction, NegotiationState, *Packet) {} // Assert that dummyTracer implements [model.HandshakeTracer]. var _ HandshakeTracer = &dummyTracer{} diff --git a/internal/packetmuxer/service.go b/internal/packetmuxer/service.go index 7f3e3222..050fe035 100644 --- a/internal/packetmuxer/service.go +++ b/internal/packetmuxer/service.go @@ -199,7 +199,7 @@ func (ws *workersState) startHardReset() error { ws.hardResetCount++ // reset the state to become initial again. - ws.sessionManager.SetNegotiationState(session.S_PRE_START) + ws.sessionManager.SetNegotiationState(model.S_PRE_START) // emit a CONTROL_HARD_RESET_CLIENT_V2 pkt packet := ws.sessionManager.NewHardResetPacket() @@ -223,7 +223,7 @@ func (ws *workersState) handleRawPacket(rawPacket []byte) error { } // handle the case where we're performing a HARD_RESET - if ws.sessionManager.NegotiationState() == session.S_PRE_START && + if ws.sessionManager.NegotiationState() == model.S_PRE_START && packet.Opcode == model.P_CONTROL_HARD_RESET_SERVER_V2 { packet.Log(ws.logger, model.DirectionIncoming) ws.hardResetTicker.Stop() @@ -238,7 +238,7 @@ func (ws *workersState) handleRawPacket(rawPacket []byte) error { return workers.ErrShutdown } } else { - if ws.sessionManager.NegotiationState() < session.S_GENERATED_KEYS { + if ws.sessionManager.NegotiationState() < model.S_GENERATED_KEYS { // A well-behaved server should not send us data packets // before we have a working session. Under normal operations, the // connection in the client side should pick a different port, @@ -269,7 +269,7 @@ func (ws *workersState) finishThreeWayHandshake(packet *model.Packet) error { ws.sessionManager.SetRemoteSessionID(packet.LocalSessionID) // advance the state - ws.sessionManager.SetNegotiationState(session.S_START) + ws.sessionManager.SetNegotiationState(model.S_START) // pass the packet up so that we can ack it properly select { @@ -302,7 +302,7 @@ func (ws *workersState) serializeAndEmit(packet *model.Packet) error { ws.tracer.OnOutgoingPacket( packet, - int(ws.sessionManager.NegotiationState()), + ws.sessionManager.NegotiationState(), ws.hardResetCount, ) diff --git a/internal/reliabletransport/receiver.go b/internal/reliabletransport/receiver.go index c3249d4c..91dc37e8 100644 --- a/internal/reliabletransport/receiver.go +++ b/internal/reliabletransport/receiver.go @@ -31,7 +31,7 @@ func (ws *workersState) moveUpWorker() { // or POSSIBLY BLOCK waiting for notifications select { case packet := <-ws.muxerToReliable: - ws.tracer.OnIncomingPacket(packet, int(ws.sessionManager.NegotiationState())) + ws.tracer.OnIncomingPacket(packet, ws.sessionManager.NegotiationState()) if packet.Opcode != model.P_CONTROL_HARD_RESET_SERVER_V2 { // the hard reset has already been logged by the layer below @@ -63,7 +63,7 @@ func (ws *workersState) moveUpWorker() { // TODO: add reason ws.tracer.OnDroppedPacket( model.DirectionIncoming, - int(ws.sessionManager.NegotiationState()), + ws.sessionManager.NegotiationState(), packet) ws.logger.Debugf("Dropping packet: %v", packet.ID) continue diff --git a/internal/reliabletransport/sender.go b/internal/reliabletransport/sender.go index c3dae808..0fb14fde 100644 --- a/internal/reliabletransport/sender.go +++ b/internal/reliabletransport/sender.go @@ -86,8 +86,8 @@ func (ws *workersState) blockOnTryingToSend(sender *reliableSender, ticker *time p.packet.Log(ws.logger, model.DirectionOutgoing) ws.tracer.OnOutgoingPacket( p.packet, - int(ws.sessionManager.NegotiationState()), - int(p.retries), + ws.sessionManager.NegotiationState(), + p.retries, ) select { diff --git a/internal/session/manager.go b/internal/session/manager.go index 0bffcaf2..4a4ec974 100644 --- a/internal/session/manager.go +++ b/internal/session/manager.go @@ -13,64 +13,6 @@ import ( "github.com/ooni/minivpn/internal/runtimex" ) -// SessionNegotiationState is the state of the session negotiation. -type SessionNegotiationState int - -const ( - // S_ERROR means there was some form of protocol error. - S_ERROR = SessionNegotiationState(iota) - 1 - - // S_UNDER is the undefined state. - S_UNDEF - - // S_INITIAL means we're ready to begin the three-way handshake. - S_INITIAL - - // S_PRE_START means we're waiting for acknowledgment from the remote. - S_PRE_START - - // S_START means we've done the three-way handshake. - S_START - - // S_SENT_KEY means we have sent the local part of the key_source2 random material. - S_SENT_KEY - - // S_GOT_KEY means we have got the remote part of key_source2. - S_GOT_KEY - - // S_ACTIVE means the control channel was established. - S_ACTIVE - - // S_GENERATED_KEYS means the data channel keys have been generated. - S_GENERATED_KEYS -) - -// String maps a [SessionNegotiationState] to a string. -func (sns SessionNegotiationState) String() string { - switch sns { - case S_UNDEF: - return "S_UNDEF" - case S_INITIAL: - return "S_INITIAL" - case S_PRE_START: - return "S_PRE_START" - case S_START: - return "S_START" - case S_SENT_KEY: - return "S_SENT_KEY" - case S_GOT_KEY: - return "S_GOT_KEY" - case S_ACTIVE: - return "S_ACTIVE" - case S_GENERATED_KEYS: - return "S_GENERATED_KEYS" - case S_ERROR: - return "S_ERROR" - default: - return "S_INVALID" - } -} - // Manager manages the session. The zero value is invalid. Please, construct // using [NewManager]. This struct is concurrency safe. type Manager struct { @@ -81,7 +23,7 @@ type Manager struct { localSessionID model.SessionID logger model.Logger mu sync.Mutex - negState SessionNegotiationState + negState model.NegotiationState remoteSessionID optional.Value[model.SessionID] tunnelInfo model.TunnelInfo tracer model.HandshakeTracer @@ -263,20 +205,20 @@ func (m *Manager) localControlPacketIDLocked() (model.PacketID, error) { } // NegotiationState returns the state of the negotiation. -func (m *Manager) NegotiationState() SessionNegotiationState { +func (m *Manager) NegotiationState() model.NegotiationState { defer m.mu.Unlock() m.mu.Lock() return m.negState } // SetNegotiationState sets the state of the negotiation. -func (m *Manager) SetNegotiationState(sns SessionNegotiationState) { +func (m *Manager) SetNegotiationState(sns model.NegotiationState) { defer m.mu.Unlock() m.mu.Lock() m.logger.Infof("[@] %s -> %s", m.negState, sns) - m.tracer.OnStateChange(int(sns)) + m.tracer.OnStateChange(sns) m.negState = sns - if sns == S_GENERATED_KEYS { + if sns == model.S_GENERATED_KEYS { m.Ready <- true } } diff --git a/internal/tlssession/tlssession.go b/internal/tlssession/tlssession.go index def3c809..1fb88d79 100644 --- a/internal/tlssession/tlssession.go +++ b/internal/tlssession/tlssession.go @@ -156,7 +156,7 @@ func (ws *workersState) doTLSAuth(conn net.Conn, config *tls.Config, errorch cha errorch <- err return } - ws.sessionManager.SetNegotiationState(session.S_SENT_KEY) + ws.sessionManager.SetNegotiationState(model.S_SENT_KEY) // read the server's keySource and options remoteKey, serverOptions, err := ws.recvAuthReplyMessage(tlsConn) @@ -174,7 +174,7 @@ func (ws *workersState) doTLSAuth(conn net.Conn, config *tls.Config, errorch cha // add the remote key to the active key activeKey.AddRemoteKey(remoteKey) - ws.sessionManager.SetNegotiationState(session.S_GOT_KEY) + ws.sessionManager.SetNegotiationState(model.S_GOT_KEY) // send the push request if err := ws.sendPushRequestMessage(tlsConn); err != nil { @@ -193,7 +193,7 @@ func (ws *workersState) doTLSAuth(conn net.Conn, config *tls.Config, errorch cha ws.sessionManager.UpdateTunnelInfo(tinfo) // progress to the ACTIVE state - ws.sessionManager.SetNegotiationState(session.S_ACTIVE) + ws.sessionManager.SetNegotiationState(model.S_ACTIVE) // notify the datachannel that we've got a key pair ready to use ws.keyUp <- activeKey diff --git a/pkg/tracex/trace.go b/pkg/tracex/trace.go index 22fd2339..09979fa1 100644 --- a/pkg/tracex/trace.go +++ b/pkg/tracex/trace.go @@ -9,7 +9,6 @@ import ( "github.com/ooni/minivpn/internal/model" "github.com/ooni/minivpn/internal/optional" - "github.com/ooni/minivpn/internal/session" ) const ( @@ -41,8 +40,8 @@ func (e HandshakeEventType) String() string { } } -// event is a handshake event collected by this [model.HandshakeTracer]. -type event struct { +// Event is a handshake event collected by this [model.HandshakeTracer]. +type Event struct { // EventType is the type for this event. EventType string `json:"operation"` @@ -59,8 +58,10 @@ type event struct { LoggedPacket optional.Value[LoggedPacket] `json:"packet"` } -func newEvent(etype HandshakeEventType, st session.SessionNegotiationState, t time.Time, t0 time.Time) *event { - return &event{ +type NegotiationState = model.NegotiationState + +func newEvent(etype HandshakeEventType, st NegotiationState, t time.Time, t0 time.Time) *Event { + return &Event{ EventType: etype.String(), Stage: st.String()[2:], AtTime: t.Sub(t0).Seconds(), @@ -72,7 +73,7 @@ func newEvent(etype HandshakeEventType, st session.SessionNegotiationState, t ti // Tracer implements [model.HandshakeTracer]. type Tracer struct { // events is the array of handshake events. - events []*event + events []*Event // mu guards access to the events. mu sync.Mutex @@ -94,55 +95,51 @@ func (t *Tracer) TimeNow() time.Time { } // OnStateChange is called for each transition in the state machine. -func (t *Tracer) OnStateChange(state int) { +func (t *Tracer) OnStateChange(state NegotiationState) { t.mu.Lock() defer t.mu.Unlock() - stg := session.SessionNegotiationState(state) - e := newEvent(handshakeEventStateChange, stg, t.TimeNow(), t.zeroTime) + e := newEvent(handshakeEventStateChange, state, t.TimeNow(), t.zeroTime) t.events = append(t.events, e) } // OnIncomingPacket is called when a packet is received. -func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage int) { +func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage NegotiationState) { t.mu.Lock() defer t.mu.Unlock() - stg := session.SessionNegotiationState(stage) - e := newEvent(handshakeEventPacketIn, stg, t.TimeNow(), t.zeroTime) + e := newEvent(handshakeEventPacketIn, stage, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, optional.None[int](), model.DirectionIncoming) maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } // OnOutgoingPacket is called when a packet is about to be sent. -func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage int, retries int) { +func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage NegotiationState, retries int) { t.mu.Lock() defer t.mu.Unlock() - stg := session.SessionNegotiationState(stage) - e := newEvent(handshakeEventPacketOut, stg, t.TimeNow(), t.zeroTime) + e := newEvent(handshakeEventPacketOut, stage, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, optional.Some(retries), model.DirectionOutgoing) maybeAddTagsFromPacket(e, packet) t.events = append(t.events, e) } // OnDroppedPacket is called whenever a packet is dropped (in/out) -func (t *Tracer) OnDroppedPacket(direction model.Direction, stage int, packet *model.Packet) { +func (t *Tracer) OnDroppedPacket(direction model.Direction, stage NegotiationState, packet *model.Packet) { t.mu.Lock() defer t.mu.Unlock() - stg := session.SessionNegotiationState(stage) - e := newEvent(handshakeEventPacketDropped, stg, t.TimeNow(), t.zeroTime) + e := newEvent(handshakeEventPacketDropped, stage, t.TimeNow(), t.zeroTime) e.LoggedPacket = logPacket(packet, optional.None[int](), direction) t.events = append(t.events, e) } // Trace returns a structured log containing a copy of the array of [model.HandshakeEvent]. -func (t *Tracer) Trace() []*event { +func (t *Tracer) Trace() []*Event { t.mu.Lock() defer t.mu.Unlock() - return append([]*event{}, t.events...) + return append([]*Event{}, t.events...) } func logPacket(p *model.Packet, retries optional.Value[int], direction model.Direction) optional.Value[LoggedPacket] { @@ -178,7 +175,7 @@ type LoggedPacket struct { // maybeAddTagsFromPacket attempts to derive meaningful tags from // the packet payload, and adds it to the tag array in the passed event. -func maybeAddTagsFromPacket(e *event, packet *model.Packet) { +func maybeAddTagsFromPacket(e *Event, packet *model.Packet) { if len(packet.Payload) <= 0 { return }