From 98174da08fed196b07b97662ed7ca97cf56087da Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Tue, 14 Jun 2016 14:15:22 +0100 Subject: [PATCH 1/7] vsudd: Correctly format go Error's with %s %#v is not correct (includes opaque pointers etc). Signed-off-by: Ian Campbell --- alpine/packages/vsudd/main.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/alpine/packages/vsudd/main.go b/alpine/packages/vsudd/main.go index 6e039e851..1565e2700 100644 --- a/alpine/packages/vsudd/main.go +++ b/alpine/packages/vsudd/main.go @@ -62,7 +62,7 @@ func main() { } l, err = hvsock.Listen(hvsock.HypervAddr{VmId: hvsock.GUID_WILDCARD, ServiceId: svcid}) if err != nil { - log.Fatalf("Failed to bind to hvsock port: %#v", err) + log.Fatalf("Failed to bind to hvsock port: %s", err) } log.Printf("Listening on ServiceId %s", svcid) useHVsock = true @@ -73,7 +73,7 @@ func main() { } l, err = vsock.Listen(uint(port)) if err != nil { - log.Fatalf("Failed to bind to vsock port %u: %#v", port, err) + log.Fatalf("Failed to bind to vsock port %u: %s", port, err) } log.Printf("Listening on port %u", port) useHVsock = false @@ -84,7 +84,7 @@ func main() { connid++ conn, err := l.Accept() if err != nil { - log.Printf("Error accepting connection: %#v", err) + log.Printf("Error accepting connection: %s", err) return // no more listening } log.Printf("Connection %d from: %s\n", connid, conn.RemoteAddr()) From f70ff0aeacf9f4cd423f9ee8a75b4b29646e0663 Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Thu, 23 Jun 2016 12:27:32 +0100 Subject: [PATCH 2/7] Revendor virtsock go library, for vsock.Dial $ gvt delete github.com/rneugeba/virtsock/go $ gvt fetch --no-recurse https://github.com/rneugeba/virtsock/go virtsock.git: $ git log --oneline 74097e05a883e89c70e6a27b342672c7fe6c846b..650ef8224a0c06b4b20e9bee1600dbf677c8176d -- go/ 0e2f0a8 vsock: Implement vsock.Dial 712714a vsock: include the errno when C.bind_sockaddr_vm 03725fe go: make errors public Signed-off-by: Ian Campbell --- .../rneugeba/virtsock/go/hvsock/hvsock.go | 28 +++++++-------- .../virtsock/go/hvsock/hvsock_darwin.go | 1 + .../virtsock/go/hvsock/hvsock_windows.go | 4 +-- .../rneugeba/virtsock/go/vsock/vsock_linux.go | 34 ++++++++++++++++--- alpine/packages/go/vendor/manifest | 2 +- 5 files changed, 47 insertions(+), 22 deletions(-) diff --git a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock.go b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock.go index 4f51e222d..2e4f19ebd 100644 --- a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock.go +++ b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock.go @@ -173,13 +173,13 @@ func (v *hvsockListener) Addr() net.Addr { */ var ( - errSocketClosed = errors.New("HvSocket has already been closed") - errSocketWriteClosed = errors.New("HvSocket has been closed for write") - errSocketReadClosed = errors.New("HvSocket has been closed for read") - errSocketMsgSize = errors.New("HvSocket message was of wrong size") - errSocketMsgWrite = errors.New("HvSocket writing message") - errSocketNotEnoughData = errors.New("HvSocket not enough data written") - errSocketUnImplemented = errors.New("Function not implemented") + ErrSocketClosed = errors.New("HvSocket has already been closed") + ErrSocketWriteClosed = errors.New("HvSocket has been closed for write") + ErrSocketReadClosed = errors.New("HvSocket has been closed for read") + ErrSocketMsgSize = errors.New("HvSocket message was of wrong size") + ErrSocketMsgWrite = errors.New("HvSocket writing message") + ErrSocketNotEnoughData = errors.New("HvSocket not enough data written") + ErrSocketUnImplemented = errors.New("Function not implemented") ) type HVsockConn struct { @@ -227,7 +227,7 @@ func (v *HVsockConn) Close() error { func (v *HVsockConn) CloseRead() error { if v.readClosed { - return errSocketReadClosed + return ErrSocketReadClosed } prDebug("TX: Shutdown Read\n") @@ -244,7 +244,7 @@ func (v *HVsockConn) CloseRead() error { func (v *HVsockConn) CloseWrite() error { if v.writeClosed { - return errSocketWriteClosed + return ErrSocketWriteClosed } prDebug("TX: Shutdown Write\n") @@ -284,7 +284,7 @@ func (v *HVsockConn) Read(buf []byte) (int, error) { } if n != 4 { - return n, errSocketMsgSize + return n, ErrSocketMsgSize } msg := int(binary.LittleEndian.Uint32(b)) @@ -333,7 +333,7 @@ func (v *HVsockConn) Read(buf []byte) (int, error) { func (v *HVsockConn) Write(buf []byte) (int, error) { if v.writeClosed { - return 0, errSocketWriteClosed + return 0, ErrSocketWriteClosed } var err error @@ -344,7 +344,7 @@ func (v *HVsockConn) Write(buf []byte) (int, error) { for toWrite > 0 { if v.writeClosed { - return 0, errSocketWriteClosed + return 0, ErrSocketWriteClosed } // We write batches of MSG + data which need to be @@ -371,7 +371,7 @@ func (v *HVsockConn) Write(buf []byte) (int, error) { } if n != thisBatch { prDebug("Write Error 4\n") - err = errSocketNotEnoughData + err = ErrSocketNotEnoughData goto ErrOut } toWrite -= n @@ -402,7 +402,7 @@ func (v *HVsockConn) sendMsg(msg uint32) error { return err } if n != len(b) { - return errSocketMsgWrite + return ErrSocketMsgWrite } return nil } diff --git a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_darwin.go b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_darwin.go index c448fb072..99f8ea1d0 100644 --- a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_darwin.go +++ b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_darwin.go @@ -1,6 +1,7 @@ // Dummy implementation to compile on Mac OSX package hvsock + import ( "errors" "time" diff --git a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_windows.go b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_windows.go index 973f3ff16..3008f9c95 100644 --- a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_windows.go +++ b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/hvsock/hvsock_windows.go @@ -240,7 +240,7 @@ func (v *hvsockConn) closeHandle() { func (s *hvsockConn) prepareIo() (*ioOperation, error) { s.wg.Add(1) if s.closing { - return nil, errSocketClosed + return nil, ErrSocketClosed } c := &ioOperation{} c.ch = make(chan ioResult) @@ -299,7 +299,7 @@ func (v *hvsockConn) asyncIo(c *ioOperation, deadline time.Time, bytes uint32, e err = r.err if err == syscall.ERROR_OPERATION_ABORTED { if v.closing { - err = errSocketClosed + err = ErrSocketClosed } else if timedout { err = errTimeout } diff --git a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/vsock/vsock_linux.go b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/vsock/vsock_linux.go index f8c38e00a..21da5cd69 100644 --- a/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/vsock/vsock_linux.go +++ b/alpine/packages/go/vendor/github.com/rneugeba/virtsock/go/vsock/vsock_linux.go @@ -37,11 +37,33 @@ int accept_vm(int fd, struct sockaddr_vm *sa_vm, socklen_t *sa_vm_len) { import "C" const ( - AF_VSOCK = 40 - VSOCK_CID_ANY = 4294967295 /* 2^32-1 */ - VSOCK_CID_SELF = 3 + AF_VSOCK = 40 + VSOCK_CID_ANY = 4294967295 /* 2^32-1 */ + VSOCK_CID_HYPERVISOR = 0 + VSOCK_CID_HOST = 2 + VSOCK_CID_SELF = 3 ) +func Dial(cid, port uint) (Conn, error) { + fd, err := syscall.Socket(AF_VSOCK, syscall.SOCK_STREAM, 0) + if err != nil { + return nil, err + } + + sa := C.struct_sockaddr_vm{} + sa.svm_family = AF_VSOCK + sa.svm_port = C.uint(port) + sa.svm_cid = C.uint(cid) + + if ret, errno := C.connect_sockaddr_vm(C.int(fd), &sa); ret != 0 { + return nil, errors.New(fmt.Sprintf( + "failed bind connect to %08x.%08x, returned %d, errno %d: %s", + sa.svm_cid, sa.svm_port, ret, errno, errno)) + } + + return newVsockConn(uintptr(fd), port) +} + // Listen returns a net.Listener which can accept connections on the given // vhan port. func Listen(port uint) (net.Listener, error) { @@ -55,8 +77,10 @@ func Listen(port uint) (net.Listener, error) { sa.svm_port = C.uint(port) sa.svm_cid = VSOCK_CID_ANY - if ret := C.bind_sockaddr_vm(C.int(accept_fd), &sa); ret != 0 { - return nil, errors.New(fmt.Sprintf("failed bind vsock connection to %08x.%08x, returned %d", sa.svm_cid, sa.svm_port, ret)) + if ret, errno := C.bind_sockaddr_vm(C.int(accept_fd), &sa); ret != 0 { + return nil, errors.New(fmt.Sprintf( + "failed bind vsock connection to %08x.%08x, returned %d, errno %d: %s", + sa.svm_cid, sa.svm_port, ret, errno, errno)) } err = syscall.Listen(accept_fd, syscall.SOMAXCONN) diff --git a/alpine/packages/go/vendor/manifest b/alpine/packages/go/vendor/manifest index a2d236026..9f686cf79 100644 --- a/alpine/packages/go/vendor/manifest +++ b/alpine/packages/go/vendor/manifest @@ -5,7 +5,7 @@ "importpath": "github.com/rneugeba/virtsock/go", "repository": "https://github.com/rneugeba/virtsock", "vcs": "git", - "revision": "74097e05a883e89c70e6a27b342672c7fe6c846b", + "revision": "650ef8224a0c06b4b20e9bee1600dbf677c8176d", "branch": "master", "path": "/go", "notests": true From b61451047d55994311706bba5036c7994e0f151b Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Fri, 1 Jul 2016 11:04:17 +0100 Subject: [PATCH 3/7] vsudd: Make incoming socket forwarding more generic Rather than hardcoding a single vsock<->docker.sock mapping allow arbitrary incoming connection forwarding between vsocks and unix domain sockets. The intention was to subsequently extend this further to support arbitrary forwarding of outgoing connections too and to use that to forward the syslog socket out to a vsock. This turned out not to be a good plan, partly since the syslog socket needs to be SOCK_DATAGRAM but vsocks only does SOCK_STREAM today (meaning we need some additional framing here) and partly because handling syslog forwarding in common code makes error logging in the common code somewhat trickier (logging syslog errors over syslog). So instead syslog will be handled as a special case in a following patch. However some vestiges of the original plan remain, e.g. the inForwards name and the net field in the forwards which could be unixgram but currently is only supporting unix(stream). In principal this patch could be dropped, but it adds some flexibility which might be useful in the future. Signed-off-by: Ian Campbell --- alpine/packages/vsudd/etc/init.d/vsudd | 8 +- alpine/packages/vsudd/main.go | 128 +++++++++++++++++-------- 2 files changed, 92 insertions(+), 44 deletions(-) diff --git a/alpine/packages/vsudd/etc/init.d/vsudd b/alpine/packages/vsudd/etc/init.d/vsudd index 686fc030c..c6439a9f2 100755 --- a/alpine/packages/vsudd/etc/init.d/vsudd +++ b/alpine/packages/vsudd/etc/init.d/vsudd @@ -9,12 +9,12 @@ depend() start() { - ebegin "Starting docker socket vsock passthrough" + ebegin "Starting vsock proxy" if [ -d /sys/bus/vmbus ]; then - PORT=23a432c2-537a-4291-bcb5-d62504644739 + DOCKER_PORT=23a432c2-537a-4291-bcb5-d62504644739 else - PORT=2376 + DOCKER_PORT=2376 fi [ -n "${PIDFILE}" ] || PIDFILE=/var/run/vsudd.pid @@ -25,7 +25,7 @@ start() --exec /sbin/vsudd \ --make-pidfile --pidfile ${PIDFILE} \ --stderr "${LOGFILE}" --stdout "${LOGFILE}" \ - -- -port "${PORT}" -sock /var/run/docker.sock + -- -inport "${DOCKER_PORT}:unix:/var/run/docker.sock" eend $? "Failed to start vsudd" } diff --git a/alpine/packages/vsudd/main.go b/alpine/packages/vsudd/main.go index 1565e2700..7d35eb211 100644 --- a/alpine/packages/vsudd/main.go +++ b/alpine/packages/vsudd/main.go @@ -2,12 +2,14 @@ package main import ( "flag" + "fmt" "io" "log" "net" "os" "strconv" "strings" + "sync" "syscall" "time" @@ -15,11 +17,18 @@ import ( "github.com/rneugeba/virtsock/go/vsock" ) +type forward struct { + vsock string + net string // "unix" or "unixgram" + usock string +} + +type forwards []forward + var ( - portstr string - sock string - detach bool - useHVsock bool + inForwards forwards + detach bool + useHVsock bool ) type vConn interface { @@ -28,9 +37,25 @@ type vConn interface { CloseWrite() error } +func (f *forwards) String() string { + return "Forwards" +} + +func (f *forwards) Set(value string) error { + s := strings.SplitN(value, ":", 3) + if len(s) != 3 { + return fmt.Errorf("Failed to parse: %s", value) + } + var newF forward + newF.vsock = s[0] + newF.net = s[1] + newF.usock = s[2] + *f = append(*f, newF) + return nil +} + func init() { - flag.StringVar(&portstr, "port", "2376", "vsock port to forward") - flag.StringVar(&sock, "sock", "/var/run/docker.sock", "path of the local Unix domain socket to forward to") + flag.Var(&inForwards, "inport", "incoming port to forward") flag.BoolVar(&detach, "detach", false, "detach from terminal") } @@ -54,46 +79,69 @@ func main() { syscall.Dup2(int(fd), int(os.Stderr.Fd())) } - var l net.Listener - if strings.Contains(portstr, "-") { - svcid, err := hvsock.GuidFromString(portstr) - if err != nil { - log.Fatalln("Failed to parse GUID", portstr, err) - } - l, err = hvsock.Listen(hvsock.HypervAddr{VmId: hvsock.GUID_WILDCARD, ServiceId: svcid}) - if err != nil { - log.Fatalf("Failed to bind to hvsock port: %s", err) - } - log.Printf("Listening on ServiceId %s", svcid) - useHVsock = true - } else { - port, err := strconv.ParseUint(portstr, 10, 32) - if err != nil { - log.Fatalln("Can't convert %s to a uint.", portstr, err) - } - l, err = vsock.Listen(uint(port)) - if err != nil { - log.Fatalf("Failed to bind to vsock port %u: %s", port, err) - } - log.Printf("Listening on port %u", port) - useHVsock = false - } + var wg sync.WaitGroup connid := 0 - for { - connid++ - conn, err := l.Accept() - if err != nil { - log.Printf("Error accepting connection: %s", err) - return // no more listening - } - log.Printf("Connection %d from: %s\n", connid, conn.RemoteAddr()) - go handleOne(connid, conn.(vConn)) + for _, inF := range inForwards { + var portstr = inF.vsock + var network = inF.net + var usock = inF.usock + + var l net.Listener + + if network != "unix" { + log.Fatalf("cannot forward incoming port to %s:%s", network, usock) + } + + log.Printf("incoming port forward from %s to %s", portstr, usock) + + if strings.Contains(portstr, "-") { + svcid, err := hvsock.GuidFromString(portstr) + if err != nil { + log.Fatalln("Failed to parse GUID", portstr, err) + } + l, err = hvsock.Listen(hvsock.HypervAddr{VmId: hvsock.GUID_WILDCARD, ServiceId: svcid}) + if err != nil { + log.Fatalf("Failed to bind to hvsock port: %s", err) + } + log.Printf("Listening on ServiceId %s", svcid) + useHVsock = true + } else { + port, err := strconv.ParseUint(portstr, 10, 32) + if err != nil { + log.Fatalln("Can't convert %s to a uint.", portstr, err) + } + l, err = vsock.Listen(uint(port)) + if err != nil { + log.Fatalf("Failed to bind to vsock port %d: %s", port, err) + } + log.Printf("Listening on port %s", portstr) + useHVsock = false + } + + wg.Add(1) + + go func() { + defer wg.Done() + for { + connid++ + conn, err := l.Accept() + if err != nil { + log.Printf("Error accepting connection: %s", err) + return // no more listening + } + log.Printf("Connection %d to: %s from: %s\n", connid, portstr, conn.RemoteAddr()) + + go handleOneIn(connid, conn.(vConn), usock) + } + }() } + + wg.Wait() } -func handleOne(connid int, conn vConn) { +func handleOneIn(connid int, conn vConn, sock string) { defer func() { if err := conn.Close(); err != nil { // On windows we get an EINVAL when the other end already closed From 7dd7b0c0da6a8877f990a09a5bbdeb795321b21e Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Fri, 1 Jul 2016 11:49:18 +0100 Subject: [PATCH 4/7] vsudd: Forward syslog from /var/run/syslog.vsock to vsock 514 This is mac only (for now) and will not actually do anything until syslogd is told to forward to /var/run/syslog.vsock. syslog uses a SOCK_DGRAM connection to /var/run/syslog.vsock, however vsock today is SOCK_STREAM only, so we need to "packetise" the stream. Do so by writing the datagram length as a (little-endian) uint32 before the data itself. This is slightly modelled after rfc6587 (syslog over TCP) but simplified by using a 4-byte binary value rather than ASCII digits. Arrange for vsudd to start before the logger so it is ready and waiting. Note that the code in vsyslog.go needs to be rather careful about its own logging, in particular logging forwarding failures over syslog seems likely to make things worse. Instead this file logs to the console when errors occur, this will be captured by the logging of the hyperkit VM console. Signed-off-by: Ian Campbell --- alpine/Dockerfile | 2 +- alpine/packages/vsudd/etc/init.d/vsudd | 12 +- alpine/packages/vsudd/main.go | 10 ++ alpine/packages/vsudd/vsyslog.go | 178 +++++++++++++++++++++++++ 4 files changed, 199 insertions(+), 3 deletions(-) create mode 100644 alpine/packages/vsudd/vsyslog.go diff --git a/alpine/Dockerfile b/alpine/Dockerfile index 64890b672..6a251b567 100644 --- a/alpine/Dockerfile +++ b/alpine/Dockerfile @@ -80,6 +80,7 @@ RUN \ rc-update add bootmisc boot && \ rc-update add urandom boot && \ rc-update add hostname boot && \ + rc-update add vsudd boot && \ rc-update add syslog boot && \ rc-update add hwclock boot && \ rc-update add networking boot && \ @@ -106,7 +107,6 @@ RUN \ rc-update add hostsettings boot && \ rc-update add hv_kvp_daemon default && \ rc-update add hv_vss_daemon default && \ - rc-update add vsudd default && \ rc-update add oom default && \ true diff --git a/alpine/packages/vsudd/etc/init.d/vsudd b/alpine/packages/vsudd/etc/init.d/vsudd index c6439a9f2..e9b89ddf1 100755 --- a/alpine/packages/vsudd/etc/init.d/vsudd +++ b/alpine/packages/vsudd/etc/init.d/vsudd @@ -4,7 +4,7 @@ description="vsock socket proxy client" depend() { - before docker + before logger docker } start() @@ -13,19 +13,27 @@ start() if [ -d /sys/bus/vmbus ]; then DOCKER_PORT=23a432c2-537a-4291-bcb5-d62504644739 + SYSLOG_PORT="" #TBD else DOCKER_PORT=2376 + SYSLOG_PORT=514 fi [ -n "${PIDFILE}" ] || PIDFILE=/var/run/vsudd.pid [ -n "${LOGFILE}" ] || LOGFILE=/var/log/vsudd.log + if [ -n "$SYSLOG_PORT" ] ; then + # Can be inlined below once Windows defines syslog port + SYSLOG_OPT="-syslog ${SYSLOG_PORT}:/var/run/syslog.vsock" + fi + start-stop-daemon --start --quiet \ --background \ --exec /sbin/vsudd \ --make-pidfile --pidfile ${PIDFILE} \ --stderr "${LOGFILE}" --stdout "${LOGFILE}" \ - -- -inport "${DOCKER_PORT}:unix:/var/run/docker.sock" + -- -inport "${DOCKER_PORT}:unix:/var/run/docker.sock" \ + ${SYSLOG_OPT} eend $? "Failed to start vsudd" } diff --git a/alpine/packages/vsudd/main.go b/alpine/packages/vsudd/main.go index 7d35eb211..7cc0639e2 100644 --- a/alpine/packages/vsudd/main.go +++ b/alpine/packages/vsudd/main.go @@ -29,6 +29,7 @@ var ( inForwards forwards detach bool useHVsock bool + syslogFwd string ) type vConn interface { @@ -56,6 +57,7 @@ func (f *forwards) Set(value string) error { func init() { flag.Var(&inForwards, "inport", "incoming port to forward") + flag.StringVar(&syslogFwd, "syslog", "", "enable syslog forwarding") flag.BoolVar(&detach, "detach", false, "detach from terminal") } @@ -81,6 +83,14 @@ func main() { var wg sync.WaitGroup + if syslogFwd != "" { + wg.Add(1) + go func() { + defer wg.Done() + handleSyslogForward(syslogFwd) + }() + } + connid := 0 for _, inF := range inForwards { diff --git a/alpine/packages/vsudd/vsyslog.go b/alpine/packages/vsudd/vsyslog.go new file mode 100644 index 000000000..3bb599214 --- /dev/null +++ b/alpine/packages/vsudd/vsyslog.go @@ -0,0 +1,178 @@ +/* + * Functions in this file are used to forward syslog messages to the + * host and must be quite careful about their own logging. In general + * error messages should go via the console log.Logger defined in this + * file. + */ +package main + +import ( + "encoding/binary" + "errors" + "log" + "net" + "os" + "strconv" + "strings" + + "github.com/rneugeba/virtsock/go/hvsock" + "github.com/rneugeba/virtsock/go/vsock" +) + +var ( + console *log.Logger + currentConn vConn + + alreadyConnectedOnce bool + + /* When writing we don't discover e.g. EPIPE until the _next_ + * attempt to write. Therefore we keep a copy of the last + * message sent such that we can repeat it after an error. + * + * Note that this is imperfect since their can be multiple + * messages in flight at the point a connection collapses + * which will then be lost. This only handles the delayed + * notification of such an error to this code. + */ + lastMessage []byte +) + +func checkedWrite(conn vConn, buf []byte) error { + + var l uint32 = uint32(len(buf)) + + err := binary.Write(conn, binary.LittleEndian, l) + /* XXX todo, check for serious vs retriable errors */ + if err != nil { + console.Printf("Error in length write: %s", err) + return err + } + + _, err = conn.Write(buf) + /* XXX todo, check for serious vs retriable errors */ + if err != nil { + console.Printf("Error in buf write: %s", err) + } + + return err +} + +func forwardSyslogDatagram(buf []byte, portstr string) error { + for try := 0; try < 2; try++ { + conn := currentConn + if conn == nil { + if strings.Contains(portstr, "-") { + svcid, err := hvsock.GuidFromString(portstr) + if err != nil { + console.Fatalln("Failed to parse GUID", portstr, err) + } + + conn, err = hvsock.Dial(hvsock.HypervAddr{VmId: hvsock.GUID_WILDCARD, ServiceId: svcid}) + if err != nil { + console.Printf("Failed to dial hvsock port: %s", err) + continue + } + } else { + port, err := strconv.ParseUint(portstr, 10, 32) + if err != nil { + console.Fatalln("Can't convert %s to a uint.", portstr, err) + } + + conn, err = vsock.Dial(vsock.VSOCK_CID_HOST, uint(port)) + if err != nil { + console.Printf("Failed to dial vsock port %d: %s", port, err) + continue + } + } + + conn.CloseRead() + + /* + * Only log on reconnection, not the initial connection since + * that is mostly uninteresting + */ + if alreadyConnectedOnce { + console.Printf("Opened new conn to %s: %#v", portstr, conn) + } + alreadyConnectedOnce = true + + if lastMessage != nil { + console.Printf("Replaying last message: %s", lastMessage) + err := checkedWrite(conn, lastMessage) + if err != nil { + conn.Close() + continue + } + lastMessage = nil + } + + currentConn = conn + } + + err := checkedWrite(conn, buf) + if err != nil { + currentConn.Close() + currentConn = nil + console.Printf("Failed to write: %s", string(buf)) + continue + } + + if try > 0 { + console.Printf("Forwarded on attempt %d: %s", try+1, string(buf)) + } + + // Keep a copy in case we get an EPIPE from the next write + lastMessage = make([]byte, len(buf)) + copy(lastMessage, buf) + + return nil + } + + lastMessage = nil // No point repeating this now + return errors.New("Failed to send datagram, too many retries") +} + +func handleSyslogForward(cfg string) { + // logging to the default syslog while trying to do syslog + // forwarding would result in infinite loops, so log all + // messages in this callchain to the console instead. + logFile, err := os.OpenFile("/dev/console", os.O_WRONLY, 0) + if err != nil { + /* What are the chances of this going anywhere useful... */ + log.Fatalln("Failed to open /dev/console for syslog forward logging", err) + } + + console = log.New(logFile, "vsyslog: ", log.LstdFlags) + + s := strings.SplitN(cfg, ":", 2) + if len(s) != 2 { + console.Fatalf("Failed to parse: %s", cfg) + } + vsock := s[0] + usock := s[1] + + err = os.Remove(usock) + if err != nil && !os.IsNotExist(err) { + console.Printf("Failed to remove %s: %s", usock, err) + /* Try and carry on... */ + } + + l, err := net.ListenUnixgram("unixgram", &net.UnixAddr{usock, "unixgram"}) + if err != nil { + console.Fatalf("Failed to listen to unixgram:%s: %s", usock, err) + } + + var buf [4096]byte // Ugh, no way to peek at the next message's size in Go + for { + r, err := l.Read(buf[:]) + if err != nil { + console.Fatalf("Failed to read: %s", err) + } + + err = forwardSyslogDatagram(buf[:r], vsock) + if err != nil { + console.Printf("Failed to send log: %s: %s", + err, string(buf[:r])) + } + } +} From ad7f4c74b2fb59e4d9e0defa5b1f54114a007897 Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Fri, 1 Jul 2016 13:44:32 +0100 Subject: [PATCH 5/7] vsudd: Log over syslog This means that with the previous patches normal vsudd logging will be logged on the console. The exceptional case of error logging during syslog forwarding established in the previous patch remains in place. Prior to this the vsudd.log was actually in /run/vsudd.log and not in /var/log/ (exported to the host) as expected. Prior to c5940b34795a ("Bind the original /var/log onto /run/log") the log was simply shadowed under the fuse mount over /var/log. Signed-off-by: Ian Campbell --- alpine/packages/vsudd/etc/init.d/vsudd | 5 ++--- alpine/packages/vsudd/main.go | 16 +++++++++++++--- 2 files changed, 15 insertions(+), 6 deletions(-) diff --git a/alpine/packages/vsudd/etc/init.d/vsudd b/alpine/packages/vsudd/etc/init.d/vsudd index e9b89ddf1..7e987ff24 100755 --- a/alpine/packages/vsudd/etc/init.d/vsudd +++ b/alpine/packages/vsudd/etc/init.d/vsudd @@ -20,7 +20,6 @@ start() fi [ -n "${PIDFILE}" ] || PIDFILE=/var/run/vsudd.pid - [ -n "${LOGFILE}" ] || LOGFILE=/var/log/vsudd.log if [ -n "$SYSLOG_PORT" ] ; then # Can be inlined below once Windows defines syslog port @@ -31,9 +30,9 @@ start() --background \ --exec /sbin/vsudd \ --make-pidfile --pidfile ${PIDFILE} \ - --stderr "${LOGFILE}" --stdout "${LOGFILE}" \ -- -inport "${DOCKER_PORT}:unix:/var/run/docker.sock" \ - ${SYSLOG_OPT} + ${SYSLOG_OPT} \ + -detach eend $? "Failed to start vsudd" } diff --git a/alpine/packages/vsudd/main.go b/alpine/packages/vsudd/main.go index 7cc0639e2..94da4faf9 100644 --- a/alpine/packages/vsudd/main.go +++ b/alpine/packages/vsudd/main.go @@ -5,6 +5,7 @@ import ( "fmt" "io" "log" + "log/syslog" "net" "os" "strconv" @@ -66,15 +67,24 @@ func main() { flag.Parse() if detach { - logFile, err := os.Create("/var/log/vsudd.log") + syslog, err := syslog.New(syslog.LOG_INFO|syslog.LOG_DAEMON, "vsudd") if err != nil { - log.Fatalln("Failed to open log file", err) + log.Fatalln("Failed to open syslog", err) } - log.SetOutput(logFile) + null, err := os.OpenFile("/dev/null", os.O_RDWR, 0) if err != nil { log.Fatalln("Failed to open /dev/null", err) } + + /* Don't do this above since we aren't yet forwarding + /* syslog (if we've been asked to) so the above error + /* reporting wants to go via the default path + /* (stdio). */ + + log.SetOutput(syslog) + log.SetFlags(0) + fd := null.Fd() syscall.Dup2(int(fd), int(os.Stdin.Fd())) syscall.Dup2(int(fd), int(os.Stdout.Fd())) From 916d920bfb6b6bdd8fd16920330c63447d5ac685 Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Fri, 27 May 2016 13:16:30 +0100 Subject: [PATCH 6/7] Direct syslog to log to /var/run/syslog.vsock on mac Avoid doing this on non-Docker-for-{Mac,Win} editions (which don't run vsudd) by checking for vsudd.pid and avoid doing it on Docker-for-Win (for now) by checking for /sys/bus/vmbus (as /etc/init.d/vsudd does too). Ideally we would just check for /var/run/syslog.vsock but this may not have arrived yet (typically vsudd is now started immediately prior to syslog and it forks via start-stop-daemon and thus before it creates the socket). Since syslogd will reopen as needed we don't want to delay boot either here or in the vsudd initscript to await the arrival of the socket. Signed-off-by: Ian Campbell --- alpine/etc/conf.d/syslog | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 alpine/etc/conf.d/syslog diff --git a/alpine/etc/conf.d/syslog b/alpine/etc/conf.d/syslog new file mode 100644 index 000000000..53ccb79d4 --- /dev/null +++ b/alpine/etc/conf.d/syslog @@ -0,0 +1,5 @@ +# Would prefer to check [ -S /var/run/syslog.vsock ] but it doesn't +# always exist by the time we get here starts. +if [ -e /var/run/vsudd.pid -a ! -d /sys/bus/vmbus ] ; then + SYSLOGD_OPTS="-R local:/var/run/syslog.vsock" +fi From 43e2030e31faf19c4edafb2713f2a681ee8dcbdb Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Mon, 4 Jul 2016 14:46:21 +0100 Subject: [PATCH 7/7] vsudd: Use RFC5425 scheme for syslog forwarding This means an ASCII MSG-LEN and a space, rather than a binary message length. Signed-off-by: Ian Campbell --- alpine/packages/vsudd/vsyslog.go | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/alpine/packages/vsudd/vsyslog.go b/alpine/packages/vsudd/vsyslog.go index 3bb599214..55de24ad1 100644 --- a/alpine/packages/vsudd/vsyslog.go +++ b/alpine/packages/vsudd/vsyslog.go @@ -7,8 +7,8 @@ package main import ( - "encoding/binary" "errors" + "fmt" "log" "net" "os" @@ -37,11 +37,12 @@ var ( lastMessage []byte ) -func checkedWrite(conn vConn, buf []byte) error { +/* rfc5425 like scheme, see section 4.3 */ +func rfc5425Write(conn vConn, buf []byte) error { - var l uint32 = uint32(len(buf)) + msglen := fmt.Sprintf("%d ", len(buf)) - err := binary.Write(conn, binary.LittleEndian, l) + _, err := conn.Write([]byte(msglen)) /* XXX todo, check for serious vs retriable errors */ if err != nil { console.Printf("Error in length write: %s", err) @@ -98,7 +99,7 @@ func forwardSyslogDatagram(buf []byte, portstr string) error { if lastMessage != nil { console.Printf("Replaying last message: %s", lastMessage) - err := checkedWrite(conn, lastMessage) + err := rfc5425Write(conn, lastMessage) if err != nil { conn.Close() continue @@ -109,7 +110,7 @@ func forwardSyslogDatagram(buf []byte, portstr string) error { currentConn = conn } - err := checkedWrite(conn, buf) + err := rfc5425Write(conn, buf) if err != nil { currentConn.Close() currentConn = nil