More data items for scsi and ioscheduler event hooks

delete filter_by_pid filter for io scheduler event hooks

7 files changed, 90 insertions, 83 deletions

diff --git a/lket.5.in b/lket.5.in
index fb1dfcba..a18d1ec1 100644
--- a/lket.5.in
+++ b/lket.5.in
@@ -100,26 +100,30 @@ You could use
 to trace the IO scheduler activities. It contains three sub event hooks:
 .P
 .TP
-.B addevent.ioscheduler.elv_next_request (HOOKID=1)
-Trace when a request is retrieved from request queue
+.B addevent.ioscheduler.elv_add_request (HOOKID=1)
+Trace when a request is added to the request queue
 
 Data format is:
 
-.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8)
+.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8), 
+.I request(INT64), request_flags(INT64)
 .TP
-.B addevent.ioscheduler.elv_add_request (HOOKID=2)
-Trace when a request is added to the request queue
+.B addevent.ioscheduler.elv_next_request (HOOKID=2)
+Trace when a request is retrieved from request queue
 
 Data format is:
 
-.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8)
+.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8), 
+.I request(INT64), request_flags(INT64)
+
 .TP
 .B addevent.ioscheduler.elv_completed_request (HOOKID=3)
 Trace when a request is completed
 
 Data format is:
 
-.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8)
+.I common_data, elevator_name(STRING), disk_major(INT8), disk_minor(INT8), 
+.I request(INT64), request_flags(INT64)
 
 .SS TASK SCHEDULE ACTIVITIES (GROUPID=5)
 You could use
@@ -152,7 +156,7 @@ mid-layer prepares a IO request
 
 Data format is:
 
-.I common_data, disk_major(INT8), disk_minor(INT8), device_state(INT8)
+.I common_data, disk_major(INT8), disk_minor(INT8), device_state(INT8), request(INT64)
 .TP
 .B addevent.scsi.iodispatching (HOOKID=2)
 Dispatch a command to the low-level driver
@@ -160,7 +164,7 @@ Dispatch a command to the low-level driver
 Data format is:
 
 .I common_data, device_state(INT8), scsi_info(INT32), data_direction(INT8), 
-.I reqbuf_addr(INT64), reqbuf_len(INT32), cmd_identifier(INT64)
+.I reqbuf_addr(INT64), reqbuf_len(INT32), cmd_identifier(INT64), request(INT64)
 
 Where 
 .I scsi_info
@@ -179,7 +183,8 @@ I/O is done by low-level driver
 
 Data format is:
 
-.I common_data, scsi_info(INT32), data_direction(INT8), cmd_identifier(INT64)
+.I common_data, scsi_info(INT32), data_direction(INT8), cmd_identifier(INT64), 
+.I request(INT64)
 .TP
 .B addevent.scsi.iocompleted (HOOKID=4)
 mid-layer processed the completed IO
@@ -187,7 +192,7 @@ mid-layer processed the completed IO
 Data format is:
 
 .I common_data, scsi_info(INT32), data_direction(INT8), cmd_identifier(INT64),
-.I bytes_done(INT32)
+.I bytes_done(INT32), request(INT64)
 
 .SS PAGE FAULT (GROUPID=7)
 You could use 
diff --git a/tapset/LKET/Changelog b/tapset/LKET/Changelog
index 0aff69b6..3d2a836d 100644
--- a/tapset/LKET/Changelog
+++ b/tapset/LKET/Changelog
@@ -1,3 +1,10 @@
+2006-06-21  Li Guanglei <guanglei@cn.ibm.com>
+	
+	* scsi.stp, ioscheduler.stp, register_event.stp: 
+	More data items for scsi and ioscheduler event hooks
+	* ioscheduler.stp: delete filter_by_pid filter for io scheduler
+	event hooks
+	
 2006-06-15  Li Guanglei <guanglei@cn.ibm.com>
 	
 	* iosyscall.stp: new event hooks for io related syscalls
diff --git a/tapset/LKET/hookid_defs.stp b/tapset/LKET/hookid_defs.stp
index 9f919938..567e3ed9 100755
--- a/tapset/LKET/hookid_defs.stp
+++ b/tapset/LKET/hookid_defs.stp
@@ -15,8 +15,9 @@ global
 
 	/* io scheduler */
 	GROUP_IOSCHED,
-	HOOKID_IOSCHED_NEXT_REQ, HOOKID_IOSCHED_ADD_REQ,
-	HOOKID_IOSCHED_REMOVE_REQ,
+	HOOKID_IOSCHED_ADD_REQ,
+	HOOKID_IOSCHED_NEXT_REQ, 
+	HOOKID_IOSCHED_COMPLETE_REQ,
 
 	/* task dispatching */
 	GROUP_TASK,
@@ -113,9 +114,9 @@ int _HOOKID_PROCESS_SNAPSHOT = 1;
 int _HOOKID_PROCESS_EXECVE = 2;
 int _HOOKID_PROCESS_FORK = 3;
 
-int _HOOKID_IOSCHED_NEXT_REQ = 1;
-int _HOOKID_IOSCHED_ADD_REQ = 2;
-int _HOOKID_IOSCHED_REMOVE_REQ = 3;
+int _HOOKID_IOSCHED_ADD_REQ = 1;
+int _HOOKID_IOSCHED_NEXT_REQ = 2;
+int _HOOKID_IOSCHED_COMPLETE_REQ = 3;
 
 int _HOOKID_TASK_CTXSWITCH = 1;
 int _HOOKID_TASK_CPUIDLE = 2;
@@ -196,9 +197,9 @@ function hookid_init()
 	HOOKID_PROCESS_FORK = 3
 
 	GROUP_IOSCHED = 4
-	HOOKID_IOSCHED_NEXT_REQ = 1
-	HOOKID_IOSCHED_ADD_REQ = 2
-	HOOKID_IOSCHED_REMOVE_REQ = 3
+	HOOKID_IOSCHED_ADD_REQ = 1
+	HOOKID_IOSCHED_NEXT_REQ = 2
+	HOOKID_IOSCHED_COMPLETE_REQ = 3
 
 	GROUP_TASK = 5
 	HOOKID_TASK_CTXSWITCH = 1
diff --git a/tapset/LKET/ioscheduler.stp b/tapset/LKET/ioscheduler.stp
index 298ae72b..d9af8a53 100755
--- a/tapset/LKET/ioscheduler.stp
+++ b/tapset/LKET/ioscheduler.stp
@@ -23,9 +23,7 @@ probe addevent.ioscheduler.elv_next_request
 probe _addevent.ioscheduler.elv_next_request
 	=  ioscheduler.elv_next_request
 {
-	if(filter_by_pid() == 1 ) {
-		log_ioscheduler_tracedata_elv_next(HOOKID_IOSCHED_NEXT_REQ, $q)
-	}
+	log_ioscheduler_tracedata_elv_next(HOOKID_IOSCHED_NEXT_REQ, $q)
 }
 
 
@@ -39,9 +37,7 @@ probe addevent.ioscheduler.elv_add_request
 probe _addevent.ioscheduler.elv_add_request
 	= ioscheduler.elv_add_request
 {
-	if(filter_by_pid() == 1 ) {
-		log_ioscheduler_tracedata_others(HOOKID_IOSCHED_ADD_REQ, $q, $rq)
-	}
+	log_ioscheduler_tracedata_others(HOOKID_IOSCHED_ADD_REQ, $q, $rq)
 }
 
 /* when a request is completed */
@@ -54,9 +50,7 @@ probe addevent.ioscheduler.elv_completed_request
 probe _addevent.ioscheduler.elv_completed_request
 	= ioscheduler.elv_completed_request
 {
-	if(filter_by_pid() == 1 ) {
-		log_ioscheduler_tracedata_others(HOOKID_IOSCHED_REMOVE_REQ, $q, $rq)
-	}
+	log_ioscheduler_tracedata_others(HOOKID_IOSCHED_COMPLETE_REQ, $q, $rq)
 }
 
 
@@ -73,11 +67,12 @@ function log_ioscheduler_tracedata_others(var_id:long, var_q:long, var_rq:long)
 	struct request *rq = (struct request *)((long)THIS->var_rq);
 	struct request_queue *q = (struct request_queue *)((long)THIS->var_q);
 	
-	/* elevator name|major|minor|  */
+	/* elevator name|major|minor|request|request_flags  */
 
-	_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b",
+	_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b",
 		q->elevator->elevator_type->elevator_name,
-		(_FMT_)rq->rq_disk->major, (_FMT_)rq->rq_disk->first_minor); 
+		(_FMT_)rq->rq_disk->major, (_FMT_)rq->rq_disk->first_minor,
+		(int64_t)((long)rq), (_FMT_)rq->flags); 
 %}
 
 %:
@@ -87,10 +82,12 @@ function log_ioscheduler_tracedata_others(var_id:long, var_q:long, var_rq:long)
 	struct request *rq = (struct request *)((long)THIS->var_rq);
 	struct request_queue *q = (struct request_queue *)((long)THIS->var_q);
 	
-	/* elevator name|major|minor|  */
+	/* elevator name|major|minor|request|request_flags  */
 
-	_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b", q->elevator.elevator_name, 
-		(_FMT_)rq->rq_disk->major, (_FMT_)rq->rq_disk->first_minor); 
+	_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b", 
+		q->elevator.elevator_name, (_FMT_)rq->rq_disk->major, 
+		(_FMT_)rq->rq_disk->first_minor, (int64_t)((long)rq),
+		(_FMT_)rq->flags);
 %}
 
 %)
@@ -108,19 +105,21 @@ function log_ioscheduler_tracedata_elv_next(var_id:long, var:long)
 	q = (struct request_queue *)((long)THIS->var);
 
 	/* If there is a request in the request queue:
-		elevator name|major|minor|
+		elevator name|major|minor|request|req_flags
 	   if there is no request in the request queue:
-		elevator name|empty| 
+		elevator name|empty|0|0 
 	*/
 
 	if(list_empty(&(q->queue_head))) {
-		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b", 
-			q->elevator->elevator_type->elevator_name, (_FMT_)-1, (_FMT_)-1);
+		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b", 
+			q->elevator->elevator_type->elevator_name, (_FMT_)-1, 
+			(_FMT_)-1, (_FMT_)0, (_FMT_)0);
 	} else  {
 		rq = list_entry_rq(q->queue_head.next);
-		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b", 
+		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b", 
 			q->elevator->elevator_type->elevator_name, (_FMT_)rq->rq_disk->major, 
-			(_FMT_)rq->rq_disk->first_minor); 
+			(_FMT_)rq->rq_disk->first_minor, (int64_t)((long)rq),
+			(_FMT_)rq->flags); 
 	}
 
 %}
@@ -136,17 +135,20 @@ function log_ioscheduler_tracedata_elv_next(var_id:long, var:long)
 	q = (struct request_queue *)((long)THIS->var);
 
 	/* If there is a request in the request queue:
-		elevator name|major|minor|
+		elevator name|major|minor|request|req_flags
 	   if there is no request in the request queue:
-		elevator name|empty| 
+		elevator name|empty|0|0
 	*/
 	if(list_empty(&(q->queue_head))) {
-		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b", 
-			q->elevator.elevator_name, (_FMT_)-1, (_FMT_)-1);
+		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b", 
+			q->elevator.elevator_name, (_FMT_)-1, (_FMT_)-1, 
+			(_FMT_)0, (_FMT_)0);
 	} else  {
 		rq = list_entry_rq(q->queue_head.next);
-		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b", q->elevator.elevator_name, 
-			(_FMT_)rq->rq_disk->major, (_FMT_)rq->rq_disk->first_minor); 
+		_lket_trace(_GROUP_IOSCHED, THIS->var_id, "%0s%1b%1b%8b%8b", 
+			q->elevator.elevator_name, (_FMT_)rq->rq_disk->major, 
+			(_FMT_)rq->rq_disk->first_minor, (int64_t)((long)rq),
+			(_FMT_)rq->flags); 
 	}
 
 %}
diff --git a/tapset/LKET/iosyscall.stp b/tapset/LKET/iosyscall.stp
index 527aaeeb..36f96fe4 100755
--- a/tapset/LKET/iosyscall.stp
+++ b/tapset/LKET/iosyscall.stp
@@ -369,15 +369,3 @@ function log_iosyscall_flock(fd:long, operation:long)
 	_lket_trace(_GROUP_IOSYSCALL, _HOOKID_IOSYSCALL_FLOCK_ENTRY,
 		"%8b%4b", THIS->fd, THIS->operation);
 %}
-	
-/*
-
-fs:
-newfstat, newlstat, newstat,pipe,poll,select,readlink,rename,rmdir,symlink,,
-truncate,ftruncate,unlink,chmod,chown,dup,dup2,fchdir,fchmod,fchown,fcntl,
-fstatfs,link,mkdir,
-
-aio:
-io_cancel,io_destroy,io_getevents,io_setup,io_submit, 
-
-*/
diff --git a/tapset/LKET/register_event.stp b/tapset/LKET/register_event.stp
index 76b6d6f2..24c8caee 100755
--- a/tapset/LKET/register_event.stp
+++ b/tapset/LKET/register_event.stp
@@ -82,7 +82,8 @@ function register_event(grpid:long, hookid:long, evt_type:long, fmt:string, name
 
 	if( THIS->grpid <= 0 || THIS->grpid > _MAXGROUPID ||
 		THIS->hookid <= 0 || THIS->hookid > _MAXHOOKID)  {
-		_stp_warn("wrong range in groupid/hookid\n");
+		_stp_warn("wrong range in groupid/hookid, grp:%d, hkid:%d\n",
+			THIS->grpid, THIS->hookid);
 		_stp_exit();
 	}
 
@@ -129,13 +130,13 @@ function register_sys_events()
 		"INT32", "pid")
 
 	register_sys_event(GROUP_IOSCHED, HOOKID_IOSCHED_NEXT_REQ,
-		"STRING:INT8:INT8", "elv_name:major:minor")
+		"STRING:INT8:INT8:INT64:INT64", "elv_name:major:minor:request:req_flags")
 
 	register_sys_event(GROUP_IOSCHED, HOOKID_IOSCHED_ADD_REQ,
-		"STRING:INT8:INT8", "elv_name:major:minor")
+		"STRING:INT8:INT8:INT64:INT64", "elv_name:major:minor:request:req_flags")
 
-	register_sys_event(GROUP_IOSCHED, HOOKID_IOSCHED_REMOVE_REQ,
-		"STRING:INT8:INT8", "elv_name:major:minor")
+	register_sys_event(GROUP_IOSCHED, HOOKID_IOSCHED_COMPLETE_REQ,
+		"STRING:INT8:INT8:INT64:INT64", "elv_name:major:minor:request:req_flags")
 
 	register_sys_event(GROUP_TASK, HOOKID_TASK_CTXSWITCH,
 		"INT32:INT32:INT8", "prev_pid:next_pid:prev_state")
@@ -144,17 +145,17 @@ function register_sys_events()
 		"INT32", "cur_pid")
 
 	register_sys_event(GROUP_SCSI, HOOKID_SCSI_IOENTRY,
-		"INT8:INT8:INT8", "major:minor:sdev_state")
+		"INT8:INT8:INT8:INT64", "major:minor:sdev_state:request")
 
 	register_sys_event(GROUP_SCSI, HOOKID_SCSI_IO_TO_LLD,
-		"INT8:INT32:INT8:INT64:INT32:INT64",
-		"sdev_state:scsi_info:data_dir:req_buff:buf_len:cmd_id")
+		"INT8:INT32:INT8:INT64:INT32:INT64:INT64",
+		"sdev_state:scsi_info:data_dir:req_buff:buf_len:cmd_id:request")
 
 	register_sys_event(GROUP_SCSI, HOOKID_SCSI_IODONE_BY_LLD,
-		"INT32:INT8:INT64", "scsi_info:data_dir:cmd_id")
+		"INT32:INT8:INT64:INT64", "scsi_info:data_dir:cmd_id:request")
 
 	register_sys_event(GROUP_SCSI, HOOKID_SCSI_IOCOMP_BY_MIDLEVEL,
-		"INT32:INT8:INT64:INT32", "scsi_info:data_dir:cmd_id:bytes");
+		"INT32:INT8:INT64:INT32:INT64", "scsi_info:data_dir:cmd_id:bytes:request");
 
 	register_sys_event(GROUP_PAGEFAULT, HOOKID_PAGEFAULT,
 		"INT64:INT8", "addr:write")
diff --git a/tapset/LKET/scsi.stp b/tapset/LKET/scsi.stp
index a9e4e4d9..1c4c5ac8 100755
--- a/tapset/LKET/scsi.stp
+++ b/tapset/LKET/scsi.stp
@@ -96,10 +96,10 @@ function log_scsi_ioentry(var_id:long, var_q:long, var_rq:long)
 	struct scsi_device *sdev = (struct scsi_device *)(q->queuedata);
 
 	/* 
-	major|minor|scsi_device_state| 
+	major|minor|scsi_device_state|request
 	*/
-	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%1b%1b", (_FMT_)rq->rq_disk->major, 
-		(_FMT_)rq->rq_disk->first_minor, (_FMT_)sdev->sdev_state);
+	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%1b%1b%8b", (_FMT_)rq->rq_disk->major, 
+		(_FMT_)rq->rq_disk->first_minor, (_FMT_)sdev->sdev_state, (int64_t)((long)rq));
 %}
 
 /* log the info about scsi_dispatching_cmd
@@ -135,16 +135,17 @@ function log_scsi_dispatch(var_id:long, var:long)
 		((cmd->device->lun & 0xFF) <<  8) | 
 		(cmd->device->id & 0xFF);
 
-	/* sdev_state|scsi_info|data_direction|cmd_identifier|request_buffer|request_bufflen
+	/* sdev_state|scsi_info|data_direction|cmd_identifier|request_buffer|request_bufflen|request
 	 *
 	 * sdev_state could be: SDEV_DEL, SDEV_BLOCK or something else.
 	 * Instead of skipping SDEV_DEL & SDEV_BLOCK, I choose to log them
 	 */
 
-	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%4b%1b%8b%4b%8b",
+	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%4b%1b%8b%4b%8b%8b",
 		(_FMT_)cmd->device->sdev_state, (_FMT_)scsi_info,
 		(_FMT_)cmd->sc_data_direction, (int64_t)((long)cmd->request_buffer),
-		(_FMT_)cmd->request_bufflen, (int64_t)cmd->device->host->cmd_pid);
+		(_FMT_)cmd->request_bufflen, (int64_t)cmd->device->host->cmd_pid,
+		(int64_t)((long)(cmd->request)));
 %}
 %:
 
@@ -158,7 +159,7 @@ function log_scsi_dispatch(var_id:long, var:long)
 		((cmd->device->lun & 0xFF) <<  8) | 
 		(cmd->device->id & 0xFF);
 
-	/* sdev_state|scsi_info|data_direction|cmd_identifier|request_buffer|request_bufflen
+	/* sdev_state|scsi_info|data_direction|cmd_identifier|request_buffer|request_bufflen|request
 	 *
 	 * sdev_state could be: SDEV_DEL, SDEV_BLOCK or something else.
 	 * Instead of skipping SDEV_DEL & SDEV_BLOCK, I choose to log them
@@ -167,10 +168,10 @@ function log_scsi_dispatch(var_id:long, var:long)
 	/* systemTap failed to access global variable. So I temporarily use 0.
 	_stp_printf("%d|", scsi_pid);
 	*/
-	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%4b%1b%8b%4b%8b",
+	_lket_trace(_GROUP_SCSI, THIS->var_id, "%1b%4b%1b%8b%4b%8b%8b",
 		(_FMT_)cmd->device->sdev_state, (_FMT_)scsi_info,
 		(_FMT_)cmd->sc_data_direction, (int64_t)((long)cmd->request_buffer),
-		(_FMT_)cmd->request_bufflen, (int64_t)0);
+		(_FMT_)cmd->request_bufflen, (int64_t)0, (int64_t)((long)(cmd->request)));
 %}
 %)
 
@@ -185,9 +186,10 @@ function log_scsi_iodone_extra(var_id:long, var:long)
 		((cmd->device->lun & 0xFF) <<  8) | 
 		(cmd->device->id & 0xFF);
 
-	/* scsi_info|data_direction|cmd_identifier| */
-	_lket_trace(_GROUP_SCSI, THIS->var_id, "%4b%1b%8b", (_FMT_)scsi_info, 
-		(_FMT_)cmd->sc_data_direction, (int64_t)cmd->pid);
+	/* scsi_info|data_direction|cmd_identifier|request */
+	_lket_trace(_GROUP_SCSI, THIS->var_id, "%4b%1b%8b%8b", (_FMT_)scsi_info, 
+		(_FMT_)cmd->sc_data_direction, (int64_t)cmd->pid, 
+		(int64_t)((long)(cmd->request)));
 %}
 
 /* log the info about scsi_dispatching_cmd */
@@ -202,7 +204,8 @@ function log_scsi_iocompleted(var_id:long, var_cmd:long, var_goodbytes:long)
 		((cmd->device->lun & 0xFF) <<  8) | 
 		(cmd->device->id & 0xFF);
 
-	/* scsi_info|data_direction|cmd_identifier|goodbytes */
-	_lket_trace(_GROUP_SCSI, THIS->var_id, "%4b%1b%8b%4b", (_FMT_)scsi_info, 
-		(_FMT_)cmd->sc_data_direction, (int64_t)cmd->pid, (_FMT_)goodbytes);
+	/* scsi_info|data_direction|cmd_identifier|goodbytes|request */
+	_lket_trace(_GROUP_SCSI, THIS->var_id, "%4b%1b%8b%4b%8b", (_FMT_)scsi_info, 
+		(_FMT_)cmd->sc_data_direction, (int64_t)cmd->pid, (_FMT_)goodbytes,
+		(int64_t)((long)(cmd->request)));
 %}