You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Yonik Seeley (Updated) (JIRA)" <ji...@apache.org> on 2012/02/27 17:14:49 UTC

[jira] [Updated] (SOLR-3157) custom logging

     [ https://issues.apache.org/jira/browse/SOLR-3157?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Yonik Seeley updated SOLR-3157:
-------------------------------

    Attachment: SOLR-3157.patch

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