2 static char sfs_c_chdSid[] = "@(#)sfs_c_chd.c 2.1 97/10/23";
6 * Copyright (c) 1992-1997,2001 by Standard Performance Evaluation Corporation
8 * Standard Performance Evaluation Corporation (SPEC)
9 * 6585 Merchant Place, Suite 100
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.
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.
20 * The source code is provided to the user or company under the license
21 * agreement for the SPEC Benchmark Suite for this product.
24 /*****************************************************************
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. *
33 *****************************************************************/
36 * -------------------------- sfs_c_chd.c -------------------------
38 * The sfs child. Routines to initialize child parameters,
39 * initialize test directories, and generate load.
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,
47 * int check_access(struct *stat)
48 * int check_fh_access();
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);
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
64 * 04-Jan-92 Pawlowski Added raw data dump hooks.
65 * 16-Dec-91 Wittle Created.
70 * ------------------------- Include Files -------------------------
83 #include <sys/types.h>
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"
94 extern struct hostent *Server_hostent;
96 #define PROB_SCALE 1000L
97 #define _M_MODULUS 2147483647L /* (2**31)-1 */
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
105 * ----------------------- External Definitions -----------------------
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);
113 /* forward definitions for local functions */
114 static int init_rpc(void);
116 /* RFS: forward definitions for local functions */
118 static void init_signal();
119 extern void init_file_system (void);
120 extern void init_dep_tab (void);
121 static void read_trace(char * trace_file);
122 static void read_fh_map();
123 static void init_play (char * mount_point);
124 static void trace_play(void);
125 static void print_result(void);
126 static int get_nextop(void);
127 static int check_timeout(void);
128 static struct biod_req * get_biod_req(int dep_tab_index);
129 static int lookup_biod_req (int xid);
130 static void init_time_offset(void);
131 static void adjust_play_window (int flag, int * poll_timeout);
132 static int poll_and_get_reply (int usecs);
133 static char * nfs3_strerror(int status);
134 static void check_clock(void);
135 static double time_so_far1(void);
136 static double get_resolution(void);
137 static void usage(void);
138 void init_dep_tab_entry (int dep_index);
139 extern fh_map_t * lookup_fh (char * trace_fh );
140 static inline void finish_request (int biod_index, int dep_index, int status);
141 static void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line);
144 * ------------- Per Child Load Generation Rate Variables -----------
146 static uint_t Calls_this_period; /* calls made during the current run period */
147 static uint_t Calls_this_test; /* calls made during the test so far */
148 static uint_t Reqs_this_period; /* reqs made during the current run period */
149 static uint_t Reqs_this_test; /* reqs made during the test so far */
150 static uint_t Sleep_msec_this_test; /* msec slept during the test so far */
151 static uint_t Sleep_msec_this_period;
152 static uint_t Previous_chkpnt_msec; /* beginning time of current run period */
153 static int Target_sleep_mspc; /* targeted sleep time per call */
155 static char io_buf[BUFSIZ]; /* io buffer for print out messages */
158 int Log_fd; /* log fd */
159 char Logname[NFS_MAXNAMLEN]; /* child processes sync logfile */
160 int Validate = 0; /* fake variable */
161 int Child_num = 0; /* fake: child index */
162 int Tcp = 0; /* We implement UDP first */
163 int Client_num = 1; /* fake: number of client */
168 * ------------------------- SFS Child -------------------------
173 printf("sfs3 hostname:mount_dir trace_file fh_map_file\n");
179 #ifdef NO_DEPENDENCY_TABLE
183 fh_map_t * fh_map_entry;
184 int req_num_with_new_fh = 0;
185 int req_num_with_discard_fh = 0;
186 int req_num_with_init_fh =0;
188 for (i=0; i<memory_trace_size; i++) {
189 line = memory_trace[i].line;
190 if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='C') {
191 trace_fh = strstr (line, "fh");
192 RFS_ASSERT (trace_fh);
194 fh_map_entry = lookup_fh (trace_fh);
195 if (fh_map_entry && (fh_map_entry->flag==FH_MAP_FLAG_DISCARD) ) {
196 req_num_with_discard_fh ++;
200 req_num_with_init_fh ++;
202 req_num_with_new_fh ++;
204 dep_tab[dep_tab_size].disk_index = memory_trace[i].disk_index;
205 dep_tab[dep_tab_size].line = memory_trace[i].line;
206 if ((dep_tab_size%100000)==0)
207 printf ("dep_tab[%d].disk_index %d = memory_trace[%d].disk_index %d\n", dep_tab_size, dep_tab[dep_tab_size].disk_index, i, memory_trace[i].disk_index);
214 printf ("read_dep_tab, req_num_with_init_fh %d req_num_with_new_fh %d discard %d\n", req_num_with_init_fh, req_num_with_new_fh, req_num_with_discard_fh);
219 memset (&total_profile, 0, sizeof(total_profile));
221 memset (&execute_next_request_profile, 0, sizeof(execute_next_request_profile));
222 memset (&valid_get_nextop_profile, 0, sizeof(valid_get_nextop_profile));
223 memset (&invalid_get_nextop_profile, 0, sizeof(invalid_get_nextop_profile));
224 memset (&prepare_argument_profile, 0, sizeof(prepare_argument_profile));
225 memset (&biod_clnt_call_profile, 0, sizeof(biod_clnt_call_profile));
227 memset (&receive_next_reply_profile, 0, sizeof(receive_next_reply_profile));
228 memset (&valid_poll_and_get_reply_profile, 0, sizeof(valid_poll_and_get_reply_profile));
229 memset (&invalid_poll_and_get_reply_profile, 0, sizeof(invalid_poll_and_get_reply_profile));
230 memset (&decode_reply_profile, 0, sizeof(decode_reply_profile));
231 memset (&check_reply_profile, 0, sizeof(check_reply_profile));
232 memset (&add_create_object_profile, 0, sizeof(add_create_object_profile));
234 memset (&check_timeout_profile, 0, sizeof(check_timeout_profile));
235 memset (&adjust_play_window_profile, 0, sizeof(adjust_play_window_profile));
238 int main(int argc, char ** argv)
240 extern char * optarg;
243 int memory_trace_size;
245 if (argc==2 && !strcmp(argv[1],"-help")) {
251 getmyhostname(lad_hostname, HOSTNAME_LEN);
255 * Get the uid and gid information.
262 Nfs_timers = Nfs_udp_timers;
267 //init_play (argv[1]);
268 init_play ("capella:/p5/RFSFS");
271 //read_fh_map (argv[3]);
272 read_fh_map ("fh-path-map");
273 init_dep_tab(); /* and dep_tab_size */
274 //read_trace (argv[2]);
275 read_trace ("anon-lair62-011130-1100.txt");
276 stage = READ_DEP_TAB_STAGE;
279 for (i=0; i<dep_tab_size; i++) {
280 RFS_ASSERT (dep_tab[i].flag == DEP_FLAG_FREE)
281 init_dep_tab_entry (i);
283 stage = TRACE_PLAY_STAGE;
293 nfs_version = NFS_V3;
296 /* Set up the signal handlers for all signals */
299 #if (defined(_XOPEN_SOURCE) || defined(USE_POSIX_SIGNALS))
300 struct sigaction sig_act, old_sig_act;
302 /* use XOPEN signal handling */
304 sig_act.sa_handler = generic_catcher;
305 (void)sigemptyset(&sig_act.sa_mask);
306 sig_act.sa_flags = 0;
308 /* signals handlers for signals used by sfs */
309 sig_act.sa_handler = sfs_cleanup;
310 if (sigaction(SIGINT,&sig_act,&old_sig_act) == -1) {
311 perror("sigaction failed: SIGINT");
315 sig_act.sa_handler = sfs_cleanup;
316 if (sigaction(SIGTERM,&sig_act,&old_sig_act) != 0) {
317 perror("sigaction failed: SIGTERM");
321 /* signals handlers for signals used by sfs */
322 (void) signal(SIGINT, sfs_cleanup);
323 // RFS (void) signal(SIGALRM, sfs_alarm);
324 (void) signal(SIGTERM, sfs_cleanup);
330 char * mount_point) /* Mount point for remote FS */
332 char namebuf[NFS_MAXNAMLEN] = "trace_play"; /* unique name for this program */
333 CLIENT * mount_client_ptr; /* Mount client handle */
336 (void) setvbuf(stderr, io_buf, _IOLBF, BUFSIZ);
338 sfs_Myname = namebuf;
341 * May require root priv to perform bindresvport operation
343 mount_client_ptr = lad_getmnt_hand(mount_point);
344 if (mount_client_ptr == NULL) {
349 * should be all done doing priv port stuff
352 if (init_rpc() == -1) {
353 (void) fprintf(stderr, "%s: rpc initialization failed\n", sfs_Myname);
354 (void) generic_kill(0, SIGINT);
360 * finish all priv bindresvport calls
363 if (setuid(Real_uid) != (uid_t)0) {
364 (void) fprintf(stderr,"%s: %s%s", sfs_Myname,
365 "cannot perform setuid operation.\n",
366 "Do `make install` as root.\n");
369 init_mount_point(0, mount_point, mount_client_ptr);
373 * Cleanup client handle for mount point
375 clnt_destroy(mount_client_ptr);
382 void read_trace (char * tracefile)
389 fp = fopen(tracefile, "r");
390 RFS_ASSERT (fp!=NULL);
391 while (fgets(buf, 1024, fp)) {
392 //printf ("buf: %s buf[36] %c\n", buf, buf[36]);
393 //if (buf[36]=='C' || strstr(buf, "create") || strstr(buf, "lookup")) {
394 #ifdef REDUCE_MEMORY_TRACE_SIZE
395 if (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='C' || strstr(buf, "create") ||
396 strstr(buf, "mkdir") || strstr(buf, "symlink") || strstr(buf, "mknod") || strstr(buf, "lookup")) {
398 if (!((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH)))
399 printf("strlen(buf) %d buf %s \n", strlen(buf), buf);
400 RFS_ASSERT ((strlen(buf)>80) && (strlen(buf)<MAX_TRACE_LINE_LENGTH));
402 /* store the request to memory */
403 strcpy (memory_trace[memory_trace_size].line, buf);
404 memory_trace[memory_trace_size].disk_index = disk_index;
405 memory_trace_size ++;
407 if (memory_trace_size >= MAX_MEMORY_TRACE_LINES) {
408 printf ("memory trace size %d is not enough\n", MAX_MEMORY_TRACE_LINES);
411 if ((disk_index%100000)==0)
412 fprintf(stderr, "%d disk trace parsed, store %d trace lines to memory\n", disk_index, memory_trace_size);
413 #ifdef REDUCE_MEMORY_TRACE_SIZE
415 RFS_ASSERT (buf[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
421 fprintf(stderr, "total %d disk lines %d memory lines \n", disk_index, memory_trace_size );
426 #ifdef REDUCE_MEMORY_TRACE_SIZE
427 inline int disk_index_to_memory_index (int disk_index)
429 static int memory_index = 0;
430 if (disk_index > memory_trace[memory_index].disk_index) {
431 while (memory_trace[memory_index].disk_index < disk_index) {
433 RFS_ASSERT (memory_index < MAX_MEMORY_TRACE_LINES);
436 if (disk_index < memory_trace[memory_index].disk_index) {
437 while (memory_trace[memory_index].disk_index > disk_index) {
439 RFS_ASSERT (memory_index >=0);
443 RFS_ASSERT (disk_index == memory_trace[memory_index].disk_index);
447 #define disk_index_to_memory_index(disk_index) disk_index
450 #define get_line_by_disk_index(disk_index) \
451 memory_trace[disk_index_to_memory_index(disk_index)].line
453 inline char * find_reply_line (char * command_line, int cur_disk_index)
458 int request_memory_index = disk_index_to_memory_index (cur_disk_index);
459 for (i=request_memory_index+1; i<request_memory_index+MAX_COMMAND_REPLY_DISTANCE && i<MAX_MEMORY_TRACE_LINES; i++) {
460 line = memory_trace[i].line;
461 if (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R') {
462 p = strchr (&line[TRACE_MSGID_POS], ' ');
464 if (!strncmp(&line[TRACE_MSGID_POS], &command_line[TRACE_MSGID_POS], p-&(line[TRACE_MSGID_POS])))
471 inline int find_reply_status (char * line)
476 //printf ("line %s flag %c\n", line, line[TRACE_COMMAND_REPLY_FLAG_POS]);
477 RFS_ASSERT (line[TRACE_COMMAND_REPLY_FLAG_POS]=='R');
478 if (!strstr(line, "OK")) {
479 p=strstr(line, " 6 read ");
481 p+=strlen(" 6 read ");
483 p = strstr (line, "status=XXX");
486 RFS_ASSERT (*p==' ');
494 sscanf (p, "%x", &i);
495 if ((i<=0) || (i>10000))
496 printf("line %s\n", line);
497 RFS_ASSERT (i>0 && i<10009);
502 inline char * find_reply_trace_fh (char * line)
505 p = strstr (line, "OK fh");
507 printf ("find_reply_trace_fh line %s\n", line);
512 inline int disk_index_to_dep_index(int cur_dep_index, int disk_index)
515 for (i=cur_dep_index; i>min_dep_index; i--) {
516 if (dep_tab[i].disk_index == disk_index)
522 inline int is_play_candidate (int dep_index)
524 #ifndef TAKE_CARE_CREATE_MODE_BY_DAN
525 int trace_reply_status;
527 if ((dep_tab[dep_index].proc==CREATE)) {
528 /* for a failed create in trace, trace_replay just ignore */
529 reply_line = find_reply_line (dep_tab[dep_index].line, dep_tab[dep_index].disk_index);
530 if (reply_line == NULL) {
531 if (dependency_debug)
532 printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
533 trace_reply_status = NFS3_OK;
535 trace_reply_status = find_reply_status (reply_line);
536 /* many time the trace create fail due to access control, but trace_play will success because our access control
537 * may be loose (all uid/gid is mapped to single one 513:513, so we just skip these requests
539 if ((dep_tab[dep_index].proc == CREATE) && (trace_reply_status!=NFS3_OK)) {
540 if (dependency_debug)
541 printf ("disk[%d] ignore failed create in trace, trace_reply_status %d line %s", dep_tab[dep_index].disk_index, trace_reply_status, dep_tab[dep_index].line);
542 failed_create_command_num ++;
547 #ifndef TAKE_CARE_SYMBOLIC_LINK
548 if ((dep_tab[dep_index].proc==READLINK)) { /* send request */
549 skipped_readlink_command_num ++;
553 #ifndef TAKE_CARE_CUSTOM_COMMAND
554 /* this line has a file handle which should belong to discard but it is not
555 * the file handle directly appears as parent directory in a lookup request
556 * the return value is NOENT, the parent directory should have been initialized
557 * but the initialization code just ignored all lookup request which didn't success
558 * including NOENT even though the parent directory is still valid.
560 if ((dep_tab[dep_index].disk_index==262213 ||
561 dep_tab[dep_index].disk_index==214402 )) {
562 skipped_custom_command_num++;
569 inline int is_dir_op (int proc)
586 inline int is_create_op (int proc)
588 if (proc==CREATE || proc==MKDIR || proc==LINK || proc==SYMLINK || proc==MKNOD || proc==RENAME)
593 inline int is_delete_op (int proc)
595 if (proc==REMOVE || proc==RMDIR || proc==RENAME)
600 inline char * find_lead_trace_fh(int proc, char * line)
603 /* check the file handle availability */
604 p = strstr (line, "fh");
606 p+=3; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
610 inline char * find_another_trace_fh(int proc, char * line)
613 /* check the file handle availability */
614 p = strstr (line, "fh2");
616 p+=4; //printf ("check dependency dep_tab[%d] trace_fh %s line %s \n", dep_index, trace_fh, line);
620 /* return the index of next request in dep_tab.
621 * Return -1 if there is no suitable request to send
623 inline int get_nextop(void)
627 static int dep_index = -2;
630 static int min_wait_fhandle_dep_index = DEP_TAB_SIZE;
634 //if (dep_index < min_dep_index-1)
635 // dep_index = min_dep_index-1;
637 dep_index = min_dep_index-1;
638 for (i=0; i<max_dep_index-min_dep_index; i++) {
640 if (dep_index == max_dep_index) {
641 dep_index = min_dep_index;
644 proc = dep_tab[dep_index].proc;
645 flag = dep_tab[dep_index].flag;
647 if (dependency_debug)
648 printf ("get_nextop check dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
649 #ifdef NO_DEPENDENCY_TABLE
650 if (dep_tab[dep_index].flag == DEP_FLAG_INIT) {
651 if (is_play_candidate(dep_index)==TRUE) {
652 /* the trace_fh is the file handle for the operation directory, trace_fh_2 is other file handle
653 * used in the request */
654 if (proc==LINK || proc==RENAME) {
655 dep_tab[dep_index].trace_fh = find_another_trace_fh (proc, dep_tab[dep_index].line);
656 dep_tab[dep_index].trace_fh_2 = find_lead_trace_fh(proc, dep_tab[dep_index].line);
657 dep_tab[dep_index].fh = 0;
658 dep_tab[dep_index].fh_2 = 0;
660 dep_tab[dep_index].trace_fh = find_lead_trace_fh(proc, dep_tab[dep_index].line);
661 dep_tab[dep_index].fh = 0;
662 dep_tab[dep_index].fh_2 = (fh_map_t *)1;
664 dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
666 dep_tab[dep_index].skip_sec = skip_sec;
668 if (dependency_debug)
669 printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_CANDIDATE\n", dep_tab[dep_index].disk_index);
671 if (dependency_debug)
672 printf ("disk[%d] state DEP_FLAG_INIT to DEP_FLAG_DONE\n", dep_tab[dep_index].disk_index);
673 dep_tab[dep_index].flag = DEP_FLAG_DONE;
678 if ((dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE) ) {
680 if (!dep_tab[dep_index].fh)
681 dep_tab[dep_index].fh = lookup_fh (dep_tab[dep_index].trace_fh);
682 if (!dep_tab[dep_index].fh_2)
683 dep_tab[dep_index].fh_2 = lookup_fh (dep_tab[dep_index].trace_fh_2);
685 /* need to wait for file handle */
686 if ((!dep_tab[dep_index].fh) || (!dep_tab[dep_index].fh_2)) {
687 if (dependency_debug)
688 printf("disk[%d] can not lookup file handle\n", dep_tab[dep_index].disk_index);
689 if (dep_tab[dep_index].flag == DEP_FLAG_CANDIDATE) {
690 if (dependency_debug)
691 printf ("disk[%d] state DEP_FLAG_CANDIDATE to DEP_FLAG_WAIT_FHANDLE\n", dep_tab[dep_index].disk_index);
692 dep_tab[dep_index].flag = DEP_FLAG_WAIT_FHANDLE;
693 sfs_gettime (&dep_tab[dep_index].start);
694 if (dep_index < min_wait_fhandle_dep_index)
695 min_wait_fhandle_dep_index = dep_index;
699 SUBTIME (tmp, dep_tab[dep_index].start);
701 RFS_ASSERT (tmp.sec < 20 + (skip_sec - dep_tab[dep_index].skip_sec));
703 RFS_ASSERT (tmp.sec < 20 );
709 /* file handle ready, adjust_min_wait_fhandle_dep_index */
710 if ((dep_tab[dep_index].flag == DEP_FLAG_WAIT_FHANDLE)) {
711 if (dep_index == min_wait_fhandle_dep_index) {
712 min_wait_fhandle_dep_index = dep_tab_size;
713 for (j=dep_index+1; j<max_dep_index; j++) {
714 if (dep_tab[j].flag ==DEP_FLAG_WAIT_FHANDLE) {
715 min_wait_fhandle_dep_index = j;
721 if (dependency_debug)
722 printf("disk[%d] found file handle\n", dep_tab[dep_index].disk_index);
723 dep_tab[dep_index].flag = DEP_FLAG_FHANDLE_READY;
725 /* the normal file operation can be executed now */
726 if (!is_dir_op (dep_tab[dep_index].proc)) {
727 if (dependency_debug)
728 printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
732 if (dependency_debug)
733 printf("disk[%d] directory operation \n", dep_tab[dep_index].disk_index);
734 /* the directory operation need to lock the directory first */
735 if (dep_tab[dep_index].fh->lock) {
736 if (dependency_debug)
737 printf ("disk[%d] state %d to DEP_FLAG_WAIT_DIRECTORY\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
738 dep_tab[dep_index].flag = DEP_FLAG_WAIT_DIRECTORY;
743 if ((dep_tab[dep_index].flag == DEP_FLAG_FHANDLE_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DIRECTORY)) {
744 int j = dep_tab[dep_index].fh - fh_map;
745 if (dependency_debug) {
746 printf ("dep_tab[%d].disk_index %d, fh_map[%d] lock=%d\n",dep_index, dep_tab[dep_index].disk_index, j, dep_tab[dep_index].fh->lock);
747 printf ("trace_fh %s path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
748 printf ("trace_fh %s path %s\n", fh_map[j].trace_fh, fh_map[j].path);
750 if ((dep_tab[dep_index].fh->lock) || ((proc==RENAME) && (dep_tab[dep_index].fh_2->lock)) ) {
751 if (dependency_debug)
752 printf ("continue to wait for directory lock\n");
755 if (dependency_debug)
756 printf ("dep_tab[%d] disk index %d LOCK fh_map[%d] \n", dep_index, dep_tab[dep_index].disk_index, j);
757 dep_tab[dep_index].fh->lock = 1;
759 dep_tab[dep_index].fh_2->lock = 1;
761 /* the non-delete directory operation can proceed now */
762 if (!is_delete_op (dep_tab[dep_index].proc)) {
763 if (dependency_debug)
764 printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
768 /* the delete operation can proceed if nobody ahead is waiting for fhandle */
769 /* probably this condition is not strong enough */
770 // if ((min_wait_fhandle_dep_index<dep_index) ) {
771 if (dep_index!=min_dep_index) {
772 if (dependency_debug)
773 printf ("disk[%d] state %d to DEP_FLAG_WAIT_DELETE\n", dep_tab[dep_index].disk_index, dep_tab[dep_index].flag);
774 dep_tab[dep_index].flag = DEP_FLAG_WAIT_DELETE;
777 dep_tab[dep_index].flag = DEP_FLAG_DIRECTORY_READY;
780 if ((dep_tab[dep_index].flag == DEP_FLAG_DIRECTORY_READY) || (dep_tab[dep_index].flag == DEP_FLAG_WAIT_DELETE)) {
781 // if (min_wait_fhandle_dep_index > dep_index) {
782 if (dep_index==min_dep_index) {
783 if (dependency_debug)
784 printf ("return disk[%d]\n", dep_tab[dep_index].disk_index);
789 if (dep_tab[dep_index].flag == DEP_FLAG_INIT){
790 for (j=0, t=&(dep_tab[dep_index].dep_ops[0]);
791 (j<dep_tab[dep_index].init_dep_num) && (dep_tab[dep_index].cur_dep_num>0);
794 if (dep_tab[disk_index_to_dep_index(dep_index, *t)].flag == DEP_FLAG_DONE) { /* The depended request has been finished */
796 dep_tab[dep_index].cur_dep_num --;
801 if (dep_tab[dep_index].cur_dep_num == 0) {
808 if (dependency_debug)
809 printf ("get_nexop return -1\n");
813 int check_timeout(void)
815 static int biod_index = 0;
817 int dep_index; /* index into dep_tab */
819 sfs_op_type *op_ptr; /* per operation info */
820 struct ladtime timeout;
822 sfs_gettime (¤t);
824 for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
825 if (biod_reqp[biod_index].in_use==TRUE) {
826 timeout = biod_reqp[biod_index].timeout;
827 if ((current.sec>timeout.sec) ||
828 ((current.sec==timeout.sec) && (current.usec>timeout.usec))) {
830 dep_index = biod_reqp[biod_index].dep_tab_index;
831 proc = dep_tab[dep_index].proc;
833 op_ptr->results.timeout_calls++;
834 Ops[TOTAL].results.timeout_calls++;
836 finish_request (biod_index, dep_index, NFS3ERR_RFS_TIMEOUT);
838 if (is_create_op(proc)) {
839 dep_tab[dep_index].flag = DEP_FLAG_CANDIDATE;
840 printf ("resend dep_tab[%d], disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
842 //RFS_ASSERT (!is_create_op(proc));
844 //printf ("timeout request: biod_reqp[%d].start %d:%d timeout %d:%d current %d:%d\n", biod_index, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, timeout.sec, timeout.usec, current.sec, current.usec);
850 /* Allocate a biod_req entry to send and receive request dep_tab[dep_index]
851 * build the cross reference between dep_tab entry and biod_req entry
853 struct biod_req * get_biod_req(int dep_index) /* index into dep_tab */
855 static int biod_index = 0;
857 for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
858 if (!biod_reqp[biod_index].in_use) {
859 biod_reqp[biod_index].in_use = 1;
860 biod_reqp[biod_index].dep_tab_index = dep_index;
861 dep_tab[dep_index].biod_req_index = biod_index;
862 return &(biod_reqp[biod_index]);
868 /* Return index into biod_reqp
869 * return -1 upon failure
871 int lookup_biod_req (int xid)
873 static int biod_index = 0;
875 for (i=0; i<max_biod_reqs; i++, biod_index = (biod_index+1)%max_biod_reqs) {
876 /* give a NULL as timeout pointer may cause indefinitely block */
877 if (biod_reqp[biod_index].xid == xid) {
884 extern struct ladtime test_start;
885 void init_time_offset(void)
892 sfs_gettime (&tmp1); /* called at initial time: tmp1 = play_starttime */
894 DIVTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime / SCALE */
897 MULTIME (tmp1, PLAY_SCALE) /* tmp1 = play_starttime * SCALE */
900 tmp2 = trace_starttime; /* tmp2 = trace_starttime */
901 SUBTIME (tmp2, tmp1); /* tmp2 = trace_starttime - play_starttime *|/ SCALE */
902 time_offset = tmp2; /* time_offset = trace_starttime - play_starttime *|/ SCALE */
905 /* initialize timestamp and proc field of dep_tab entry */
906 void init_dep_tab_entry (int dep_index)
908 static int nfs2proc_to_rfsproc[18] = {0, 1, 2, 3, 4, 5, 6, 7, 8, 9,
909 10, 11, 12, 13, 14, 15, 16, 17};
910 static int nfs3proc_to_rfsproc[NFS3_PROCEDURE_COUNT] = {0, 1, 2, 4, 18, 5, 6, 8, 9, 14,
911 13, 21, 10, 15, 11, 12, 16, 23, 17, 20,
918 //line = get_line_by_disk_index (dep_tab[dep_index].disk_index);
919 line = dep_tab[dep_index].line;
920 sscanf (line, "%d.%d", &(dep_tab[dep_index].timestamp.tv_sec), &(dep_tab[dep_index].timestamp.tv_usec));
921 sscanf (&line[39], "%x %x", &msgid, &nfsproc);
922 if (line[TRACE_VERSION_POS]=='2') {
923 dep_tab[dep_index].proc = nfs2proc_to_rfsproc[nfsproc];
924 RFS_ASSERT (nfsproc <18);
926 /* This is for debug purpose */
927 if (line[TRACE_VERSION_POS] !='3') {
928 fprintf(stderr, "line[TRACE_VERSION_POS] %c line %s\n", line[TRACE_VERSION_POS], line);
929 line = get_line_by_disk_index (dep_tab[dep_index].disk_index-1);
931 line = get_line_by_disk_index (dep_tab[dep_index].disk_index-2);
933 fprintf(stderr, "previousline %s\n", line);
935 RFS_ASSERT (line[TRACE_VERSION_POS] =='3');
936 if (nfsproc >= NFS3_PROCEDURE_COUNT) {
937 fprintf(stderr, "proc %d line %s\n", nfsproc, line);
940 RFS_ASSERT (nfsproc <NFS3_PROCEDURE_COUNT);
941 dep_tab[dep_index].proc = nfs3proc_to_rfsproc[nfsproc];
943 RFS_ASSERT (dep_tab[dep_index].proc >= 0 && dep_tab[dep_index].proc < NOPS);
944 dep_tab[dep_index].flag = DEP_FLAG_INIT;
947 /* initialize status, reply status, reply lines in one shot is probably better ????????????????
949 static void adjust_play_window (int flag, int * poll_timeout)
951 struct ladtime max_window_time;
952 static struct ladtime max_poll_time = {0, 2000, 0};
954 int old_min = min_dep_index;
955 int old_max = max_dep_index;
959 for (; (dep_tab[min_dep_index].flag == DEP_FLAG_DONE) && (min_dep_index<dep_tab_size); min_dep_index++)
961 RFS_ASSERT (min_dep_index <= max_dep_index);
963 /* max_trace_window_time = current *|/ SCALE + trace_starttime */
964 sfs_gettime (¤t);
968 MULTIME (current, PLAY_SCALE);
971 DIVTIME (current, PLAY_SCALE);
973 ADDTIME (current, trace_starttime);
974 max_window_time = current;
976 while ((max_dep_index<min_dep_index+MAX_PLAY_WINDOW) && (max_dep_index<dep_tab_size))
978 t.sec = dep_tab[max_dep_index].timestamp.tv_sec;
979 t.usec = dep_tab[max_dep_index].timestamp.tv_usec;
981 if (adjust_play_window_debug)
982 printf ("max_window_time sec %d usec %d : max_dep_index %d, t.sec %d t.usec %d\n", max_window_time.sec, max_window_time.usec, max_dep_index, t.sec, t.usec );
984 if ((t.sec>max_window_time.sec)||(t.sec==max_window_time.sec && t.usec>max_window_time.usec))
990 /* Right now it is not clear how to deal with the situation where MAX_PLAY_WINDOW is reached */
991 if (max_dep_index == min_dep_index+MAX_PLAY_WINDOW) {
992 //printf ("can not catch up the speed, max_dep_index %d reach min_dep_index %d+MAX_PLAY_WINDOW\n", max_dep_index, min_dep_index);
994 can_not_catch_speed_num ++;
996 //RFS_ASSERT (max_dep_index < min_dep_index+MAX_PLAY_WINDOW);
998 ADDTIME (current, trace_starttime);
999 max_window_time = current;
1000 max_dep_index = min_dep_index + MAX_PLAY_WINDOW;
1001 if (max_dep_index >dep_tab_size)
1002 max_dep_index = dep_tab_size;
1007 else if (max_dep_index == dep_tab_size) {
1008 *poll_timeout = 1000000; /* poll_timeout set to 1 second for the last request */
1012 struct ladtime tmp1;
1013 tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
1014 tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
1015 if (adjust_play_window_debug)
1016 printf ("dep_tab[max_dep_index %d].timestamp %d:%d, max_window_time %d:%d\n",
1017 max_dep_index, tmp.sec, tmp.usec, max_window_time.sec, max_window_time.usec);
1019 SUBTIME (tmp, max_window_time);
1021 DIVTIME (tmp, PLAY_SCALE);
1024 MULTIME (tmp, PLAY_SCALE);
1028 if (tmp.sec > max_poll_time.sec) {
1031 printf ("dep_tab[%d].timestamp %d:%d, max_window_time %d:%d\n",
1032 max_dep_index, dep_tab[max_dep_index].timestamp.tv_sec, dep_tab[max_dep_index].timestamp.tv_usec, max_window_time.sec, max_window_time.usec);
1033 printf ("skip %d seconds\n", tmp.sec-max_poll_time.sec);
1034 SUBTIME (tmp, max_poll_time);
1036 skip_sec += tmp.sec;
1037 SUBTIME (test_start, tmp);
1038 tmp = max_poll_time;
1041 RFS_ASSERT ((tmp.sec < 1000));
1042 if ((tmp.sec ==0) && (tmp.usec==0)) {
1045 *poll_timeout = tmp.sec*1000000+tmp.usec;
1049 struct ladtime tmp1;
1050 tmp.sec = dep_tab[max_dep_index].timestamp.tv_sec;
1051 tmp.usec = dep_tab[max_dep_index].timestamp.tv_usec;
1052 tmp1.sec = dep_tab[max_dep_index-1].timestamp.tv_sec;
1053 tmp1.usec = dep_tab[max_dep_index-1].timestamp.tv_usec;
1054 SUBTIME (tmp, tmp1);
1055 RFS_ASSERT ((tmp.sec < 1000));
1056 RFS_ASSERT ((tmp.sec>0) || ((tmp.sec==0) && (tmp.usec>0)));
1057 *poll_timeout = tmp.sec*1000000+tmp.usec;
1060 *poll_timeout = 100000;
1064 printf ("adjust_play_window: flag %d min %d -> %d, max %d -> %d poll_timeout %d \n", flag, old_min, min_dep_index, old_max, max_dep_index, *poll_timeout);
1067 /* poll for usecs and receive, after receive one reply,
1068 * return index in biod_reqp of the corresponding request
1070 int poll_and_get_reply (int usecs)
1072 int biod_index = -1;
1075 struct timeval zero_time = {0, 0}; /* Immediately return */
1078 error = biod_poll_wait (NFS_client, usecs);
1081 if (errno == EINTR) {
1086 (void) fprintf(stderr, "biod_poll_wait error\n");
1088 (void) fflush(stderr);
1095 error = get_areply_udp (NFS_client, &xid, &zero_time);
1096 // RFS_ASSERT (error!= RPC_TIMEOUT); /* we have polled and know there is data */
1097 // RFS_ASSERT (error!= RPC_CANTRECV);
1098 RFS_ASSERT (error == RPC_SUCCESS);
1100 biod_index = lookup_biod_req (xid);
1101 sfs_gettime (&(biod_reqp[biod_index].stop));
1110 void print_result(void)
1116 unsigned long long tmp;
1119 printf("read_data_bytes %d owe %d GB and %d bytes, adjusted %d times \n",read_data_total, read_data_owe_GB, read_data_owe, read_data_adjust_times);
1120 printf("write_data_bytes %d owe %d GB and %d bytes, adjusted %d times \n",write_data_total, write_data_owe_GB, write_data_owe, write_data_adjust_times);
1121 printf("failed_create_command_num %d skipped_readlink_command_num %d skipped_custom_command_num %d\n missing_reply_num %d rename_rmdir_noent_reply_num %d rmdir_not_empty_reply_num %d\n loose_access_control_reply_num %d, proper_reply_num %d, lookup_err_due_to_rename %d\n",
1122 failed_create_command_num, skipped_readlink_command_num, skipped_custom_command_num,
1123 missing_reply_num, rename_rmdir_noent_reply_num, rmdir_not_empty_reply_num,
1124 loose_access_control_reply_num, lookup_err_due_to_rename_num, proper_reply_num );
1126 if (DEBUG_CHILD_GENERAL) {
1127 (void) fprintf(stdout, "trace play result:\n");
1128 (void) fprintf(stdout, "\t percentage good_cnt bad_cnt timeout_cnt\telapsed time\t\t\taverage time\n");
1129 for (i=0; i<NOPS+1; i++) {
1130 if (Ops[i].results.good_calls==0) {
1134 tmp = Ops[i].results.time.sec*1000000 + Ops[i].results.time.usec;
1136 avg_usecs = tmp/Ops[i].results.good_calls;
1138 avg_msecs = (Ops[i].results.time.sec*1000 + Ops[i].results.time.usec/1000)/Ops[i].results.good_calls;
1139 avg_usecs = (Ops[i].results.time.usec%1000)/Ops[i].results.good_calls;
1142 (void) fprintf(stdout, "%11s\t%4.1f\t%4d\t%4d\t%4d\t\tsec %8d usec %8d \tusec %8d\n",
1144 (float)(100*Ops[i].results.good_calls)/(float)Ops[TOTAL].results.good_calls,
1145 Ops[i].results.good_calls, Ops[i].results.bad_calls, Ops[i].results.timeout_calls,
1146 Ops[i].results.time.sec, Ops[i].results.time.usec, avg_msecs*1000+avg_usecs);
1148 (void) fflush (stdout);
1151 clnt_destroy(NFS_client);
1154 // print_dump(Client_num, Child_num);
1157 printf ("[%4d] %s \tstart %4d:%6d \n",
1158 dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
1159 for (i=1; i<dep_tab_size*2; i++) {
1160 dep_index = event_order[i];
1162 printf ("[%4d] %s \tstart %4d:%6d \n",
1163 dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec);
1165 dep_index = -dep_index;
1166 t=dep_tab[dep_index].stop;
1167 SUBTIME (t, dep_tab[dep_index].start);
1168 printf ("\t\t\t\t\t[%4d] %s stop %4d:%6d\tinterval %4d:%6d %s\n",
1169 dep_index, Ops[dep_tab[dep_index].proc].name, dep_tab[dep_index].stop.sec, dep_tab[dep_index].stop.usec, t.sec, t.usec, nfs3_strerror(dep_tab[dep_index].status));
1174 for (i=0, j=0; i<dep_tab_size || j<dep_tab_size; ) {
1175 if ((i==dep_tab_size) ||
1176 (LARGERTIME(dep_tab[i].start, dep_tab[j].stop) && j<dep_tab_size)) {
1178 SUBTIME (t, dep_tab[j].start);
1179 printf ("dep_tab[%d].proc %s stop %d:%d interval %d:%d status %s\n",
1180 j, Ops[dep_tab[j].proc].name, dep_tab[j].stop.sec, dep_tab[j].stop.usec, t.sec, t.usec, nfs3_strerror(dep_tab[j].status));
1183 printf ("dep_tab[%d].proc %s start %d:%d \n",
1184 i, Ops[dep_tab[i].proc].name, dep_tab[i].start.sec, dep_tab[i].start.usec);
1192 * allocate and initialize client handles
1200 * Set up the client handles. We get them all before trying one
1201 * out to insure that the client handle for LOOKUP class is allocated
1202 * before calling op_getattr().
1204 if (DEBUG_CHILD_GENERAL) {
1205 (void) fprintf(stderr, "%s: set up client handle\n", sfs_Myname);
1208 NFS_client = lad_clnt_create(Tcp? 1: 0, Server_hostent,
1209 (uint32_t) NFS_PROGRAM,
1210 (uint32_t) nfs_version,
1211 RPC_ANYSOCK, &Nfs_timers[0]);
1213 if (NFS_client == ((CLIENT *) NULL)) {
1218 * create credentials using the REAL uid
1220 NFS_client->cl_auth = authunix_create(lad_hostname, (int)Real_uid,
1221 (int)Cur_gid, 0, NULL);
1224 if (biod_init(dummy, dummy) == -1) {
1237 /* Ready to go - initialize operation counters */
1238 for (i = 0; i < NOPS + 1; i++) {
1240 Ops[i].results.good_calls = 0;
1241 Ops[i].results.bad_calls = 0;
1242 Ops[i].results.timeout_calls = 0; // RFS
1243 Ops[i].results.fast_calls = 0;
1244 Ops[i].results.time.sec = 0;
1245 Ops[i].results.time.usec = 0;
1246 Ops[i].results.msec2 = 0;
1249 /* initialize timers and period variables */
1250 sfs_gettime(&Starttime);
1251 Cur_time = Starttime;
1252 start_msec = (Starttime.sec * 1000) + (Starttime.usec / 1000);
1253 Previous_chkpnt_msec = start_msec;
1254 Calls_this_period = 0;
1255 Reqs_this_period = 0;
1256 Sleep_msec_this_period = 0;
1257 Calls_this_test = 0;
1259 Sleep_msec_this_test = 0;
1263 nfs3_strerror(int status)
1265 static char str[40];
1268 (void) strcpy(str, "no error");
1271 (void) strcpy(str, "Not owner");
1274 (void) strcpy(str, "No such file or directory");
1277 (void) strcpy(str, "I/O error");
1280 (void) strcpy(str, "No such device or address");
1283 (void) strcpy(str, "Permission denied");
1286 (void) strcpy(str, "File exists");
1289 (void) strcpy(str, "Cross-device link");
1292 (void) strcpy(str, "No such device");
1294 case NFS3ERR_NOTDIR:
1295 (void) strcpy(str, "Not a directory");
1298 (void) strcpy(str, "Is a directory");
1301 (void) strcpy(str, "Invalid argument");
1304 (void) strcpy(str, "File too large");
1307 (void) strcpy(str, "No space left on device");
1310 (void) strcpy(str, "Read-only file system");
1313 (void) strcpy(str, "Too many links");
1315 case NFS3ERR_NAMETOOLONG:
1316 (void) strcpy(str, "File name too long");
1318 case NFS3ERR_NOTEMPTY:
1319 (void) strcpy(str, "Directory not empty");
1322 (void) strcpy(str, "Disc quota exceeded");
1325 (void) strcpy(str, "Stale NFS file handle");
1327 case NFS3ERR_REMOTE:
1328 (void) strcpy(str, "Object is remote");
1330 case NFS3ERR_BADHANDLE:
1331 (void) strcpy(str, "Bad file handle");
1333 case NFS3ERR_NOT_SYNC:
1334 (void) strcpy(str, "Not sync write");
1336 case NFS3ERR_BAD_COOKIE:
1337 (void) strcpy(str, "Bad cookie");
1339 case NFS3ERR_NOTSUPP:
1340 (void) strcpy(str, "Operation not supported");
1342 case NFS3ERR_TOOSMALL:
1343 (void) strcpy(str, "Value too small");
1345 case NFS3ERR_SERVERFAULT:
1346 (void) strcpy(str, "Server fault");
1348 case NFS3ERR_BADTYPE:
1349 (void) strcpy(str, "Bad type");
1351 case NFS3ERR_JUKEBOX:
1352 (void) strcpy(str, "Jukebox");
1354 case NFS3ERR_RFS_TIMEOUT:
1355 (void) strcpy(str, "Timeout");
1358 (void) sprintf(str, "Unknown status %d", status);
1365 * Check the gettimeofday() resolution. If the resolution
1366 * is in chunks bigger than SFS_MIN_RES then the client
1367 * does not have a usable resolution for running the
1374 char tmp_hostname[HOSTNAME_LEN];
1376 time_res = get_resolution();
1377 getmyhostname(tmp_hostname, HOSTNAME_LEN);
1378 if( time_res > (double)SFS_MIN_RES )
1380 (void) fprintf(stderr,
1381 "\n%s: Clock resolution too poor to obtain valid results.\n",
1383 (void) fprintf(stderr,
1384 "%s: Clock resolution %f Micro seconds.\n", tmp_hostname,
1390 (void) fprintf(stderr,
1391 "\n%s: Good clock resolution [ %f ] Micro seconds.\n",
1392 tmp_hostname, time_res);
1397 * Lifted code from Iozone with permission from author. (Don Capps)
1398 * Returns the resolution of the gettimeofday() function
1402 get_resolution(void)
1404 double starttime, finishtime, besttime;
1408 finishtime=time_so_far1(); /* Warm up the instruction cache */
1409 starttime=time_so_far1(); /* Warm up the instruction cache */
1410 delay=j=0; /* Warm up the data cache */
1415 starttime=time_so_far1();
1416 for(j=0;j< delay;j++)
1418 finishtime=time_so_far1();
1419 if(starttime==finishtime)
1424 besttime=(finishtime-starttime);
1425 if((finishtime-starttime) < besttime)
1426 besttime=(finishtime-starttime);
1435 * Lifted code from Iozone with permission from author. (Don Capps)
1436 * Returns current result of gettimeofday() in microseconds.
1438 /************************************************************************/
1439 /* Time measurement routines. */
1440 /* Return time in microseconds */
1441 /************************************************************************/
1446 /* For Windows the time_of_day() is useless. It increments in 55 */
1447 /* milli second increments. By using the Win32api one can get */
1448 /* access to the high performance measurement interfaces. */
1449 /* With this one can get back into the 8 to 9 microsecond */
1452 LARGE_INTEGER freq,counter;
1456 QueryPerformanceFrequency(&freq);
1457 QueryPerformanceCounter(&counter);
1458 bigcounter=(double)counter.HighPart *(double)0xffffffff +
1459 (double)counter.LowPart;
1460 wintime = (double)(bigcounter/(double)freq.LowPart);
1461 return((double)wintime*1000000.0);
1463 #if defined (OSFV4) || defined(OSFV3) || defined(OSFV5)
1466 if (getclock(TIMEOFDAY, (struct timespec *) &gp) == -1)
1468 return (( (double) (gp.tv_sec)*1000000.0) +
1469 ( ((float)(gp.tv_nsec)) * 0.001 ));
1473 if (gettimeofday(&tp, (struct timezone *) NULL) == -1)
1474 perror("gettimeofday");
1475 return ((double) (tp.tv_sec)*1000000.0) +
1476 (((double) tp.tv_usec) );
1484 fprintf(stderr, "trace play usage");
1486 extern void init_file_system (void)
1491 extern void init_dep_tab (void)
1494 memset (&dep_tab, 0, sizeof(dep_tab));
1496 dep_tab[0].disk_index = 0;
1497 dep_tab[1].disk_index = 2;
1498 dep_tab[2].disk_index = 3;
1499 dep_tab[3].disk_index = 5;
1500 dep_tab[4].disk_index = 7;
1501 dep_tab[5].disk_index = 9;
1502 dep_tab[6].disk_index = 11;
1503 dep_tab[7].disk_index = 12;
1504 dep_tab[8].disk_index = 15;
1505 dep_tab[9].disk_index = 17;
1506 dep_tab[10].disk_index = 18;
1507 dep_tab[11].disk_index = 20;
1513 extern void init_dep_tab_old (void)
1517 Cur_file_ptr = &Export_dir;
1520 for (i=0; i<5; i++) {
1521 dep_tab[i].flag = DEP_FLAG_INIT;
1522 dep_tab[i].proc = CREATE;
1523 dep_tab[i].timestamp.tv_sec = trace_starttime.sec;
1524 dep_tab[i].timestamp.tv_usec = trace_starttime.usec+i*10;
1525 dep_tab[i].init_dep_num = 0;
1526 dep_tab[i].cur_dep_num = 0;
1529 for (i=5; i<10; i++) {
1530 dep_tab[i].flag = DEP_FLAG_INIT;
1531 dep_tab[i].proc = CREATE;
1532 dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i;
1533 dep_tab[i].timestamp.tv_usec = trace_starttime.usec;
1534 dep_tab[i].init_dep_num = 0;
1535 dep_tab[i].cur_dep_num = 0;
1538 dep_tab[2].init_dep_num = 2;
1539 dep_tab[2].cur_dep_num = 2;
1540 dep_tab[2].dep_ops[0] = 0;
1541 dep_tab[2].dep_ops[1] = 1;
1543 // printf ("trace_starttime (%d %d)\n", trace_starttime.sec, trace_starttime.usec);
1546 for (i=2; i<4; i++) {
1547 dep_tab[i].flag = DEP_FLAG_INIT;
1548 dep_tab[i].proc = CREATE;
1549 dep_tab[i].timestamp.tv_sec = trace_starttime.sec+i*10;
1550 dep_tab[i].timestamp.tv_usec = trace_starttime.usec;
1551 dep_tab[i].init_dep_num = 0;
1552 dep_tab[i].cur_dep_num = 0;
1558 for (i=0; i<dep_tab_size; i++)
1560 printf("dep_tab[%d].timestamp (%d %d)\n", i, dep_tab[i].timestamp.tv_sec, dep_tab[i].timestamp.tv_usec);
1564 void show_fhandle (nfs_fh3 * fhp)
1566 struct knfs_fh * kfhp = (struct knfs_fh *)fhp;
1573 RFS_ASSERT (kfhp->fh_version == 1);
1574 RFS_ASSERT (kfhp->fh_fsid_type == 0);
1575 RFS_ASSERT (kfhp->fh_auth_type == 0);
1577 dev = ntohs(kfhp->fh_dev_major);
1579 dev = dev + ntohs(kfhp->fh_dev_minor);
1581 /* kfhp->fh_dev_ino hold the inode number of export point of the mounted
1582 * file system. For example, if /tmp/t1 is exported, /tmp/t1/t2 is mounted,
1583 * then fh_dev_ino hold the inode number of t1, not t2
1586 switch (kfhp->fh_fileid_type) {
1588 printf("fh:type 0 root dev 0x%x dev_ino %d\n", dev, kfhp->fh_dev_ino);
1591 printf("fh:type 1 %d %x dev %x dev_ino %x\n",
1592 kfhp->fh_ino, kfhp->fh_generation, dev, kfhp->fh_dev_ino);
1595 printf("fh:type2 %d %x dirino %d dev 0x%x dev_ino %x\n",
1596 kfhp->fh_ino, kfhp->fh_generation, kfhp->fh_dirino, dev, kfhp->fh_dev_ino);
1603 nfs_fh3 zero_fhandle;
1606 memset (fh_map, 0, sizeof (fh_map));
1607 memset(fh_htable, 0, sizeof (fh_htable));
1608 memset (&zero_fhandle, 0, sizeof(nfs_fh3));
1609 printf ("SIZE of fh map %d KB\n", sizeof (fh_map)/1000);
1613 int add_fh (int map_flag, char * trace_fh, char * path, nfs_fh3 * play_fh)
1615 char * old_trace_fh;
1617 /* first lookup if the entry for fh is already in the table */
1618 struct generic_entry * p;
1620 p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
1622 RFS_ASSERT (fh_map[p->key3].flag = FH_MAP_FLAG_PARTIAL);
1623 RFS_ASSERT (map_flag ==FH_MAP_FLAG_COMPLETE);
1624 fh_map[p->key3].flag = map_flag;
1625 RFS_ASSERT (!memcmp(fh_map[p->key3].trace_fh, trace_fh, TRACE_FH_SIZE));
1626 RFS_ASSERT (!strcmp(fh_map[p->key3].path, path));
1627 RFS_ASSERT (!memcmp(&fh_map[p->key3].play_fh, &zero_fhandle, sizeof(nfs_fh3)));
1628 memcpy (&fh_map[p->key3].play_fh, play_fh, sizeof (nfs_fh3));
1629 if ((fh_map_debug==1)) // || (stage ==TRACE_PLAY_STAGE))
1630 printf ("update the play_fh for trace_fh %s path %s \n", trace_fh, path);
1634 fh_map[fh_i].flag = map_flag;
1635 fh_map[fh_i].lock = 0;
1636 memcpy(fh_map[fh_i].trace_fh, trace_fh, TRACE_FH_SIZE);
1638 RFS_ASSERT (strlen(path) < MAX_PLAY_PATH_SIZE);
1639 strcpy (fh_map [fh_i].path, path);
1640 if (map_flag==FH_MAP_FLAG_COMPLETE)
1641 memcpy (&fh_map[fh_i].play_fh, play_fh, sizeof(nfs_fh3));
1643 memset (&fh_map[fh_i].play_fh, 0, sizeof(nfs_fh3));
1645 if ((fh_map_debug==1)) { // || (stage ==TRACE_PLAY_STAGE)) {
1646 printf ("insert trace_fh %s path %s play_fh:\n", trace_fh, path);
1647 if (map_flag == FH_MAP_FLAG_COMPLETE)
1648 show_fhandle(play_fh);
1654 if (map_flag == FH_MAP_FLAG_DISCARD)
1655 printf ("insert flag %d trace_fh %s path %s play_fh:\n", map_flag, trace_fh, path);
1658 generic_insert(trace_fh, TRACE_FH_SIZE, fh_i, fh_htable, FH_HTABLE_SIZE);
1661 RFS_ASSERT (fh_i < FH_MAP_SIZE);
1666 fh_map_t * lookup_fh (char * trace_fh )
1668 struct generic_entry * p;
1669 p = generic_lookup (trace_fh, TRACE_FH_SIZE, 0, fh_htable, FH_HTABLE_SIZE);
1670 if (fh_map_debug==1)
1671 printf ("lookup trace_fh %s\n", trace_fh);
1674 if (fh_map_debug==1) {
1675 printf ("found: fh_i %d path %s play_fh:", p->key3, fh_map[p->key3].path);
1676 show_fhandle(&fh_map[p->key3].play_fh);
1678 return (&(fh_map[p->key3]));
1680 //printf ("lookup_fh %s not found\n", trace_fh);
1681 if (stage != READ_DEP_TAB_STAGE && (fh_map_debug==1)) {
1682 printf ("lookup not found trace_fh %s\n", trace_fh);
1689 int delete_fh (char * trace_fh, int fh_map_index)
1691 generic_delete (trace_fh, TRACE_FH_SIZE, fh_map_index, fh_htable, FH_HTABLE_SIZE);
1695 void lookup_init_filesystem (nfs_fh3 * parent, char * name, nfs_fh3 * result)
1698 LOOKUP3res reply; /* the reply */
1699 enum clnt_stat rpc_stat; /* result from RPC call */
1700 struct ladtime start;
1701 struct ladtime stop;
1704 /* set up the arguments */
1705 (void) memcpy((char *) &args.what.dir, (char *) parent,
1707 args.what.name = name;
1708 (void) memset((char *) &reply.resok.object, '\0', sizeof (nfs_fh3));
1711 sfs_gettime(&start);
1712 rpc_stat = clnt_call(NFS_client, NFSPROC3_LOOKUP,
1713 xdr_LOOKUP3args, (char *) &args,
1714 xdr_LOOKUP3res, (char *) &reply,
1718 if (rpc_stat !=RPC_SUCCESS) {
1719 printf("rpc_stat %d\n", rpc_stat);
1722 RFS_ASSERT (rpc_stat == RPC_SUCCESS);
1723 RFS_ASSERT (reply.status == NFS3_OK);
1724 (void) memcpy((char *) result, (char *) &reply.resok.object, sizeof (nfs_fh3));
1727 void read_fh_map(char * fh_map_file)
1732 char trace_fh[TRACE_FH_SIZE];
1737 #define MAX_PATH_DEPTH 20
1738 nfs_fh3 parents[MAX_PATH_DEPTH];
1739 char * lookup_path_ptr[MAX_PATH_DEPTH];
1740 char lookup_path [MAX_PLAY_PATH_SIZE];
1742 int new_dir_flag = 0;
1745 memset(lookup_path_ptr, 0, sizeof(lookup_path_ptr));
1746 memcpy(&parents[depth], &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
1747 strcpy(lookup_path, "/");
1748 lookup_path_ptr[depth]=&lookup_path[0];
1750 fp = fopen(fh_map_file, "r");
1751 RFS_ASSERT (fp!=NULL);
1755 memset(buf, 0, sizeof(buf));
1756 while (fgets(buf, 1024, fp)) {
1758 if (fh_i % 10000==0)
1759 printf("%d fh_map entry read\n", fh_i);
1761 RFS_ASSERT (buf[strlen(buf)-1]=='\n');
1762 buf[strlen(buf)-1]=0;
1764 printf("%d fgets return %s\n", fh_i, buf);
1765 printf("depth %d lookup_path %s\n", depth, lookup_path);
1767 //for (i=0; i<=depth; i++)
1768 //printf("lookup_path_ptr[%d] %s ", i, lookup_path_ptr[i]);
1770 #ifdef COMPRESS_TRACE_FH
1771 for (i=0; i<TRACE_FH_SIZE/8; i++) {
1772 strncpy(intbuf, buf+i*8, 8);
1773 sscanf(intbuf, "%x", trace_fh+i*8); // maybe it should be 4, anyway we don't compress for now
1775 trace_path = buf+TRACE_FH_SIZE*2+1; /* +1 the trace contains only initial file handle */
1777 memcpy(trace_fh, buf, TRACE_FH_SIZE);
1778 trace_path = buf + TRACE_FH_SIZE +1;
1780 #ifdef TRACE_CONTAIN_LATER_FHANDLE
1781 trace_path = +=2; /* +3 if the trace contains both initial and later created file handle */
1784 #ifdef NO_DEPENDENCY_TABLE
1785 if (!strncmp (trace_path, "DISCARD", 7)) {
1786 map_flag = FH_MAP_FLAG_DISCARD;
1787 add_fh (map_flag, buf, trace_path, 0);
1792 p = trace_path+strlen(trace_path)-2;
1796 //RFS_ASSERT (p-trace_path<=strlen(lookup_path)+1);
1797 //RFS_ASSERT (p>trace_path);
1799 if (strncmp(lookup_path, trace_path, p-trace_path)) {
1800 printf("strncmp lookup_path %s trace_path %s for length %d\n", lookup_path, trace_path, p-trace_path);
1802 RFS_ASSERT (!strncmp(lookup_path, trace_path, p-trace_path));
1803 //while (strncmp(lookup_path, trace_path, p-trace_path)) { /* one step deeper */
1804 while (strlen(lookup_path)>p-trace_path && depth>0) {
1805 //printf("depth--\n");
1807 printf ("lookup_path %s trace_path %s p-trace_path %d depth %d\n", lookup_path, trace_path, p-trace_path, depth);
1808 RFS_ASSERT (depth>0);
1809 *lookup_path_ptr[depth]=0;
1810 lookup_path_ptr[depth]=0;
1813 RFS_ASSERT (strlen(lookup_path)==(p-trace_path) || (depth==0));
1816 #ifdef TRACE_CONTAIN_LATER_FHANDLE
1817 if (buf[TRACE_FH_SIZE*2+1]=='Y') {
1818 map_flag = FH_MAP_FLAG_COMPLETE;
1820 map_flag = FH_MAP_FLAG_PARTIAL;
1821 RFS_ASSERT (buf[TRACE_FH_SIZE*2+1]=='N');
1824 map_flag = FH_MAP_FLAG_COMPLETE;
1826 if ((*(p+strlen(p)-1))=='/') {
1832 if (map_flag == FH_MAP_FLAG_COMPLETE) {
1833 lookup_init_filesystem (&parents[depth], p, &parents[depth+1]);
1834 add_fh (map_flag, buf, trace_path, &parents[depth+1]);
1836 add_fh (map_flag, buf, trace_path, 0);
1839 /* the new fhandle is of a directory */
1840 lookup_path_ptr[depth+1] = lookup_path+strlen(lookup_path);
1841 strcat (lookup_path, p);
1842 strcat (lookup_path, "/");
1844 //printf("depth++\n");
1848 memset(buf, 0, sizeof(buf));
1852 for (i=0; i<fh_i; i++) {
1853 int * p1 = (int *)&(fh_map[i].play_fh);
1854 #ifdef COMPRESS_TRACE_FH
1855 int * p = (int *)fh_map[i].trace_fh;
1856 printf("fh_map[%d].trace_fh %8x%8x%8x%8x%8x%8x%8x%8x path %s \nnew_filehandle %8x%8x%8x%8x%8x%8x%8x%8x\n",
1857 i, *p, *(p+1), *(p+2), *(p+3), *(p+4), *(p+5), *(p+6), *(p+7), fh_map[i].path,
1858 *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
1860 printf("fh_map[%d].trace_fh %s path %s \nnew_filehandle %8x%8x%8x%8x%8x%8x%8x%8x\n",
1861 i, fh_map[i].trace_fh, fh_map[i].path,
1862 *p1, *(p1+1), *(p1+2), *(p1+3), *(p1+4), *(p1+5), *(p1+6), *(p1+7));
1866 fprintf(stderr, "total %d requests \n", i);
1875 inline void finish_request (int biod_index, int dep_index, int status)
1877 /* the ending operation, same as when a request time out */
1878 dep_tab[dep_index].stop = biod_reqp[biod_index].stop; /* RFS: to dump data */
1879 dep_tab[dep_index].status = status;
1880 event_order[event_order_index++] = -dep_index;
1881 biod_reqp[biod_index].in_use = FALSE;
1882 dep_tab[dep_index].flag = DEP_FLAG_DONE;
1883 if (is_dir_op(dep_tab[dep_index].proc)) {
1885 RFS_ASSERT (dep_tab[dep_index].fh->lock = 1);
1886 dep_tab[dep_index].fh->lock = 0;
1887 if (dep_tab[dep_index].proc==RENAME)
1888 dep_tab[dep_index].fh_2->lock = 0;
1889 j = dep_tab[dep_index].fh-fh_map;
1890 if (dependency_debug) {
1891 printf ("fh_map[%d] is UNlocked\n",j);
1892 printf ("trace_fh %d path %s\n", dep_tab[dep_index].fh->trace_fh, dep_tab[dep_index].fh->path);
1893 printf ("trace_fh %d path %s\n", fh_map[j].trace_fh, fh_map[j].path);
1899 /* the request argument may have pointers pointing to buffers, e.g. the name in lookup,
1900 * the target of symlink, the write data */
1901 char arg_res[MAX_ARG_RES_SIZE];
1902 int poll_timeout = 0; /* timeout in usecs */
1903 char buf1 [MAX_BUF1_SIZE];
1904 char buf2 [MAX_BUF2_SIZE];
1905 #define NFS3_REPLY_MISS -1
1907 int execute_next_request ()
1912 struct biod_req * reqp;
1913 sfs_op_type *op_ptr; /* per operation info */
1914 struct ladtime call_timeout;
1916 start_profile (&valid_get_nextop_profile);
1917 start_profile (&invalid_get_nextop_profile);
1918 dep_index = get_nextop();
1919 if (dep_index == -1) {
1920 end_profile (&invalid_get_nextop_profile);
1923 end_profile (&valid_get_nextop_profile);
1925 start_profile (&prepare_argument_profile);
1926 line = dep_tab[dep_index].line;
1927 if ((dep_index%(10000))==0) {
1929 fprintf (stderr, "processing dep_tab[%d] disk_index %d num_out_reqs %d \n", dep_index, dep_tab[dep_index].disk_index, num_out_reqs);
1931 fprintf (stderr, "processing dep_tab[%d] disk_index %d num_out_reqs %d can_not_catch_speed_num %d PLAY_SCALE %d \n", dep_index, dep_tab[dep_index].disk_index, num_out_reqs, can_not_catch_speed_num, PLAY_SCALE);
1933 if (can_not_catch_speed_num < 2000) {
1935 printf ("set PLAY_SCALE to %d\n", PLAY_SCALE);
1937 if (can_not_catch_speed_num > 50000) {
1940 if (can_not_catch_speed_num > 5000) {
1947 can_not_catch_speed_num = 0;
1951 printf ("processing dep_tab[%d] disk_index %d %s\n", dep_index, dep_tab[dep_index].disk_index, line);
1953 proc = dep_tab[dep_index].proc;
1954 rfs_Ops[proc].setarg (dep_index, line, arg_res, buf1, buf2);
1956 op_ptr = &Ops[proc];
1957 reqp = get_biod_req (dep_index);
1960 call_timeout.sec = 4; //Nfs_timers[op_ptr->call_class].tv_sec;
1961 call_timeout.usec = Nfs_timers[op_ptr->call_class].tv_usec;
1964 sfs_gettime(&(reqp->start));
1965 end_profile (&prepare_argument_profile);
1966 start_profile (&biod_clnt_call_profile);
1969 reqp->xid = biod_clnt_call(NFS_client, rfs_Ops[proc].nfsv3_proc,
1970 rfs_Ops[proc].xdr_arg, arg_res);
1973 reqp->xid = dep_index+1; /* just fake a message id and let it expire */
1975 if (reqp->xid != 0) {
1976 reqp->timeout = reqp->start;
1977 ADDTIME (reqp->timeout, call_timeout);
1979 dep_tab[dep_index].flag = DEP_FLAG_SENT;
1980 event_order[event_order_index++] = dep_index;
1984 dep_tab[dep_index].start = reqp->start; /* RFS: to dump data */
1985 end_profile (&biod_clnt_call_profile);
1988 void check_reply (int proc, int biod_index, int dep_index, int status, char * errmsg, int trace_reply_status)
1990 if (((status!=trace_reply_status)) && (trace_reply_status!=NFS3_REPLY_MISS)) {
1992 printf ("receive problem reply, xid %x nfs_ret %d %s trace_reply_status %d start %d:%d stop %d:%d command disk index %d\n", biod_reqp[biod_index].xid, status, errmsg, trace_reply_status, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, biod_reqp[biod_index].stop.sec, biod_reqp[biod_index].stop.usec, dep_tab[dep_index].disk_index);
1993 #ifndef TAKE_CARE_UNLOOKED_UP_NON_NEW_FILES
1994 /* these files is not looked up and is not create/mkdir/symlink/link/mknod ed before they
1995 * are refered by name through rename, remove
1997 if ((proc==RENAME || proc==REMOVE) && (status==NFS3ERR_NOENT) && (trace_reply_status ==0)) {
1998 /* current initialization doesnot take care of rename source, if there is no
1999 * create or lookup before that source, the source object will not exist when
2003 rename_rmdir_noent_reply_num++;
2006 #ifndef TAKE_CARE_SYMBOLIC_LINK
2007 if ((proc==LOOKUP) && (status==NFS3_OK) && (trace_reply_status==NFS3ERR_NOENT)) {
2008 /* in the original trace, first lookup return NOENT, then symlink is executed, then lookup return OK
2009 * the initialization considers only the lookup return OK and created the file in the initialization
2010 * so in trace play the first lookup return OK
2013 } else if ((proc==SYMLINK) && (status == NFS3ERR_EXIST) && (trace_reply_status == 0)) {
2014 /* due to similar reason as above, the initialization code initializes the symbolic link as a normal
2020 #ifndef TAKE_CARE_NOEMPTY_RMDIR
2021 /* the remove packet seems got lost in the trace capture, so replay can not finish */
2022 if ((proc==RMDIR) && (status==NFS3ERR_NOTEMPTY)) {
2024 RENAME3res reply; /* the reply */
2025 RMDIR3args * rmdir_argp;
2026 enum clnt_stat rpc_stat; /* result from RPC call */
2028 rfs_Ops[proc].setarg (dep_index, dep_tab[dep_index].line, arg_res, buf1, buf2);
2029 rmdir_argp = (RMDIR3args *)arg_res;
2031 memcpy(&args.from, &(rmdir_argp->object), sizeof (diropargs3));
2032 memcpy(&args.to.dir, &(Export_dir.fh_data->sfs_fh_un.f_fh3), sizeof(nfs_fh3));
2033 args.from.name = buf1; /* the buf1 is already filled when parsing rmdir */
2034 args.to.name = buf2;
2035 sprintf(buf2, "rmdir_%d_%s", dep_tab[dep_index].disk_index, rmdir_argp->object.name);
2037 rpc_stat = clnt_call(NFS_client, NFSPROC3_RENAME,
2038 xdr_RENAME3args, (char *) &args,
2039 xdr_RENAME3res, (char *) &reply,
2041 RFS_ASSERT (rpc_stat == RPC_SUCCESS);
2042 if (reply.status!=NFS3_OK)
2043 printf ("change rmdir into rename, reply.status %d\n", reply.status);
2044 RFS_ASSERT (reply.status==NFS3_OK);
2045 rmdir_not_empty_reply_num ++;
2047 #ifndef TAKE_CARE_ACCESS_ERROR
2048 } else if ((status==0) && (trace_reply_status==NFS3ERR_ACCES)) {
2049 loose_access_control_reply_num ++;
2051 #ifdef NO_DEPENDENCY_TABLE
2052 } else if ((proc==LOOKUP) && (status==NFS3ERR_NOENT) && (trace_reply_status==NFS3_OK)) {
2053 lookup_err_due_to_rename_num ++;
2057 for (i=min_dep_index; i<max_dep_index; i++)
2058 printf ("dep_tab[%d].disk_index %d, flag %d line %s\n", i, dep_tab[i].disk_index, dep_tab[i].flag, dep_tab[i].line);
2062 proper_reply_num ++;
2066 /* return -1 if there is no reply being received
2067 * return the dep_index if the corresponding reply has been received
2069 int receive_next_reply (int busy_flag)
2076 sfs_op_type *op_ptr; /* per operation info */
2079 int trace_reply_status;
2082 /* wait for reply */
2083 start_profile (&valid_poll_and_get_reply_profile);
2084 start_profile (&invalid_poll_and_get_reply_profile);
2086 if (busy_flag == IDLE)
2089 poll_timeout = 10000;
2091 biod_index = poll_and_get_reply (poll_timeout);
2092 if (biod_index==-1) {
2093 end_profile (&invalid_poll_and_get_reply_profile);
2096 end_profile (&valid_poll_and_get_reply_profile);
2098 start_profile (&decode_reply_profile);
2099 /* check the corresponding request */
2100 dep_index = biod_reqp[biod_index].dep_tab_index;
2101 proc = dep_tab[dep_index].proc;
2102 op_ptr = &Ops[proc];
2104 if (dep_tab[dep_index].flag != DEP_FLAG_SENT) {
2105 printf("dep_tab[%d].flag %d proc %d status %d start %d:%d stop %d:%d\n",
2106 dep_index, dep_tab[dep_index].flag, proc, dep_tab[dep_index].status,
2107 dep_tab[dep_index].start.sec, dep_tab[dep_index].start.usec,
2108 dep_tab[dep_index].stop.sec, dep_tab[dep_index].stop.usec );
2109 printf ("received reply for timeout requests dep_tab[%d].disk_index %d\n", dep_index, dep_tab[dep_index].disk_index);
2112 RFS_ASSERT (dep_tab[dep_index].flag == DEP_FLAG_SENT);
2114 /* decode the reply */
2115 rfs_Ops[proc].setres (arg_res, buf1);
2116 ret = proc_header (NFS_client, rfs_Ops[proc].xdr_res, arg_res);
2117 RFS_ASSERT (ret == RPC_SUCCESS);
2118 status = *((int *)arg_res);
2119 errmsg = nfs3_strerror (status);
2120 end_profile (&decode_reply_profile);
2122 start_profile (&check_reply_profile);
2123 /* compare with the reply in the trace */
2124 line = dep_tab[dep_index].line;
2125 reply_line = find_reply_line (line, dep_tab[dep_index].disk_index);
2126 if (reply_line == NULL) {
2127 //printf ("disk[%d] can not find the reply line, assume trace_reply_status OK\n", dep_tab[dep_index].disk_index);
2128 trace_reply_status = NFS3_REPLY_MISS;
2129 missing_reply_num ++;
2131 trace_reply_status = find_reply_status (reply_line);
2133 /* print the result, trace play progress indicator */
2134 if ((dep_index %10000)==0 || rfs_debug)
2135 fprintf (stdout, "dep_tab[%d], disk_index %d, receive reply, rpc_ret %d xid %x nfs_ret %d %s trace_reply_status %d start %d:%d stop %d:%d \n", dep_index, dep_tab[dep_index].disk_index, ret, biod_reqp[biod_index].xid, status, errmsg, trace_reply_status, biod_reqp[biod_index].start.sec, biod_reqp[biod_index].start.usec, biod_reqp[biod_index].stop.sec, biod_reqp[biod_index].stop.usec);
2137 /* error checking */
2138 check_reply (proc, biod_index, dep_index, status, errmsg, trace_reply_status);
2140 /* free resources */
2141 finish_request (biod_index, dep_index, status);
2143 /* get statistics */
2144 if (status == trace_reply_status) {
2145 op_ptr->results.good_calls++;
2146 Ops[TOTAL].results.good_calls++;
2148 op_ptr->results.bad_calls++;
2149 Ops[TOTAL].results.bad_calls++;
2151 sfs_elapsedtime (op_ptr, &(biod_reqp[biod_index].start), &(biod_reqp[biod_index].stop));
2152 end_profile (&check_reply_profile);
2154 //start_profile (&add_create_object_profile);
2155 #ifndef TAKE_CARE_SYMBOLIC_LINK
2156 if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==MKNOD)) {
2158 if (trace_reply_status == NFS3_OK && (proc==CREATE || proc==MKDIR || proc==SYMLINK || proc==MKNOD)) {
2160 RFS_ASSERT (status == NFS_OK);
2161 RFS_ASSERT (reply_line);
2162 add_new_file_system_object(proc, dep_index, line, reply_line);
2164 //end_profile (&add_create_object_profile);
2167 void add_new_file_system_object (int proc, int dep_index, char * line, char * reply_line)
2169 char * child_trace_fh;
2170 fh_map_t * parent_entryp;
2171 char component_name[MAX_PLAY_PATH_SIZE];
2172 char * parent_trace_fh;
2173 char child_path[MAX_PLAY_PATH_SIZE];
2174 post_op_fh3 * post_op_fh3_child;
2175 char * reply_trace_fh;
2176 nfs_fh3 * child_fh3;
2178 parent_trace_fh = strstr (line, "fh");
2179 RFS_ASSERT (parent_trace_fh);
2180 parent_trace_fh +=3;
2181 parent_entryp = lookup_fh (parent_trace_fh);
2182 RFS_ASSERT (parent_entryp);
2183 parse_name (parent_trace_fh+65, component_name);
2184 strcpy (child_path, parent_entryp->path);
2185 strcat (child_path, "/");
2186 strcat (child_path, component_name);
2188 /* find the corresponding create request */
2189 //printf ("before find reply trace_fh reply_line %s\n", reply_line);
2190 reply_trace_fh = find_reply_trace_fh (reply_line);
2191 RFS_ASSERT (reply_trace_fh != NULL);
2194 RFS_ASSERT (((CREATE3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2195 child_fh3 = &((CREATE3res *)arg_res)->res_u.ok.obj.handle;
2198 RFS_ASSERT (((MKDIR3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2199 child_fh3 = &((MKDIR3res *)arg_res)->res_u.ok.obj.handle;
2202 RFS_ASSERT (((SYMLINK3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2203 child_fh3 = &((SYMLINK3res *)arg_res)->res_u.ok.obj.handle;
2206 RFS_ASSERT (((MKNOD3res *)arg_res)->res_u.ok.obj.handle_follows==TRUE);
2207 child_fh3 = &((MKNOD3res *)arg_res)->res_u.ok.obj.handle;
2210 RFS_ASSERT (proc==LOOKUP);
2211 child_fh3 = &((LOOKUP3res *)arg_res)->res_u.ok.object;
2216 RFS_ASSERT (reply_trace_fh[TRACE_FH_SIZE]==' ');
2217 reply_trace_fh[TRACE_FH_SIZE] = 0;
2218 add_fh (FH_MAP_FLAG_COMPLETE, reply_trace_fh, child_path, child_fh3); /* exist flag is not used now, set to 1 */
2219 reply_trace_fh[TRACE_FH_SIZE] = ' ';
2222 /* initialize timestamp and proc field of dep_tab entry */
2223 void trace_play(void)
2226 /* The flag to indicate whether trace_player is BUSY. Trace_player is BUSY
2227 * when either there is request to send or there is reply being
2228 * received. Otherwise it is IDLE. The timeout for polling replies
2229 * is set to 0 when BUSY, it is set to the waiting time to the first
2230 * request outside of current <min_dep_index, max_dep_index> window when IDLE.
2232 int busy_flag = BUSY;
2234 //int dep_index; /* index into dependency table: dep_tab */
2235 //int biod_index; /* index into outstanding requests: biod_reqp */
2240 adjust_play_window(busy_flag, &poll_timeout);
2242 start_profile (&total_profile);
2243 while ((min_dep_index<dep_tab_size) || (num_out_reqs>0)) {
2245 if (busy_flag == IDLE) {
2246 //start_profile (&check_timeout_profile);
2248 //end_profile (&check_timeout_profile);
2251 //start_profile (&adjust_play_window_profile);
2252 //adjust_play_window (flag, &poll_timeout);
2253 //adjust_play_window (flag+(max_dep_index-min_dep_index), &poll_timeout);
2254 adjust_play_window (busy_flag, &poll_timeout);
2256 printf("num_out_reqs %d\n", num_out_reqs);
2258 //end_profile (&adjust_play_window_profile);
2260 start_profile (&execute_next_request_profile);
2261 while (execute_next_request()!=-1)
2263 end_profile (&execute_next_request_profile);
2265 start_profile (&receive_next_reply_profile);
2266 while (receive_next_reply(busy_flag)!=-1)
2268 end_profile (&receive_next_reply_profile);
2270 end_profile (&total_profile);
2272 print_profile ("total_profile", &total_profile);
2274 print_profile ("check_timeout", &check_timeout_profile);
2276 print_profile ("adjust_play_window", &adjust_play_window_profile);
2278 print_profile ("execute_next_request_profile", &execute_next_request_profile);
2279 print_profile ("valid_get_nextop_profile", &valid_get_nextop_profile);
2280 print_profile ("invalid_get_nextop_profile", &invalid_get_nextop_profile);
2281 print_profile ("prepare_argument", &prepare_argument_profile);
2282 print_profile ("biod_clnt_call", &biod_clnt_call_profile);
2284 print_profile ("receive_next_reply", &receive_next_reply_profile);
2285 print_profile ("valid_poll_and_get_reply_profile", &valid_poll_and_get_reply_profile);
2286 print_profile ("invalid_poll_and_get_reply_profile", &invalid_poll_and_get_reply_profile);
2287 print_profile ("decode_reply", &decode_reply_profile);
2288 print_profile ("check_reply", &check_reply_profile);
2289 print_profile ("add_create_object", &add_create_object_profile);
2292 printf ("min_dep_index %d dep_tab_size %d num_out_reqs %d\n", min_dep_index, dep_tab_size, num_out_reqs);