[PATCH 0/2] qom: Make "info qom-tree" show children sorted

[PATCH 0/2] qom: Make "info qom-tree" show children sorted

[Markus Armbruster]

Extracted from my '[PATCH not-for-merge 0/5] Instrumentation for
"Fixes around device realization"' on reviewer's advice.

Markus Armbruster (2):
  qom: Constify object_get_canonical_path{,_component}()'s parameter
  qom: Make "info qom-tree" show children sorted

 include/qom/object.h |  4 ++--
 qom/object.c         |  4 ++--
 qom/qom-hmp-cmds.c   | 24 ++++++++++++++++--------
 3 files changed, 20 insertions(+), 12 deletions(-)

-- 
2.21.3

[PATCH 1/2] qom: Constify object_get_canonical_path{, _component}()'s parameter

[Markus Armbruster]

Suggested-by: Eric Blake <eblake@redhat.com>
Signed-off-by: Markus Armbruster <armbru@redhat.com>
---
 include/qom/object.h | 4 ++--
 qom/object.c         | 4 ++--
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/include/qom/object.h b/include/qom/object.h
index fd453dc8d6..b3eb05d65d 100644
--- a/include/qom/object.h
+++ b/include/qom/object.h
@@ -1406,7 +1406,7 @@ Object *object_get_internal_root(void);
  * path is the path within the composition tree starting from the root.
  * %NULL if the object doesn't have a parent (and thus a canonical path).
  */
-char *object_get_canonical_path_component(Object *obj);
+char *object_get_canonical_path_component(const Object *obj);
 
 /**
  * object_get_canonical_path:
@@ -1414,7 +1414,7 @@ char *object_get_canonical_path_component(Object *obj);
  * Returns: The canonical path for a object.  This is the path within the
  * composition tree starting from the root.
  */
-char *object_get_canonical_path(Object *obj);
+char *object_get_canonical_path(const Object *obj);
 
 /**
  * object_resolve_path:
diff --git a/qom/object.c b/qom/object.c
index d0be42c8d6..c02487ec1a 100644
--- a/qom/object.c
+++ b/qom/object.c
@@ -1883,7 +1883,7 @@ object_property_add_const_link(Object *obj, const char *name,
                                 NULL, OBJ_PROP_LINK_DIRECT);
 }
 
-char *object_get_canonical_path_component(Object *obj)
+char *object_get_canonical_path_component(const Object *obj)
 {
     ObjectProperty *prop = NULL;
     GHashTableIter iter;
@@ -1908,7 +1908,7 @@ char *object_get_canonical_path_component(Object *obj)
     return NULL;
 }
 
-char *object_get_canonical_path(Object *obj)
+char *object_get_canonical_path(const Object *obj)
 {
     Object *root = object_get_root();
     char *newpath, *path = NULL;
-- 
2.21.3

[PATCH 2/2] qom: Make "info qom-tree" show children sorted

[Markus Armbruster]

"info qom-tree" prints children in unstable order.  This is a pain
when diffing output for different versions to find change.  Print it
sorted.

Signed-off-by: Markus Armbruster <armbru@redhat.com>
---
 qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
 1 file changed, 16 insertions(+), 8 deletions(-)

diff --git a/qom/qom-hmp-cmds.c b/qom/qom-hmp-cmds.c
index cd08233a4c..94bdee9a90 100644
--- a/qom/qom-hmp-cmds.c
+++ b/qom/qom-hmp-cmds.c
@@ -69,22 +69,25 @@ typedef struct QOMCompositionState {
 
 static void print_qom_composition(Monitor *mon, Object *obj, int indent);
 
-static int print_qom_composition_child(Object *obj, void *opaque)
+static int qom_composition_compare(const void *a, const void *b, void *ignore)
 {
-    QOMCompositionState *s = opaque;
+    return g_strcmp0(a ? object_get_canonical_path_component(a) : NULL,
+                     b ? object_get_canonical_path_component(b) : NULL);
+}
 
-    print_qom_composition(s->mon, obj, s->indent);
+static int insert_qom_composition_child(Object *obj, void *opaque)
+{
+    GQueue *children = opaque;
 
+    g_queue_insert_sorted(children, obj, qom_composition_compare, NULL);
     return 0;
 }
 
 static void print_qom_composition(Monitor *mon, Object *obj, int indent)
 {
-    QOMCompositionState s = {
-        .mon = mon,
-        .indent = indent + 2,
-    };
     char *name;
+    GQueue children;
+    Object *child;
 
     if (obj == object_get_root()) {
         name = g_strdup("");
@@ -94,7 +97,12 @@ static void print_qom_composition(Monitor *mon, Object *obj, int indent)
     monitor_printf(mon, "%*s/%s (%s)\n", indent, "", name,
                    object_get_typename(obj));
     g_free(name);
-    object_child_foreach(obj, print_qom_composition_child, &s);
+
+    g_queue_init(&children);
+    object_child_foreach(obj, insert_qom_composition_child, &children);
+    while ((child = g_queue_pop_head(&children))) {
+        print_qom_composition(mon, child, indent + 2);
+    }
 }
 
 void hmp_info_qom_tree(Monitor *mon, const QDict *dict)
-- 
2.21.3

Re: [PATCH 1/2] qom: Constify object_get_canonical_path{, _component}()'s parameter

[Cédric Le Goater]

On 5/27/20 10:47 AM, Markus Armbruster wrote:
> Suggested-by: Eric Blake <eblake@redhat.com>
> Signed-off-by: Markus Armbruster <armbru@redhat.com>

Reviewed-by: Cédric Le Goater <clg@kaod.org>


> ---
>  include/qom/object.h | 4 ++--
>  qom/object.c         | 4 ++--
>  2 files changed, 4 insertions(+), 4 deletions(-)
> 
> diff --git a/include/qom/object.h b/include/qom/object.h
> index fd453dc8d6..b3eb05d65d 100644
> --- a/include/qom/object.h
> +++ b/include/qom/object.h
> @@ -1406,7 +1406,7 @@ Object *object_get_internal_root(void);
>   * path is the path within the composition tree starting from the root.
>   * %NULL if the object doesn't have a parent (and thus a canonical path).
>   */
> -char *object_get_canonical_path_component(Object *obj);
> +char *object_get_canonical_path_component(const Object *obj);
>  
>  /**
>   * object_get_canonical_path:
> @@ -1414,7 +1414,7 @@ char *object_get_canonical_path_component(Object *obj);
>   * Returns: The canonical path for a object.  This is the path within the
>   * composition tree starting from the root.
>   */
> -char *object_get_canonical_path(Object *obj);
> +char *object_get_canonical_path(const Object *obj);
>  
>  /**
>   * object_resolve_path:
> diff --git a/qom/object.c b/qom/object.c
> index d0be42c8d6..c02487ec1a 100644
> --- a/qom/object.c
> +++ b/qom/object.c
> @@ -1883,7 +1883,7 @@ object_property_add_const_link(Object *obj, const char *name,
>                                  NULL, OBJ_PROP_LINK_DIRECT);
>  }
>  
> -char *object_get_canonical_path_component(Object *obj)
> +char *object_get_canonical_path_component(const Object *obj)
>  {
>      ObjectProperty *prop = NULL;
>      GHashTableIter iter;
> @@ -1908,7 +1908,7 @@ char *object_get_canonical_path_component(Object *obj)
>      return NULL;
>  }
>  
> -char *object_get_canonical_path(Object *obj)
> +char *object_get_canonical_path(const Object *obj)
>  {
>      Object *root = object_get_root();
>      char *newpath, *path = NULL;
> 

Re: [PATCH 2/2] qom: Make "info qom-tree" show children sorted

[Cédric Le Goater]

On 5/27/20 10:47 AM, Markus Armbruster wrote:
> "info qom-tree" prints children in unstable order.  This is a pain
> when diffing output for different versions to find change.  Print it
> sorted.

yes. Thanks for fixing that.

 
> Signed-off-by: Markus Armbruster <armbru@redhat.com>

I used the powernv9 machine.

Tested-by: Cédric Le Goater <clg@kaod.org>

> ---
>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>  1 file changed, 16 insertions(+), 8 deletions(-)
> 
> diff --git a/qom/qom-hmp-cmds.c b/qom/qom-hmp-cmds.c
> index cd08233a4c..94bdee9a90 100644
> --- a/qom/qom-hmp-cmds.c
> +++ b/qom/qom-hmp-cmds.c
> @@ -69,22 +69,25 @@ typedef struct QOMCompositionState {
>  
>  static void print_qom_composition(Monitor *mon, Object *obj, int indent);
>  
> -static int print_qom_composition_child(Object *obj, void *opaque)
> +static int qom_composition_compare(const void *a, const void *b, void *ignore)
>  {
> -    QOMCompositionState *s = opaque;
> +    return g_strcmp0(a ? object_get_canonical_path_component(a) : NULL,
> +                     b ? object_get_canonical_path_component(b) : NULL);
> +}
>  
> -    print_qom_composition(s->mon, obj, s->indent);
> +static int insert_qom_composition_child(Object *obj, void *opaque)
> +{
> +    GQueue *children = opaque;
>  
> +    g_queue_insert_sorted(children, obj, qom_composition_compare, NULL);
>      return 0;
>  }
>  
>  static void print_qom_composition(Monitor *mon, Object *obj, int indent)
>  {
> -    QOMCompositionState s = {
> -        .mon = mon,
> -        .indent = indent + 2,
> -    };
>      char *name;
> +    GQueue children;
> +    Object *child;
>  
>      if (obj == object_get_root()) {
>          name = g_strdup("");
> @@ -94,7 +97,12 @@ static void print_qom_composition(Monitor *mon, Object *obj, int indent)
>      monitor_printf(mon, "%*s/%s (%s)\n", indent, "", name,
>                     object_get_typename(obj));
>      g_free(name);
> -    object_child_foreach(obj, print_qom_composition_child, &s);
> +
> +    g_queue_init(&children);
> +    object_child_foreach(obj, insert_qom_composition_child, &children);
> +    while ((child = g_queue_pop_head(&children))) {
> +        print_qom_composition(mon, child, indent + 2);
> +    }
>  }
>  
>  void hmp_info_qom_tree(Monitor *mon, const QDict *dict)
> 

Re: [PATCH 1/2] qom: Constify object_get_canonical_path{,_component}()'s parameter

[Philippe Mathieu-Daudé]

On 5/27/20 10:47 AM, Markus Armbruster wrote:
> Suggested-by: Eric Blake <eblake@redhat.com>
> Signed-off-by: Markus Armbruster <armbru@redhat.com>
> ---
>  include/qom/object.h | 4 ++--
>  qom/object.c         | 4 ++--
>  2 files changed, 4 insertions(+), 4 deletions(-)
> 
> diff --git a/include/qom/object.h b/include/qom/object.h
> index fd453dc8d6..b3eb05d65d 100644
> --- a/include/qom/object.h
> +++ b/include/qom/object.h
> @@ -1406,7 +1406,7 @@ Object *object_get_internal_root(void);
>   * path is the path within the composition tree starting from the root.
>   * %NULL if the object doesn't have a parent (and thus a canonical path).
>   */
> -char *object_get_canonical_path_component(Object *obj);
> +char *object_get_canonical_path_component(const Object *obj);
>  
>  /**
>   * object_get_canonical_path:
> @@ -1414,7 +1414,7 @@ char *object_get_canonical_path_component(Object *obj);
>   * Returns: The canonical path for a object.  This is the path within the
>   * composition tree starting from the root.
>   */
> -char *object_get_canonical_path(Object *obj);
> +char *object_get_canonical_path(const Object *obj);
>  
>  /**
>   * object_resolve_path:
> diff --git a/qom/object.c b/qom/object.c
> index d0be42c8d6..c02487ec1a 100644
> --- a/qom/object.c
> +++ b/qom/object.c
> @@ -1883,7 +1883,7 @@ object_property_add_const_link(Object *obj, const char *name,
>                                  NULL, OBJ_PROP_LINK_DIRECT);
>  }
>  
> -char *object_get_canonical_path_component(Object *obj)
> +char *object_get_canonical_path_component(const Object *obj)
>  {
>      ObjectProperty *prop = NULL;
>      GHashTableIter iter;
> @@ -1908,7 +1908,7 @@ char *object_get_canonical_path_component(Object *obj)
>      return NULL;
>  }
>  
> -char *object_get_canonical_path(Object *obj)
> +char *object_get_canonical_path(const Object *obj)
>  {
>      Object *root = object_get_root();
>      char *newpath, *path = NULL;
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH 2/2] qom: Make "info qom-tree" show children sorted

[Philippe Mathieu-Daudé]

On 5/27/20 10:47 AM, Markus Armbruster wrote:
> "info qom-tree" prints children in unstable order.  This is a pain
> when diffing output for different versions to find change.  Print it
> sorted.
> 
> Signed-off-by: Markus Armbruster <armbru@redhat.com>
> ---
>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>  1 file changed, 16 insertions(+), 8 deletions(-)
> 
> diff --git a/qom/qom-hmp-cmds.c b/qom/qom-hmp-cmds.c
> index cd08233a4c..94bdee9a90 100644
> --- a/qom/qom-hmp-cmds.c
> +++ b/qom/qom-hmp-cmds.c
> @@ -69,22 +69,25 @@ typedef struct QOMCompositionState {
>  
>  static void print_qom_composition(Monitor *mon, Object *obj, int indent);
>  
> -static int print_qom_composition_child(Object *obj, void *opaque)
> +static int qom_composition_compare(const void *a, const void *b, void *ignore)
>  {
> -    QOMCompositionState *s = opaque;
> +    return g_strcmp0(a ? object_get_canonical_path_component(a) : NULL,
> +                     b ? object_get_canonical_path_component(b) : NULL);
> +}
>  
> -    print_qom_composition(s->mon, obj, s->indent);
> +static int insert_qom_composition_child(Object *obj, void *opaque)
> +{
> +    GQueue *children = opaque;
>  
> +    g_queue_insert_sorted(children, obj, qom_composition_compare, NULL);
>      return 0;
>  }
>  
>  static void print_qom_composition(Monitor *mon, Object *obj, int indent)
>  {
> -    QOMCompositionState s = {
> -        .mon = mon,
> -        .indent = indent + 2,
> -    };
>      char *name;
> +    GQueue children;
> +    Object *child;
>  
>      if (obj == object_get_root()) {
>          name = g_strdup("");
> @@ -94,7 +97,12 @@ static void print_qom_composition(Monitor *mon, Object *obj, int indent)
>      monitor_printf(mon, "%*s/%s (%s)\n", indent, "", name,
>                     object_get_typename(obj));
>      g_free(name);
> -    object_child_foreach(obj, print_qom_composition_child, &s);
> +
> +    g_queue_init(&children);
> +    object_child_foreach(obj, insert_qom_composition_child, &children);
> +    while ((child = g_queue_pop_head(&children))) {
> +        print_qom_composition(mon, child, indent + 2);
> +    }
>  }
>  
>  void hmp_info_qom_tree(Monitor *mon, const QDict *dict)
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH 0/2] qom: Make "info qom-tree" show children sorted

[Mark Cave-Ayland]

On 27/05/2020 09:47, Markus Armbruster wrote:

> Extracted from my '[PATCH not-for-merge 0/5] Instrumentation for
> "Fixes around device realization"' on reviewer's advice.
> 
> Markus Armbruster (2):
>   qom: Constify object_get_canonical_path{,_component}()'s parameter
>   qom: Make "info qom-tree" show children sorted
> 
>  include/qom/object.h |  4 ++--
>  qom/object.c         |  4 ++--
>  qom/qom-hmp-cmds.c   | 24 ++++++++++++++++--------
>  3 files changed, 20 insertions(+), 12 deletions(-)

I've just given this a quick spin on a couple of my local branches here and it looks
good:

Tested-by: Mark Cave-Ayland <mark.cave-ayland@ilande.co.uk>


ATB,

Mark.

Slow down with: 'Make "info qom-tree" show children sorted'

[Thomas Huth]

On 27/05/2020 10.47, Markus Armbruster wrote:
> "info qom-tree" prints children in unstable order.  This is a pain
> when diffing output for different versions to find change.  Print it
> sorted.
> 
> Signed-off-by: Markus Armbruster <armbru@redhat.com>
> ---
>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>  1 file changed, 16 insertions(+), 8 deletions(-)

 Hi Markus,

this patch causes a slow down of the qtests which becomes quite massive
when e.g. using the ppc64 and thourough testing. When I'm running

QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
./tests/qtest/device-introspect-test -m slow | tail -n 10

the test runs for ca. 6m40s here before the patch got applied, and for
mor than 20 minutes after the patch got applied!

This causes our gitlab CI to constantly fail since the patch got merged,
since the testing time now exceeds the 1h time limit:

 https://gitlab.com/qemu-project/qemu/-/pipelines/156767175

Sure, we can work around that problem in the CI (Alex has already a
patch queued), but still, is there something you could do about this
massive slowdown?

 Thanks,
  Thomas

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Philippe Mathieu-Daudé]

On 7/7/20 6:45 AM, Thomas Huth wrote:
> On 27/05/2020 10.47, Markus Armbruster wrote:
>> "info qom-tree" prints children in unstable order.  This is a pain
>> when diffing output for different versions to find change.  Print it
>> sorted.
>>
>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
>> ---
>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>>  1 file changed, 16 insertions(+), 8 deletions(-)
> 
>  Hi Markus,
> 
> this patch causes a slow down of the qtests which becomes quite massive
> when e.g. using the ppc64 and thourough testing. When I'm running
> 
> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
> ./tests/qtest/device-introspect-test -m slow | tail -n 10
> 
> the test runs for ca. 6m40s here before the patch got applied, and for
> mor than 20 minutes after the patch got applied!

Argh, yesterday I reviewed again all the range except this patch... not
sure why as looking at it now it is obvious.

> This causes our gitlab CI to constantly fail since the patch got merged,
> since the testing time now exceeds the 1h time limit:
> 
>  https://gitlab.com/qemu-project/qemu/-/pipelines/156767175
> 
> Sure, we can work around that problem in the CI (Alex has already a
> patch queued), but still, is there something you could do about this
> massive slowdown?

Suggestion: add a '-u' option for unsorted mode, to use in qtests.

Humans want the new behavior (default: sorted).

Regards,

Phil.

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Markus Armbruster]

Philippe Mathieu-Daudé <philmd@redhat.com> writes:

> On 7/7/20 6:45 AM, Thomas Huth wrote:
>> On 27/05/2020 10.47, Markus Armbruster wrote:
>>> "info qom-tree" prints children in unstable order.  This is a pain
>>> when diffing output for different versions to find change.  Print it
>>> sorted.
>>>
>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
>>> ---
>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>>>  1 file changed, 16 insertions(+), 8 deletions(-)
>> 
>>  Hi Markus,
>> 
>> this patch causes a slow down of the qtests which becomes quite massive
>> when e.g. using the ppc64 and thourough testing. When I'm running
>> 
>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
>> 
>> the test runs for ca. 6m40s here before the patch got applied, and for
>> mor than 20 minutes after the patch got applied!

That's surprising.

> Argh, yesterday I reviewed again all the range except this patch... not
> sure why as looking at it now it is obvious.
>
>> This causes our gitlab CI to constantly fail since the patch got merged,
>> since the testing time now exceeds the 1h time limit:
>> 
>>  https://gitlab.com/qemu-project/qemu/-/pipelines/156767175
>> 
>> Sure, we can work around that problem in the CI (Alex has already a
>> patch queued), but still, is there something you could do about this
>> massive slowdown?
>
> Suggestion: add a '-u' option for unsorted mode, to use in qtests.
>
> Humans want the new behavior (default: sorted).

Last resort.  

I'll look into speeding up the sort first.

Work-around: drop -m slow until we get this sorted (pardon the pun).

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Paolo Bonzini]

On 07/07/20 07:33, Markus Armbruster wrote:
> Philippe Mathieu-Daudé <philmd@redhat.com> writes:
> 
>> On 7/7/20 6:45 AM, Thomas Huth wrote:
>>> On 27/05/2020 10.47, Markus Armbruster wrote:
>>>> "info qom-tree" prints children in unstable order.  This is a pain
>>>> when diffing output for different versions to find change.  Print it
>>>> sorted.
>>>>
>>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
>>>> ---
>>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>>>>  1 file changed, 16 insertions(+), 8 deletions(-)
>>>
>>>  Hi Markus,
>>>
>>> this patch causes a slow down of the qtests which becomes quite massive
>>> when e.g. using the ppc64 and thourough testing. When I'm running
>>>
>>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
>>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
>>>
>>> the test runs for ca. 6m40s here before the patch got applied, and for
>>> mor than 20 minutes after the patch got applied!
> 
> That's surprising.

It's a bit surprising indeed, but on the other hand using
g_queue_insert_sorted results in a quadratic loop.  It should probably
be fixed by using g_queue_sort, or switching to g_list_prepend+g_list_sort.

Paolo

>> Argh, yesterday I reviewed again all the range except this patch... not
>> sure why as looking at it now it is obvious.
>>
>>> This causes our gitlab CI to constantly fail since the patch got merged,
>>> since the testing time now exceeds the 1h time limit:
>>>
>>>  https://gitlab.com/qemu-project/qemu/-/pipelines/156767175
>>>
>>> Sure, we can work around that problem in the CI (Alex has already a
>>> patch queued), but still, is there something you could do about this
>>> massive slowdown?
>>
>> Suggestion: add a '-u' option for unsorted mode, to use in qtests.
>>
>> Humans want the new behavior (default: sorted).
> 
> Last resort.  
> 
> I'll look into speeding up the sort first.
> 
> Work-around: drop -m slow until we get this sorted (pardon the pun).
> 

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Daniel P. Berrangé]

On Tue, Jul 07, 2020 at 06:45:57AM +0200, Thomas Huth wrote:
> On 27/05/2020 10.47, Markus Armbruster wrote:
> > "info qom-tree" prints children in unstable order.  This is a pain
> > when diffing output for different versions to find change.  Print it
> > sorted.
> > 
> > Signed-off-by: Markus Armbruster <armbru@redhat.com>
> > ---
> >  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
> >  1 file changed, 16 insertions(+), 8 deletions(-)
> 
>  Hi Markus,
> 
> this patch causes a slow down of the qtests which becomes quite massive
> when e.g. using the ppc64 and thourough testing. When I'm running
> 
> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
> ./tests/qtest/device-introspect-test -m slow | tail -n 10
> 
> the test runs for ca. 6m40s here before the patch got applied, and for
> mor than 20 minutes after the patch got applied!
> 
> This causes our gitlab CI to constantly fail since the patch got merged,
> since the testing time now exceeds the 1h time limit:
> 
>  https://gitlab.com/qemu-project/qemu/-/pipelines/156767175
> 
> Sure, we can work around that problem in the CI (Alex has already a
> patch queued), but still, is there something you could do about this
> massive slowdown?

I think the answer is to stop using q_queue_insert_sorted(). The impl of
it looks like it is quadratic in complexity. Instead store the objects
in a plain array and then use qsort() at the end.

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Paolo Bonzini]

On 07/07/20 10:46, Daniel P. Berrangé wrote:
> On Tue, Jul 07, 2020 at 06:45:57AM +0200, Thomas Huth wrote:
>> Sure, we can work around that problem in the CI (Alex has already a
>> patch queued), but still, is there something you could do about this
>> massive slowdown?
> 
> I think the answer is to stop using q_queue_insert_sorted(). The impl of
> it looks like it is quadratic in complexity. Instead store the objects
> in a plain array and then use qsort() at the end.

g_list_sort uses a mergesort, so it's a good choice as well.  But yeah
GPtrArray is another possibility.

Paolo

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Daniel P. Berrangé]

On Tue, Jul 07, 2020 at 06:45:57AM +0200, Thomas Huth wrote:
> On 27/05/2020 10.47, Markus Armbruster wrote:
> > "info qom-tree" prints children in unstable order.  This is a pain
> > when diffing output for different versions to find change.  Print it
> > sorted.
> > 
> > Signed-off-by: Markus Armbruster <armbru@redhat.com>
> > ---
> >  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
> >  1 file changed, 16 insertions(+), 8 deletions(-)
> 
>  Hi Markus,
> 
> this patch causes a slow down of the qtests which becomes quite massive
> when e.g. using the ppc64 and thourough testing. When I'm running
> 
> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
> ./tests/qtest/device-introspect-test -m slow | tail -n 10
> 
> the test runs for ca. 6m40s here before the patch got applied, and for
> mor than 20 minutes after the patch got applied!

I think the test case itself could be optimized. Currently it does
approx

   for each device type
      info qom-tree
      device_addr type,help
      info qom-tree

it compares the before/after qom-tree to look for stray objects or
to try to trigger crashes.

The info qom-tree calls could be pushed outside the loop

   info qom-tree
   for each device type
      device_addr type,help
   info qom-tree

Taking /x86_64/device/introspect/concrete/defaults/pc-q35-5.1 as a
example, this change is the difference between 20 seconds running and
3 seconds running.

Reverting Markus' change actually didn't make much difference, only
reducing the 20 seconds to 17 seconds.

The downside is that if there is a stray object/crash, it would not
immediately associate with the device type. I'm not sure that's a
real problem though. Especially if we are running this as pre-merge
CI we'll only need to look at the patch series to find the broken
device. If this is quick enough that we can run it as standard,
instead of only with -m slow, then its a net win I think.


Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Paolo Bonzini]

On 07/07/20 11:40, Daniel P. Berrangé wrote:
> 
> The info qom-tree calls could be pushed outside the loop
> 
>    info qom-tree
>    for each device type
>       device_addr type,help
>    info qom-tree
> 
> Taking /x86_64/device/introspect/concrete/defaults/pc-q35-5.1 as a
> example, this change is the difference between 20 seconds running and
> 3 seconds running.

Or even, saving half the runtime:

    info qom-tree
    for each device type
       device_addr type,help
       info qom-tree

Paolo

> Reverting Markus' change actually didn't make much difference, only
> reducing the 20 seconds to 17 seconds.
> 
> The downside is that if there is a stray object/crash, it would not
> immediately associate with the device type. I'm not sure that's a
> real problem though. Especially if we are running this as pre-merge
> CI we'll only need to look at the patch series to find the broken
> device. If this is quick enough that we can run it as standard,
> instead of only with -m slow, then its a net win I think.

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Markus Armbruster]

Paolo Bonzini <pbonzini@redhat.com> writes:

> On 07/07/20 07:33, Markus Armbruster wrote:
>> Philippe Mathieu-Daudé <philmd@redhat.com> writes:
>> 
>>> On 7/7/20 6:45 AM, Thomas Huth wrote:
>>>> On 27/05/2020 10.47, Markus Armbruster wrote:
>>>>> "info qom-tree" prints children in unstable order.  This is a pain
>>>>> when diffing output for different versions to find change.  Print it
>>>>> sorted.
>>>>>
>>>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
>>>>> ---
>>>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>>>>>  1 file changed, 16 insertions(+), 8 deletions(-)
>>>>
>>>>  Hi Markus,
>>>>
>>>> this patch causes a slow down of the qtests which becomes quite massive
>>>> when e.g. using the ppc64 and thourough testing. When I'm running
>>>>
>>>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
>>>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
>>>>
>>>> the test runs for ca. 6m40s here before the patch got applied, and for
>>>> mor than 20 minutes after the patch got applied!
>> 
>> That's surprising.
>
> It's a bit surprising indeed, but on the other hand using
> g_queue_insert_sorted results in a quadratic loop.

The surprising part is that n turns out to be large enough for n^2 to
matter *that* much.

>                                                     It should probably
> be fixed by using g_queue_sort, or switching to g_list_prepend+g_list_sort.

Yes.

Additional ideas on how to make the test less wasteful elsewhere in the
thread.

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Daniel P. Berrangé]

On Tue, Jul 07, 2020 at 02:00:06PM +0200, Markus Armbruster wrote:
> Paolo Bonzini <pbonzini@redhat.com> writes:
> 
> > On 07/07/20 07:33, Markus Armbruster wrote:
> >> Philippe Mathieu-Daudé <philmd@redhat.com> writes:
> >> 
> >>> On 7/7/20 6:45 AM, Thomas Huth wrote:
> >>>> On 27/05/2020 10.47, Markus Armbruster wrote:
> >>>>> "info qom-tree" prints children in unstable order.  This is a pain
> >>>>> when diffing output for different versions to find change.  Print it
> >>>>> sorted.
> >>>>>
> >>>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
> >>>>> ---
> >>>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
> >>>>>  1 file changed, 16 insertions(+), 8 deletions(-)
> >>>>
> >>>>  Hi Markus,
> >>>>
> >>>> this patch causes a slow down of the qtests which becomes quite massive
> >>>> when e.g. using the ppc64 and thourough testing. When I'm running
> >>>>
> >>>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
> >>>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
> >>>>
> >>>> the test runs for ca. 6m40s here before the patch got applied, and for
> >>>> mor than 20 minutes after the patch got applied!
> >> 
> >> That's surprising.
> >
> > It's a bit surprising indeed, but on the other hand using
> > g_queue_insert_sorted results in a quadratic loop.
> 
> The surprising part is that n turns out to be large enough for n^2 to
> matter *that* much.

The test suite as a whole is more like n^3  because it is running
sooooo many repeats of "info qom-tree"

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Markus Armbruster]

Daniel P. Berrangé <berrange@redhat.com> writes:

> On Tue, Jul 07, 2020 at 06:45:57AM +0200, Thomas Huth wrote:
>> On 27/05/2020 10.47, Markus Armbruster wrote:
>> > "info qom-tree" prints children in unstable order.  This is a pain
>> > when diffing output for different versions to find change.  Print it
>> > sorted.
>> > 
>> > Signed-off-by: Markus Armbruster <armbru@redhat.com>
>> > ---
>> >  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>> >  1 file changed, 16 insertions(+), 8 deletions(-)
>> 
>>  Hi Markus,
>> 
>> this patch causes a slow down of the qtests which becomes quite massive
>> when e.g. using the ppc64 and thourough testing. When I'm running
>> 
>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
>> 
>> the test runs for ca. 6m40s here before the patch got applied, and for
>> mor than 20 minutes after the patch got applied!
>
> I think the test case itself could be optimized. Currently it does
> approx
>
>    for each device type
>       info qom-tree
>       device_addr type,help
>       info qom-tree
>
> it compares the before/after qom-tree to look for stray objects or
> to try to trigger crashes.
>
> The info qom-tree calls could be pushed outside the loop
>
>    info qom-tree
>    for each device type
>       device_addr type,help
>    info qom-tree
>
> Taking /x86_64/device/introspect/concrete/defaults/pc-q35-5.1 as a
> example, this change is the difference between 20 seconds running and
> 3 seconds running.

Patch?

> Reverting Markus' change actually didn't make much difference, only
> reducing the 20 seconds to 17 seconds.

I found and plugged a memory leak.  I haven't checked its impact on test
performance.

> The downside is that if there is a stray object/crash, it would not
> immediately associate with the device type. I'm not sure that's a
> real problem though. Especially if we are running this as pre-merge
> CI we'll only need to look at the patch series to find the broken
> device. If this is quick enough that we can run it as standard,
> instead of only with -m slow, then its a net win I think.

Easier investigation of failures is a valid argument, but not at this
price.  Our "make check" is painfully slow.

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[David Gibson]

[-- Attachment #1: Type: text/plain, Size: 1797 bytes --]

On Tue, 07 Jul 2020 14:00:06 +0200
Markus Armbruster <armbru@redhat.com> wrote:

> Paolo Bonzini <pbonzini@redhat.com> writes:
> 
> > On 07/07/20 07:33, Markus Armbruster wrote:  
> >> Philippe Mathieu-Daudé <philmd@redhat.com> writes:
> >>   
> >>> On 7/7/20 6:45 AM, Thomas Huth wrote:  
> >>>> On 27/05/2020 10.47, Markus Armbruster wrote:  
> >>>>> "info qom-tree" prints children in unstable order.  This is a pain
> >>>>> when diffing output for different versions to find change.  Print it
> >>>>> sorted.
> >>>>>
> >>>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
> >>>>> ---
> >>>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
> >>>>>  1 file changed, 16 insertions(+), 8 deletions(-)  
> >>>>
> >>>>  Hi Markus,
> >>>>
> >>>> this patch causes a slow down of the qtests which becomes quite massive
> >>>> when e.g. using the ppc64 and thourough testing. When I'm running
> >>>>
> >>>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
> >>>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
> >>>>
> >>>> the test runs for ca. 6m40s here before the patch got applied, and for
> >>>> mor than 20 minutes after the patch got applied!  
> >> 
> >> That's surprising.  
> >
> > It's a bit surprising indeed, but on the other hand using
> > g_queue_insert_sorted results in a quadratic loop.  
> 
> The surprising part is that n turns out to be large enough for n^2 to
> matter *that* much.

Is this another consequence of the ludicrous number of QOM objects we
create for LMB DRCs (one for every 256MiB of guest RAM)?  Avoiding that
is on my list.  Though avoiding a n^2 behaviour here is probably a good
idea anyway.

-- 
David Gibson <dgibson@redhat.com>
Principal Software Engineer, Virtualization, Red Hat

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Markus Armbruster]

David Gibson <dgibson@redhat.com> writes:

> On Tue, 07 Jul 2020 14:00:06 +0200
> Markus Armbruster <armbru@redhat.com> wrote:
>
>> Paolo Bonzini <pbonzini@redhat.com> writes:
>> 
>> > On 07/07/20 07:33, Markus Armbruster wrote:  
>> >> Philippe Mathieu-Daudé <philmd@redhat.com> writes:
>> >>   
>> >>> On 7/7/20 6:45 AM, Thomas Huth wrote:  
>> >>>> On 27/05/2020 10.47, Markus Armbruster wrote:  
>> >>>>> "info qom-tree" prints children in unstable order.  This is a pain
>> >>>>> when diffing output for different versions to find change.  Print it
>> >>>>> sorted.
>> >>>>>
>> >>>>> Signed-off-by: Markus Armbruster <armbru@redhat.com>
>> >>>>> ---
>> >>>>>  qom/qom-hmp-cmds.c | 24 ++++++++++++++++--------
>> >>>>>  1 file changed, 16 insertions(+), 8 deletions(-)  
>> >>>>
>> >>>>  Hi Markus,
>> >>>>
>> >>>> this patch causes a slow down of the qtests which becomes quite massive
>> >>>> when e.g. using the ppc64 and thourough testing. When I'm running
>> >>>>
>> >>>> QTEST_QEMU_BINARY="ppc64-softmmu/qemu-system-ppc64" time \
>> >>>> ./tests/qtest/device-introspect-test -m slow | tail -n 10
>> >>>>
>> >>>> the test runs for ca. 6m40s here before the patch got applied, and for
>> >>>> mor than 20 minutes after the patch got applied!  
>> >> 
>> >> That's surprising.  
>> >
>> > It's a bit surprising indeed, but on the other hand using
>> > g_queue_insert_sorted results in a quadratic loop.  
>> 
>> The surprising part is that n turns out to be large enough for n^2 to
>> matter *that* much.
>
> Is this another consequence of the ludicrous number of QOM objects we
> create for LMB DRCs (one for every 256MiB of guest RAM)?  Avoiding that
> is on my list.

You're talking about machine pseries, I presume.  With
print_qom_composition() patched to print the number of children, I get

    $ echo -e 'info qom-tree\nq' | ../qemu/bld/ppc64-softmmu/qemu-system-ppc64 -S -display none -M pseries -accel qtest -monitor stdio | grep '###' | sort | uniq -c | sort -k 3n
        360 ### 0 children
          5 ### 1 children
          5 ### 2 children
          2 ### 3 children
          1 ### 4 children
          1 ### 15 children
          1 ### 16 children
          1 ### 18 children
          1 ### 37 children
          1 ### 266 children

The outlier is

        /device[5] (spapr-pci-host-bridge)

due to its 256 spapr-drc-pci children.

I found quite a few machines with similar outliers.  ARM machines nuri
and smdkc210 together take the cake: they each have a node with 513
children.

My stupid n^2 sort is unnoticable in normal, human usage even for n=513.

>                 Though avoiding a n^2 behaviour here is probably a good
> idea anyway.

Agreed.

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[David Gibson]

[-- Attachment #1: Type: text/plain, Size: 2369 bytes --]

On Mon, 13 Jul 2020 18:13:42 +0200
Markus Armbruster <armbru@redhat.com> wrote:

> David Gibson <dgibson@redhat.com> writes:
> 
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
> >> 
> >> The surprising part is that n turns out to be large enough for n^2 to
> >> matter *that* much.  
> >
> > Is this another consequence of the ludicrous number of QOM objects we
> > create for LMB DRCs (one for every 256MiB of guest RAM)?  Avoiding that
> > is on my list.  
> 
> You're talking about machine pseries, I presume.

Yes.

>  With
> print_qom_composition() patched to print the number of children, I get
> 
>     $ echo -e 'info qom-tree\nq' | ../qemu/bld/ppc64-softmmu/qemu-system-ppc64 -S -display none -M pseries -accel qtest -monitor stdio | grep '###' | sort | uniq -c | sort -k 3n
>         360 ### 0 children
>           5 ### 1 children
>           5 ### 2 children
>           2 ### 3 children
>           1 ### 4 children
>           1 ### 15 children
>           1 ### 16 children
>           1 ### 18 children
>           1 ### 37 children
>           1 ### 266 children
> 
> The outlier is
> 
>         /device[5] (spapr-pci-host-bridge)
> 
> due to its 256 spapr-drc-pci children.

Right, that's one for each possible PCI slot on the bus.  That will be
reduced by the idea I have in mind for this, but...

> I found quite a few machines with similar outliers.  ARM machines nuri
> and smdkc210 together take the cake: they each have a node with 513
> children.
> 
> My stupid n^2 sort is unnoticable in normal, human usage even for n=513.

... as you say, 256 shouldn't really be a problem.  I was concerned
about LMB DRCs rather than PCI DRCs.  To have that show up, you might
need to create a machine with a large difference between initial memory
and maxmem - I think you'll get a DRC object for every 256MiB in there,
which can easily get into the thousands for large (potential) memory
VMs.

I don't know what the config was that showed up this problem in the
first place, and whether that could be the case there.

> >                 Though avoiding a n^2 behaviour here is probably a good
> > idea anyway.  
> 
> Agreed.

-- 
David Gibson <dgibson@redhat.com>
Principal Software Engineer, Virtualization, Red Hat

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[Markus Armbruster]

David Gibson <dgibson@redhat.com> writes:

> On Mon, 13 Jul 2020 18:13:42 +0200
> Markus Armbruster <armbru@redhat.com> wrote:
>
>> David Gibson <dgibson@redhat.com> writes:
>> 
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>>  [...]  
>> >> 
>> >> The surprising part is that n turns out to be large enough for n^2 to
>> >> matter *that* much.  
>> >
>> > Is this another consequence of the ludicrous number of QOM objects we
>> > create for LMB DRCs (one for every 256MiB of guest RAM)?  Avoiding that
>> > is on my list.  
>> 
>> You're talking about machine pseries, I presume.
>
> Yes.
>
>>  With
>> print_qom_composition() patched to print the number of children, I get
>> 
>>     $ echo -e 'info qom-tree\nq' | ../qemu/bld/ppc64-softmmu/qemu-system-ppc64 -S -display none -M pseries -accel qtest -monitor stdio | grep '###' | sort | uniq -c | sort -k 3n
>>         360 ### 0 children
>>           5 ### 1 children
>>           5 ### 2 children
>>           2 ### 3 children
>>           1 ### 4 children
>>           1 ### 15 children
>>           1 ### 16 children
>>           1 ### 18 children
>>           1 ### 37 children
>>           1 ### 266 children
>> 
>> The outlier is
>> 
>>         /device[5] (spapr-pci-host-bridge)
>> 
>> due to its 256 spapr-drc-pci children.
>
> Right, that's one for each possible PCI slot on the bus.  That will be
> reduced by the idea I have in mind for this, but...
>
>> I found quite a few machines with similar outliers.  ARM machines nuri
>> and smdkc210 together take the cake: they each have a node with 513
>> children.
>> 
>> My stupid n^2 sort is unnoticable in normal, human usage even for n=513.
>
> ... as you say, 256 shouldn't really be a problem.  I was concerned
> about LMB DRCs rather than PCI DRCs.  To have that show up, you might
> need to create a machine with a large difference between initial memory
> and maxmem - I think you'll get a DRC object for every 256MiB in there,
> which can easily get into the thousands for large (potential) memory
> VMs.

Okay, I can reproduce: with -m 256,128G, /machine has 549 children, of
which 511 are spapr-drc-lmb.

> I don't know what the config was that showed up this problem in the
> first place, and whether that could be the case there.

Thomas reported device-introspect-test -m slow has become much slower
for ppc64.  Bisection traced it to my commit e8c9e65816 "qom: Make "info
qom-tree" show children sorted".  Uses default memory size, no
spapr-drc-lmb as far as I remember.

>> >                 Though avoiding a n^2 behaviour here is probably a good
>> > idea anyway.  
>> 
>> Agreed.

Patch posted:

    Subject: [PATCH for-5.1 5/5] qom: Make info qom-tree sort children more efficiently
    Message-Id: <20200714160202.3121879-6-armbru@redhat.com>

Re: Slow down with: 'Make "info qom-tree" show children sorted'

[David Gibson]

[-- Attachment #1: Type: text/plain, Size: 1595 bytes --]

On Thu, 16 Jul 2020 07:37:17 +0200
Markus Armbruster <armbru@redhat.com> wrote:

> David Gibson <dgibson@redhat.com> writes:
> 
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
>  [...]  
> >
> > ... as you say, 256 shouldn't really be a problem.  I was concerned
> > about LMB DRCs rather than PCI DRCs.  To have that show up, you might
> > need to create a machine with a large difference between initial memory
> > and maxmem - I think you'll get a DRC object for every 256MiB in there,
> > which can easily get into the thousands for large (potential) memory
> > VMs.  
> 
> Okay, I can reproduce: with -m 256,128G, /machine has 549 children, of
> which 511 are spapr-drc-lmb.

Ok.

> > I don't know what the config was that showed up this problem in the
> > first place, and whether that could be the case there.  
> 
> Thomas reported device-introspect-test -m slow has become much slower
> for ppc64.  Bisection traced it to my commit e8c9e65816 "qom: Make "info
> qom-tree" show children sorted".  Uses default memory size, no
> spapr-drc-lmb as far as I remember.

Ok, I think that nixes my theory.

> >> >                 Though avoiding a n^2 behaviour here is probably a good
> >> > idea anyway.    
> >> 
> >> Agreed.  
> 
> Patch posted:
> 
>     Subject: [PATCH for-5.1 5/5] qom: Make info qom-tree sort children more efficiently
>     Message-Id: <20200714160202.3121879-6-armbru@redhat.com>
> 


-- 
David Gibson <dgibson@redhat.com>
Principal Software Engineer, Virtualization, Red Hat

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]