Import TBBT (NFS trace replay).
[bluesky.git] / TBBT / trace_play / sfs_c_chd.c.old.2
diff --git a/TBBT/trace_play/sfs_c_chd.c.old.2 b/TBBT/trace_play/sfs_c_chd.c.old.2
new file mode 100644 (file)
index 0000000..a8c71f7
--- /dev/null
@@ -0,0 +1,2294 @@
+#ifndef lint
+static char sfs_c_chdSid[] = "@(#)sfs_c_chd.c  2.1     97/10/23";
+#endif
+
+/*
+ *   Copyright (c) 1992-1997,2001 by Standard Performance Evaluation Corporation
+ *     All rights reserved.
+ *             Standard Performance Evaluation Corporation (SPEC)
+ *             6585 Merchant Place, Suite 100
+ *             Warrenton, VA 20187
+ *
+ *     This product contains benchmarks acquired from several sources who
+ *     understand and agree with SPEC's goal of creating fair and objective
+ *     benchmarks to measure computer performance.
+ *
+ *     This copyright notice is placed here only to protect SPEC in the
+ *     event the source is misused in any manner that is contrary to the
+ *     spirit, the goals and the intent of SPEC.
+ *
+ *     The source code is provided to the user or company under the license
+ *     agreement for the SPEC Benchmark Suite for this product.
+ */
+
+/*****************************************************************
+ *                                                               *
+ *     Copyright 1991,1992  Legato Systems, Inc.                *
+ *     Copyright 1991,1992  Auspex Systems, Inc.                *
+ *     Copyright 1991,1992  Data General Corporation            *
+ *     Copyright 1991,1992  Digital Equipment Corporation       *
+ *     Copyright 1991,1992  Interphase Corporation              *
+ *     Copyright 1991,1992  Sun Microsystems, Inc.              *
+ *                                                               *
+ *****************************************************************/
+
+/*
+ * -------------------------- sfs_c_chd.c -------------------------
+ *
+ *      The sfs child.  Routines to initialize child parameters,
+ *     initialize test directories, and generate load.
+ *
+ *.Exported_Routines
+ *     void child(int, float, int, char *);
+ *     void init_fileinfo(void);
+ *     void init_counters(void);
+ *     sfs_fh_type * randfh(int, int, uint_t, sfs_state_type,
+ *                             sfs_file_type);
+ *     int check_access(struct *stat)
+ *     int check_fh_access();
+ *
+ *.Local_Routines
+ *     void check_call_rate(void);
+ *     void init_targets(void);
+ *     void init_dirlayout(void);
+ *     void init_rpc(void);
+ *     void init_testdir(void);
+ *     int do_op(void);
+ *     int op(int);
+ *
+ *.Revision_History
+ *     21-Aug-92       Wittle          randfh() uses working set files array.
+ *                                     init_fileinfo() sets up working set.
+ *      02-Jul-92      Teelucksingh    Target file size now based on peak load
+ *                                     instead of BTDT.
+ *     04-Jan-92       Pawlowski       Added raw data dump hooks.
+ *     16-Dec-91       Wittle          Created.
+ */
+
+
+/*
+ * -------------------------  Include Files  -------------------------
+ */
+
+/*
+ * ANSI C headers
+ */
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <errno.h>
+#include <math.h>
+#include <signal.h>
+
+#include <sys/types.h>
+#include <sys/stat.h> 
+#include <unistd.h>
+
+#include "sfs_c_def.h"
+#include "sfs_m_def.h"
+#include "rfs_c_def.h"
+#include "generic_hash.h"
+#include "nfsd_nfsfh_cust.h"
+
+extern struct hostent   *Server_hostent;
+
+#define PROB_SCALE 1000L
+#define _M_MODULUS 2147483647L /* (2**31)-1 */
+
+#define _GROUP_DIVISOR 500
+#define _FILES_PER_GROUP 4
+#define _MIN_GROUPS 12
+#define _WORKING_SET_AT_25_OPS_PER_SEC 975
+
+/*
+ * -----------------------  External Definitions  -----------------------
+ */
+extern uint32_t    biod_clnt_call(CLIENT *, uint32_t, xdrproc_t, void *);
+extern enum clnt_stat proc_header(CLIENT *cl, xdrproc_t xdr_results, void *results_ptr);
+extern int  biod_poll_wait(CLIENT *, uint32_t);
+extern enum clnt_stat get_areply_udp (CLIENT * cl, uint32_t *xid, struct timeval *timeout);
+extern char * parse_name (char * t, char * buf);
+
+/* forward definitions for local functions */
+static int init_rpc(void);
+
+/* RFS: forward definitions for local functions */
+void init_ops(void);
+static void init_signal();
+extern void init_file_system (void);
+extern void init_dep_tab (void);
+static void read_trace(char * trace_file);
+static void read_fh_map();
+static void init_play (char * mount_point);
+static void trace_play(void);
+static void print_result(void);
+static int get_nextop(void);
+static int check_timeout(void);
+static struct biod_req * get_biod_req(int dep_tab_index);
+static int lookup_biod_req (int xid);
+static void init_time_offset(void);
+static void adjust_play_window (int flag, int * poll_timeout);
+static int poll_and_get_reply (int usecs);
+static char * nfs3_strerror(int status);
+static void check_clock(void);
+static double time_so_far1(void);
+static double get_resolution(void);
+static void usage(void);
+void init_dep_tab_entry (int dep_index);
+extern fh_map_t * lookup_fh (char * trace_fh );
+static inline void finish_request (int biod_index, int dep_index, int status);
+static void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line);
+
+/*
+ * -------------  Per Child Load Generation Rate Variables  -----------
+ */
+static uint_t Calls_this_period; /* calls made during the current run period */
+static uint_t Calls_this_test; /* calls made during the test so far */
+static uint_t Reqs_this_period;        /* reqs made during the current run period */
+static uint_t Reqs_this_test;  /* reqs made during the test so far */
+static uint_t Sleep_msec_this_test; /* msec slept during the test so far */
+static uint_t Sleep_msec_this_period;
+static uint_t Previous_chkpnt_msec; /* beginning time of current run period */
+static int Target_sleep_mspc;  /* targeted sleep time per call */
+
+static char io_buf[BUFSIZ];    /* io buffer for print out messages */
+
+char * sfs_Myname;
+int     Log_fd;                         /* log fd */
+char    Logname[NFS_MAXNAMLEN];         /* child processes sync logfile */
+int    Validate = 0;                                   /* fake variable */
+int Child_num = 0;                                             /* fake: child index */
+int Tcp = 0;                                                   /* We implement UDP first */
+int Client_num = 1;                                            /* fake: number of client */
+uid_t Real_uid;
+gid_t Cur_gid;
+uid_t Cur_uid;
+/*
+ * -------------------------  SFS Child  -------------------------
+ */
+
+void print_usage()
+{
+       printf("sfs3 hostname:mount_dir trace_file fh_map_file\n");
+       exit;
+}
+
+void read_dep_tab()
+{
+#ifdef NO_DEPENDENCY_TABLE
+       int i;
+       char * line;
+       char * trace_fh;
+       fh_map_t * fh_map_entry;
+       int req_num_with_new_fh = 0;
+       int     req_num_with_discard_fh = 0;
+       int req_num_with_init_fh =0;
+
+       for (i=0; i<memory_trace_size; i++) {
+               line = memory_trace[i].line;
+               if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='C') {
+                       trace_fh = strstr (line, "fh");
+                       RFS_ASSERT (trace_fh);
+                       trace_fh += 3;
+                       fh_map_entry = lookup_fh (trace_fh);
+                       if (fh_map_entry && (fh_map_entry->flag==FH_MAP_FLAG_DISCARD) )  {
+                               req_num_with_discard_fh ++;
+                               continue;
+                       }
+                       if (fh_map_entry)
+                               req_num_with_init_fh ++;
+                       else
+                               req_num_with_new_fh ++;
+
+                       dep_tab[dep_tab_size].disk_index = memory_trace[i].disk_index;
+                       dep_tab[dep_tab_size].line = memory_trace[i].line;
+                       if ((dep_tab_size%100000)==0)
+                               printf ("dep_tab[%d].disk_index %d = memory_trace[%d].disk_index %d\n", dep_tab_size, dep_tab[dep_tab_size].disk_index, i, memory_trace[i].disk_index);
+                       dep_tab_size ++;
+               }
+       }
+#else
+       RFS_ASSERT (0);
+#endif
+       printf ("read_dep_tab, req_num_with_init_fh %d req_num_with_new_fh %d discard %d\n", req_num_with_init_fh, req_num_with_new_fh, req_num_with_discard_fh);
+}
+
+void init_profile()
+{
+       memset (&total_profile, 0, sizeof(total_profile));
+
+       memset (&execute_next_request_profile, 0, sizeof(execute_next_request_profile));
+       memset (&valid_get_nextop_profile, 0, sizeof(valid_get_nextop_profile));
+       memset (&invalid_get_nextop_profile, 0, sizeof(invalid_get_nextop_profile));
+       memset (&prepare_argument_profile, 0, sizeof(prepare_argument_profile));
+       memset (&biod_clnt_call_profile, 0, sizeof(biod_clnt_call_profile));
+
+       memset (&receive_next_reply_profile, 0, sizeof(receive_next_reply_profile));
+       memset (&valid_poll_and_get_reply_profile, 0, sizeof(valid_poll_and_get_reply_profile));
+       memset (&invalid_poll_and_get_reply_profile, 0, sizeof(invalid_poll_and_get_reply_profile));
+       memset (&decode_reply_profile, 0, sizeof(decode_reply_profile));
+       memset (&check_reply_profile, 0, sizeof(check_reply_profile));
+       memset (&add_create_object_profile, 0, sizeof(add_create_object_profile));
+
+       memset (&check_timeout_profile, 0, sizeof(check_timeout_profile));
+       memset (&adjust_play_window_profile, 0, sizeof(adjust_play_window_profile));
+}
+
+int main(int argc, char ** argv)
+{
+       extern char * optarg;
+       char tracefile[256];
+       int i;
+       int memory_trace_size;
+
+       if (argc==2 && !strcmp(argv[1],"-help")) {
+               print_usage();
+               exit(0);
+       }
+
+       check_clock();
+    getmyhostname(lad_hostname, HOSTNAME_LEN);
+
+    init_ops();
+       /*
+        * Get the uid and gid information.
+        */
+       Real_uid = getuid();
+       Cur_gid = getgid();
+       //Real_uid = 513;
+       //Cur_gid = 513;
+
+       Nfs_timers = Nfs_udp_timers;
+
+       init_file_system ();
+
+       init_signal();
+       //init_play (argv[1]);
+       init_play ("capella:/p5/RFSFS");
+       init_profile();
+       init_fh_map();
+       //read_fh_map (argv[3]);
+       read_fh_map ("fh-path-map");
+       init_dep_tab();                 /* and  dep_tab_size */
+       //read_trace (argv[2]);
+       read_trace ("anon-lair62-011130-1100.txt");
+       stage = READ_DEP_TAB_STAGE;
+       read_dep_tab();
+
+       for (i=0; i<dep_tab_size; i++) {
+               RFS_ASSERT (dep_tab[i].flag == DEP_FLAG_FREE) 
+               init_dep_tab_entry (i);
+       }
+       stage = TRACE_PLAY_STAGE;
+       init_time_offset();
+       trace_play ();
+       print_result();
+       printf("ffff\n");
+}
+
+void init_ops (void)
+{
+       Ops = nfsv3_Ops;
+       nfs_version = NFS_V3;
+}
+
+/* Set up the signal handlers for all signals */
+void init_signal()
+{
+#if (defined(_XOPEN_SOURCE) || defined(USE_POSIX_SIGNALS))
+       struct sigaction sig_act, old_sig_act;
+
+       /* use XOPEN signal handling */
+
+       sig_act.sa_handler = generic_catcher;
+       (void)sigemptyset(&sig_act.sa_mask);
+       sig_act.sa_flags = 0;
+
+       /* signals handlers for signals used by sfs */
+       sig_act.sa_handler = sfs_cleanup;
+       if (sigaction(SIGINT,&sig_act,&old_sig_act) == -1) {
+           perror("sigaction failed: SIGINT");
+           exit(135);
+       }
+
+       sig_act.sa_handler = sfs_cleanup;
+       if (sigaction(SIGTERM,&sig_act,&old_sig_act) != 0)  {
+           perror("sigaction failed: SIGTERM");
+           exit(137);
+       }
+#else
+    /* signals handlers for signals used by sfs */
+    (void) signal(SIGINT, sfs_cleanup);
+    // RFS (void) signal(SIGALRM, sfs_alarm);
+       (void) signal(SIGTERM, sfs_cleanup);
+#endif
+}
+
+void
+init_play (
+    char       * mount_point)          /* Mount point for remote FS */
+{
+    char       namebuf[NFS_MAXNAMLEN] = "trace_play";  /* unique name for this program */
+    CLIENT *   mount_client_ptr;       /* Mount client handle */
+
+       if (!rfs_debug);
+       (void) setvbuf(stderr, io_buf, _IOLBF, BUFSIZ);
+
+    sfs_Myname = namebuf;
+
+    /*
+     * May require root priv to perform bindresvport operation
+     */
+    mount_client_ptr = lad_getmnt_hand(mount_point);
+    if (mount_client_ptr == NULL) {
+               exit(145);
+    }
+
+    /*
+     * should be all done doing priv port stuff
+     */
+
+    if (init_rpc() == -1) {
+               (void) fprintf(stderr, "%s: rpc initialization failed\n", sfs_Myname);
+               (void) generic_kill(0, SIGINT);
+               exit(146);
+    }
+
+
+    /*
+     * finish all priv bindresvport calls
+     * reset uid
+     */
+    if (setuid(Real_uid) != (uid_t)0) {
+       (void) fprintf(stderr,"%s: %s%s", sfs_Myname,
+           "cannot perform setuid operation.\n",
+           "Do `make install` as root.\n");
+    }
+
+    init_mount_point(0, mount_point, mount_client_ptr);
+
+
+    /*
+     * Cleanup client handle for mount point
+     */
+    clnt_destroy(mount_client_ptr);
+
+       init_counters();
+       
+
+}
+
+void read_trace (char * tracefile)
+{
+       FILE * fp;
+       char buf[1024];
+       // char * t=buf;        
+       int disk_index=0;
+
+       fp = fopen(tracefile, "r");
+       RFS_ASSERT (fp!=NULL);
+       while (fgets(buf, 1024, fp)) {
+               //printf ("buf: %s buf[36] %c\n", buf, buf[36]);
+               //if (buf[36]=='C' || strstr(buf, "create") || strstr(buf, "lookup")) {
+#ifdef REDUCE_MEMORY_TRACE_SIZE
+               if (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='C' || strstr(buf, "create") || 
+                       strstr(buf, "mkdir") || strstr(buf, "symlink") || strstr(buf, "mknod") || strstr(buf, "lookup")) {
+#endif
+                       if (!((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH)))
+                               printf("strlen(buf) %d buf %s \n", strlen(buf), buf);
+                       RFS_ASSERT ((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH));
+
+                       /* store the request to memory */
+                       strcpy (memory_trace[memory_trace_size].line, buf);
+                       memory_trace[memory_trace_size].disk_index = disk_index;
+                       memory_trace_size ++;
+
+                       if (memory_trace_size >= MAX_MEMORY_TRACE_LINES) {
+                               printf ("memory trace size %d is not enough\n", MAX_MEMORY_TRACE_LINES);
+                               break;
+                       }
+                       if ((disk_index%100000)==0)
+                               fprintf(stderr, "%d disk trace parsed, store %d trace lines to memory\n", disk_index, memory_trace_size);
+#ifdef REDUCE_MEMORY_TRACE_SIZE
+               } else {
+                       RFS_ASSERT (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
+               }
+#endif
+               disk_index ++;
+       };
+
+       fprintf(stderr, "total %d disk lines %d memory lines \n", disk_index, memory_trace_size );
+
+}
+
+
+#ifdef REDUCE_MEMORY_TRACE_SIZE
+inline int disk_index_to_memory_index (int disk_index)
+{
+       static int memory_index = 0;
+       if (disk_index > memory_trace[memory_index].disk_index) {
+               while (memory_trace[memory_index].disk_index < disk_index) {
+                       memory_index++;
+                       RFS_ASSERT (memory_index < MAX_MEMORY_TRACE_LINES);
+               }
+       };
+       if (disk_index < memory_trace[memory_index].disk_index) {
+               while (memory_trace[memory_index].disk_index > disk_index) {
+                       memory_index--;
+                       RFS_ASSERT (memory_index >=0);
+               }
+       };
+
+       RFS_ASSERT (disk_index == memory_trace[memory_index].disk_index);
+       return memory_index;
+}
+#else
+#define disk_index_to_memory_index(disk_index) disk_index
+#endif
+
+#define get_line_by_disk_index(disk_index) \
+       memory_trace[disk_index_to_memory_index(disk_index)].line
+
+inline char * find_reply_line (char * command_line, int cur_disk_index)
+{
+       int i;
+       char * line;
+       char * p;
+       int request_memory_index = disk_index_to_memory_index (cur_disk_index);
+       for (i=request_memory_index+1; i<request_memory_index+MAX_COMMAND_REPLY_DISTANCE && i<MAX_MEMORY_TRACE_LINES; i++) {
+               line = memory_trace[i].line;
+               if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R') {
+               p = strchr (&line[TRACE_MSGID_POS], ' ');
+           RFS_ASSERT (p);
+                       if (!strncmp(&line[TRACE_MSGID_POS], &command_line[TRACE_MSGID_POS], p-&(line[TRACE_MSGID_POS]))) 
+                               return line;
+               }
+       }
+       return NULL;
+}
+
+inline int find_reply_status (char * line)
+{
+       char * p;
+       int i=0;
+
+       //printf ("line %s  flag %c\n", line, line[TRACE_COMMAND_REPLY_FLAG_POS]);
+       RFS_ASSERT (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
+       if (!strstr(line, "OK")) {
+               p=strstr(line, " 6 read ");
+               if (p) {
+                       p+=strlen(" 6 read ");
+               } else {
+                       p = strstr (line, "status=XXX");
+                       RFS_ASSERT (p);
+                       p--;
+                       RFS_ASSERT (*p==' ');
+                       while (*p==' ')
+                               p--;
+                       while (*p!=' ') {
+                               p--;
+                       }
+                       p++;
+               }
+               sscanf (p, "%x", &i);
+               if ((i<=0) || (i>10000))
+                       printf("line %s\n", line);
+               RFS_ASSERT (i>0 && i<10009);
+       }
+       return i;
+}
+
+inline char * find_reply_trace_fh (char * line)
+{
+       char * p;       
+       p = strstr (line, "OK fh");
+       if (!p)
+               printf ("find_reply_trace_fh line %s\n", line);
+       RFS_ASSERT (p);
+       return p+6;
+}
+
+inline int disk_index_to_dep_index(int cur_dep_index, int disk_index)
+{
+       int i;
+       for (i=cur_dep_index; i>min_dep_index; i--) {
+               if (dep_tab[i].disk_index == disk_index)
+                       return i;
+       } 
+       RFS_ASSERT (0);
+}
+
+inline int is_play_candidate (int dep_index)
+{
+#ifndef TAKE_CARE_CREATE_MODE_BY_DAN
+       int trace_reply_status;
+       char * reply_line;
+       if ((dep_tab[dep_index].proc==CREATE)) {
+               /* for a failed create in trace, trace_replay just ignore */
+               reply_line = find_reply_line (dep_tab[dep_index].line, dep_tab[dep_index].disk_index);
+               if (reply_line == NULL) {
+                       if (dependency_debug)
+                               printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
+                       trace_reply_status = NFS3_OK;
+               } else 
+                       trace_reply_status = find_reply_status (reply_line);
+               /* many time the trace create fail due to access control, but trace_play will success because our access control
+                * may be loose (all uid/gid is mapped to single one 513:513, so we just skip these requests 
+                */
+               if ((dep_tab[dep_index].proc == CREATE) && (trace_reply_status!=NFS3_OK)) {
+                       if (dependency_debug)
+                               printf ("disk[%d] ignore failed create in trace, trace_reply_status %d line %s", dep_tab[dep_index].disk_index, trace_reply_status, dep_tab[dep_index].line);
+                       failed_create_command_num ++;
+                       return FALSE;
+               }
+       }
+#endif
+#ifndef TAKE_CARE_SYMBOLIC_LINK
+       if ((dep_tab[dep_index].proc==READLINK)) { /* send request */
+               skipped_readlink_command_num ++;
+               return FALSE;
+       }
+#endif
+#ifndef TAKE_CARE_CUSTOM_COMMAND
+       /* this line has a file handle which should belong to discard but it is not
+        * the file handle directly appears as parent directory in a lookup request
+        * the return value is NOENT, the parent directory should have been initialized
+        * but the initialization code just ignored all lookup request which didn't success
+        * including NOENT even though the parent directory is still valid.
+        */
+       if ((dep_tab[dep_index].disk_index==262213 ||
+                dep_tab[dep_index].disk_index==214402          )) {
+               skipped_custom_command_num++;
+               return FALSE;
+       }
+#endif
+       return TRUE;
+}
+
+inline int is_dir_op (int proc)
+{
+       switch (proc) {
+       case MKDIR:
+       case CREATE:
+       case LINK:
+       case SYMLINK:
+       case MKNOD:
+       case REMOVE:
+       case RMDIR:
+       case RENAME:
+               return 1;
+       default:
+               return 0;
+       }
+}      
+
+inline int is_create_op (int proc)
+{
+       if (proc==CREATE || proc==MKDIR || proc==LINK || proc==SYMLINK || proc==MKNOD || proc==RENAME)
+               return 1;
+       return 0;
+}
+
+inline int is_delete_op (int proc)
+{
+       if (proc==REMOVE || proc==RMDIR || proc==RENAME)
+               return 1;
+       return 0;
+}      
+
+inline char * find_lead_trace_fh(int proc, char * line)
+{
+       char * p;
+       /* check the file handle availability */ 
+       p = strstr (line, "fh");
+       RFS_ASSERT (p);
+       p+=3; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
+       return p;
+}
+
+inline char * find_another_trace_fh(int proc, char * line)
+{
+       char * p;
+       /* check the file handle availability */ 
+       p = strstr (line, "fh2");
+       RFS_ASSERT (p);
+       p+=4; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
+       return p;
+}
+
+/* return the index of next request in dep_tab.
+ * Return -1 if there is no suitable request to send
+ */
+inline int get_nextop(void)
+{
+       int i,j, k;
+       int * t;
+       static int dep_index = -2;
+       char * line;
+       char * p;
+       static int min_wait_fhandle_dep_index = DEP_TAB_SIZE;
+       int proc;
+       int flag;
+
+       //if (dep_index < min_dep_index-1)
+       //      dep_index = min_dep_index-1;
+
+       dep_index = min_dep_index-1;
+       for (i=0; i<max_dep_index-min_dep_index; i++) {
+               dep_index ++;
+               if (dep_index == max_dep_index) {
+                       dep_index = min_dep_index;
+               }
+       
+               proc = dep_tab[dep_index].proc;
+               flag = dep_tab[dep_index].flag;
+
+               if (dependency_debug)
+                       printf ("get_nextop check dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
+#ifdef NO_DEPENDENCY_TABLE
+               if (dep_tab[dep_index].flag == DEP_FLAG_INIT) {
+                       if (is_play_candidate(dep_index)==TRUE) {
+                               /* the trace_fh is the file handle for the operation directory, trace_fh_2 is other file handle
+                                * used in the request */
+                               if (proc==LINK || proc==RENAME) {
+                                       dep_tab[dep_index].trace_fh = find_another_trace_fh (proc, dep_tab[dep_index].line);
+                                       dep_tab[dep_index].trace_fh_2 = find_lead_trace_fh(proc, dep_tab[dep_index].line);
+                                       dep_tab[dep_index].fh = 0;
+                                       dep_tab[dep_index].fh_2 = 0;
+                               } else {
+                                       dep_tab[dep_index].trace_fh = find_lead_trace_fh(proc, dep_tab[dep_index].line);
+                                       dep_tab[dep_index].fh = 0;
+                                       dep_tab[dep_index].fh_2 = (fh_map_t *)1;
+                               };
+                               dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
+#ifdef TIME_PLAY
+                               dep_tab[dep_index].skip_sec = skip_sec;
+#endif
+                               if (dependency_debug)
+                                       printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_CANDIDATE\n", dep_tab[dep_index].disk_index);
+                       } else {
+                               if (dependency_debug)
+                                       printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_DONE\n", dep_tab[dep_index].disk_index);
+                               dep_tab[dep_index].flag = DEP_FLAG_DONE;
+                               continue;
+                       }
+               }
+
+               if ((dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE) ) {
+
+                       if (!dep_tab[dep_index].fh)
+                               dep_tab[dep_index].fh = lookup_fh (dep_tab[dep_index].trace_fh);
+                       if (!dep_tab[dep_index].fh_2)
+                               dep_tab[dep_index].fh_2 = lookup_fh (dep_tab[dep_index].trace_fh_2);
+
+                       /* need to wait for file handle */
+                       if ((!dep_tab[dep_index].fh) || (!dep_tab[dep_index].fh_2)) {
+                               if (dependency_debug)
+                                       printf("disk[%d] can not lookup file handle\n", dep_tab[dep_index].disk_index);
+                               if (dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) {
+                                       if (dependency_debug)
+                                               printf ("disk[%d] state DEP_FLAG_CANDIDATE to DEP_FLAG_WAIT_FHANDLE\n", dep_tab[dep_index].disk_index);
+                                       dep_tab[dep_index].flag = DEP_FLAG_WAIT_FHANDLE;
+                                       sfs_gettime (&dep_tab[dep_index].start);
+                                       if (dep_index < min_wait_fhandle_dep_index)
+                                               min_wait_fhandle_dep_index = dep_index;
+                               } else {
+                                       struct ladtime tmp;
+                                       sfs_gettime (&tmp);
+                                       SUBTIME (tmp, dep_tab[dep_index].start);
+#ifdef TIME_PLAY
+                                       RFS_ASSERT (tmp.sec < 20 + (skip_sec - dep_tab[dep_index].skip_sec));   
+#else
+                                       RFS_ASSERT (tmp.sec < 20 );     
+#endif
+                               }
+                               continue;
+                       }
+
+                       /* file handle ready, adjust_min_wait_fhandle_dep_index */
+                       if ((dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE)) {
+                               if (dep_index == min_wait_fhandle_dep_index) {
+                                       min_wait_fhandle_dep_index = dep_tab_size;
+                                       for (j=dep_index+1; j<max_dep_index; j++) {
+                                               if (dep_tab[j].flag ==DEP_FLAG_WAIT_FHANDLE) {
+                                                       min_wait_fhandle_dep_index = j;
+                                                       break;
+                                               }
+                                       }
+                               }
+                       }
+                       if (dependency_debug)
+                               printf("disk[%d] found file handle\n", dep_tab[dep_index].disk_index);
+                       dep_tab[dep_index].flag = DEP_FLAG_FHANDLE_READY;
+
+                       /* the normal file operation can be executed now */
+                       if (!is_dir_op (dep_tab[dep_index].proc)) {
+                               if (dependency_debug)
+                                       printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
+                               return dep_index;
+                       }
+
+                       if (dependency_debug)
+                               printf("disk[%d] directory operation \n", dep_tab[dep_index].disk_index);
+                       /* the directory operation need to lock the directory first */
+                       if (dep_tab[dep_index].fh->lock) {
+                               if (dependency_debug)
+                                       printf ("disk[%d] state %d to DEP_FLAG_WAIT_DIRECTORY\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
+                               dep_tab[dep_index].flag = DEP_FLAG_WAIT_DIRECTORY;
+                               continue;
+                       }
+               }
+                               
+               if ((dep_tab[dep_index].flag == DEP_FLAG_FHANDLE_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DIRECTORY)) {
+                       int j = dep_tab[dep_index].fh - fh_map;
+                       if (dependency_debug) {
+                               printf ("dep_tab[%d].disk_index %d, fh_map[%d] lock=%d\n",dep_index, dep_tab[dep_index].disk_index, j, dep_tab[dep_index].fh->lock);
+                               printf ("trace_fh %s path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
+                               printf ("trace_fh %s path %s\n", fh_map[j].trace_fh, fh_map[j].path);
+                       }
+                       if ((dep_tab[dep_index].fh->lock) || ((proc==RENAME) && (dep_tab[dep_index].fh_2->lock)) ) {
+                               if (dependency_debug) 
+                                       printf ("continue to wait for directory lock\n");
+                               continue;
+                       }
+                       if (dependency_debug) 
+                               printf ("dep_tab[%d] disk index %d LOCK fh_map[%d] \n", dep_index, dep_tab[dep_index].disk_index, j);
+                       dep_tab[dep_index].fh->lock = 1;
+                       if (proc==RENAME)
+                               dep_tab[dep_index].fh_2->lock = 1;
+
+                       /* the non-delete directory operation can proceed now */
+                       if (!is_delete_op (dep_tab[dep_index].proc)) {
+                               if (dependency_debug) 
+                                       printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
+                               return dep_index;
+                       }
+
+                       /* the delete operation can proceed if nobody ahead is waiting for fhandle */
+                       /* probably this condition is not strong enough */
+//                     if ((min_wait_fhandle_dep_index<dep_index) ) {
+                       if (dep_index!=min_dep_index) {
+                               if (dependency_debug) 
+                                       printf ("disk[%d] state %d to DEP_FLAG_WAIT_DELETE\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
+                               dep_tab[dep_index].flag = DEP_FLAG_WAIT_DELETE;
+                               continue;
+                       } 
+                       dep_tab[dep_index].flag = DEP_FLAG_DIRECTORY_READY;
+               }
+
+               if ((dep_tab[dep_index].flag == DEP_FLAG_DIRECTORY_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DELETE)) {
+//                     if (min_wait_fhandle_dep_index > dep_index) {
+                       if (dep_index==min_dep_index) {
+                               if (dependency_debug) 
+                                       printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
+                               return dep_index;
+                       }
+               }
+#else
+               if (dep_tab[dep_index].flag == DEP_FLAG_INIT){
+                       for (j=0, t=&(dep_tab[dep_index].dep_ops[0]);
+                               (j<dep_tab[dep_index].init_dep_num) && (dep_tab[dep_index].cur_dep_num>0); 
+                               j++, t++) {
+                               if (*t !=-1) {
+                                       if (dep_tab[disk_index_to_dep_index(dep_index, *t)].flag == DEP_FLAG_DONE) { /* The depended request has been finished */ 
+                                               *t = -1;
+                                               dep_tab[dep_index].cur_dep_num --;
+                                       }
+                               } 
+                       }
+
+                       if (dep_tab[dep_index].cur_dep_num == 0) {
+                               return dep_index;
+                       }
+               }
+#endif
+       }
+
+       if (dependency_debug) 
+               printf ("get_nexop return -1\n");
+       return -1;
+}
+
+int check_timeout(void)
+{
+       static int biod_index = 0;
+       int i;
+       int dep_index;  /* index into dep_tab */
+       int proc;
+       sfs_op_type *op_ptr;            /* per operation info */
+       struct ladtime timeout;
+
+       sfs_gettime (&current); 
+
+       for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
+               if (biod_reqp[biod_index].in_use==TRUE) {
+                       timeout = biod_reqp[biod_index].timeout;
+                       if ((current.sec>timeout.sec) ||
+                               ((current.sec==timeout.sec) && (current.usec>timeout.usec))) {
+
+                               dep_index = biod_reqp[biod_index].dep_tab_index;
+                               proc = dep_tab[dep_index].proc;
+                               op_ptr = &Ops[proc];
+                               op_ptr->results.timeout_calls++;
+                               Ops[TOTAL].results.timeout_calls++;
+
+                               finish_request (biod_index, dep_index, NFS3ERR_RFS_TIMEOUT);
+
+                               if (is_create_op(proc)) {
+                                       dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
+                                       printf ("resend dep_tab[%d], disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
+                               }
+                               //RFS_ASSERT (!is_create_op(proc));
+
+                               //printf ("timeout request: biod_reqp[%d].start %d:%d timeout %d:%d current %d:%d\n", biod_index, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, timeout.sec, timeout.usec, current.sec, current.usec);
+                       }
+               }
+       }
+}
+
+/* Allocate a biod_req entry to send and receive request dep_tab[dep_index]
+ * build the cross reference between dep_tab entry and biod_req entry
+ */
+struct biod_req * get_biod_req(int dep_index) /* index into dep_tab */
+{
+       static int biod_index = 0;
+       int i;
+       for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
+               if (!biod_reqp[biod_index].in_use) {
+                       biod_reqp[biod_index].in_use = 1;
+                       biod_reqp[biod_index].dep_tab_index = dep_index;
+                       dep_tab[dep_index].biod_req_index = biod_index;
+                       return &(biod_reqp[biod_index]);
+               }
+       }
+       return NULL;
+}
+
+/* Return index into biod_reqp
+ * return -1 upon failure 
+ */
+int lookup_biod_req (int xid)
+{
+       static int biod_index = 0;
+       int i;
+       for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
+               /* give a NULL as timeout pointer may cause indefinitely block */
+               if (biod_reqp[biod_index].xid == xid) {
+                       return biod_index;
+               }
+       }
+       return -1;
+}
+
+extern struct ladtime test_start;
+void init_time_offset(void)
+{
+       struct ladtime tmp1;
+       struct ladtime tmp2;
+
+       test_start.sec = 0;
+       test_start.usec = 0;
+       sfs_gettime (&tmp1);            /* called at initial time: tmp1 = play_starttime */
+#ifdef SPEED_UP
+       DIVTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime / SCALE */
+#endif
+#ifdef SLOW_DOWN
+       MULTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime * SCALE */
+#endif
+
+       tmp2 = trace_starttime; /* tmp2 = trace_starttime */
+       SUBTIME (tmp2, tmp1);   /* tmp2 = trace_starttime - play_starttime *|/ SCALE */
+       time_offset = tmp2;             /* time_offset = trace_starttime - play_starttime *|/ SCALE */ 
+}
+
+/* initialize timestamp and proc field of dep_tab entry */
+void init_dep_tab_entry (int dep_index)
+{
+       static int nfs2proc_to_rfsproc[18] = {0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 
+                                                                                                                       10, 11, 12, 13, 14, 15, 16, 17};
+       static int nfs3proc_to_rfsproc[NFS3_PROCEDURE_COUNT] = {0, 1, 2, 4, 18, 5, 6, 8, 9, 14, 
+                                                                                                                       13, 21, 10, 15, 11, 12, 16, 23, 17, 20, 
+                                                                                                                       22, 19};
+       char * line;
+       int version;
+       int nfsproc;
+       int msgid;
+
+       //line = get_line_by_disk_index (dep_tab[dep_index].disk_index);
+       line = dep_tab[dep_index].line;
+       sscanf (line, "%d.%d", &(dep_tab[dep_index].timestamp.tv_sec), &(dep_tab[dep_index].timestamp.tv_usec));
+       sscanf (&line[39], "%x %x", &msgid, &nfsproc);
+       if (line[TRACE_VERSION_POS]=='2') {
+               dep_tab[dep_index].proc = nfs2proc_to_rfsproc[nfsproc];
+               RFS_ASSERT (nfsproc <18);
+       } else {
+               /* This is for debug purpose */
+               if (line[TRACE_VERSION_POS] !='3') {
+                       fprintf(stderr, "line[TRACE_VERSION_POS] %c line %s\n", line[TRACE_VERSION_POS], line);
+                       line = get_line_by_disk_index (dep_tab[dep_index].disk_index-1);
+                       if (!line)
+                               line = get_line_by_disk_index (dep_tab[dep_index].disk_index-2);
+                       RFS_ASSERT (line);
+                       fprintf(stderr, "previousline %s\n", line);
+               }
+               RFS_ASSERT (line[TRACE_VERSION_POS] =='3');
+               if (nfsproc >= NFS3_PROCEDURE_COUNT) {
+                       fprintf(stderr, "proc %d line %s\n", nfsproc, line);
+                       
+               }
+               RFS_ASSERT (nfsproc <NFS3_PROCEDURE_COUNT);
+               dep_tab[dep_index].proc = nfs3proc_to_rfsproc[nfsproc];
+       }
+       RFS_ASSERT (dep_tab[dep_index].proc >= 0 && dep_tab[dep_index].proc < NOPS);
+       dep_tab[dep_index].flag = DEP_FLAG_INIT;
+}
+
+/* initialize status, reply status, reply lines in one shot is probably better ????????????????
+
+static void adjust_play_window (int flag, int * poll_timeout)
+{
+       struct ladtime max_window_time;
+       static struct ladtime max_poll_time = {0, 2000, 0};
+       struct ladtime t;
+       int old_min = min_dep_index;
+       int old_max = max_dep_index;
+       int i;
+       char * line;
+
+       for (; (dep_tab[min_dep_index].flag == DEP_FLAG_DONE) && (min_dep_index<dep_tab_size); min_dep_index++)
+               ;
+       RFS_ASSERT (min_dep_index <= max_dep_index);
+
+       /* max_trace_window_time = current *|/ SCALE + trace_starttime */
+       sfs_gettime (&current);
+
+#ifdef TIME_PLAY
+#ifdef SPEED_UP
+       MULTIME (current, PLAY_SCALE);
+#endif
+#ifdef SLOW_DOWN
+       DIVTIME (current, PLAY_SCALE);
+#endif
+       ADDTIME (current, trace_starttime);
+       max_window_time = current;
+
+       while ((max_dep_index<min_dep_index+MAX_PLAY_WINDOW) && (max_dep_index<dep_tab_size))
+       {
+               t.sec = dep_tab[max_dep_index].timestamp.tv_sec;
+               t.usec = dep_tab[max_dep_index].timestamp.tv_usec;
+
+               if (adjust_play_window_debug)
+                       printf ("max_window_time sec %d usec %d : max_dep_index %d, t.sec %d t.usec %d\n", max_window_time.sec, max_window_time.usec,  max_dep_index, t.sec, t.usec );
+
+               if ((t.sec>max_window_time.sec)||(t.sec==max_window_time.sec && t.usec>max_window_time.usec))
+                       break;
+               
+               max_dep_index++;
+       }
+
+       /* Right now it is not clear how to deal with the situation where MAX_PLAY_WINDOW is reached */
+       if (max_dep_index == min_dep_index+MAX_PLAY_WINDOW) {
+               //printf ("can not catch up the speed, max_dep_index %d reach min_dep_index %d+MAX_PLAY_WINDOW\n", max_dep_index, min_dep_index);
+               //printf (".");
+               can_not_catch_speed_num ++;
+       }
+       //RFS_ASSERT (max_dep_index < min_dep_index+MAX_PLAY_WINDOW);
+#else
+       ADDTIME (current, trace_starttime);
+       max_window_time = current;
+       max_dep_index = min_dep_index + MAX_PLAY_WINDOW;
+       if (max_dep_index >dep_tab_size)
+               max_dep_index = dep_tab_size;
+#endif
+
+       if (flag == BUSY)
+               *poll_timeout = 0;
+       else if (max_dep_index == dep_tab_size) {
+               *poll_timeout = 1000000;        /* poll_timeout set to 1 second for the last request */
+       } else {
+#ifdef TIME_PLAY
+               struct ladtime tmp;
+               struct ladtime tmp1;
+               tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
+               tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
+               if (adjust_play_window_debug)
+                       printf ("dep_tab[max_dep_index %d].timestamp %d:%d, max_window_time %d:%d\n",
+                               max_dep_index, tmp.sec, tmp.usec, max_window_time.sec, max_window_time.usec);
+
+               SUBTIME (tmp, max_window_time);
+#ifdef SPEED_UP
+               DIVTIME (tmp, PLAY_SCALE);
+#endif
+#ifdef SLOW_DOWN
+               MULTIME (tmp, PLAY_SCALE);
+#endif
+               tmp1 = tmp;
+
+               if (tmp.sec > max_poll_time.sec) {
+
+                       if (rfs_debug) 
+                               printf ("dep_tab[%d].timestamp %d:%d, max_window_time %d:%d\n",
+                               max_dep_index, dep_tab[max_dep_index].timestamp.tv_sec, dep_tab[max_dep_index].timestamp.tv_usec, max_window_time.sec, max_window_time.usec);
+                       printf ("skip %d seconds\n", tmp.sec-max_poll_time.sec);
+                       SUBTIME (tmp, max_poll_time);
+                       tmp.usec = 0;
+                       skip_sec += tmp.sec;
+                       SUBTIME (test_start, tmp);
+                       tmp = max_poll_time;
+               }
+
+               RFS_ASSERT ((tmp.sec < 1000));
+               if ((tmp.sec ==0) && (tmp.usec==0)) {
+                       *poll_timeout = 0;
+               } else
+                       *poll_timeout = tmp.sec*1000000+tmp.usec;
+#else 
+               /*
+               struct ladtime tmp;
+               struct ladtime tmp1;
+               tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
+               tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
+               tmp1.sec = dep_tab[max_dep_index-1].timestamp.tv_sec;
+               tmp1.usec = dep_tab[max_dep_index-1].timestamp.tv_usec;
+               SUBTIME (tmp, tmp1);
+               RFS_ASSERT ((tmp.sec < 1000));
+               RFS_ASSERT ((tmp.sec>0) || ((tmp.sec==0) && (tmp.usec>0)));
+               *poll_timeout = tmp.sec*1000000+tmp.usec;
+               */
+
+               *poll_timeout = 100000;
+#endif
+       }       
+       if (rfs_debug)
+               printf ("adjust_play_window: flag %d min %d -> %d, max %d -> %d poll_timeout %d \n", flag, old_min, min_dep_index, old_max, max_dep_index, *poll_timeout);
+}
+
+/* poll for usecs and receive, after receive one reply,
+ * return index in biod_reqp of the corresponding request
+ */
+int poll_and_get_reply (int usecs)
+{
+       int biod_index = -1;
+       int xid;
+       int error;
+       struct timeval zero_time = {0, 0}; /* Immediately return */
+
+       do {
+               error = biod_poll_wait (NFS_client, usecs);
+               switch (error) {
+               case -1:
+                       if (errno == EINTR) {
+                               error = 1;
+                               continue;
+                       }
+                       if (rfs_debug) {
+                               (void) fprintf(stderr, "biod_poll_wait error\n");
+                               perror ("");
+                           (void) fflush(stderr);
+                       }
+                       break;
+               case 0:
+                       break;
+               default:
+#ifdef UDP
+                       error = get_areply_udp (NFS_client, &xid, &zero_time);
+                       // RFS_ASSERT (error!= RPC_TIMEOUT);    /* we have polled and know there is data */
+                       // RFS_ASSERT (error!= RPC_CANTRECV);
+                       RFS_ASSERT (error == RPC_SUCCESS);
+
+                       biod_index = lookup_biod_req (xid);
+                       sfs_gettime (&(biod_reqp[biod_index].stop));
+#else
+                       RFS_ASSERT (0);
+#endif
+               }
+       } while (0);
+       return biod_index;
+}
+
+void print_result(void)
+{
+       int i, j;
+       struct ladtime t;
+       int dep_index;
+       int avg_msecs;
+       unsigned long long tmp;
+       int avg_usecs;
+
+       printf("read_data_bytes %d owe %d GB and %d bytes, adjusted %d times \n",read_data_total, read_data_owe_GB, read_data_owe, read_data_adjust_times);
+       printf("write_data_bytes %d owe %d GB and %d bytes, adjusted %d times \n",write_data_total, write_data_owe_GB, write_data_owe, write_data_adjust_times);
+       printf("failed_create_command_num %d skipped_readlink_command_num %d skipped_custom_command_num %d\n missing_reply_num %d rename_rmdir_noent_reply_num %d rmdir_not_empty_reply_num %d\n loose_access_control_reply_num %d, proper_reply_num %d, lookup_err_due_to_rename %d\n", 
+                       failed_create_command_num, skipped_readlink_command_num, skipped_custom_command_num,
+                       missing_reply_num, rename_rmdir_noent_reply_num, rmdir_not_empty_reply_num, 
+                       loose_access_control_reply_num, lookup_err_due_to_rename_num, proper_reply_num );
+
+    if (DEBUG_CHILD_GENERAL) {
+               (void) fprintf(stdout, "trace play result:\n");
+               (void) fprintf(stdout, "\t    percentage good_cnt bad_cnt timeout_cnt\telapsed time\t\t\taverage time\n");
+               for (i=0; i<NOPS+1; i++) {
+                       if (Ops[i].results.good_calls==0) {
+                               avg_msecs = 0;
+                               avg_usecs = 0;
+                       } else {
+                               tmp = Ops[i].results.time.sec*1000000 + Ops[i].results.time.usec;
+                               avg_msecs = 0;
+                               avg_usecs = tmp/Ops[i].results.good_calls;
+/*
+                               avg_msecs = (Ops[i].results.time.sec*1000 + Ops[i].results.time.usec/1000)/Ops[i].results.good_calls;
+                               avg_usecs = (Ops[i].results.time.usec%1000)/Ops[i].results.good_calls;
+*/
+                       }
+                       (void) fprintf(stdout,  "%11s\t%4.1f\t%4d\t%4d\t%4d\t\tsec %8d usec %8d \tusec %8d\n", 
+                               Ops[i].name, 
+                               (float)(100*Ops[i].results.good_calls)/(float)Ops[TOTAL].results.good_calls, 
+                               Ops[i].results.good_calls, Ops[i].results.bad_calls, Ops[i].results.timeout_calls,
+                               Ops[i].results.time.sec, Ops[i].results.time.usec, avg_msecs*1000+avg_usecs);
+               }
+               (void) fflush (stdout);
+    }
+
+    clnt_destroy(NFS_client);
+    biod_term();
+
+//   print_dump(Client_num, Child_num);
+       return;
+       dep_index = 0;
+       printf ("[%4d] %s \tstart %4d:%6d \n",
+               dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
+       for (i=1; i<dep_tab_size*2; i++) {
+               dep_index = event_order[i];
+               if (dep_index >0) 
+                       printf ("[%4d] %s \tstart %4d:%6d \n",
+                               dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
+               else {
+                       dep_index = -dep_index;
+                       t=dep_tab[dep_index].stop;
+                       SUBTIME (t, dep_tab[dep_index].start);
+                       printf ("\t\t\t\t\t[%4d] %s stop %4d:%6d\tinterval %4d:%6d %s\n",
+                               dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].stop.sec, dep_tab[dep_index].stop.usec, t.sec, t.usec, nfs3_strerror(dep_tab[dep_index].status));
+               }       
+       }
+/*
+       
+       for (i=0, j=0; i<dep_tab_size || j<dep_tab_size; ) {
+               if ((i==dep_tab_size) || 
+                       (LARGERTIME(dep_tab[i].start, dep_tab[j].stop) && j<dep_tab_size)) {
+                       t=dep_tab[j].stop;
+                       SUBTIME (t, dep_tab[j].start);
+                       printf ("dep_tab[%d].proc %s                  stop %d:%d interval %d:%d status %s\n",
+                               j, Ops[dep_tab[j].proc].name, dep_tab[j].stop.sec, dep_tab[j].stop.usec, t.sec, t.usec, nfs3_strerror(dep_tab[j].status));
+                       j++;
+               } else {
+                       printf ("dep_tab[%d].proc %s start %d:%d \n",
+                               i, Ops[dep_tab[i].proc].name, dep_tab[i].start.sec, dep_tab[i].start.usec);
+                       i++;
+               }
+       }
+*/
+} 
+
+/*
+ * allocate and initialize client handles
+ */
+static int
+init_rpc(void)
+{
+       int dummy = 0;
+
+    /*
+     * Set up the client handles.  We get them all before trying one
+     * out to insure that the client handle for LOOKUP class is allocated
+     * before calling op_getattr().
+     */
+    if (DEBUG_CHILD_GENERAL) {
+       (void) fprintf(stderr, "%s: set up client handle\n", sfs_Myname);
+    }
+
+    NFS_client = lad_clnt_create(Tcp? 1: 0, Server_hostent,
+                                       (uint32_t) NFS_PROGRAM,
+                                       (uint32_t) nfs_version,
+                                       RPC_ANYSOCK, &Nfs_timers[0]);
+               
+    if (NFS_client  == ((CLIENT *) NULL)) {
+        return(-1);
+    }
+
+    /*
+     * create credentials using the REAL uid
+     */
+    NFS_client->cl_auth = authunix_create(lad_hostname, (int)Real_uid,
+                                     (int)Cur_gid, 0, NULL);
+
+
+       if (biod_init(dummy, dummy) == -1) {
+                   return(-1);
+       }
+
+    return(0);
+} /* init_rpc */
+
+void
+init_counters(void)
+{
+    uint_t i;
+    uint_t start_msec;
+
+    /* Ready to go - initialize operation counters */
+    for (i = 0; i < NOPS + 1; i++) {
+       Ops[i].req_cnt = 0;
+       Ops[i].results.good_calls = 0;
+       Ops[i].results.bad_calls = 0;
+       Ops[i].results.timeout_calls = 0;       // RFS
+       Ops[i].results.fast_calls = 0;
+       Ops[i].results.time.sec = 0;
+       Ops[i].results.time.usec = 0;
+       Ops[i].results.msec2 = 0;
+    }
+
+    /* initialize timers and period variables */
+    sfs_gettime(&Starttime);
+    Cur_time = Starttime;
+    start_msec = (Starttime.sec * 1000) + (Starttime.usec / 1000);
+    Previous_chkpnt_msec = start_msec;
+    Calls_this_period = 0;
+    Reqs_this_period = 0;
+    Sleep_msec_this_period = 0;
+    Calls_this_test = 0;
+    Reqs_this_test = 0;
+    Sleep_msec_this_test = 0;
+}
+
+static char *
+nfs3_strerror(int status)
+{
+    static char str[40];
+    switch (status) {
+       case NFS3_OK:
+           (void) strcpy(str, "no error");
+           break;
+       case NFS3ERR_PERM:
+           (void) strcpy(str, "Not owner");
+           break;
+       case NFS3ERR_NOENT:
+           (void) strcpy(str, "No such file or directory");
+           break;
+       case NFS3ERR_IO:
+           (void) strcpy(str, "I/O error");
+           break;
+       case NFS3ERR_NXIO:
+           (void) strcpy(str, "No such device or address");
+           break;
+       case NFS3ERR_ACCES:
+           (void) strcpy(str, "Permission denied");
+           break;
+       case NFS3ERR_EXIST:
+           (void) strcpy(str, "File exists");
+           break;
+       case NFS3ERR_XDEV:
+           (void) strcpy(str, "Cross-device link");
+           break;
+       case NFS3ERR_NODEV:
+           (void) strcpy(str, "No such device");
+           break;
+       case NFS3ERR_NOTDIR:
+           (void) strcpy(str, "Not a directory");
+           break;
+       case NFS3ERR_ISDIR:
+           (void) strcpy(str, "Is a directory");
+           break;
+       case NFS3ERR_INVAL:
+           (void) strcpy(str, "Invalid argument");
+           break;
+       case NFS3ERR_FBIG:
+           (void) strcpy(str, "File too large");
+           break;
+       case NFS3ERR_NOSPC:
+           (void) strcpy(str, "No space left on device");
+           break;
+       case NFS3ERR_ROFS:
+           (void) strcpy(str, "Read-only file system");
+           break;
+       case NFS3ERR_MLINK:
+           (void) strcpy(str, "Too many links");
+           break;
+       case NFS3ERR_NAMETOOLONG:
+           (void) strcpy(str, "File name too long");
+           break;
+       case NFS3ERR_NOTEMPTY:
+           (void) strcpy(str, "Directory not empty");
+           break;
+       case NFS3ERR_DQUOT:
+           (void) strcpy(str, "Disc quota exceeded");
+           break;
+       case NFS3ERR_STALE:
+           (void) strcpy(str, "Stale NFS file handle");
+           break;
+       case NFS3ERR_REMOTE:
+           (void) strcpy(str, "Object is remote");
+           break;
+       case NFS3ERR_BADHANDLE:
+           (void) strcpy(str, "Bad file handle");
+           break;
+       case NFS3ERR_NOT_SYNC:
+           (void) strcpy(str, "Not sync write");
+           break;
+       case NFS3ERR_BAD_COOKIE:
+           (void) strcpy(str, "Bad cookie");
+           break;
+       case NFS3ERR_NOTSUPP:
+           (void) strcpy(str, "Operation not supported");
+           break;
+       case NFS3ERR_TOOSMALL:
+           (void) strcpy(str, "Value too small");
+           break;
+       case NFS3ERR_SERVERFAULT:
+           (void) strcpy(str, "Server fault");
+           break;
+       case NFS3ERR_BADTYPE:
+           (void) strcpy(str, "Bad type");
+           break;
+       case NFS3ERR_JUKEBOX:
+           (void) strcpy(str, "Jukebox");
+           break;
+       case NFS3ERR_RFS_TIMEOUT:
+               (void) strcpy(str, "Timeout");
+               break;
+       default:
+           (void) sprintf(str, "Unknown status %d", status);
+           break;
+    }
+    return (str);
+}
+
+/*
+ * Check the gettimeofday() resolution. If the resolution
+ * is in chunks bigger than SFS_MIN_RES then the client
+ * does not have a usable resolution for running the 
+ * benchmark.
+ */
+static void
+check_clock(void)
+{
+       double time_res;
+       char tmp_hostname[HOSTNAME_LEN];
+
+       time_res = get_resolution();
+       getmyhostname(tmp_hostname, HOSTNAME_LEN);
+       if( time_res > (double)SFS_MIN_RES )
+       {
+               (void) fprintf(stderr,
+               "\n%s: Clock resolution too poor to obtain valid results.\n",
+                       tmp_hostname);
+               (void) fprintf(stderr,
+               "%s: Clock resolution %f Micro seconds.\n", tmp_hostname,
+                       time_res);
+               exit(175);
+       }
+       else
+       {
+               (void) fprintf(stderr,
+               "\n%s: Good clock resolution [ %f ] Micro seconds.\n", 
+                       tmp_hostname, time_res);
+       }
+}
+
+/*
+ * Lifted code from Iozone with permission from author. (Don Capps)
+ * Returns the resolution of the gettimeofday() function 
+ * in microseconds.
+ */
+static double
+get_resolution(void)
+{
+        double starttime, finishtime, besttime;
+        long  j,delay;
+       int k;
+
+        finishtime=time_so_far1(); /* Warm up the instruction cache */
+        starttime=time_so_far1();  /* Warm up the instruction cache */
+        delay=j=0;                 /* Warm up the data cache */
+       for(k=0;k<10;k++)
+       {
+               while(1)
+                       {
+                               starttime=time_so_far1();
+                               for(j=0;j< delay;j++)
+                               ;
+                               finishtime=time_so_far1();
+                               if(starttime==finishtime)
+                                       delay++;
+                               else
+                       {
+                               if(k==0)
+                                       besttime=(finishtime-starttime);
+                               if((finishtime-starttime) < besttime)
+                                       besttime=(finishtime-starttime);
+                                       break;
+                       }
+               }
+        }
+         return(besttime);
+}
+
+/*
+ * Lifted code from Iozone with permission from author. (Don Capps)
+ * Returns current result of gettimeofday() in microseconds.
+ */
+/************************************************************************/
+/* Time measurement routines.                                           */
+/* Return time in microseconds                                          */
+/************************************************************************/
+
+static double
+time_so_far1(void)
+{
+        /* For Windows the time_of_day() is useless. It increments in 55 */
+       /* milli second increments. By using the Win32api one can get */
+       /* access to the high performance measurement interfaces. */
+       /* With this one can get back into the 8 to 9 microsecond */
+       /* resolution.  */
+#ifdef Windows
+        LARGE_INTEGER freq,counter;
+        double wintime;
+        double bigcounter;
+
+        QueryPerformanceFrequency(&freq);
+        QueryPerformanceCounter(&counter);
+        bigcounter=(double)counter.HighPart *(double)0xffffffff +
+                (double)counter.LowPart;
+        wintime = (double)(bigcounter/(double)freq.LowPart);
+        return((double)wintime*1000000.0);
+#else
+#if defined (OSFV4) || defined(OSFV3) || defined(OSFV5)
+  struct timespec gp;
+
+  if (getclock(TIMEOFDAY, (struct timespec *) &gp) == -1)
+    perror("getclock");
+  return (( (double) (gp.tv_sec)*1000000.0) +
+    ( ((float)(gp.tv_nsec)) * 0.001 ));
+#else
+  struct timeval tp;
+
+  if (gettimeofday(&tp, (struct timezone *) NULL) == -1)
+    perror("gettimeofday");
+  return ((double) (tp.tv_sec)*1000000.0) +
+    (((double) tp.tv_usec) );
+#endif
+#endif
+}
+
+static void
+usage(void)
+{
+       fprintf(stderr, "trace play usage");
+}
+extern void init_file_system (void)
+{
+       return;
+}
+
+extern void init_dep_tab (void)
+{
+       int i;
+       memset (&dep_tab, 0, sizeof(dep_tab));
+#ifdef notdef
+       dep_tab[0].disk_index = 0;
+       dep_tab[1].disk_index = 2;
+       dep_tab[2].disk_index = 3;
+       dep_tab[3].disk_index = 5;
+       dep_tab[4].disk_index = 7;
+       dep_tab[5].disk_index = 9;
+       dep_tab[6].disk_index = 11;
+       dep_tab[7].disk_index = 12;
+       dep_tab[8].disk_index = 15;
+       dep_tab[9].disk_index = 17;
+       dep_tab[10].disk_index = 18;
+       dep_tab[11].disk_index = 20;
+       dep_tab_size = 12;
+       //dep_tab_size = 2;
+#endif
+}
+
+extern void init_dep_tab_old (void)
+{
+       int i;
+
+       Cur_file_ptr = &Export_dir;
+       Cur_uid = Real_uid;
+
+       for (i=0; i<5; i++) {
+               dep_tab[i].flag = DEP_FLAG_INIT;
+               dep_tab[i].proc = CREATE;
+               dep_tab[i].timestamp.tv_sec = trace_starttime.sec;
+           dep_tab[i].timestamp.tv_usec = trace_starttime.usec+i*10;   
+               dep_tab[i].init_dep_num = 0;
+               dep_tab[i].cur_dep_num = 0;
+       }
+
+       for (i=5; i<10; i++) {
+               dep_tab[i].flag = DEP_FLAG_INIT;
+               dep_tab[i].proc = CREATE;
+               dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i;
+           dep_tab[i].timestamp.tv_usec = trace_starttime.usec;        
+               dep_tab[i].init_dep_num = 0;
+               dep_tab[i].cur_dep_num = 0;
+       }
+
+       dep_tab[2].init_dep_num = 2;
+       dep_tab[2].cur_dep_num = 2;
+       dep_tab[2].dep_ops[0] = 0;
+       dep_tab[2].dep_ops[1] = 1;
+
+       // printf ("trace_starttime (%d %d)\n", trace_starttime.sec, trace_starttime.usec);
+
+       /*
+       for (i=2; i<4; i++) {
+               dep_tab[i].flag = DEP_FLAG_INIT;
+               dep_tab[i].proc = CREATE;
+               dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i*10;
+           dep_tab[i].timestamp.tv_usec = trace_starttime.usec;        
+               dep_tab[i].init_dep_num = 0;
+               dep_tab[i].cur_dep_num = 0;
+       }
+       */
+
+       dep_tab_size = 10;
+
+       for (i=0; i<dep_tab_size; i++)
+       {
+               printf("dep_tab[%d].timestamp (%d %d)\n", i, dep_tab[i].timestamp.tv_sec, dep_tab[i].timestamp.tv_usec);
+       }
+}
+
+void show_fhandle (nfs_fh3 * fhp)
+{
+       struct knfs_fh * kfhp = (struct knfs_fh *)fhp;
+
+       int dev;
+
+       if (quiet_flag)
+               return;
+               
+       RFS_ASSERT (kfhp->fh_version == 1);
+       RFS_ASSERT (kfhp->fh_fsid_type == 0);
+       RFS_ASSERT (kfhp->fh_auth_type == 0);
+
+       dev = ntohs(kfhp->fh_dev_major);
+       dev = dev<<8;
+       dev = dev + ntohs(kfhp->fh_dev_minor);
+
+       /* kfhp->fh_dev_ino hold the inode number of export point of the mounted
+        * file system. For example, if /tmp/t1 is exported, /tmp/t1/t2 is mounted,
+        * then fh_dev_ino hold the inode number of t1, not t2
+        */
+
+       switch (kfhp->fh_fileid_type) {
+               case 0:
+                       printf("fh:type 0 root dev 0x%x dev_ino %d\n", dev, kfhp->fh_dev_ino); 
+                       break;
+               case 1:
+                       printf("fh:type 1 %d %x dev %x dev_ino %x\n", 
+                               kfhp->fh_ino, kfhp->fh_generation, dev, kfhp->fh_dev_ino);
+                       break;
+               case 2:
+                       printf("fh:type2 %d %x dirino %d dev 0x%x dev_ino %x\n", 
+                               kfhp->fh_ino, kfhp->fh_generation, kfhp->fh_dirino, dev, kfhp->fh_dev_ino);
+                       break;
+               default:
+                       RFS_ASSERT (0);
+       }
+}
+
+nfs_fh3 zero_fhandle;
+int init_fh_map ()
+{
+       memset (fh_map, 0, sizeof (fh_map));
+       memset(fh_htable, 0, sizeof (fh_htable));
+       memset (&zero_fhandle, 0, sizeof(nfs_fh3));
+       printf ("SIZE of fh map %d KB\n", sizeof (fh_map)/1000);
+       fh_i = 0;
+}
+
+int add_fh (int map_flag, char * trace_fh, char * path, nfs_fh3 * play_fh)
+{
+       char * old_trace_fh;
+
+       /* first lookup if the entry for fh is already in the table */
+    struct generic_entry * p;
+
+    p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
+       if (p) {
+               RFS_ASSERT (fh_map[p->key3].flag = FH_MAP_FLAG_PARTIAL);
+               RFS_ASSERT (map_flag ==FH_MAP_FLAG_COMPLETE);
+               fh_map[p->key3].flag = map_flag;
+               RFS_ASSERT (!memcmp(fh_map[p->key3].trace_fh, trace_fh, TRACE_FH_SIZE));
+               RFS_ASSERT (!strcmp(fh_map[p->key3].path, path));
+               RFS_ASSERT (!memcmp(&fh_map[p->key3].play_fh, &zero_fhandle, sizeof(nfs_fh3)));
+               memcpy (&fh_map[p->key3].play_fh, play_fh, sizeof (nfs_fh3));
+               if ((fh_map_debug==1)) // || (stage ==TRACE_PLAY_STAGE)) 
+                       printf ("update the play_fh for trace_fh %s path %s \n", trace_fh, path);
+               return 0;
+       }
+
+       fh_map[fh_i].flag = map_flag;
+       fh_map[fh_i].lock = 0;
+       memcpy(fh_map[fh_i].trace_fh, trace_fh, TRACE_FH_SIZE);
+
+       RFS_ASSERT (strlen(path) < MAX_PLAY_PATH_SIZE);
+       strcpy (fh_map [fh_i].path, path);
+       if (map_flag==FH_MAP_FLAG_COMPLETE)
+               memcpy (&fh_map[fh_i].play_fh, play_fh, sizeof(nfs_fh3));
+       else 
+               memset (&fh_map[fh_i].play_fh, 0, sizeof(nfs_fh3));
+
+       if ((fh_map_debug==1)) { // || (stage ==TRACE_PLAY_STAGE)) {
+               printf ("insert trace_fh %s path %s play_fh:\n", trace_fh, path);
+               if (map_flag == FH_MAP_FLAG_COMPLETE)
+                       show_fhandle(play_fh);
+               else 
+                       printf("null\n");
+       }
+
+/*
+       if (map_flag == FH_MAP_FLAG_DISCARD)
+               printf ("insert flag %d trace_fh %s path %s play_fh:\n", map_flag, trace_fh, path);
+*/
+
+    generic_insert(trace_fh, TRACE_FH_SIZE, fh_i, fh_htable, FH_HTABLE_SIZE);
+       
+       fh_i = (fh_i+1);
+       RFS_ASSERT (fh_i < FH_MAP_SIZE);
+
+    return 0;
+};
+
+fh_map_t * lookup_fh (char * trace_fh )
+{
+    struct generic_entry * p;
+    p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
+       if (fh_map_debug==1)
+               printf ("lookup trace_fh %s\n", trace_fh);
+
+    if (p) {
+               if (fh_map_debug==1) {
+                       printf ("found: fh_i %d path %s play_fh:", p->key3, fh_map[p->key3].path);
+                       show_fhandle(&fh_map[p->key3].play_fh);
+               }
+        return (&(fh_map[p->key3]));
+    } else {
+               //printf ("lookup_fh %s not found\n", trace_fh);
+               if (stage != READ_DEP_TAB_STAGE && (fh_map_debug==1)) {
+                       printf ("lookup not found trace_fh %s\n", trace_fh);
+               }
+        return NULL;
+       }
+       RFS_ASSERT (0);
+}
+
+int delete_fh (char * trace_fh, int fh_map_index)
+{
+    generic_delete (trace_fh, TRACE_FH_SIZE, fh_map_index, fh_htable, FH_HTABLE_SIZE);
+    return 0;
+};
+
+void lookup_init_filesystem (nfs_fh3 * parent, char * name, nfs_fh3 * result)
+{
+    LOOKUP3args                args;
+    LOOKUP3res         reply;          /* the reply */
+    enum clnt_stat     rpc_stat;       /* result from RPC call */
+    struct ladtime     start;
+    struct ladtime     stop;
+       static int i=0;
+
+    /* set up the arguments */
+    (void) memcpy((char *) &args.what.dir, (char *) parent,
+                                                       sizeof (nfs_fh3));
+    args.what.name = name;
+    (void) memset((char *) &reply.resok.object, '\0', sizeof (nfs_fh3));
+
+    /* make the call */
+    sfs_gettime(&start);
+    rpc_stat = clnt_call(NFS_client, NFSPROC3_LOOKUP,
+                       xdr_LOOKUP3args, (char *) &args,
+                       xdr_LOOKUP3res, (char *) &reply,
+                       Nfs_timers[Init]);
+    sfs_gettime(&stop);
+
+       if (rpc_stat !=RPC_SUCCESS) {
+               printf("rpc_stat %d\n", rpc_stat);
+               perror("");
+       }
+    RFS_ASSERT (rpc_stat == RPC_SUCCESS);
+       RFS_ASSERT (reply.status == NFS3_OK);
+       (void) memcpy((char *) result, (char *) &reply.resok.object, sizeof (nfs_fh3));
+}
+
+void read_fh_map(char * fh_map_file)
+{
+       FILE * fp;
+       int i = 0;
+       char buf[1024];
+       char trace_fh[TRACE_FH_SIZE];
+       char intbuf[9];
+       char * trace_path;
+       char * p;
+       int map_flag;
+#define MAX_PATH_DEPTH 20
+       nfs_fh3 parents[MAX_PATH_DEPTH];
+       char * lookup_path_ptr[MAX_PATH_DEPTH];
+       char lookup_path [MAX_PLAY_PATH_SIZE];
+       int depth;
+       int new_dir_flag = 0;
+
+       depth = 0;
+       memset(lookup_path_ptr, 0, sizeof(lookup_path_ptr));
+       memcpy(&parents[depth], &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
+       strcpy(lookup_path, "/");
+       lookup_path_ptr[depth]=&lookup_path[0];
+
+       fp = fopen(fh_map_file, "r");
+       RFS_ASSERT (fp!=NULL);
+       
+       intbuf[8]=0;
+
+       memset(buf, 0, sizeof(buf));
+       while (fgets(buf, 1024, fp)) {
+
+               if (fh_i % 10000==0)
+                       printf("%d fh_map entry read\n", fh_i);
+
+               RFS_ASSERT (buf[strlen(buf)-1]=='\n');
+               buf[strlen(buf)-1]=0;
+               if (fh_map_debug) {
+                       printf("%d fgets return %s\n", fh_i, buf);
+                       printf("depth %d lookup_path %s\n", depth, lookup_path);
+               }
+               //for (i=0; i<=depth; i++) 
+                       //printf("lookup_path_ptr[%d] %s ", i, lookup_path_ptr[i]);
+               //printf("\n");
+#ifdef COMPRESS_TRACE_FH 
+               for (i=0; i<TRACE_FH_SIZE/8; i++) {
+                       strncpy(intbuf, buf+i*8, 8);
+                       sscanf(intbuf, "%x", trace_fh+i*8); // maybe it should be 4, anyway we don't compress for now 
+               }
+               trace_path = buf+TRACE_FH_SIZE*2+1;             /* +1 the trace contains only initial file handle */
+#else
+               memcpy(trace_fh, buf, TRACE_FH_SIZE);
+               trace_path = buf + TRACE_FH_SIZE +1;
+#endif
+#ifdef TRACE_CONTAIN_LATER_FHANDLE
+               trace_path = +=2;       /* +3 if the trace contains both initial and later created file handle */
+#endif
+
+#ifdef NO_DEPENDENCY_TABLE
+               if (!strncmp (trace_path, "DISCARD", 7)) {
+                       map_flag = FH_MAP_FLAG_DISCARD;
+                       add_fh (map_flag, buf, trace_path, 0);
+                       continue;
+               }
+#endif
+               
+               p = trace_path+strlen(trace_path)-2;
+               while (*p!='/')
+                       p--;
+               p++;
+               //RFS_ASSERT (p-trace_path<=strlen(lookup_path)+1);
+               //RFS_ASSERT (p>trace_path);
+
+               if (strncmp(lookup_path, trace_path, p-trace_path)) {
+                       printf("strncmp lookup_path %s trace_path %s for length %d\n", lookup_path, trace_path, p-trace_path);
+               }
+               RFS_ASSERT (!strncmp(lookup_path, trace_path, p-trace_path));
+               //while (strncmp(lookup_path, trace_path, p-trace_path)) {      /* one step deeper */
+               while (strlen(lookup_path)>p-trace_path && depth>0) {
+                       //printf("depth--\n");
+                       if (depth<=0) 
+                               printf ("lookup_path %s trace_path %s p-trace_path %d depth %d\n", lookup_path, trace_path, p-trace_path, depth);
+                       RFS_ASSERT (depth>0);
+                       *lookup_path_ptr[depth]=0;
+                       lookup_path_ptr[depth]=0;
+                       depth--;
+               }
+               RFS_ASSERT (strlen(lookup_path)==(p-trace_path) || (depth==0));
+
+
+#ifdef TRACE_CONTAIN_LATER_FHANDLE
+               if (buf[TRACE_FH_SIZE*2+1]=='Y') {
+                       map_flag = FH_MAP_FLAG_COMPLETE;
+               } else {
+                       map_flag = FH_MAP_FLAG_PARTIAL;
+                       RFS_ASSERT (buf[TRACE_FH_SIZE*2+1]=='N');
+               }
+#else
+               map_flag = FH_MAP_FLAG_COMPLETE;
+#endif
+               if ((*(p+strlen(p)-1))=='/') {
+                       *(p+strlen(p)-1)=0;
+                       new_dir_flag = 1;
+               } else 
+                       new_dir_flag = 0;
+
+               if (map_flag == FH_MAP_FLAG_COMPLETE) {
+                       lookup_init_filesystem (&parents[depth], p, &parents[depth+1]);         
+                       add_fh (map_flag, buf, trace_path, &parents[depth+1]);  
+               } else 
+                       add_fh (map_flag, buf, trace_path, 0);
+
+               if (new_dir_flag) {
+                       /* the new fhandle is of a directory */
+                       lookup_path_ptr[depth+1] = lookup_path+strlen(lookup_path);
+                       strcat (lookup_path, p);
+                       strcat (lookup_path, "/");
+
+                       //printf("depth++\n");
+                       depth++;
+               }
+
+               memset(buf, 0, sizeof(buf));
+       }
+                       
+       if (fh_map_debug) {
+               for (i=0; i<fh_i; i++) {
+                       int * p1 = (int *)&(fh_map[i].play_fh);
+#ifdef COMPRESS_TRACE_FH
+                       int * p = (int *)fh_map[i].trace_fh;
+                       printf("fh_map[%d].trace_fh %8x%8x%8x%8x%8x%8x%8x%8x path %s \nnew_filehandle %8x%8x%8x%8x%8x%8x%8x%8x\n",
+                        i, *p, *(p+1), *(p+2), *(p+3), *(p+4), *(p+5), *(p+6), *(p+7), fh_map[i].path,
+                        *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
+#else
+                       printf("fh_map[%d].trace_fh %s path %s \nnew_filehandle %8x%8x%8x%8x%8x%8x%8x%8x\n",
+                        i, fh_map[i].trace_fh, fh_map[i].path,
+                        *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
+               }
+#endif
+
+               fprintf(stderr, "total %d requests \n", i);
+       }
+}
+
+int f()
+{
+       return 1;
+}
+
+inline void finish_request (int biod_index, int dep_index, int status)
+{
+       /* the ending operation, same as when a request time out */
+       dep_tab[dep_index].stop = biod_reqp[biod_index].stop;   /* RFS: to dump data */
+       dep_tab[dep_index].status = status;
+       event_order[event_order_index++] = -dep_index;
+       biod_reqp[biod_index].in_use = FALSE;
+       dep_tab[dep_index].flag = DEP_FLAG_DONE;
+       if (is_dir_op(dep_tab[dep_index].proc)) {
+               int j;
+               RFS_ASSERT (dep_tab[dep_index].fh->lock = 1);
+               dep_tab[dep_index].fh->lock = 0;
+               if (dep_tab[dep_index].proc==RENAME)
+                       dep_tab[dep_index].fh_2->lock = 0;
+               j = dep_tab[dep_index].fh-fh_map;
+               if (dependency_debug) {
+                       printf ("fh_map[%d] is UNlocked\n",j);
+                       printf ("trace_fh %d path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
+                       printf ("trace_fh %d path %s\n", fh_map[j].trace_fh, fh_map[j].path);
+               }
+       }
+       num_out_reqs --;
+}
+
+/* the request argument may have pointers pointing to buffers, e.g. the name in lookup, 
+ * the target of symlink, the write data */
+char arg_res[MAX_ARG_RES_SIZE];
+int poll_timeout = 0;          /* timeout in usecs */
+char buf1 [MAX_BUF1_SIZE]; 
+char buf2 [MAX_BUF2_SIZE];
+#define NFS3_REPLY_MISS -1
+
+int execute_next_request ()
+{
+       int dep_index;
+       int proc;
+       char * line;
+       struct biod_req * reqp;
+       sfs_op_type *op_ptr;            /* per operation info */
+       struct ladtime call_timeout;
+
+       start_profile (&valid_get_nextop_profile);
+       start_profile (&invalid_get_nextop_profile);
+       dep_index = get_nextop();
+       if (dep_index == -1) {
+               end_profile (&invalid_get_nextop_profile);
+               return dep_index;
+       };
+       end_profile (&valid_get_nextop_profile);
+
+       start_profile (&prepare_argument_profile);
+       line = dep_tab[dep_index].line;
+       if ((dep_index%(10000))==0) {
+#ifndef TIME_PLAY
+               fprintf (stderr, "processing dep_tab[%d] disk_index %d num_out_reqs %d \n", dep_index, dep_tab[dep_index].disk_index, num_out_reqs);
+#else
+               fprintf (stderr, "processing dep_tab[%d] disk_index %d num_out_reqs %d can_not_catch_speed_num %d PLAY_SCALE %d \n", dep_index, dep_tab[dep_index].disk_index, num_out_reqs, can_not_catch_speed_num, PLAY_SCALE);
+#ifdef SPEED_UP
+               if (can_not_catch_speed_num < 2000) {
+                       PLAY_SCALE ++;
+                       printf ("set PLAY_SCALE to %d\n", PLAY_SCALE);
+               };
+               if (can_not_catch_speed_num > 50000) {
+                       PLAY_SCALE /= 2;
+               } else {
+                       if (can_not_catch_speed_num > 5000) {
+                               PLAY_SCALE -= 2;
+                               if (PLAY_SCALE < 1)
+                                       PLAY_SCALE = 1;
+                       }
+               }
+#endif
+               can_not_catch_speed_num = 0;
+#endif
+       }
+       if (rfs_debug)
+               printf ("processing dep_tab[%d] disk_index %d %s\n", dep_index, dep_tab[dep_index].disk_index, line);
+
+       proc = dep_tab[dep_index].proc;
+       rfs_Ops[proc].setarg (dep_index, line, arg_res, buf1, buf2);
+
+       op_ptr = &Ops[proc];
+       reqp = get_biod_req (dep_index);
+       RFS_ASSERT (reqp);
+
+       call_timeout.sec = 4; //Nfs_timers[op_ptr->call_class].tv_sec;
+       call_timeout.usec = Nfs_timers[op_ptr->call_class].tv_usec;
+
+    /* make the call */
+    sfs_gettime(&(reqp->start));
+       end_profile (&prepare_argument_profile);
+       start_profile (&biod_clnt_call_profile);
+#define REAL_PLAY
+#ifdef REAL_PLAY
+    reqp->xid = biod_clnt_call(NFS_client, rfs_Ops[proc].nfsv3_proc, 
+                                       rfs_Ops[proc].xdr_arg, arg_res);
+#else
+
+       reqp->xid = dep_index+1;        /* just fake a message id and let it expire */
+#endif
+    if (reqp->xid != 0) {
+        reqp->timeout = reqp->start;
+        ADDTIME (reqp->timeout, call_timeout);
+        num_out_reqs++;
+        dep_tab[dep_index].flag = DEP_FLAG_SENT;
+               event_order[event_order_index++] = dep_index;
+    } else
+               RFS_ASSERT (0);
+
+       dep_tab[dep_index].start = reqp->start; /* RFS: to dump data */
+       end_profile (&biod_clnt_call_profile);
+}
+
+void check_reply (int proc, int biod_index, int dep_index, int status, char * errmsg, int trace_reply_status)
+{
+       if (((status!=trace_reply_status)) && (trace_reply_status!=NFS3_REPLY_MISS)) {
+               if (rfs_debug)
+                       printf ("receive problem reply, xid %x nfs_ret %d %s trace_reply_status %d start %d:%d stop %d:%d command disk index %d\n", biod_reqp[biod_index].xid, status, errmsg, trace_reply_status, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, biod_reqp[biod_index].stop.sec, biod_reqp[biod_index].stop.usec, dep_tab[dep_index].disk_index); 
+#ifndef TAKE_CARE_UNLOOKED_UP_NON_NEW_FILES
+               /* these files is not looked up and is not create/mkdir/symlink/link/mknod ed before they
+                * are refered by name through rename, remove
+                */
+               if ((proc==RENAME || proc==REMOVE) && (status==NFS3ERR_NOENT) && (trace_reply_status ==0)) {
+                       /* current initialization doesnot take care of rename source, if there is no
+                        * create or lookup before that source, the source object will not exist when
+                        * rename occurs
+                        */
+                       RFS_ASSERT (1);
+                       rename_rmdir_noent_reply_num++;
+               } else 
+#endif
+#ifndef TAKE_CARE_SYMBOLIC_LINK
+               if ((proc==LOOKUP) && (status==NFS3_OK) && (trace_reply_status==NFS3ERR_NOENT)) {
+                       /* in the original trace, first lookup return NOENT, then symlink is executed, then lookup return OK
+                        * the initialization considers only the lookup return OK and created the file in the initialization
+                        * so in trace play the first lookup return OK
+                        */
+                       RFS_ASSERT (1);
+               } else if ((proc==SYMLINK) && (status == NFS3ERR_EXIST) && (trace_reply_status == 0)) {
+                       /* due to similar reason as above, the initialization code initializes the symbolic link as a normal
+                        * file already
+                        */
+                       RFS_ASSERT (1);
+               } else
+#endif
+#ifndef TAKE_CARE_NOEMPTY_RMDIR
+               /* the remove packet seems got lost in the trace capture, so replay can not finish */
+               if ((proc==RMDIR) && (status==NFS3ERR_NOTEMPTY)) {
+                       RENAME3args             args;
+                       RENAME3res              reply;          /* the reply */
+                       RMDIR3args * rmdir_argp;
+                       enum clnt_stat rpc_stat;        /* result from RPC call */
+
+                       rfs_Ops[proc].setarg (dep_index, dep_tab[dep_index].line, arg_res, buf1, buf2);
+                       rmdir_argp = (RMDIR3args *)arg_res;
+
+                       memcpy(&args.from, &(rmdir_argp->object), sizeof (diropargs3));
+                       memcpy(&args.to.dir, &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
+                       args.from.name = buf1;  /* the buf1 is already filled when parsing rmdir */
+                       args.to.name = buf2;
+                       sprintf(buf2, "rmdir_%d_%s", dep_tab[dep_index].disk_index, rmdir_argp->object.name);
+
+                       rpc_stat = clnt_call(NFS_client, NFSPROC3_RENAME,
+                       xdr_RENAME3args, (char *) &args,
+                       xdr_RENAME3res, (char *) &reply,
+                               Nfs_timers[Init]);
+                       RFS_ASSERT (rpc_stat == RPC_SUCCESS);
+                       if (reply.status!=NFS3_OK)
+                               printf ("change rmdir into rename, reply.status %d\n", reply.status);
+                       RFS_ASSERT (reply.status==NFS3_OK);
+                       rmdir_not_empty_reply_num ++;
+#endif
+#ifndef TAKE_CARE_ACCESS_ERROR
+               } else if ((status==0) && (trace_reply_status==NFS3ERR_ACCES)) {
+                       loose_access_control_reply_num ++;
+#endif
+#ifdef NO_DEPENDENCY_TABLE 
+               } else if ((proc==LOOKUP) && (status==NFS3ERR_NOENT) && (trace_reply_status==NFS3_OK)) {
+                       lookup_err_due_to_rename_num ++;
+#endif
+               } else {
+                       int i;
+                       for (i=min_dep_index; i<max_dep_index; i++) 
+                               printf ("dep_tab[%d].disk_index %d, flag %d line %s\n", i, dep_tab[i].disk_index, dep_tab[i].flag, dep_tab[i].line);
+                       RFS_ASSERT (0);
+               }
+       } else 
+               proper_reply_num ++;
+
+}
+
+/* return -1 if there is no reply being received 
+ * return the dep_index if the corresponding reply has been received
+ */
+int receive_next_reply (int busy_flag)
+{
+       int dep_index;
+       int biod_index;
+       int proc;
+       char * line;
+       char * reply_line;
+       sfs_op_type *op_ptr;            /* per operation info */
+       int ret;
+       int status;
+       int trace_reply_status;
+       char * errmsg;
+
+       /* wait for reply */
+       start_profile (&valid_poll_and_get_reply_profile);
+       start_profile (&invalid_poll_and_get_reply_profile);
+/*
+       if (busy_flag == IDLE)
+               poll_timeout = 0;
+       else 
+               poll_timeout = 10000;
+*/
+       biod_index = poll_and_get_reply (poll_timeout);
+       if (biod_index==-1) {
+               end_profile (&invalid_poll_and_get_reply_profile);
+               return -1;
+       };
+       end_profile (&valid_poll_and_get_reply_profile);
+
+       start_profile (&decode_reply_profile);
+       /* check the corresponding request */
+       dep_index = biod_reqp[biod_index].dep_tab_index;
+       proc = dep_tab[dep_index].proc;
+       op_ptr = &Ops[proc];
+
+       if (dep_tab[dep_index].flag != DEP_FLAG_SENT) {
+               printf("dep_tab[%d].flag %d proc %d status %d start %d:%d stop %d:%d\n",
+                       dep_index, dep_tab[dep_index].flag, proc, dep_tab[dep_index].status, 
+                       dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec,
+                       dep_tab[dep_index].stop.sec, dep_tab[dep_index].stop.usec );
+               printf ("received reply for timeout requests dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
+               return dep_index;
+       }
+       RFS_ASSERT (dep_tab[dep_index].flag == DEP_FLAG_SENT);
+
+       /* decode the reply */
+       rfs_Ops[proc].setres (arg_res, buf1);
+       ret = proc_header (NFS_client, rfs_Ops[proc].xdr_res, arg_res);
+       RFS_ASSERT (ret == RPC_SUCCESS);
+       status = *((int *)arg_res);
+       errmsg = nfs3_strerror (status);
+       end_profile (&decode_reply_profile);
+
+       start_profile (&check_reply_profile);
+       /* compare with the reply in the trace */
+       line = dep_tab[dep_index].line;
+       reply_line = find_reply_line (line, dep_tab[dep_index].disk_index);
+       if (reply_line == NULL) {
+               //printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
+               trace_reply_status = NFS3_REPLY_MISS;
+               missing_reply_num ++;
+       } else 
+               trace_reply_status = find_reply_status (reply_line);
+
+       /* print the result, trace play progress indicator */
+       if ((dep_index %10000)==0 || rfs_debug)
+               fprintf (stdout, "dep_tab[%d], disk_index %d, receive reply, rpc_ret %d xid %x nfs_ret %d %s trace_reply_status %d start %d:%d stop %d:%d \n", dep_index, dep_tab[dep_index].disk_index, ret, biod_reqp[biod_index].xid, status, errmsg, trace_reply_status, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, biod_reqp[biod_index].stop.sec, biod_reqp[biod_index].stop.usec);
+
+       /* error checking */
+       check_reply (proc, biod_index, dep_index, status, errmsg, trace_reply_status);
+
+       /* free resources */
+       finish_request (biod_index, dep_index, status);
+       
+       /* get statistics */
+       if (status == trace_reply_status) {
+               op_ptr->results.good_calls++;
+               Ops[TOTAL].results.good_calls++;
+       } else {
+               op_ptr->results.bad_calls++;
+               Ops[TOTAL].results.bad_calls++;
+       }
+       sfs_elapsedtime (op_ptr, &(biod_reqp[biod_index].start), &(biod_reqp[biod_index].stop));
+       end_profile (&check_reply_profile);
+       
+       //start_profile (&add_create_object_profile);
+#ifndef TAKE_CARE_SYMBOLIC_LINK
+       if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==MKNOD)) {
+#else
+       if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==SYMLINK || proc==MKNOD)) {
+#endif
+               RFS_ASSERT (status == NFS_OK);
+               RFS_ASSERT (reply_line);
+               add_new_file_system_object(proc, dep_index, line, reply_line);
+       }
+       //end_profile (&add_create_object_profile);
+}
+
+void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line)
+{
+       char * child_trace_fh;
+       fh_map_t * parent_entryp;
+       char component_name[MAX_PLAY_PATH_SIZE];
+       char * parent_trace_fh;
+       char child_path[MAX_PLAY_PATH_SIZE];
+       post_op_fh3 * post_op_fh3_child;
+       char * reply_trace_fh;
+       nfs_fh3 * child_fh3;
+
+       parent_trace_fh = strstr (line, "fh");
+       RFS_ASSERT (parent_trace_fh);
+       parent_trace_fh +=3;
+       parent_entryp = lookup_fh (parent_trace_fh);
+       RFS_ASSERT (parent_entryp);
+       parse_name (parent_trace_fh+65, component_name);
+       strcpy (child_path, parent_entryp->path);
+       strcat (child_path, "/");
+       strcat (child_path, component_name);
+                               
+       /* find the corresponding create request */
+       //printf ("before find reply trace_fh reply_line %s\n", reply_line);
+       reply_trace_fh = find_reply_trace_fh (reply_line);
+       RFS_ASSERT (reply_trace_fh != NULL);
+       switch (proc) {
+       case CREATE:
+               RFS_ASSERT (((CREATE3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
+               child_fh3 = &((CREATE3res *)arg_res)->res_u.ok.obj.handle;
+               break;
+       case MKDIR:
+               RFS_ASSERT (((MKDIR3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
+               child_fh3 = &((MKDIR3res *)arg_res)->res_u.ok.obj.handle;
+               break;
+       case SYMLINK:
+               RFS_ASSERT (((SYMLINK3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
+               child_fh3 = &((SYMLINK3res *)arg_res)->res_u.ok.obj.handle;
+               break;
+       case MKNOD:
+               RFS_ASSERT (((MKNOD3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
+               child_fh3 = &((MKNOD3res *)arg_res)->res_u.ok.obj.handle;
+               break;
+       case LOOKUP:
+               RFS_ASSERT (proc==LOOKUP);
+               child_fh3 = &((LOOKUP3res *)arg_res)->res_u.ok.object;
+               break;
+       default:
+               RFS_ASSERT (0);
+       }
+       RFS_ASSERT (reply_trace_fh[TRACE_FH_SIZE]==' ');
+       reply_trace_fh[TRACE_FH_SIZE] = 0;
+       add_fh (FH_MAP_FLAG_COMPLETE, reply_trace_fh, child_path, child_fh3);   /* exist flag is not used now, set to 1 */
+       reply_trace_fh[TRACE_FH_SIZE] = ' ';
+}
+
+/* initialize timestamp and proc field of dep_tab entry */
+void trace_play(void)
+{
+       
+       /* The flag to indicate whether trace_player is BUSY. Trace_player is BUSY
+        * when either there is request to send or there is reply being
+        * received. Otherwise it is IDLE. The timeout for polling replies 
+        * is set to 0 when BUSY, it is set to the waiting time to the first
+        * request outside of current <min_dep_index, max_dep_index> window when IDLE.
+        */
+       int busy_flag = BUSY;           
+
+       //int dep_index;                /* index into dependency table: dep_tab */
+       //int biod_index;       /* index into outstanding requests: biod_reqp */
+
+       int count = 0;
+       min_dep_index = 0;
+       max_dep_index = 0;
+       adjust_play_window(busy_flag, &poll_timeout);
+
+       start_profile (&total_profile);
+       while ((min_dep_index<dep_tab_size) || (num_out_reqs>0)) {
+
+               if (busy_flag == IDLE) {
+                       //start_profile (&check_timeout_profile);
+                       check_timeout();
+                       //end_profile (&check_timeout_profile);
+               }
+
+               //start_profile (&adjust_play_window_profile);
+               //adjust_play_window (flag, &poll_timeout);
+               //adjust_play_window (flag+(max_dep_index-min_dep_index), &poll_timeout);
+               adjust_play_window (busy_flag, &poll_timeout);
+               if (rfs_debug)
+                       printf("num_out_reqs %d\n", num_out_reqs);
+               busy_flag = IDLE;
+               //end_profile (&adjust_play_window_profile);
+
+               start_profile (&execute_next_request_profile);
+               while (execute_next_request()!=-1)
+                       busy_flag = BUSY;
+               end_profile (&execute_next_request_profile);
+
+               start_profile (&receive_next_reply_profile);
+               while (receive_next_reply(busy_flag)!=-1)
+                       busy_flag = BUSY;
+               end_profile (&receive_next_reply_profile);
+       }
+       end_profile (&total_profile);
+
+       print_profile ("total_profile", &total_profile);
+       printf("\n");
+       print_profile ("check_timeout", &check_timeout_profile);
+       printf("\n");
+       print_profile ("adjust_play_window", &adjust_play_window_profile);
+       printf("\n");
+       print_profile ("execute_next_request_profile", &execute_next_request_profile);
+       print_profile ("valid_get_nextop_profile", &valid_get_nextop_profile);
+       print_profile ("invalid_get_nextop_profile", &invalid_get_nextop_profile);
+       print_profile ("prepare_argument", &prepare_argument_profile);
+       print_profile ("biod_clnt_call", &biod_clnt_call_profile);
+       printf("\n");
+       print_profile ("receive_next_reply", &receive_next_reply_profile);
+       print_profile ("valid_poll_and_get_reply_profile", &valid_poll_and_get_reply_profile);
+       print_profile ("invalid_poll_and_get_reply_profile", &invalid_poll_and_get_reply_profile);
+       print_profile ("decode_reply", &decode_reply_profile);
+       print_profile ("check_reply", &check_reply_profile);
+       print_profile ("add_create_object", &add_create_object_profile);
+       printf("\n");
+       
+       printf ("min_dep_index %d dep_tab_size %d num_out_reqs %d\n", min_dep_index, dep_tab_size, num_out_reqs);
+}
+/* sfs_c_chd.c */