[Qemu-devel] QOM cast debug

[Qemu-devel] QOM cast debug

[Laurent Desnogues]

Hello,

while looking at some perf results, I saw object_dynamic_cast_assert
taking more than 3% of the run time.

After some digging I found out that this time can be cut by passing
--disable-qom-cast-debug to configure.  This was added by Paolo:

commit 3556c233d931ad5ffa46a35cb25cfc057732ebb8
Author: Paolo Bonzini <pbonzini@redhat.com>
Date:   Fri May 10 14:16:40 2013 +0200

    qom: allow turning cast debugging off

    Cast debugging can have a substantial cost (20% or more).  Instead of adding
    special-cased "fast casts" in the hot paths, we can just disable it in
    releases.  The tracing facilities we just added make it easier to analyze
    those problems that cast debugging would reveal.

I find it odd that the default is to have this debug flag on by
default while the other such debug options are off.  Wouldn't it make
more sense to have it off by default and let devs turn it on?

Thanks,

Laurent

Re: [Qemu-devel] QOM cast debug

[Paolo Bonzini]

Il 20/03/2014 11:52, Laurent Desnogues ha scritto:
> Hello,
>
> while looking at some perf results, I saw object_dynamic_cast_assert
> taking more than 3% of the run time.
>
> After some digging I found out that this time can be cut by passing
> --disable-qom-cast-debug to configure.  This was added by Paolo:
>
> commit 3556c233d931ad5ffa46a35cb25cfc057732ebb8
> Author: Paolo Bonzini <pbonzini@redhat.com>
> Date:   Fri May 10 14:16:40 2013 +0200
>
>     qom: allow turning cast debugging off
>
>     Cast debugging can have a substantial cost (20% or more).  Instead of adding
>     special-cased "fast casts" in the hot paths, we can just disable it in
>     releases.  The tracing facilities we just added make it easier to analyze
>     those problems that cast debugging would reveal.
>
> I find it odd that the default is to have this debug flag on by
> default while the other such debug options are off.  Wouldn't it make
> more sense to have it off by default and let devs turn it on?

I agree, but Anthony (and Andreas?) did not.

Which path is calling object_dynamic_cast_assert so much?  It was agreed 
to just use C casts in hot code.

Paolo

Re: [Qemu-devel] QOM cast debug

[Laurent Desnogues]

On Thu, Mar 20, 2014 at 1:45 PM, Paolo Bonzini <pbonzini@redhat.com> wrote:
> Il 20/03/2014 11:52, Laurent Desnogues ha scritto:
>
>> Hello,
>>
>> while looking at some perf results, I saw object_dynamic_cast_assert
>> taking more than 3% of the run time.
>>
>> After some digging I found out that this time can be cut by passing
>> --disable-qom-cast-debug to configure.  This was added by Paolo:
>>
>> commit 3556c233d931ad5ffa46a35cb25cfc057732ebb8
>> Author: Paolo Bonzini <pbonzini@redhat.com>
>> Date:   Fri May 10 14:16:40 2013 +0200
>>
>>     qom: allow turning cast debugging off
>>
>>     Cast debugging can have a substantial cost (20% or more).  Instead of
>> adding
>>     special-cased "fast casts" in the hot paths, we can just disable it in
>>     releases.  The tracing facilities we just added make it easier to
>> analyze
>>     those problems that cast debugging would reveal.
>>
>> I find it odd that the default is to have this debug flag on by
>> default while the other such debug options are off.  Wouldn't it make
>> more sense to have it off by default and let devs turn it on?
>
>
> I agree, but Anthony (and Andreas?) did not.
>
> Which path is calling object_dynamic_cast_assert so much?  It was agreed to
> just use C casts in hot code.

The culprit seems to be ENV_GET_CPU:

#define ENV_GET_CPU(e) CPU(arm_env_get_cpu(e))
#define CPU(obj) OBJECT_CHECK(CPUState, (obj), TYPE_CPU)
#define OBJECT_CHECK(type, obj, name) \
    ((type *)object_dynamic_cast_assert(OBJECT(obj), (name), \
                                        __FILE__, __LINE__, __func__))

                0.00    0.00 1391069/289549110     io_writel [46]
                0.00    0.00 2038947/289549110     helper_le_stl_mmu [32]
                0.00    0.00 3986870/289549110     helper_ret_ldub_mmu [31]
                0.00    0.00 8131587/289549110     helper_ret_ldb_cmmu [28]
                0.00    0.00 17849223/289549110     helper_le_ldul_mmu [18]
                0.00    0.00 32244969/289549110     tb_find_slow [26]
                0.00    0.00 32347716/289549110
arm_cpu_handle_mmu_fault [11]
                0.00    0.00 32347737/289549110     get_phys_addr_v6 [17]
                0.00    0.00 32598025/289549110     get_page_addr_code [27]
                0.00    0.00 124705628/289549110     tb_find_fast [25]
[106]    0.0    0.00    0.00 289549110         object_dynamic_cast_assert [106]


Laurent

Re: [Qemu-devel] QOM cast debug

[Paolo Bonzini]

Il 20/03/2014 14:24, Laurent Desnogues ha scritto:
> On Thu, Mar 20, 2014 at 1:45 PM, Paolo Bonzini <pbonzini@redhat.com> wrote:
>> Il 20/03/2014 11:52, Laurent Desnogues ha scritto:
>>
>>> Hello,
>>>
>>> while looking at some perf results, I saw object_dynamic_cast_assert
>>> taking more than 3% of the run time.
>>>
>>> After some digging I found out that this time can be cut by passing
>>> --disable-qom-cast-debug to configure.  This was added by Paolo:
>>>
>>> commit 3556c233d931ad5ffa46a35cb25cfc057732ebb8
>>> Author: Paolo Bonzini <pbonzini@redhat.com>
>>> Date:   Fri May 10 14:16:40 2013 +0200
>>>
>>>     qom: allow turning cast debugging off
>>>
>>>     Cast debugging can have a substantial cost (20% or more).  Instead of
>>> adding
>>>     special-cased "fast casts" in the hot paths, we can just disable it in
>>>     releases.  The tracing facilities we just added make it easier to
>>> analyze
>>>     those problems that cast debugging would reveal.
>>>
>>> I find it odd that the default is to have this debug flag on by
>>> default while the other such debug options are off.  Wouldn't it make
>>> more sense to have it off by default and let devs turn it on?
>>
>>
>> I agree, but Anthony (and Andreas?) did not.
>>
>> Which path is calling object_dynamic_cast_assert so much?  It was agreed to
>> just use C casts in hot code.
>
> The culprit seems to be ENV_GET_CPU:
>
> #define ENV_GET_CPU(e) CPU(arm_env_get_cpu(e))
> #define CPU(obj) OBJECT_CHECK(CPUState, (obj), TYPE_CPU)
> #define OBJECT_CHECK(type, obj, name) \
>     ((type *)object_dynamic_cast_assert(OBJECT(obj), (name), \
>                                         __FILE__, __LINE__, __func__))
>
>                 0.00    0.00 1391069/289549110     io_writel [46]
>                 0.00    0.00 2038947/289549110     helper_le_stl_mmu [32]
>                 0.00    0.00 3986870/289549110     helper_ret_ldub_mmu [31]
>                 0.00    0.00 8131587/289549110     helper_ret_ldb_cmmu [28]
>                 0.00    0.00 17849223/289549110     helper_le_ldul_mmu [18]
>                 0.00    0.00 32244969/289549110     tb_find_slow [26]
>                 0.00    0.00 32347716/289549110
> arm_cpu_handle_mmu_fault [11]
>                 0.00    0.00 32347737/289549110     get_phys_addr_v6 [17]
>                 0.00    0.00 32598025/289549110     get_page_addr_code [27]
>                 0.00    0.00 124705628/289549110     tb_find_fast [25]
> [106]    0.0    0.00    0.00 289549110         object_dynamic_cast_assert [106]

Andreas, why can't we just do (CPUState *) in the actual ENV_GET_CPU 
macro?  It's pretty much assured to be called by hot spots.

Paolo