TBBT/trace_play/sfs_c_chd.c.old.2

   1 #ifndef lint
   2 static char sfs_c_chdSid[] = "@(#)sfs_c_chd.c   2.1     97/10/23";
   3 #endif
   4
   5 /*
   6  *   Copyright (c) 1992-1997,2001 by Standard Performance Evaluation Corporation
   7  *      All rights reserved.
   8  *              Standard Performance Evaluation Corporation (SPEC)
   9  *              6585 Merchant Place, Suite 100
  10  *              Warrenton, VA 20187
  11  *
  12  *      This product contains benchmarks acquired from several sources who
  13  *      understand and agree with SPEC's goal of creating fair and objective
  14  *      benchmarks to measure computer performance.
  15  *
  16  *      This copyright notice is placed here only to protect SPEC in the
  17  *      event the source is misused in any manner that is contrary to the
  18  *      spirit, the goals and the intent of SPEC.
  19  *
  20  *      The source code is provided to the user or company under the license
  21  *      agreement for the SPEC Benchmark Suite for this product.
  22  */
  23
  24 /*****************************************************************
  25  *                                                               *
  26  *      Copyright 1991,1992  Legato Systems, Inc.                *
  27  *      Copyright 1991,1992  Auspex Systems, Inc.                *
  28  *      Copyright 1991,1992  Data General Corporation            *
  29  *      Copyright 1991,1992  Digital Equipment Corporation       *
  30  *      Copyright 1991,1992  Interphase Corporation              *
  31  *      Copyright 1991,1992  Sun Microsystems, Inc.              *
  32  *                                                               *
  33  *****************************************************************/
  34
  35 /*
  36  * -------------------------- sfs_c_chd.c -------------------------
  37  *
  38  *      The sfs child.  Routines to initialize child parameters,
  39  *      initialize test directories, and generate load.
  40  *
  41  *.Exported_Routines
  42  *      void child(int, float, int, char *);
  43  *      void init_fileinfo(void);
  44  *      void init_counters(void);
  45  *      sfs_fh_type * randfh(int, int, uint_t, sfs_state_type,
  46  *                              sfs_file_type);
  47  *      int check_access(struct *stat)
  48  *      int check_fh_access();
  49  *
  50  *.Local_Routines
  51  *      void check_call_rate(void);
  52  *      void init_targets(void);
  53  *      void init_dirlayout(void);
  54  *      void init_rpc(void);
  55  *      void init_testdir(void);
  56  *      int do_op(void);
  57  *      int op(int);
  58  *
  59  *.Revision_History
  60  *      21-Aug-92       Wittle          randfh() uses working set files array.
  61  *                                      init_fileinfo() sets up working set.
  62  *      02-Jul-92       Teelucksingh    Target file size now based on peak load
  63  *                                      instead of BTDT.
  64  *      04-Jan-92       Pawlowski       Added raw data dump hooks.
  65  *      16-Dec-91       Wittle          Created.
  66  */
  67
  68
  69 /*
  70  * -------------------------  Include Files  -------------------------
  71  */
  72
  73 /*
  74  * ANSI C headers
  75  */
  76 #include <stdio.h>
  77 #include <stdlib.h>
  78 #include <string.h>
  79 #include <errno.h>
  80 #include <math.h>
  81 #include <signal.h>
  82
  83 #include <sys/types.h>
  84 #include <sys/stat.h>
  85
  86 #include <unistd.h>
  87
  88 #include "sfs_c_def.h"
  89 #include "sfs_m_def.h"
  90 #include "rfs_c_def.h"
  91 #include "generic_hash.h"
  92 #include "nfsd_nfsfh_cust.h"
  93
  94 extern struct hostent   *Server_hostent;
  95
  96 #define PROB_SCALE 1000L
  97 #define _M_MODULUS 2147483647L /* (2**31)-1 */
  98
  99 #define _GROUP_DIVISOR 500
 100 #define _FILES_PER_GROUP 4
 101 #define _MIN_GROUPS 12
 102 #define _WORKING_SET_AT_25_OPS_PER_SEC 975
 103
 104 /*
 105  * -----------------------  External Definitions  -----------------------
 106  */
 107 extern uint32_t    biod_clnt_call(CLIENT *, uint32_t, xdrproc_t, void *);
 108 extern enum clnt_stat proc_header(CLIENT *cl, xdrproc_t xdr_results, void *results_ptr);
 109 extern int  biod_poll_wait(CLIENT *, uint32_t);
 110 extern enum clnt_stat get_areply_udp (CLIENT * cl, uint32_t *xid, struct timeval *timeout);
 111 extern char * parse_name (char * t, char * buf);
 112
 113 /* forward definitions for local functions */
 114 static int init_rpc(void);
 115
 116 /* RFS: forward definitions for local functions */
 117 void init_ops(void);
 118 static void init_signal();
 119 extern void init_file_system (void);
 120 extern void init_dep_tab (void);
 121 static void read_trace(char * trace_file);
 122 static void read_fh_map();
 123 static void init_play (char * mount_point);
 124 static void trace_play(void);
 125 static void print_result(void);
 126 static int get_nextop(void);
 127 static int check_timeout(void);
 128 static struct biod_req * get_biod_req(int dep_tab_index);
 129 static int lookup_biod_req (int xid);
 130 static void init_time_offset(void);
 131 static void adjust_play_window (int flag, int * poll_timeout);
 132 static int poll_and_get_reply (int usecs);
 133 static char * nfs3_strerror(int status);
 134 static void check_clock(void);
 135 static double time_so_far1(void);
 136 static double get_resolution(void);
 137 static void usage(void);
 138 void init_dep_tab_entry (int dep_index);
 139 extern fh_map_t * lookup_fh (char * trace_fh );
 140 static inline void finish_request (int biod_index, int dep_index, int status);
 141 static void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line);
 142
 143 /*
 144  * -------------  Per Child Load Generation Rate Variables  -----------
 145  */
 146 static uint_t Calls_this_period; /* calls made during the current run period */
 147 static uint_t Calls_this_test;  /* calls made during the test so far */
 148 static uint_t Reqs_this_period; /* reqs made during the current run period */
 149 static uint_t Reqs_this_test;   /* reqs made during the test so far */
 150 static uint_t Sleep_msec_this_test; /* msec slept during the test so far */
 151 static uint_t Sleep_msec_this_period;
 152 static uint_t Previous_chkpnt_msec; /* beginning time of current run period */
 153 static int Target_sleep_mspc;   /* targeted sleep time per call */
 154
 155 static char io_buf[BUFSIZ];     /* io buffer for print out messages */
 156
 157 char * sfs_Myname;
 158 int     Log_fd;                         /* log fd */
 159 char    Logname[NFS_MAXNAMLEN];         /* child processes sync logfile */
 160 int     Validate = 0;                                   /* fake variable */
 161 int Child_num = 0;                                              /* fake: child index */
 162 int Tcp = 0;                                                    /* We implement UDP first */
 163 int Client_num = 1;                                             /* fake: number of client */
 164 uid_t Real_uid;
 165 gid_t Cur_gid;
 166 uid_t Cur_uid;
 167 /*
 168  * -------------------------  SFS Child  -------------------------
 169  */
 170
 171 void print_usage()
 172 {
 173         printf("sfs3 hostname:mount_dir trace_file fh_map_file\n");
 174         exit;
 175 }
 176
 177 void read_dep_tab()
 178 {
 179 #ifdef NO_DEPENDENCY_TABLE
 180         int i;
 181         char * line;
 182         char * trace_fh;
 183         fh_map_t * fh_map_entry;
 184         int req_num_with_new_fh = 0;
 185         int     req_num_with_discard_fh = 0;
 186         int req_num_with_init_fh =0;
 187
 188         for (i=0; i<memory_trace_size; i++) {
 189                 line = memory_trace[i].line;
 190                 if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='C') {
 191                         trace_fh = strstr (line, "fh");
 192                         RFS_ASSERT (trace_fh);
 193                         trace_fh += 3;
 194                         fh_map_entry = lookup_fh (trace_fh);
 195                         if (fh_map_entry && (fh_map_entry->flag==FH_MAP_FLAG_DISCARD) )  {
 196                                 req_num_with_discard_fh ++;
 197                                 continue;
 198                         }
 199                         if (fh_map_entry)
 200                                 req_num_with_init_fh ++;
 201                         else
 202                                 req_num_with_new_fh ++;
 203
 204                         dep_tab[dep_tab_size].disk_index = memory_trace[i].disk_index;
 205                         dep_tab[dep_tab_size].line = memory_trace[i].line;
 206                         if ((dep_tab_size%100000)==0)
 207                                 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);
 208                         dep_tab_size ++;
 209                 }
 210         }
 211 #else
 212         RFS_ASSERT (0);
 213 #endif
 214         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);
 215 }
 216
 217 void init_profile()
 218 {
 219         memset (&total_profile, 0, sizeof(total_profile));
 220
 221         memset (&execute_next_request_profile, 0, sizeof(execute_next_request_profile));
 222         memset (&valid_get_nextop_profile, 0, sizeof(valid_get_nextop_profile));
 223         memset (&invalid_get_nextop_profile, 0, sizeof(invalid_get_nextop_profile));
 224         memset (&prepare_argument_profile, 0, sizeof(prepare_argument_profile));
 225         memset (&biod_clnt_call_profile, 0, sizeof(biod_clnt_call_profile));
 226
 227         memset (&receive_next_reply_profile, 0, sizeof(receive_next_reply_profile));
 228         memset (&valid_poll_and_get_reply_profile, 0, sizeof(valid_poll_and_get_reply_profile));
 229         memset (&invalid_poll_and_get_reply_profile, 0, sizeof(invalid_poll_and_get_reply_profile));
 230         memset (&decode_reply_profile, 0, sizeof(decode_reply_profile));
 231         memset (&check_reply_profile, 0, sizeof(check_reply_profile));
 232         memset (&add_create_object_profile, 0, sizeof(add_create_object_profile));
 233
 234         memset (&check_timeout_profile, 0, sizeof(check_timeout_profile));
 235         memset (&adjust_play_window_profile, 0, sizeof(adjust_play_window_profile));
 236 }
 237
 238 int main(int argc, char ** argv)
 239 {
 240         extern char * optarg;
 241         char tracefile[256];
 242         int i;
 243         int memory_trace_size;
 244
 245         if (argc==2 && !strcmp(argv[1],"-help")) {
 246                 print_usage();
 247                 exit(0);
 248         }
 249
 250         check_clock();
 251     getmyhostname(lad_hostname, HOSTNAME_LEN);
 252
 253     init_ops();
 254         /*
 255          * Get the uid and gid information.
 256          */
 257         Real_uid = getuid();
 258         Cur_gid = getgid();
 259         //Real_uid = 513;
 260         //Cur_gid = 513;
 261
 262         Nfs_timers = Nfs_udp_timers;
 263
 264         init_file_system ();
 265
 266         init_signal();
 267         //init_play (argv[1]);
 268         init_play ("capella:/p5/RFSFS");
 269         init_profile();
 270         init_fh_map();
 271         //read_fh_map (argv[3]);
 272         read_fh_map ("fh-path-map");
 273         init_dep_tab();                 /* and  dep_tab_size */
 274         //read_trace (argv[2]);
 275         read_trace ("anon-lair62-011130-1100.txt");
 276         stage = READ_DEP_TAB_STAGE;
 277         read_dep_tab();
 278
 279         for (i=0; i<dep_tab_size; i++) {
 280                 RFS_ASSERT (dep_tab[i].flag == DEP_FLAG_FREE)
 281                 init_dep_tab_entry (i);
 282         }
 283         stage = TRACE_PLAY_STAGE;
 284         init_time_offset();
 285         trace_play ();
 286         print_result();
 287         printf("ffff\n");
 288 }
 289
 290 void init_ops (void)
 291 {
 292         Ops = nfsv3_Ops;
 293         nfs_version = NFS_V3;
 294 }
 295
 296 /* Set up the signal handlers for all signals */
 297 void init_signal()
 298 {
 299 #if (defined(_XOPEN_SOURCE) || defined(USE_POSIX_SIGNALS))
 300         struct sigaction sig_act, old_sig_act;
 301
 302         /* use XOPEN signal handling */
 303
 304         sig_act.sa_handler = generic_catcher;
 305         (void)sigemptyset(&sig_act.sa_mask);
 306         sig_act.sa_flags = 0;
 307
 308         /* signals handlers for signals used by sfs */
 309         sig_act.sa_handler = sfs_cleanup;
 310         if (sigaction(SIGINT,&sig_act,&old_sig_act) == -1) {
 311             perror("sigaction failed: SIGINT");
 312             exit(135);
 313         }
 314
 315         sig_act.sa_handler = sfs_cleanup;
 316         if (sigaction(SIGTERM,&sig_act,&old_sig_act) != 0)  {
 317             perror("sigaction failed: SIGTERM");
 318             exit(137);
 319         }
 320 #else
 321     /* signals handlers for signals used by sfs */
 322     (void) signal(SIGINT, sfs_cleanup);
 323     // RFS (void) signal(SIGALRM, sfs_alarm);
 324         (void) signal(SIGTERM, sfs_cleanup);
 325 #endif
 326 }
 327
 328 void
 329 init_play (
 330     char        * mount_point)          /* Mount point for remote FS */
 331 {
 332     char        namebuf[NFS_MAXNAMLEN] = "trace_play";  /* unique name for this program */
 333     CLIENT *    mount_client_ptr;       /* Mount client handle */
 334
 335         if (!rfs_debug);
 336         (void) setvbuf(stderr, io_buf, _IOLBF, BUFSIZ);
 337
 338     sfs_Myname = namebuf;
 339
 340     /*
 341      * May require root priv to perform bindresvport operation
 342      */
 343     mount_client_ptr = lad_getmnt_hand(mount_point);
 344     if (mount_client_ptr == NULL) {
 345                 exit(145);
 346     }
 347
 348     /*
 349      * should be all done doing priv port stuff
 350      */
 351
 352     if (init_rpc() == -1) {
 353                 (void) fprintf(stderr, "%s: rpc initialization failed\n", sfs_Myname);
 354                 (void) generic_kill(0, SIGINT);
 355                 exit(146);
 356     }
 357
 358
 359     /*
 360      * finish all priv bindresvport calls
 361      * reset uid
 362      */
 363     if (setuid(Real_uid) != (uid_t)0) {
 364         (void) fprintf(stderr,"%s: %s%s", sfs_Myname,
 365             "cannot perform setuid operation.\n",
 366             "Do `make install` as root.\n");
 367     }
 368
 369     init_mount_point(0, mount_point, mount_client_ptr);
 370
 371
 372     /*
 373      * Cleanup client handle for mount point
 374      */
 375     clnt_destroy(mount_client_ptr);
 376
 377         init_counters();
 378
 379
 380 }
 381
 382 void read_trace (char * tracefile)
 383 {
 384         FILE * fp;
 385         char buf[1024];
 386         // char * t=buf;
 387         int disk_index=0;
 388
 389         fp = fopen(tracefile, "r");
 390         RFS_ASSERT (fp!=NULL);
 391         while (fgets(buf, 1024, fp)) {
 392                 //printf ("buf: %s buf[36] %c\n", buf, buf[36]);
 393                 //if (buf[36]=='C' || strstr(buf, "create") || strstr(buf, "lookup")) {
 394 #ifdef REDUCE_MEMORY_TRACE_SIZE
 395                 if (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='C' || strstr(buf, "create") ||
 396                         strstr(buf, "mkdir") || strstr(buf, "symlink") || strstr(buf, "mknod") || strstr(buf, "lookup")) {
 397 #endif
 398                         if (!((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH)))
 399                                 printf("strlen(buf) %d buf %s \n", strlen(buf), buf);
 400                         RFS_ASSERT ((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH));
 401
 402                         /* store the request to memory */
 403                         strcpy (memory_trace[memory_trace_size].line, buf);
 404                         memory_trace[memory_trace_size].disk_index = disk_index;
 405                         memory_trace_size ++;
 406
 407                         if (memory_trace_size >= MAX_MEMORY_TRACE_LINES) {
 408                                 printf ("memory trace size %d is not enough\n", MAX_MEMORY_TRACE_LINES);
 409                                 break;
 410                         }
 411                         if ((disk_index%100000)==0)
 412                                 fprintf(stderr, "%d disk trace parsed, store %d trace lines to memory\n", disk_index, memory_trace_size);
 413 #ifdef REDUCE_MEMORY_TRACE_SIZE
 414                 } else {
 415                         RFS_ASSERT (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
 416                 }
 417 #endif
 418                 disk_index ++;
 419         };
 420
 421         fprintf(stderr, "total %d disk lines %d memory lines \n", disk_index, memory_trace_size );
 422
 423 }
 424
 425
 426 #ifdef REDUCE_MEMORY_TRACE_SIZE
 427 inline int disk_index_to_memory_index (int disk_index)
 428 {
 429         static int memory_index = 0;
 430         if (disk_index > memory_trace[memory_index].disk_index) {
 431                 while (memory_trace[memory_index].disk_index < disk_index) {
 432                         memory_index++;
 433                         RFS_ASSERT (memory_index < MAX_MEMORY_TRACE_LINES);
 434                 }
 435         };
 436         if (disk_index < memory_trace[memory_index].disk_index) {
 437                 while (memory_trace[memory_index].disk_index > disk_index) {
 438                         memory_index--;
 439                         RFS_ASSERT (memory_index >=0);
 440                 }
 441         };
 442
 443         RFS_ASSERT (disk_index == memory_trace[memory_index].disk_index);
 444         return memory_index;
 445 }
 446 #else
 447 #define disk_index_to_memory_index(disk_index)  disk_index
 448 #endif
 449
 450 #define get_line_by_disk_index(disk_index) \
 451         memory_trace[disk_index_to_memory_index(disk_index)].line
 452
 453 inline char * find_reply_line (char * command_line, int cur_disk_index)
 454 {
 455         int i;
 456         char * line;
 457         char * p;
 458         int request_memory_index = disk_index_to_memory_index (cur_disk_index);
 459         for (i=request_memory_index+1; i<request_memory_index+MAX_COMMAND_REPLY_DISTANCE && i<MAX_MEMORY_TRACE_LINES; i++) {
 460                 line = memory_trace[i].line;
 461                 if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R') {
 462                 p = strchr (&line[TRACE_MSGID_POS], ' ');
 463             RFS_ASSERT (p);
 464                         if (!strncmp(&line[TRACE_MSGID_POS], &command_line[TRACE_MSGID_POS], p-&(line[TRACE_MSGID_POS])))
 465                                 return line;
 466                 }
 467         }
 468         return NULL;
 469 }
 470
 471 inline int find_reply_status (char * line)
 472 {
 473         char * p;
 474         int i=0;
 475
 476         //printf ("line %s  flag %c\n", line, line[TRACE_COMMAND_REPLY_FLAG_POS]);
 477         RFS_ASSERT (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
 478         if (!strstr(line, "OK")) {
 479                 p=strstr(line, " 6 read ");
 480                 if (p) {
 481                         p+=strlen(" 6 read ");
 482                 } else {
 483                         p = strstr (line, "status=XXX");
 484                         RFS_ASSERT (p);
 485                         p--;
 486                         RFS_ASSERT (*p==' ');
 487                         while (*p==' ')
 488                                 p--;
 489                         while (*p!=' ') {
 490                                 p--;
 491                         }
 492                         p++;
 493                 }
 494                 sscanf (p, "%x", &i);
 495                 if ((i<=0) || (i>10000))
 496                         printf("line %s\n", line);
 497                 RFS_ASSERT (i>0 && i<10009);
 498         }
 499         return i;
 500 }
 501
 502 inline char * find_reply_trace_fh (char * line)
 503 {
 504         char * p;
 505         p = strstr (line, "OK fh");
 506         if (!p)
 507                 printf ("find_reply_trace_fh line %s\n", line);
 508         RFS_ASSERT (p);
 509         return p+6;
 510 }
 511
 512 inline int disk_index_to_dep_index(int cur_dep_index, int disk_index)
 513 {
 514         int i;
 515         for (i=cur_dep_index; i>min_dep_index; i--) {
 516                 if (dep_tab[i].disk_index == disk_index)
 517                         return i;
 518         }
 519         RFS_ASSERT (0);
 520 }
 521
 522 inline int is_play_candidate (int dep_index)
 523 {
 524 #ifndef TAKE_CARE_CREATE_MODE_BY_DAN
 525         int trace_reply_status;
 526         char * reply_line;
 527         if ((dep_tab[dep_index].proc==CREATE)) {
 528                 /* for a failed create in trace, trace_replay just ignore */
 529                 reply_line = find_reply_line (dep_tab[dep_index].line, dep_tab[dep_index].disk_index);
 530                 if (reply_line == NULL) {
 531                         if (dependency_debug)
 532                                 printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
 533                         trace_reply_status = NFS3_OK;
 534                 } else
 535                         trace_reply_status = find_reply_status (reply_line);
 536                 /* many time the trace create fail due to access control, but trace_play will success because our access control
 537                  * may be loose (all uid/gid is mapped to single one 513:513, so we just skip these requests
 538                  */
 539                 if ((dep_tab[dep_index].proc == CREATE) && (trace_reply_status!=NFS3_OK)) {
 540                         if (dependency_debug)
 541                                 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);
 542                         failed_create_command_num ++;
 543                         return FALSE;
 544                 }
 545         }
 546 #endif
 547 #ifndef TAKE_CARE_SYMBOLIC_LINK
 548         if ((dep_tab[dep_index].proc==READLINK)) { /* send request */
 549                 skipped_readlink_command_num ++;
 550                 return FALSE;
 551         }
 552 #endif
 553 #ifndef TAKE_CARE_CUSTOM_COMMAND
 554         /* this line has a file handle which should belong to discard but it is not
 555          * the file handle directly appears as parent directory in a lookup request
 556          * the return value is NOENT, the parent directory should have been initialized
 557          * but the initialization code just ignored all lookup request which didn't success
 558          * including NOENT even though the parent directory is still valid.
 559          */
 560         if ((dep_tab[dep_index].disk_index==262213 ||
 561                  dep_tab[dep_index].disk_index==214402          )) {
 562                 skipped_custom_command_num++;
 563                 return FALSE;
 564         }
 565 #endif
 566         return TRUE;
 567 }
 568
 569 inline int is_dir_op (int proc)
 570 {
 571         switch (proc) {
 572         case MKDIR:
 573         case CREATE:
 574         case LINK:
 575         case SYMLINK:
 576         case MKNOD:
 577         case REMOVE:
 578         case RMDIR:
 579         case RENAME:
 580                 return 1;
 581         default:
 582                 return 0;
 583         }
 584 }
 585
 586 inline int is_create_op (int proc)
 587 {
 588         if (proc==CREATE || proc==MKDIR || proc==LINK || proc==SYMLINK || proc==MKNOD || proc==RENAME)
 589                 return 1;
 590         return 0;
 591 }
 592
 593 inline int is_delete_op (int proc)
 594 {
 595         if (proc==REMOVE || proc==RMDIR || proc==RENAME)
 596                 return 1;
 597         return 0;
 598 }
 599
 600 inline char * find_lead_trace_fh(int proc, char * line)
 601 {
 602         char * p;
 603         /* check the file handle availability */
 604         p = strstr (line, "fh");
 605         RFS_ASSERT (p);
 606         p+=3; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
 607         return p;
 608 }
 609
 610 inline char * find_another_trace_fh(int proc, char * line)
 611 {
 612         char * p;
 613         /* check the file handle availability */
 614         p = strstr (line, "fh2");
 615         RFS_ASSERT (p);
 616         p+=4; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
 617         return p;
 618 }
 619
 620 /* return the index of next request in dep_tab.
 621  * Return -1 if there is no suitable request to send
 622  */
 623 inline int get_nextop(void)
 624 {
 625         int i,j, k;
 626         int * t;
 627         static int dep_index = -2;
 628         char * line;
 629         char * p;
 630         static int min_wait_fhandle_dep_index = DEP_TAB_SIZE;
 631         int proc;
 632         int flag;
 633
 634         //if (dep_index < min_dep_index-1)
 635         //      dep_index = min_dep_index-1;
 636
 637         dep_index = min_dep_index-1;
 638         for (i=0; i<max_dep_index-min_dep_index; i++) {
 639                 dep_index ++;
 640                 if (dep_index == max_dep_index) {
 641                         dep_index = min_dep_index;
 642                 }
 643
 644                 proc = dep_tab[dep_index].proc;
 645                 flag = dep_tab[dep_index].flag;
 646
 647                 if (dependency_debug)
 648                         printf ("get_nextop check dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
 649 #ifdef NO_DEPENDENCY_TABLE
 650                 if (dep_tab[dep_index].flag == DEP_FLAG_INIT) {
 651                         if (is_play_candidate(dep_index)==TRUE) {
 652                                 /* the trace_fh is the file handle for the operation directory, trace_fh_2 is other file handle
 653                                  * used in the request */
 654                                 if (proc==LINK || proc==RENAME) {
 655                                         dep_tab[dep_index].trace_fh = find_another_trace_fh (proc, dep_tab[dep_index].line);
 656                                         dep_tab[dep_index].trace_fh_2 = find_lead_trace_fh(proc, dep_tab[dep_index].line);
 657                                         dep_tab[dep_index].fh = 0;
 658                                         dep_tab[dep_index].fh_2 = 0;
 659                                 } else {
 660                                         dep_tab[dep_index].trace_fh = find_lead_trace_fh(proc, dep_tab[dep_index].line);
 661                                         dep_tab[dep_index].fh = 0;
 662                                         dep_tab[dep_index].fh_2 = (fh_map_t *)1;
 663                                 };
 664                                 dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
 665 #ifdef TIME_PLAY
 666                                 dep_tab[dep_index].skip_sec = skip_sec;
 667 #endif
 668                                 if (dependency_debug)
 669                                         printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_CANDIDATE\n", dep_tab[dep_index].disk_index);
 670                         } else {
 671                                 if (dependency_debug)
 672                                         printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_DONE\n", dep_tab[dep_index].disk_index);
 673                                 dep_tab[dep_index].flag = DEP_FLAG_DONE;
 674                                 continue;
 675                         }
 676                 }
 677
 678                 if ((dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE) ) {
 679
 680                         if (!dep_tab[dep_index].fh)
 681                                 dep_tab[dep_index].fh = lookup_fh (dep_tab[dep_index].trace_fh);
 682                         if (!dep_tab[dep_index].fh_2)
 683                                 dep_tab[dep_index].fh_2 = lookup_fh (dep_tab[dep_index].trace_fh_2);
 684
 685                         /* need to wait for file handle */
 686                         if ((!dep_tab[dep_index].fh) || (!dep_tab[dep_index].fh_2)) {
 687                                 if (dependency_debug)
 688                                         printf("disk[%d] can not lookup file handle\n", dep_tab[dep_index].disk_index);
 689                                 if (dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) {
 690                                         if (dependency_debug)
 691                                                 printf ("disk[%d] state DEP_FLAG_CANDIDATE to DEP_FLAG_WAIT_FHANDLE\n", dep_tab[dep_index].disk_index);
 692                                         dep_tab[dep_index].flag = DEP_FLAG_WAIT_FHANDLE;
 693                                         sfs_gettime (&dep_tab[dep_index].start);
 694                                         if (dep_index < min_wait_fhandle_dep_index)
 695                                                 min_wait_fhandle_dep_index = dep_index;
 696                                 } else {
 697                                         struct ladtime tmp;
 698                                         sfs_gettime (&tmp);
 699                                         SUBTIME (tmp, dep_tab[dep_index].start);
 700 #ifdef TIME_PLAY
 701                                         RFS_ASSERT (tmp.sec < 20 + (skip_sec - dep_tab[dep_index].skip_sec));
 702 #else
 703                                         RFS_ASSERT (tmp.sec < 20 );
 704 #endif
 705                                 }
 706                                 continue;
 707                         }
 708
 709                         /* file handle ready, adjust_min_wait_fhandle_dep_index */
 710                         if ((dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE)) {
 711                                 if (dep_index == min_wait_fhandle_dep_index) {
 712                                         min_wait_fhandle_dep_index = dep_tab_size;
 713                                         for (j=dep_index+1; j<max_dep_index; j++) {
 714                                                 if (dep_tab[j].flag ==DEP_FLAG_WAIT_FHANDLE) {
 715                                                         min_wait_fhandle_dep_index = j;
 716                                                         break;
 717                                                 }
 718                                         }
 719                                 }
 720                         }
 721                         if (dependency_debug)
 722                                 printf("disk[%d] found file handle\n", dep_tab[dep_index].disk_index);
 723                         dep_tab[dep_index].flag = DEP_FLAG_FHANDLE_READY;
 724
 725                         /* the normal file operation can be executed now */
 726                         if (!is_dir_op (dep_tab[dep_index].proc)) {
 727                                 if (dependency_debug)
 728                                         printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
 729                                 return dep_index;
 730                         }
 731
 732                         if (dependency_debug)
 733                                 printf("disk[%d] directory operation \n", dep_tab[dep_index].disk_index);
 734                         /* the directory operation need to lock the directory first */
 735                         if (dep_tab[dep_index].fh->lock) {
 736                                 if (dependency_debug)
 737                                         printf ("disk[%d] state %d to DEP_FLAG_WAIT_DIRECTORY\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
 738                                 dep_tab[dep_index].flag = DEP_FLAG_WAIT_DIRECTORY;
 739                                 continue;
 740                         }
 741                 }
 742
 743                 if ((dep_tab[dep_index].flag == DEP_FLAG_FHANDLE_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DIRECTORY)) {
 744                         int j = dep_tab[dep_index].fh - fh_map;
 745                         if (dependency_debug) {
 746                                 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);
 747                                 printf ("trace_fh %s path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
 748                                 printf ("trace_fh %s path %s\n", fh_map[j].trace_fh, fh_map[j].path);
 749                         }
 750                         if ((dep_tab[dep_index].fh->lock) || ((proc==RENAME) && (dep_tab[dep_index].fh_2->lock)) ) {
 751                                 if (dependency_debug)
 752                                         printf ("continue to wait for directory lock\n");
 753                                 continue;
 754                         }
 755                         if (dependency_debug)
 756                                 printf ("dep_tab[%d] disk index %d LOCK fh_map[%d] \n", dep_index, dep_tab[dep_index].disk_index, j);
 757                         dep_tab[dep_index].fh->lock = 1;
 758                         if (proc==RENAME)
 759                                 dep_tab[dep_index].fh_2->lock = 1;
 760
 761                         /* the non-delete directory operation can proceed now */
 762                         if (!is_delete_op (dep_tab[dep_index].proc)) {
 763                                 if (dependency_debug)
 764                                         printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
 765                                 return dep_index;
 766                         }
 767
 768                         /* the delete operation can proceed if nobody ahead is waiting for fhandle */
 769                         /* probably this condition is not strong enough */
 770 //                      if ((min_wait_fhandle_dep_index<dep_index) ) {
 771                         if (dep_index!=min_dep_index) {
 772                                 if (dependency_debug)
 773                                         printf ("disk[%d] state %d to DEP_FLAG_WAIT_DELETE\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
 774                                 dep_tab[dep_index].flag = DEP_FLAG_WAIT_DELETE;
 775                                 continue;
 776                         }
 777                         dep_tab[dep_index].flag = DEP_FLAG_DIRECTORY_READY;
 778                 }
 779
 780                 if ((dep_tab[dep_index].flag == DEP_FLAG_DIRECTORY_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DELETE)) {
 781 //                      if (min_wait_fhandle_dep_index > dep_index) {
 782                         if (dep_index==min_dep_index) {
 783                                 if (dependency_debug)
 784                                         printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
 785                                 return dep_index;
 786                         }
 787                 }
 788 #else
 789                 if (dep_tab[dep_index].flag == DEP_FLAG_INIT){
 790                         for (j=0, t=&(dep_tab[dep_index].dep_ops[0]);
 791                                 (j<dep_tab[dep_index].init_dep_num) && (dep_tab[dep_index].cur_dep_num>0);
 792                                 j++, t++) {
 793                                 if (*t !=-1) {
 794                                         if (dep_tab[disk_index_to_dep_index(dep_index, *t)].flag == DEP_FLAG_DONE) { /* The depended request has been finished */
 795                                                 *t = -1;
 796                                                 dep_tab[dep_index].cur_dep_num --;
 797                                         }
 798                                 }
 799                         }
 800
 801                         if (dep_tab[dep_index].cur_dep_num == 0) {
 802                                 return dep_index;
 803                         }
 804                 }
 805 #endif
 806         }
 807
 808         if (dependency_debug)
 809                 printf ("get_nexop return -1\n");
 810         return -1;
 811 }
 812
 813 int check_timeout(void)
 814 {
 815         static int biod_index = 0;
 816         int i;
 817         int dep_index;  /* index into dep_tab */
 818         int proc;
 819         sfs_op_type *op_ptr;            /* per operation info */
 820         struct ladtime timeout;
 821
 822         sfs_gettime (&current);
 823
 824         for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
 825                 if (biod_reqp[biod_index].in_use==TRUE) {
 826                         timeout = biod_reqp[biod_index].timeout;
 827                         if ((current.sec>timeout.sec) ||
 828                                 ((current.sec==timeout.sec) && (current.usec>timeout.usec))) {
 829
 830                                 dep_index = biod_reqp[biod_index].dep_tab_index;
 831                                 proc = dep_tab[dep_index].proc;
 832                                 op_ptr = &Ops[proc];
 833                                 op_ptr->results.timeout_calls++;
 834                                 Ops[TOTAL].results.timeout_calls++;
 835
 836                                 finish_request (biod_index, dep_index, NFS3ERR_RFS_TIMEOUT);
 837
 838                                 if (is_create_op(proc)) {
 839                                         dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
 840                                         printf ("resend dep_tab[%d], disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
 841                                 }
 842                                 //RFS_ASSERT (!is_create_op(proc));
 843
 844                                 //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);
 845                         }
 846                 }
 847         }
 848 }
 849
 850 /* Allocate a biod_req entry to send and receive request dep_tab[dep_index]
 851  * build the cross reference between dep_tab entry and biod_req entry
 852  */
 853 struct biod_req * get_biod_req(int dep_index) /* index into dep_tab */
 854 {
 855         static int biod_index = 0;
 856         int i;
 857         for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
 858                 if (!biod_reqp[biod_index].in_use) {
 859                         biod_reqp[biod_index].in_use = 1;
 860                         biod_reqp[biod_index].dep_tab_index = dep_index;
 861                         dep_tab[dep_index].biod_req_index = biod_index;
 862                         return &(biod_reqp[biod_index]);
 863                 }
 864         }
 865         return NULL;
 866 }
 867
 868 /* Return index into biod_reqp
 869  * return -1 upon failure
 870  */
 871 int lookup_biod_req (int xid)
 872 {
 873         static int biod_index = 0;
 874         int i;
 875         for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
 876                 /* give a NULL as timeout pointer may cause indefinitely block */
 877                 if (biod_reqp[biod_index].xid == xid) {
 878                         return biod_index;
 879                 }
 880         }
 881         return -1;
 882 }
 883
 884 extern struct ladtime test_start;
 885 void init_time_offset(void)
 886 {
 887         struct ladtime tmp1;
 888         struct ladtime tmp2;
 889
 890         test_start.sec = 0;
 891         test_start.usec = 0;
 892         sfs_gettime (&tmp1);            /* called at initial time: tmp1 = play_starttime */
 893 #ifdef SPEED_UP
 894         DIVTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime / SCALE */
 895 #endif
 896 #ifdef SLOW_DOWN
 897         MULTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime * SCALE */
 898 #endif
 899
 900         tmp2 = trace_starttime; /* tmp2 = trace_starttime */
 901         SUBTIME (tmp2, tmp1);   /* tmp2 = trace_starttime - play_starttime *|/ SCALE */
 902         time_offset = tmp2;             /* time_offset = trace_starttime - play_starttime *|/ SCALE */
 903 }
 904
 905 /* initialize timestamp and proc field of dep_tab entry */
 906 void init_dep_tab_entry (int dep_index)
 907 {
 908         static int nfs2proc_to_rfsproc[18] = {0, 1, 2, 3, 4, 5, 6, 7, 8, 9,
 909                                                                                                                         10, 11, 12, 13, 14, 15, 16, 17};
 910         static int nfs3proc_to_rfsproc[NFS3_PROCEDURE_COUNT] = {0, 1, 2, 4, 18, 5, 6, 8, 9, 14,
 911                                                                                                                         13, 21, 10, 15, 11, 12, 16, 23, 17, 20,
 912                                                                                                                         22, 19};
 913         char * line;
 914         int version;
 915         int nfsproc;
 916         int msgid;
 917
 918         //line = get_line_by_disk_index (dep_tab[dep_index].disk_index);
 919         line = dep_tab[dep_index].line;
 920         sscanf (line, "%d.%d", &(dep_tab[dep_index].timestamp.tv_sec), &(dep_tab[dep_index].timestamp.tv_usec));
 921         sscanf (&line[39], "%x %x", &msgid, &nfsproc);
 922         if (line[TRACE_VERSION_POS]=='2') {
 923                 dep_tab[dep_index].proc = nfs2proc_to_rfsproc[nfsproc];
 924                 RFS_ASSERT (nfsproc <18);
 925         } else {
 926                 /* This is for debug purpose */
 927                 if (line[TRACE_VERSION_POS] !='3') {
 928                         fprintf(stderr, "line[TRACE_VERSION_POS] %c line %s\n", line[TRACE_VERSION_POS], line);
 929                         line = get_line_by_disk_index (dep_tab[dep_index].disk_index-1);
 930                         if (!line)
 931                                 line = get_line_by_disk_index (dep_tab[dep_index].disk_index-2);
 932                         RFS_ASSERT (line);
 933                         fprintf(stderr, "previousline %s\n", line);
 934                 }
 935                 RFS_ASSERT (line[TRACE_VERSION_POS] =='3');
 936                 if (nfsproc >= NFS3_PROCEDURE_COUNT) {
 937                         fprintf(stderr, "proc %d line %s\n", nfsproc, line);
 938
 939                 }
 940                 RFS_ASSERT (nfsproc <NFS3_PROCEDURE_COUNT);
 941                 dep_tab[dep_index].proc = nfs3proc_to_rfsproc[nfsproc];
 942         }
 943         RFS_ASSERT (dep_tab[dep_index].proc >= 0 && dep_tab[dep_index].proc < NOPS);
 944         dep_tab[dep_index].flag = DEP_FLAG_INIT;
 945 }
 946
 947 /* initialize status, reply status, reply lines in one shot is probably better ????????????????
 948
 949 static void adjust_play_window (int flag, int * poll_timeout)
 950 {
 951         struct ladtime max_window_time;
 952         static struct ladtime max_poll_time = {0, 2000, 0};
 953         struct ladtime t;
 954         int old_min = min_dep_index;
 955         int old_max = max_dep_index;
 956         int i;
 957         char * line;
 958
 959         for (; (dep_tab[min_dep_index].flag == DEP_FLAG_DONE) && (min_dep_index<dep_tab_size); min_dep_index++)
 960                 ;
 961         RFS_ASSERT (min_dep_index <= max_dep_index);
 962
 963         /* max_trace_window_time = current *|/ SCALE + trace_starttime */
 964         sfs_gettime (&current);
 965
 966 #ifdef TIME_PLAY
 967 #ifdef SPEED_UP
 968         MULTIME (current, PLAY_SCALE);
 969 #endif
 970 #ifdef SLOW_DOWN
 971         DIVTIME (current, PLAY_SCALE);
 972 #endif
 973         ADDTIME (current, trace_starttime);
 974         max_window_time = current;
 975
 976         while ((max_dep_index<min_dep_index+MAX_PLAY_WINDOW) && (max_dep_index<dep_tab_size))
 977         {
 978                 t.sec = dep_tab[max_dep_index].timestamp.tv_sec;
 979                 t.usec = dep_tab[max_dep_index].timestamp.tv_usec;
 980
 981                 if (adjust_play_window_debug)
 982                         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 );
 983
 984                 if ((t.sec>max_window_time.sec)||(t.sec==max_window_time.sec && t.usec>max_window_time.usec))
 985                         break;
 986
 987                 max_dep_index++;
 988         }
 989
 990         /* Right now it is not clear how to deal with the situation where MAX_PLAY_WINDOW is reached */
 991         if (max_dep_index == min_dep_index+MAX_PLAY_WINDOW) {
 992                 //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);
 993                 //printf (".");
 994                 can_not_catch_speed_num ++;
 995         }
 996         //RFS_ASSERT (max_dep_index < min_dep_index+MAX_PLAY_WINDOW);
 997 #else
 998         ADDTIME (current, trace_starttime);
 999         max_window_time = current;
1000         max_dep_index = min_dep_index + MAX_PLAY_WINDOW;
1001         if (max_dep_index >dep_tab_size)
1002                 max_dep_index = dep_tab_size;
1003 #endif
1004
1005         if (flag == BUSY)
1006                 *poll_timeout = 0;
1007         else if (max_dep_index == dep_tab_size) {
1008                 *poll_timeout = 1000000;        /* poll_timeout set to 1 second for the last request */
1009         } else {
1010 #ifdef TIME_PLAY
1011                 struct ladtime tmp;
1012                 struct ladtime tmp1;
1013                 tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
1014                 tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
1015                 if (adjust_play_window_debug)
1016                         printf ("dep_tab[max_dep_index %d].timestamp %d:%d, max_window_time %d:%d\n",
1017                                 max_dep_index, tmp.sec, tmp.usec, max_window_time.sec, max_window_time.usec);
1018
1019                 SUBTIME (tmp, max_window_time);
1020 #ifdef SPEED_UP
1021                 DIVTIME (tmp, PLAY_SCALE);
1022 #endif
1023 #ifdef SLOW_DOWN
1024                 MULTIME (tmp, PLAY_SCALE);
1025 #endif
1026                 tmp1 = tmp;
1027
1028                 if (tmp.sec > max_poll_time.sec) {
1029
1030                         if (rfs_debug)
1031                                 printf ("dep_tab[%d].timestamp %d:%d, max_window_time %d:%d\n",
1032                                 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);
1033                         printf ("skip %d seconds\n", tmp.sec-max_poll_time.sec);
1034                         SUBTIME (tmp, max_poll_time);
1035                         tmp.usec = 0;
1036                         skip_sec += tmp.sec;
1037                         SUBTIME (test_start, tmp);
1038                         tmp = max_poll_time;
1039                 }
1040
1041                 RFS_ASSERT ((tmp.sec < 1000));
1042                 if ((tmp.sec ==0) && (tmp.usec==0)) {
1043                         *poll_timeout = 0;
1044                 } else
1045                         *poll_timeout = tmp.sec*1000000+tmp.usec;
1046 #else
1047                 /*
1048                 struct ladtime tmp;
1049                 struct ladtime tmp1;
1050                 tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
1051                 tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
1052                 tmp1.sec = dep_tab[max_dep_index-1].timestamp.tv_sec;
1053                 tmp1.usec = dep_tab[max_dep_index-1].timestamp.tv_usec;
1054                 SUBTIME (tmp, tmp1);
1055                 RFS_ASSERT ((tmp.sec < 1000));
1056                 RFS_ASSERT ((tmp.sec>0) || ((tmp.sec==0) && (tmp.usec>0)));
1057                 *poll_timeout = tmp.sec*1000000+tmp.usec;
1058                 */
1059
1060                 *poll_timeout = 100000;
1061 #endif
1062         }
1063         if (rfs_debug)
1064                 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);
1065 }
1066
1067 /* poll for usecs and receive, after receive one reply,
1068  * return index in biod_reqp of the corresponding request
1069  */
1070 int poll_and_get_reply (int usecs)
1071 {
1072         int biod_index = -1;
1073         int xid;
1074         int error;
1075         struct timeval zero_time = {0, 0}; /* Immediately return */
1076
1077         do {
1078                 error = biod_poll_wait (NFS_client, usecs);
1079                 switch (error) {
1080                 case -1:
1081                         if (errno == EINTR) {
1082                                 error = 1;
1083                                 continue;
1084                         }
1085                         if (rfs_debug) {
1086                                 (void) fprintf(stderr, "biod_poll_wait error\n");
1087                                 perror ("");
1088                             (void) fflush(stderr);
1089                         }
1090                         break;
1091                 case 0:
1092                         break;
1093                 default:
1094 #ifdef UDP
1095                         error = get_areply_udp (NFS_client, &xid, &zero_time);
1096                         // RFS_ASSERT (error!= RPC_TIMEOUT);    /* we have polled and know there is data */
1097                         // RFS_ASSERT (error!= RPC_CANTRECV);
1098                         RFS_ASSERT (error == RPC_SUCCESS);
1099
1100                         biod_index = lookup_biod_req (xid);
1101                         sfs_gettime (&(biod_reqp[biod_index].stop));
1102 #else
1103                         RFS_ASSERT (0);
1104 #endif
1105                 }
1106         } while (0);
1107         return biod_index;
1108 }
1109
1110 void print_result(void)
1111 {
1112         int i, j;
1113         struct ladtime t;
1114         int dep_index;
1115         int avg_msecs;
1116         unsigned long long tmp;
1117         int avg_usecs;
1118
1119         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);
1120         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);
1121         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",
1122                         failed_create_command_num, skipped_readlink_command_num, skipped_custom_command_num,
1123                         missing_reply_num, rename_rmdir_noent_reply_num, rmdir_not_empty_reply_num,
1124                         loose_access_control_reply_num, lookup_err_due_to_rename_num, proper_reply_num );
1125
1126     if (DEBUG_CHILD_GENERAL) {
1127                 (void) fprintf(stdout, "trace play result:\n");
1128                 (void) fprintf(stdout, "\t    percentage good_cnt bad_cnt timeout_cnt\telapsed time\t\t\taverage time\n");
1129                 for (i=0; i<NOPS+1; i++) {
1130                         if (Ops[i].results.good_calls==0) {
1131                                 avg_msecs = 0;
1132                                 avg_usecs = 0;
1133                         } else {
1134                                 tmp = Ops[i].results.time.sec*1000000 + Ops[i].results.time.usec;
1135                                 avg_msecs = 0;
1136                                 avg_usecs = tmp/Ops[i].results.good_calls;
1137 /*
1138                                 avg_msecs = (Ops[i].results.time.sec*1000 + Ops[i].results.time.usec/1000)/Ops[i].results.good_calls;
1139                                 avg_usecs = (Ops[i].results.time.usec%1000)/Ops[i].results.good_calls;
1140 */
1141                         }
1142                         (void) fprintf(stdout,  "%11s\t%4.1f\t%4d\t%4d\t%4d\t\tsec %8d usec %8d \tusec %8d\n",
1143                                 Ops[i].name,
1144                                 (float)(100*Ops[i].results.good_calls)/(float)Ops[TOTAL].results.good_calls,
1145                                 Ops[i].results.good_calls, Ops[i].results.bad_calls, Ops[i].results.timeout_calls,
1146                                 Ops[i].results.time.sec, Ops[i].results.time.usec, avg_msecs*1000+avg_usecs);
1147                 }
1148                 (void) fflush (stdout);
1149     }
1150
1151     clnt_destroy(NFS_client);
1152     biod_term();
1153
1154 //   print_dump(Client_num, Child_num);
1155         return;
1156         dep_index = 0;
1157         printf ("[%4d] %s \tstart %4d:%6d \n",
1158                 dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
1159         for (i=1; i<dep_tab_size*2; i++) {
1160                 dep_index = event_order[i];
1161                 if (dep_index >0)
1162                         printf ("[%4d] %s \tstart %4d:%6d \n",
1163                                 dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
1164                 else {
1165                         dep_index = -dep_index;
1166                         t=dep_tab[dep_index].stop;
1167                         SUBTIME (t, dep_tab[dep_index].start);
1168                         printf ("\t\t\t\t\t[%4d] %s stop %4d:%6d\tinterval %4d:%6d %s\n",
1169                                 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));
1170                 }
1171         }
1172 /*
1173
1174         for (i=0, j=0; i<dep_tab_size || j<dep_tab_size; ) {
1175                 if ((i==dep_tab_size) ||
1176                         (LARGERTIME(dep_tab[i].start, dep_tab[j].stop) && j<dep_tab_size)) {
1177                         t=dep_tab[j].stop;
1178                         SUBTIME (t, dep_tab[j].start);
1179                         printf ("dep_tab[%d].proc %s                  stop %d:%d interval %d:%d status %s\n",
1180                                 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));
1181                         j++;
1182                 } else {
1183                         printf ("dep_tab[%d].proc %s start %d:%d \n",
1184                                 i, Ops[dep_tab[i].proc].name, dep_tab[i].start.sec, dep_tab[i].start.usec);
1185                         i++;
1186                 }
1187         }
1188 */
1189 }
1190
1191 /*
1192  * allocate and initialize client handles
1193  */
1194 static int
1195 init_rpc(void)
1196 {
1197         int dummy = 0;
1198
1199     /*
1200      * Set up the client handles.  We get them all before trying one
1201      * out to insure that the client handle for LOOKUP class is allocated
1202      * before calling op_getattr().
1203      */
1204     if (DEBUG_CHILD_GENERAL) {
1205         (void) fprintf(stderr, "%s: set up client handle\n", sfs_Myname);
1206     }
1207
1208     NFS_client = lad_clnt_create(Tcp? 1: 0, Server_hostent,
1209                                         (uint32_t) NFS_PROGRAM,
1210                                         (uint32_t) nfs_version,
1211                                         RPC_ANYSOCK, &Nfs_timers[0]);
1212
1213     if (NFS_client  == ((CLIENT *) NULL)) {
1214         return(-1);
1215     }
1216
1217     /*
1218      * create credentials using the REAL uid
1219      */
1220     NFS_client->cl_auth = authunix_create(lad_hostname, (int)Real_uid,
1221                                       (int)Cur_gid, 0, NULL);
1222
1223
1224         if (biod_init(dummy, dummy) == -1) {
1225                     return(-1);
1226         }
1227
1228     return(0);
1229 } /* init_rpc */
1230
1231 void
1232 init_counters(void)
1233 {
1234     uint_t i;
1235     uint_t start_msec;
1236
1237     /* Ready to go - initialize operation counters */
1238     for (i = 0; i < NOPS + 1; i++) {
1239         Ops[i].req_cnt = 0;
1240         Ops[i].results.good_calls = 0;
1241         Ops[i].results.bad_calls = 0;
1242         Ops[i].results.timeout_calls = 0;       // RFS
1243         Ops[i].results.fast_calls = 0;
1244         Ops[i].results.time.sec = 0;
1245         Ops[i].results.time.usec = 0;
1246         Ops[i].results.msec2 = 0;
1247     }
1248
1249     /* initialize timers and period variables */
1250     sfs_gettime(&Starttime);
1251     Cur_time = Starttime;
1252     start_msec = (Starttime.sec * 1000) + (Starttime.usec / 1000);
1253     Previous_chkpnt_msec = start_msec;
1254     Calls_this_period = 0;
1255     Reqs_this_period = 0;
1256     Sleep_msec_this_period = 0;
1257     Calls_this_test = 0;
1258     Reqs_this_test = 0;
1259     Sleep_msec_this_test = 0;
1260 }
1261
1262 static char *
1263 nfs3_strerror(int status)
1264 {
1265     static char str[40];
1266     switch (status) {
1267         case NFS3_OK:
1268             (void) strcpy(str, "no error");
1269             break;
1270         case NFS3ERR_PERM:
1271             (void) strcpy(str, "Not owner");
1272             break;
1273         case NFS3ERR_NOENT:
1274             (void) strcpy(str, "No such file or directory");
1275             break;
1276         case NFS3ERR_IO:
1277             (void) strcpy(str, "I/O error");
1278             break;
1279         case NFS3ERR_NXIO:
1280             (void) strcpy(str, "No such device or address");
1281             break;
1282         case NFS3ERR_ACCES:
1283             (void) strcpy(str, "Permission denied");
1284             break;
1285         case NFS3ERR_EXIST:
1286             (void) strcpy(str, "File exists");
1287             break;
1288         case NFS3ERR_XDEV:
1289             (void) strcpy(str, "Cross-device link");
1290             break;
1291         case NFS3ERR_NODEV:
1292             (void) strcpy(str, "No such device");
1293             break;
1294         case NFS3ERR_NOTDIR:
1295             (void) strcpy(str, "Not a directory");
1296             break;
1297         case NFS3ERR_ISDIR:
1298             (void) strcpy(str, "Is a directory");
1299             break;
1300         case NFS3ERR_INVAL:
1301             (void) strcpy(str, "Invalid argument");
1302             break;
1303         case NFS3ERR_FBIG:
1304             (void) strcpy(str, "File too large");
1305             break;
1306         case NFS3ERR_NOSPC:
1307             (void) strcpy(str, "No space left on device");
1308             break;
1309         case NFS3ERR_ROFS:
1310             (void) strcpy(str, "Read-only file system");
1311             break;
1312         case NFS3ERR_MLINK:
1313             (void) strcpy(str, "Too many links");
1314             break;
1315         case NFS3ERR_NAMETOOLONG:
1316             (void) strcpy(str, "File name too long");
1317             break;
1318         case NFS3ERR_NOTEMPTY:
1319             (void) strcpy(str, "Directory not empty");
1320             break;
1321         case NFS3ERR_DQUOT:
1322             (void) strcpy(str, "Disc quota exceeded");
1323             break;
1324         case NFS3ERR_STALE:
1325             (void) strcpy(str, "Stale NFS file handle");
1326             break;
1327         case NFS3ERR_REMOTE:
1328             (void) strcpy(str, "Object is remote");
1329             break;
1330         case NFS3ERR_BADHANDLE:
1331             (void) strcpy(str, "Bad file handle");
1332             break;
1333         case NFS3ERR_NOT_SYNC:
1334             (void) strcpy(str, "Not sync write");
1335             break;
1336         case NFS3ERR_BAD_COOKIE:
1337             (void) strcpy(str, "Bad cookie");
1338             break;
1339         case NFS3ERR_NOTSUPP:
1340             (void) strcpy(str, "Operation not supported");
1341             break;
1342         case NFS3ERR_TOOSMALL:
1343             (void) strcpy(str, "Value too small");
1344             break;
1345         case NFS3ERR_SERVERFAULT:
1346             (void) strcpy(str, "Server fault");
1347             break;
1348         case NFS3ERR_BADTYPE:
1349             (void) strcpy(str, "Bad type");
1350             break;
1351         case NFS3ERR_JUKEBOX:
1352             (void) strcpy(str, "Jukebox");
1353             break;
1354         case NFS3ERR_RFS_TIMEOUT:
1355                 (void) strcpy(str, "Timeout");
1356                 break;
1357         default:
1358             (void) sprintf(str, "Unknown status %d", status);
1359             break;
1360     }
1361     return (str);
1362 }
1363
1364 /*
1365  * Check the gettimeofday() resolution. If the resolution
1366  * is in chunks bigger than SFS_MIN_RES then the client
1367  * does not have a usable resolution for running the
1368  * benchmark.
1369  */
1370 static void
1371 check_clock(void)
1372 {
1373         double time_res;
1374         char tmp_hostname[HOSTNAME_LEN];
1375
1376         time_res = get_resolution();
1377         getmyhostname(tmp_hostname, HOSTNAME_LEN);
1378         if( time_res > (double)SFS_MIN_RES )
1379         {
1380                 (void) fprintf(stderr,
1381                 "\n%s: Clock resolution too poor to obtain valid results.\n",
1382                         tmp_hostname);
1383                 (void) fprintf(stderr,
1384                 "%s: Clock resolution %f Micro seconds.\n", tmp_hostname,
1385                         time_res);
1386                 exit(175);
1387         }
1388         else
1389         {
1390                 (void) fprintf(stderr,
1391                 "\n%s: Good clock resolution [ %f ] Micro seconds.\n",
1392                         tmp_hostname, time_res);
1393         }
1394 }
1395
1396 /*
1397  * Lifted code from Iozone with permission from author. (Don Capps)
1398  * Returns the resolution of the gettimeofday() function
1399  * in microseconds.
1400  */
1401 static double
1402 get_resolution(void)
1403 {
1404         double starttime, finishtime, besttime;
1405         long  j,delay;
1406         int k;
1407
1408         finishtime=time_so_far1(); /* Warm up the instruction cache */
1409         starttime=time_so_far1();  /* Warm up the instruction cache */
1410         delay=j=0;                 /* Warm up the data cache */
1411         for(k=0;k<10;k++)
1412         {
1413                 while(1)
1414                 {
1415                         starttime=time_so_far1();
1416                         for(j=0;j< delay;j++)
1417                         ;
1418                         finishtime=time_so_far1();
1419                         if(starttime==finishtime)
1420                                 delay++;
1421                         else
1422                         {
1423                                 if(k==0)
1424                                         besttime=(finishtime-starttime);
1425                                 if((finishtime-starttime) < besttime)
1426                                         besttime=(finishtime-starttime);
1427                                 break;
1428                         }
1429                 }
1430         }
1431          return(besttime);
1432 }
1433
1434 /*
1435  * Lifted code from Iozone with permission from author. (Don Capps)
1436  * Returns current result of gettimeofday() in microseconds.
1437  */
1438 /************************************************************************/
1439 /* Time measurement routines.                                           */
1440 /* Return time in microseconds                                          */
1441 /************************************************************************/
1442
1443 static double
1444 time_so_far1(void)
1445 {
1446         /* For Windows the time_of_day() is useless. It increments in 55 */
1447         /* milli second increments. By using the Win32api one can get */
1448         /* access to the high performance measurement interfaces. */
1449         /* With this one can get back into the 8 to 9 microsecond */
1450         /* resolution.  */
1451 #ifdef Windows
1452         LARGE_INTEGER freq,counter;
1453         double wintime;
1454         double bigcounter;
1455
1456         QueryPerformanceFrequency(&freq);
1457         QueryPerformanceCounter(&counter);
1458         bigcounter=(double)counter.HighPart *(double)0xffffffff +
1459                 (double)counter.LowPart;
1460         wintime = (double)(bigcounter/(double)freq.LowPart);
1461         return((double)wintime*1000000.0);
1462 #else
1463 #if defined (OSFV4) || defined(OSFV3) || defined(OSFV5)
1464   struct timespec gp;
1465
1466   if (getclock(TIMEOFDAY, (struct timespec *) &gp) == -1)
1467     perror("getclock");
1468   return (( (double) (gp.tv_sec)*1000000.0) +
1469     ( ((float)(gp.tv_nsec)) * 0.001 ));
1470 #else
1471   struct timeval tp;
1472
1473   if (gettimeofday(&tp, (struct timezone *) NULL) == -1)
1474     perror("gettimeofday");
1475   return ((double) (tp.tv_sec)*1000000.0) +
1476     (((double) tp.tv_usec) );
1477 #endif
1478 #endif
1479 }
1480
1481 static void
1482 usage(void)
1483 {
1484         fprintf(stderr, "trace play usage");
1485 }
1486 extern void init_file_system (void)
1487 {
1488         return;
1489 }
1490
1491 extern void init_dep_tab (void)
1492 {
1493         int i;
1494         memset (&dep_tab, 0, sizeof(dep_tab));
1495 #ifdef notdef
1496         dep_tab[0].disk_index = 0;
1497         dep_tab[1].disk_index = 2;
1498         dep_tab[2].disk_index = 3;
1499         dep_tab[3].disk_index = 5;
1500         dep_tab[4].disk_index = 7;
1501         dep_tab[5].disk_index = 9;
1502         dep_tab[6].disk_index = 11;
1503         dep_tab[7].disk_index = 12;
1504         dep_tab[8].disk_index = 15;
1505         dep_tab[9].disk_index = 17;
1506         dep_tab[10].disk_index = 18;
1507         dep_tab[11].disk_index = 20;
1508         dep_tab_size = 12;
1509         //dep_tab_size = 2;
1510 #endif
1511 }
1512
1513 extern void init_dep_tab_old (void)
1514 {
1515         int i;
1516
1517         Cur_file_ptr = &Export_dir;
1518         Cur_uid = Real_uid;
1519
1520         for (i=0; i<5; i++) {
1521                 dep_tab[i].flag = DEP_FLAG_INIT;
1522                 dep_tab[i].proc = CREATE;
1523                 dep_tab[i].timestamp.tv_sec = trace_starttime.sec;
1524             dep_tab[i].timestamp.tv_usec = trace_starttime.usec+i*10;
1525                 dep_tab[i].init_dep_num = 0;
1526                 dep_tab[i].cur_dep_num = 0;
1527         }
1528
1529         for (i=5; i<10; i++) {
1530                 dep_tab[i].flag = DEP_FLAG_INIT;
1531                 dep_tab[i].proc = CREATE;
1532                 dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i;
1533             dep_tab[i].timestamp.tv_usec = trace_starttime.usec;
1534                 dep_tab[i].init_dep_num = 0;
1535                 dep_tab[i].cur_dep_num = 0;
1536         }
1537
1538         dep_tab[2].init_dep_num = 2;
1539         dep_tab[2].cur_dep_num = 2;
1540         dep_tab[2].dep_ops[0] = 0;
1541         dep_tab[2].dep_ops[1] = 1;
1542
1543         // printf ("trace_starttime (%d %d)\n", trace_starttime.sec, trace_starttime.usec);
1544
1545         /*
1546         for (i=2; i<4; i++) {
1547                 dep_tab[i].flag = DEP_FLAG_INIT;
1548                 dep_tab[i].proc = CREATE;
1549                 dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i*10;
1550             dep_tab[i].timestamp.tv_usec = trace_starttime.usec;
1551                 dep_tab[i].init_dep_num = 0;
1552                 dep_tab[i].cur_dep_num = 0;
1553         }
1554         */
1555
1556         dep_tab_size = 10;
1557
1558         for (i=0; i<dep_tab_size; i++)
1559         {
1560                 printf("dep_tab[%d].timestamp (%d %d)\n", i, dep_tab[i].timestamp.tv_sec, dep_tab[i].timestamp.tv_usec);
1561         }
1562 }
1563
1564 void show_fhandle (nfs_fh3 * fhp)
1565 {
1566         struct knfs_fh * kfhp = (struct knfs_fh *)fhp;
1567
1568         int dev;
1569
1570         if (quiet_flag)
1571                 return;
1572
1573         RFS_ASSERT (kfhp->fh_version == 1);
1574         RFS_ASSERT (kfhp->fh_fsid_type == 0);
1575         RFS_ASSERT (kfhp->fh_auth_type == 0);
1576
1577         dev = ntohs(kfhp->fh_dev_major);
1578         dev = dev<<8;
1579         dev = dev + ntohs(kfhp->fh_dev_minor);
1580
1581         /* kfhp->fh_dev_ino hold the inode number of export point of the mounted
1582          * file system. For example, if /tmp/t1 is exported, /tmp/t1/t2 is mounted,
1583          * then fh_dev_ino hold the inode number of t1, not t2
1584          */
1585
1586         switch (kfhp->fh_fileid_type) {
1587                 case 0:
1588                         printf("fh:type 0 root dev 0x%x dev_ino %d\n", dev, kfhp->fh_dev_ino);
1589                         break;
1590                 case 1:
1591                         printf("fh:type 1 %d %x dev %x dev_ino %x\n",
1592                                 kfhp->fh_ino, kfhp->fh_generation, dev, kfhp->fh_dev_ino);
1593                         break;
1594                 case 2:
1595                         printf("fh:type2 %d %x dirino %d dev 0x%x dev_ino %x\n",
1596                                 kfhp->fh_ino, kfhp->fh_generation, kfhp->fh_dirino, dev, kfhp->fh_dev_ino);
1597                         break;
1598                 default:
1599                         RFS_ASSERT (0);
1600         }
1601 }
1602
1603 nfs_fh3 zero_fhandle;
1604 int init_fh_map ()
1605 {
1606         memset (fh_map, 0, sizeof (fh_map));
1607         memset(fh_htable, 0, sizeof (fh_htable));
1608         memset (&zero_fhandle, 0, sizeof(nfs_fh3));
1609         printf ("SIZE of fh map %d KB\n", sizeof (fh_map)/1000);
1610         fh_i = 0;
1611 }
1612
1613 int add_fh (int map_flag, char * trace_fh, char * path, nfs_fh3 * play_fh)
1614 {
1615         char * old_trace_fh;
1616
1617         /* first lookup if the entry for fh is already in the table */
1618     struct generic_entry * p;
1619
1620     p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
1621         if (p) {
1622                 RFS_ASSERT (fh_map[p->key3].flag = FH_MAP_FLAG_PARTIAL);
1623                 RFS_ASSERT (map_flag ==FH_MAP_FLAG_COMPLETE);
1624                 fh_map[p->key3].flag = map_flag;
1625                 RFS_ASSERT (!memcmp(fh_map[p->key3].trace_fh, trace_fh, TRACE_FH_SIZE));
1626                 RFS_ASSERT (!strcmp(fh_map[p->key3].path, path));
1627                 RFS_ASSERT (!memcmp(&fh_map[p->key3].play_fh, &zero_fhandle, sizeof(nfs_fh3)));
1628                 memcpy (&fh_map[p->key3].play_fh, play_fh, sizeof (nfs_fh3));
1629                 if ((fh_map_debug==1)) // || (stage ==TRACE_PLAY_STAGE))
1630                         printf ("update the play_fh for trace_fh %s path %s \n", trace_fh, path);
1631                 return 0;
1632         }
1633
1634         fh_map[fh_i].flag = map_flag;
1635         fh_map[fh_i].lock = 0;
1636         memcpy(fh_map[fh_i].trace_fh, trace_fh, TRACE_FH_SIZE);
1637
1638         RFS_ASSERT (strlen(path) < MAX_PLAY_PATH_SIZE);
1639         strcpy (fh_map [fh_i].path, path);
1640         if (map_flag==FH_MAP_FLAG_COMPLETE)
1641                 memcpy (&fh_map[fh_i].play_fh, play_fh, sizeof(nfs_fh3));
1642         else
1643                 memset (&fh_map[fh_i].play_fh, 0, sizeof(nfs_fh3));
1644
1645         if ((fh_map_debug==1)) { // || (stage ==TRACE_PLAY_STAGE)) {
1646                 printf ("insert trace_fh %s path %s play_fh:\n", trace_fh, path);
1647                 if (map_flag == FH_MAP_FLAG_COMPLETE)
1648                         show_fhandle(play_fh);
1649                 else
1650                         printf("null\n");
1651         }
1652
1653 /*
1654         if (map_flag == FH_MAP_FLAG_DISCARD)
1655                 printf ("insert flag %d trace_fh %s path %s play_fh:\n", map_flag, trace_fh, path);
1656 */
1657
1658     generic_insert(trace_fh, TRACE_FH_SIZE, fh_i, fh_htable, FH_HTABLE_SIZE);
1659
1660         fh_i = (fh_i+1);
1661         RFS_ASSERT (fh_i < FH_MAP_SIZE);
1662
1663     return 0;
1664 };
1665
1666 fh_map_t * lookup_fh (char * trace_fh )
1667 {
1668     struct generic_entry * p;
1669     p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
1670         if (fh_map_debug==1)
1671                 printf ("lookup trace_fh %s\n", trace_fh);
1672
1673     if (p) {
1674                 if (fh_map_debug==1) {
1675                         printf ("found: fh_i %d path %s play_fh:", p->key3, fh_map[p->key3].path);
1676                         show_fhandle(&fh_map[p->key3].play_fh);
1677                 }
1678         return (&(fh_map[p->key3]));
1679     } else {
1680                 //printf ("lookup_fh %s not found\n", trace_fh);
1681                 if (stage != READ_DEP_TAB_STAGE && (fh_map_debug==1)) {
1682                         printf ("lookup not found trace_fh %s\n", trace_fh);
1683                 }
1684         return NULL;
1685         }
1686         RFS_ASSERT (0);
1687 }
1688
1689 int delete_fh (char * trace_fh, int fh_map_index)
1690 {
1691     generic_delete (trace_fh, TRACE_FH_SIZE, fh_map_index, fh_htable, FH_HTABLE_SIZE);
1692     return 0;
1693 };
1694
1695 void lookup_init_filesystem (nfs_fh3 * parent, char * name, nfs_fh3 * result)
1696 {
1697     LOOKUP3args         args;
1698     LOOKUP3res          reply;          /* the reply */
1699     enum clnt_stat      rpc_stat;       /* result from RPC call */
1700     struct ladtime      start;
1701     struct ladtime      stop;
1702         static int i=0;
1703
1704     /* set up the arguments */
1705     (void) memcpy((char *) &args.what.dir, (char *) parent,
1706                                                         sizeof (nfs_fh3));
1707     args.what.name = name;
1708     (void) memset((char *) &reply.resok.object, '\0', sizeof (nfs_fh3));
1709
1710     /* make the call */
1711     sfs_gettime(&start);
1712     rpc_stat = clnt_call(NFS_client, NFSPROC3_LOOKUP,
1713                         xdr_LOOKUP3args, (char *) &args,
1714                         xdr_LOOKUP3res, (char *) &reply,
1715                         Nfs_timers[Init]);
1716     sfs_gettime(&stop);
1717
1718         if (rpc_stat !=RPC_SUCCESS) {
1719                 printf("rpc_stat %d\n", rpc_stat);
1720                 perror("");
1721         }
1722     RFS_ASSERT (rpc_stat == RPC_SUCCESS);
1723         RFS_ASSERT (reply.status == NFS3_OK);
1724         (void) memcpy((char *) result, (char *) &reply.resok.object, sizeof (nfs_fh3));
1725 }
1726
1727 void read_fh_map(char * fh_map_file)
1728 {
1729         FILE * fp;
1730         int i = 0;
1731         char buf[1024];
1732         char trace_fh[TRACE_FH_SIZE];
1733         char intbuf[9];
1734         char * trace_path;
1735         char * p;
1736         int map_flag;
1737 #define MAX_PATH_DEPTH 20
1738         nfs_fh3 parents[MAX_PATH_DEPTH];
1739         char * lookup_path_ptr[MAX_PATH_DEPTH];
1740         char lookup_path [MAX_PLAY_PATH_SIZE];
1741         int depth;
1742         int new_dir_flag = 0;
1743
1744         depth = 0;
1745         memset(lookup_path_ptr, 0, sizeof(lookup_path_ptr));
1746         memcpy(&parents[depth], &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
1747         strcpy(lookup_path, "/");
1748         lookup_path_ptr[depth]=&lookup_path[0];
1749
1750         fp = fopen(fh_map_file, "r");
1751         RFS_ASSERT (fp!=NULL);
1752
1753         intbuf[8]=0;
1754
1755         memset(buf, 0, sizeof(buf));
1756         while (fgets(buf, 1024, fp)) {
1757
1758                 if (fh_i % 10000==0)
1759                         printf("%d fh_map entry read\n", fh_i);
1760
1761                 RFS_ASSERT (buf[strlen(buf)-1]=='\n');
1762                 buf[strlen(buf)-1]=0;
1763                 if (fh_map_debug) {
1764                         printf("%d fgets return %s\n", fh_i, buf);
1765                         printf("depth %d lookup_path %s\n", depth, lookup_path);
1766                 }
1767                 //for (i=0; i<=depth; i++)
1768                         //printf("lookup_path_ptr[%d] %s ", i, lookup_path_ptr[i]);
1769                 //printf("\n");
1770 #ifdef COMPRESS_TRACE_FH
1771                 for (i=0; i<TRACE_FH_SIZE/8; i++) {
1772                         strncpy(intbuf, buf+i*8, 8);
1773                         sscanf(intbuf, "%x", trace_fh+i*8); // maybe it should be 4, anyway we don't compress for now
1774                 }
1775                 trace_path = buf+TRACE_FH_SIZE*2+1;             /* +1 the trace contains only initial file handle */
1776 #else
1777                 memcpy(trace_fh, buf, TRACE_FH_SIZE);
1778                 trace_path = buf + TRACE_FH_SIZE +1;
1779 #endif
1780 #ifdef TRACE_CONTAIN_LATER_FHANDLE
1781                 trace_path = +=2;       /* +3 if the trace contains both initial and later created file handle */
1782 #endif
1783
1784 #ifdef NO_DEPENDENCY_TABLE
1785                 if (!strncmp (trace_path, "DISCARD", 7)) {
1786                         map_flag = FH_MAP_FLAG_DISCARD;
1787                         add_fh (map_flag, buf, trace_path, 0);
1788                         continue;
1789                 }
1790 #endif
1791
1792                 p = trace_path+strlen(trace_path)-2;
1793                 while (*p!='/')
1794                         p--;
1795                 p++;
1796                 //RFS_ASSERT (p-trace_path<=strlen(lookup_path)+1);
1797                 //RFS_ASSERT (p>trace_path);
1798
1799                 if (strncmp(lookup_path, trace_path, p-trace_path)) {
1800                         printf("strncmp lookup_path %s trace_path %s for length %d\n", lookup_path, trace_path, p-trace_path);
1801                 }
1802                 RFS_ASSERT (!strncmp(lookup_path, trace_path, p-trace_path));
1803                 //while (strncmp(lookup_path, trace_path, p-trace_path)) {      /* one step deeper */
1804                 while (strlen(lookup_path)>p-trace_path && depth>0) {
1805                         //printf("depth--\n");
1806                         if (depth<=0)
1807                                 printf ("lookup_path %s trace_path %s p-trace_path %d depth %d\n", lookup_path, trace_path, p-trace_path, depth);
1808                         RFS_ASSERT (depth>0);
1809                         *lookup_path_ptr[depth]=0;
1810                         lookup_path_ptr[depth]=0;
1811                         depth--;
1812                 }
1813                 RFS_ASSERT (strlen(lookup_path)==(p-trace_path) || (depth==0));
1814
1815
1816 #ifdef TRACE_CONTAIN_LATER_FHANDLE
1817                 if (buf[TRACE_FH_SIZE*2+1]=='Y') {
1818                         map_flag = FH_MAP_FLAG_COMPLETE;
1819                 } else {
1820                         map_flag = FH_MAP_FLAG_PARTIAL;
1821                         RFS_ASSERT (buf[TRACE_FH_SIZE*2+1]=='N');
1822                 }
1823 #else
1824                 map_flag = FH_MAP_FLAG_COMPLETE;
1825 #endif
1826                 if ((*(p+strlen(p)-1))=='/') {
1827                         *(p+strlen(p)-1)=0;
1828                         new_dir_flag = 1;
1829                 } else
1830                         new_dir_flag = 0;
1831
1832                 if (map_flag == FH_MAP_FLAG_COMPLETE) {
1833                         lookup_init_filesystem (&parents[depth], p, &parents[depth+1]);
1834                         add_fh (map_flag, buf, trace_path, &parents[depth+1]);
1835                 } else
1836                         add_fh (map_flag, buf, trace_path, 0);
1837
1838                 if (new_dir_flag) {
1839                         /* the new fhandle is of a directory */
1840                         lookup_path_ptr[depth+1] = lookup_path+strlen(lookup_path);
1841                         strcat (lookup_path, p);
1842                         strcat (lookup_path, "/");
1843
1844                         //printf("depth++\n");
1845                         depth++;
1846                 }
1847
1848                 memset(buf, 0, sizeof(buf));
1849         }
1850
1851         if (fh_map_debug) {
1852                 for (i=0; i<fh_i; i++) {
1853                         int * p1 = (int *)&(fh_map[i].play_fh);
1854 #ifdef COMPRESS_TRACE_FH
1855                         int * p = (int *)fh_map[i].trace_fh;
1856                         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",
1857                          i, *p, *(p+1), *(p+2), *(p+3), *(p+4), *(p+5), *(p+6), *(p+7), fh_map[i].path,
1858                          *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
1859 #else
1860                         printf("fh_map[%d].trace_fh %s path %s \nnew_filehandle %8x%8x%8x%8x%8x%8x%8x%8x\n",
1861                          i, fh_map[i].trace_fh, fh_map[i].path,
1862                          *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
1863                 }
1864 #endif
1865
1866                 fprintf(stderr, "total %d requests \n", i);
1867         }
1868 }
1869
1870 int f()
1871 {
1872         return 1;
1873 }
1874
1875 inline void finish_request (int biod_index, int dep_index, int status)
1876 {
1877         /* the ending operation, same as when a request time out */
1878         dep_tab[dep_index].stop = biod_reqp[biod_index].stop;   /* RFS: to dump data */
1879         dep_tab[dep_index].status = status;
1880         event_order[event_order_index++] = -dep_index;
1881         biod_reqp[biod_index].in_use = FALSE;
1882         dep_tab[dep_index].flag = DEP_FLAG_DONE;
1883         if (is_dir_op(dep_tab[dep_index].proc)) {
1884                 int j;
1885                 RFS_ASSERT (dep_tab[dep_index].fh->lock = 1);
1886                 dep_tab[dep_index].fh->lock = 0;
1887                 if (dep_tab[dep_index].proc==RENAME)
1888                         dep_tab[dep_index].fh_2->lock = 0;
1889                 j = dep_tab[dep_index].fh-fh_map;
1890                 if (dependency_debug) {
1891                         printf ("fh_map[%d] is UNlocked\n",j);
1892                         printf ("trace_fh %d path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
1893                         printf ("trace_fh %d path %s\n", fh_map[j].trace_fh, fh_map[j].path);
1894                 }
1895         }
1896         num_out_reqs --;
1897 }
1898
1899 /* the request argument may have pointers pointing to buffers, e.g. the name in lookup,
1900  * the target of symlink, the write data */
1901 char arg_res[MAX_ARG_RES_SIZE];
1902 int poll_timeout = 0;           /* timeout in usecs */
1903 char buf1 [MAX_BUF1_SIZE];
1904 char buf2 [MAX_BUF2_SIZE];
1905 #define NFS3_REPLY_MISS -1
1906
1907 int execute_next_request ()
1908 {
1909         int dep_index;
1910         int proc;
1911         char * line;
1912         struct biod_req * reqp;
1913         sfs_op_type *op_ptr;            /* per operation info */
1914         struct ladtime call_timeout;
1915
1916         start_profile (&valid_get_nextop_profile);
1917         start_profile (&invalid_get_nextop_profile);
1918         dep_index = get_nextop();
1919         if (dep_index == -1) {
1920                 end_profile (&invalid_get_nextop_profile);
1921                 return dep_index;
1922         };
1923         end_profile (&valid_get_nextop_profile);
1924
1925         start_profile (&prepare_argument_profile);
1926         line = dep_tab[dep_index].line;
1927         if ((dep_index%(10000))==0) {
1928 #ifndef TIME_PLAY
1929                 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);
1930 #else
1931                 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);
1932 #ifdef SPEED_UP
1933                 if (can_not_catch_speed_num < 2000) {
1934                         PLAY_SCALE ++;
1935                         printf ("set PLAY_SCALE to %d\n", PLAY_SCALE);
1936                 };
1937                 if (can_not_catch_speed_num > 50000) {
1938                         PLAY_SCALE /= 2;
1939                 } else {
1940                         if (can_not_catch_speed_num > 5000) {
1941                                 PLAY_SCALE -= 2;
1942                                 if (PLAY_SCALE < 1)
1943                                         PLAY_SCALE = 1;
1944                         }
1945                 }
1946 #endif
1947                 can_not_catch_speed_num = 0;
1948 #endif
1949         }
1950         if (rfs_debug)
1951                 printf ("processing dep_tab[%d] disk_index %d %s\n", dep_index, dep_tab[dep_index].disk_index, line);
1952
1953         proc = dep_tab[dep_index].proc;
1954         rfs_Ops[proc].setarg (dep_index, line, arg_res, buf1, buf2);
1955
1956         op_ptr = &Ops[proc];
1957         reqp = get_biod_req (dep_index);
1958         RFS_ASSERT (reqp);
1959
1960         call_timeout.sec = 4; //Nfs_timers[op_ptr->call_class].tv_sec;
1961         call_timeout.usec = Nfs_timers[op_ptr->call_class].tv_usec;
1962
1963     /* make the call */
1964     sfs_gettime(&(reqp->start));
1965         end_profile (&prepare_argument_profile);
1966         start_profile (&biod_clnt_call_profile);
1967 #define REAL_PLAY
1968 #ifdef REAL_PLAY
1969     reqp->xid = biod_clnt_call(NFS_client, rfs_Ops[proc].nfsv3_proc,
1970                                         rfs_Ops[proc].xdr_arg, arg_res);
1971 #else
1972
1973         reqp->xid = dep_index+1;        /* just fake a message id and let it expire */
1974 #endif
1975     if (reqp->xid != 0) {
1976         reqp->timeout = reqp->start;
1977         ADDTIME (reqp->timeout, call_timeout);
1978         num_out_reqs++;
1979         dep_tab[dep_index].flag = DEP_FLAG_SENT;
1980                 event_order[event_order_index++] = dep_index;
1981     } else
1982                 RFS_ASSERT (0);
1983
1984         dep_tab[dep_index].start = reqp->start; /* RFS: to dump data */
1985         end_profile (&biod_clnt_call_profile);
1986 }
1987
1988 void check_reply (int proc, int biod_index, int dep_index, int status, char * errmsg, int trace_reply_status)
1989 {
1990         if (((status!=trace_reply_status)) && (trace_reply_status!=NFS3_REPLY_MISS)) {
1991                 if (rfs_debug)
1992                         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);
1993 #ifndef TAKE_CARE_UNLOOKED_UP_NON_NEW_FILES
1994                 /* these files is not looked up and is not create/mkdir/symlink/link/mknod ed before they
1995                  * are refered by name through rename, remove
1996                  */
1997                 if ((proc==RENAME || proc==REMOVE) && (status==NFS3ERR_NOENT) && (trace_reply_status ==0)) {
1998                         /* current initialization doesnot take care of rename source, if there is no
1999                          * create or lookup before that source, the source object will not exist when
2000                          * rename occurs
2001                          */
2002                         RFS_ASSERT (1);
2003                         rename_rmdir_noent_reply_num++;
2004                 } else
2005 #endif
2006 #ifndef TAKE_CARE_SYMBOLIC_LINK
2007                 if ((proc==LOOKUP) && (status==NFS3_OK) && (trace_reply_status==NFS3ERR_NOENT)) {
2008                         /* in the original trace, first lookup return NOENT, then symlink is executed, then lookup return OK
2009                          * the initialization considers only the lookup return OK and created the file in the initialization
2010                          * so in trace play the first lookup return OK
2011                          */
2012                         RFS_ASSERT (1);
2013                 } else if ((proc==SYMLINK) && (status == NFS3ERR_EXIST) && (trace_reply_status == 0)) {
2014                         /* due to similar reason as above, the initialization code initializes the symbolic link as a normal
2015                          * file already
2016                          */
2017                         RFS_ASSERT (1);
2018                 } else
2019 #endif
2020 #ifndef TAKE_CARE_NOEMPTY_RMDIR
2021                 /* the remove packet seems got lost in the trace capture, so replay can not finish */
2022                 if ((proc==RMDIR) && (status==NFS3ERR_NOTEMPTY)) {
2023                         RENAME3args             args;
2024                         RENAME3res              reply;          /* the reply */
2025                         RMDIR3args * rmdir_argp;
2026                         enum clnt_stat rpc_stat;        /* result from RPC call */
2027
2028                         rfs_Ops[proc].setarg (dep_index, dep_tab[dep_index].line, arg_res, buf1, buf2);
2029                         rmdir_argp = (RMDIR3args *)arg_res;
2030
2031                         memcpy(&args.from, &(rmdir_argp->object), sizeof (diropargs3));
2032                         memcpy(&args.to.dir, &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
2033                         args.from.name = buf1;  /* the buf1 is already filled when parsing rmdir */
2034                         args.to.name = buf2;
2035                         sprintf(buf2, "rmdir_%d_%s", dep_tab[dep_index].disk_index, rmdir_argp->object.name);
2036
2037                         rpc_stat = clnt_call(NFS_client, NFSPROC3_RENAME,
2038                         xdr_RENAME3args, (char *) &args,
2039                         xdr_RENAME3res, (char *) &reply,
2040                                 Nfs_timers[Init]);
2041                         RFS_ASSERT (rpc_stat == RPC_SUCCESS);
2042                         if (reply.status!=NFS3_OK)
2043                                 printf ("change rmdir into rename, reply.status %d\n", reply.status);
2044                         RFS_ASSERT (reply.status==NFS3_OK);
2045                         rmdir_not_empty_reply_num ++;
2046 #endif
2047 #ifndef TAKE_CARE_ACCESS_ERROR
2048                 } else if ((status==0) && (trace_reply_status==NFS3ERR_ACCES)) {
2049                         loose_access_control_reply_num ++;
2050 #endif
2051 #ifdef NO_DEPENDENCY_TABLE
2052                 } else if ((proc==LOOKUP) && (status==NFS3ERR_NOENT) && (trace_reply_status==NFS3_OK)) {
2053                         lookup_err_due_to_rename_num ++;
2054 #endif
2055                 } else {
2056                         int i;
2057                         for (i=min_dep_index; i<max_dep_index; i++)
2058                                 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);
2059                         RFS_ASSERT (0);
2060                 }
2061         } else
2062                 proper_reply_num ++;
2063
2064 }
2065
2066 /* return -1 if there is no reply being received
2067  * return the dep_index if the corresponding reply has been received
2068  */
2069 int receive_next_reply (int busy_flag)
2070 {
2071         int dep_index;
2072         int biod_index;
2073         int proc;
2074         char * line;
2075         char * reply_line;
2076         sfs_op_type *op_ptr;            /* per operation info */
2077         int ret;
2078         int status;
2079         int trace_reply_status;
2080         char * errmsg;
2081
2082         /* wait for reply */
2083         start_profile (&valid_poll_and_get_reply_profile);
2084         start_profile (&invalid_poll_and_get_reply_profile);
2085 /*
2086         if (busy_flag == IDLE)
2087                 poll_timeout = 0;
2088         else
2089                 poll_timeout = 10000;
2090 */
2091         biod_index = poll_and_get_reply (poll_timeout);
2092         if (biod_index==-1) {
2093                 end_profile (&invalid_poll_and_get_reply_profile);
2094                 return -1;
2095         };
2096         end_profile (&valid_poll_and_get_reply_profile);
2097
2098         start_profile (&decode_reply_profile);
2099         /* check the corresponding request */
2100         dep_index = biod_reqp[biod_index].dep_tab_index;
2101         proc = dep_tab[dep_index].proc;
2102         op_ptr = &Ops[proc];
2103
2104         if (dep_tab[dep_index].flag != DEP_FLAG_SENT) {
2105                 printf("dep_tab[%d].flag %d proc %d status %d start %d:%d stop %d:%d\n",
2106                         dep_index, dep_tab[dep_index].flag, proc, dep_tab[dep_index].status,
2107                         dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec,
2108                         dep_tab[dep_index].stop.sec, dep_tab[dep_index].stop.usec );
2109                 printf ("received reply for timeout requests dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
2110                 return dep_index;
2111         }
2112         RFS_ASSERT (dep_tab[dep_index].flag == DEP_FLAG_SENT);
2113
2114         /* decode the reply */
2115         rfs_Ops[proc].setres (arg_res, buf1);
2116         ret = proc_header (NFS_client, rfs_Ops[proc].xdr_res, arg_res);
2117         RFS_ASSERT (ret == RPC_SUCCESS);
2118         status = *((int *)arg_res);
2119         errmsg = nfs3_strerror (status);
2120         end_profile (&decode_reply_profile);
2121
2122         start_profile (&check_reply_profile);
2123         /* compare with the reply in the trace */
2124         line = dep_tab[dep_index].line;
2125         reply_line = find_reply_line (line, dep_tab[dep_index].disk_index);
2126         if (reply_line == NULL) {
2127                 //printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
2128                 trace_reply_status = NFS3_REPLY_MISS;
2129                 missing_reply_num ++;
2130         } else
2131                 trace_reply_status = find_reply_status (reply_line);
2132
2133         /* print the result, trace play progress indicator */
2134         if ((dep_index %10000)==0 || rfs_debug)
2135                 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);
2136
2137         /* error checking */
2138         check_reply (proc, biod_index, dep_index, status, errmsg, trace_reply_status);
2139
2140         /* free resources */
2141         finish_request (biod_index, dep_index, status);
2142
2143         /* get statistics */
2144         if (status == trace_reply_status) {
2145                 op_ptr->results.good_calls++;
2146                 Ops[TOTAL].results.good_calls++;
2147         } else {
2148                 op_ptr->results.bad_calls++;
2149                 Ops[TOTAL].results.bad_calls++;
2150         }
2151         sfs_elapsedtime (op_ptr, &(biod_reqp[biod_index].start), &(biod_reqp[biod_index].stop));
2152         end_profile (&check_reply_profile);
2153
2154         //start_profile (&add_create_object_profile);
2155 #ifndef TAKE_CARE_SYMBOLIC_LINK
2156         if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==MKNOD)) {
2157 #else
2158         if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==SYMLINK || proc==MKNOD)) {
2159 #endif
2160                 RFS_ASSERT (status == NFS_OK);
2161                 RFS_ASSERT (reply_line);
2162                 add_new_file_system_object(proc, dep_index, line, reply_line);
2163         }
2164         //end_profile (&add_create_object_profile);
2165 }
2166
2167 void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line)
2168 {
2169         char * child_trace_fh;
2170         fh_map_t * parent_entryp;
2171         char component_name[MAX_PLAY_PATH_SIZE];
2172         char * parent_trace_fh;
2173         char child_path[MAX_PLAY_PATH_SIZE];
2174         post_op_fh3 * post_op_fh3_child;
2175         char * reply_trace_fh;
2176         nfs_fh3 * child_fh3;
2177
2178         parent_trace_fh = strstr (line, "fh");
2179         RFS_ASSERT (parent_trace_fh);
2180         parent_trace_fh +=3;
2181         parent_entryp = lookup_fh (parent_trace_fh);
2182         RFS_ASSERT (parent_entryp);
2183         parse_name (parent_trace_fh+65, component_name);
2184         strcpy (child_path, parent_entryp->path);
2185         strcat (child_path, "/");
2186         strcat (child_path, component_name);
2187
2188         /* find the corresponding create request */
2189         //printf ("before find reply trace_fh reply_line %s\n", reply_line);
2190         reply_trace_fh = find_reply_trace_fh (reply_line);
2191         RFS_ASSERT (reply_trace_fh != NULL);
2192         switch (proc) {
2193         case CREATE:
2194                 RFS_ASSERT (((CREATE3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2195                 child_fh3 = &((CREATE3res *)arg_res)->res_u.ok.obj.handle;
2196                 break;
2197         case MKDIR:
2198                 RFS_ASSERT (((MKDIR3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2199                 child_fh3 = &((MKDIR3res *)arg_res)->res_u.ok.obj.handle;
2200                 break;
2201         case SYMLINK:
2202                 RFS_ASSERT (((SYMLINK3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2203                 child_fh3 = &((SYMLINK3res *)arg_res)->res_u.ok.obj.handle;
2204                 break;
2205         case MKNOD:
2206                 RFS_ASSERT (((MKNOD3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2207                 child_fh3 = &((MKNOD3res *)arg_res)->res_u.ok.obj.handle;
2208                 break;
2209         case LOOKUP:
2210                 RFS_ASSERT (proc==LOOKUP);
2211                 child_fh3 = &((LOOKUP3res *)arg_res)->res_u.ok.object;
2212                 break;
2213         default:
2214                 RFS_ASSERT (0);
2215         }
2216         RFS_ASSERT (reply_trace_fh[TRACE_FH_SIZE]==' ');
2217         reply_trace_fh[TRACE_FH_SIZE] = 0;
2218         add_fh (FH_MAP_FLAG_COMPLETE, reply_trace_fh, child_path, child_fh3);   /* exist flag is not used now, set to 1 */
2219         reply_trace_fh[TRACE_FH_SIZE] = ' ';
2220 }
2221
2222 /* initialize timestamp and proc field of dep_tab entry */
2223 void trace_play(void)
2224 {
2225
2226         /* The flag to indicate whether trace_player is BUSY. Trace_player is BUSY
2227          * when either there is request to send or there is reply being
2228          * received. Otherwise it is IDLE. The timeout for polling replies
2229          * is set to 0 when BUSY, it is set to the waiting time to the first
2230          * request outside of current <min_dep_index, max_dep_index> window when IDLE.
2231          */
2232         int busy_flag = BUSY;
2233
2234         //int dep_index;                /* index into dependency table: dep_tab */
2235         //int biod_index;       /* index into outstanding requests: biod_reqp */
2236
2237         int count = 0;
2238         min_dep_index = 0;
2239         max_dep_index = 0;
2240         adjust_play_window(busy_flag, &poll_timeout);
2241
2242         start_profile (&total_profile);
2243         while ((min_dep_index<dep_tab_size) || (num_out_reqs>0)) {
2244
2245                 if (busy_flag == IDLE) {
2246                         //start_profile (&check_timeout_profile);
2247                         check_timeout();
2248                         //end_profile (&check_timeout_profile);
2249                 }
2250
2251                 //start_profile (&adjust_play_window_profile);
2252                 //adjust_play_window (flag, &poll_timeout);
2253                 //adjust_play_window (flag+(max_dep_index-min_dep_index), &poll_timeout);
2254                 adjust_play_window (busy_flag, &poll_timeout);
2255                 if (rfs_debug)
2256                         printf("num_out_reqs %d\n", num_out_reqs);
2257                 busy_flag = IDLE;
2258                 //end_profile (&adjust_play_window_profile);
2259
2260                 start_profile (&execute_next_request_profile);
2261                 while (execute_next_request()!=-1)
2262                         busy_flag = BUSY;
2263                 end_profile (&execute_next_request_profile);
2264
2265                 start_profile (&receive_next_reply_profile);
2266                 while (receive_next_reply(busy_flag)!=-1)
2267                         busy_flag = BUSY;
2268                 end_profile (&receive_next_reply_profile);
2269         }
2270         end_profile (&total_profile);
2271
2272         print_profile ("total_profile", &total_profile);
2273         printf("\n");
2274         print_profile ("check_timeout", &check_timeout_profile);
2275         printf("\n");
2276         print_profile ("adjust_play_window", &adjust_play_window_profile);
2277         printf("\n");
2278         print_profile ("execute_next_request_profile", &execute_next_request_profile);
2279         print_profile ("valid_get_nextop_profile", &valid_get_nextop_profile);
2280         print_profile ("invalid_get_nextop_profile", &invalid_get_nextop_profile);
2281         print_profile ("prepare_argument", &prepare_argument_profile);
2282         print_profile ("biod_clnt_call", &biod_clnt_call_profile);
2283         printf("\n");
2284         print_profile ("receive_next_reply", &receive_next_reply_profile);
2285         print_profile ("valid_poll_and_get_reply_profile", &valid_poll_and_get_reply_profile);
2286         print_profile ("invalid_poll_and_get_reply_profile", &invalid_poll_and_get_reply_profile);
2287         print_profile ("decode_reply", &decode_reply_profile);
2288         print_profile ("check_reply", &check_reply_profile);
2289         print_profile ("add_create_object", &add_create_object_profile);
2290         printf("\n");
2291
2292         printf ("min_dep_index %d dep_tab_size %d num_out_reqs %d\n", min_dep_index, dep_tab_size, num_out_reqs);
2293 }
2294 /* sfs_c_chd.c */