timestamp-output: like 'annotate-output' from ubuntu devscripts but in python

README.md

timestamp-output

Run a command and add timestamps to its standard in and standard out.

This annotates output the same way that annotate-output from the ubuntu devscripts does. The benefit of this over that is primarily in that it does not create a subprocess for every line read (annotate-output users date to get the timestamp).

The string _S_ is replaced in the format with 'O' or 'E' for stdout and stderr respectively.

Examples

• Simple

   $ timestamp-output -- echo hi world
   12:36:47 O: hi world
  
   $ timestamp-output --delta --
   [   0.003] hi world
  

• Sub-second timestamps

   $ timestamp-output --output-prefix="%H:%M:%S.%f _S_: " -- \
       sh -c 'echo hello stdout; echo hello stderr 1>&2'
   12:29:00.169712 E: hello stderr
   12:29:00.169829 O: hello stdout
  

• Delta timestamps

  By providing a output format with '%s' in it, you can get the time in seconds since command start. The '%s' can be anything that is accepted as a float format for printfi ('%.3s' to give 3 decimal places).

   $ timestamp-output --output-prefix="%M:%S.%f %s _S_: " -- \
       sh -c 'echo hello stdout; sleep 1; echo hello stderr 1>&2'
   39:38.121876 0.002955 O: hello stdout
   39:39.123261 1.004340 E: hello stderr
  

  To pad the delta in order to make decimal places line-up, use something like this:

   $ timestamp-output --output-prefix="[%6.2s] " -- \
       sh -c 'echo hi; sleep .5; echo mid; sleep 60; echo bye'
   [  0.00] hi
   [ 60.00] mid
   [ 60.50] bye
  

timestamp-output

#!/usr/bin/python3
"""timestamp-output

This annotates output the same way that annotate-output from
the ubuntu devscripts does.  The benefit of this over that is
primarily in that it does not create a subprocess for every
line read (annotate-output users `date` to get the timestamp)"""

import argparse
import datetime
import os
import re
import subprocess
import sys
import threading


START_TIME = datetime.datetime.now()
DELTA_FMT_RE = re.compile('(?P<tok>%(s|-?\d*.?\d+s))')

FD_STDOUT = 1
FD_STDERR = 2


def fp_readlines(fp, sizehint=None):
    if sizehint is None:
        sizehint = 1024
    leftover = bytes()
    while True:
        buf = os.read(fp, sizehint)
        consumed = buf == b''

        if leftover:
            buf = leftover + buf
            leftover = bytes()

        while True:
            end = buf.find(b'\n')
            if end != -1:
                yield buf[0:end+1]
                buf = buf[end+1:]
            else:
                leftover = buf
                break

        if consumed:
            break


def ftime(fmt, ts=None):
    if ts is None:
        ts = datetime.datetime.now()
    return datetime.datetime.strftime(ts, fmt)


def uftime(fmt, ts=None, ref=None):
    if ref is None:
        ref = START_TIME
    if ts is None:
        ts = datetime.datetime.now()
    match = DELTA_FMT_RE.search(fmt)
    if match:
        fmtstr = match.group('tok')
        fmtfloat = fmtstr[:-1] + "f"
        fmt = fmt.replace(
            fmtstr, fmtfloat % (ts - ref).total_seconds(), 1)
    return ftime(fmt, ts)


def needs_delta(fmt):
    return bool(DELTA_FMT_RE.search(fmt))


def addtime(fh_in, fh_out, fmt='%H:%M:%S '):
    if needs_delta(fmt):
        fmtfunc = uftime
    else:
        fmtfunc = ftime

    for line in fp_readlines(fh_in):
        os.write(fh_out, fmtfunc(fmt).encode() + line)

    return


def main():
    hmr = "%H:%M:%S"
    ymd = "%Y-%m-%d"
    def_out_fmt = hmr + " O: "
    def_err_fmt = hmr + " E: "
    delta_fmt = "[%8.3s] "
    date_delta_fmt = " ".join((ymd, hmr, delta_fmt))

    parser = argparse.ArgumentParser()
    parser.add_argument('-o', '--stdout-prefix',
                        dest='out_fmt', default=def_out_fmt,
                        help='the format prefix for stdout')
    parser.add_argument('-e', '--stderr-prefix',
                        dest='err_fmt', default=def_err_fmt,
                        help='the format prefix for stderr')
    group = parser.add_mutually_exclusive_group()
    group.add_argument('-O', '--output-prefix',
                       dest='all_fmt', default=None,
                       help='the format prefix for both out and err')
    mhelp = 'Shortcut for --output-prefix=' + delta_fmt.replace("%", "%%")
    group.add_argument('-d', '--delta', action='store_const',
                       dest='all_fmt', default=None, const=delta_fmt,
                       help=mhelp)
    mhelp = 'Shortcut for --output-prefix=' + date_delta_fmt.replace("%", "%%")
    group.add_argument('-D', '--date-delta', action='store_const',
                       dest='all_fmt', default=None, const=date_delta_fmt,
                       help=mhelp)

    parser.add_argument('cmd', nargs='+', default=[])

    args = parser.parse_args()

    if args.all_fmt:
        if args.out_fmt != def_out_fmt or args.err_fmt != def_err_fmt:
            sys.stderr.write(
                "--stdout-prefix/--stderr-prefix are "
                "incompatible with --output-prefix and --delta.\n")
            sys.exit(1)
        args.out_fmt = args.all_fmt.replace("_S_", "O")
        args.err_fmt = args.all_fmt.replace("_S_", "E")

    threads = []
    cmd = args.cmd

    out_r, out_w = os.pipe()
    err_r, err_w = os.pipe()

    try:
        t = threading.Thread(
            target=addtime, args=(out_r, FD_STDOUT, args.out_fmt))
        t.start()
        threads.append(t)

        t = threading.Thread(
            target=addtime, args=(err_r, FD_STDERR, args.err_fmt))
        t.start()
        threads.append(t)

        sp = subprocess.Popen(cmd, stdout=out_w, stderr=err_w)
        sp.communicate()
        rc = sp.returncode

        sys.exit(rc)

    finally:
        os.close(out_w)
        os.close(err_w)

        for t in threads:
            t.join()

        os.close(out_r)
        os.close(err_r)


main()

timestamp-output.go

package main

import (
	"bufio"
	"fmt"
	"io"
	"log"
	"os"
	"os/exec"
	"strings"
	"syscall"
	"time"
)

func readWrite(reader io.ReadCloser, writer io.WriteCloser,
	tsfunc func() []byte, c chan error) {
	defer reader.Close()
	defer writer.Close()
	bufReader := bufio.NewReader(reader)
	for {
		buf, err := bufReader.ReadBytes('\n')
		if err != nil {
			if err != io.EOF && err != io.ErrClosedPipe {
				switch err.(type) {
				case *os.PathError:
				default:
					c <- err
					return
				}
			}
			c <- nil
			return
		}
		_, err = writer.Write(append(append(tsfunc(), ' '), buf...))
		if err != nil {
			c <- err
		}
	}
	c <- nil
}

func getStamp() []byte {
	return []byte(time.Now().Format("15:04:05"))
}

func main() {
	var cmd []string = []string{}
	var myargs []string = []string{}
	var start int = 1
	c := make(chan error)
	if len(os.Args) == 1 {
		fmt.Printf("Fail\n")
		os.Exit(1)
	}
	for n, arg := range os.Args[1:] {
		// fmt.Printf("%d: %s\n", n, arg)
		if arg == "--" {
			start = n + 2
			break
		}
		if !strings.HasPrefix(arg, "-") {
			start = n + 1
			break
		}
	}
	cmd = os.Args[start:]
	myargs = os.Args[1:start]

	// TODO: use myargs for:
	//   -j --join: join stdout and stdin
	//   -e --elapsed: show [  0.00000] like stamps.
	_ = myargs
	eCmd := exec.Command(cmd[0], cmd[1:]...)
	cmdStdout, err := eCmd.StdoutPipe()
	if err != nil {
		fmt.Printf("ERROR: %s\n", err)
		log.Fatal(err)
	}
	cmdStderr, err := eCmd.StderrPipe()
	if err != nil {
		fmt.Printf("ERROR: %s\n", err)
		log.Fatal(err)
	}
	myStdin := os.NewFile(uintptr(syscall.Stdin), "/dev/stdin")
	eCmd.Stdin = myStdin

	eCmd.Start()
	if err != nil {
		fmt.Printf("error: %s", err)
		os.Exit(1)
	}

	myStdout := os.NewFile(uintptr(syscall.Stdout), "/dev/stdout")
	myStderr := os.NewFile(uintptr(syscall.Stderr), "/dev/stderr")

	myStderr.Write(getStamp())
	myStderr.Write([]byte(" "))
	myStderr.Write([]byte(fmt.Sprintf("%s\n", cmd)))
	myStdout.Sync()

	// myReadCloser := io.ReadCloser{myStdin.Read, myStdin.Close}
	go readWrite(cmdStdout, myStdout, getStamp, c)
	go readWrite(cmdStderr, myStderr, getStamp, c)
	// go readWrite(myStdin, cmdStdin, func() []byte { return []byte{} }, c)

	err = eCmd.Wait()
	if err != nil {
		fmt.Printf("error: %v", err)
		// FIXME: how do i get exit code ?
		if exiterr, ok := err.(*exec.ExitError); ok {
			if status, ok := exiterr.Sys().(syscall.WaitStatus); ok {
				i := status.ExitStatus()
				os.Exit(i)
			}
		} else {
			os.Exit(1)
		}
	}
	for i := 0; i < 2; i++ {
		err := <-c
		if err != nil {
			fmt.Printf("ERROR: %s\n", err)
		}
		fmt.Printf("not error: %s\n", err)
	}
	os.Exit(0)
}