lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Yonik Seeley (Issue Comment Edited) (JIRA)" <j...@apache.org>
Subject [jira] [Issue Comment Edited] (SOLR-3157) custom logging
Date Mon, 27 Feb 2012 16:22:55 GMT

    [ https://issues.apache.org/jira/browse/SOLR-3157?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13217250#comment-13217250
] 

Yonik Seeley edited comment on SOLR-3157 at 2/27/12 4:21 PM:
-------------------------------------------------------------

Here's a patch that changes the log format for tests to something that should be easier to
debug tests with multiple core containers.

Example:

{code}
18808 T=64 C3 UPDATE /update {waitSearcher=true&wt=javabin&wt=javabin&commit_end_point=true&commit=true&version=2&version=2}
{commit=} 0 60
18809 T=61 C2 UPDATE /update {waitSearcher=true&wt=javabin&commit=true&version=2}
{commit=} 0 94
18810 T=1 oascc.ZkStateReader.updateCloudState Manual update of cluster state initiated
18811 T=1 oascc.ZkStateReader.updateCloudState Updating cloud state from ZooKeeper... 
18855 T=99 C1 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=190
status=0 QTime=35 
18864 T=100 C3 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=189
status=0 QTime=1 
18868 T=101 C2 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=180
status=0 QTime=1 
{code}

- first number is milliseconds since the start of the test.  Makes it easy to sort by the
first number or subtract to get elapsed time, and is more relevant to a short running test.
- T=101 is the thread ID... this will be useful for any multi-threaded test.
- C2 is the core number.  we don't use core name since there can be multiple core containers
with the same name (like "") in these distributed tests.
- package names just use the first letters catenated together for brevity
- aliases for common log output are implemented (REQ and UPDATE)
- I got rid of the double logging for updates
- single line format is easier to read and  easier to grep and do things with scripts
- the first time a core is seen (or whenever it's cloudstate changes) that is output.  This
allows correlation of C2 with URLs.
For example, if we want to know about core C2, we search back in the logs for C2_STATE and
see
{code}
ASYNC  NEW_CORE C2 name= org.apache.solr.core.SolrCore@22e38fca url=http://127.0.0.1:58141/solr/
node=127.0.0.1:58141_solr C2_STATE=coll:collection1 core: props:{num_shards=3, shard=shard3,
state=active, core=, collection=collection1, node_name=127.0.0.1:58141_solr, base_url=http://127.0.0.1:58141/solr}
{code}

We can only currently do core / container correlation when SolrRequestInfo is set (i.e. request
handler requests).  I tried setting a ThreadGroup for the jetty instances we spin up, but
they didn't stick (request threads were still part of the main thread group).  Still, I think
this is moving in the right direction.
                
      was (Author: yseeley@gmail.com):
    Here's a patch that changes the log format for tests to something that should be easier
to debug tests with multiple core containers.

Example:

{code}
18808 T=64 C3 UPDATE /update {waitSearcher=true&wt=javabin&wt=javabin&commit_end_point=true&commit=true&version=2&version=2}
{commit=} 0 60
18809 T=61 C2 UPDATE /update {waitSearcher=true&wt=javabin&commit=true&version=2}
{commit=} 0 94
18810 T=1 oascc.ZkStateReader.updateCloudState Manual update of cluster state initiated
18811 T=1 oascc.ZkStateReader.updateCloudState Updating cloud state from ZooKeeper... 
18855 T=99 C1 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=190
status=0 QTime=35 
18864 T=100 C3 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=189
status=0 QTime=1 
18868 T=101 C2 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=180
status=0 QTime=1 
{code}

- first number is milliseconds since the start of the test.  Makes it easy to sort by the
first number or subtract to get elapsed time, and is more relevant to a short running test.
- T=101 is the thread ID... this will be useful for any multi-threaded test.
- C2 is the core number.  we don't use core name since there can be multiple core containers
with the same name (like "") in these distributed tests.
- package names just use the first letters catenated together for brevity
- aliases for common log output are implemented (REQ and UPDATE)
- I got rid of the double logging for updates
- the first time a core is seen (or whenever it's cloudstate changes) that is output.  This
allows correlation of C2 with URLs.
For example, if we want to know about core C2, we search back in the logs for C2_STATE and
see
{code}
ASYNC  NEW_CORE C2 name= org.apache.solr.core.SolrCore@22e38fca url=http://127.0.0.1:58141/solr/
node=127.0.0.1:58141_solr C2_STATE=coll:collection1 core: props:{num_shards=3, shard=shard3,
state=active, core=, collection=collection1, node_name=127.0.0.1:58141_solr, base_url=http://127.0.0.1:58141/solr}
{code}

We can only currently do core / container correlation when SolrRequestInfo is set (i.e. request
handler requests).  I tried setting a ThreadGroup for the jetty instances we spin up, but
they didn't stick (request threads were still part of the main thread group).  Still, I think
this is moving in the right direction.
                  
> custom logging
> --------------
>
>                 Key: SOLR-3157
>                 URL: https://issues.apache.org/jira/browse/SOLR-3157
>             Project: Solr
>          Issue Type: Test
>            Reporter: Yonik Seeley
>            Priority: Blocker
>         Attachments: SOLR-3157.patch
>
>
> We need custom logging to decipher tests with multiple core containers, cores, in a single
JVM.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Mime
View raw message