Re: suggested addition to 'date'

On 2006-08-11 20:03, Julian Elischer <julian_at_elischer.org> wrote:
> At various times I've wanted to add timestamps to logfiles as they are 
> generated..
> 
> usually this has involved perl or something to do it.

Indeed, I use a tiny Perl script to do this:

     1  #!/usr/bin/perl -wT
     2  #
     3  # A utility to timestamp logs.  Useful for piping the output of long
     4  # running commands through it, before saving to a file.
     5  #
     6  # $Id: tslog,v 1.4 2006/03/30 15:00:49 giorgos Exp $
     7  
     8  use strict;
     9  use POSIX qw(strftime);
    10  use Time::HiRes qw( gettimeofday );
    11  
    12  my ($line, $microseconds, $now, $seconds, $tag);
    13  
    14  if ($#ARGV == 0) {
    15      $tag = $ARGV[0] . " --- ";
    16  } else {
    17      $tag = "";
    18  }
    19  
    20  $| = 1;
    21  while (defined($line = <STDIN>)) {
    22      chomp $line;
    23      ($seconds, $microseconds) = gettimeofday;
    24      $now = strftime "%Y-%m-%d %H:%M:%S", gmtime($seconds);
    25      printf "%s%s.%06d - %s\n", $tag, $now, $microseconds, $line;
    26  }

The $tag part is there so you can do stuff like:

$ ls -l | tslog FOO | head
FOO --- 2006-08-12 03:12:17.954283 - total 386
FOO --- 2006-08-12 03:12:17.954784 - -rw-rw-r--   1 giorgos  giorgos  -      1 Aug  9 20:10 #kot#
FOO --- 2006-08-12 03:12:17.955014 - drwxrwxr-x   2 giorgos  giorgos  -    512 Aug  8 13:27 CVS
FOO --- 2006-08-12 03:12:17.955378 - drwxrwxr-x   5 giorgos  giorgos  -    512 Oct 23  2004 GNUstep
FOO --- 2006-08-12 03:12:17.957108 - -rw-rw-r--   1 giorgos  giorgos  -   6945 Jul 10 15:59 GOTHMOG
FOO --- 2006-08-12 03:12:17.957475 - drwx------   4 giorgos  giorgos  -   1536 Aug 12 06:10 Mail
FOO --- 2006-08-12 03:12:17.959169 - -rw-------   1 giorgos  giorgos  - 226927 Aug 12 05:29 Mailbox
FOO --- 2006-08-12 03:12:17.959528 - -rw-------   1 giorgos  giorgos  -   4553 May 23 19:22 NOTES
FOO --- 2006-08-12 03:12:17.961219 - drwxr-xr-x   5 giorgos  giorgos  -    512 Jun 22 16:13 News
FOO --- 2006-08-12 03:12:17.961576 - drwxrwxr-x   2 giorgos  giorgos  -    512 May 30 14:30 RCS
$

which includes the "FOO --- " prefix at the beginning of default output:

$ ls -l | tslog | head
2006-08-12 03:12:26.670881 - total 386
2006-08-12 03:12:26.671382 - -rw-rw-r--   1 giorgos  giorgos  -      1 Aug  9 20:10 #kot#
2006-08-12 03:12:26.671608 - drwxrwxr-x   2 giorgos  giorgos  -    512 Aug  8 13:27 CVS
2006-08-12 03:12:26.673455 - drwxrwxr-x   5 giorgos  giorgos  -    512 Oct 23  2004 GNUstep
2006-08-12 03:12:26.673926 - -rw-rw-r--   1 giorgos  giorgos  -   6945 Jul 10 15:59 GOTHMOG
2006-08-12 03:12:26.675527 - drwx------   4 giorgos  giorgos  -   1536 Aug 12 06:10 Mail
2006-08-12 03:12:26.675963 - -rw-------   1 giorgos  giorgos  - 226927 Aug 12 05:29 Mailbox
2006-08-12 03:12:26.677567 - -rw-------   1 giorgos  giorgos  -   4553 May 23 19:22 NOTES
2006-08-12 03:12:26.678002 - drwxr-xr-x   5 giorgos  giorgos  -    512 Jun 22 16:13 News
2006-08-12 03:12:26.679604 - drwxrwxr-x   2 giorgos  giorgos  -    512 May 30 14:30 RCS
$

> finally I broke down and just added  a small bit to date(1)
> 
> the -s option tells date to add a timestamp on the front of every line 
> read in through stdin

I'm not suggesting that this is not a worthwhile addition, but it does
have some minor glitches that a Perl version doesn't need to work
around.  The following part, for example, is a bit buggy unless I'm not
reading it correctly:

> +     if (sflag) {
> +             char linebuf[2048];
> +             time_t otval = 0;
> +
> +             while (fgets(linebuf, 2048, stdin)) {
> +                     if (!rflag && time(&tval) == -1)
> +                             err(1, "time");
> +
> +                     if (tval != otval) {
> +                             lt = *localtime(&tval);
> +                             badv = vary_apply(v, &lt);
> +                             if (badv) {
> +                                     fprintf(stderr, "%s: Cannot apply date adjustment\n",
> +                                             badv->arg);
> +                                     vary_destroy(v);
> +                                     usage();
> +                             }
> +                             (void)strftime(buf, sizeof(buf), format, &lt);
> +                             otval = tval;
> +                     }
> +                     (void)printf("%s", buf);
> +                     fputs(linebuf, stdout);
> +                     if (fflush(stdout)) {
> +                             err(1, "stdout");
> +                     }
> +             }

If you receive lines with a length greater than 2048 - strlen(length of
timestamp) there is a case that this will print output like:

    Fri Aug 11 19:53:34 PDT 2006: ...lots of stuff here...Fri Aug 11 19:53:34 PDT 2006: ...

To make sure that lines are not concatenated too early and still check
that linebuf[] is not overflow, we may have to use something like the
following (untested) patch:

	...

        if (sflag) {
                char linebuf[sizeof(buf)];
		time_t otval = 0;
		int complete = 0;
		size_t len;

		while (fgets(linebuf, 2048, stdin) != NULL) {
			if (rlfag == 0 && time(&tval) == -1)
				err(1, "time");

			if (complete != 0 && tval != otval) {
			        lt = *localtime(&tval);
			        badv = vary_apply(v, &lt);
			        if (badv) {
			                fprintf(stderr, "%s: Cannot apply date adjustment\n",
			                        badv->arg);
			                vary_destroy(v);
			                usage();
			        }
			        (void)strftime(buf, sizeof(buf), format, &lt);
			        otval = tval;
			}
			if (complete != 0) {
				(void)printf("%s", buf);
				complete = 0;
			}
			fputs(linebuf, stdout);
			if (fflush(stdout))
				err(1, "stdout");

			/*
			 * If we just printed a newline, make sure we
			 * print a new timestamp when we loop back for
			 * the next batch of input characters.
			 */
			len = strlen(linebuf);
			if (linebuf[len - 1] == '\n')
				complete = 1;
		}
	} else ...