From owner-freebsd-current@freebsd.org Mon Dec 19 19:39:39 2016 Return-Path: Delivered-To: freebsd-current@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 24535C87524; Mon, 19 Dec 2016 19:39:39 +0000 (UTC) (envelope-from hrs@FreeBSD.org) Received: from mail.allbsd.org (gatekeeper.allbsd.org [IPv6:2001:2f0:104:e001::32]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "*.allbsd.org", Issuer "RapidSSL SHA256 CA - G3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 73A50187B; Mon, 19 Dec 2016 19:39:38 +0000 (UTC) (envelope-from hrs@FreeBSD.org) Received: from mail-d.allbsd.org (p2027-ipbf1605funabasi.chiba.ocn.ne.jp [123.225.191.27]) (authenticated bits=56) by mail.allbsd.org (8.15.2/8.15.2) with ESMTPSA id uBJJdEtQ006323 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=FAIL) (Client CN "/OU=GT07882699/OU=See+20www.rapidssl.com/resources/cps+20+28c+2915/OU=Domain+20Control+20Validated+20-+20RapidSSL+28R+29/CN=*.allbsd.org", Issuer "/C=US/O=GeoTrust+20Inc./CN=RapidSSL+20SHA256+20CA+20-+20G3"); Tue, 20 Dec 2016 04:39:34 +0900 (JST) (envelope-from hrs@FreeBSD.org) Received: from alph.allbsd.org (alph.allbsd.org [192.168.0.10]) by mail-d.allbsd.org (8.15.2/8.15.2) with ESMTPS id uBJJbxEg049627 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Tue, 20 Dec 2016 04:37:59 +0900 (JST) (envelope-from hrs@FreeBSD.org) Received: from localhost (localhost [IPv6:::1]) (authenticated bits=0) by alph.allbsd.org (8.15.2/8.15.2) with ESMTPA id uBJJbuSp049616; Tue, 20 Dec 2016 04:37:59 +0900 (JST) (envelope-from hrs@FreeBSD.org) Date: Tue, 20 Dec 2016 04:36:46 +0900 (JST) Message-Id: <20161220.043646.1181938468712455328.hrs@allbsd.org> To: freebsd-arch@FreeBSD.org, freebsd-current@FreeBSD.org Reply-To: freebsd-arch@FreeBSD.org Subject: RFC: DTrace probes for debugging or testing in userland programs From: Hiroki Sato X-PGPkey-fingerprint: BDB3 443F A5DD B3D0 A530 FFD7 4F2C D3D8 2793 CF2D X-Mailer: Mew version 6.7 on Emacs 25.1 / Mule 6.0 (HANACHIRUSATO) Mime-Version: 1.0 Content-Type: Multipart/Signed; protocol="application/pgp-signature"; micalg=pgp-sha1; boundary="--Security_Multipart(Tue_Dec_20_04_36_46_2016_787)--" Content-Transfer-Encoding: 7bit X-Virus-Scanned: clamav-milter 0.99 at gatekeeper.allbsd.org X-Virus-Status: Clean X-Greylist: Sender DNS name whitelisted, not delayed by milter-greylist-4.4.3 (mail.allbsd.org [133.31.130.32]); Tue, 20 Dec 2016 04:39:35 +0900 (JST) X-Spam-Status: No, score=-99.4 required=13.0 tests=CONTENT_TYPE_PRESENT, FAKEDWORD_BACKQUOTE,QENCPTR1,USER_IN_WHITELIST autolearn=no autolearn_force=no version=3.4.1 X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on gatekeeper.allbsd.org X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 19 Dec 2016 19:39:39 -0000 ----Security_Multipart(Tue_Dec_20_04_36_46_2016_787)-- Content-Type: Text/Plain; charset=us-ascii Content-Transfer-Encoding: 7bit Hi, I am trying to rewrite userland programs (especially daemons) to support userland DTrace probes to make it possible to trace the behavior by using dtrace(1). The purpose is to provide a consistent interface to enable/collect debug log and show internal states. A lot of daemons define their own debug output function like dprintf() and there is no consistency of where to be recorded. I would like your comment about this change because I want to know whether this change (or direction) is acceptable or not. I put an example by using syslogd at the following URL: (diff) https://people.freebsd.org/~hrs/syslogd_usdt.20161220-1.diff (tarball) https://people.freebsd.org/~hrs/syslogd_usdt.20161220-1.tar.gz You can try to compile a new syslogd, run it, and then attach dtrace(1) to the syslogd process by "dtrace -q -CI./ -s ./syslogd_trace.d -p `pgrep syslogd`" in the same directory. Basically this change is invisible for normal users. This includes some rough edges but I think it is sufficient to understand the concept. I do not intend to commit this soon. Questions from me are the following: 1. Where should foo_probes.d and foo_trace.d be installed? And if they depend on foo.h, where should foo.h be? 2. Is documenting probes into foo.8 reasonable? The details are as follows. * Rewrite example This rewrite is twofold. First, simply replace a call of the logging function into DTrace USDT like this: (old) | dprintf("an error occurred, errno=%d\n", errno); (new) | FOO_LOG(LOG_ERR, "an error occurred, errno=%d\n", errno); And then if it involves a result of a specific operation, replace trace probes for the simple logging with dedicated ones: (old) | error = bind(s, res->ai_addr, res->ar_addrlen); | if (error) { | dprintf("bind failed, errno=%d\n", errno); | close(s); | return (-1); | } (new) | error = bind(s, res->ai_addr, res->ar_addrlen); | if (error) { | FOO_SOCK_BIND_FAILED(errno, s, res->ai_addr, res->ar_addrlen); | close(s); | return (-1); | } | FOO_SOCK_BIND_SUCCESS(s, res->ai_addr, res->ar_addrlen); and implement the functionality of the original log message in D script: | foo$target:::sock-bind-failed | { | printf("bind failed, errno=%d", arg0); | /* The other argN can be used to report in more detail. */ | } * Additional files in the existing directory layout After this rewrite, the directory layout for a daemon "foo" will look like the following: | Makefile | foo.8 | foo.c | foo.h | foo_probes.d | foo_trace.d foo_probes.d and foo_trace.d are added. The former is the definition of USDT probes, and the latter is a D script example to reproduce the original debug log by dprintf() or something like that. A section to describe what probes are available is added into foo.8. One can trace the foo daemon using "dtrace -Cs foo_trace.d -p `pgrep foo`" on runtime, and also can create own script. foo.h may be added because foo_probes.d and foo_trace.d often require information of data structure used in foo.c. * Possible incompatible change A debug flag to activate additional logging is no longer necessary after this rewrite, so we can remove it (-d flag in the case of syslogd). And dump of the internal state can be implemented as a SIGINFO handler. In the syslogd example, SIGINFO dumps syslogd configuration and access control list. -- Hiroki ----Security_Multipart(Tue_Dec_20_04_36_46_2016_787)-- Content-Type: application/pgp-signature Content-Transfer-Encoding: 7bit -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 iEYEABECAAYFAlhYNs4ACgkQTyzT2CeTzy3utQCfRQ7RboCA4kENZfoHYr7xdiYL HNAAoJJC1PpDrIS27+quyzUKD9FdwIDO =OeQe -----END PGP SIGNATURE----- ----Security_Multipart(Tue_Dec_20_04_36_46_2016_787)----