thr3ads.net - freebsd stable - Something missing in truss [Dec 2011]

If this information is useful, please help other people find it:
Share via:

Eivind Evensen

2011-Dec-02 10:14 UTC

Something missing in truss

Does anybody else see this or know why?

The machine here is running :
> uname -aFreeBSD elg.hjerdalen.lokalnett 8.2-STABLE FreeBSD 8.2-STABLE #36: Wed Nov 30
22:03:07 CET 2011     rumrunner@elg.hjerdalen.lokalnett:/usr/obj/usr/src/sys/RUM
amd64

While trying to weed out some firefox problems, I've noticed
that truss doesn't recognise certain syscalls :

getpid()					 = 1519 (0x5ef)
clock_gettime(4,{48496.335142903 })		 = 0 (0x0)
kevent(20,{0x23,EVFILT_READ,EV_ADD,0,0x0,0x809ec9d80},1,{0x15,EVFILT_READ,0x0,0,0x1,0x809ec9e80},64,0x0)
= 1 (0x1)
clock_gettime(4,{48496.335293202 })		 = 0 (0x0)
read(21,"\0",1)					 = 1 (0x1)
clock_gettime(4,{48496.335382599 })		 = 0 (0x0)
umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116 (0x74)
-- UNKNOWN SYSCALL -14704864 --
syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116 (0x74)
-- UNKNOWN SYSCALL -14704864 --
syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116 (0x74)
-- UNKNOWN SYSCALL -14704864 --
syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116 (0x74)
-- UNKNOWN SYSCALL -14704864 --
syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116 (0x74)
-- UNKNOWN SYSCALL -14704864 --
syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)

Using ktrace/kdump at the same time gives this (manually correlated) :

  1519 firefox-bin RET   getpid 1519/0x5ef
  1519 firefox-bin CALL  clock_gettime(0x4,0x7fffff9fdca0)
  1519 firefox-bin RET   clock_gettime 0
  1519 firefox-bin CALL  kevent(0x14,0x809ec0800,0x1,0x809ec0000,0x40,0)
  1519 firefox-bin GIO   fd 20 wrote 32 bytes
       0x0000 2300 0000 0000 0000 ffff 0100 0000 0000  |#...............|
       0x0010 0000 0000 0000 0000 809d ec09 0800 0000  |................|
  1519 firefox-bin GIO   fd 20 read 32 bytes
       0x0000 1500 0000 0000 0000 ffff 0000 0000 0000  |................|
       0x0010 0100 0000 0000 0000 809e ec09 0800 0000  |................|
  1519 firefox-bin RET   kevent 1
  1519 firefox-bin CALL  clock_gettime(0x4,0x7fffff9fdca0)
  1519 firefox-bin RET   clock_gettime 0
  1519 firefox-bin CALL  read(0x15,0x7fffff9fdc9f,0x1)
  1519 firefox-bin GIO   fd 21 read 1 byte
       "\0"
  1519 firefox-bin RET   read 1
  1519 firefox-bin CALL  clock_gettime(0x4,0x7fffff9fdca0)
  1519 firefox-bin RET   clock_gettime 0
  1519 firefox-bin CALL  kevent(0x14,0x809ec0800,0,0x809ec0000,0x40,0)
  1519 firefox-bin RET   _umtx_op -1 errno 60 Operation timed out
  1519 firefox-bin CALL  gettimeofday(0x7fffff1f9f20,0)
  1519 firefox-bin RET   gettimeofday 0
  1519 firefox-bin CALL  clock_gettime(0,0x7fffff1f9ec0)
  1519 firefox-bin RET   clock_gettime 0
  1519 firefox-bin CALL  _umtx_op(0x80a52ee20,0x8,0,0x80a52ee00,0x7fffff1f9eb0)
  1519 firefox-bin RET   _umtx_op -1 errno 60 Operation timed out
  1519 firefox-bin CALL  gettimeofday(0x7fffff1f9f20,0)
  1519 firefox-bin RET   gettimeofday 0
  1519 firefox-bin CALL  clock_gettime(0,0x7fffff1f9ec0)
  1519 firefox-bin RET   clock_gettime 0
  1519 firefox-bin CALL  _umtx_op(0x80a52ee20,0x8,0,0x80a52ee00,0x7fffff1f9eb0)
  1519 firefox-bin RET   _umtx_op -1 errno 60 Operation timed out


-- 
    _
_  //
\\//   Eivind Evensen
 \/

Dan Nelson

2011-Dec-03 20:10 UTC

head link

Something missing in truss

In the last episode (Dec 02), Eivind Evensen said:> Does anybody else see this or know why?
> 
> The machine here is running :
> 
> > uname -a
> FreeBSD elg.hjerdalen.lokalnett 8.2-STABLE FreeBSD 8.2-STABLE #36: Wed Nov
30 22:03:07 CET 2011    
rumrunner@elg.hjerdalen.lokalnett:/usr/obj/usr/src/sys/RUM  amd64
> 
> While trying to weed out some firefox problems, I've noticed
> that truss doesn't recognise certain syscalls :
> 
> getpid()					 = 1519 (0x5ef)
> clock_gettime(4,{48496.335142903 })		 = 0 (0x0)
>
kevent(20,{0x23,EVFILT_READ,EV_ADD,0,0x0,0x809ec9d80},1,{0x15,EVFILT_READ,0x0,0,0x1,0x809ec9e80},64,0x0)
= 1 (0x1)
> clock_gettime(4,{48496.335293202 })		 = 0 (0x0)
> read(21,"\0",1)					 = 1 (0x1)
> clock_gettime(4,{48496.335382599 })		 = 0 (0x0)
> umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116
(0x74)
> -- UNKNOWN SYSCALL -14704864 --
> syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
> umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116
(0x74)
> -- UNKNOWN SYSCALL -14704864 --
> syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
> umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116
(0x74)
> -- UNKNOWN SYSCALL -14704864 --
> syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
> umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116
(0x74)
> -- UNKNOWN SYSCALL -14704864 --
> syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
> umask(0x80a52ee20,0x8,0x0,0x80a52ee00,0x7fffff1f9eb0,0x80a52ee00) = 116
(0x74)
> -- UNKNOWN SYSCALL -14704864 --
> syscall(0x7fffff1f9ec0,0x0,0x18745,0x7fffff1f9eb0,0x1,0x7fffff1f9e90) = 454
(0x1c6)
Two problems: truss get confused when you attach to a process that's
currently executing a syscall, and it gets even more confused when you have
a threaded process waiting in many syscalls at once.

The following patch fixes problem #1, but problem #2 involves keeping more
per-thread state and ends up touching a lot of the truss code.  See
http://www.evoy.net/FreeBSD/truss.diff for one solution (and more syscall
decodes).

Index: setup.c
==================================================================--- setup.c
(revision 228242)
+++ setup.c	(working copy)
@@ -202,8 +202,10 @@
 		find_thread(info, lwpinfo.pl_lwpid);
 		switch(WSTOPSIG(waitval)) {
 		case SIGTRAP:
-			info->pr_why = info->curthread->in_syscall?S_SCX:S_SCE;
-			info->curthread->in_syscall = 1 - info->curthread->in_syscall;
+			if ((lwpinfo.pl_flags&(PL_FLAG_SCE|PL_FLAG_SCX)) == 0)
+				err(1,"pl_flags=%x contains neither PL_FLAG_SCE or PL_FLAG_SCX",
lwpinfo.pl_flags);
+			info->pr_why = (lwpinfo.pl_flags&PL_FLAG_SCE) ? S_SCE:S_SCX;
+			info->curthread->in_syscall = (info->pr_why == S_SCE) ? 1:0;
 			break;
 		default:
 			info->pr_why = S_SIG;


-- 
	Dan Nelson
	dnelson@allantgroup.com

freebsd stable - Dec 2011 - Something missing in truss

Something missing in truss

Something missing in truss