Add profiling data to debug slow startup times

This commit is contained in:
Richard Hughes 2015-09-24 15:43:02 +01:00
parent d449447fc8
commit 3f23650f15
4 changed files with 96 additions and 39 deletions

View File

@ -63,6 +63,7 @@ typedef struct {
PolkitAuthority *authority;
FwupdStatus status;
FuPending *pending;
AsProfile *profile;
AsStore *store;
guint store_changed_id;
} FuMainPrivate;
@ -1476,10 +1477,16 @@ fu_main_providers_coldplug (FuMainPrivate *priv)
{
FuProvider *provider;
guint i;
g_autoptr(AsProfileTask) ptask = NULL;
ptask = as_profile_start_literal (priv->profile, "FuMain:coldplug");
for (i = 0; i < priv->providers->len; i++) {
g_autoptr(GError) error = NULL;
g_autoptr(AsProfileTask) ptask2 = NULL;
provider = g_ptr_array_index (priv->providers, i);
ptask2 = as_profile_start (priv->profile,
"FuMain:coldplug{%s}",
fu_provider_get_name (provider));
if (!fu_provider_coldplug (FU_PROVIDER (provider), &error))
g_warning ("Failed to coldplug: %s", error->message);
}
@ -1530,6 +1537,9 @@ fu_main_on_bus_acquired_cb (GDBusConnection *connection,
g_warning ("cannot connect to DBus: %s", error->message);
return;
}
/* dump startup profile data */
as_profile_dump (priv->profile);
}
/**
@ -1716,6 +1726,7 @@ main (int argc, char *argv[])
priv->loop = g_main_loop_new (NULL, FALSE);
priv->pending = fu_pending_new ();
priv->store = as_store_new ();
priv->profile = as_profile_new ();
g_signal_connect (priv->store, "changed",
G_CALLBACK (fu_main_store_changed_cb), priv);
as_store_set_watch_flags (priv->store, AS_STORE_WATCH_FLAG_ADDED |
@ -1809,6 +1820,8 @@ out:
g_object_unref (priv->connection);
if (priv->authority != NULL)
g_object_unref (priv->authority);
if (priv->profile != NULL)
g_object_unref (priv->profile);
if (priv->store != NULL)
g_object_unref (priv->store);
if (priv->introspection_daemon != NULL)

View File

@ -113,6 +113,8 @@ fu_provider_udev_client_add (FuProviderUdev *provider_udev, GUdevDevice *device)
g_autofree gchar *rom_fn = NULL;
g_autofree gchar *version = NULL;
g_auto(GStrv) split = NULL;
g_autoptr(AsProfile) profile = as_profile_new ();
g_autoptr(AsProfileTask) ptask = NULL;
/* interesting device? */
guid = g_udev_device_get_property (device, "FWUPD_GUID");
@ -120,6 +122,7 @@ fu_provider_udev_client_add (FuProviderUdev *provider_udev, GUdevDevice *device)
return;
/* get data */
ptask = as_profile_start (profile, "FuProviderUdev:client-add{%s}", guid);
g_debug ("adding udev device: %s", g_udev_device_get_sysfs_path (device));
if (0) {
const gchar * const *keys;
@ -160,6 +163,7 @@ fu_provider_udev_client_add (FuProviderUdev *provider_udev, GUdevDevice *device)
g_autoptr(GError) error = NULL;
g_autoptr(GFile) file = NULL;
g_autoptr(FuRom) rom = NULL;
file = g_file_new_for_path (rom_fn);
rom = fu_rom_new ();
if (!fu_rom_load_file (rom, file, FU_ROM_LOAD_FLAG_BLANK_PPID, NULL, &error)) {
@ -267,9 +271,12 @@ fu_provider_udev_coldplug (FuProvider *provider, GError **error)
GUdevDevice *udev_device;
const gchar *devclass[] = { "usb", "pci", NULL };
guint i;
g_autoptr(AsProfile) profile = as_profile_new ();
/* get all devices of class */
for (i = 0; devclass[i] != NULL; i++) {
g_autoptr(AsProfileTask) ptask = NULL;
ptask = as_profile_start (profile, "FuProviderUdev:coldplug{%s}", devclass[i]);
devices = g_udev_client_query_by_subsystem (priv->gudev_client,
devclass[i]);
for (l = devices; l != NULL; l = l->next) {

View File

@ -21,6 +21,7 @@
#include "config.h"
#include <appstream-glib.h>
#include <fwupd.h>
#include <glib-object.h>
#include <gusb.h>
@ -60,6 +61,70 @@ fu_provider_usb_get_id (GUsbDevice *device)
return g_strdup_printf ("ro-%s", g_usb_device_get_platform_id (device));
}
/**
* fu_provider_usb_device_add:
*
* Important, the device must already be open!
**/
static void
fu_provider_usb_device_add (FuProviderUsb *provider_usb, const gchar *id, GUsbDevice *device)
{
FuProviderUsbPrivate *priv = GET_PRIVATE (provider_usb);
FuDevice *dev;
guint8 idx = 0x00;
g_autofree gchar *guid = NULL;
g_autofree gchar *product = NULL;
g_autofree gchar *version = NULL;
g_autoptr(AsProfile) profile = as_profile_new ();
g_autoptr(AsProfileTask) ptask = NULL;
/* get product */
idx = g_usb_device_get_product_index (device);
if (idx != 0x00) {
g_autoptr(AsProfileTask) ptask2 = NULL;
ptask2 = as_profile_start_literal (profile, "FuProviderUsb:get-string-desc");
product = g_usb_device_get_string_descriptor (device, idx, NULL);
}
if (product == NULL) {
g_debug ("ignoring %s as no product string descriptor", id);
return;
}
ptask = as_profile_start_literal (profile, "FuProviderUsb:get-custom-index");
#if G_USB_CHECK_VERSION(0,2,5)
idx = g_usb_device_get_custom_index (device,
G_USB_DEVICE_CLASS_VENDOR_SPECIFIC,
'F', 'W', NULL);
#endif
if (idx != 0x00)
version = g_usb_device_get_string_descriptor (device, idx, NULL);
if (version == NULL) {
g_debug ("ignoring %s [%s] as no version", id, product);
return;
}
#if G_USB_CHECK_VERSION(0,2,5)
idx = g_usb_device_get_custom_index (device,
G_USB_DEVICE_CLASS_VENDOR_SPECIFIC,
'G', 'U', NULL);
#endif
if (idx != 0x00)
guid = g_usb_device_get_string_descriptor (device, idx, NULL);
if (guid == NULL) {
g_debug ("ignoring %s [%s] as no GUID", id, product);
return;
}
/* insert to hash */
dev = fu_device_new ();
fu_device_set_id (dev, id);
fu_device_set_guid (dev, guid);
fu_device_set_display_name (dev, product);
fu_device_set_metadata (dev, FU_DEVICE_KEY_VERSION, version);
g_hash_table_insert (priv->devices,
g_strdup (id), dev);
fu_provider_device_add (FU_PROVIDER (provider_usb), dev);
}
/**
* fu_provider_usb_device_added_cb:
**/
@ -70,18 +135,19 @@ fu_provider_usb_device_added_cb (GUsbContext *ctx,
{
FuProviderUsbPrivate *priv = GET_PRIVATE (provider_usb);
FuDevice *dev;
guint8 idx = 0x00;
g_autoptr(GError) error = NULL;
g_autofree gchar *guid = NULL;
g_autofree gchar *id = NULL;
g_autofree gchar *product = NULL;
g_autofree gchar *version = NULL;
g_autoptr(AsProfile) profile = as_profile_new ();
g_autoptr(AsProfileTask) ptask = NULL;
/* ignore hubs */
#if G_USB_CHECK_VERSION(0,2,5)
if (g_usb_device_get_device_class (device) == G_USB_DEVICE_CLASS_HUB)
return;
#endif
ptask = as_profile_start (profile, "FuProviderUsb:added{%04x:%04x}",
g_usb_device_get_vid (device),
g_usb_device_get_pid (device));
/* handled by another provider */
id = fu_provider_usb_get_id (device);
@ -102,42 +168,9 @@ fu_provider_usb_device_added_cb (GUsbContext *ctx,
g_debug ("Failed to open: %s", error->message);
return;
}
#if G_USB_CHECK_VERSION(0,2,5)
idx = g_usb_device_get_custom_index (device,
G_USB_DEVICE_CLASS_VENDOR_SPECIFIC,
'F', 'W', NULL);
#endif
if (idx != 0x00)
version = g_usb_device_get_string_descriptor (device, idx, NULL);
#if G_USB_CHECK_VERSION(0,2,5)
idx = g_usb_device_get_custom_index (device,
G_USB_DEVICE_CLASS_VENDOR_SPECIFIC,
'G', 'U', NULL);
#endif
if (idx != 0x00)
guid = g_usb_device_get_string_descriptor (device, idx, NULL);
idx = g_usb_device_get_product_index (device);
if (idx != 0x00)
product = g_usb_device_get_string_descriptor (device, idx, NULL);
/* did we get enough data */
if (version != NULL && guid != NULL && product != NULL) {
dev = fu_device_new ();
fu_device_set_id (dev, id);
fu_device_set_guid (dev, guid);
fu_device_set_display_name (dev, product);
fu_device_set_metadata (dev, FU_DEVICE_KEY_VERSION, version);
/* insert to hash */
g_hash_table_insert (priv->devices,
g_strdup (id), dev);
fu_provider_device_add (FU_PROVIDER (provider_usb), dev);
} else {
g_debug ("ignoring %s [%s:%s:%s]", id,
product != NULL ? product : "",
version != NULL ? version : "",
guid != NULL ? guid : "");
}
/* try to add the device */
fu_provider_usb_device_add (provider_usb, id, device);
/* we're done here */
if (!g_usb_device_close (device, &error))
@ -172,6 +205,7 @@ fu_provider_usb_coldplug (FuProvider *provider, GError **error)
{
FuProviderUsb *provider_usb = FU_PROVIDER_USB (provider);
FuProviderUsbPrivate *priv = GET_PRIVATE (provider_usb);
g_usb_context_enumerate (priv->usb_ctx);
return TRUE;
}

View File

@ -633,10 +633,13 @@ fu_rom_load_file (FuRom *rom, GFile *file, FuRomLoadFlags flags,
g_autofree gchar *id = NULL;
g_autofree guint8 *buffer = NULL;
g_autoptr(GFileOutputStream) output_stream = NULL;
g_autoptr(AsProfile) profile = as_profile_new ();
g_autoptr(AsProfileTask) ptask = NULL;
g_return_val_if_fail (FU_IS_ROM (rom), FALSE);
/* open file */
ptask = as_profile_start_literal (profile, "FuRom:reading-data");
priv->stream = G_INPUT_STREAM (g_file_read (file, cancellable, &error_local));
if (priv->stream == NULL) {
g_set_error_literal (error,