From 7dd7b0c0da6a8877f990a09a5bbdeb795321b21e Mon Sep 17 00:00:00 2001 From: Ian Campbell Date: Fri, 1 Jul 2016 11:49:18 +0100 Subject: [PATCH] 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])) + } + } +}