You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@uima.apache.org by "Thilo Goetz (JIRA)" <ui...@incubator.apache.org> on 2008/03/28 08:20:24 UTC

[jira] Created: (UIMA-941) No ProcessTrace events for process calls that take 0ms

No ProcessTrace events for process calls that take 0ms
------------------------------------------------------

                 Key: UIMA-941
                 URL: https://issues.apache.org/jira/browse/UIMA-941
             Project: UIMA
          Issue Type: Bug
          Components: Core Java Framework
    Affects Versions: 2.2.2
         Environment: Windows XP, Java 1.5
            Reporter: Thilo Goetz
            Priority: Minor


Found when testing release candidate 4 of 2.2.2.  Here's the text of an email I wrote.  Adam responded that it's probably a bug.

http://www.mail-archive.com/uima-dev%40incubator.apache.org/msg06565.html

I was just testing CVD for the next release, and tried
out the new performance report feature.  Internally, this
uses the ProcessTrace feature of AnalysisEngine.process().
It seems that if the process() call returns very quickly,
i.e., in 0ms according to the Java timer, no ProcessTrace
sub-events are recorded.  For example, I'm running the
tagger, and here's some output I get:

This one looks fine, as expected:

3/27/08 4:29:52 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
Component Name: HmmTaggerTAE
Event Type: Analysis
Duration: 2078ms (100%)
Sub-events:
    Component Name: WhitespaceTokenizer
    Event Type: Analysis
    Duration: 265ms (12.75%)

    Component Name: Hidden Markov Model - Part of Speech Tagger
    Event Type: Analysis
    Duration: 1813ms (87.25%)

    Component Name: Fixed Flow Controller
    Event Type: Analysis
    Duration: 0ms (0%)

Next one seems to have lost the tagger:

3/27/08 4:30:08 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
Component Name: HmmTaggerTAE
Event Type: Analysis
Duration: 16ms (100%)
Sub-events:
    Component Name: WhitespaceTokenizer
    Event Type: Analysis
    Duration: 16ms (100%)

    Component Name: Fixed Flow Controller
    Event Type: Analysis
    Duration: 0ms (0%)

Finally, this one only has the flow controller:

3/27/08 4:30:19 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
Component Name: HmmTaggerTAE
Event Type: Analysis
Duration: 0ms
Sub-events:
    Component Name: Fixed Flow Controller
    Event Type: Analysis
    Duration: 0ms

Looking at this in the debugger, there are no subevents
there, so it's not a problem with the printing.

Is this expected, or is it a bug?  Seems to me it is a bug,
but I'm not sure from the documentation.

--Thilo



-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Closed: (UIMA-941) No ProcessTrace events for process calls that take 0ms

Posted by "Marshall Schor (JIRA)" <ui...@incubator.apache.org>.
     [ https://issues.apache.org/jira/browse/UIMA-941?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Marshall Schor closed UIMA-941.
-------------------------------

       Resolution: Fixed
    Fix Version/s: 2.3

fixed per Adam's last suggestion

> No ProcessTrace events for process calls that take 0ms
> ------------------------------------------------------
>
>                 Key: UIMA-941
>                 URL: https://issues.apache.org/jira/browse/UIMA-941
>             Project: UIMA
>          Issue Type: Bug
>          Components: Core Java Framework
>    Affects Versions: 2.2.2
>         Environment: Windows XP, Java 1.5
>            Reporter: Thilo Goetz
>            Priority: Minor
>             Fix For: 2.3
>
>
> Found when testing release candidate 4 of 2.2.2.  Here's the text of an email I wrote.  Adam responded that it's probably a bug.
> http://www.mail-archive.com/uima-dev%40incubator.apache.org/msg06565.html
> I was just testing CVD for the next release, and tried
> out the new performance report feature.  Internally, this
> uses the ProcessTrace feature of AnalysisEngine.process().
> It seems that if the process() call returns very quickly,
> i.e., in 0ms according to the Java timer, no ProcessTrace
> sub-events are recorded.  For example, I'm running the
> tagger, and here's some output I get:
> This one looks fine, as expected:
> 3/27/08 4:29:52 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 2078ms (100%)
> Sub-events:
>     Component Name: WhitespaceTokenizer
>     Event Type: Analysis
>     Duration: 265ms (12.75%)
>     Component Name: Hidden Markov Model - Part of Speech Tagger
>     Event Type: Analysis
>     Duration: 1813ms (87.25%)
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms (0%)
> Next one seems to have lost the tagger:
> 3/27/08 4:30:08 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 16ms (100%)
> Sub-events:
>     Component Name: WhitespaceTokenizer
>     Event Type: Analysis
>     Duration: 16ms (100%)
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms (0%)
> Finally, this one only has the flow controller:
> 3/27/08 4:30:19 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 0ms
> Sub-events:
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms
> Looking at this in the debugger, there are no subevents
> there, so it's not a problem with the printing.
> Is this expected, or is it a bug?  Seems to me it is a bug,
> but I'm not sure from the documentation.
> --Thilo

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (UIMA-941) No ProcessTrace events for process calls that take 0ms

Posted by "Adam Lally (JIRA)" <ui...@incubator.apache.org>.
    [ https://issues.apache.org/jira/browse/UIMA-941?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12749523#action_12749523 ] 

Adam Lally commented on UIMA-941:
---------------------------------

In AnalysisEngineImplBase.buildProcessTraceFromMBeanStats, it is specifically checking for a time > 0 before adding an event.  We could remove that check.


I think the intention of that check might have been for remote services where "analysis time" is not available (but "service call time" is), and so it was better to not log an analysis time than to log an artificial time of 0.  A way to fix that would be to set times originally to -1 [indicating not applicable] and change them to 0 the first time any time is logged.  A simpler alternative might be in the case where both service call time and analysis time are 0, to create an Analysis entry in the ProcessTrace, with a time of 0.

> No ProcessTrace events for process calls that take 0ms
> ------------------------------------------------------
>
>                 Key: UIMA-941
>                 URL: https://issues.apache.org/jira/browse/UIMA-941
>             Project: UIMA
>          Issue Type: Bug
>          Components: Core Java Framework
>    Affects Versions: 2.2.2
>         Environment: Windows XP, Java 1.5
>            Reporter: Thilo Goetz
>            Priority: Minor
>
> Found when testing release candidate 4 of 2.2.2.  Here's the text of an email I wrote.  Adam responded that it's probably a bug.
> http://www.mail-archive.com/uima-dev%40incubator.apache.org/msg06565.html
> I was just testing CVD for the next release, and tried
> out the new performance report feature.  Internally, this
> uses the ProcessTrace feature of AnalysisEngine.process().
> It seems that if the process() call returns very quickly,
> i.e., in 0ms according to the Java timer, no ProcessTrace
> sub-events are recorded.  For example, I'm running the
> tagger, and here's some output I get:
> This one looks fine, as expected:
> 3/27/08 4:29:52 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 2078ms (100%)
> Sub-events:
>     Component Name: WhitespaceTokenizer
>     Event Type: Analysis
>     Duration: 265ms (12.75%)
>     Component Name: Hidden Markov Model - Part of Speech Tagger
>     Event Type: Analysis
>     Duration: 1813ms (87.25%)
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms (0%)
> Next one seems to have lost the tagger:
> 3/27/08 4:30:08 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 16ms (100%)
> Sub-events:
>     Component Name: WhitespaceTokenizer
>     Event Type: Analysis
>     Duration: 16ms (100%)
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms (0%)
> Finally, this one only has the flow controller:
> 3/27/08 4:30:19 PM - 10: org.apache.uima.tools.cvd.MainFrame.internalRunAE(1570): INFO: Process trace of AE run:
> Component Name: HmmTaggerTAE
> Event Type: Analysis
> Duration: 0ms
> Sub-events:
>     Component Name: Fixed Flow Controller
>     Event Type: Analysis
>     Duration: 0ms
> Looking at this in the debugger, there are no subevents
> there, so it's not a problem with the printing.
> Is this expected, or is it a bug?  Seems to me it is a bug,
> but I'm not sure from the documentation.
> --Thilo

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.