Subject: bin/1915: verbosity additions to dump(8)
To: None <gnats-bugs@gnats.netbsd.org>
From: Luke Mewburn <lukem@supp.cpr.itg.telecom.com.au>
List: netbsd-bugs
Date: 01/08/1996 19:45:00
>Number:         1915
>Category:       bin
>Synopsis:       verbosity additions to dump(8)
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    bin-bug-people (Utility Bug People)
>State:          open
>Class:          change-request
>Submitter-Id:   net
>Arrival-Date:   Mon Jan  8 04:05:01 1996
>Last-Modified:
>Originator:     Luke Mewburn
>Organization:
Luke Mewburn <luke.mewburn@itg.telstra.com.au>
>Release:        NetBSD-current-960105
>Environment:
>Description:
	dump(8) could use some more verbosity (IMHO) with information
	such as starting and ending time of a volume and the dump,
	transfer rate, etc.

	Also, the 'w' and 'W' options don't display the year, even
	though it is stored in /etc/dumpdates. This fixes that
	problem too.

	Here is an example output with my patch for the former applied.
	New lines are prefixed with '-->'

	DUMP: Date of this level 0 dump: Mon Jan  8 19:33:49 1996
	DUMP: Date of last level 0 dump: the epoch
	DUMP: Dumping /dev/rsd0a (/) to /dev/null
	DUMP: mapping (Pass I) [regular files]
	DUMP: mapping (Pass II) [directories]
	DUMP: estimated 104637 tape blocks on 2.69 tape(s).
  -->	DUMP: Volume 1 started at: Mon Jan  8 19:33:51 1996
	DUMP: dumping (Pass III) [directories]
	DUMP: dumping (Pass IV) [regular files]
	DUMP: Closing /dev/null
  -->	DUMP: Volume 1 completed at: Mon Jan  8 19:35:22 1996
  -->	DUMP: Volume 1 took 0:01:31
  -->	DUMP: Volume 1 transfer rate: 421K/s
	DUMP: Change Volumes: Mount volume #2
	DUMP: Is the new volume mounted and ready to go?: ("yes" or "no") yes
  -->	DUMP: Volume 2 started at: Mon Jan  8 19:35:58 1996
	DUMP: Volume 2 begins with blocks from inode 7629
	DUMP: Closing /dev/null
  -->	DUMP: Volume 2 completed at: Mon Jan  8 19:37:26 1996
  -->	DUMP: Volume 2 took 0:01:28
  -->	DUMP: Volume 2 transfer rate: 435K/s
	DUMP: Change Volumes: Mount volume #3
	DUMP: Is the new volume mounted and ready to go?: ("yes" or "no") yes
  -->	DUMP: Volume 3 started at: Mon Jan  8 19:38:47 1996
	DUMP: Volume 3 begins with blocks from inode 13785
	DUMP: 74.17% done, finished in 0:01
	DUMP: DUMP: 105280 tape blocks on 3 volumes
  -->	DUMP: Volume 3 completed at: Mon Jan  8 19:39:52 1996
  -->	DUMP: Volume 3 took 0:01:05
  -->	DUMP: Volume 3 transfer rate: 440K/s
  -->	DUMP: Date of this level 0 dump: Mon Jan  8 19:33:49 1996
  -->	DUMP: Date this dump completed:  Mon Jan  8 19:39:52 1996
  -->	DUMP: Average transfer rate: 432K/s
	DUMP: Closing /dev/null
	DUMP: DUMP IS DONE

	Notice how that I took a minute or so before typing 'yes'
	between volumes (I was playing moria in another virtual
	session :)

>How-To-Repeat:
>Fix:
	apply this patch

Index: dump.h
===================================================================
RCS file: /z/cvsroot/src/sbin/dump/dump.h,v
retrieving revision 1.1.1.1
diff -c -r1.1.1.1 dump.h
*** dump.h	1996/01/06 09:48:24	1.1.1.1
--- dump.h	1996/01/06 23:14:11
***************
*** 81,86 ****
--- 81,87 ----
  int	blockswritten;	/* number of blocks written on current tape */
  int	tapeno;		/* current tape number */
  time_t	tstart_writing;	/* when started writing the first tape block */
+ int	xferrate;	/* averaged transfer rate of all volumes */
  struct	fs *sblock;	/* the file system super block */
  char	sblock_buf[MAXBSIZE];
  long	dev_bsize;	/* block size of underlying disk device */
***************
*** 99,108 ****
  int	query __P((char *question));
  void	quit __P((const char *fmt, ...));
  void	set_operators __P((void));
  void	timeest __P((void));
  time_t	unctime __P((char *str));
  
! /* mapping rouintes */
  struct	dinode;
  long	blockest __P((struct dinode *dp));
  int	mapfiles __P((ino_t maxino, long *tapesize));
--- 100,110 ----
  int	query __P((char *question));
  void	quit __P((const char *fmt, ...));
  void	set_operators __P((void));
+ time_t	do_stats __P((void));
  void	timeest __P((void));
  time_t	unctime __P((char *str));
  
! /* mapping routines */
  struct	dinode;
  long	blockest __P((struct dinode *dp));
  int	mapfiles __P((ino_t maxino, long *tapesize));
Index: main.c
===================================================================
RCS file: /z/cvsroot/src/sbin/dump/main.c,v
retrieving revision 1.1.1.1
diff -c -r1.1.1.1 main.c
*** main.c	1996/01/06 09:48:25	1.1.1.1
--- main.c	1996/01/06 23:14:11
***************
*** 70,75 ****
--- 70,76 ----
  #include <stdio.h>
  #include <stdlib.h>
  #include <string.h>
+ #include <time.h>
  #include <unistd.h>
  
  #include "dump.h"
***************
*** 106,111 ****
--- 107,113 ----
  	register int ch;
  	int i, anydirskipped, bflag = 0, Tflag = 0, honorlevel = 1;
  	ino_t maxino;
+ 	time_t tnow;
  
  	spcl.c_date = 0;
  	(void)time((time_t *)&spcl.c_date);
***************
*** 388,393 ****
--- 390,396 ----
  
  	startnewtape(1);
  	(void)time((time_t *)&(tstart_writing));
+ 	xferrate = 0;
  	dumpmap(usedinomap, TS_CLRI, maxino - 1);
  
  	msg("dumping (Pass III) [directories]\n");
***************
*** 434,441 ****
  	if (pipeout)
  		msg("DUMP: %ld tape blocks\n",spcl.c_tapea);
  	else
! 		msg("DUMP: %ld tape blocks on %d volumes(s)\n",
! 		    spcl.c_tapea, spcl.c_volume);
  	putdumptime();
  	trewind();
  	broadcast("DUMP IS DONE!\7\7\n");
--- 437,450 ----
  	if (pipeout)
  		msg("DUMP: %ld tape blocks\n",spcl.c_tapea);
  	else
! 		msg("DUMP: %ld tape blocks on %d volume%s\n",
! 		    spcl.c_tapea, spcl.c_volume,
! 		    (spcl.c_volume == 1) ? "" : "s");
! 	tnow = do_stats();
! 	msg("Date of this level %c dump: %s", level,
! 		spcl.c_date == 0 ? "the epoch\n" : ctime(&spcl.c_date));
! 	msg("Date this dump completed:  %s", ctime(&tnow));
! 	msg("Average transfer rate: %ldK/s\n", xferrate / tapeno);
  	putdumptime();
  	trewind();
  	broadcast("DUMP IS DONE!\7\7\n");
Index: optr.c
===================================================================
RCS file: /z/cvsroot/src/sbin/dump/optr.c,v
retrieving revision 1.1.1.1
diff -c -r1.1.1.1 optr.c
*** optr.c	1996/01/06 09:48:25	1.1.1.1
--- optr.c	1996/01/06 23:14:12
***************
*** 512,518 ****
  		    sizeof(dtwalk->dd_name)) == 0)
  			continue;
  		date = (char *)ctime(&dtwalk->dd_ddate);
! 		date[16] = '\0';	/* blast away seconds and year */
  		lastname = dtwalk->dd_name;
  		dt = fstabsearch(dtwalk->dd_name);
  		dumpme = (dt != NULL &&
--- 512,519 ----
  		    sizeof(dtwalk->dd_name)) == 0)
  			continue;
  		date = (char *)ctime(&dtwalk->dd_ddate);
! 		date[24] = '\0';
! 		strcpy(date + 16, date + 19);	/* blast away seconds */
  		lastname = dtwalk->dd_name;
  		dt = fstabsearch(dtwalk->dd_name);
  		dumpme = (dt != NULL &&
Index: tape.c
===================================================================
RCS file: /z/cvsroot/src/sbin/dump/tape.c,v
retrieving revision 1.1.1.1
diff -c -r1.1.1.1 tape.c
*** tape.c	1996/01/06 09:48:25	1.1.1.1
--- tape.c	1996/01/06 23:14:12
***************
*** 65,70 ****
--- 65,71 ----
  #ifdef __STDC__
  #include <stdlib.h>
  #include <string.h>
+ #include <time.h>
  #include <unistd.h>
  #else
  int	write(), read();
***************
*** 121,126 ****
--- 122,130 ----
  
  char	(*nextblock)[TP_BSIZE];
  
+ static time_t tstart_volume;	/* time of volume start */
+ static int tapea_volume;	/* value of spcl.c_tapea at volume start */
+ 
  int master;		/* pid of master, for sending error signals */
  int tenths;		/* length of tape used per block written */
  static int caught;	/* have we caught the signal to proceed? */
***************
*** 239,244 ****
--- 243,272 ----
  	quit("Broken pipe\n");
  }
  
+ /*
+  * do_stats --
+  *	Update xferrate stats
+  */
+ time_t
+ do_stats()
+ {
+ 	time_t tnow, ttaken;
+ 	int blocks;
+ 
+ 	(void)time(&tnow);
+ 	ttaken = tnow - tstart_volume;
+ 	blocks = spcl.c_tapea - tapea_volume;
+ 	msg("Volume %d completed at: %s", tapeno, ctime(&tnow));
+ 	if (ttaken > 0) {
+ 		msg("Volume %d took %d:%02d:%02d\n", tapeno,
+ 		    ttaken / 3600, (ttaken % 3600) / 60, ttaken % 60); 
+ 		msg("Volume %d transfer rate: %ldK/s\n", tapeno,
+ 		    blocks / ttaken);
+ 		xferrate += blocks / ttaken;
+ 	}
+ 	return(tnow);
+ }
+ 
  static void
  flushtape()
  {
***************
*** 373,378 ****
--- 401,407 ----
  close_rewind()
  {
  	trewind();
+ 	(void)do_stats();
  	if (nexttape)
  		return;
  	if (!nogripe) {
***************
*** 518,523 ****
--- 547,554 ----
  
  	interrupt_save = signal(SIGINT, SIG_IGN);
  	parentpid = getpid();
+ 	tapea_volume = spcl.c_tapea;
+ 	(void)time(&tstart_volume);
  
  restore_check_point:
  	(void)signal(SIGINT, interrupt_save);
***************
*** 630,635 ****
--- 661,667 ----
  		spcl.c_flags |= DR_NEWHEADER;
  		writeheader((ino_t)slp->inode);
  		spcl.c_flags &=~ DR_NEWHEADER;
+ 		msg("Volume %d started at: %s", tapeno, ctime(&tstart_volume));
  		if (tapeno > 1)
  			msg("Volume %d begins with blocks from inode %d\n",
  				tapeno, slp->inode);
>Audit-Trail:
>Unformatted: