From owner-freebsd-stable@FreeBSD.ORG Wed Dec 3 18:36:50 2008 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id D3A281065677 for ; Wed, 3 Dec 2008 18:36:50 +0000 (UTC) (envelope-from marius@nuenneri.ch) Received: from el-out-1112.google.com (el-out-1112.google.com [209.85.162.178]) by mx1.freebsd.org (Postfix) with ESMTP id 91F5C8FC0A for ; Wed, 3 Dec 2008 18:36:50 +0000 (UTC) (envelope-from marius@nuenneri.ch) Received: by el-out-1112.google.com with SMTP id v27so1033750ele.17 for ; Wed, 03 Dec 2008 10:36:49 -0800 (PST) Received: by 10.90.92.16 with SMTP id p16mr2068753agb.91.1228327417729; Wed, 03 Dec 2008 10:03:37 -0800 (PST) Received: by 10.90.73.15 with HTTP; Wed, 3 Dec 2008 10:03:37 -0800 (PST) Message-ID: Date: Wed, 3 Dec 2008 19:03:37 +0100 From: "=?ISO-8859-1?Q?Marius_N=FCnnerich?=" To: "Dan Nelson" In-Reply-To: <20081203170857.GE22076@dan.emsphone.com> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: <20081203152330.GD22076@dan.emsphone.com> <20081203170857.GE22076@dan.emsphone.com> Cc: Vlad GALU , freebsd-stable@freebsd.org Subject: Re: Weird truss output X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 03 Dec 2008 18:36:50 -0000 On Wed, Dec 3, 2008 at 6:08 PM, Dan Nelson wrote: > In the last episode (Dec 03), Vlad GALU said: >> On Wed, Dec 3, 2008 at 5:23 PM, Dan Nelson wrote: >> > In the last episode (Dec 03), Vlad GALU said: >> >> I'm running a statically linked binary, which I've built inside a >> >> jail. The jail's libc & co are in sync with the host's. Truss then >> >> shows this: >> >> >> >> -- cut here -- >> >> -- UNKNOWN SYSCALL 1048532 -- >> >> -- UNKNOWN SYSCALL 1048532 -- >> > >> > Is this a threaded app that you attached truss to after it was >> > started? The method that truss uses to catch syscall enter/exit >> > events doesn't indicate whether the event is an enter or an exit, >> > so if you attach while a syscall is active, truss handles the exit >> > event as if it were a syscall entry event, and never gets back in >> > synch. It gets worse with threaded apps because each thread is >> > another chance to get out of synch. Try this patch: >> >> You were right, this application was indeed threaded. The messages >> still occur, although at a slightly lower rate. One other thing >> that's not particularly helpful is this: >> >> -- cut here-- >> read(1074283119,"\M-Ry\^A\0",7356800) = 4 (0x4) >> -- and here -- >> >> I obviously don't have that many descriptors in my process. I can >> live with the malformed message, but it's a PITA not to know which fd >> the read was actually made from :( > > It looks like there's some other problem where truss either drops a > syscall event, or puts some status fields into the wrong thread's > structure. It seems to happen when two threads call blocking syscalls, > and when they return, truss gets confused as to which thread called > which syscall. The read syscall is probably still pending, and you're > getting the arguments of the syscall that returned, printed as if it > was the read syscall. When the read call completes, you'll probably > get an --UNKNOWN SYSCALL-- line, or another mismatched syscall output > line. > > An alternative it to use ktrace/kdump to trace the process; it's more > cumbersome to use, but doesn't have problems with threaded processes. Maybe DTrace will help you but I don't know if there is enough ported yet.