TBBT/trace_play/sfs_c_chd.c.old

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