You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by Tomàs Núnez <to...@groupalia.com> on 2013/05/17 18:00:49 UTC

Logging Cassandra queries

Hi!

For quite time I've been having some unexpected loadavg in the cassandra
servers. I suspect there are lots of uncontrolled queries to the cassandra
servers causing this load, but the developers say that there are none, and
the load is due to cassandra internal processes.

Trying to get to the bottom, I've been looking into completed ReadStage and
MutationStage through JMX, and the numbers seem to confirm my theory, but
I'd like to go one step forward and, if possible, list all the queries from
the webservers to the cassandra cluster (just one node would be enough).

I've been playing with cassandra loglevels, and I can see when a Read or a
Write is done, but it would be better if I could knew the CF of the query.
For my tests I've put the in the log4j.server
" log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I
can't see the name of it anywhere.

For the test I'm using Cassandra 0.8.4 (yes, still), as my production
servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing
something wrong? Any hint?

And... could I be more precise when enabling logging? Because right now,
with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information I
won't use ever, and I'd like to enable just what I need to see gets and
seds....

Thanks in advance,
Tomàs

Re: Logging Cassandra queries

Posted by aaron morton <aa...@thelastpickle.com>.
>  (but still the list of classes would be helpful :) )
The source code is the most up to date list of the classes.

This is a talk I did on Cassandra Internals at Apache Con in Feb 2013, unfortunately it looks like the videos will never be released owing to technical snafu's http://www.slideshare.net/aaronmorton/apachecon-nafeb2013

Cass 1.2 also has probabilistic logging of queries. 

I'm doing a cut down version at the Cassandra SF conference in June. 

Cheers
 
-----------------
Aaron Morton
Freelance Cassandra Consultant
New Zealand

@aaronmorton
http://www.thelastpickle.com

On 21/05/2013, at 10:28 AM, Ilya Kirnos <il...@cardspring.com> wrote:

> sure, i think it'd be a useful feature
> 
> 
> On Sat, May 18, 2013 at 4:13 PM, Tomàs Núnez <to...@groupalia.com> wrote:
> If you're looking for logging like "get keyX with CL quorum and slice Y took n millis" 
> 
> That would be even better! Maybe should I file a ticket in Cassandra Jira for this feature? Do you think it would be helpful?
> 
> BTW, just "get keyX" or "set keyX" would work for me. I'll check org.apache.cassandra.thrift.CassandraServer as Aaron suggested (but still the list of classes would be helpful :) )
> 
> Thanks!
> 
> 2013/5/19 Ilya Kirnos <il...@cardspring.com>
> If you're looking for logging like "get keyX with CL quorum and slice Y took n millis" there's nothing like that from what I could find.  We had to modify c* source (CassandraServer.java) to add this query logging to the thrift codepath.
> 
> On May 18, 2013 3:20 PM, "Tomàs Núnez" <to...@groupalia.com> wrote:
> Yes, I read how to do that here, as well:
> http://www.datastax.com/docs/1.1/configuration/logging_options
> 
> But I didn't know what classes to enable logging for the queries... Is there any document with the list of classes with a bit explanation for each of them? I can't find any, and I don't understand java enough to dive through the code....
> 
> Thanks!
> 
> 
> 2013/5/17 aaron morton <aa...@thelastpickle.com>
>> And... could I be more precise when enabling logging? Because right now, with log4j.rootLogger=DEBUG,stdout,R I'm getting a lot of information I won't use ever, and I'd like to enable just what I need to see gets and seds….
> 
> see the example at the bottom of this file about setting the log level for a single class https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties
> 
> You probably want to set it for the org.apache.cassandra.thrift.CassandraServer class. But I cannot remember what the logging is like in 0.8. 
> 
> Cassandra gets faster in the later versions, which normally means doing less work. Upgrading to 1.1 would be the first step I would take in improving performance.  
> 
> Cheers
> 
> -----------------
> Aaron Morton
> Freelance Cassandra Consultant
> New Zealand
> 
> @aaronmorton
> http://www.thelastpickle.com
> 
> On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com> wrote:
> 
>> Hi!
>> 
>> For quite time I've been having some unexpected loadavg in the cassandra servers. I suspect there are lots of uncontrolled queries to the cassandra servers causing this load, but the developers say that there are none, and the load is due to cassandra internal processes. 
>> 
>> Trying to get to the bottom, I've been looking into completed ReadStage and MutationStage through JMX, and the numbers seem to confirm my theory, but I'd like to go one step forward and, if possible, list all the queries from the webservers to the cassandra cluster (just one node would be enough). 
>> 
>> I've been playing with cassandra loglevels, and I can see when a Read or a Write is done, but it would be better if I could knew the CF of the query. For my tests I've put the in the log4j.server " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I can't see the name of it anywhere.
>> 
>> For the test I'm using Cassandra 0.8.4 (yes, still), as my production servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing something wrong? Any hint?
>> 
>> And... could I be more precise when enabling logging? Because right now, with log4j.rootLogger=DEBUG,stdout,R I'm getting a lot of information I won't use ever, and I'd like to enable just what I need to see gets and seds....
>> 
>> Thanks in advance, 
>> Tomàs
>> 
> 
> 
> 
> 
> 
> -- 
> -ilya

Re: Logging Cassandra queries

Posted by Ilya Kirnos <il...@cardspring.com>.
sure, i think it'd be a useful feature


On Sat, May 18, 2013 at 4:13 PM, Tomàs Núnez <to...@groupalia.com>wrote:

> If you're looking for logging like "get keyX with CL quorum and slice Y
>> took n millis"
>
>
> That would be even better! Maybe should I file a ticket in Cassandra Jira
> for this feature? Do you think it would be helpful?
>
> BTW, just "get keyX" or "set keyX" would work for me. I'll
> check org.apache.cassandra.thrift.CassandraServer as Aaron suggested (but
> still the list of classes would be helpful :) )
>
> Thanks!
>
> 2013/5/19 Ilya Kirnos <il...@cardspring.com>
>
>> If you're looking for logging like "get keyX with CL quorum and slice Y
>> took n millis" there's nothing like that from what I could find.  We had to
>> modify c* source (CassandraServer.java) to add this query logging to the
>> thrift codepath.
>>  On May 18, 2013 3:20 PM, "Tomàs Núnez" <to...@groupalia.com>
>> wrote:
>>
>>> Yes, I read how to do that here, as well:
>>> http://www.datastax.com/docs/1.1/configuration/logging_options
>>>
>>> But I didn't know what classes to enable logging for the queries... Is
>>> there any document with the list of classes with a bit explanation for each
>>> of them? I can't find any, and I don't understand java enough to dive
>>> through the code....
>>>
>>> Thanks!
>>>
>>>
>>> 2013/5/17 aaron morton <aa...@thelastpickle.com>
>>>
>>>> And... could I be more precise when enabling logging? Because right
>>>> now, with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of
>>>> information I won't use ever, and I'd like to enable just what I need to
>>>> see gets and seds….
>>>>
>>>>
>>>> see the example at the bottom of this file about setting the log level
>>>> for a single class
>>>> https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties
>>>>
>>>> You probably want to set it for the
>>>> org.apache.cassandra.thrift.CassandraServer class. But I cannot remember
>>>> what the logging is like in 0.8.
>>>>
>>>> Cassandra gets faster in the later versions, which normally means doing
>>>> less work. Upgrading to 1.1 would be the first step I would take in
>>>> improving performance.
>>>>
>>>> Cheers
>>>>
>>>>    -----------------
>>>> Aaron Morton
>>>> Freelance Cassandra Consultant
>>>> New Zealand
>>>>
>>>> @aaronmorton
>>>> http://www.thelastpickle.com
>>>>
>>>> On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com>
>>>> wrote:
>>>>
>>>> Hi!
>>>>
>>>> For quite time I've been having some unexpected loadavg in the
>>>> cassandra servers. I suspect there are lots of uncontrolled queries to the
>>>> cassandra servers causing this load, but the developers say that there are
>>>> none, and the load is due to cassandra internal processes.
>>>>
>>>> Trying to get to the bottom, I've been looking into completed ReadStage
>>>> and MutationStage through JMX, and the numbers seem to confirm my theory,
>>>> but I'd like to go one step forward and, if possible, list all the queries
>>>> from the webservers to the cassandra cluster (just one node would be
>>>> enough).
>>>>
>>>> I've been playing with cassandra loglevels, and I can see when a Read
>>>> or a Write is done, but it would be better if I could knew the CF of the
>>>> query. For my tests I've put the in the log4j.server
>>>> " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I
>>>> can't see the name of it anywhere.
>>>>
>>>> For the test I'm using Cassandra 0.8.4 (yes, still), as my production
>>>> servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing
>>>> something wrong? Any hint?
>>>>
>>>> And... could I be more precise when enabling logging? Because right
>>>> now, with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of
>>>> information I won't use ever, and I'd like to enable just what I need to
>>>> see gets and seds....
>>>>
>>>> Thanks in advance,
>>>> Tomàs
>>>>
>>>>
>>>
>


-- 
-ilya

Re: Logging Cassandra queries

Posted by Tomàs Núnez <to...@groupalia.com>.
>
> If you're looking for logging like "get keyX with CL quorum and slice Y
> took n millis"


That would be even better! Maybe should I file a ticket in Cassandra Jira
for this feature? Do you think it would be helpful?

BTW, just "get keyX" or "set keyX" would work for me. I'll
check org.apache.cassandra.thrift.CassandraServer as Aaron suggested (but
still the list of classes would be helpful :) )

Thanks!

2013/5/19 Ilya Kirnos <il...@cardspring.com>

> If you're looking for logging like "get keyX with CL quorum and slice Y
> took n millis" there's nothing like that from what I could find.  We had to
> modify c* source (CassandraServer.java) to add this query logging to the
> thrift codepath.
> On May 18, 2013 3:20 PM, "Tomàs Núnez" <to...@groupalia.com> wrote:
>
>> Yes, I read how to do that here, as well:
>> http://www.datastax.com/docs/1.1/configuration/logging_options
>>
>> But I didn't know what classes to enable logging for the queries... Is
>> there any document with the list of classes with a bit explanation for each
>> of them? I can't find any, and I don't understand java enough to dive
>> through the code....
>>
>> Thanks!
>>
>>
>> 2013/5/17 aaron morton <aa...@thelastpickle.com>
>>
>>> And... could I be more precise when enabling logging? Because right now,
>>> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information
>>> I won't use ever, and I'd like to enable just what I need to see gets and
>>> seds….
>>>
>>>
>>> see the example at the bottom of this file about setting the log level
>>> for a single class
>>> https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties
>>>
>>> You probably want to set it for the
>>> org.apache.cassandra.thrift.CassandraServer class. But I cannot remember
>>> what the logging is like in 0.8.
>>>
>>> Cassandra gets faster in the later versions, which normally means doing
>>> less work. Upgrading to 1.1 would be the first step I would take in
>>> improving performance.
>>>
>>> Cheers
>>>
>>>    -----------------
>>> Aaron Morton
>>> Freelance Cassandra Consultant
>>> New Zealand
>>>
>>> @aaronmorton
>>> http://www.thelastpickle.com
>>>
>>> On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com>
>>> wrote:
>>>
>>> Hi!
>>>
>>> For quite time I've been having some unexpected loadavg in the cassandra
>>> servers. I suspect there are lots of uncontrolled queries to the cassandra
>>> servers causing this load, but the developers say that there are none, and
>>> the load is due to cassandra internal processes.
>>>
>>> Trying to get to the bottom, I've been looking into completed ReadStage
>>> and MutationStage through JMX, and the numbers seem to confirm my theory,
>>> but I'd like to go one step forward and, if possible, list all the queries
>>> from the webservers to the cassandra cluster (just one node would be
>>> enough).
>>>
>>> I've been playing with cassandra loglevels, and I can see when a Read or
>>> a Write is done, but it would be better if I could knew the CF of the
>>> query. For my tests I've put the in the log4j.server
>>> " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I
>>> can't see the name of it anywhere.
>>>
>>> For the test I'm using Cassandra 0.8.4 (yes, still), as my production
>>> servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing
>>> something wrong? Any hint?
>>>
>>> And... could I be more precise when enabling logging? Because right now,
>>> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information
>>> I won't use ever, and I'd like to enable just what I need to see gets and
>>> seds....
>>>
>>> Thanks in advance,
>>> Tomàs
>>>
>>>
>>

Re: Logging Cassandra queries

Posted by Ilya Kirnos <il...@cardspring.com>.
If you're looking for logging like "get keyX with CL quorum and slice Y
took n millis" there's nothing like that from what I could find.  We had to
modify c* source (CassandraServer.java) to add this query logging to the
thrift codepath.
On May 18, 2013 3:20 PM, "Tomàs Núnez" <to...@groupalia.com> wrote:

> Yes, I read how to do that here, as well:
> http://www.datastax.com/docs/1.1/configuration/logging_options
>
> But I didn't know what classes to enable logging for the queries... Is
> there any document with the list of classes with a bit explanation for each
> of them? I can't find any, and I don't understand java enough to dive
> through the code....
>
> Thanks!
>
>
> 2013/5/17 aaron morton <aa...@thelastpickle.com>
>
>> And... could I be more precise when enabling logging? Because right now,
>> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information
>> I won't use ever, and I'd like to enable just what I need to see gets and
>> seds….
>>
>>
>> see the example at the bottom of this file about setting the log level
>> for a single class
>> https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties
>>
>> You probably want to set it for the
>> org.apache.cassandra.thrift.CassandraServer class. But I cannot remember
>> what the logging is like in 0.8.
>>
>> Cassandra gets faster in the later versions, which normally means doing
>> less work. Upgrading to 1.1 would be the first step I would take in
>> improving performance.
>>
>> Cheers
>>
>>    -----------------
>> Aaron Morton
>> Freelance Cassandra Consultant
>> New Zealand
>>
>> @aaronmorton
>> http://www.thelastpickle.com
>>
>> On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com> wrote:
>>
>> Hi!
>>
>> For quite time I've been having some unexpected loadavg in the cassandra
>> servers. I suspect there are lots of uncontrolled queries to the cassandra
>> servers causing this load, but the developers say that there are none, and
>> the load is due to cassandra internal processes.
>>
>> Trying to get to the bottom, I've been looking into completed ReadStage
>> and MutationStage through JMX, and the numbers seem to confirm my theory,
>> but I'd like to go one step forward and, if possible, list all the queries
>> from the webservers to the cassandra cluster (just one node would be
>> enough).
>>
>> I've been playing with cassandra loglevels, and I can see when a Read or
>> a Write is done, but it would be better if I could knew the CF of the
>> query. For my tests I've put the in the log4j.server
>> " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I
>> can't see the name of it anywhere.
>>
>> For the test I'm using Cassandra 0.8.4 (yes, still), as my production
>> servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing
>> something wrong? Any hint?
>>
>> And... could I be more precise when enabling logging? Because right now,
>> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information
>> I won't use ever, and I'd like to enable just what I need to see gets and
>> seds....
>>
>> Thanks in advance,
>> Tomàs
>>
>>
>>
>
>

Re: Logging Cassandra queries

Posted by Tomàs Núnez <to...@groupalia.com>.
Yes, I read how to do that here, as well:
http://www.datastax.com/docs/1.1/configuration/logging_options

But I didn't know what classes to enable logging for the queries... Is
there any document with the list of classes with a bit explanation for each
of them? I can't find any, and I don't understand java enough to dive
through the code....

Thanks!


2013/5/17 aaron morton <aa...@thelastpickle.com>

> And... could I be more precise when enabling logging? Because right now,
> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information I
> won't use ever, and I'd like to enable just what I need to see gets and
> seds….
>
>
> see the example at the bottom of this file about setting the log level for
> a single class
> https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties
>
> You probably want to set it for the
> org.apache.cassandra.thrift.CassandraServer class. But I cannot remember
> what the logging is like in 0.8.
>
> Cassandra gets faster in the later versions, which normally means doing
> less work. Upgrading to 1.1 would be the first step I would take in
> improving performance.
>
> Cheers
>
> -----------------
> Aaron Morton
> Freelance Cassandra Consultant
> New Zealand
>
> @aaronmorton
> http://www.thelastpickle.com
>
> On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com> wrote:
>
> Hi!
>
> For quite time I've been having some unexpected loadavg in the cassandra
> servers. I suspect there are lots of uncontrolled queries to the cassandra
> servers causing this load, but the developers say that there are none, and
> the load is due to cassandra internal processes.
>
> Trying to get to the bottom, I've been looking into completed ReadStage
> and MutationStage through JMX, and the numbers seem to confirm my theory,
> but I'd like to go one step forward and, if possible, list all the queries
> from the webservers to the cassandra cluster (just one node would be
> enough).
>
> I've been playing with cassandra loglevels, and I can see when a Read or a
> Write is done, but it would be better if I could knew the CF of the query.
> For my tests I've put the in the log4j.server
> " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I
> can't see the name of it anywhere.
>
> For the test I'm using Cassandra 0.8.4 (yes, still), as my production
> servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing
> something wrong? Any hint?
>
> And... could I be more precise when enabling logging? Because right now,
> with *log4j.rootLogger=DEBUG,stdout,R* I'm getting a lot of information I
> won't use ever, and I'd like to enable just what I need to see gets and
> seds....
>
> Thanks in advance,
> Tomàs
>
>
>

Re: Logging Cassandra queries

Posted by aaron morton <aa...@thelastpickle.com>.
> And... could I be more precise when enabling logging? Because right now, with log4j.rootLogger=DEBUG,stdout,R I'm getting a lot of information I won't use ever, and I'd like to enable just what I need to see gets and seds….

see the example at the bottom of this file about setting the log level for a single class https://github.com/apache/cassandra/blob/trunk/conf/log4j-server.properties

You probably want to set it for the org.apache.cassandra.thrift.CassandraServer class. But I cannot remember what the logging is like in 0.8. 

Cassandra gets faster in the later versions, which normally means doing less work. Upgrading to 1.1 would be the first step I would take in improving performance.  

Cheers

-----------------
Aaron Morton
Freelance Cassandra Consultant
New Zealand

@aaronmorton
http://www.thelastpickle.com

On 18/05/2013, at 4:00 AM, Tomàs Núnez <to...@groupalia.com> wrote:

> Hi!
> 
> For quite time I've been having some unexpected loadavg in the cassandra servers. I suspect there are lots of uncontrolled queries to the cassandra servers causing this load, but the developers say that there are none, and the load is due to cassandra internal processes. 
> 
> Trying to get to the bottom, I've been looking into completed ReadStage and MutationStage through JMX, and the numbers seem to confirm my theory, but I'd like to go one step forward and, if possible, list all the queries from the webservers to the cassandra cluster (just one node would be enough). 
> 
> I've been playing with cassandra loglevels, and I can see when a Read or a Write is done, but it would be better if I could knew the CF of the query. For my tests I've put the in the log4j.server " log4j.rootLogger=DEBUG,stdout,R", writing and reading a test CF, and I can't see the name of it anywhere.
> 
> For the test I'm using Cassandra 0.8.4 (yes, still), as my production servers, and also 1.0.11. Maybe this changes in 1.1? Maybe I'm doing something wrong? Any hint?
> 
> And... could I be more precise when enabling logging? Because right now, with log4j.rootLogger=DEBUG,stdout,R I'm getting a lot of information I won't use ever, and I'd like to enable just what I need to see gets and seds....
> 
> Thanks in advance, 
> Tomàs
>