From 5b03f23e01dfeb68846fcd280ba6ee9d4dd6113a Mon Sep 17 00:00:00 2001 From: "Richard W.M. Jones" Date: Tue, 3 May 2016 11:53:57 +0100 Subject: [PATCH] utils: Move tests/qemu/ boot-analysis etc tools to new utils top level directory. Create a new top level directory called 'utils' and move the following programs there: tests/qemu/boot-analysis -> utils/boot-analysis/ tests/qemu/boot-benchmark -> utils/boot-benchmark/ tests/qemu/qemu-boot -> utils/qemu-boot/ tests/qemu/qemu-speed-test -> utils/qemu-speed-test/ Also we only build the boot-analysis program on x86-64 and aarch64, since it requires custom porting to each architecture. (cherry picked from commit 3b581a727c9e906f9d9b10e2f73ed853ab324fd0) --- .gitignore | 8 +- Makefile.am | 9 + configure.ac | 10 +- docs/guestfs-hacking.pod | 4 + docs/guestfs-performance.pod | 30 +- m4/guestfs_misc.m4 | 28 + po/POTFILES | 7 + tests/qemu/Makefile.am | 87 +- tests/qemu/boot-analysis-timeline.c | 523 ----------- tests/qemu/boot-analysis-utils.c | 90 -- tests/qemu/boot-analysis-utils.h | 36 - tests/qemu/boot-analysis.c | 1269 -------------------------- tests/qemu/boot-analysis.h | 102 --- tests/qemu/boot-benchmark-range.pl | 240 ----- tests/qemu/boot-benchmark.c | 225 ----- tests/qemu/qemu-boot.c | 362 -------- tests/qemu/qemu-speed-test.c | 480 ---------- utils/boot-analysis/Makefile.am | 43 + utils/boot-analysis/boot-analysis-timeline.c | 523 +++++++++++ utils/boot-analysis/boot-analysis-utils.c | 90 ++ utils/boot-analysis/boot-analysis-utils.h | 36 + utils/boot-analysis/boot-analysis.c | 1268 +++++++++++++++++++++++++ utils/boot-analysis/boot-analysis.h | 102 +++ utils/boot-benchmark/Makefile.am | 44 + utils/boot-benchmark/boot-benchmark-range.pl | 240 +++++ utils/boot-benchmark/boot-benchmark.c | 225 +++++ utils/qemu-boot/Makefile.am | 39 + utils/qemu-boot/qemu-boot.c | 362 ++++++++ utils/qemu-speed-test/Makefile.am | 36 + utils/qemu-speed-test/qemu-speed-test.c | 480 ++++++++++ 30 files changed, 3562 insertions(+), 3436 deletions(-) create mode 100644 m4/guestfs_misc.m4 delete mode 100644 tests/qemu/boot-analysis-timeline.c delete mode 100644 tests/qemu/boot-analysis-utils.c delete mode 100644 tests/qemu/boot-analysis-utils.h delete mode 100644 tests/qemu/boot-analysis.c delete mode 100644 tests/qemu/boot-analysis.h delete mode 100755 tests/qemu/boot-benchmark-range.pl delete mode 100644 tests/qemu/boot-benchmark.c delete mode 100644 tests/qemu/qemu-boot.c delete mode 100644 tests/qemu/qemu-speed-test.c create mode 100644 utils/boot-analysis/Makefile.am create mode 100644 utils/boot-analysis/boot-analysis-timeline.c create mode 100644 utils/boot-analysis/boot-analysis-utils.c create mode 100644 utils/boot-analysis/boot-analysis-utils.h create mode 100644 utils/boot-analysis/boot-analysis.c create mode 100644 utils/boot-analysis/boot-analysis.h create mode 100644 utils/boot-benchmark/Makefile.am create mode 100755 utils/boot-benchmark/boot-benchmark-range.pl create mode 100644 utils/boot-benchmark/boot-benchmark.c create mode 100644 utils/qemu-boot/Makefile.am create mode 100644 utils/qemu-boot/qemu-boot.c create mode 100644 utils/qemu-speed-test/Makefile.am create mode 100644 utils/qemu-speed-test/qemu-speed-test.c diff --git a/.gitignore b/.gitignore index 46a6e65..d79dc98 100644 --- a/.gitignore +++ b/.gitignore @@ -509,10 +509,6 @@ Makefile.in /tests/mountable/test-internal-parse-mountable /tests/parallel/test-parallel /tests/protocol/test-error-messages -/tests/qemu/boot-analysis -/tests/qemu/boot-benchmark -/tests/qemu/qemu-boot -/tests/qemu/qemu-speed-test /tests/regressions/rhbz501893 /tests/regressions/rhbz790721 /tests/regressions/rhbz914931 @@ -561,6 +557,10 @@ Makefile.in /test-tool/stamp-libguestfs-test-tool.pod /tools/stamp-virt-*.pod /tools/virt-*.1 +/utils/boot-analysis/boot-analysis +/utils/boot-benchmark/boot-benchmark +/utils/qemu-boot/qemu-boot +/utils/qemu-speed-test/qemu-speed-test /v2v/.depend /v2v/centos-6.img /v2v/centos-7.0.img diff --git a/Makefile.am b/Makefile.am index c77fc34..079aa7d 100644 --- a/Makefile.am +++ b/Makefile.am @@ -165,6 +165,15 @@ if HAVE_FUSE SUBDIRS += fuse endif +# Miscellaneous utilities. +if HAVE_BOOT_ANALYSIS +SUBDIRS += utils/boot-analysis +endif +SUBDIRS += \ + utils/boot-benchmark \ + utils/qemu-boot \ + utils/qemu-speed-test + # po-docs must come after tools, inspector. if HAVE_PO4A SUBDIRS += po-docs diff --git a/configure.ac b/configure.ac index 6cef0a7..0bff74f 100644 --- a/configure.ac +++ b/configure.ac @@ -124,10 +124,8 @@ m4_include([m4/guestfs_gobject.m4]) dnl Bash completion. m4_include([m4/guestfs_bash_completion.m4]) -dnl Replace libtool with a wrapper that clobbers dependency_libs in *.la files -dnl http://lists.fedoraproject.org/pipermail/devel/2010-November/146343.html -LIBTOOL='bash $(top_srcdir)/libtool-kill-dependency_libs.sh $(top_builddir)/libtool' -AC_SUBST([LIBTOOL]) +dnl Miscellaneous configuration that doesn't fit anywhere else. +m4_include([m4/guestfs_misc.m4]) dnl Work around autoconf's lack of expanded variables. eval my_sysconfdir="\"[$]sysconfdir\"" @@ -283,6 +281,10 @@ AC_CONFIG_FILES([Makefile tests/xfs/Makefile tests/xml/Makefile tools/Makefile + utils/boot-analysis/Makefile + utils/boot-benchmark/Makefile + utils/qemu-boot/Makefile + utils/qemu-speed-test/Makefile v2v/Makefile v2v/test-harness/Makefile v2v/test-harness/META diff --git a/docs/guestfs-hacking.pod b/docs/guestfs-hacking.pod index 756c6f2..f2f8207 100644 --- a/docs/guestfs-hacking.pod +++ b/docs/guestfs-hacking.pod @@ -694,6 +694,10 @@ created by another. Command line tools written in Perl (L and many others). +=item F + +Miscellaneous utilities, such as C. + =item F L command and documentation. diff --git a/docs/guestfs-performance.pod b/docs/guestfs-performance.pod index d9c76ac..7304b63 100644 --- a/docs/guestfs-performance.pod +++ b/docs/guestfs-performance.pod @@ -30,13 +30,13 @@ Run this command several times in a row and discard the first few runs, so that you are measuring a typical "hot cache" case. I If you are compiling libguestfs from -source, there is a program called F which -does the same thing, but performs multiple runs and prints the mean -and standard deviation. To run it, do: +source, there is a program called +F which does the same thing, but +performs multiple runs and prints the mean and standard deviation. To +run it, do: make - make -C tests/qemu boot-benchmark - ./run ./tests/qemu/boot-benchmark + ./run utils/boot-benchmark/boot-benchmark =head3 Explanation @@ -442,17 +442,16 @@ not available. =head2 Boot analysis -In the libguestfs source directory, in F is a program -called C. This program is able to produce a very -detailed breakdown of the boot steps (eg. qemu, BIOS, kernel, +In the libguestfs source directory, in F is a +program called C. This program is able to produce a +very detailed breakdown of the boot steps (eg. qemu, BIOS, kernel, libguestfs init script), and can measure how long it takes to perform each step. To run this program, do: make - make -C tests/qemu boot-analysis - ./run ./tests/qemu/boot-analysis + ./run utils/boot-analysis/boot-analysis =head2 Detailed timings using ts @@ -594,14 +593,15 @@ bit. Sometimes performance regressions happen in other programs (eg. qemu, the kernel) that cause problems for libguestfs. -In the libguestfs source, F is a -script which can be used to benchmark libguestfs across a range of git -commits in another project to find out if any commit is causing a -slowdown (or speedup). +In the libguestfs source, +F is a script which can +be used to benchmark libguestfs across a range of git commits in +another project to find out if any commit is causing a slowdown (or +speedup). To find out how to use this script, consult the manual: - ./tests/qemu/boot-benchmark-range.pl --man + ./utils/boot-benchmark/boot-benchmark-range.pl --man =head1 SEE ALSO diff --git a/m4/guestfs_misc.m4 b/m4/guestfs_misc.m4 new file mode 100644 index 0000000..e6f4b05 --- /dev/null +++ b/m4/guestfs_misc.m4 @@ -0,0 +1,28 @@ +# libguestfs +# Copyright (C) 2009-2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +dnl Miscellaneous configuration that doesn't fit anywhere else. + +dnl Replace libtool with a wrapper that clobbers dependency_libs in *.la files +dnl http://lists.fedoraproject.org/pipermail/devel/2010-November/146343.html +LIBTOOL='bash $(top_srcdir)/libtool-kill-dependency_libs.sh $(top_builddir)/libtool' +AC_SUBST([LIBTOOL]) + +dnl Only build boot-analysis program on x86-64 and aarch64. It +dnl requires custom work to port to each architecture. +AM_CONDITIONAL([HAVE_BOOT_ANALYSIS], + [test "$host_cpu" = "x86_64" || test "$host_cpu" = "aarch64"]) diff --git a/po/POTFILES b/po/POTFILES index a5f3f9e..ebee244 100644 --- a/po/POTFILES +++ b/po/POTFILES @@ -359,6 +359,13 @@ src/utils.c src/wait.c src/whole-file.c test-tool/test-tool.c +utils/boot-analysis/boot-analysis-timeline.c +utils/boot-analysis/boot-analysis-utils.c +utils/boot-analysis/boot-analysis.c +utils/boot-benchmark/boot-benchmark-range.pl +utils/boot-benchmark/boot-benchmark.c +utils/qemu-boot/qemu-boot.c +utils/qemu-speed-test/qemu-speed-test.c v2v/changeuid-c.c v2v/domainxml-c.c v2v/utils-c.c diff --git a/tests/qemu/Makefile.am b/tests/qemu/Makefile.am index f2171cd..472788a 100644 --- a/tests/qemu/Makefile.am +++ b/tests/qemu/Makefile.am @@ -28,92 +28,7 @@ TESTS = \ TESTS_ENVIRONMENT = $(top_builddir)/run --test -EXTRA_DIST = \ - $(TESTS) \ - boot-benchmark-range.pl \ - qemu-boot.c \ - qemu-speed-test.c - -# qemu-boot, qemu-speed-test, boot-analysis and boot-benchmark are -# built but not run by default as they are mainly qemu & kernel -# diagnostic tools. - -check_PROGRAMS = qemu-boot qemu-speed-test boot-analysis boot-benchmark - -qemu_boot_SOURCES = \ - ../../df/estimate-max-threads.c \ - ../../df/estimate-max-threads.h \ - qemu-boot.c -qemu_boot_CPPFLAGS = \ - -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ - -I$(top_srcdir)/src -I$(top_builddir)/src \ - -I$(top_srcdir)/df -qemu_boot_CFLAGS = \ - -pthread \ - $(WARN_CFLAGS) $(WERROR_CFLAGS) -qemu_boot_LDADD = \ - $(top_builddir)/src/libutils.la \ - $(top_builddir)/src/libguestfs.la \ - $(LIBXML2_LIBS) \ - $(LIBVIRT_LIBS) \ - $(LTLIBINTL) \ - $(top_builddir)/gnulib/lib/libgnu.la - -qemu_speed_test_SOURCES = \ - qemu-speed-test.c -qemu_speed_test_CPPFLAGS = \ - -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ - -I$(top_srcdir)/src -I$(top_builddir)/src \ - -I$(top_srcdir)/df -qemu_speed_test_CFLAGS = \ - $(WARN_CFLAGS) $(WERROR_CFLAGS) -qemu_speed_test_LDADD = \ - $(top_builddir)/src/libutils.la \ - $(top_builddir)/src/libguestfs.la \ - $(LIBXML2_LIBS) \ - $(LIBVIRT_LIBS) \ - $(LTLIBINTL) \ - $(top_builddir)/gnulib/lib/libgnu.la - -boot_analysis_SOURCES = \ - boot-analysis.c \ - boot-analysis.h \ - boot-analysis-timeline.c \ - boot-analysis-utils.c \ - boot-analysis-utils.h -boot_analysis_CPPFLAGS = \ - -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ - -I$(top_srcdir)/src -I$(top_builddir)/src -boot_analysis_CFLAGS = \ - -pthread \ - $(WARN_CFLAGS) $(WERROR_CFLAGS) \ - $(PCRE_CFLAGS) -boot_analysis_LDADD = \ - $(top_builddir)/src/libutils.la \ - $(top_builddir)/src/libguestfs.la \ - $(PCRE_LIBS) \ - $(LIBXML2_LIBS) \ - $(LIBVIRT_LIBS) \ - $(LTLIBINTL) \ - $(top_builddir)/gnulib/lib/libgnu.la \ - -lm - -boot_benchmark_SOURCES = \ - boot-benchmark.c \ - boot-analysis-utils.c \ - boot-analysis-utils.h -boot_benchmark_CPPFLAGS = \ - -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ - -I$(top_srcdir)/src -I$(top_builddir)/src -boot_benchmark_CFLAGS = \ - $(WARN_CFLAGS) $(WERROR_CFLAGS) -boot_benchmark_LDADD = \ - $(top_builddir)/src/libutils.la \ - $(top_builddir)/src/libguestfs.la \ - $(LIBXML2_LIBS) \ - $(LTLIBINTL) \ - $(top_builddir)/gnulib/lib/libgnu.la \ - -lm +EXTRA_DIST = $(TESTS) # Don't run these tests in parallel, since they are designed to check # the integrity of qemu. diff --git a/tests/qemu/boot-analysis-timeline.c b/tests/qemu/boot-analysis-timeline.c deleted file mode 100644 index 09a78ef..0000000 --- a/tests/qemu/boot-analysis-timeline.c +++ /dev/null @@ -1,523 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -#include - -#include -#include -#include -#include -#include -#include -#include -#include -#include - -#include - -#include "ignore-value.h" - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" - -#include "boot-analysis.h" - -COMPILE_REGEXP(re_initcall_calling_module, - "calling ([_A-Za-z0-9]+)\\+.*\\[([_A-Za-z0-9]+)]", 0) -COMPILE_REGEXP(re_initcall_calling, - "calling ([_A-Za-z0-9]+)\\+", 0) - -static void construct_initcall_timeline (void); - -/* "supermin: internal insmod xx.ko" -> "insmod xx.ko" */ -static char * -translate_supermin_insmod_message (const char *message) -{ - char *ret; - - assert (STRPREFIX (message, "supermin: internal ")); - - ret = strdup (message + strlen ("supermin: internal ")); - if (ret == NULL) - error (EXIT_FAILURE, errno, "strdup"); - return ret; -} - -/* Analyze significant events from the events array, to form a - * timeline of activities. - */ -void -construct_timeline (void) -{ - size_t i, j, k; - struct pass_data *data; - struct activity *activity; - - for (i = 0; i < NR_TEST_PASSES; ++i) { - data = &pass_data[i]; - - /* Find an activity, by matching an event with the condition - * `begin_cond' through to the second event `end_cond'. Create an - * activity object in the timeline from the result. - */ -#define FIND(name, flags, begin_cond, end_cond) \ - do { \ - activity = NULL; \ - for (j = 0; j < data->nr_events; ++j) { \ - if (begin_cond) { \ - for (k = j+1; k < data->nr_events; ++k) { \ - if (end_cond) { \ - if (i == 0) \ - activity = add_activity (name, flags); \ - else \ - activity = find_activity (name); \ - break; \ - } \ - } \ - break; \ - } \ - } \ - if (activity) { \ - activity->start_event[i] = j; \ - activity->end_event[i] = k; \ - } \ - else \ - error (EXIT_FAILURE, 0, "could not find activity '%s' in pass '%zu'", \ - name, i); \ - } while (0) - - /* Same as FIND() macro, but if no matching events are found, - * ignore it. - */ -#define FIND_OPTIONAL(name, flags, begin_cond, end_cond) \ - do { \ - activity = NULL; \ - for (j = 0; j < data->nr_events; ++j) { \ - if (begin_cond) { \ - for (k = j+1; k < data->nr_events; ++k) { \ - if (end_cond) { \ - if (i == 0) \ - activity = add_activity (name, flags); \ - else \ - activity = find_activity (name); \ - break; \ - } \ - } \ - break; \ - } \ - } \ - if (activity) { \ - activity->start_event[i] = j; \ - activity->end_event[i] = k; \ - } \ - } while (0) - - /* Find multiple entries, where we check for: - * next_cond - * next_cond - * next_cond - * end_cond - */ -#define FIND_MULTIPLE(debug_name, flags, next_cond, end_cond, translate_message) \ - do { \ - activity = NULL; \ - for (j = 0; j < data->nr_events; ++j) { \ - if (next_cond) { \ - CLEANUP_FREE char *message = translate_message (data->events[j].message); \ - if (activity) \ - activity->end_event[i] = j; \ - if (i == 0) \ - activity = add_activity (message, flags); \ - else \ - activity = find_activity (message); \ - activity->start_event[i] = j; \ - } \ - else if (end_cond) \ - break; \ - } \ - if (j < data->nr_events && activity) \ - activity->end_event[i] = j; \ - else \ - error (EXIT_FAILURE, 0, "could not find activity '%s' in pass '%zu'", \ - debug_name, i); \ - } while (0) - - /* Add one activity which is going to cover the whole process - * from launch to close. The launch event is always event 0. - * NB: This activity must be called "run" (see below). - */ - FIND ("run", LONG_ACTIVITY, - j == 0, data->events[k].source == GUESTFS_EVENT_CLOSE); - - /* Find where we invoke supermin --build. This should be a null - * operation, but it still takes time to run the external command. - */ - FIND ("supermin:build", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, - "begin building supermin appliance"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, - "finished building supermin appliance")); - - /* Find where we invoke qemu to test features. */ - FIND_OPTIONAL ("qemu:feature-detect", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, - "begin testing qemu features"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, - "finished testing qemu features")); - - /* Find where we run qemu. */ - FIND_OPTIONAL ("qemu", LONG_ACTIVITY, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "-nodefconfig"), - data->events[k].source == GUESTFS_EVENT_CLOSE); - - /* For the libvirt backend, connecting to libvirt, getting - * capabilities, parsing capabilities etc. - */ - FIND_OPTIONAL ("libvirt:connect", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, "connect to libvirt"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, "successfully opened libvirt handle")); - FIND_OPTIONAL ("libvirt:get-libvirt-capabilities", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, "get libvirt capabilities"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, "parsing capabilities XML")); - - FIND_OPTIONAL ("libguestfs:parse-libvirt-capabilities", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, "parsing capabilities XML"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, "get_backend_setting")); - - FIND_OPTIONAL ("libguestfs:create-libvirt-xml", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, "create libvirt XML"), - data->events[k].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[k].message, "libvirt XML:")); - -#if defined(__aarch64__) -#define FIRST_KERNEL_MESSAGE "Booting Linux on physical CPU" -#define FIRST_FIRMWARE_MESSAGE "UEFI firmware starting" -#else -#define SGABIOS_STRING "\033[1;256r\033[256;256H\033[6n" -#define FIRST_KERNEL_MESSAGE "Probing EDD" -#define FIRST_FIRMWARE_MESSAGE SGABIOS_STRING -#endif - - /* For the libvirt backend, find the overhead of libvirt. */ - FIND_OPTIONAL ("libvirt:overhead", 0, - data->events[j].source == GUESTFS_EVENT_LIBRARY && - strstr (data->events[j].message, "launch libvirt guest"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, FIRST_FIRMWARE_MESSAGE)); - - /* From starting qemu up to entering the BIOS is the qemu overhead. */ - FIND_OPTIONAL ("qemu:overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "-nodefconfig"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, FIRST_FIRMWARE_MESSAGE)); - - /* From entering the BIOS to starting the kernel is the BIOS overhead. */ - FIND_OPTIONAL ("bios:overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, FIRST_FIRMWARE_MESSAGE), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, FIRST_KERNEL_MESSAGE)); - -#if defined(__i386__) || defined(__x86_64__) - /* SGABIOS (option ROM). */ - FIND_OPTIONAL ("sgabios", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, SGABIOS_STRING), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "SeaBIOS (version")); -#endif - -#if defined(__i386__) || defined(__x86_64__) - /* SeaBIOS. */ - FIND ("seabios", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "SeaBIOS (version"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, FIRST_KERNEL_MESSAGE)); -#endif - -#if defined(__i386__) || defined(__x86_64__) - /* SeaBIOS - only available when using debug messages. */ - FIND_OPTIONAL ("seabios:pci-probe", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "Searching bootorder for: /pci@"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "Scan for option roms")); -#endif - - /* Find where we run the guest kernel. */ - FIND ("kernel", LONG_ACTIVITY, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), - data->events[k].source == GUESTFS_EVENT_CLOSE); - - /* Kernel startup to userspace. */ - FIND ("kernel:overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "supermin:") && - strstr (data->events[k].message, "starting up")); - - /* The time taken to get into start_kernel function. */ - FIND ("kernel:entry", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "Linux version")); - -#if defined(__i386__) || defined(__x86_64__) - /* Alternatives patching instructions (XXX not very accurate we - * really need some debug messages inserted into the code). - */ - FIND ("kernel:alternatives", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "Last level dTLB entries"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "Freeing SMP alternatives")); -#endif - - /* ftrace patching instructions. */ - FIND ("kernel:ftrace", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "ftrace: allocating"), - 1); - - /* All initcall functions, before we enter userspace. */ - FIND ("kernel:initcalls-before-userspace", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "calling "), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "Freeing unused kernel memory")); - - /* Find where we run supermin mini-initrd. */ - FIND ("supermin:mini-initrd", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "supermin:") && - strstr (data->events[j].message, "starting up"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "supermin: chroot")); - - /* Loading kernel modules from supermin initrd. */ - FIND_MULTIPLE - ("supermin insmod", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "supermin: internal insmod"), - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "supermin: picked"), - translate_supermin_insmod_message); - - /* Find where we run the /init script. */ - FIND ("/init", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "supermin: chroot"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "guestfsd --verbose")); - - /* Everything from the chroot to the first echo in the /init - * script counts as bash overhead. - */ - FIND ("bash:overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "supermin: chroot"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "Starting /init script")); - - /* /init: Mount special filesystems. */ - FIND ("/init:mount-special", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "*guestfs_boot_analysis=1*"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "kmod static-nodes")); - - /* /init: Run kmod static-nodes */ - FIND ("/init:kmod-static-nodes", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "kmod static-nodes"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "systemd-tmpfiles")); - - /* /init: systemd-tmpfiles. */ - FIND ("/init:systemd-tmpfiles", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "systemd-tmpfiles"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "udev")); - - /* /init: start udevd. */ - FIND ("/init:udev-overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "udevd --daemon"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "nullglob")); - - /* /init: set up network. */ - FIND ("/init:network-overhead", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "+ ip addr"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "+ test")); - - /* /init: probe MD arrays. */ - FIND ("/init:md-probe", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "+ mdadm"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "+ modprobe dm_mod")); - - /* /init: probe DM/LVM. */ - FIND ("/init:lvm-probe", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "+ modprobe dm_mod"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "+ ldmtool")); - - /* /init: probe Windows dynamic disks. */ - FIND ("/init:windows-dynamic-disks-probe", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "+ ldmtool"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "+ test")); - - /* Find where we run guestfsd. */ - FIND ("guestfsd", 0, - data->events[j].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[j].message, "guestfsd --verbose"), - data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, "fsync /dev/sda")); - - /* Shutdown process. */ - FIND ("shutdown", 0, - data->events[j].source == GUESTFS_EVENT_TRACE && - STREQ (data->events[j].message, "close"), - data->events[k].source == GUESTFS_EVENT_CLOSE); - } - - construct_initcall_timeline (); -} - -/* Handling of initcall is so peculiar that we hide it in a separate - * function from the rest. - */ -static void -construct_initcall_timeline (void) -{ - size_t i, j, k; - struct pass_data *data; - struct activity *activity; - - for (i = 0; i < NR_TEST_PASSES; ++i) { - data = &pass_data[i]; - - /* Each kernel initcall is bracketed by: - * - * calling ehci_hcd_init+0x0/0xc1 @ 1" - * initcall ehci_hcd_init+0x0/0xc1 returned 0 after 420 usecs" - * - * For initcall functions in modules: - * - * calling virtio_mmio_init+0x0/0x1000 [virtio_mmio] @ 1" - * initcall virtio_mmio_init+0x0/0x1000 [virtio_mmio] returned 0 after 14 usecs" - * - * Initcall functions can be nested, and do not have unique names. - */ - for (j = 0; j < data->nr_events; ++j) { - int vec[30], r; - const char *message = data->events[j].message; - - if (data->events[j].source == GUESTFS_EVENT_APPLIANCE && - ((r = pcre_exec (re_initcall_calling_module, NULL, - message, strlen (message), - 0, 0, vec, sizeof vec / sizeof vec[0])) >= 1 || - (r = pcre_exec (re_initcall_calling, NULL, - message, strlen (message), - 0, 0, vec, sizeof vec / sizeof vec[0])) >= 1)) { - - CLEANUP_FREE char *fn_name = NULL, *module_name = NULL; - if (r >= 2) /* because pcre_exec returns 1 + number of captures */ - fn_name = strndup (message + vec[2], vec[3]-vec[2]); - if (r >= 3) - module_name = strndup (message + vec[4], vec[5]-vec[4]); - - CLEANUP_FREE char *fullname; - if (asprintf (&fullname, "%s.%s", - module_name ? module_name : "kernel", fn_name) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - - CLEANUP_FREE char *initcall_match; - if (asprintf (&initcall_match, "initcall %s", fn_name) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - - /* Get a unique name for this activity. Unfortunately - * kernel initcall function names are not unique! - */ - CLEANUP_FREE char *activity_name; - if (asprintf (&activity_name, "initcall %s", fullname) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - - if (i == 0) { - int n = 1; - while (activity_exists (activity_name)) { - free (activity_name); - if (asprintf (&activity_name, "initcall %s:%d", fullname, n) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - n++; - } - } - else { - int n = 1; - while (!activity_exists_with_no_data (activity_name, i)) { - free (activity_name); - if (asprintf (&activity_name, "initcall %s:%d", fullname, n) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - n++; - } - } - - /* Find the matching end event. It might be some time later, - * since it appears initcalls can be nested. - */ - for (k = j+1; k < data->nr_events; ++k) { - if (data->events[k].source == GUESTFS_EVENT_APPLIANCE && - strstr (data->events[k].message, initcall_match)) { - if (i == 0) - activity = add_activity (activity_name, 0); - else - activity = find_activity (activity_name); - activity->start_event[i] = j; - activity->end_event[i] = k; - break; - } - } - } - } - } -} diff --git a/tests/qemu/boot-analysis-utils.c b/tests/qemu/boot-analysis-utils.c deleted file mode 100644 index 693b6f4..0000000 --- a/tests/qemu/boot-analysis-utils.c +++ /dev/null @@ -1,90 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -#include - -#include -#include -#include -#include -#include - -#include "ignore-value.h" - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" - -#include "boot-analysis-utils.h" - -void -get_time (struct timespec *ts) -{ - if (clock_gettime (CLOCK_REALTIME, ts) == -1) - error (EXIT_FAILURE, errno, "clock_gettime: CLOCK_REALTIME"); -} - -int64_t -timespec_diff (const struct timespec *x, const struct timespec *y) -{ - int64_t nsec; - - nsec = (y->tv_sec - x->tv_sec) * UINT64_C(1000000000); - nsec += y->tv_nsec - x->tv_nsec; - return nsec; -} - -void -test_info (guestfs_h *g, int nr_test_passes) -{ - const char *qemu = guestfs_get_hv (g); - CLEANUP_FREE char *cmd = NULL; - CLEANUP_FREE char *backend = NULL; - - /* Related to the test program. */ - printf ("test version: %s %s\n", PACKAGE_NAME, PACKAGE_VERSION_FULL); - printf (" test passes: %d\n", nr_test_passes); - - /* Related to the host. */ - printf ("host version: "); - fflush (stdout); - ignore_value (system ("uname -a")); - printf (" host CPU: "); - fflush (stdout); - ignore_value (system ("perl -n -e 'if (/^model name.*: (.*)/) { print \"$1\\n\"; exit }' /proc/cpuinfo")); - - /* Related to qemu. */ - backend = guestfs_get_backend (g); - printf (" backend: %-20s [to change set LIBGUESTFS_BACKEND]\n", - backend); - printf (" qemu: %-20s [to change set $LIBGUESTFS_HV]\n", qemu); - printf ("qemu version: "); - fflush (stdout); - if (asprintf (&cmd, "%s -version", qemu) == -1) - error (EXIT_FAILURE, errno, "asprintf"); - ignore_value (system (cmd)); - printf (" smp: %-20d [to change use --smp option]\n", - guestfs_get_smp (g)); - printf (" memsize: %-20d [to change use --memsize option]\n", - guestfs_get_memsize (g)); - - /* Related to the guest kernel. Be nice to get the guest - * kernel version here somehow (XXX). - */ - printf (" append: %-20s [to change use --append option]\n", - guestfs_get_append (g) ? : ""); -} diff --git a/tests/qemu/boot-analysis-utils.h b/tests/qemu/boot-analysis-utils.h deleted file mode 100644 index 95e4f06..0000000 --- a/tests/qemu/boot-analysis-utils.h +++ /dev/null @@ -1,36 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -#ifndef GUESTFS_BOOT_ANALYSIS_UTILS_H_ -#define GUESTFS_BOOT_ANALYSIS_UTILS_H_ - -/* Get current time, returning it in *ts. If there is a system call - * failure, this exits. - */ -extern void get_time (struct timespec *ts); - -/* Computes Y - X, returning nanoseconds. */ -extern int64_t timespec_diff (const struct timespec *x, const struct timespec *y); - -/* Display host machine and test parameters (to stdout). 'g' should - * be an open libguestfs handle. It is used for reading hv, memsize - * etc. and is not modified. - */ -extern void test_info (guestfs_h *g, int nr_test_passes); - -#endif /* GUESTFS_BOOT_ANALYSIS_UTILS_H_ */ diff --git a/tests/qemu/boot-analysis.c b/tests/qemu/boot-analysis.c deleted file mode 100644 index 2067dfc..0000000 --- a/tests/qemu/boot-analysis.c +++ /dev/null @@ -1,1269 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -/* Trace and analyze the appliance boot process to find out which - * steps are taking the most time. It is not part of the standard - * tests. - * - * This needs to be run on a quiet machine, so that other processes - * disturb the timing as little as possible. The program is - * completely safe to run at any time. It doesn't read or write any - * external files, and it doesn't require root. - * - * You can run it from the build directory like this: - * - * make - * make -C tests/qemu boot-analysis - * ./run tests/qemu/boot-analysis - * - * The way it works is roughly like this: - * - * We create a libguestfs handle and register callback handlers so we - * can see appliance messages, trace events and so on. - * - * We then launch the handle and shut it down as quickly as possible. - * - * While the handle is running, events (seen by the callback handlers) - * are written verbatim into an in-memory buffer, with timestamps. - * - * Afterwards we analyze the result using regular expressions to try - * to identify a "timeline" for the handle (eg. at what time did the - * BIOS hand control to the kernel). This analysis is done in - * 'boot-analysis-timeline.c'. - * - * The whole process is repeated across a few runs, and the final - * timeline (including statistical analysis of the variation between - * runs) gets printed. - * - * The program is very sensitive to the specific messages printed by - * BIOS/kernel/supermin/userspace, so it won't work on non-x86, and it - * will require periodic adjustment of the regular expressions in - * order to keep things up to date. - */ - -#include - -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" - -#include "boot-analysis.h" -#include "boot-analysis-utils.h" - -/* Activities taking longer than this % of the total time, except - * those flagged as LONG_ACTIVITY, are highlighted in red. - */ -#define WARNING_THRESHOLD 1.0 - -static const char *append = NULL; -static int force_colour = 0; -static int memsize = 0; -static int smp = 1; -static int verbose = 0; - -static int libvirt_pipe[2] = { -1, -1 }; -static ssize_t libvirt_pass = -1; - -/* Because there is a separate thread which collects libvirt log data, - * we must protect the pass_data struct with a mutex. This only - * applies during the data collection passes. - */ -static pthread_mutex_t pass_data_lock = PTHREAD_MUTEX_INITIALIZER; -struct pass_data pass_data[NR_TEST_PASSES]; - -size_t nr_activities; -struct activity *activities; - -static void run_test (void); -static struct event *add_event (struct pass_data *, uint64_t source); -static guestfs_h *create_handle (void); -static void set_up_event_handlers (guestfs_h *g, size_t pass); -static void libvirt_log_hack (int argc, char **argv); -static void start_libvirt_thread (size_t pass); -static void stop_libvirt_thread (void); -static void add_drive (guestfs_h *g); -static void check_pass_data (void); -static void dump_pass_data (void); -static void analyze_timeline (void); -static void dump_timeline (void); -static void print_analysis (void); -static void print_longest_to_shortest (void); -static void free_pass_data (void); -static void free_final_timeline (void); -static void ansi_green (void); -static void ansi_red (void); -static void ansi_blue (void); -static void ansi_magenta (void); -static void ansi_restore (void); - -static void -usage (int exitcode) -{ - guestfs_h *g; - int default_memsize = -1; - - g = guestfs_create (); - if (g) { - default_memsize = guestfs_get_memsize (g); - guestfs_close (g); - } - - fprintf (stderr, - "boot-analysis: Trace and analyze the appliance boot process.\n" - "Usage:\n" - " boot-analysis [--options]\n" - "Options:\n" - " --help Display this usage text and exit.\n" - " --append OPTS Append OPTS to kernel command line.\n" - " --colour Output colours, even if not a terminal.\n" - " -m MB\n" - " --memsize MB Set memory size in MB (default: %d).\n" - " --smp N Enable N virtual CPUs (default: 1).\n" - " -v|--verbose Verbose output, useful for debugging.\n", - default_memsize); - exit (exitcode); -} - -int -main (int argc, char *argv[]) -{ - enum { HELP_OPTION = CHAR_MAX + 1 }; - static const char *options = "m:v"; - static const struct option long_options[] = { - { "help", 0, 0, HELP_OPTION }, - { "append", 1, 0, 0 }, - { "color", 0, 0, 0 }, - { "colour", 0, 0, 0 }, - { "memsize", 1, 0, 'm' }, - { "libvirt-pipe-0", 1, 0, 0 }, /* see libvirt_log_hack */ - { "libvirt-pipe-1", 1, 0, 0 }, - { "smp", 1, 0, 0 }, - { "verbose", 0, 0, 'v' }, - { 0, 0, 0, 0 } - }; - int c, option_index; - - for (;;) { - c = getopt_long (argc, argv, options, long_options, &option_index); - if (c == -1) break; - - switch (c) { - case 0: /* Options which are long only. */ - if (STREQ (long_options[option_index].name, "append")) { - append = optarg; - break; - } - else if (STREQ (long_options[option_index].name, "color") || - STREQ (long_options[option_index].name, "colour")) { - force_colour = 1; - break; - } - else if (STREQ (long_options[option_index].name, "libvirt-pipe-0")) { - if (sscanf (optarg, "%d", &libvirt_pipe[0]) != 1) - error (EXIT_FAILURE, 0, - "could not parse libvirt-pipe-0 parameter: %s", optarg); - break; - } - else if (STREQ (long_options[option_index].name, "libvirt-pipe-1")) { - if (sscanf (optarg, "%d", &libvirt_pipe[1]) != 1) - error (EXIT_FAILURE, 0, - "could not parse libvirt-pipe-1 parameter: %s", optarg); - break; - } - else if (STREQ (long_options[option_index].name, "smp")) { - if (sscanf (optarg, "%d", &smp) != 1) - error (EXIT_FAILURE, 0, - "could not parse smp parameter: %s", optarg); - break; - } - fprintf (stderr, "%s: unknown long option: %s (%d)\n", - guestfs_int_program_name, long_options[option_index].name, option_index); - exit (EXIT_FAILURE); - - case 'm': - if (sscanf (optarg, "%d", &memsize) != 1) { - fprintf (stderr, "%s: could not parse memsize parameter: %s\n", - guestfs_int_program_name, optarg); - exit (EXIT_FAILURE); - } - break; - - case 'v': - verbose = 1; - break; - - case HELP_OPTION: - usage (EXIT_SUCCESS); - - default: - usage (EXIT_FAILURE); - } - } - - libvirt_log_hack (argc, argv); - - if (STRNEQ (host_cpu, "x86_64") && STRNEQ (host_cpu, "aarch64")) - fprintf (stderr, "WARNING: host_cpu != x86_64|aarch64: This program may not work or give bogus results.\n"); - - run_test (); -} - -static void -run_test (void) -{ - guestfs_h *g; - size_t i; - - printf ("Warming up the libguestfs cache ...\n"); - for (i = 0; i < NR_WARMUP_PASSES; ++i) { - g = create_handle (); - add_drive (g); - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - guestfs_close (g); - } - - printf ("Running the tests in %d passes ...\n", NR_TEST_PASSES); - for (i = 0; i < NR_TEST_PASSES; ++i) { - g = create_handle (); - set_up_event_handlers (g, i); - start_libvirt_thread (i); - add_drive (g); - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - guestfs_close (g); - stop_libvirt_thread (); - - printf (" pass %zu: %zu events collected in %" PRIi64 " ns\n", - i+1, pass_data[i].nr_events, pass_data[i].elapsed_ns); - } - - if (verbose) - dump_pass_data (); - - printf ("Analyzing the results ...\n"); - check_pass_data (); - construct_timeline (); - analyze_timeline (); - - if (verbose) - dump_timeline (); - - printf ("\n"); - g = create_handle (); - test_info (g, NR_TEST_PASSES); - guestfs_close (g); - printf ("\n"); - print_analysis (); - printf ("\n"); - printf ("Longest activities:\n"); - printf ("\n"); - print_longest_to_shortest (); - - free_pass_data (); - free_final_timeline (); -} - -static struct event * -add_event_unlocked (struct pass_data *data, uint64_t source) -{ - struct event *ret; - - data->nr_events++; - data->events = realloc (data->events, - sizeof (struct event) * data->nr_events); - if (data->events == NULL) - error (EXIT_FAILURE, errno, "realloc"); - ret = &data->events[data->nr_events-1]; - get_time (&ret->t); - ret->source = source; - ret->message = NULL; - return ret; -} - -static struct event * -add_event (struct pass_data *data, uint64_t source) -{ - struct event *ret; - - pthread_mutex_lock (&pass_data_lock); - ret = add_event_unlocked (data, source); - pthread_mutex_unlock (&pass_data_lock); - return ret; -} - -/* Common function to create the handle and set various defaults. */ -static guestfs_h * -create_handle (void) -{ - guestfs_h *g; - CLEANUP_FREE char *full_append = NULL; - - g = guestfs_create (); - if (!g) error (EXIT_FAILURE, errno, "guestfs_create"); - - if (memsize != 0) - if (guestfs_set_memsize (g, memsize) == -1) - exit (EXIT_FAILURE); - - if (smp >= 2) - if (guestfs_set_smp (g, smp) == -1) - exit (EXIT_FAILURE); - - /* This changes some details in appliance/init and enables a - * detailed trace of calls to initcall functions in the kernel. - */ - if (asprintf (&full_append, - "guestfs_boot_analysis=1 " - "ignore_loglevel initcall_debug " - "%s", - append != NULL ? append : "") == -1) - error (EXIT_FAILURE, errno, "asprintf"); - - if (guestfs_set_append (g, full_append) == -1) - exit (EXIT_FAILURE); - - return g; -} - -/* Common function to add the /dev/null drive. */ -static void -add_drive (guestfs_h *g) -{ - if (guestfs_add_drive_opts (g, "/dev/null", - GUESTFS_ADD_DRIVE_OPTS_FORMAT, "raw", - GUESTFS_ADD_DRIVE_OPTS_READONLY, 1, - -1) == -1) - exit (EXIT_FAILURE); -} - -/* Called when the handle is closed. Perform any cleanups required in - * the pass_data here. - */ -static void -close_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - - if (!data->seen_launch) - return; - - event = add_event (data, source); - event->message = strdup ("close callback"); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strdup"); - - get_time (&data->end_t); - data->elapsed_ns = timespec_diff (&data->start_t, &data->end_t); -} - -/* Called when the qemu subprocess exits. - * XXX This is never called - why? - */ -static void -subprocess_quit_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - - if (!data->seen_launch) - return; - - event = add_event (data, source); - event->message = strdup ("subprocess quit callback"); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strdup"); -} - -/* Called when the launch operation is complete (the library and the - * guestfs daemon and talking to each other). - */ -static void -launch_done_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - - if (!data->seen_launch) - return; - - event = add_event (data, source); - event->message = strdup ("launch done callback"); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strdup"); -} - -/* Trim \r (multiple) from the end of a string. */ -static void -trim_r (char *message) -{ - size_t len = strlen (message); - - while (len > 0 && message[len-1] == '\r') { - message[len-1] = '\0'; - len--; - } -} - -/* Called when we get (possibly part of) a log message (or more than - * one log message) from the appliance (which may include qemu, the - * BIOS, kernel, etc). - */ -static void -appliance_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - size_t i, len, slen; - - if (!data->seen_launch) - return; - - /* If the previous log message was incomplete, but time has moved on - * a lot, record a new log message anyway, so it gets a new - * timestamp. - */ - if (data->incomplete_log_message >= 0) { - struct timespec ts; - get_time (&ts); - if (timespec_diff (&data->events[data->incomplete_log_message].t, - &ts) >= 10000000 /* 10ms */) - data->incomplete_log_message = -1; - } - - /* If the previous log message was incomplete then we may need to - * append part of the current log message to a previous one. - */ - if (data->incomplete_log_message >= 0) { - len = buf_len; - for (i = 0; i < buf_len; ++i) { - if (buf[i] == '\n') { - len = i; - break; - } - } - - event = &data->events[data->incomplete_log_message]; - slen = strlen (event->message); - event->message = realloc (event->message, slen + len + 1); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "realloc"); - memcpy (event->message + slen, buf, len); - event->message[slen + len] = '\0'; - trim_r (event->message); - - /* Skip what we just added to the previous incomplete message. */ - buf += len; - buf_len -= len; - - if (buf_len == 0) /* still not complete, more to come! */ - return; - - /* Skip the \n in the buffer. */ - buf++; - buf_len--; - data->incomplete_log_message = -1; - } - - /* Add the event, or perhaps multiple events if the message - * contains \n characters. - */ - while (buf_len > 0) { - len = buf_len; - for (i = 0; i < buf_len; ++i) { - if (buf[i] == '\n') { - len = i; - break; - } - } - - event = add_event (data, source); - event->message = strndup (buf, len); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strndup"); - trim_r (event->message); - - /* Skip what we just added to the event. */ - buf += len; - buf_len -= len; - - if (buf_len == 0) { - /* Event is incomplete (doesn't end with \n). We'll finish it - * in the next callback. - */ - data->incomplete_log_message = event - data->events; - return; - } - - /* Skip the \n in the buffer. */ - buf++; - buf_len--; - } -} - -/* Called when we get a debug message from the library side. These - * are always delivered as complete messages. - */ -static void -library_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - - if (!data->seen_launch) - return; - - event = add_event (data, source); - event->message = strndup (buf, buf_len); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strndup"); -} - -/* Called when we get a call trace message (a libguestfs API function - * has been called or is returning). These are always delivered as - * complete messages. - */ -static void -trace_callback (guestfs_h *g, void *datavp, uint64_t source, - int eh, int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - struct pass_data *data = datavp; - struct event *event; - char *message; - - message = strndup (buf, buf_len); - if (message == NULL) - error (EXIT_FAILURE, errno, "strndup"); - - if (STREQ (message, "launch")) - data->seen_launch = 1; - - if (!data->seen_launch) { - free (message); - return; - } - - event = add_event (data, source); - event->message = message; -} - -/* Common function to set up event callbacks and record data in memory - * for a particular pass (0 <= pass < NR_TEST_PASSES). - */ -static void -set_up_event_handlers (guestfs_h *g, size_t pass) -{ - struct pass_data *data; - - assert (/* 0 <= pass && */ pass < NR_TEST_PASSES); - - data = &pass_data[pass]; - data->pass = pass; - data->nr_events = 0; - data->events = NULL; - get_time (&data->start_t); - data->incomplete_log_message = -1; - data->seen_launch = 0; - - guestfs_set_event_callback (g, close_callback, - GUESTFS_EVENT_CLOSE, 0, data); - guestfs_set_event_callback (g, subprocess_quit_callback, - GUESTFS_EVENT_SUBPROCESS_QUIT, 0, data); - guestfs_set_event_callback (g, launch_done_callback, - GUESTFS_EVENT_LAUNCH_DONE, 0, data); - guestfs_set_event_callback (g, appliance_callback, - GUESTFS_EVENT_APPLIANCE, 0, data); - guestfs_set_event_callback (g, library_callback, - GUESTFS_EVENT_LIBRARY, 0, data); - guestfs_set_event_callback (g, trace_callback, - GUESTFS_EVENT_TRACE, 0, data); - - guestfs_set_verbose (g, 1); - guestfs_set_trace (g, 1); -} - -/* libvirt debugging sucks in a number of concrete ways: - * - * - you can't get a synchronous callback from a log message - * - you can't enable logging per handle (only globally - * by setting environment variables) - * - you can't debug the daemon easily - * - it's very complex - * - it's very complex but not in ways that are practical or useful - * - * To get log messages at all, we need to create a pipe connected to a - * second thread, and when libvirt prints something to the pipe we log - * that. - * - * However that's not sufficient. Because logging is only enabled - * when libvirt examines environment variables at the start of the - * program, we need to create the pipe and then fork+exec a new - * instance of the whole program with the pipe and environment - * variables set up. - */ -static int is_libvirt_backend (guestfs_h *g); -static void *libvirt_log_thread (void *datavp); - -static void -libvirt_log_hack (int argc, char **argv) -{ - guestfs_h *g; - - g = guestfs_create (); - if (!is_libvirt_backend (g)) { - guestfs_close (g); - return; - } - guestfs_close (g); - - /* Have we set up the pipes and environment and forked yet? If not, - * do that first. - */ - if (libvirt_pipe[0] == -1 || libvirt_pipe[1] == -1) { - char log_outputs[64]; - char **new_argv; - char param1[64], param2[64]; - size_t i; - pid_t pid; - int status; - - /* Create the pipe. NB: do NOT use O_CLOEXEC since we want to pass - * this pipe into a child process. - */ - if (pipe (libvirt_pipe) == -1) - error (EXIT_FAILURE, 0, "pipe2"); - - /* Create the environment variables to enable logging in libvirt. */ - setenv ("LIBVIRT_DEBUG", "1", 1); - //setenv ("LIBVIRT_LOG_FILTERS", - // "1:qemu 1:securit 3:file 3:event 3:object 1:util", 1); - snprintf (log_outputs, sizeof log_outputs, - "1:file:/dev/fd/%d", libvirt_pipe[1]); - setenv ("LIBVIRT_LOG_OUTPUTS", log_outputs, 1); - - /* Run self again. */ - new_argv = malloc ((argc+3) * sizeof (char *)); - if (new_argv == NULL) - error (EXIT_FAILURE, errno, "malloc"); - - for (i = 0; i < (size_t) argc; ++i) - new_argv[i] = argv[i]; - - snprintf (param1, sizeof param1, "--libvirt-pipe-0=%d", libvirt_pipe[0]); - new_argv[argc] = param1; - snprintf (param2, sizeof param2, "--libvirt-pipe-1=%d", libvirt_pipe[1]); - new_argv[argc+1] = param2; - new_argv[argc+2] = NULL; - - pid = fork (); - if (pid == -1) - error (EXIT_FAILURE, errno, "fork"); - if (pid == 0) { /* Child process. */ - execvp (argv[0], new_argv); - perror ("execvp"); - _exit (EXIT_FAILURE); - } - - if (waitpid (pid, &status, 0) == -1) - error (EXIT_FAILURE, errno, "waitpid"); - if (WIFEXITED (status)) - exit (WEXITSTATUS (status)); - error (EXIT_FAILURE, 0, "unexpected exit status from process: %d", status); - } - - /* If we reach this else clause, then we have forked. Now we must - * create a thread to read events from the pipe. This must be - * constantly reading from the pipe, otherwise we will deadlock. - * During the warm-up phase we end up throwing away messages. - */ - else { - pthread_t thread; - pthread_attr_t attr; - int r; - - r = pthread_attr_init (&attr); - if (r != 0) - error (EXIT_FAILURE, r, "pthread_attr_init"); - r = pthread_attr_setdetachstate (&attr, PTHREAD_CREATE_DETACHED); - if (r != 0) - error (EXIT_FAILURE, r, "pthread_attr_setdetachstate"); - r = pthread_create (&thread, &attr, libvirt_log_thread, NULL); - if (r != 0) - error (EXIT_FAILURE, r, "pthread_create"); - pthread_attr_destroy (&attr); - } -} - -static void -start_libvirt_thread (size_t pass) -{ - /* In the non-libvirt case, this variable is ignored. */ - pthread_mutex_lock (&pass_data_lock); - libvirt_pass = pass; - pthread_mutex_unlock (&pass_data_lock); -} - -static void -stop_libvirt_thread (void) -{ - /* In the non-libvirt case, this variable is ignored. */ - pthread_mutex_lock (&pass_data_lock); - libvirt_pass = -1; - pthread_mutex_unlock (&pass_data_lock); -} - -/* The separate "libvirt thread". It loops reading debug messages - * printed by libvirt and adds them to the pass_data. - */ -static void * -libvirt_log_thread (void *arg) -{ - struct event *event; - CLEANUP_FREE char *buf = NULL; - ssize_t r; - - buf = malloc (BUFSIZ); - if (buf == NULL) - error (EXIT_FAILURE, errno, "malloc"); - - while ((r = read (libvirt_pipe[0], buf, BUFSIZ)) > 0) { - pthread_mutex_lock (&pass_data_lock); - if (libvirt_pass == -1) goto discard; - event = - add_event_unlocked (&pass_data[libvirt_pass], SOURCE_LIBVIRT); - event->message = strndup (buf, r); - if (event->message == NULL) - error (EXIT_FAILURE, errno, "strndup"); - discard: - pthread_mutex_unlock (&pass_data_lock); - } - - if (r == -1) - error (EXIT_FAILURE, errno, "libvirt_log_thread: read"); - - /* It's possible for the pipe to be closed (r == 0) if thread - * cancellation is delayed after the main thread exits, so just - * ignore that case and exit. - */ - pthread_exit (NULL); -} - -static int -is_libvirt_backend (guestfs_h *g) -{ - CLEANUP_FREE char *backend = guestfs_get_backend (g); - - return backend && - (STREQ (backend, "libvirt") || STRPREFIX (backend, "libvirt:")); -} - -/* Sanity check the collected events. */ -static void -check_pass_data (void) -{ - size_t i, j, len; - int64_t ns; - const char *message; - - for (i = 0; i < NR_TEST_PASSES; ++i) { - assert (pass_data[i].pass == i); - assert (pass_data[i].elapsed_ns > 1000); - assert (pass_data[i].nr_events > 0); - assert (pass_data[i].events != NULL); - - for (j = 0; j < pass_data[i].nr_events; ++j) { - assert (pass_data[i].events[j].t.tv_sec > 0); - if (j > 0) { - ns = timespec_diff (&pass_data[i].events[j-1].t, - &pass_data[i].events[j].t); - assert (ns >= 0); - } - assert (pass_data[i].events[j].source != 0); - message = pass_data[i].events[j].message; - assert (message != NULL); - assert (pass_data[i].events[j].source != GUESTFS_EVENT_APPLIANCE || - strchr (message, '\n') == NULL); - len = strlen (message); - assert (len == 0 || message[len-1] != '\r'); - } - } -} - -static void -print_escaped_string (const char *message) -{ - while (*message) { - if (isprint (*message)) - putchar (*message); - else - printf ("\\x%02x", (unsigned int) *message); - message++; - } -} - -/* Dump the events to stdout, if verbose is set. */ -static void -dump_pass_data (void) -{ - size_t i, j; - - for (i = 0; i < NR_TEST_PASSES; ++i) { - printf ("pass %zu\n", pass_data[i].pass); - printf (" number of events collected %zu\n", pass_data[i].nr_events); - printf (" elapsed time %" PRIi64 " ns\n", pass_data[i].elapsed_ns); - for (j = 0; j < pass_data[i].nr_events; ++j) { - int64_t ns, diff_ns; - CLEANUP_FREE char *source_str = NULL; - - ns = timespec_diff (&pass_data[i].start_t, &pass_data[i].events[j].t); - source_str = source_to_string (pass_data[i].events[j].source); - printf (" %.1fms ", ns / 1000000.0); - if (j > 0) { - diff_ns = timespec_diff (&pass_data[i].events[j-1].t, - &pass_data[i].events[j].t); - printf ("(+%.1f) ", diff_ns / 1000000.0); - } - printf ("[%s] \"", source_str); - print_escaped_string (pass_data[i].events[j].message); - printf ("\"\n"); - } - } -} - -/* Convert source to a printable string. The caller must free the - * returned string. - */ -char * -source_to_string (uint64_t source) -{ - char *ret; - - if (source == SOURCE_LIBVIRT) { - ret = strdup ("libvirt"); - if (ret == NULL) - error (EXIT_FAILURE, errno, "strdup"); - } - else - ret = guestfs_event_to_string (source); - - return ret; /* caller frees */ -} - -int -activity_exists (const char *name) -{ - size_t i; - - for (i = 0; i < nr_activities; ++i) - if (STREQ (activities[i].name, name)) - return 1; - return 0; -} - -/* Add an activity to the global list. */ -struct activity * -add_activity (const char *name, int flags) -{ - struct activity *ret; - size_t i; - - /* You shouldn't have two activities with the same name. */ - assert (!activity_exists (name)); - - nr_activities++; - activities = realloc (activities, sizeof (struct activity) * nr_activities); - if (activities == NULL) - error (EXIT_FAILURE, errno, "realloc"); - ret = &activities[nr_activities-1]; - ret->name = strdup (name); - if (ret->name == NULL) - error (EXIT_FAILURE, errno, "strdup"); - ret->flags = flags; - - for (i = 0; i < NR_TEST_PASSES; ++i) - ret->start_event[i] = ret->end_event[i] = 0; - - return ret; -} - -struct activity * -find_activity (const char *name) -{ - size_t i; - - for (i = 0; i < nr_activities; ++i) - if (STREQ (activities[i].name, name)) - return &activities[i]; - error (EXIT_FAILURE, 0, - "internal error: could not find activity '%s'", name); - /*NOTREACHED*/ - abort (); -} - -int -activity_exists_with_no_data (const char *name, size_t pass) -{ - size_t i; - - for (i = 0; i < nr_activities; ++i) - if (STREQ (activities[i].name, name) && - activities[i].start_event[pass] == 0 && - activities[i].end_event[pass] == 0) - return 1; - return 0; -} - -static int -compare_activities_by_t (const void *av, const void *bv) -{ - const struct activity *a = av; - const struct activity *b = bv; - - return a->t - b->t; -} - -/* Go through the activities, computing the start and elapsed time. */ -static void -analyze_timeline (void) -{ - struct activity *activity; - size_t i, j; - int64_t delta_ns; - - for (j = 0; j < nr_activities; ++j) { - activity = &activities[j]; - - activity->t = 0; - activity->mean = 0; - for (i = 0; i < NR_TEST_PASSES; ++i) { - delta_ns = - timespec_diff (&pass_data[i].events[0].t, - &pass_data[i].events[activity->start_event[i]].t); - activity->t += delta_ns; - - delta_ns = - timespec_diff (&pass_data[i].events[activity->start_event[i]].t, - &pass_data[i].events[activity->end_event[i]].t); - activity->mean += delta_ns; - } - - /* Divide through to get real start time and mean of each activity. */ - activity->t /= NR_TEST_PASSES; - activity->mean /= NR_TEST_PASSES; - - /* Calculate the end time of this activity. It's convenient when - * drawing the timeline for one activity to finish just before the - * next activity starts, rather than having them end and start at - * the same time, hence ``- 1'' here. - */ - activity->end_t = activity->t + activity->mean - 1; - - /* The above only calculated mean. Now we are able to - * calculate from the mean the variance and the standard - * deviation. - */ - activity->variance = 0; - for (i = 0; i < NR_TEST_PASSES; ++i) { - delta_ns = - timespec_diff (&pass_data[i].events[activity->start_event[i]].t, - &pass_data[i].events[activity->end_event[i]].t); - activity->variance += pow (delta_ns - activity->mean, 2); - } - activity->variance /= NR_TEST_PASSES; - - activity->sd = sqrt (activity->variance); - } - - /* Get the total mean elapsed time from the special "run" activity. */ - activity = find_activity ("run"); - for (j = 0; j < nr_activities; ++j) { - activities[j].percent = 100.0 * activities[j].mean / activity->mean; - - activities[j].warning = - !(activities[j].flags & LONG_ACTIVITY) && - activities[j].percent >= WARNING_THRESHOLD; - } - - /* Sort the activities by start time. */ - qsort (activities, nr_activities, sizeof (struct activity), - compare_activities_by_t); -} - -/* Dump the timeline to stdout, if verbose is set. */ -static void -dump_timeline (void) -{ - size_t i; - - for (i = 0; i < nr_activities; ++i) { - printf ("activity %zu:\n", i); - printf (" name = %s\n", activities[i].name); - printf (" start - end = %.1f - %.1f\n", - activities[i].t, activities[i].end_t); - printf (" mean elapsed = %.1f\n", activities[i].mean); - printf (" variance = %.1f\n", activities[i].variance); - printf (" s.d = %.1f\n", activities[i].sd); - printf (" percent = %.1f\n", activities[i].percent); - } -} - -static void -print_activity (struct activity *activity) -{ - if (activity->warning) ansi_red (); else ansi_green (); - print_escaped_string (activity->name); - ansi_restore (); - printf (" %.1fms ±%.1fms ", - activity->mean / 1000000, activity->sd / 1000000); - if (activity->warning) ansi_red (); else ansi_green (); - printf ("(%.1f%%) ", activity->percent); - ansi_restore (); -} - -static void -print_analysis (void) -{ - double t = -1; /* Current time. */ - /* Which columns contain activities that we are displaying now? - * -1 == unused column, else index of an activity - */ - CLEANUP_FREE ssize_t *columns = NULL; - const size_t nr_columns = nr_activities; - size_t last_free_column = 0; - - size_t i, j; - double last_t, smallest_next_t; - const double MAX_T = 1e20; - - columns = malloc (nr_columns * sizeof (ssize_t)); - if (columns == NULL) error (EXIT_FAILURE, errno, "malloc"); - for (j = 0; j < nr_columns; ++j) - columns[j] = -1; - - for (;;) { - /* Find the next significant time to display, which is a time when - * some activity started or ended. - */ - smallest_next_t = MAX_T; - for (i = 0; i < nr_activities; ++i) { - if (t < activities[i].t && activities[i].t < smallest_next_t) - smallest_next_t = activities[i].t; - else if (t < activities[i].end_t && activities[i].end_t < smallest_next_t) - smallest_next_t = activities[i].end_t; - } - if (smallest_next_t == MAX_T) - break; /* Finished. */ - - last_t = t; - t = smallest_next_t; - - /* Draw a spacer line, but only if last_t -> t is a large jump. */ - if (t - last_t >= 1000000 /* ns */) { - printf (" "); - ansi_magenta (); - for (j = 0; j < last_free_column; ++j) { - if (columns[j] >= 0 && - activities[columns[j]].end_t != last_t /* !▼ */) - printf ("│ "); - else - printf (" "); - } - ansi_restore (); - printf ("\n"); - } - - /* If there are any activities that ended before this time, drop - * them from the columns list. - */ - for (i = 0; i < nr_activities; ++i) { - if (activities[i].end_t < t) { - for (j = 0; j < nr_columns; ++j) - if (columns[j] == (ssize_t) i) { - columns[j] = -1; - break; - } - } - } - - /* May need to adjust last_free_column after previous operation. */ - while (last_free_column > 0 && columns[last_free_column-1] == -1) - last_free_column--; - - /* If there are any activities starting at this time, add them to - * the right hand end of the columns list. - */ - for (i = 0; i < nr_activities; ++i) { - if (activities[i].t == t) - columns[last_free_column++] = i; - } - - /* Draw the line. */ - ansi_blue (); - printf ("%6.1fms: ", t / 1000000); - - ansi_magenta (); - for (j = 0; j < last_free_column; ++j) { - if (columns[j] >= 0) { - if (activities[columns[j]].t == t) - printf ("▲ "); - else if (activities[columns[j]].end_t == t) - printf ("▼ "); - else - printf ("│ "); - } - else - printf (" "); - } - ansi_restore (); - - for (j = 0; j < last_free_column; ++j) { - if (columns[j] >= 0 && activities[columns[j]].t == t) /* ▲ */ - print_activity (&activities[columns[j]]); - } - - printf ("\n"); - } -} - -static int -compare_activities_pointers_by_mean (const void *av, const void *bv) -{ - const struct activity * const *a = av; - const struct activity * const *b = bv; - - return (*b)->mean - (*a)->mean; -} - -static void -print_longest_to_shortest (void) -{ - size_t i; - CLEANUP_FREE struct activity **longest; - - /* Sort the activities longest first. In order not to affect the - * global activities array, sort an array of pointers to the - * activities instead. - */ - longest = malloc (sizeof (struct activity *) * nr_activities); - for (i = 0; i < nr_activities; ++i) - longest[i] = &activities[i]; - - qsort (longest, nr_activities, sizeof (struct activity *), - compare_activities_pointers_by_mean); - - /* Display the activities, longest first. */ - for (i = 0; i < nr_activities; ++i) { - print_activity (longest[i]); - printf ("\n"); - } -} - -/* Free the non-static part of the pass_data structures. */ -static void -free_pass_data (void) -{ - size_t i, j; - - for (i = 0; i < NR_TEST_PASSES; ++i) { - for (j = 0; j < pass_data[i].nr_events; ++j) - free (pass_data[i].events[j].message); - free (pass_data[i].events); - } -} - -static void -free_final_timeline (void) -{ - size_t i; - - for (i = 0; i < nr_activities; ++i) - free (activities[i].name); - free (activities); -} - -/* Colours. */ -static void -ansi_green (void) -{ - if (force_colour || isatty (1)) - fputs ("\033[0;32m", stdout); -} - -static void -ansi_red (void) -{ - if (force_colour || isatty (1)) - fputs ("\033[1;31m", stdout); -} - -static void -ansi_blue (void) -{ - if (force_colour || isatty (1)) - fputs ("\033[1;34m", stdout); -} - -static void -ansi_magenta (void) -{ - if (force_colour || isatty (1)) - fputs ("\033[1;35m", stdout); -} - -static void -ansi_restore (void) -{ - if (force_colour || isatty (1)) - fputs ("\033[0m", stdout); -} diff --git a/tests/qemu/boot-analysis.h b/tests/qemu/boot-analysis.h deleted file mode 100644 index a07f12e..0000000 --- a/tests/qemu/boot-analysis.h +++ /dev/null @@ -1,102 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -#ifndef GUESTFS_BOOT_ANALYSIS_H_ -#define GUESTFS_BOOT_ANALYSIS_H_ - -#define NR_WARMUP_PASSES 3 -#define NR_TEST_PASSES 5 - -/* Per-pass data collected. */ -struct pass_data { - size_t pass; - struct timespec start_t; - struct timespec end_t; - int64_t elapsed_ns; - - /* Array of timestamped events. */ - size_t nr_events; - struct event *events; - - /* Was the previous appliance log message incomplete? If so, this - * contains the index of that incomplete message in the events - * array. - */ - ssize_t incomplete_log_message; - - /* Have we seen the launch event yet? We don't record events until - * this one has been received. This makes it easy to base the - * timeline at event 0. - */ - int seen_launch; -}; - -/* The 'source' field in the event is a guestfs event - * (GUESTFS_EVENT_*). We also wish to encode libvirt as a source, so - * we use a magic/impossible value for that here. Note that events - * are bitmasks, and normally no more than one bit may be set. - */ -#define SOURCE_LIBVIRT ((uint64_t)~0) -extern char *source_to_string (uint64_t source); - -struct event { - struct timespec t; - uint64_t source; - char *message; -}; - -extern struct pass_data pass_data[NR_TEST_PASSES]; - -/* The final timeline consisting of various activities starting and - * ending. We're interested in when the activities start, and how - * long they take (mean, variance, standard deviation of length). - */ -struct activity { - char *name; /* Name of this activity. */ - int flags; -#define LONG_ACTIVITY 1 /* Expected to take a long time. */ - - /* For each pass, record the actual start & end events of this - * activity. - */ - size_t start_event[NR_TEST_PASSES]; - size_t end_event[NR_TEST_PASSES]; - - double t; /* Start (ns offset). */ - double end_t; /* t + mean - 1 */ - - /* Length of this activity. */ - double mean; /* Mean time elapsed (ns). */ - double variance; /* Variance. */ - double sd; /* Standard deviation. */ - double percent; /* Percent of total elapsed time. */ - - int warning; /* Appears in red. */ -}; - -extern size_t nr_activities; -extern struct activity *activities; - -extern int activity_exists (const char *name); -extern struct activity *add_activity (const char *name, int flags); -extern struct activity *find_activity (const char *name); -extern int activity_exists_with_no_data (const char *name, size_t pass); - -extern void construct_timeline (void); - -#endif /* GUESTFS_BOOT_ANALYSIS_H_ */ diff --git a/tests/qemu/boot-benchmark-range.pl b/tests/qemu/boot-benchmark-range.pl deleted file mode 100755 index 0e31c4d..0000000 --- a/tests/qemu/boot-benchmark-range.pl +++ /dev/null @@ -1,240 +0,0 @@ -#!/usr/bin/env perl -# Copyright (C) 2016 Red Hat Inc. -# -# This program is free software; you can redistribute it and/or modify -# it under the terms of the GNU General Public License as published by -# the Free Software Foundation; either version 2 of the License, or -# (at your option) any later version. -# -# This program is distributed in the hope that it will be useful, -# but WITHOUT ANY WARRANTY; without even the implied warranty of -# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the -# GNU General Public License for more details. -# -# You should have received a copy of the GNU General Public License -# along with this program; if not, write to the Free Software -# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - -use warnings; -use strict; - -use Pod::Usage; -use Getopt::Long; - -=head1 NAME - -boot-benchmark-range.pl - Benchmark libguestfs across a range of commits -from another project - -=head1 SYNOPSIS - - LIBGUESTFS_BACKEND=direct \ - LIBGUESTFS_HV=/path/to/qemu/x86_64-softmmu/qemu-system-x86_64 \ - ./run \ - tests/qemu/boot-benchmark-range.pl /path/to/qemu HEAD~50..HEAD - -=head1 - -Run F across a range of commits in another -project. This is useful for finding performance regressions in other -programs such as qemu or the Linux kernel which might be affecting -libguestfs. - -For example, suppose you suspect there has been a performance -regression in qemu, somewhere between C. You could run -the script like this: - - LIBGUESTFS_BACKEND=direct \ - LIBGUESTFS_HV=/path/to/qemu/x86_64-softmmu/qemu-system-x86_64 \ - ./run \ - tests/qemu/boot-benchmark-range.pl /path/to/qemu HEAD~50..HEAD - -where F is the path to the qemu git repository. - -The output is a list of the qemu commits, annotated by the benchmark -time and some other information about how the time compares to the -previous commit. - -You should run these tests on an unloaded machine. In particular -running a desktop environment, web browser and so on can make the -benchmarks useless. - -=head1 OPTIONS - -=over 4 - -=cut - -my $help; - -=item B<--help> - -Display brief help. - -=cut - -my $man; - -=item B<--man> - -Display full documentation (man page). - -=cut - -my $benchmark_command; - -=item B<--benchmark> C - -Set the name of the benchmark to run. You only need to use this if -the script cannot find the right path to the libguestfs -F program. By default the script looks for -this file in the same directory as its executable. - -=cut - -my $make_command = "make"; - -=item B<--make> C - -Set the command used to build the other project. The default is -to run C. - -If the command fails, then the commit is skipped. - -=back - -=cut - -# Clean up the program name. -my $progname = $0; -$progname =~ s{.*/}{}; - -# Parse options. -GetOptions ("help|?" => \$help, - "man" => \$man, - "benchmark=s" => \$benchmark_command, - "make=s" => \$make_command, - ) or pod2usage (2); -pod2usage (-exitval => 0) if $help; -pod2usage (-exitval => 0, -verbose => 2) if $man; - -die "$progname: missing argument: requires path to git repository and range of commits\n" unless @ARGV == 2; - -my $dir = $ARGV[0]; -my $range = $ARGV[1]; - -die "$progname: $dir is not a git repository\n" - unless -d $dir && -d "$dir/.git"; - -sub silently_run -{ - open my $saveout, ">&STDOUT"; - open my $saveerr, ">&STDERR"; - open STDOUT, ">/dev/null"; - open STDERR, ">/dev/null"; - my $ret = system (@_); - open STDOUT, ">&", $saveout; - open STDERR, ">&", $saveerr; - return $ret; -} - -# Find the benchmark program and check it works. -unless (defined $benchmark_command) { - $benchmark_command = $0; - $benchmark_command =~ s{/[^/]+$}{}; - $benchmark_command .= "/boot-benchmark"; - - my $r = silently_run ("$benchmark_command", "--help"); - die "$progname: cannot locate boot-benchmark program, try using --benchmark\n" unless $r == 0; -} - -# Get the top-most commit from the remote, and restore it on exit. -my $top_commit = `git -C '$dir' rev-parse HEAD`; -chomp $top_commit; - -sub checkout -{ - my $sha = shift; - my $ret = silently_run ("git", "-C", $dir, "checkout", $sha); - return $ret; -} - -END { - checkout ($top_commit); -} - -# Get the range of commits and log messages. -my @range = (); -open RANGE, "git -C '$dir' log --reverse --oneline $range |" or die; -while () { - if (m/^([0-9a-f]+) (.*)/) { - my $sha = $1; - my $msg = $2; - push @range, [ $sha, $msg ]; - } -} -close RANGE or die; - -# Run the test. -my $prev_ms; -foreach (@range) { - my ($sha, $msg) = @$_; - my $r; - - print "\n"; - print "$sha $msg\n"; - - # Checkout this commit in the other repo. - $r = checkout ($sha); - if ($r != 0) { - print "git checkout failed\n"; - next; - } - - # Build the repo, silently. - $r = silently_run ("cd $dir && $make_command"); - if ($r != 0) { - print "build failed\n"; - next; - } - - # Run the benchmark program and get the timing. - my ($time_ms, $time_str); - open BENCHMARK, "$benchmark_command | grep '^Result:' |" or die; - while () { - die unless m/^Result: (([\d.]+)ms ±[\d.]+ms)/; - $time_ms = $2; - $time_str = $1; - } - close BENCHMARK; - - print "\t", $time_str; - if (defined $prev_ms) { - if ($prev_ms > $time_ms) { - my $pc = 100 * ($prev_ms-$time_ms) / $time_ms; - if ($pc >= 1) { - printf (" ↑ improves performance by %0.1f%%", $pc); - } - } elsif ($prev_ms < $time_ms) { - my $pc = 100 * ($time_ms-$prev_ms) / $prev_ms; - if ($pc >= 1) { - printf (" ↓ degrades performance by %0.1f%%", $pc); - } - } - } - print "\n"; - $prev_ms = $time_ms; -} - -=head1 SEE ALSO - -L, -L. - -=head1 AUTHOR - -Richard W.M. Jones. - -=head1 COPYRIGHT - -Copyright (C) 2016 Red Hat Inc. diff --git a/tests/qemu/boot-benchmark.c b/tests/qemu/boot-benchmark.c deleted file mode 100644 index 0508ee9..0000000 --- a/tests/qemu/boot-benchmark.c +++ /dev/null @@ -1,225 +0,0 @@ -/* libguestfs - * Copyright (C) 2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -/* Benchmark the time taken to boot the libguestfs appliance. */ - -#include - -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" - -#include "boot-analysis-utils.h" - -#define NR_WARMUP_PASSES 3 -#define NR_TEST_PASSES 10 - -static const char *append = NULL; -static int memsize = 0; -static int smp = 1; - -static void run_test (void); -static guestfs_h *create_handle (void); -static void add_drive (guestfs_h *g); - -static void -usage (int exitcode) -{ - guestfs_h *g; - int default_memsize = -1; - - g = guestfs_create (); - if (g) { - default_memsize = guestfs_get_memsize (g); - guestfs_close (g); - } - - fprintf (stderr, - "boot-benchmark: Benchmark the time taken to boot the libguestfs appliance.\n" - "Usage:\n" - " boot-benchmark [--options]\n" - "Options:\n" - " --help Display this usage text and exit.\n" - " --append OPTS Append OPTS to kernel command line.\n" - " -m MB\n" - " --memsize MB Set memory size in MB (default: %d).\n" - " --smp N Enable N virtual CPUs (default: 1).\n", - default_memsize); - exit (exitcode); -} - -int -main (int argc, char *argv[]) -{ - enum { HELP_OPTION = CHAR_MAX + 1 }; - static const char *options = "m:"; - static const struct option long_options[] = { - { "help", 0, 0, HELP_OPTION }, - { "append", 1, 0, 0 }, - { "memsize", 1, 0, 'm' }, - { "smp", 1, 0, 0 }, - { 0, 0, 0, 0 } - }; - int c, option_index; - - for (;;) { - c = getopt_long (argc, argv, options, long_options, &option_index); - if (c == -1) break; - - switch (c) { - case 0: /* Options which are long only. */ - if (STREQ (long_options[option_index].name, "append")) { - append = optarg; - break; - } - else if (STREQ (long_options[option_index].name, "smp")) { - if (sscanf (optarg, "%d", &smp) != 1) { - fprintf (stderr, "%s: could not parse smp parameter: %s\n", - guestfs_int_program_name, optarg); - exit (EXIT_FAILURE); - } - break; - } - fprintf (stderr, "%s: unknown long option: %s (%d)\n", - guestfs_int_program_name, long_options[option_index].name, option_index); - exit (EXIT_FAILURE); - - case 'm': - if (sscanf (optarg, "%d", &memsize) != 1) { - fprintf (stderr, "%s: could not parse memsize parameter: %s\n", - guestfs_int_program_name, optarg); - exit (EXIT_FAILURE); - } - break; - - case HELP_OPTION: - usage (EXIT_SUCCESS); - - default: - usage (EXIT_FAILURE); - } - } - - run_test (); -} - -static void -run_test (void) -{ - guestfs_h *g; - size_t i; - int64_t ns[NR_TEST_PASSES]; - double mean; - double variance; - double sd; - - printf ("Warming up the libguestfs cache ...\n"); - for (i = 0; i < NR_WARMUP_PASSES; ++i) { - g = create_handle (); - add_drive (g); - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - guestfs_close (g); - } - - printf ("Running the tests ...\n"); - for (i = 0; i < NR_TEST_PASSES; ++i) { - struct timespec start_t, end_t; - - g = create_handle (); - add_drive (g); - get_time (&start_t); - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - guestfs_close (g); - get_time (&end_t); - - ns[i] = timespec_diff (&start_t, &end_t); - } - - /* Calculate the mean. */ - mean = 0; - for (i = 0; i < NR_TEST_PASSES; ++i) - mean += ns[i]; - mean /= NR_TEST_PASSES; - - /* Calculate the variance and standard deviation. */ - variance = 0; - for (i = 0; i < NR_TEST_PASSES; ++i) - variance = pow (ns[i] - mean, 2); - variance /= NR_TEST_PASSES; - sd = sqrt (variance); - - /* Print the test parameters. */ - printf ("\n"); - g = create_handle (); - test_info (g, NR_TEST_PASSES); - guestfs_close (g); - - /* Print the result. */ - printf ("\n"); - printf ("Result: %.1fms ±%.1fms\n", mean / 1000000, sd / 1000000); -} - -/* Common function to create the handle and set various defaults. */ -static guestfs_h * -create_handle (void) -{ - guestfs_h *g; - CLEANUP_FREE char *full_append = NULL; - - g = guestfs_create (); - if (!g) error (EXIT_FAILURE, errno, "guestfs_create"); - - if (memsize != 0) - if (guestfs_set_memsize (g, memsize) == -1) - exit (EXIT_FAILURE); - - if (smp >= 2) - if (guestfs_set_smp (g, smp) == -1) - exit (EXIT_FAILURE); - - if (append != NULL) - if (guestfs_set_append (g, full_append) == -1) - exit (EXIT_FAILURE); - - return g; -} - -/* Common function to add the /dev/null drive. */ -static void -add_drive (guestfs_h *g) -{ - if (guestfs_add_drive_opts (g, "/dev/null", - GUESTFS_ADD_DRIVE_OPTS_FORMAT, "raw", - GUESTFS_ADD_DRIVE_OPTS_READONLY, 1, - -1) == -1) - exit (EXIT_FAILURE); -} diff --git a/tests/qemu/qemu-boot.c b/tests/qemu/qemu-boot.c deleted file mode 100644 index 336c26e..0000000 --- a/tests/qemu/qemu-boot.c +++ /dev/null @@ -1,362 +0,0 @@ -/* libguestfs - * Copyright (C) 2014-2016 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -/* Ancient libguestfs had a script called test-bootbootboot which just - * booted up the appliance in a loop. This was necessary back in the - * bad old days when qemu was not very reliable. This is the - * spiritual successor of that script, designed to find bugs in - * aarch64 KVM. You can control the number of boots that are done and - * the amount of parallelism. - */ - -#include - -#include -#include -#include -#include -#include -#include -#include - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" -#include "estimate-max-threads.h" - -#define MIN(a,b) ((a)<(b)?(a):(b)) - -/* Maximum number of threads we would ever run. Note this should not - * be > 20, unless libvirt is modified to increase the maximum number - * of clients. User can override this limit using -P. - */ -#define MAX_THREADS 12 - -static size_t n; /* Number of qemu processes to run in total. */ -static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER; - -static int ignore_errors = 0; -static const char *log_template = NULL; -static size_t log_file_size; -static int trace = 0; -static int verbose = 0; - -/* Events captured by the --log option. */ -static const uint64_t event_bitmask = - GUESTFS_EVENT_LIBRARY | - GUESTFS_EVENT_WARNING | - GUESTFS_EVENT_APPLIANCE | - GUESTFS_EVENT_TRACE; - -struct thread_data { - int thread_num; - int r; -}; - -static void *start_thread (void *thread_data_vp); -static void message_callback (guestfs_h *g, void *opaque, uint64_t event, int event_handle, int flags, const char *buf, size_t buf_len, const uint64_t *array, size_t array_len); - -static void -usage (int exitcode) -{ - fprintf (stderr, - "qemu-boot: A program for repeatedly running the libguestfs appliance.\n" - "qemu-boot [-i] [--log output.%%] [-P ] -n \n" - " -i Ignore errors\n" - " --log \n" - " Write per-appliance logs to file (%% in name replaced by boot number)\n" - " -P Set number of parallel threads\n" - " (default is based on the amount of free memory)\n" - " -n Set number of appliances to run before exiting\n" - " -v Verbose appliance\n" - " -x Enable libguestfs tracing\n"); - exit (exitcode); -} - -int -main (int argc, char *argv[]) -{ - enum { HELP_OPTION = CHAR_MAX + 1 }; - static const char options[] = "in:P:vx"; - static const struct option long_options[] = { - { "help", 0, 0, HELP_OPTION }, - { "ignore", 0, 0, 'i' }, - { "log", 1, 0, 0 }, - { "number", 1, 0, 'n' }, - { "processes", 1, 0, 'P' }, - { "trace", 0, 0, 'x' }, - { "verbose", 0, 0, 'v' }, - { 0, 0, 0, 0 } - }; - size_t P = 0, i, errors; - int c, option_index; - int err; - void *status; - - for (;;) { - c = getopt_long (argc, argv, options, long_options, &option_index); - if (c == -1) break; - - switch (c) { - case 0: - /* Options which are long only. */ - if (STREQ (long_options[option_index].name, "log")) { - log_template = optarg; - log_file_size = strlen (log_template); - for (i = 0; i < strlen (log_template); ++i) { - if (log_template[i] == '%') - log_file_size += 64; - } - } - else { - fprintf (stderr, "%s: unknown long option: %s (%d)\n", - guestfs_int_program_name, long_options[option_index].name, option_index); - exit (EXIT_FAILURE); - } - break; - - case 'i': - ignore_errors = 1; - break; - - case 'n': - if (sscanf (optarg, "%zu", &n) != 1 || n == 0) { - fprintf (stderr, "%s: -n option not numeric and greater than 0\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - break; - - case 'P': - if (sscanf (optarg, "%zu", &P) != 1) { - fprintf (stderr, "%s: -P option not numeric\n", guestfs_int_program_name); - exit (EXIT_FAILURE); - } - break; - - case 'v': - verbose = 1; - break; - - case 'x': - trace = 1; - break; - - case HELP_OPTION: - usage (EXIT_SUCCESS); - - default: - usage (EXIT_FAILURE); - } - } - - if (n == 0) { - fprintf (stderr, - "%s: must specify number of processes to run (-n option)\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - if (optind != argc) { - fprintf (stderr, "%s: extra arguments found on the command line\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - /* Calculate the number of threads to use. */ - if (P > 0) - P = MIN (n, P); - else - P = MIN (n, MIN (MAX_THREADS, estimate_max_threads ())); - - /* Start the worker threads. */ - struct thread_data thread_data[P]; - pthread_t threads[P]; - - for (i = 0; i < P; ++i) { - thread_data[i].thread_num = i; - err = pthread_create (&threads[i], NULL, start_thread, &thread_data[i]); - if (err != 0) { - fprintf (stderr, "%s: pthread_create[%zu]: %s\n", - guestfs_int_program_name, i, strerror (err)); - exit (EXIT_FAILURE); - } - } - - /* Wait for the threads to exit. */ - errors = 0; - for (i = 0; i < P; ++i) { - err = pthread_join (threads[i], &status); - if (err != 0) { - fprintf (stderr, "%s: pthread_join[%zu]: %s\n", - guestfs_int_program_name, i, strerror (err)); - errors++; - } - if (*(int *)status == -1) - errors++; - } - - exit (errors == 0 ? EXIT_SUCCESS : EXIT_FAILURE); -} - -/* Worker thread. */ -static void * -start_thread (void *thread_data_vp) -{ - struct thread_data *thread_data = thread_data_vp; - int quit = 0; - int err; - size_t i; - guestfs_h *g; - unsigned errors = 0; - char id[64]; - - for (;;) { - CLEANUP_FREE char *log_file = NULL; - CLEANUP_FCLOSE FILE *log_fp = NULL; - - /* Take the next process. */ - err = pthread_mutex_lock (&mutex); - if (err != 0) { - fprintf (stderr, "%s: pthread_mutex_lock: %s", - guestfs_int_program_name, strerror (err)); - goto error; - } - - i = n; - if (i > 0) { - printf ("%zu to go ... \r", n); - fflush (stdout); - - n--; - } - else - quit = 1; - - err = pthread_mutex_unlock (&mutex); - if (err != 0) { - fprintf (stderr, "%s: pthread_mutex_unlock: %s", - guestfs_int_program_name, strerror (err)); - goto error; - } - - if (quit) /* Work finished. */ - break; - - g = guestfs_create (); - if (g == NULL) { - perror ("guestfs_create"); - errors++; - if (!ignore_errors) - goto error; - } - - /* Only if using --log, set up a callback. See examples/debug-logging.c */ - if (log_template != NULL) { - size_t j, k; - - log_file = malloc (log_file_size + 1); - if (log_file == NULL) abort (); - for (j = 0, k = 0; j < strlen (log_template); ++j) { - if (log_template[j] == '%') { - snprintf (&log_file[k], log_file_size - k, "%zu", i); - k += strlen (&log_file[k]); - } - else - log_file[k++] = log_template[j]; - } - log_file[k] = '\0'; - log_fp = fopen (log_file, "w"); - if (log_fp == NULL) { - perror (log_file); - abort (); - } - guestfs_set_event_callback (g, message_callback, - event_bitmask, 0, log_fp); - } - - snprintf (id, sizeof id, "%zu", i); - guestfs_set_identifier (g, id); - - guestfs_set_trace (g, trace); - guestfs_set_verbose (g, verbose); - - if (guestfs_add_drive_ro (g, "/dev/null") == -1) { - errors++; - if (!ignore_errors) - goto error; - } - - if (guestfs_launch (g) == -1) { - errors++; - if (!ignore_errors) - goto error; - } - - if (guestfs_shutdown (g) == -1) { - errors++; - if (!ignore_errors) - goto error; - } - - guestfs_close (g); - } - - if (errors > 0) { - fprintf (stderr, "%s: thread %d: %u errors were ignored\n", - guestfs_int_program_name, thread_data->thread_num, errors); - goto error; - } - - thread_data->r = 0; - return &thread_data->r; - - error: - thread_data->r = -1; - return &thread_data->r; -} - -/* If using --log, this is called to write messages to the log file. */ -static void -message_callback (guestfs_h *g, void *opaque, - uint64_t event, int event_handle, - int flags, - const char *buf, size_t buf_len, - const uint64_t *array, size_t array_len) -{ - FILE *fp = opaque; - - if (buf_len > 0) { - CLEANUP_FREE char *msg = strndup (buf, buf_len); - - switch (event) { - case GUESTFS_EVENT_APPLIANCE: - fprintf (fp, "%s", msg); - break; - case GUESTFS_EVENT_LIBRARY: - fprintf (fp, "libguestfs: %s\n", msg); - break; - case GUESTFS_EVENT_WARNING: - fprintf (fp, "libguestfs: warning: %s\n", msg); - break; - case GUESTFS_EVENT_TRACE: - fprintf (fp, "libguestfs: trace: %s\n", msg); - break; - } - fflush (fp); - } -} diff --git a/tests/qemu/qemu-speed-test.c b/tests/qemu/qemu-speed-test.c deleted file mode 100644 index d5e34c3..0000000 --- a/tests/qemu/qemu-speed-test.c +++ /dev/null @@ -1,480 +0,0 @@ -/* libguestfs - * Copyright (C) 2014 Red Hat Inc. - * - * This program is free software; you can redistribute it and/or modify - * it under the terms of the GNU General Public License as published by - * the Free Software Foundation; either version 2 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License along - * with this program; if not, write to the Free Software Foundation, Inc., - * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. - */ - -/* Test the speed of various qemu features. Currently tested are: - * - virtio-serial upload - * - virtio-serial download - * - block device read - * - block device write - * More to come in future. - */ - -#include - -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include - -#include "guestfs.h" -#include "guestfs-internal-frontend.h" - -static void test_virtio_serial (void); -static void test_block_device (void); - -/* Which tests are enabled? -- All by default. */ -static int virtio_serial_upload = 1; -static int virtio_serial_download = 1; -static int block_device_write = 1; -static int block_device_read = 1; - -static int max_time_override = 0; - -static void -reset_default_tests (int *flag) -{ - if (*flag) { - virtio_serial_upload = 0; - virtio_serial_download = 0; - block_device_write = 0; - block_device_read = 0; - *flag = 0; - } -} - -static void -usage (int exitcode) -{ - fprintf (stderr, - "qemu-speed-test: Test the speed of qemu features.\n" - "\n" - "To run all tests (recommended), do:\n" - " qemu-speed-test\n" - "\n" - "To run only specific tests, do:\n" - " qemu-speed-test --option [--option ...]\n" - "where the test options are:\n" - " --virtio-serial-upload\n" - " --virtio-serial-download\n" - " --block-device-write\n" - " --block-device-read\n" - "\n" - "Other options:\n" - " --help Display help output and exit\n" - " -t | --time= Set max length of test in seconds\n" - ); - exit (exitcode); -} - -int -main (int argc, char *argv[]) -{ - enum { HELP_OPTION = CHAR_MAX + 1 }; - static const char options[] = "t:"; - static const struct option long_options[] = { - { "help", 0, 0, HELP_OPTION }, - { "time", 1, 0, 't' }, - - /* Tests. */ - { "virtio-serial-upload", 0, 0, 0 }, - { "virtio-serial-download", 0, 0, 0 }, - { "block-device-write", 0, 0, 0 }, - { "block-device-read", 0, 0, 0 }, - - { 0, 0, 0, 0 } - }; - int c, option_index; - int reset_flag = 1; - - for (;;) { - c = getopt_long (argc, argv, options, long_options, &option_index); - if (c == -1) break; - - switch (c) { - case 0: - /* Options which are long only. */ - if (STREQ (long_options[option_index].name, "virtio-serial-upload")) { - reset_default_tests (&reset_flag); - virtio_serial_upload = 1; - } - else if (STREQ (long_options[option_index].name, "virtio-serial-download")) { - reset_default_tests (&reset_flag); - virtio_serial_download = 1; - } - else if (STREQ (long_options[option_index].name, "block-device-write")) { - reset_default_tests (&reset_flag); - block_device_write = 1; - } - else if (STREQ (long_options[option_index].name, "block-device-read")) { - reset_default_tests (&reset_flag); - block_device_read = 1; - } - else { - fprintf (stderr, "%s: unknown long option: %s (%d)\n", - guestfs_int_program_name, long_options[option_index].name, option_index); - exit (EXIT_FAILURE); - } - break; - - case 't': - if (sscanf (optarg, "%d", &max_time_override) != 1 || - max_time_override < 0) { - fprintf (stderr, "%s: -t: argument is not a positive integer\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - break; - - case HELP_OPTION: - usage (EXIT_SUCCESS); - - default: - usage (EXIT_FAILURE); - } - } - - if (optind != argc) { - fprintf (stderr, "%s: extra arguments found on the command line\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - test_virtio_serial (); - test_block_device (); - - exit (EXIT_SUCCESS); -} - -static void -print_rate (const char *msg, int64_t rate) -{ - printf ("%-40s %" PRIi64 " bytes/sec (%" PRIi64 " Mbytes/sec)\n", - msg, rate, rate / 1024 / 1024); - fflush (stdout); -} - -/* The maximum time we will spend running the test (seconds). */ -#define TEST_SERIAL_MAX_TIME 30 - -/* The maximum amount of data to copy. You can safely make this very - * large because it's only making sparse files. - */ -#define TEST_SERIAL_MAX_SIZE \ - (INT64_C(1024) * INT64_C(1024) * INT64_C(1024) * INT64_C(1024)) - -static guestfs_h *g; -static struct timeval start; -static const char *operation; -static int64_t rate; - -static void -stop_transfer (int sig) -{ - guestfs_user_cancel (g); -} - -/* Compute Y - X and return the result in milliseconds. - * Approximately the same as this code: - * http://www.mpp.mpg.de/~huber/util/timevaldiff.c - */ -static int64_t -timeval_diff (const struct timeval *x, const struct timeval *y) -{ - int64_t msec; - - msec = (y->tv_sec - x->tv_sec) * 1000; - msec += (y->tv_usec - x->tv_usec) / 1000; - return msec; -} - -static void -progress_cb (guestfs_h *g, void *vp, uint64_t event, - int eh, int flags, - const char *buf, size_t buflen, - const uint64_t *array, size_t arraylen) -{ - uint64_t transferred; - struct timeval now; - int64_t millis; - - assert (event == GUESTFS_EVENT_PROGRESS); - assert (arraylen >= 4); - - gettimeofday (&now, NULL); - - /* Bytes transferred. */ - transferred = array[2]; - - /* Calculate the speed of the upload or download. */ - millis = timeval_diff (&start, &now); - assert (millis >= 0); - - if (millis != 0) { - rate = 1000 * transferred / millis; - printf ("%s: %" PRIi64 " bytes/sec \r", - operation, rate); - fflush (stdout); - } -} - -static void -test_virtio_serial (void) -{ - int fd, r, eh; - char tmpfile[] = "/tmp/speedtestXXXXXX"; - struct sigaction sa, old_sa; - - if (!virtio_serial_upload && !virtio_serial_download) - return; - - /* Create a sparse file. We could upload from /dev/zero, but we - * won't get progress messages because libguestfs tests if the - * source file is a regular file. - */ - fd = mkstemp (tmpfile); - if (fd == -1) { - perror ("mkstemp"); - exit (EXIT_FAILURE); - } - if (ftruncate (fd, TEST_SERIAL_MAX_SIZE) == -1) { - perror ("ftruncate"); - exit (EXIT_FAILURE); - } - if (close (fd) == -1) { - perror ("close"); - exit (EXIT_FAILURE); - } - - g = guestfs_create (); - if (!g) { - perror ("guestfs_create"); - exit (EXIT_FAILURE); - } - - if (guestfs_add_drive_scratch (g, INT64_C (100*1024*1024), -1) == -1) - exit (EXIT_FAILURE); - - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - - /* Make and mount a filesystem which will be used by the download test. */ - if (guestfs_mkfs (g, "ext4", "/dev/sda") == -1) - exit (EXIT_FAILURE); - if (guestfs_mount (g, "/dev/sda", "/") == -1) - exit (EXIT_FAILURE); - - /* Time out the upload after TEST_SERIAL_MAX_TIME seconds have passed. */ - memset (&sa, 0, sizeof sa); - sa.sa_handler = stop_transfer; - sa.sa_flags = SA_RESTART; - sigaction (SIGALRM, &sa, &old_sa); - - /* Get progress messages, which will tell us how much data has been - * transferred. - */ - eh = guestfs_set_event_callback (g, progress_cb, GUESTFS_EVENT_PROGRESS, - 0, NULL); - if (eh == -1) - exit (EXIT_FAILURE); - - if (virtio_serial_upload) { - gettimeofday (&start, NULL); - rate = -1; - operation = "upload"; - alarm (max_time_override > 0 ? max_time_override : TEST_SERIAL_MAX_TIME); - - /* For the upload test, upload the sparse file to /dev/null in the - * appliance. Hopefully this is mostly testing just virtio-serial. - */ - guestfs_push_error_handler (g, NULL, NULL); - r = guestfs_upload (g, tmpfile, "/dev/null"); - alarm (0); - unlink (tmpfile); - guestfs_pop_error_handler (g); - - /* It's possible that the upload will finish before the alarm fires, - * or that the upload will be stopped by the alarm. - */ - if (r == -1 && guestfs_last_errno (g) != EINTR) { - fprintf (stderr, - "%s: expecting upload command to return EINTR\n%s\n", - guestfs_int_program_name, guestfs_last_error (g)); - exit (EXIT_FAILURE); - } - - if (rate == -1) { - rate_error: - fprintf (stderr, "%s: internal error: progress callback was not called! (r=%d, errno=%d)\n", - guestfs_int_program_name, - r, guestfs_last_errno (g)); - exit (EXIT_FAILURE); - } - - print_rate ("virtio-serial upload rate:", rate); - } - - if (virtio_serial_download) { - /* For the download test, download a sparse file within the - * appliance to /dev/null on the host. - */ - if (guestfs_touch (g, "/sparse") == -1) - exit (EXIT_FAILURE); - if (guestfs_truncate_size (g, "/sparse", TEST_SERIAL_MAX_SIZE) == -1) - exit (EXIT_FAILURE); - - gettimeofday (&start, NULL); - rate = -1; - operation = "download"; - alarm (max_time_override > 0 ? max_time_override : TEST_SERIAL_MAX_TIME); - guestfs_push_error_handler (g, NULL, NULL); - r = guestfs_download (g, "/sparse", "/dev/null"); - alarm (0); - guestfs_pop_error_handler (g); - - if (r == -1 && guestfs_last_errno (g) != EINTR) { - fprintf (stderr, - "%s: expecting download command to return EINTR\n%s\n", - guestfs_int_program_name, guestfs_last_error (g)); - exit (EXIT_FAILURE); - } - - if (rate == -1) - goto rate_error; - - print_rate ("virtio-serial download rate:", rate); - } - - if (guestfs_shutdown (g) == -1) - exit (EXIT_FAILURE); - - guestfs_close (g); - - /* Restore SIGALRM signal handler. */ - sigaction (SIGALRM, &old_sa, NULL); -} - -/* The time we will spend running the test (seconds). */ -#define TEST_BLOCK_DEVICE_TIME 30 - -static void -test_block_device (void) -{ - int fd; - char tmpfile[] = "/tmp/speedtestXXXXXX"; - CLEANUP_FREE char **devices = NULL; - char *r; - const char *argv[4]; - const int t = - max_time_override > 0 ? max_time_override : TEST_BLOCK_DEVICE_TIME; - char tbuf[64]; - int64_t bytes_written, bytes_read; - - if (!block_device_write && !block_device_read) - return; - - snprintf (tbuf, sizeof tbuf, "%d", t); - - g = guestfs_create (); - if (!g) { - perror ("guestfs_create"); - exit (EXIT_FAILURE); - } - - /* Create a fully allocated backing file. Note we are not testing - * the speed of allocation on the host. - */ - fd = mkstemp (tmpfile); - if (fd == -1) { - perror ("mkstemp"); - exit (EXIT_FAILURE); - } - close (fd); - - if (guestfs_disk_create (g, tmpfile, "raw", - INT64_C (1024*1024*1024), - GUESTFS_DISK_CREATE_PREALLOCATION, "full", - -1) == -1) - exit (EXIT_FAILURE); - - if (guestfs_add_drive (g, tmpfile) == -1) - exit (EXIT_FAILURE); - - if (guestfs_launch (g) == -1) - exit (EXIT_FAILURE); - - devices = guestfs_list_devices (g); - if (devices == NULL) - exit (EXIT_FAILURE); - if (devices[0] == NULL) { - fprintf (stderr, "%s: expected guestfs_list_devices to return at least 1 device\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - if (block_device_write) { - /* Test write speed. */ - argv[0] = devices[0]; - argv[1] = "w"; - argv[2] = tbuf; - argv[3] = NULL; - r = guestfs_debug (g, "device_speed", (char **) argv); - if (r == NULL) - exit (EXIT_FAILURE); - - if (sscanf (r, "%" SCNi64, &bytes_written) != 1) { - fprintf (stderr, "%s: could not parse device_speed output\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - print_rate ("block device writes:", bytes_written / t); - } - - if (block_device_read) { - /* Test read speed. */ - argv[0] = devices[0]; - argv[1] = "r"; - argv[2] = tbuf; - argv[3] = NULL; - r = guestfs_debug (g, "device_speed", (char **) argv); - if (r == NULL) - exit (EXIT_FAILURE); - - if (sscanf (r, "%" SCNi64, &bytes_read) != 1) { - fprintf (stderr, "%s: could not parse device_speed output\n", - guestfs_int_program_name); - exit (EXIT_FAILURE); - } - - print_rate ("block device reads:", bytes_read / t); - } - - if (guestfs_shutdown (g) == -1) - exit (EXIT_FAILURE); - - guestfs_close (g); - - /* Remove temporary file. */ - unlink (tmpfile); -} diff --git a/utils/boot-analysis/Makefile.am b/utils/boot-analysis/Makefile.am new file mode 100644 index 0000000..ef9b2cb --- /dev/null +++ b/utils/boot-analysis/Makefile.am @@ -0,0 +1,43 @@ +# libguestfs +# Copyright (C) 2011-2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +include $(top_srcdir)/subdir-rules.mk + +noinst_PROGRAMS = boot-analysis + +boot_analysis_SOURCES = \ + boot-analysis.c \ + boot-analysis.h \ + boot-analysis-timeline.c \ + boot-analysis-utils.c \ + boot-analysis-utils.h +boot_analysis_CPPFLAGS = \ + -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ + -I$(top_srcdir)/src -I$(top_builddir)/src +boot_analysis_CFLAGS = \ + -pthread \ + $(WARN_CFLAGS) $(WERROR_CFLAGS) \ + $(PCRE_CFLAGS) +boot_analysis_LDADD = \ + $(top_builddir)/src/libutils.la \ + $(top_builddir)/src/libguestfs.la \ + $(PCRE_LIBS) \ + $(LIBXML2_LIBS) \ + $(LIBVIRT_LIBS) \ + $(LTLIBINTL) \ + $(top_builddir)/gnulib/lib/libgnu.la \ + -lm diff --git a/utils/boot-analysis/boot-analysis-timeline.c b/utils/boot-analysis/boot-analysis-timeline.c new file mode 100644 index 0000000..09a78ef --- /dev/null +++ b/utils/boot-analysis/boot-analysis-timeline.c @@ -0,0 +1,523 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include + +#include "ignore-value.h" + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" + +#include "boot-analysis.h" + +COMPILE_REGEXP(re_initcall_calling_module, + "calling ([_A-Za-z0-9]+)\\+.*\\[([_A-Za-z0-9]+)]", 0) +COMPILE_REGEXP(re_initcall_calling, + "calling ([_A-Za-z0-9]+)\\+", 0) + +static void construct_initcall_timeline (void); + +/* "supermin: internal insmod xx.ko" -> "insmod xx.ko" */ +static char * +translate_supermin_insmod_message (const char *message) +{ + char *ret; + + assert (STRPREFIX (message, "supermin: internal ")); + + ret = strdup (message + strlen ("supermin: internal ")); + if (ret == NULL) + error (EXIT_FAILURE, errno, "strdup"); + return ret; +} + +/* Analyze significant events from the events array, to form a + * timeline of activities. + */ +void +construct_timeline (void) +{ + size_t i, j, k; + struct pass_data *data; + struct activity *activity; + + for (i = 0; i < NR_TEST_PASSES; ++i) { + data = &pass_data[i]; + + /* Find an activity, by matching an event with the condition + * `begin_cond' through to the second event `end_cond'. Create an + * activity object in the timeline from the result. + */ +#define FIND(name, flags, begin_cond, end_cond) \ + do { \ + activity = NULL; \ + for (j = 0; j < data->nr_events; ++j) { \ + if (begin_cond) { \ + for (k = j+1; k < data->nr_events; ++k) { \ + if (end_cond) { \ + if (i == 0) \ + activity = add_activity (name, flags); \ + else \ + activity = find_activity (name); \ + break; \ + } \ + } \ + break; \ + } \ + } \ + if (activity) { \ + activity->start_event[i] = j; \ + activity->end_event[i] = k; \ + } \ + else \ + error (EXIT_FAILURE, 0, "could not find activity '%s' in pass '%zu'", \ + name, i); \ + } while (0) + + /* Same as FIND() macro, but if no matching events are found, + * ignore it. + */ +#define FIND_OPTIONAL(name, flags, begin_cond, end_cond) \ + do { \ + activity = NULL; \ + for (j = 0; j < data->nr_events; ++j) { \ + if (begin_cond) { \ + for (k = j+1; k < data->nr_events; ++k) { \ + if (end_cond) { \ + if (i == 0) \ + activity = add_activity (name, flags); \ + else \ + activity = find_activity (name); \ + break; \ + } \ + } \ + break; \ + } \ + } \ + if (activity) { \ + activity->start_event[i] = j; \ + activity->end_event[i] = k; \ + } \ + } while (0) + + /* Find multiple entries, where we check for: + * next_cond + * next_cond + * next_cond + * end_cond + */ +#define FIND_MULTIPLE(debug_name, flags, next_cond, end_cond, translate_message) \ + do { \ + activity = NULL; \ + for (j = 0; j < data->nr_events; ++j) { \ + if (next_cond) { \ + CLEANUP_FREE char *message = translate_message (data->events[j].message); \ + if (activity) \ + activity->end_event[i] = j; \ + if (i == 0) \ + activity = add_activity (message, flags); \ + else \ + activity = find_activity (message); \ + activity->start_event[i] = j; \ + } \ + else if (end_cond) \ + break; \ + } \ + if (j < data->nr_events && activity) \ + activity->end_event[i] = j; \ + else \ + error (EXIT_FAILURE, 0, "could not find activity '%s' in pass '%zu'", \ + debug_name, i); \ + } while (0) + + /* Add one activity which is going to cover the whole process + * from launch to close. The launch event is always event 0. + * NB: This activity must be called "run" (see below). + */ + FIND ("run", LONG_ACTIVITY, + j == 0, data->events[k].source == GUESTFS_EVENT_CLOSE); + + /* Find where we invoke supermin --build. This should be a null + * operation, but it still takes time to run the external command. + */ + FIND ("supermin:build", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, + "begin building supermin appliance"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, + "finished building supermin appliance")); + + /* Find where we invoke qemu to test features. */ + FIND_OPTIONAL ("qemu:feature-detect", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, + "begin testing qemu features"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, + "finished testing qemu features")); + + /* Find where we run qemu. */ + FIND_OPTIONAL ("qemu", LONG_ACTIVITY, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "-nodefconfig"), + data->events[k].source == GUESTFS_EVENT_CLOSE); + + /* For the libvirt backend, connecting to libvirt, getting + * capabilities, parsing capabilities etc. + */ + FIND_OPTIONAL ("libvirt:connect", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, "connect to libvirt"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, "successfully opened libvirt handle")); + FIND_OPTIONAL ("libvirt:get-libvirt-capabilities", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, "get libvirt capabilities"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, "parsing capabilities XML")); + + FIND_OPTIONAL ("libguestfs:parse-libvirt-capabilities", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, "parsing capabilities XML"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, "get_backend_setting")); + + FIND_OPTIONAL ("libguestfs:create-libvirt-xml", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, "create libvirt XML"), + data->events[k].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[k].message, "libvirt XML:")); + +#if defined(__aarch64__) +#define FIRST_KERNEL_MESSAGE "Booting Linux on physical CPU" +#define FIRST_FIRMWARE_MESSAGE "UEFI firmware starting" +#else +#define SGABIOS_STRING "\033[1;256r\033[256;256H\033[6n" +#define FIRST_KERNEL_MESSAGE "Probing EDD" +#define FIRST_FIRMWARE_MESSAGE SGABIOS_STRING +#endif + + /* For the libvirt backend, find the overhead of libvirt. */ + FIND_OPTIONAL ("libvirt:overhead", 0, + data->events[j].source == GUESTFS_EVENT_LIBRARY && + strstr (data->events[j].message, "launch libvirt guest"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, FIRST_FIRMWARE_MESSAGE)); + + /* From starting qemu up to entering the BIOS is the qemu overhead. */ + FIND_OPTIONAL ("qemu:overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "-nodefconfig"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, FIRST_FIRMWARE_MESSAGE)); + + /* From entering the BIOS to starting the kernel is the BIOS overhead. */ + FIND_OPTIONAL ("bios:overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, FIRST_FIRMWARE_MESSAGE), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, FIRST_KERNEL_MESSAGE)); + +#if defined(__i386__) || defined(__x86_64__) + /* SGABIOS (option ROM). */ + FIND_OPTIONAL ("sgabios", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, SGABIOS_STRING), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "SeaBIOS (version")); +#endif + +#if defined(__i386__) || defined(__x86_64__) + /* SeaBIOS. */ + FIND ("seabios", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "SeaBIOS (version"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, FIRST_KERNEL_MESSAGE)); +#endif + +#if defined(__i386__) || defined(__x86_64__) + /* SeaBIOS - only available when using debug messages. */ + FIND_OPTIONAL ("seabios:pci-probe", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "Searching bootorder for: /pci@"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "Scan for option roms")); +#endif + + /* Find where we run the guest kernel. */ + FIND ("kernel", LONG_ACTIVITY, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), + data->events[k].source == GUESTFS_EVENT_CLOSE); + + /* Kernel startup to userspace. */ + FIND ("kernel:overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "supermin:") && + strstr (data->events[k].message, "starting up")); + + /* The time taken to get into start_kernel function. */ + FIND ("kernel:entry", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, FIRST_KERNEL_MESSAGE), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "Linux version")); + +#if defined(__i386__) || defined(__x86_64__) + /* Alternatives patching instructions (XXX not very accurate we + * really need some debug messages inserted into the code). + */ + FIND ("kernel:alternatives", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "Last level dTLB entries"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "Freeing SMP alternatives")); +#endif + + /* ftrace patching instructions. */ + FIND ("kernel:ftrace", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "ftrace: allocating"), + 1); + + /* All initcall functions, before we enter userspace. */ + FIND ("kernel:initcalls-before-userspace", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "calling "), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "Freeing unused kernel memory")); + + /* Find where we run supermin mini-initrd. */ + FIND ("supermin:mini-initrd", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "supermin:") && + strstr (data->events[j].message, "starting up"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "supermin: chroot")); + + /* Loading kernel modules from supermin initrd. */ + FIND_MULTIPLE + ("supermin insmod", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "supermin: internal insmod"), + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "supermin: picked"), + translate_supermin_insmod_message); + + /* Find where we run the /init script. */ + FIND ("/init", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "supermin: chroot"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "guestfsd --verbose")); + + /* Everything from the chroot to the first echo in the /init + * script counts as bash overhead. + */ + FIND ("bash:overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "supermin: chroot"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "Starting /init script")); + + /* /init: Mount special filesystems. */ + FIND ("/init:mount-special", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "*guestfs_boot_analysis=1*"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "kmod static-nodes")); + + /* /init: Run kmod static-nodes */ + FIND ("/init:kmod-static-nodes", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "kmod static-nodes"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "systemd-tmpfiles")); + + /* /init: systemd-tmpfiles. */ + FIND ("/init:systemd-tmpfiles", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "systemd-tmpfiles"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "udev")); + + /* /init: start udevd. */ + FIND ("/init:udev-overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "udevd --daemon"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "nullglob")); + + /* /init: set up network. */ + FIND ("/init:network-overhead", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "+ ip addr"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "+ test")); + + /* /init: probe MD arrays. */ + FIND ("/init:md-probe", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "+ mdadm"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "+ modprobe dm_mod")); + + /* /init: probe DM/LVM. */ + FIND ("/init:lvm-probe", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "+ modprobe dm_mod"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "+ ldmtool")); + + /* /init: probe Windows dynamic disks. */ + FIND ("/init:windows-dynamic-disks-probe", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "+ ldmtool"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "+ test")); + + /* Find where we run guestfsd. */ + FIND ("guestfsd", 0, + data->events[j].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[j].message, "guestfsd --verbose"), + data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, "fsync /dev/sda")); + + /* Shutdown process. */ + FIND ("shutdown", 0, + data->events[j].source == GUESTFS_EVENT_TRACE && + STREQ (data->events[j].message, "close"), + data->events[k].source == GUESTFS_EVENT_CLOSE); + } + + construct_initcall_timeline (); +} + +/* Handling of initcall is so peculiar that we hide it in a separate + * function from the rest. + */ +static void +construct_initcall_timeline (void) +{ + size_t i, j, k; + struct pass_data *data; + struct activity *activity; + + for (i = 0; i < NR_TEST_PASSES; ++i) { + data = &pass_data[i]; + + /* Each kernel initcall is bracketed by: + * + * calling ehci_hcd_init+0x0/0xc1 @ 1" + * initcall ehci_hcd_init+0x0/0xc1 returned 0 after 420 usecs" + * + * For initcall functions in modules: + * + * calling virtio_mmio_init+0x0/0x1000 [virtio_mmio] @ 1" + * initcall virtio_mmio_init+0x0/0x1000 [virtio_mmio] returned 0 after 14 usecs" + * + * Initcall functions can be nested, and do not have unique names. + */ + for (j = 0; j < data->nr_events; ++j) { + int vec[30], r; + const char *message = data->events[j].message; + + if (data->events[j].source == GUESTFS_EVENT_APPLIANCE && + ((r = pcre_exec (re_initcall_calling_module, NULL, + message, strlen (message), + 0, 0, vec, sizeof vec / sizeof vec[0])) >= 1 || + (r = pcre_exec (re_initcall_calling, NULL, + message, strlen (message), + 0, 0, vec, sizeof vec / sizeof vec[0])) >= 1)) { + + CLEANUP_FREE char *fn_name = NULL, *module_name = NULL; + if (r >= 2) /* because pcre_exec returns 1 + number of captures */ + fn_name = strndup (message + vec[2], vec[3]-vec[2]); + if (r >= 3) + module_name = strndup (message + vec[4], vec[5]-vec[4]); + + CLEANUP_FREE char *fullname; + if (asprintf (&fullname, "%s.%s", + module_name ? module_name : "kernel", fn_name) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + + CLEANUP_FREE char *initcall_match; + if (asprintf (&initcall_match, "initcall %s", fn_name) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + + /* Get a unique name for this activity. Unfortunately + * kernel initcall function names are not unique! + */ + CLEANUP_FREE char *activity_name; + if (asprintf (&activity_name, "initcall %s", fullname) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + + if (i == 0) { + int n = 1; + while (activity_exists (activity_name)) { + free (activity_name); + if (asprintf (&activity_name, "initcall %s:%d", fullname, n) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + n++; + } + } + else { + int n = 1; + while (!activity_exists_with_no_data (activity_name, i)) { + free (activity_name); + if (asprintf (&activity_name, "initcall %s:%d", fullname, n) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + n++; + } + } + + /* Find the matching end event. It might be some time later, + * since it appears initcalls can be nested. + */ + for (k = j+1; k < data->nr_events; ++k) { + if (data->events[k].source == GUESTFS_EVENT_APPLIANCE && + strstr (data->events[k].message, initcall_match)) { + if (i == 0) + activity = add_activity (activity_name, 0); + else + activity = find_activity (activity_name); + activity->start_event[i] = j; + activity->end_event[i] = k; + break; + } + } + } + } + } +} diff --git a/utils/boot-analysis/boot-analysis-utils.c b/utils/boot-analysis/boot-analysis-utils.c new file mode 100644 index 0000000..693b6f4 --- /dev/null +++ b/utils/boot-analysis/boot-analysis-utils.c @@ -0,0 +1,90 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +#include + +#include +#include +#include +#include +#include + +#include "ignore-value.h" + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" + +#include "boot-analysis-utils.h" + +void +get_time (struct timespec *ts) +{ + if (clock_gettime (CLOCK_REALTIME, ts) == -1) + error (EXIT_FAILURE, errno, "clock_gettime: CLOCK_REALTIME"); +} + +int64_t +timespec_diff (const struct timespec *x, const struct timespec *y) +{ + int64_t nsec; + + nsec = (y->tv_sec - x->tv_sec) * UINT64_C(1000000000); + nsec += y->tv_nsec - x->tv_nsec; + return nsec; +} + +void +test_info (guestfs_h *g, int nr_test_passes) +{ + const char *qemu = guestfs_get_hv (g); + CLEANUP_FREE char *cmd = NULL; + CLEANUP_FREE char *backend = NULL; + + /* Related to the test program. */ + printf ("test version: %s %s\n", PACKAGE_NAME, PACKAGE_VERSION_FULL); + printf (" test passes: %d\n", nr_test_passes); + + /* Related to the host. */ + printf ("host version: "); + fflush (stdout); + ignore_value (system ("uname -a")); + printf (" host CPU: "); + fflush (stdout); + ignore_value (system ("perl -n -e 'if (/^model name.*: (.*)/) { print \"$1\\n\"; exit }' /proc/cpuinfo")); + + /* Related to qemu. */ + backend = guestfs_get_backend (g); + printf (" backend: %-20s [to change set LIBGUESTFS_BACKEND]\n", + backend); + printf (" qemu: %-20s [to change set $LIBGUESTFS_HV]\n", qemu); + printf ("qemu version: "); + fflush (stdout); + if (asprintf (&cmd, "%s -version", qemu) == -1) + error (EXIT_FAILURE, errno, "asprintf"); + ignore_value (system (cmd)); + printf (" smp: %-20d [to change use --smp option]\n", + guestfs_get_smp (g)); + printf (" memsize: %-20d [to change use --memsize option]\n", + guestfs_get_memsize (g)); + + /* Related to the guest kernel. Be nice to get the guest + * kernel version here somehow (XXX). + */ + printf (" append: %-20s [to change use --append option]\n", + guestfs_get_append (g) ? : ""); +} diff --git a/utils/boot-analysis/boot-analysis-utils.h b/utils/boot-analysis/boot-analysis-utils.h new file mode 100644 index 0000000..95e4f06 --- /dev/null +++ b/utils/boot-analysis/boot-analysis-utils.h @@ -0,0 +1,36 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +#ifndef GUESTFS_BOOT_ANALYSIS_UTILS_H_ +#define GUESTFS_BOOT_ANALYSIS_UTILS_H_ + +/* Get current time, returning it in *ts. If there is a system call + * failure, this exits. + */ +extern void get_time (struct timespec *ts); + +/* Computes Y - X, returning nanoseconds. */ +extern int64_t timespec_diff (const struct timespec *x, const struct timespec *y); + +/* Display host machine and test parameters (to stdout). 'g' should + * be an open libguestfs handle. It is used for reading hv, memsize + * etc. and is not modified. + */ +extern void test_info (guestfs_h *g, int nr_test_passes); + +#endif /* GUESTFS_BOOT_ANALYSIS_UTILS_H_ */ diff --git a/utils/boot-analysis/boot-analysis.c b/utils/boot-analysis/boot-analysis.c new file mode 100644 index 0000000..b90806b --- /dev/null +++ b/utils/boot-analysis/boot-analysis.c @@ -0,0 +1,1268 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +/* Trace and analyze the appliance boot process to find out which + * steps are taking the most time. It is not part of the standard + * tests. + * + * This needs to be run on a quiet machine, so that other processes + * disturb the timing as little as possible. The program is + * completely safe to run at any time. It doesn't read or write any + * external files, and it doesn't require root. + * + * You can run it from the build directory like this: + * + * make + * ./run utils/boot-analysis/boot-analysis + * + * The way it works is roughly like this: + * + * We create a libguestfs handle and register callback handlers so we + * can see appliance messages, trace events and so on. + * + * We then launch the handle and shut it down as quickly as possible. + * + * While the handle is running, events (seen by the callback handlers) + * are written verbatim into an in-memory buffer, with timestamps. + * + * Afterwards we analyze the result using regular expressions to try + * to identify a "timeline" for the handle (eg. at what time did the + * BIOS hand control to the kernel). This analysis is done in + * 'boot-analysis-timeline.c'. + * + * The whole process is repeated across a few runs, and the final + * timeline (including statistical analysis of the variation between + * runs) gets printed. + * + * The program is very sensitive to the specific messages printed by + * BIOS/kernel/supermin/userspace, so it won't work on non-x86, and it + * will require periodic adjustment of the regular expressions in + * order to keep things up to date. + */ + +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" + +#include "boot-analysis.h" +#include "boot-analysis-utils.h" + +/* Activities taking longer than this % of the total time, except + * those flagged as LONG_ACTIVITY, are highlighted in red. + */ +#define WARNING_THRESHOLD 1.0 + +static const char *append = NULL; +static int force_colour = 0; +static int memsize = 0; +static int smp = 1; +static int verbose = 0; + +static int libvirt_pipe[2] = { -1, -1 }; +static ssize_t libvirt_pass = -1; + +/* Because there is a separate thread which collects libvirt log data, + * we must protect the pass_data struct with a mutex. This only + * applies during the data collection passes. + */ +static pthread_mutex_t pass_data_lock = PTHREAD_MUTEX_INITIALIZER; +struct pass_data pass_data[NR_TEST_PASSES]; + +size_t nr_activities; +struct activity *activities; + +static void run_test (void); +static struct event *add_event (struct pass_data *, uint64_t source); +static guestfs_h *create_handle (void); +static void set_up_event_handlers (guestfs_h *g, size_t pass); +static void libvirt_log_hack (int argc, char **argv); +static void start_libvirt_thread (size_t pass); +static void stop_libvirt_thread (void); +static void add_drive (guestfs_h *g); +static void check_pass_data (void); +static void dump_pass_data (void); +static void analyze_timeline (void); +static void dump_timeline (void); +static void print_analysis (void); +static void print_longest_to_shortest (void); +static void free_pass_data (void); +static void free_final_timeline (void); +static void ansi_green (void); +static void ansi_red (void); +static void ansi_blue (void); +static void ansi_magenta (void); +static void ansi_restore (void); + +static void +usage (int exitcode) +{ + guestfs_h *g; + int default_memsize = -1; + + g = guestfs_create (); + if (g) { + default_memsize = guestfs_get_memsize (g); + guestfs_close (g); + } + + fprintf (stderr, + "boot-analysis: Trace and analyze the appliance boot process.\n" + "Usage:\n" + " boot-analysis [--options]\n" + "Options:\n" + " --help Display this usage text and exit.\n" + " --append OPTS Append OPTS to kernel command line.\n" + " --colour Output colours, even if not a terminal.\n" + " -m MB\n" + " --memsize MB Set memory size in MB (default: %d).\n" + " --smp N Enable N virtual CPUs (default: 1).\n" + " -v|--verbose Verbose output, useful for debugging.\n", + default_memsize); + exit (exitcode); +} + +int +main (int argc, char *argv[]) +{ + enum { HELP_OPTION = CHAR_MAX + 1 }; + static const char *options = "m:v"; + static const struct option long_options[] = { + { "help", 0, 0, HELP_OPTION }, + { "append", 1, 0, 0 }, + { "color", 0, 0, 0 }, + { "colour", 0, 0, 0 }, + { "memsize", 1, 0, 'm' }, + { "libvirt-pipe-0", 1, 0, 0 }, /* see libvirt_log_hack */ + { "libvirt-pipe-1", 1, 0, 0 }, + { "smp", 1, 0, 0 }, + { "verbose", 0, 0, 'v' }, + { 0, 0, 0, 0 } + }; + int c, option_index; + + for (;;) { + c = getopt_long (argc, argv, options, long_options, &option_index); + if (c == -1) break; + + switch (c) { + case 0: /* Options which are long only. */ + if (STREQ (long_options[option_index].name, "append")) { + append = optarg; + break; + } + else if (STREQ (long_options[option_index].name, "color") || + STREQ (long_options[option_index].name, "colour")) { + force_colour = 1; + break; + } + else if (STREQ (long_options[option_index].name, "libvirt-pipe-0")) { + if (sscanf (optarg, "%d", &libvirt_pipe[0]) != 1) + error (EXIT_FAILURE, 0, + "could not parse libvirt-pipe-0 parameter: %s", optarg); + break; + } + else if (STREQ (long_options[option_index].name, "libvirt-pipe-1")) { + if (sscanf (optarg, "%d", &libvirt_pipe[1]) != 1) + error (EXIT_FAILURE, 0, + "could not parse libvirt-pipe-1 parameter: %s", optarg); + break; + } + else if (STREQ (long_options[option_index].name, "smp")) { + if (sscanf (optarg, "%d", &smp) != 1) + error (EXIT_FAILURE, 0, + "could not parse smp parameter: %s", optarg); + break; + } + fprintf (stderr, "%s: unknown long option: %s (%d)\n", + guestfs_int_program_name, long_options[option_index].name, option_index); + exit (EXIT_FAILURE); + + case 'm': + if (sscanf (optarg, "%d", &memsize) != 1) { + fprintf (stderr, "%s: could not parse memsize parameter: %s\n", + guestfs_int_program_name, optarg); + exit (EXIT_FAILURE); + } + break; + + case 'v': + verbose = 1; + break; + + case HELP_OPTION: + usage (EXIT_SUCCESS); + + default: + usage (EXIT_FAILURE); + } + } + + libvirt_log_hack (argc, argv); + + if (STRNEQ (host_cpu, "x86_64") && STRNEQ (host_cpu, "aarch64")) + fprintf (stderr, "WARNING: host_cpu != x86_64|aarch64: This program may not work or give bogus results.\n"); + + run_test (); +} + +static void +run_test (void) +{ + guestfs_h *g; + size_t i; + + printf ("Warming up the libguestfs cache ...\n"); + for (i = 0; i < NR_WARMUP_PASSES; ++i) { + g = create_handle (); + add_drive (g); + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + guestfs_close (g); + } + + printf ("Running the tests in %d passes ...\n", NR_TEST_PASSES); + for (i = 0; i < NR_TEST_PASSES; ++i) { + g = create_handle (); + set_up_event_handlers (g, i); + start_libvirt_thread (i); + add_drive (g); + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + guestfs_close (g); + stop_libvirt_thread (); + + printf (" pass %zu: %zu events collected in %" PRIi64 " ns\n", + i+1, pass_data[i].nr_events, pass_data[i].elapsed_ns); + } + + if (verbose) + dump_pass_data (); + + printf ("Analyzing the results ...\n"); + check_pass_data (); + construct_timeline (); + analyze_timeline (); + + if (verbose) + dump_timeline (); + + printf ("\n"); + g = create_handle (); + test_info (g, NR_TEST_PASSES); + guestfs_close (g); + printf ("\n"); + print_analysis (); + printf ("\n"); + printf ("Longest activities:\n"); + printf ("\n"); + print_longest_to_shortest (); + + free_pass_data (); + free_final_timeline (); +} + +static struct event * +add_event_unlocked (struct pass_data *data, uint64_t source) +{ + struct event *ret; + + data->nr_events++; + data->events = realloc (data->events, + sizeof (struct event) * data->nr_events); + if (data->events == NULL) + error (EXIT_FAILURE, errno, "realloc"); + ret = &data->events[data->nr_events-1]; + get_time (&ret->t); + ret->source = source; + ret->message = NULL; + return ret; +} + +static struct event * +add_event (struct pass_data *data, uint64_t source) +{ + struct event *ret; + + pthread_mutex_lock (&pass_data_lock); + ret = add_event_unlocked (data, source); + pthread_mutex_unlock (&pass_data_lock); + return ret; +} + +/* Common function to create the handle and set various defaults. */ +static guestfs_h * +create_handle (void) +{ + guestfs_h *g; + CLEANUP_FREE char *full_append = NULL; + + g = guestfs_create (); + if (!g) error (EXIT_FAILURE, errno, "guestfs_create"); + + if (memsize != 0) + if (guestfs_set_memsize (g, memsize) == -1) + exit (EXIT_FAILURE); + + if (smp >= 2) + if (guestfs_set_smp (g, smp) == -1) + exit (EXIT_FAILURE); + + /* This changes some details in appliance/init and enables a + * detailed trace of calls to initcall functions in the kernel. + */ + if (asprintf (&full_append, + "guestfs_boot_analysis=1 " + "ignore_loglevel initcall_debug " + "%s", + append != NULL ? append : "") == -1) + error (EXIT_FAILURE, errno, "asprintf"); + + if (guestfs_set_append (g, full_append) == -1) + exit (EXIT_FAILURE); + + return g; +} + +/* Common function to add the /dev/null drive. */ +static void +add_drive (guestfs_h *g) +{ + if (guestfs_add_drive_opts (g, "/dev/null", + GUESTFS_ADD_DRIVE_OPTS_FORMAT, "raw", + GUESTFS_ADD_DRIVE_OPTS_READONLY, 1, + -1) == -1) + exit (EXIT_FAILURE); +} + +/* Called when the handle is closed. Perform any cleanups required in + * the pass_data here. + */ +static void +close_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + + if (!data->seen_launch) + return; + + event = add_event (data, source); + event->message = strdup ("close callback"); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strdup"); + + get_time (&data->end_t); + data->elapsed_ns = timespec_diff (&data->start_t, &data->end_t); +} + +/* Called when the qemu subprocess exits. + * XXX This is never called - why? + */ +static void +subprocess_quit_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + + if (!data->seen_launch) + return; + + event = add_event (data, source); + event->message = strdup ("subprocess quit callback"); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strdup"); +} + +/* Called when the launch operation is complete (the library and the + * guestfs daemon and talking to each other). + */ +static void +launch_done_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + + if (!data->seen_launch) + return; + + event = add_event (data, source); + event->message = strdup ("launch done callback"); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strdup"); +} + +/* Trim \r (multiple) from the end of a string. */ +static void +trim_r (char *message) +{ + size_t len = strlen (message); + + while (len > 0 && message[len-1] == '\r') { + message[len-1] = '\0'; + len--; + } +} + +/* Called when we get (possibly part of) a log message (or more than + * one log message) from the appliance (which may include qemu, the + * BIOS, kernel, etc). + */ +static void +appliance_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + size_t i, len, slen; + + if (!data->seen_launch) + return; + + /* If the previous log message was incomplete, but time has moved on + * a lot, record a new log message anyway, so it gets a new + * timestamp. + */ + if (data->incomplete_log_message >= 0) { + struct timespec ts; + get_time (&ts); + if (timespec_diff (&data->events[data->incomplete_log_message].t, + &ts) >= 10000000 /* 10ms */) + data->incomplete_log_message = -1; + } + + /* If the previous log message was incomplete then we may need to + * append part of the current log message to a previous one. + */ + if (data->incomplete_log_message >= 0) { + len = buf_len; + for (i = 0; i < buf_len; ++i) { + if (buf[i] == '\n') { + len = i; + break; + } + } + + event = &data->events[data->incomplete_log_message]; + slen = strlen (event->message); + event->message = realloc (event->message, slen + len + 1); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "realloc"); + memcpy (event->message + slen, buf, len); + event->message[slen + len] = '\0'; + trim_r (event->message); + + /* Skip what we just added to the previous incomplete message. */ + buf += len; + buf_len -= len; + + if (buf_len == 0) /* still not complete, more to come! */ + return; + + /* Skip the \n in the buffer. */ + buf++; + buf_len--; + data->incomplete_log_message = -1; + } + + /* Add the event, or perhaps multiple events if the message + * contains \n characters. + */ + while (buf_len > 0) { + len = buf_len; + for (i = 0; i < buf_len; ++i) { + if (buf[i] == '\n') { + len = i; + break; + } + } + + event = add_event (data, source); + event->message = strndup (buf, len); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strndup"); + trim_r (event->message); + + /* Skip what we just added to the event. */ + buf += len; + buf_len -= len; + + if (buf_len == 0) { + /* Event is incomplete (doesn't end with \n). We'll finish it + * in the next callback. + */ + data->incomplete_log_message = event - data->events; + return; + } + + /* Skip the \n in the buffer. */ + buf++; + buf_len--; + } +} + +/* Called when we get a debug message from the library side. These + * are always delivered as complete messages. + */ +static void +library_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + + if (!data->seen_launch) + return; + + event = add_event (data, source); + event->message = strndup (buf, buf_len); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strndup"); +} + +/* Called when we get a call trace message (a libguestfs API function + * has been called or is returning). These are always delivered as + * complete messages. + */ +static void +trace_callback (guestfs_h *g, void *datavp, uint64_t source, + int eh, int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + struct pass_data *data = datavp; + struct event *event; + char *message; + + message = strndup (buf, buf_len); + if (message == NULL) + error (EXIT_FAILURE, errno, "strndup"); + + if (STREQ (message, "launch")) + data->seen_launch = 1; + + if (!data->seen_launch) { + free (message); + return; + } + + event = add_event (data, source); + event->message = message; +} + +/* Common function to set up event callbacks and record data in memory + * for a particular pass (0 <= pass < NR_TEST_PASSES). + */ +static void +set_up_event_handlers (guestfs_h *g, size_t pass) +{ + struct pass_data *data; + + assert (/* 0 <= pass && */ pass < NR_TEST_PASSES); + + data = &pass_data[pass]; + data->pass = pass; + data->nr_events = 0; + data->events = NULL; + get_time (&data->start_t); + data->incomplete_log_message = -1; + data->seen_launch = 0; + + guestfs_set_event_callback (g, close_callback, + GUESTFS_EVENT_CLOSE, 0, data); + guestfs_set_event_callback (g, subprocess_quit_callback, + GUESTFS_EVENT_SUBPROCESS_QUIT, 0, data); + guestfs_set_event_callback (g, launch_done_callback, + GUESTFS_EVENT_LAUNCH_DONE, 0, data); + guestfs_set_event_callback (g, appliance_callback, + GUESTFS_EVENT_APPLIANCE, 0, data); + guestfs_set_event_callback (g, library_callback, + GUESTFS_EVENT_LIBRARY, 0, data); + guestfs_set_event_callback (g, trace_callback, + GUESTFS_EVENT_TRACE, 0, data); + + guestfs_set_verbose (g, 1); + guestfs_set_trace (g, 1); +} + +/* libvirt debugging sucks in a number of concrete ways: + * + * - you can't get a synchronous callback from a log message + * - you can't enable logging per handle (only globally + * by setting environment variables) + * - you can't debug the daemon easily + * - it's very complex + * - it's very complex but not in ways that are practical or useful + * + * To get log messages at all, we need to create a pipe connected to a + * second thread, and when libvirt prints something to the pipe we log + * that. + * + * However that's not sufficient. Because logging is only enabled + * when libvirt examines environment variables at the start of the + * program, we need to create the pipe and then fork+exec a new + * instance of the whole program with the pipe and environment + * variables set up. + */ +static int is_libvirt_backend (guestfs_h *g); +static void *libvirt_log_thread (void *datavp); + +static void +libvirt_log_hack (int argc, char **argv) +{ + guestfs_h *g; + + g = guestfs_create (); + if (!is_libvirt_backend (g)) { + guestfs_close (g); + return; + } + guestfs_close (g); + + /* Have we set up the pipes and environment and forked yet? If not, + * do that first. + */ + if (libvirt_pipe[0] == -1 || libvirt_pipe[1] == -1) { + char log_outputs[64]; + char **new_argv; + char param1[64], param2[64]; + size_t i; + pid_t pid; + int status; + + /* Create the pipe. NB: do NOT use O_CLOEXEC since we want to pass + * this pipe into a child process. + */ + if (pipe (libvirt_pipe) == -1) + error (EXIT_FAILURE, 0, "pipe2"); + + /* Create the environment variables to enable logging in libvirt. */ + setenv ("LIBVIRT_DEBUG", "1", 1); + //setenv ("LIBVIRT_LOG_FILTERS", + // "1:qemu 1:securit 3:file 3:event 3:object 1:util", 1); + snprintf (log_outputs, sizeof log_outputs, + "1:file:/dev/fd/%d", libvirt_pipe[1]); + setenv ("LIBVIRT_LOG_OUTPUTS", log_outputs, 1); + + /* Run self again. */ + new_argv = malloc ((argc+3) * sizeof (char *)); + if (new_argv == NULL) + error (EXIT_FAILURE, errno, "malloc"); + + for (i = 0; i < (size_t) argc; ++i) + new_argv[i] = argv[i]; + + snprintf (param1, sizeof param1, "--libvirt-pipe-0=%d", libvirt_pipe[0]); + new_argv[argc] = param1; + snprintf (param2, sizeof param2, "--libvirt-pipe-1=%d", libvirt_pipe[1]); + new_argv[argc+1] = param2; + new_argv[argc+2] = NULL; + + pid = fork (); + if (pid == -1) + error (EXIT_FAILURE, errno, "fork"); + if (pid == 0) { /* Child process. */ + execvp (argv[0], new_argv); + perror ("execvp"); + _exit (EXIT_FAILURE); + } + + if (waitpid (pid, &status, 0) == -1) + error (EXIT_FAILURE, errno, "waitpid"); + if (WIFEXITED (status)) + exit (WEXITSTATUS (status)); + error (EXIT_FAILURE, 0, "unexpected exit status from process: %d", status); + } + + /* If we reach this else clause, then we have forked. Now we must + * create a thread to read events from the pipe. This must be + * constantly reading from the pipe, otherwise we will deadlock. + * During the warm-up phase we end up throwing away messages. + */ + else { + pthread_t thread; + pthread_attr_t attr; + int r; + + r = pthread_attr_init (&attr); + if (r != 0) + error (EXIT_FAILURE, r, "pthread_attr_init"); + r = pthread_attr_setdetachstate (&attr, PTHREAD_CREATE_DETACHED); + if (r != 0) + error (EXIT_FAILURE, r, "pthread_attr_setdetachstate"); + r = pthread_create (&thread, &attr, libvirt_log_thread, NULL); + if (r != 0) + error (EXIT_FAILURE, r, "pthread_create"); + pthread_attr_destroy (&attr); + } +} + +static void +start_libvirt_thread (size_t pass) +{ + /* In the non-libvirt case, this variable is ignored. */ + pthread_mutex_lock (&pass_data_lock); + libvirt_pass = pass; + pthread_mutex_unlock (&pass_data_lock); +} + +static void +stop_libvirt_thread (void) +{ + /* In the non-libvirt case, this variable is ignored. */ + pthread_mutex_lock (&pass_data_lock); + libvirt_pass = -1; + pthread_mutex_unlock (&pass_data_lock); +} + +/* The separate "libvirt thread". It loops reading debug messages + * printed by libvirt and adds them to the pass_data. + */ +static void * +libvirt_log_thread (void *arg) +{ + struct event *event; + CLEANUP_FREE char *buf = NULL; + ssize_t r; + + buf = malloc (BUFSIZ); + if (buf == NULL) + error (EXIT_FAILURE, errno, "malloc"); + + while ((r = read (libvirt_pipe[0], buf, BUFSIZ)) > 0) { + pthread_mutex_lock (&pass_data_lock); + if (libvirt_pass == -1) goto discard; + event = + add_event_unlocked (&pass_data[libvirt_pass], SOURCE_LIBVIRT); + event->message = strndup (buf, r); + if (event->message == NULL) + error (EXIT_FAILURE, errno, "strndup"); + discard: + pthread_mutex_unlock (&pass_data_lock); + } + + if (r == -1) + error (EXIT_FAILURE, errno, "libvirt_log_thread: read"); + + /* It's possible for the pipe to be closed (r == 0) if thread + * cancellation is delayed after the main thread exits, so just + * ignore that case and exit. + */ + pthread_exit (NULL); +} + +static int +is_libvirt_backend (guestfs_h *g) +{ + CLEANUP_FREE char *backend = guestfs_get_backend (g); + + return backend && + (STREQ (backend, "libvirt") || STRPREFIX (backend, "libvirt:")); +} + +/* Sanity check the collected events. */ +static void +check_pass_data (void) +{ + size_t i, j, len; + int64_t ns; + const char *message; + + for (i = 0; i < NR_TEST_PASSES; ++i) { + assert (pass_data[i].pass == i); + assert (pass_data[i].elapsed_ns > 1000); + assert (pass_data[i].nr_events > 0); + assert (pass_data[i].events != NULL); + + for (j = 0; j < pass_data[i].nr_events; ++j) { + assert (pass_data[i].events[j].t.tv_sec > 0); + if (j > 0) { + ns = timespec_diff (&pass_data[i].events[j-1].t, + &pass_data[i].events[j].t); + assert (ns >= 0); + } + assert (pass_data[i].events[j].source != 0); + message = pass_data[i].events[j].message; + assert (message != NULL); + assert (pass_data[i].events[j].source != GUESTFS_EVENT_APPLIANCE || + strchr (message, '\n') == NULL); + len = strlen (message); + assert (len == 0 || message[len-1] != '\r'); + } + } +} + +static void +print_escaped_string (const char *message) +{ + while (*message) { + if (isprint (*message)) + putchar (*message); + else + printf ("\\x%02x", (unsigned int) *message); + message++; + } +} + +/* Dump the events to stdout, if verbose is set. */ +static void +dump_pass_data (void) +{ + size_t i, j; + + for (i = 0; i < NR_TEST_PASSES; ++i) { + printf ("pass %zu\n", pass_data[i].pass); + printf (" number of events collected %zu\n", pass_data[i].nr_events); + printf (" elapsed time %" PRIi64 " ns\n", pass_data[i].elapsed_ns); + for (j = 0; j < pass_data[i].nr_events; ++j) { + int64_t ns, diff_ns; + CLEANUP_FREE char *source_str = NULL; + + ns = timespec_diff (&pass_data[i].start_t, &pass_data[i].events[j].t); + source_str = source_to_string (pass_data[i].events[j].source); + printf (" %.1fms ", ns / 1000000.0); + if (j > 0) { + diff_ns = timespec_diff (&pass_data[i].events[j-1].t, + &pass_data[i].events[j].t); + printf ("(+%.1f) ", diff_ns / 1000000.0); + } + printf ("[%s] \"", source_str); + print_escaped_string (pass_data[i].events[j].message); + printf ("\"\n"); + } + } +} + +/* Convert source to a printable string. The caller must free the + * returned string. + */ +char * +source_to_string (uint64_t source) +{ + char *ret; + + if (source == SOURCE_LIBVIRT) { + ret = strdup ("libvirt"); + if (ret == NULL) + error (EXIT_FAILURE, errno, "strdup"); + } + else + ret = guestfs_event_to_string (source); + + return ret; /* caller frees */ +} + +int +activity_exists (const char *name) +{ + size_t i; + + for (i = 0; i < nr_activities; ++i) + if (STREQ (activities[i].name, name)) + return 1; + return 0; +} + +/* Add an activity to the global list. */ +struct activity * +add_activity (const char *name, int flags) +{ + struct activity *ret; + size_t i; + + /* You shouldn't have two activities with the same name. */ + assert (!activity_exists (name)); + + nr_activities++; + activities = realloc (activities, sizeof (struct activity) * nr_activities); + if (activities == NULL) + error (EXIT_FAILURE, errno, "realloc"); + ret = &activities[nr_activities-1]; + ret->name = strdup (name); + if (ret->name == NULL) + error (EXIT_FAILURE, errno, "strdup"); + ret->flags = flags; + + for (i = 0; i < NR_TEST_PASSES; ++i) + ret->start_event[i] = ret->end_event[i] = 0; + + return ret; +} + +struct activity * +find_activity (const char *name) +{ + size_t i; + + for (i = 0; i < nr_activities; ++i) + if (STREQ (activities[i].name, name)) + return &activities[i]; + error (EXIT_FAILURE, 0, + "internal error: could not find activity '%s'", name); + /*NOTREACHED*/ + abort (); +} + +int +activity_exists_with_no_data (const char *name, size_t pass) +{ + size_t i; + + for (i = 0; i < nr_activities; ++i) + if (STREQ (activities[i].name, name) && + activities[i].start_event[pass] == 0 && + activities[i].end_event[pass] == 0) + return 1; + return 0; +} + +static int +compare_activities_by_t (const void *av, const void *bv) +{ + const struct activity *a = av; + const struct activity *b = bv; + + return a->t - b->t; +} + +/* Go through the activities, computing the start and elapsed time. */ +static void +analyze_timeline (void) +{ + struct activity *activity; + size_t i, j; + int64_t delta_ns; + + for (j = 0; j < nr_activities; ++j) { + activity = &activities[j]; + + activity->t = 0; + activity->mean = 0; + for (i = 0; i < NR_TEST_PASSES; ++i) { + delta_ns = + timespec_diff (&pass_data[i].events[0].t, + &pass_data[i].events[activity->start_event[i]].t); + activity->t += delta_ns; + + delta_ns = + timespec_diff (&pass_data[i].events[activity->start_event[i]].t, + &pass_data[i].events[activity->end_event[i]].t); + activity->mean += delta_ns; + } + + /* Divide through to get real start time and mean of each activity. */ + activity->t /= NR_TEST_PASSES; + activity->mean /= NR_TEST_PASSES; + + /* Calculate the end time of this activity. It's convenient when + * drawing the timeline for one activity to finish just before the + * next activity starts, rather than having them end and start at + * the same time, hence ``- 1'' here. + */ + activity->end_t = activity->t + activity->mean - 1; + + /* The above only calculated mean. Now we are able to + * calculate from the mean the variance and the standard + * deviation. + */ + activity->variance = 0; + for (i = 0; i < NR_TEST_PASSES; ++i) { + delta_ns = + timespec_diff (&pass_data[i].events[activity->start_event[i]].t, + &pass_data[i].events[activity->end_event[i]].t); + activity->variance += pow (delta_ns - activity->mean, 2); + } + activity->variance /= NR_TEST_PASSES; + + activity->sd = sqrt (activity->variance); + } + + /* Get the total mean elapsed time from the special "run" activity. */ + activity = find_activity ("run"); + for (j = 0; j < nr_activities; ++j) { + activities[j].percent = 100.0 * activities[j].mean / activity->mean; + + activities[j].warning = + !(activities[j].flags & LONG_ACTIVITY) && + activities[j].percent >= WARNING_THRESHOLD; + } + + /* Sort the activities by start time. */ + qsort (activities, nr_activities, sizeof (struct activity), + compare_activities_by_t); +} + +/* Dump the timeline to stdout, if verbose is set. */ +static void +dump_timeline (void) +{ + size_t i; + + for (i = 0; i < nr_activities; ++i) { + printf ("activity %zu:\n", i); + printf (" name = %s\n", activities[i].name); + printf (" start - end = %.1f - %.1f\n", + activities[i].t, activities[i].end_t); + printf (" mean elapsed = %.1f\n", activities[i].mean); + printf (" variance = %.1f\n", activities[i].variance); + printf (" s.d = %.1f\n", activities[i].sd); + printf (" percent = %.1f\n", activities[i].percent); + } +} + +static void +print_activity (struct activity *activity) +{ + if (activity->warning) ansi_red (); else ansi_green (); + print_escaped_string (activity->name); + ansi_restore (); + printf (" %.1fms ±%.1fms ", + activity->mean / 1000000, activity->sd / 1000000); + if (activity->warning) ansi_red (); else ansi_green (); + printf ("(%.1f%%) ", activity->percent); + ansi_restore (); +} + +static void +print_analysis (void) +{ + double t = -1; /* Current time. */ + /* Which columns contain activities that we are displaying now? + * -1 == unused column, else index of an activity + */ + CLEANUP_FREE ssize_t *columns = NULL; + const size_t nr_columns = nr_activities; + size_t last_free_column = 0; + + size_t i, j; + double last_t, smallest_next_t; + const double MAX_T = 1e20; + + columns = malloc (nr_columns * sizeof (ssize_t)); + if (columns == NULL) error (EXIT_FAILURE, errno, "malloc"); + for (j = 0; j < nr_columns; ++j) + columns[j] = -1; + + for (;;) { + /* Find the next significant time to display, which is a time when + * some activity started or ended. + */ + smallest_next_t = MAX_T; + for (i = 0; i < nr_activities; ++i) { + if (t < activities[i].t && activities[i].t < smallest_next_t) + smallest_next_t = activities[i].t; + else if (t < activities[i].end_t && activities[i].end_t < smallest_next_t) + smallest_next_t = activities[i].end_t; + } + if (smallest_next_t == MAX_T) + break; /* Finished. */ + + last_t = t; + t = smallest_next_t; + + /* Draw a spacer line, but only if last_t -> t is a large jump. */ + if (t - last_t >= 1000000 /* ns */) { + printf (" "); + ansi_magenta (); + for (j = 0; j < last_free_column; ++j) { + if (columns[j] >= 0 && + activities[columns[j]].end_t != last_t /* !▼ */) + printf ("│ "); + else + printf (" "); + } + ansi_restore (); + printf ("\n"); + } + + /* If there are any activities that ended before this time, drop + * them from the columns list. + */ + for (i = 0; i < nr_activities; ++i) { + if (activities[i].end_t < t) { + for (j = 0; j < nr_columns; ++j) + if (columns[j] == (ssize_t) i) { + columns[j] = -1; + break; + } + } + } + + /* May need to adjust last_free_column after previous operation. */ + while (last_free_column > 0 && columns[last_free_column-1] == -1) + last_free_column--; + + /* If there are any activities starting at this time, add them to + * the right hand end of the columns list. + */ + for (i = 0; i < nr_activities; ++i) { + if (activities[i].t == t) + columns[last_free_column++] = i; + } + + /* Draw the line. */ + ansi_blue (); + printf ("%6.1fms: ", t / 1000000); + + ansi_magenta (); + for (j = 0; j < last_free_column; ++j) { + if (columns[j] >= 0) { + if (activities[columns[j]].t == t) + printf ("▲ "); + else if (activities[columns[j]].end_t == t) + printf ("▼ "); + else + printf ("│ "); + } + else + printf (" "); + } + ansi_restore (); + + for (j = 0; j < last_free_column; ++j) { + if (columns[j] >= 0 && activities[columns[j]].t == t) /* ▲ */ + print_activity (&activities[columns[j]]); + } + + printf ("\n"); + } +} + +static int +compare_activities_pointers_by_mean (const void *av, const void *bv) +{ + const struct activity * const *a = av; + const struct activity * const *b = bv; + + return (*b)->mean - (*a)->mean; +} + +static void +print_longest_to_shortest (void) +{ + size_t i; + CLEANUP_FREE struct activity **longest; + + /* Sort the activities longest first. In order not to affect the + * global activities array, sort an array of pointers to the + * activities instead. + */ + longest = malloc (sizeof (struct activity *) * nr_activities); + for (i = 0; i < nr_activities; ++i) + longest[i] = &activities[i]; + + qsort (longest, nr_activities, sizeof (struct activity *), + compare_activities_pointers_by_mean); + + /* Display the activities, longest first. */ + for (i = 0; i < nr_activities; ++i) { + print_activity (longest[i]); + printf ("\n"); + } +} + +/* Free the non-static part of the pass_data structures. */ +static void +free_pass_data (void) +{ + size_t i, j; + + for (i = 0; i < NR_TEST_PASSES; ++i) { + for (j = 0; j < pass_data[i].nr_events; ++j) + free (pass_data[i].events[j].message); + free (pass_data[i].events); + } +} + +static void +free_final_timeline (void) +{ + size_t i; + + for (i = 0; i < nr_activities; ++i) + free (activities[i].name); + free (activities); +} + +/* Colours. */ +static void +ansi_green (void) +{ + if (force_colour || isatty (1)) + fputs ("\033[0;32m", stdout); +} + +static void +ansi_red (void) +{ + if (force_colour || isatty (1)) + fputs ("\033[1;31m", stdout); +} + +static void +ansi_blue (void) +{ + if (force_colour || isatty (1)) + fputs ("\033[1;34m", stdout); +} + +static void +ansi_magenta (void) +{ + if (force_colour || isatty (1)) + fputs ("\033[1;35m", stdout); +} + +static void +ansi_restore (void) +{ + if (force_colour || isatty (1)) + fputs ("\033[0m", stdout); +} diff --git a/utils/boot-analysis/boot-analysis.h b/utils/boot-analysis/boot-analysis.h new file mode 100644 index 0000000..a07f12e --- /dev/null +++ b/utils/boot-analysis/boot-analysis.h @@ -0,0 +1,102 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +#ifndef GUESTFS_BOOT_ANALYSIS_H_ +#define GUESTFS_BOOT_ANALYSIS_H_ + +#define NR_WARMUP_PASSES 3 +#define NR_TEST_PASSES 5 + +/* Per-pass data collected. */ +struct pass_data { + size_t pass; + struct timespec start_t; + struct timespec end_t; + int64_t elapsed_ns; + + /* Array of timestamped events. */ + size_t nr_events; + struct event *events; + + /* Was the previous appliance log message incomplete? If so, this + * contains the index of that incomplete message in the events + * array. + */ + ssize_t incomplete_log_message; + + /* Have we seen the launch event yet? We don't record events until + * this one has been received. This makes it easy to base the + * timeline at event 0. + */ + int seen_launch; +}; + +/* The 'source' field in the event is a guestfs event + * (GUESTFS_EVENT_*). We also wish to encode libvirt as a source, so + * we use a magic/impossible value for that here. Note that events + * are bitmasks, and normally no more than one bit may be set. + */ +#define SOURCE_LIBVIRT ((uint64_t)~0) +extern char *source_to_string (uint64_t source); + +struct event { + struct timespec t; + uint64_t source; + char *message; +}; + +extern struct pass_data pass_data[NR_TEST_PASSES]; + +/* The final timeline consisting of various activities starting and + * ending. We're interested in when the activities start, and how + * long they take (mean, variance, standard deviation of length). + */ +struct activity { + char *name; /* Name of this activity. */ + int flags; +#define LONG_ACTIVITY 1 /* Expected to take a long time. */ + + /* For each pass, record the actual start & end events of this + * activity. + */ + size_t start_event[NR_TEST_PASSES]; + size_t end_event[NR_TEST_PASSES]; + + double t; /* Start (ns offset). */ + double end_t; /* t + mean - 1 */ + + /* Length of this activity. */ + double mean; /* Mean time elapsed (ns). */ + double variance; /* Variance. */ + double sd; /* Standard deviation. */ + double percent; /* Percent of total elapsed time. */ + + int warning; /* Appears in red. */ +}; + +extern size_t nr_activities; +extern struct activity *activities; + +extern int activity_exists (const char *name); +extern struct activity *add_activity (const char *name, int flags); +extern struct activity *find_activity (const char *name); +extern int activity_exists_with_no_data (const char *name, size_t pass); + +extern void construct_timeline (void); + +#endif /* GUESTFS_BOOT_ANALYSIS_H_ */ diff --git a/utils/boot-benchmark/Makefile.am b/utils/boot-benchmark/Makefile.am new file mode 100644 index 0000000..429832a --- /dev/null +++ b/utils/boot-benchmark/Makefile.am @@ -0,0 +1,44 @@ +# libguestfs +# Copyright (C) 2011-2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +# Safety and liveness tests of components that libguestfs depends upon +# (not of libguestfs itself). Mainly this is for qemu and the kernel. +# This test is the first to run. + +include $(top_srcdir)/subdir-rules.mk + +noinst_PROGRAMS = boot-benchmark + +boot_benchmark_SOURCES = \ + boot-benchmark.c \ + ../boot-analysis/boot-analysis-utils.c \ + ../boot-analysis/boot-analysis-utils.h +boot_benchmark_CPPFLAGS = \ + -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ + -I$(top_srcdir)/src -I$(top_builddir)/src \ + -I$(top_srcdir)/utils/boot-analysis +boot_benchmark_CFLAGS = \ + $(WARN_CFLAGS) $(WERROR_CFLAGS) +boot_benchmark_LDADD = \ + $(top_builddir)/src/libutils.la \ + $(top_builddir)/src/libguestfs.la \ + $(LIBXML2_LIBS) \ + $(LTLIBINTL) \ + $(top_builddir)/gnulib/lib/libgnu.la \ + -lm + +EXTRA_DIST = boot-benchmark-range.pl diff --git a/utils/boot-benchmark/boot-benchmark-range.pl b/utils/boot-benchmark/boot-benchmark-range.pl new file mode 100755 index 0000000..b69a835 --- /dev/null +++ b/utils/boot-benchmark/boot-benchmark-range.pl @@ -0,0 +1,240 @@ +#!/usr/bin/env perl +# Copyright (C) 2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +use warnings; +use strict; + +use Pod::Usage; +use Getopt::Long; + +=head1 NAME + +boot-benchmark-range.pl - Benchmark libguestfs across a range of commits +from another project + +=head1 SYNOPSIS + + LIBGUESTFS_BACKEND=direct \ + LIBGUESTFS_HV=/path/to/qemu/x86_64-softmmu/qemu-system-x86_64 \ + ./run \ + utils/boot-benchmark/boot-benchmark-range.pl /path/to/qemu HEAD~50..HEAD + +=head1 + +Run F across a range of commits +in another project. This is useful for finding performance +regressions in other programs such as qemu or the Linux kernel which +might be affecting libguestfs. + +For example, suppose you suspect there has been a performance +regression in qemu, somewhere between C. You could run +the script like this: + + LIBGUESTFS_BACKEND=direct \ + LIBGUESTFS_HV=/path/to/qemu/x86_64-softmmu/qemu-system-x86_64 \ + ./run \ + utils/boot-benchmark/boot-benchmark-range.pl /path/to/qemu HEAD~50..HEAD + +where F is the path to the qemu git repository. + +The output is a list of the qemu commits, annotated by the benchmark +time and some other information about how the time compares to the +previous commit. + +You should run these tests on an unloaded machine. In particular +running a desktop environment, web browser and so on can make the +benchmarks useless. + +=head1 OPTIONS + +=over 4 + +=cut + +my $help; + +=item B<--help> + +Display brief help. + +=cut + +my $man; + +=item B<--man> + +Display full documentation (man page). + +=cut + +my $benchmark_command; + +=item B<--benchmark> C + +Set the name of the benchmark to run. You only need to use this if +the script cannot find the right path to the libguestfs +F program. By default the script +looks for this file in the same directory as its executable. + +=cut + +my $make_command = "make"; + +=item B<--make> C + +Set the command used to build the other project. The default is +to run C. + +If the command fails, then the commit is skipped. + +=back + +=cut + +# Clean up the program name. +my $progname = $0; +$progname =~ s{.*/}{}; + +# Parse options. +GetOptions ("help|?" => \$help, + "man" => \$man, + "benchmark=s" => \$benchmark_command, + "make=s" => \$make_command, + ) or pod2usage (2); +pod2usage (-exitval => 0) if $help; +pod2usage (-exitval => 0, -verbose => 2) if $man; + +die "$progname: missing argument: requires path to git repository and range of commits\n" unless @ARGV == 2; + +my $dir = $ARGV[0]; +my $range = $ARGV[1]; + +die "$progname: $dir is not a git repository\n" + unless -d $dir && -d "$dir/.git"; + +sub silently_run +{ + open my $saveout, ">&STDOUT"; + open my $saveerr, ">&STDERR"; + open STDOUT, ">/dev/null"; + open STDERR, ">/dev/null"; + my $ret = system (@_); + open STDOUT, ">&", $saveout; + open STDERR, ">&", $saveerr; + return $ret; +} + +# Find the benchmark program and check it works. +unless (defined $benchmark_command) { + $benchmark_command = $0; + $benchmark_command =~ s{/[^/]+$}{}; + $benchmark_command .= "/boot-benchmark"; + + my $r = silently_run ("$benchmark_command", "--help"); + die "$progname: cannot locate boot-benchmark program, try using --benchmark\n" unless $r == 0; +} + +# Get the top-most commit from the remote, and restore it on exit. +my $top_commit = `git -C '$dir' rev-parse HEAD`; +chomp $top_commit; + +sub checkout +{ + my $sha = shift; + my $ret = silently_run ("git", "-C", $dir, "checkout", $sha); + return $ret; +} + +END { + checkout ($top_commit); +} + +# Get the range of commits and log messages. +my @range = (); +open RANGE, "git -C '$dir' log --reverse --oneline $range |" or die; +while () { + if (m/^([0-9a-f]+) (.*)/) { + my $sha = $1; + my $msg = $2; + push @range, [ $sha, $msg ]; + } +} +close RANGE or die; + +# Run the test. +my $prev_ms; +foreach (@range) { + my ($sha, $msg) = @$_; + my $r; + + print "\n"; + print "$sha $msg\n"; + + # Checkout this commit in the other repo. + $r = checkout ($sha); + if ($r != 0) { + print "git checkout failed\n"; + next; + } + + # Build the repo, silently. + $r = silently_run ("cd $dir && $make_command"); + if ($r != 0) { + print "build failed\n"; + next; + } + + # Run the benchmark program and get the timing. + my ($time_ms, $time_str); + open BENCHMARK, "$benchmark_command | grep '^Result:' |" or die; + while () { + die unless m/^Result: (([\d.]+)ms ±[\d.]+ms)/; + $time_ms = $2; + $time_str = $1; + } + close BENCHMARK; + + print "\t", $time_str; + if (defined $prev_ms) { + if ($prev_ms > $time_ms) { + my $pc = 100 * ($prev_ms-$time_ms) / $time_ms; + if ($pc >= 1) { + printf (" ↑ improves performance by %0.1f%%", $pc); + } + } elsif ($prev_ms < $time_ms) { + my $pc = 100 * ($time_ms-$prev_ms) / $prev_ms; + if ($pc >= 1) { + printf (" ↓ degrades performance by %0.1f%%", $pc); + } + } + } + print "\n"; + $prev_ms = $time_ms; +} + +=head1 SEE ALSO + +L, +L. + +=head1 AUTHOR + +Richard W.M. Jones. + +=head1 COPYRIGHT + +Copyright (C) 2016 Red Hat Inc. diff --git a/utils/boot-benchmark/boot-benchmark.c b/utils/boot-benchmark/boot-benchmark.c new file mode 100644 index 0000000..0508ee9 --- /dev/null +++ b/utils/boot-benchmark/boot-benchmark.c @@ -0,0 +1,225 @@ +/* libguestfs + * Copyright (C) 2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +/* Benchmark the time taken to boot the libguestfs appliance. */ + +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" + +#include "boot-analysis-utils.h" + +#define NR_WARMUP_PASSES 3 +#define NR_TEST_PASSES 10 + +static const char *append = NULL; +static int memsize = 0; +static int smp = 1; + +static void run_test (void); +static guestfs_h *create_handle (void); +static void add_drive (guestfs_h *g); + +static void +usage (int exitcode) +{ + guestfs_h *g; + int default_memsize = -1; + + g = guestfs_create (); + if (g) { + default_memsize = guestfs_get_memsize (g); + guestfs_close (g); + } + + fprintf (stderr, + "boot-benchmark: Benchmark the time taken to boot the libguestfs appliance.\n" + "Usage:\n" + " boot-benchmark [--options]\n" + "Options:\n" + " --help Display this usage text and exit.\n" + " --append OPTS Append OPTS to kernel command line.\n" + " -m MB\n" + " --memsize MB Set memory size in MB (default: %d).\n" + " --smp N Enable N virtual CPUs (default: 1).\n", + default_memsize); + exit (exitcode); +} + +int +main (int argc, char *argv[]) +{ + enum { HELP_OPTION = CHAR_MAX + 1 }; + static const char *options = "m:"; + static const struct option long_options[] = { + { "help", 0, 0, HELP_OPTION }, + { "append", 1, 0, 0 }, + { "memsize", 1, 0, 'm' }, + { "smp", 1, 0, 0 }, + { 0, 0, 0, 0 } + }; + int c, option_index; + + for (;;) { + c = getopt_long (argc, argv, options, long_options, &option_index); + if (c == -1) break; + + switch (c) { + case 0: /* Options which are long only. */ + if (STREQ (long_options[option_index].name, "append")) { + append = optarg; + break; + } + else if (STREQ (long_options[option_index].name, "smp")) { + if (sscanf (optarg, "%d", &smp) != 1) { + fprintf (stderr, "%s: could not parse smp parameter: %s\n", + guestfs_int_program_name, optarg); + exit (EXIT_FAILURE); + } + break; + } + fprintf (stderr, "%s: unknown long option: %s (%d)\n", + guestfs_int_program_name, long_options[option_index].name, option_index); + exit (EXIT_FAILURE); + + case 'm': + if (sscanf (optarg, "%d", &memsize) != 1) { + fprintf (stderr, "%s: could not parse memsize parameter: %s\n", + guestfs_int_program_name, optarg); + exit (EXIT_FAILURE); + } + break; + + case HELP_OPTION: + usage (EXIT_SUCCESS); + + default: + usage (EXIT_FAILURE); + } + } + + run_test (); +} + +static void +run_test (void) +{ + guestfs_h *g; + size_t i; + int64_t ns[NR_TEST_PASSES]; + double mean; + double variance; + double sd; + + printf ("Warming up the libguestfs cache ...\n"); + for (i = 0; i < NR_WARMUP_PASSES; ++i) { + g = create_handle (); + add_drive (g); + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + guestfs_close (g); + } + + printf ("Running the tests ...\n"); + for (i = 0; i < NR_TEST_PASSES; ++i) { + struct timespec start_t, end_t; + + g = create_handle (); + add_drive (g); + get_time (&start_t); + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + guestfs_close (g); + get_time (&end_t); + + ns[i] = timespec_diff (&start_t, &end_t); + } + + /* Calculate the mean. */ + mean = 0; + for (i = 0; i < NR_TEST_PASSES; ++i) + mean += ns[i]; + mean /= NR_TEST_PASSES; + + /* Calculate the variance and standard deviation. */ + variance = 0; + for (i = 0; i < NR_TEST_PASSES; ++i) + variance = pow (ns[i] - mean, 2); + variance /= NR_TEST_PASSES; + sd = sqrt (variance); + + /* Print the test parameters. */ + printf ("\n"); + g = create_handle (); + test_info (g, NR_TEST_PASSES); + guestfs_close (g); + + /* Print the result. */ + printf ("\n"); + printf ("Result: %.1fms ±%.1fms\n", mean / 1000000, sd / 1000000); +} + +/* Common function to create the handle and set various defaults. */ +static guestfs_h * +create_handle (void) +{ + guestfs_h *g; + CLEANUP_FREE char *full_append = NULL; + + g = guestfs_create (); + if (!g) error (EXIT_FAILURE, errno, "guestfs_create"); + + if (memsize != 0) + if (guestfs_set_memsize (g, memsize) == -1) + exit (EXIT_FAILURE); + + if (smp >= 2) + if (guestfs_set_smp (g, smp) == -1) + exit (EXIT_FAILURE); + + if (append != NULL) + if (guestfs_set_append (g, full_append) == -1) + exit (EXIT_FAILURE); + + return g; +} + +/* Common function to add the /dev/null drive. */ +static void +add_drive (guestfs_h *g) +{ + if (guestfs_add_drive_opts (g, "/dev/null", + GUESTFS_ADD_DRIVE_OPTS_FORMAT, "raw", + GUESTFS_ADD_DRIVE_OPTS_READONLY, 1, + -1) == -1) + exit (EXIT_FAILURE); +} diff --git a/utils/qemu-boot/Makefile.am b/utils/qemu-boot/Makefile.am new file mode 100644 index 0000000..d4716cc --- /dev/null +++ b/utils/qemu-boot/Makefile.am @@ -0,0 +1,39 @@ +# libguestfs +# Copyright (C) 2011-2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +include $(top_srcdir)/subdir-rules.mk + +noinst_PROGRAMS = qemu-boot + +qemu_boot_SOURCES = \ + ../../df/estimate-max-threads.c \ + ../../df/estimate-max-threads.h \ + qemu-boot.c +qemu_boot_CPPFLAGS = \ + -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ + -I$(top_srcdir)/src -I$(top_builddir)/src \ + -I$(top_srcdir)/df +qemu_boot_CFLAGS = \ + -pthread \ + $(WARN_CFLAGS) $(WERROR_CFLAGS) +qemu_boot_LDADD = \ + $(top_builddir)/src/libutils.la \ + $(top_builddir)/src/libguestfs.la \ + $(LIBXML2_LIBS) \ + $(LIBVIRT_LIBS) \ + $(LTLIBINTL) \ + $(top_builddir)/gnulib/lib/libgnu.la diff --git a/utils/qemu-boot/qemu-boot.c b/utils/qemu-boot/qemu-boot.c new file mode 100644 index 0000000..336c26e --- /dev/null +++ b/utils/qemu-boot/qemu-boot.c @@ -0,0 +1,362 @@ +/* libguestfs + * Copyright (C) 2014-2016 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +/* Ancient libguestfs had a script called test-bootbootboot which just + * booted up the appliance in a loop. This was necessary back in the + * bad old days when qemu was not very reliable. This is the + * spiritual successor of that script, designed to find bugs in + * aarch64 KVM. You can control the number of boots that are done and + * the amount of parallelism. + */ + +#include + +#include +#include +#include +#include +#include +#include +#include + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" +#include "estimate-max-threads.h" + +#define MIN(a,b) ((a)<(b)?(a):(b)) + +/* Maximum number of threads we would ever run. Note this should not + * be > 20, unless libvirt is modified to increase the maximum number + * of clients. User can override this limit using -P. + */ +#define MAX_THREADS 12 + +static size_t n; /* Number of qemu processes to run in total. */ +static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER; + +static int ignore_errors = 0; +static const char *log_template = NULL; +static size_t log_file_size; +static int trace = 0; +static int verbose = 0; + +/* Events captured by the --log option. */ +static const uint64_t event_bitmask = + GUESTFS_EVENT_LIBRARY | + GUESTFS_EVENT_WARNING | + GUESTFS_EVENT_APPLIANCE | + GUESTFS_EVENT_TRACE; + +struct thread_data { + int thread_num; + int r; +}; + +static void *start_thread (void *thread_data_vp); +static void message_callback (guestfs_h *g, void *opaque, uint64_t event, int event_handle, int flags, const char *buf, size_t buf_len, const uint64_t *array, size_t array_len); + +static void +usage (int exitcode) +{ + fprintf (stderr, + "qemu-boot: A program for repeatedly running the libguestfs appliance.\n" + "qemu-boot [-i] [--log output.%%] [-P ] -n \n" + " -i Ignore errors\n" + " --log \n" + " Write per-appliance logs to file (%% in name replaced by boot number)\n" + " -P Set number of parallel threads\n" + " (default is based on the amount of free memory)\n" + " -n Set number of appliances to run before exiting\n" + " -v Verbose appliance\n" + " -x Enable libguestfs tracing\n"); + exit (exitcode); +} + +int +main (int argc, char *argv[]) +{ + enum { HELP_OPTION = CHAR_MAX + 1 }; + static const char options[] = "in:P:vx"; + static const struct option long_options[] = { + { "help", 0, 0, HELP_OPTION }, + { "ignore", 0, 0, 'i' }, + { "log", 1, 0, 0 }, + { "number", 1, 0, 'n' }, + { "processes", 1, 0, 'P' }, + { "trace", 0, 0, 'x' }, + { "verbose", 0, 0, 'v' }, + { 0, 0, 0, 0 } + }; + size_t P = 0, i, errors; + int c, option_index; + int err; + void *status; + + for (;;) { + c = getopt_long (argc, argv, options, long_options, &option_index); + if (c == -1) break; + + switch (c) { + case 0: + /* Options which are long only. */ + if (STREQ (long_options[option_index].name, "log")) { + log_template = optarg; + log_file_size = strlen (log_template); + for (i = 0; i < strlen (log_template); ++i) { + if (log_template[i] == '%') + log_file_size += 64; + } + } + else { + fprintf (stderr, "%s: unknown long option: %s (%d)\n", + guestfs_int_program_name, long_options[option_index].name, option_index); + exit (EXIT_FAILURE); + } + break; + + case 'i': + ignore_errors = 1; + break; + + case 'n': + if (sscanf (optarg, "%zu", &n) != 1 || n == 0) { + fprintf (stderr, "%s: -n option not numeric and greater than 0\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + break; + + case 'P': + if (sscanf (optarg, "%zu", &P) != 1) { + fprintf (stderr, "%s: -P option not numeric\n", guestfs_int_program_name); + exit (EXIT_FAILURE); + } + break; + + case 'v': + verbose = 1; + break; + + case 'x': + trace = 1; + break; + + case HELP_OPTION: + usage (EXIT_SUCCESS); + + default: + usage (EXIT_FAILURE); + } + } + + if (n == 0) { + fprintf (stderr, + "%s: must specify number of processes to run (-n option)\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + if (optind != argc) { + fprintf (stderr, "%s: extra arguments found on the command line\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + /* Calculate the number of threads to use. */ + if (P > 0) + P = MIN (n, P); + else + P = MIN (n, MIN (MAX_THREADS, estimate_max_threads ())); + + /* Start the worker threads. */ + struct thread_data thread_data[P]; + pthread_t threads[P]; + + for (i = 0; i < P; ++i) { + thread_data[i].thread_num = i; + err = pthread_create (&threads[i], NULL, start_thread, &thread_data[i]); + if (err != 0) { + fprintf (stderr, "%s: pthread_create[%zu]: %s\n", + guestfs_int_program_name, i, strerror (err)); + exit (EXIT_FAILURE); + } + } + + /* Wait for the threads to exit. */ + errors = 0; + for (i = 0; i < P; ++i) { + err = pthread_join (threads[i], &status); + if (err != 0) { + fprintf (stderr, "%s: pthread_join[%zu]: %s\n", + guestfs_int_program_name, i, strerror (err)); + errors++; + } + if (*(int *)status == -1) + errors++; + } + + exit (errors == 0 ? EXIT_SUCCESS : EXIT_FAILURE); +} + +/* Worker thread. */ +static void * +start_thread (void *thread_data_vp) +{ + struct thread_data *thread_data = thread_data_vp; + int quit = 0; + int err; + size_t i; + guestfs_h *g; + unsigned errors = 0; + char id[64]; + + for (;;) { + CLEANUP_FREE char *log_file = NULL; + CLEANUP_FCLOSE FILE *log_fp = NULL; + + /* Take the next process. */ + err = pthread_mutex_lock (&mutex); + if (err != 0) { + fprintf (stderr, "%s: pthread_mutex_lock: %s", + guestfs_int_program_name, strerror (err)); + goto error; + } + + i = n; + if (i > 0) { + printf ("%zu to go ... \r", n); + fflush (stdout); + + n--; + } + else + quit = 1; + + err = pthread_mutex_unlock (&mutex); + if (err != 0) { + fprintf (stderr, "%s: pthread_mutex_unlock: %s", + guestfs_int_program_name, strerror (err)); + goto error; + } + + if (quit) /* Work finished. */ + break; + + g = guestfs_create (); + if (g == NULL) { + perror ("guestfs_create"); + errors++; + if (!ignore_errors) + goto error; + } + + /* Only if using --log, set up a callback. See examples/debug-logging.c */ + if (log_template != NULL) { + size_t j, k; + + log_file = malloc (log_file_size + 1); + if (log_file == NULL) abort (); + for (j = 0, k = 0; j < strlen (log_template); ++j) { + if (log_template[j] == '%') { + snprintf (&log_file[k], log_file_size - k, "%zu", i); + k += strlen (&log_file[k]); + } + else + log_file[k++] = log_template[j]; + } + log_file[k] = '\0'; + log_fp = fopen (log_file, "w"); + if (log_fp == NULL) { + perror (log_file); + abort (); + } + guestfs_set_event_callback (g, message_callback, + event_bitmask, 0, log_fp); + } + + snprintf (id, sizeof id, "%zu", i); + guestfs_set_identifier (g, id); + + guestfs_set_trace (g, trace); + guestfs_set_verbose (g, verbose); + + if (guestfs_add_drive_ro (g, "/dev/null") == -1) { + errors++; + if (!ignore_errors) + goto error; + } + + if (guestfs_launch (g) == -1) { + errors++; + if (!ignore_errors) + goto error; + } + + if (guestfs_shutdown (g) == -1) { + errors++; + if (!ignore_errors) + goto error; + } + + guestfs_close (g); + } + + if (errors > 0) { + fprintf (stderr, "%s: thread %d: %u errors were ignored\n", + guestfs_int_program_name, thread_data->thread_num, errors); + goto error; + } + + thread_data->r = 0; + return &thread_data->r; + + error: + thread_data->r = -1; + return &thread_data->r; +} + +/* If using --log, this is called to write messages to the log file. */ +static void +message_callback (guestfs_h *g, void *opaque, + uint64_t event, int event_handle, + int flags, + const char *buf, size_t buf_len, + const uint64_t *array, size_t array_len) +{ + FILE *fp = opaque; + + if (buf_len > 0) { + CLEANUP_FREE char *msg = strndup (buf, buf_len); + + switch (event) { + case GUESTFS_EVENT_APPLIANCE: + fprintf (fp, "%s", msg); + break; + case GUESTFS_EVENT_LIBRARY: + fprintf (fp, "libguestfs: %s\n", msg); + break; + case GUESTFS_EVENT_WARNING: + fprintf (fp, "libguestfs: warning: %s\n", msg); + break; + case GUESTFS_EVENT_TRACE: + fprintf (fp, "libguestfs: trace: %s\n", msg); + break; + } + fflush (fp); + } +} diff --git a/utils/qemu-speed-test/Makefile.am b/utils/qemu-speed-test/Makefile.am new file mode 100644 index 0000000..bf1c915 --- /dev/null +++ b/utils/qemu-speed-test/Makefile.am @@ -0,0 +1,36 @@ +# libguestfs +# Copyright (C) 2011-2016 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +include $(top_srcdir)/subdir-rules.mk + +noinst_PROGRAMS = qemu-speed-test + +qemu_speed_test_SOURCES = \ + qemu-speed-test.c +qemu_speed_test_CPPFLAGS = \ + -I$(top_srcdir)/gnulib/lib -I$(top_builddir)/gnulib/lib \ + -I$(top_srcdir)/src -I$(top_builddir)/src \ + -I$(top_srcdir)/df +qemu_speed_test_CFLAGS = \ + $(WARN_CFLAGS) $(WERROR_CFLAGS) +qemu_speed_test_LDADD = \ + $(top_builddir)/src/libutils.la \ + $(top_builddir)/src/libguestfs.la \ + $(LIBXML2_LIBS) \ + $(LIBVIRT_LIBS) \ + $(LTLIBINTL) \ + $(top_builddir)/gnulib/lib/libgnu.la diff --git a/utils/qemu-speed-test/qemu-speed-test.c b/utils/qemu-speed-test/qemu-speed-test.c new file mode 100644 index 0000000..d5e34c3 --- /dev/null +++ b/utils/qemu-speed-test/qemu-speed-test.c @@ -0,0 +1,480 @@ +/* libguestfs + * Copyright (C) 2014 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + */ + +/* Test the speed of various qemu features. Currently tested are: + * - virtio-serial upload + * - virtio-serial download + * - block device read + * - block device write + * More to come in future. + */ + +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "guestfs.h" +#include "guestfs-internal-frontend.h" + +static void test_virtio_serial (void); +static void test_block_device (void); + +/* Which tests are enabled? -- All by default. */ +static int virtio_serial_upload = 1; +static int virtio_serial_download = 1; +static int block_device_write = 1; +static int block_device_read = 1; + +static int max_time_override = 0; + +static void +reset_default_tests (int *flag) +{ + if (*flag) { + virtio_serial_upload = 0; + virtio_serial_download = 0; + block_device_write = 0; + block_device_read = 0; + *flag = 0; + } +} + +static void +usage (int exitcode) +{ + fprintf (stderr, + "qemu-speed-test: Test the speed of qemu features.\n" + "\n" + "To run all tests (recommended), do:\n" + " qemu-speed-test\n" + "\n" + "To run only specific tests, do:\n" + " qemu-speed-test --option [--option ...]\n" + "where the test options are:\n" + " --virtio-serial-upload\n" + " --virtio-serial-download\n" + " --block-device-write\n" + " --block-device-read\n" + "\n" + "Other options:\n" + " --help Display help output and exit\n" + " -t | --time= Set max length of test in seconds\n" + ); + exit (exitcode); +} + +int +main (int argc, char *argv[]) +{ + enum { HELP_OPTION = CHAR_MAX + 1 }; + static const char options[] = "t:"; + static const struct option long_options[] = { + { "help", 0, 0, HELP_OPTION }, + { "time", 1, 0, 't' }, + + /* Tests. */ + { "virtio-serial-upload", 0, 0, 0 }, + { "virtio-serial-download", 0, 0, 0 }, + { "block-device-write", 0, 0, 0 }, + { "block-device-read", 0, 0, 0 }, + + { 0, 0, 0, 0 } + }; + int c, option_index; + int reset_flag = 1; + + for (;;) { + c = getopt_long (argc, argv, options, long_options, &option_index); + if (c == -1) break; + + switch (c) { + case 0: + /* Options which are long only. */ + if (STREQ (long_options[option_index].name, "virtio-serial-upload")) { + reset_default_tests (&reset_flag); + virtio_serial_upload = 1; + } + else if (STREQ (long_options[option_index].name, "virtio-serial-download")) { + reset_default_tests (&reset_flag); + virtio_serial_download = 1; + } + else if (STREQ (long_options[option_index].name, "block-device-write")) { + reset_default_tests (&reset_flag); + block_device_write = 1; + } + else if (STREQ (long_options[option_index].name, "block-device-read")) { + reset_default_tests (&reset_flag); + block_device_read = 1; + } + else { + fprintf (stderr, "%s: unknown long option: %s (%d)\n", + guestfs_int_program_name, long_options[option_index].name, option_index); + exit (EXIT_FAILURE); + } + break; + + case 't': + if (sscanf (optarg, "%d", &max_time_override) != 1 || + max_time_override < 0) { + fprintf (stderr, "%s: -t: argument is not a positive integer\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + break; + + case HELP_OPTION: + usage (EXIT_SUCCESS); + + default: + usage (EXIT_FAILURE); + } + } + + if (optind != argc) { + fprintf (stderr, "%s: extra arguments found on the command line\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + test_virtio_serial (); + test_block_device (); + + exit (EXIT_SUCCESS); +} + +static void +print_rate (const char *msg, int64_t rate) +{ + printf ("%-40s %" PRIi64 " bytes/sec (%" PRIi64 " Mbytes/sec)\n", + msg, rate, rate / 1024 / 1024); + fflush (stdout); +} + +/* The maximum time we will spend running the test (seconds). */ +#define TEST_SERIAL_MAX_TIME 30 + +/* The maximum amount of data to copy. You can safely make this very + * large because it's only making sparse files. + */ +#define TEST_SERIAL_MAX_SIZE \ + (INT64_C(1024) * INT64_C(1024) * INT64_C(1024) * INT64_C(1024)) + +static guestfs_h *g; +static struct timeval start; +static const char *operation; +static int64_t rate; + +static void +stop_transfer (int sig) +{ + guestfs_user_cancel (g); +} + +/* Compute Y - X and return the result in milliseconds. + * Approximately the same as this code: + * http://www.mpp.mpg.de/~huber/util/timevaldiff.c + */ +static int64_t +timeval_diff (const struct timeval *x, const struct timeval *y) +{ + int64_t msec; + + msec = (y->tv_sec - x->tv_sec) * 1000; + msec += (y->tv_usec - x->tv_usec) / 1000; + return msec; +} + +static void +progress_cb (guestfs_h *g, void *vp, uint64_t event, + int eh, int flags, + const char *buf, size_t buflen, + const uint64_t *array, size_t arraylen) +{ + uint64_t transferred; + struct timeval now; + int64_t millis; + + assert (event == GUESTFS_EVENT_PROGRESS); + assert (arraylen >= 4); + + gettimeofday (&now, NULL); + + /* Bytes transferred. */ + transferred = array[2]; + + /* Calculate the speed of the upload or download. */ + millis = timeval_diff (&start, &now); + assert (millis >= 0); + + if (millis != 0) { + rate = 1000 * transferred / millis; + printf ("%s: %" PRIi64 " bytes/sec \r", + operation, rate); + fflush (stdout); + } +} + +static void +test_virtio_serial (void) +{ + int fd, r, eh; + char tmpfile[] = "/tmp/speedtestXXXXXX"; + struct sigaction sa, old_sa; + + if (!virtio_serial_upload && !virtio_serial_download) + return; + + /* Create a sparse file. We could upload from /dev/zero, but we + * won't get progress messages because libguestfs tests if the + * source file is a regular file. + */ + fd = mkstemp (tmpfile); + if (fd == -1) { + perror ("mkstemp"); + exit (EXIT_FAILURE); + } + if (ftruncate (fd, TEST_SERIAL_MAX_SIZE) == -1) { + perror ("ftruncate"); + exit (EXIT_FAILURE); + } + if (close (fd) == -1) { + perror ("close"); + exit (EXIT_FAILURE); + } + + g = guestfs_create (); + if (!g) { + perror ("guestfs_create"); + exit (EXIT_FAILURE); + } + + if (guestfs_add_drive_scratch (g, INT64_C (100*1024*1024), -1) == -1) + exit (EXIT_FAILURE); + + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + + /* Make and mount a filesystem which will be used by the download test. */ + if (guestfs_mkfs (g, "ext4", "/dev/sda") == -1) + exit (EXIT_FAILURE); + if (guestfs_mount (g, "/dev/sda", "/") == -1) + exit (EXIT_FAILURE); + + /* Time out the upload after TEST_SERIAL_MAX_TIME seconds have passed. */ + memset (&sa, 0, sizeof sa); + sa.sa_handler = stop_transfer; + sa.sa_flags = SA_RESTART; + sigaction (SIGALRM, &sa, &old_sa); + + /* Get progress messages, which will tell us how much data has been + * transferred. + */ + eh = guestfs_set_event_callback (g, progress_cb, GUESTFS_EVENT_PROGRESS, + 0, NULL); + if (eh == -1) + exit (EXIT_FAILURE); + + if (virtio_serial_upload) { + gettimeofday (&start, NULL); + rate = -1; + operation = "upload"; + alarm (max_time_override > 0 ? max_time_override : TEST_SERIAL_MAX_TIME); + + /* For the upload test, upload the sparse file to /dev/null in the + * appliance. Hopefully this is mostly testing just virtio-serial. + */ + guestfs_push_error_handler (g, NULL, NULL); + r = guestfs_upload (g, tmpfile, "/dev/null"); + alarm (0); + unlink (tmpfile); + guestfs_pop_error_handler (g); + + /* It's possible that the upload will finish before the alarm fires, + * or that the upload will be stopped by the alarm. + */ + if (r == -1 && guestfs_last_errno (g) != EINTR) { + fprintf (stderr, + "%s: expecting upload command to return EINTR\n%s\n", + guestfs_int_program_name, guestfs_last_error (g)); + exit (EXIT_FAILURE); + } + + if (rate == -1) { + rate_error: + fprintf (stderr, "%s: internal error: progress callback was not called! (r=%d, errno=%d)\n", + guestfs_int_program_name, + r, guestfs_last_errno (g)); + exit (EXIT_FAILURE); + } + + print_rate ("virtio-serial upload rate:", rate); + } + + if (virtio_serial_download) { + /* For the download test, download a sparse file within the + * appliance to /dev/null on the host. + */ + if (guestfs_touch (g, "/sparse") == -1) + exit (EXIT_FAILURE); + if (guestfs_truncate_size (g, "/sparse", TEST_SERIAL_MAX_SIZE) == -1) + exit (EXIT_FAILURE); + + gettimeofday (&start, NULL); + rate = -1; + operation = "download"; + alarm (max_time_override > 0 ? max_time_override : TEST_SERIAL_MAX_TIME); + guestfs_push_error_handler (g, NULL, NULL); + r = guestfs_download (g, "/sparse", "/dev/null"); + alarm (0); + guestfs_pop_error_handler (g); + + if (r == -1 && guestfs_last_errno (g) != EINTR) { + fprintf (stderr, + "%s: expecting download command to return EINTR\n%s\n", + guestfs_int_program_name, guestfs_last_error (g)); + exit (EXIT_FAILURE); + } + + if (rate == -1) + goto rate_error; + + print_rate ("virtio-serial download rate:", rate); + } + + if (guestfs_shutdown (g) == -1) + exit (EXIT_FAILURE); + + guestfs_close (g); + + /* Restore SIGALRM signal handler. */ + sigaction (SIGALRM, &old_sa, NULL); +} + +/* The time we will spend running the test (seconds). */ +#define TEST_BLOCK_DEVICE_TIME 30 + +static void +test_block_device (void) +{ + int fd; + char tmpfile[] = "/tmp/speedtestXXXXXX"; + CLEANUP_FREE char **devices = NULL; + char *r; + const char *argv[4]; + const int t = + max_time_override > 0 ? max_time_override : TEST_BLOCK_DEVICE_TIME; + char tbuf[64]; + int64_t bytes_written, bytes_read; + + if (!block_device_write && !block_device_read) + return; + + snprintf (tbuf, sizeof tbuf, "%d", t); + + g = guestfs_create (); + if (!g) { + perror ("guestfs_create"); + exit (EXIT_FAILURE); + } + + /* Create a fully allocated backing file. Note we are not testing + * the speed of allocation on the host. + */ + fd = mkstemp (tmpfile); + if (fd == -1) { + perror ("mkstemp"); + exit (EXIT_FAILURE); + } + close (fd); + + if (guestfs_disk_create (g, tmpfile, "raw", + INT64_C (1024*1024*1024), + GUESTFS_DISK_CREATE_PREALLOCATION, "full", + -1) == -1) + exit (EXIT_FAILURE); + + if (guestfs_add_drive (g, tmpfile) == -1) + exit (EXIT_FAILURE); + + if (guestfs_launch (g) == -1) + exit (EXIT_FAILURE); + + devices = guestfs_list_devices (g); + if (devices == NULL) + exit (EXIT_FAILURE); + if (devices[0] == NULL) { + fprintf (stderr, "%s: expected guestfs_list_devices to return at least 1 device\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + if (block_device_write) { + /* Test write speed. */ + argv[0] = devices[0]; + argv[1] = "w"; + argv[2] = tbuf; + argv[3] = NULL; + r = guestfs_debug (g, "device_speed", (char **) argv); + if (r == NULL) + exit (EXIT_FAILURE); + + if (sscanf (r, "%" SCNi64, &bytes_written) != 1) { + fprintf (stderr, "%s: could not parse device_speed output\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + print_rate ("block device writes:", bytes_written / t); + } + + if (block_device_read) { + /* Test read speed. */ + argv[0] = devices[0]; + argv[1] = "r"; + argv[2] = tbuf; + argv[3] = NULL; + r = guestfs_debug (g, "device_speed", (char **) argv); + if (r == NULL) + exit (EXIT_FAILURE); + + if (sscanf (r, "%" SCNi64, &bytes_read) != 1) { + fprintf (stderr, "%s: could not parse device_speed output\n", + guestfs_int_program_name); + exit (EXIT_FAILURE); + } + + print_rate ("block device reads:", bytes_read / t); + } + + if (guestfs_shutdown (g) == -1) + exit (EXIT_FAILURE); + + guestfs_close (g); + + /* Remove temporary file. */ + unlink (tmpfile); +} -- 2.7.4