Hi,
In this D script:
#
#
#
#
# cat spa_sync_2.d
#!/usr/sbin/dtrace -qs
BEGIN {
self->prevtime=0;
}
spa_sync:entry
{
printf("%Y thread %a enter\n", walltimestamp, curthread );
self->t = 1;
}
spa_sync:entry
/self->prevtime > 0 && self->t == 1/
{
times = self->prevtime ? timestamp - self->prevtime : 0;
printf("%Y thread %a re-entering after %d\n", walltimestamp, curthread,
times/(1000*1000));
}
spa_sync:entry
{
self->prevtime = timestamp;
}
spa_sync:return
/self->t == 1 && self->prevtime > 0/
{
self->t = 0;
printf("%Y thread %a did work for %d ms\n", walltimestamp, curthread
,(timestamp - self->prevtime)/(1000*1000));
printf("%Y thread %a leaving \n\n", walltimestamp,curthread);
}
tick-1s {
printf("%Y \n",walltimestamp);
}
most of the times the probes fire as expected in this order
"enter
re-enter [optional]
did work
leave
"
2009 Dec 18 19:44:43
2009 Dec 18 19:44:44
2009 Dec 18 19:44:45
2009 Dec 18 19:44:46
2009 Dec 18 19:44:47
2009 Dec 18 19:44:48
2009 Dec 18 19:44:49
2009 Dec 18 19:44:50
2009 Dec 18 19:44:51
2009 Dec 18 19:44:52
2009 Dec 18 19:44:53
2009 Dec 18 19:44:54
2009 Dec 18 19:44:55
2009 Dec 18 19:44:56
2009 Dec 18 19:44:57 thread 0x2a100be7ca0 enter
2009 Dec 18 19:44:57 thread 0x2a100be7ca0 did work for 309 ms
2009 Dec 18 19:44:57 thread 0x2a100be7ca0 leaving
2009 Dec 18 19:44:57
2009 Dec 18 19:44:58 thread 0x2a103aa7ca0 enter
2009 Dec 18 19:44:58 thread 0x2a103aa7ca0 did work for 30 ms
2009 Dec 18 19:44:58 thread 0x2a103aa7ca0 leaving
2009 Dec 18 19:44:58
2009 Dec 18 19:44:59
2009 Dec 18 19:45:00
2009 Dec 18 19:45:01 thread 0x2a1065d9ca0 enter
2009 Dec 18 19:45:01 thread 0x2a1065d9ca0 did work for 15 ms
2009 Dec 18 19:45:01 thread 0x2a1065d9ca0 leaving
2009 Dec 18 19:45:01
2009 Dec 18 19:45:02
2009 Dec 18 19:45:03
2009 Dec 18 19:45:04
2009 Dec 18 19:45:05
2009 Dec 18 19:45:06
2009 Dec 18 19:45:07
2009 Dec 18 19:45:08
2009 Dec 18 19:45:09
2009 Dec 18 19:45:10
2009 Dec 18 19:45:11
2009 Dec 18 19:45:12
2009 Dec 18 19:45:13
2009 Dec 18 19:45:14
2009 Dec 18 19:45:15
2009 Dec 18 19:45:16
2009 Dec 18 19:45:17
2009 Dec 18 19:45:18
2009 Dec 18 19:45:19
2009 Dec 18 19:45:20
2009 Dec 18 19:45:21
2009 Dec 18 19:45:22
2009 Dec 18 19:45:23
2009 Dec 18 19:45:24
2009 Dec 18 19:45:25
2009 Dec 18 19:45:26
2009 Dec 18 19:45:27 thread 0x2a100be7ca0 enter
2009 Dec 18 19:45:27 thread 0x2a100be7ca0 re-entering after 30010
2009 Dec 18 19:45:27
2009 Dec 18 19:45:27 thread 0x2a100be7ca0 did work for 293 ms
2009 Dec 18 19:45:27 thread 0x2a100be7ca0 leaving
2009 Dec 18 19:45:28 thread 0x2a103aa7ca0 enter
2009 Dec 18 19:45:28 thread 0x2a103aa7ca0 re-entering after 30009
2009 Dec 18 19:45:28
2009 Dec 18 19:45:28 thread 0x2a103aa7ca0 did work for 22 ms
2009 Dec 18 19:45:28 thread 0x2a103aa7ca0 leaving
2009 Dec 18 19:45:29
2009 Dec 18 19:45:30
2009 Dec 18 19:45:31 thread 0x2a1065d9ca0 enter
2009 Dec 18 19:45:31 thread 0x2a1065d9ca0 re-entering after 30009
2009 Dec 18 19:45:31 thread 0x2a1065d9ca0 did work for 12 ms
2009 Dec 18 19:45:31 thread 0x2a1065d9ca0 leaving
2009 Dec 18 19:45:31
2009 Dec 18 19:45:32
2009 Dec 18 19:45:33
2009 Dec 18 19:45:34
2009 Dec 18 19:45:35
2009 Dec 18 19:45:36
2009 Dec 18 19:45:37
2009 Dec 18 19:45:38
2009 Dec 18 19:45:39
2009 Dec 18 19:45:40
2009 Dec 18 19:45:41
2009 Dec 18 19:45:42
2009 Dec 18 19:45:43
2009 Dec 18 19:45:44
2009 Dec 18 19:45:45
2009 Dec 18 19:45:46
2009 Dec 18 19:45:47
2009 Dec 18 19:45:48
2009 Dec 18 19:45:49
2009 Dec 18 19:45:50
2009 Dec 18 19:45:51
2009 Dec 18 19:45:52
2009 Dec 18 19:45:53
2009 Dec 18 19:45:54
2009 Dec 18 19:45:55
2009 Dec 18 19:45:56
2009 Dec 18 19:45:57 thread 0x2a100be7ca0 enter
2009 Dec 18 19:45:57 thread 0x2a100be7ca0 re-entering after 30010
2009 Dec 18 19:45:57
2009 Dec 18 19:45:57 thread 0x2a100be7ca0 did work for 286 ms
2009 Dec 18 19:45:57 thread 0x2a100be7ca0 leaving
2009 Dec 18 19:45:58 thread 0x2a103aa7ca0 enter
2009 Dec 18 19:45:58 thread 0x2a103aa7ca0 re-entering after 30010
2009 Dec 18 19:45:58 thread 0x2a103aa7ca0 did work for 20 ms
2009 Dec 18 19:45:58 thread 0x2a103aa7ca0 leaving
2009 Dec 18 19:45:58
2009 Dec 18 19:45:59
2009 Dec 18 19:46:00
2009 Dec 18 19:46:01 thread 0x2a1065d9ca0 did work for 17 ms
2009 Dec 18 19:46:01 thread 0x2a1065d9ca0 leaving
2009 Dec 18 19:46:01 thread 0x2a1065d9ca0 enter
2009 Dec 18 19:46:01 thread 0x2a1065d9ca0 re-entering after 30009
2009 Dec 18 19:46:01
but in the last instance we have the order
"did work
leaving
enter
re-enter"
I checked that thread 0x2a1065d9ca0 did fire spa_sync:return, so I don't
understand why the order changed.
Thanks for any clarification.
--
This message posted from opensolaris.org
_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org
