Discussion:
Multiple provider and count()
Juhasz Balint
2011-08-26 08:17:23 UTC
Permalink
Hy!


I think i find some interesting problem (maybe it is basic :) ):
***@thelab ~/Tools/IPC$ ./ipc_count_syscall.d

syscall::semsys 1690
***@thelab ~/Tools/IPC$ cat ./ipc_count_syscall.d
#!/usr/sbin/dtrace -qs

#pragma D option quiet
#pragma D option destructive

syscall::sem*:entry
{
self->time = timestamp;
}

syscall::sem*:return
/self->time/
{
this->name = strjoin(probeprov, strjoin("::",probefunc));
@semcheck[this->name] = count();
self->time = 0;
}

tick-10sec
{
exit(0);
}

It's ok, but if i put fbt provider checking to this script, i can't
see syscall fields in the count() result:

***@thelab ~/Tools/IPC$ ./ipc_count_all.d

fbt:genunix:sema_destroy 4
fbt:genunix:sema_init 8
fbt:genunix:sema_tryp 81
fbt:genunix:sema_p 208
fbt:genunix:sema_v 289
fbt:ipc:ipc_lock_internal 1850
fbt:ipc:ipcperm_access 1850
fbt:semsys:sem_undo_add 1850
fbt:semsys:sem_undo_compar 1850
fbt:semsys:semsys 1850
***@thelab ~/Tools/IPC$ cat ./ipc_count_all.d
#!/usr/sbin/dtrace -qs

#pragma D option quiet
#pragma D option destructive

fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
self->time = timestamp;
}

fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return
/self->time/
{
this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
@semcheck[this->name] = count();
self->time = 0;
}

syscall::sem*:return
/self->time/
{
this->name = strjoin(probeprov, strjoin("::",probefunc));
@semcheck[this->name] = count();
self->time = 0;
}

tick-10sec
{
exit(0);
}

If i modify the script, it also not working.

***@thelab ~/Tools/IPC$ ./ipc_count_all.d

fbt:genunix:sema_tryp 1
fbt:genunix:sema_destroy 4
fbt:genunix:sema_init 14
fbt:genunix:sema_p 59
fbt:genunix:sema_v 60
fbt:ipc:ipc_lock_internal 1850
fbt:ipc:ipcperm_access 1850
fbt:semsys:sem_undo_add 1850
fbt:semsys:sem_undo_compar 1850
fbt:semsys:semsys 1850
***@thelab ~/Tools/IPC$ cat ./ipc_count_all.d
#!/usr/sbin/dtrace -qs

#pragma D option quiet
#pragma D option destructive

fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
self->time = timestamp;
}

fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return,
syscall::sem*:return
/self->time/
{
this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
@semcheck[this->name] = count();
self->time = 0;
}

tick-10sec
{
exit(0);
}

I know i can use printa to print probeprov, probemod and probefunc but
i prefer strjoin :)
In this case i doesn't understand where are syscall' count.

Anyone has an idea about this problem?

Cni
Adam Leventhal
2011-08-26 15:09:10 UTC
Permalink
Hi Cni,

Your script is not operating the way you intended, but DTrace is
functioning properly. The fbt return probes are firing before the
syscall return probes and thus setting self->time to 0 so that when
the syscall return probe fires the predicate evaluates to false.

You don't seem to be doing any computation with self->time. If you're
just trying to count the number of times the functions you've listed
fire, you can just do this:

fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
this->name = strjoin(probeprov, strjoin(strjoin(":", probemod),
strjoin(":", probefunc)));
@semcheck[this->name] = count();
}

Adam
Hy!
 syscall::semsys                                                1690
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
syscall::sem*:entry
{
     self->time = timestamp;
}
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov, strjoin("::",probefunc));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
It's ok, but if i put fbt provider checking to this script, i can't
 fbt:genunix:sema_destroy                                          4
 fbt:genunix:sema_init                                             8
 fbt:genunix:sema_tryp                                            81
 fbt:genunix:sema_p                                              208
 fbt:genunix:sema_v                                              289
 fbt:ipc:ipc_lock_internal                                      1850
 fbt:ipc:ipcperm_access                                         1850
 fbt:semsys:sem_undo_add                                        1850
 fbt:semsys:sem_undo_compar                                     1850
 fbt:semsys:semsys                                              1850
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
     self->time = timestamp;
}
fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return
/self->time/
{
     this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
     self->time = 0;
}
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov, strjoin("::",probefunc));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
If i modify the script, it also not working.
 fbt:genunix:sema_tryp                                             1
 fbt:genunix:sema_destroy                                          4
 fbt:genunix:sema_init                                            14
 fbt:genunix:sema_p                                               59
 fbt:genunix:sema_v                                               60
 fbt:ipc:ipc_lock_internal                                      1850
 fbt:ipc:ipcperm_access                                         1850
 fbt:semsys:sem_undo_add                                        1850
 fbt:semsys:sem_undo_compar                                     1850
 fbt:semsys:semsys                                              1850
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
     self->time = timestamp;
}
fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return,
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
I know i can use printa to print probeprov, probemod and probefunc but
i prefer strjoin :)
In this case i doesn't understand where are syscall' count.
Anyone has an idea about this problem?
Cni
_______________________________________________
dtrace-discuss mailing list
--
Adam Leventhal, Delphix
http://dtrace.org/blogs/ahl

275 Middlefield Road, Suite 50
Menlo Park, CA 94025
http://www.delphix.com
Juhasz Balint
2011-08-26 19:19:40 UTC
Permalink
Hy!


In the script i used self->time = timestamp because in that version i
used @semcheck[this->name] = quantize(timestamp - self->time);.

After the letters i thinking and checking, there are syscall if i
check only entry:
***@thelab ~/Tools/IPC$ ./ipc_count_entry.d

fbt:ipc:ipcs_lock 2
fbt:ipc:ipcs_unlock 2
fbt:ipc:ipc_lock 4
fbt:ipc:ipc_commit_begin 5
fbt:ipc:ipc_commit_end 5
fbt:ipc:ipc_get 5
fbt:ipc:ipc_remove 5
fbt:ipc:ipc_rmid 5
fbt:ipc:ipcperm_stat64 5
fbt:ipc:ipc_rele 9
fbt:ipc:ipc_alloc_test 10
fbt:ipc:ipc_hold 10
fbt:genunix:sema_tryp 107
fbt:genunix:sema_p 110
fbt:genunix:sema_destroy 160
fbt:genunix:sema_init 160
fbt:genunix:sema_v 217
fbt:semsys:sem_undo_add 1416
fbt:semsys:sem_undo_compar 1416
fbt:semsys:semop 1416
fbt:semsys:semsys 1416
syscall::semsys 1416
fbt:ipc:ipc_lookup 1436
fbt:ipc:ipcperm_access 1436
fbt:ipc:ipc_lock_internal 1440
***@thelab ~/Tools/IPC$ cat ./ipc_count_entry.d
#!/usr/sbin/dtrace -qs

#pragma D option quiet
#pragma D option destructive

fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
@semcheck[this->name] = count();
}

tick-10sec
{
exit(0);
}

And i find where set the original script self->time to 0 before
syscall::semsys:return, if i used flowident to
***@thelab ~/Tools/IPC$ ./ipc_syscall_flow.d
CPU FUNCTION
0 => semsys syscall::semsys
0 -> semsys fbt:semsys:semsys
0 <- semsys fbt:semsys:semsys <-
1. point where syscall's self->time set to 0 in the original script
0 -> semop fbt:semsys:semop
0 -> ipc_lookup fbt:ipc:ipc_lookup
0 -> ipc_lock_internal fbt:ipc:ipc_lock_internal
0 <- ipc_lock_internal
fbt:ipc:ipc_lock_internal <- 2. point where syscall's self->time set
to 0 in the original script
0 <- ipc_lookup fbt:ipc:ipc_lookup
<- 3. point where syscall's self->time set to 0 in the
original script
0 -> ipcperm_access fbt:ipc:ipcperm_access
0 -> crgetuid fbt:genunix:crgetuid
0 <- crgetuid fbt:genunix:crgetuid
0 -> getzoneid fbt:genunix:getzoneid
0 <- getzoneid fbt:genunix:getzoneid
0 <- ipcperm_access
fbt:ipc:ipcperm_access <- 4. point where syscall's self->time set to 0
in the original script
0 -> avl_find fbt:genunix:avl_find
0 -> sem_undo_compar fbt:semsys:sem_undo_compar
0 <- sem_undo_compar
fbt:semsys:sem_undo_compar<- 5. point where syscall's self->time set
to 0 in the original script
0 <- avl_find fbt:genunix:avl_find
0 -> sem_undo_add fbt:semsys:sem_undo_add
0 <- sem_undo_add
fbt:semsys:sem_undo_add <- 6. point where syscall's self->time set to
0 in the original script
0 <- semop fbt:semsys:semop <- 7.
point where syscall's self->time set to 0 in the original script
0 <= semsys syscall::semsys
Time: 232750

My original script doesn't reach syscall::semsys:return in my original script.
Thanks a lot Pramod and Adam, it was my fault :)

Br.:
Cni
Post by Adam Leventhal
Hi Cni,
Your script is not operating the way you intended, but DTrace is
functioning properly. The fbt return probes are firing before the
syscall return probes and thus setting self->time to 0 so that when
the syscall return probe fires the predicate evaluates to false.
You don't seem to be doing any computation with self->time. If you're
just trying to count the number of times the functions you've listed
fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
    this->name = strjoin(probeprov, strjoin(strjoin(":", probemod),
strjoin(":", probefunc)));
}
Adam
Hy!
 syscall::semsys                                                1690
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
syscall::sem*:entry
{
     self->time = timestamp;
}
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov, strjoin("::",probefunc));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
It's ok, but if i put fbt provider checking to this script, i can't
 fbt:genunix:sema_destroy                                          4
 fbt:genunix:sema_init                                             8
 fbt:genunix:sema_tryp                                            81
 fbt:genunix:sema_p                                              208
 fbt:genunix:sema_v                                              289
 fbt:ipc:ipc_lock_internal                                      1850
 fbt:ipc:ipcperm_access                                         1850
 fbt:semsys:sem_undo_add                                        1850
 fbt:semsys:sem_undo_compar                                     1850
 fbt:semsys:semsys                                              1850
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
     self->time = timestamp;
}
fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return
/self->time/
{
     this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
     self->time = 0;
}
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov, strjoin("::",probefunc));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
If i modify the script, it also not working.
 fbt:genunix:sema_tryp                                             1
 fbt:genunix:sema_destroy                                          4
 fbt:genunix:sema_init                                            14
 fbt:genunix:sema_p                                               59
 fbt:genunix:sema_v                                               60
 fbt:ipc:ipc_lock_internal                                      1850
 fbt:ipc:ipcperm_access                                         1850
 fbt:semsys:sem_undo_add                                        1850
 fbt:semsys:sem_undo_compar                                     1850
 fbt:semsys:semsys                                              1850
#!/usr/sbin/dtrace -qs
#pragma D option quiet
#pragma D option destructive
fbt:ipc::entry,
fbt:semsys::entry,
fbt:genunix:sem*:entry,
syscall::sem*:entry
{
     self->time = timestamp;
}
fbt:ipc::return,
fbt:semsys::return,
fbt:genunix:sem*:return,
syscall::sem*:return
/self->time/
{
     this->name = strjoin(probeprov,
strjoin(strjoin(":",probemod),strjoin(":",probefunc)));
     self->time = 0;
}
tick-10sec
{
     exit(0);
}
I know i can use printa to print probeprov, probemod and probefunc but
i prefer strjoin :)
In this case i doesn't understand where are syscall' count.
Anyone has an idea about this problem?
Cni
_______________________________________________
dtrace-discuss mailing list
--
Adam Leventhal, Delphix
http://dtrace.org/blogs/ahl
275 Middlefield Road, Suite 50
Menlo Park, CA 94025
http://www.delphix.com
_______________________________________________
dtrace-

Loading...