You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cocoon.apache.org by Stefano Mazzocchi <st...@apache.org> on 2003/11/02 10:36:03 UTC

Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:

> And finally, on a somewhat unrelated subject, one thing that I've 
> always wanted Cocoon to do may be possible if support for collecting 
> the XML at each pipeline step is added.  To aid in debugging, I think 
> it would be very helpful to switch on some kind of debug mode, that 
> would cause a trace of what pipeline steps where executed and the 
> state of the XML at each step to be printed out at the bottom of each 
> page you output to the browser.  This way it is easy for a developer 
> to see the path though the pipelines the request took, as well as a 
> snapshot of the XML each step of the way.

This is already there, althought somewhat hidden, check into the 
"profiler" block.

BTW, there is something that always bugged me about the profiler: the 
time that gives you is almost totally useless, while the exposed view 
of the pipeline internals is a *great* debugging tool (some people do 
it with views, but sometimes you don't know where the problem is so you 
might want to see it all).

I propose two changes here:

1) rename the "profiling" pipeline into "debug"
2) remove the timings (they don't make any sense)
3) move the whole thing into core

WTYT?

--
Stefano.


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Vadim Gritsenko <va...@verizon.net>.
Nicola Ken Barozzi wrote:

> Berin Loritsch wrote:
> ...
>
>>
>>
>> I have a feeling the timings are useless largely because of the 
>> granularity
>> of the System.getTimeInMillis() method.  On Windows the granularity 
>> is 10 ms.
>> If the timing is less than that it registers as 0.  Add enough zeros 
>> and it
>> will always be less than the total time for the timing.
>
>
> There is a way of getting around this by using JNI and calling the 
> correct stuff. If you Google round you will sure find something. 
> Probably there is something at www.javaworld.com.


It's JavaPRO [1]. Any takers? :)

Vadim


[1] 
http://www.fawcette.com/archives/premier/mgznarch/javapro/2001/08aug01/km0108/km0108-2.asp



Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Thor Heinrichs-Wolpert <th...@lunartek.com>.
If you try to profile on a Unix environment based on timings you have 
to do multiple passes and get a statistical average to be meaningful.  
The timer functionality in the kernel or user space is at such a low 
priority that effectively it jumps between values ... that's why when 
tuning using tools like sar you have to set a decent sample size.  This 
is pretty much the case for any current non-realtime OS.  For long 
running tasks the time is probably OK, for small times ( < 10 ms  or 
even .1s timings ) on a busy system the times are just erroneous.

Cheers,
Thor HW

On 3-Nov-03, at 9:36 AM, Nicola Ken Barozzi wrote:

> Berin Loritsch wrote:
> ...
>> I have a feeling the timings are useless largely because of the 
>> granularity
>> of the System.getTimeInMillis() method.  On Windows the granularity 
>> is 10 ms.
>> If the timing is less than that it registers as 0.  Add enough zeros 
>> and it
>> will always be less than the total time for the timing.
>
> There is a way of getting around this by using JNI and calling the 
> correct stuff. If you Google round you will sure find something. 
> Probably there is something at www.javaworld.com.
>
> -- 
> Nicola Ken Barozzi                   nicolaken@apache.org
>             - verba volant, scripta manent -
>    (discussions get forgotten, just code remains)
> ---------------------------------------------------------------------
>
>
>


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Nicola Ken Barozzi <ni...@apache.org>.
Berin Loritsch wrote:
...
> 
> 
> I have a feeling the timings are useless largely because of the granularity
> of the System.getTimeInMillis() method.  On Windows the granularity is 
> 10 ms.
> If the timing is less than that it registers as 0.  Add enough zeros and it
> will always be less than the total time for the timing.

There is a way of getting around this by using JNI and calling the 
correct stuff. If you Google round you will sure find something. 
Probably there is something at www.javaworld.com.

-- 
Nicola Ken Barozzi                   nicolaken@apache.org
             - verba volant, scripta manent -
    (discussions get forgotten, just code remains)
---------------------------------------------------------------------



Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Berin Loritsch <bl...@apache.org>.
Antonio Gallardo wrote:

> Stefano Mazzocchi dijo:
> 
>>On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>>
>>
>>>And finally, on a somewhat unrelated subject, one thing that I've
>>>always wanted Cocoon to do may be possible if support for collecting
>>>the XML at each pipeline step is added.  To aid in debugging, I think
>>>it would be very helpful to switch on some kind of debug mode, that
>>>would cause a trace of what pipeline steps where executed and the
>>>state of the XML at each step to be printed out at the bottom of each
>>>page you output to the browser.  This way it is easy for a developer
>>>to see the path though the pipelines the request took, as well as a
>>>snapshot of the XML each step of the way.
>>
>>This is already there, althought somewhat hidden, check into the
>>"profiler" block.
>>
>>BTW, there is something that always bugged me about the profiler: the
>>time that gives you is almost totally useless, while the exposed view
>>of the pipeline internals is a *great* debugging tool (some people do
>>it with views, but sometimes you don't know where the problem is so you
>>might want to see it all).
>>
>>I propose two changes here:
>>
>>1) rename the "profiling" pipeline into "debug"
>>2) remove the timings (they don't make any sense)
>>3) move the whole thing into core
> 
> 
>>WTYT?
> 
> 
> +1 on 1)
> 
> +- ? 2) What are the timings? Sorry, I don't understand this point.

I have a feeling the timings are useless largely because of the granularity
of the System.getTimeInMillis() method.  On Windows the granularity is 10 ms.
If the timing is less than that it registers as 0.  Add enough zeros and it
will always be less than the total time for the timing.


-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Antonio Gallardo <ag...@agsoftware.dnsalias.com>.
Stefano Mazzocchi dijo:
>
> On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>
>> And finally, on a somewhat unrelated subject, one thing that I've
>> always wanted Cocoon to do may be possible if support for collecting
>> the XML at each pipeline step is added.  To aid in debugging, I think
>> it would be very helpful to switch on some kind of debug mode, that
>> would cause a trace of what pipeline steps where executed and the
>> state of the XML at each step to be printed out at the bottom of each
>> page you output to the browser.  This way it is easy for a developer
>> to see the path though the pipelines the request took, as well as a
>> snapshot of the XML each step of the way.
>
> This is already there, althought somewhat hidden, check into the
> "profiler" block.
>
> BTW, there is something that always bugged me about the profiler: the
> time that gives you is almost totally useless, while the exposed view
> of the pipeline internals is a *great* debugging tool (some people do
> it with views, but sometimes you don't know where the problem is so you
> might want to see it all).
>
> I propose two changes here:
>
> 1) rename the "profiling" pipeline into "debug"
> 2) remove the timings (they don't make any sense)
> 3) move the whole thing into core

> WTYT?

+1 on 1)

+- ? 2) What are the timings? Sorry, I don't understand this point.

-1 on 3) It is desired to have a very light core. If the core can live
without the profiler please don't include them on every distribution. I
mean development and production.

Best Regards,

Antonio Gallardo




Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Antonio Gallardo <ag...@agsoftware.dnsalias.com>.
Stefano Mazzocchi dijo:
>>>> I propose two changes here:
>>>>
>>>> 1) rename the "profiling" pipeline into "debug"
>>>>
>>>
>>> +1
>>>
>>
>> -0. Current name suits me well.
>
> I see, but people that look for debugging the pipeline will not find it
> (since profiling is not the same as debugging).
>
> Maybe "pipe-instrumentation"?

what about:

cocoon-instrumentation

Because if we will include there also the current instrumentation then we
are talking also about components. Not only about pipes.

>>>> 3) move the whole thing into core
>>>>
>>>
>>> -1, the core should only contain necessary components.
>>>
>>
>> +1, I wouldn't mind seeing it in core. It's like instrumentation
>> manager which is also in core.
>
> which I would like to be moved away as well... maybe an
> "instrumentation" block with both? I don't know. WDYT?

+1

Best Regards,

Antonio Gallardo




Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Torsten Curdt <tc...@vafer.org>.
>> "instrumentation" block can be a good place for both.
> 
> 
> The problem is that the instrumentation code is not (easily) 
> modularizable as it's intermixed with a bunch of places (in short, is an 
> aspect, not an object).

I haven't looked into this yet but... Doesn't instrumentation also work
through java bytecode transformation?

So having a special classloader inside an intrumenation block
that transforms the classes should be enough... IMO

...or what am I here missing?

cheers
--
Torsten


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Stefano Mazzocchi <st...@apache.org>.
On Sunday, Nov 2, 2003, at 20:32 Europe/Rome, Vadim Gritsenko wrote:

> Stefano Mazzocchi wrote:
>
>>>>> 3) move the whole thing into core
>>>>>
>>>>
>>>> -1, the core should only contain necessary components.
>>>
>>>
>>> +1, I wouldn't mind seeing it in core. It's like instrumentation 
>>> manager which is also in core.
>>
>>
>> which I would like to be moved away as well... maybe an 
>> "instrumentation" block with both? I don't know. WDYT?
>
>
> "instrumentation" block can be a good place for both.

The problem is that the instrumentation code is not (easily) 
modularizable as it's intermixed with a bunch of places (in short, is 
an aspect, not an object).

This is a much bigger issue that is seems at first sight :-/

--
Stefano.


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Vadim Gritsenko <va...@verizon.net>.
Stefano Mazzocchi wrote:

>>>> 3) move the whole thing into core
>>>>
>>>
>>> -1, the core should only contain necessary components.
>>
>>
>> +1, I wouldn't mind seeing it in core. It's like instrumentation 
>> manager which is also in core.
>
>
> which I would like to be moved away as well... maybe an 
> "instrumentation" block with both? I don't know. WDYT?


"instrumentation" block can be a good place for both.

Vadim



Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Stefano Mazzocchi <st...@apache.org>.
On Monday, Nov 3, 2003, at 11:53 Europe/Rome, Stephan Michels wrote:

>
>
> On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:
>
>>
>> On Sunday, Nov 2, 2003, at 15:57 Europe/Rome, Vadim Gritsenko wrote:
>>
>>> Stephan Michels wrote:
>>>
>>>> On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:
>>>>
>>>>
>>>>> On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>>>>>
>>>>>
>>>>>> And finally, on a somewhat unrelated subject, one thing that I've
>>>>>> always wanted Cocoon to do may be possible if support for 
>>>>>> collecting
>>>>>> the XML at each pipeline step is added.  To aid in debugging, I
>>>>>> think
>>>>>> it would be very helpful to switch on some kind of debug mode, 
>>>>>> that
>>>>>> would cause a trace of what pipeline steps where executed and the
>>>>>> state of the XML at each step to be printed out at the bottom of
>>>>>> each
>>>>>> page you output to the browser.  This way it is easy for a 
>>>>>> developer
>>>>>> to see the path though the pipelines the request took, as well as 
>>>>>> a
>>>>>> snapshot of the XML each step of the way.
>>>>>>
>>>>> This is already there, althought somewhat hidden, check into the
>>>>> "profiler" block.
>>>>>
>>>>> BTW, there is something that always bugged me about the profiler: 
>>>>> the
>>>>> time that gives you is almost totally useless,
>>>>>
>>>
>>> (IIRC) Stephan did a lot of work on how profiler counts time, and now
>>> it's not useless at all.
>>
>> ah, didn't know that! I used it a while ago and it seemed to me that
>> the numbers were totally silly.
>>
>> Stephan, can you explain the changes (or point me to a message that
>> explains it)? thanks.
>
> All I made was to use XMLByteStreamInterpreter/Compiler as a buffer,
> measure each sitemap component separate.
>
> G -> Buffer1
>
> Buffer1 -> T1 -> Buffer2
>
> etc.
>
> The side effect is that you can use these buffers to get intermediate
> document as debug information.
>
> (Buffer(n) -> Buffer(n+1) take in most cases less than a 1ms)
>
> I also measure the time for setup(), which needs in some special cases
> 400 times more time.

Ok, great. Makes perfect sense. Sorry for the noise.

--
Stefano.


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Stephan Michels <st...@apache.org>.

On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:

>
> On Sunday, Nov 2, 2003, at 15:57 Europe/Rome, Vadim Gritsenko wrote:
>
> > Stephan Michels wrote:
> >
> >> On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:
> >>
> >>
> >>> On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
> >>>
> >>>
> >>>> And finally, on a somewhat unrelated subject, one thing that I've
> >>>> always wanted Cocoon to do may be possible if support for collecting
> >>>> the XML at each pipeline step is added.  To aid in debugging, I
> >>>> think
> >>>> it would be very helpful to switch on some kind of debug mode, that
> >>>> would cause a trace of what pipeline steps where executed and the
> >>>> state of the XML at each step to be printed out at the bottom of
> >>>> each
> >>>> page you output to the browser.  This way it is easy for a developer
> >>>> to see the path though the pipelines the request took, as well as a
> >>>> snapshot of the XML each step of the way.
> >>>>
> >>> This is already there, althought somewhat hidden, check into the
> >>> "profiler" block.
> >>>
> >>> BTW, there is something that always bugged me about the profiler: the
> >>> time that gives you is almost totally useless,
> >>>
> >
> > (IIRC) Stephan did a lot of work on how profiler counts time, and now
> > it's not useless at all.
>
> ah, didn't know that! I used it a while ago and it seemed to me that
> the numbers were totally silly.
>
> Stephan, can you explain the changes (or point me to a message that
> explains it)? thanks.

All I made was to use XMLByteStreamInterpreter/Compiler as a buffer,
measure each sitemap component separate.

G -> Buffer1

Buffer1 -> T1 -> Buffer2

etc.

The side effect is that you can use these buffers to get intermediate
document as debug information.

(Buffer(n) -> Buffer(n+1) take in most cases less than a 1ms)

I also measure the time for setup(), which needs in some special cases
400 times more time.

Stephan.


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Stefano Mazzocchi <st...@apache.org>.
On Sunday, Nov 2, 2003, at 15:57 Europe/Rome, Vadim Gritsenko wrote:

> Stephan Michels wrote:
>
>> On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:
>>
>>
>>> On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>>>
>>>
>>>> And finally, on a somewhat unrelated subject, one thing that I've
>>>> always wanted Cocoon to do may be possible if support for collecting
>>>> the XML at each pipeline step is added.  To aid in debugging, I 
>>>> think
>>>> it would be very helpful to switch on some kind of debug mode, that
>>>> would cause a trace of what pipeline steps where executed and the
>>>> state of the XML at each step to be printed out at the bottom of 
>>>> each
>>>> page you output to the browser.  This way it is easy for a developer
>>>> to see the path though the pipelines the request took, as well as a
>>>> snapshot of the XML each step of the way.
>>>>
>>> This is already there, althought somewhat hidden, check into the
>>> "profiler" block.
>>>
>>> BTW, there is something that always bugged me about the profiler: the
>>> time that gives you is almost totally useless,
>>>
>
> (IIRC) Stephan did a lot of work on how profiler counts time, and now 
> it's not useless at all.

ah, didn't know that! I used it a while ago and it seemed to me that 
the numbers were totally silly.

Stephan, can you explain the changes (or point me to a message that 
explains it)? thanks.

> For example, I recently used profiler with different XSLT engines and 
> found out that XSLTC finally became a tad faster than Saxon. Also, I 
> found couple of stylesheets which were rewritten as transformers to 
> gain some speed improvements.

Very cool. Then I remove my proposal.

>>> while the exposed view
>>> of the pipeline internals is a *great* debugging tool
>>>
>
> Never tried it (yet)! :)
>
>
>>> (some people do
>>> it with views, but sometimes you don't know where the problem is so 
>>> you
>>> might want to see it all).
>>>
>>> I propose two changes here:
>>>
>>> 1) rename the "profiling" pipeline into "debug"
>>>
>>
>> +1
>>
>
> -0. Current name suits me well.

I see, but people that look for debugging the pipeline will not find it 
(since profiling is not the same as debugging).

Maybe "pipe-instrumentation"?

>>> 2) remove the timings (they don't make any sense)
>>>
>>
>> -1, why do you think the timings are useless?! I done a lot of 
>> profiling
>> with it in the past, and found for example the problem with the 
>> use-store
>> paramter of the TaxTransformer.
>>
>
> -1, it's useful to me.

I remove my proposal after your comments above.

>>> 3) move the whole thing into core
>>>
>>
>> -1, the core should only contain necessary components.
>>
>
> +1, I wouldn't mind seeing it in core. It's like instrumentation 
> manager which is also in core.

which I would like to be moved away as well... maybe an 
"instrumentation" block with both? I don't know. WDYT?

--
Stefano.


Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Vadim Gritsenko <va...@verizon.net>.
Stephan Michels wrote:

>On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:
>
>  
>
>>On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>>
>>    
>>
>>>And finally, on a somewhat unrelated subject, one thing that I've
>>>always wanted Cocoon to do may be possible if support for collecting
>>>the XML at each pipeline step is added.  To aid in debugging, I think
>>>it would be very helpful to switch on some kind of debug mode, that
>>>would cause a trace of what pipeline steps where executed and the
>>>state of the XML at each step to be printed out at the bottom of each
>>>page you output to the browser.  This way it is easy for a developer
>>>to see the path though the pipelines the request took, as well as a
>>>snapshot of the XML each step of the way.
>>>      
>>>
>>This is already there, althought somewhat hidden, check into the
>>"profiler" block.
>>
>>BTW, there is something that always bugged me about the profiler: the
>>time that gives you is almost totally useless,
>>

(IIRC) Stephan did a lot of work on how profiler counts time, and now 
it's not useless at all. For example, I recently used profiler with 
different XSLT engines and found out that XSLTC finally became a tad 
faster than Saxon. Also, I found couple of stylesheets which were 
rewritten as transformers to gain some speed improvements.


>>while the exposed view
>>of the pipeline internals is a *great* debugging tool
>>

Never tried it (yet)! :)


>>(some people do
>>it with views, but sometimes you don't know where the problem is so you
>>might want to see it all).
>>
>>I propose two changes here:
>>
>>1) rename the "profiling" pipeline into "debug"
>>    
>>
>
>+1
>  
>

-0. Current name suits me well.


>>2) remove the timings (they don't make any sense)
>>    
>>
>
>-1, why do you think the timings are useless?! I done a lot of profiling
>with it in the past, and found for example the problem with the use-store
>paramter of the TaxTransformer.
>  
>

-1, it's useful to me.


>>3) move the whole thing into core
>>    
>>
>
>-1, the core should only contain necessary components.
>  
>

+1, I wouldn't mind seeing it in core. It's like instrumentation manager 
which is also in core.

Vadim



Re: Profiling Pipeline [was Re: [RT] Unit testing and CocoonUnit]

Posted by Stephan Michels <st...@apache.org>.

On Sun, 2 Nov 2003, Stefano Mazzocchi wrote:

>
> On Saturday, Nov 1, 2003, at 23:29 Europe/Rome, Steve K wrote:
>
> > And finally, on a somewhat unrelated subject, one thing that I've
> > always wanted Cocoon to do may be possible if support for collecting
> > the XML at each pipeline step is added.  To aid in debugging, I think
> > it would be very helpful to switch on some kind of debug mode, that
> > would cause a trace of what pipeline steps where executed and the
> > state of the XML at each step to be printed out at the bottom of each
> > page you output to the browser.  This way it is easy for a developer
> > to see the path though the pipelines the request took, as well as a
> > snapshot of the XML each step of the way.
>
> This is already there, althought somewhat hidden, check into the
> "profiler" block.
>
> BTW, there is something that always bugged me about the profiler: the
> time that gives you is almost totally useless, while the exposed view
> of the pipeline internals is a *great* debugging tool (some people do
> it with views, but sometimes you don't know where the problem is so you
> might want to see it all).
>
> I propose two changes here:
>
> 1) rename the "profiling" pipeline into "debug"

+1

> 2) remove the timings (they don't make any sense)

-1, why do you think the timings are useless?! I done a lot of profiling
with it in the past, and found for example the problem with the use-store
paramter of the TaxTransformer.

> 3) move the whole thing into core

-1, the core should only contain necessary components.

Stephan.