From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([140.186.70.92]:48244) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1RDKyt-0005bh-8d for qemu-devel@nongnu.org; Mon, 10 Oct 2011 14:53:44 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1RDKyn-0005tJ-SS for qemu-devel@nongnu.org; Mon, 10 Oct 2011 14:53:43 -0400 Received: from mail-vx0-f173.google.com ([209.85.220.173]:53702) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1RDKyn-0005si-Ll for qemu-devel@nongnu.org; Mon, 10 Oct 2011 14:53:37 -0400 Received: by vcbfl10 with SMTP id fl10so5780430vcb.4 for ; Mon, 10 Oct 2011 11:53:36 -0700 (PDT) Message-ID: <4E933F2D.7090703@codemonkey.ws> Date: Mon, 10 Oct 2011 13:53:33 -0500 From: Anthony Liguori MIME-Version: 1.0 References: <20111010170803.GV9408@redhat.com> In-Reply-To: <20111010170803.GV9408@redhat.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] Hack integrating SeaBios / LinuxBoot option rom with QEMU trace backends List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: "Daniel P. Berrange" Cc: seabios@seabios.org, qemu-devel , Gleb Natapov , Alexander Graf On 10/10/2011 12:08 PM, Daniel P. Berrange wrote: > I've been investigating where time disappears to when booting Linux guests. > > Initially I enabled DEBUG_BIOS in QEMU's hw/pc.c, and then hacked it so > that it could print a timestamp before each new line of debug output. The > problem with that is that it slowed down startup, so the timings I was > examining all changed. > > What I really wanted was to use QEMU's trace infrastructure with a simple > SystemTAP script. This is easy enough in the QEMU layer, but I also need > to see where time goes to inside the various BIOS functions, and the > options ROMs such as LinuxBoot. So I came up with a small hack to insert > "probes" into SeaBios and LinuxBoot, which trigger a special IO port > (0x404), which then cause QEMU to emit a trace event. > > The implementation is really very crude and does not allow any arguments > to be passed each probes, but since all I care about is timing information, > it is good enough for my needs. > > I'm not really expecting these patches to be merged into QEMU/SeaBios > since they're just a crude hack& I don't have time to write something > better. I figure they might be useful for someone else though... > > With the attached patches applied to QEMU and SeaBios, the attached > systemtap script can be used to debug timings in QEMU startup. > > For example, one execution of QEMU produced the following log: > > $ stap qemu-timing.stp > 0.000 Start > 0.036 Run > 0.038 BIOS post > 0.180 BIOS int 19 > 0.181 BIOS boot OS > 0.181 LinuxBoot copy kernel > 1.371 LinuxBoot copy initrd Yeah, there was a thread a bit ago about the performance of the interface to read the kernel/initrd. I think at it was using single byte access instructions and there were patches to use string accessors instead? I can't remember where that threaded ended up. CC'ing Gleb and Alex who may recall more. Regards, Anthony Liguori > 1.616 LinuxBoot boot OS > 2.489 Shutdown request > 2.490 Stop > > showing that LinuxBoot is responsible for by far the most execution > time (~1500ms), in my test which runs for 2500ms in total. > > Regards, > Daniel