You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@samza.apache.org by "Chris Riccomini (JIRA)" <ji...@apache.org> on 2014/08/14 03:14:11 UTC

[jira] [Updated] (SAMZA-379) Turn down verbosity of debug logging

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

Chris Riccomini updated SAMZA-379:
----------------------------------

    Attachment: SAMZA-379-0.patch

Attaching patch. RB at:

https://reviews.apache.org/r/24684/

* Changed debug() to trace() in SystemConsumers for all log calls that are called inside RunLoop.run.
* Changed debug() to trace() for some send() calls in KafkaSystemProducer.

For testing, I ran against hello-samza, and turned on debug logging. The goal was to verify that we didn't get megs and megs of logs spewing out when doing this. Here's a 2 second snippt:

{noformat}
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 420 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 420 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 422 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 422 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:41 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 424 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:41 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 424 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 426 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 426 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 428 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 428 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 430 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 430 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 432 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 432 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 JvmMetrics [DEBUG] updating jvm metrics
2014-08-13 18:02:42 JvmMetrics [DEBUG] updated metrics to: [34.649727, 35.5, 20.738724, 46.5, 0, 9, 0, 4, 8, 0, 20, 109]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Handling 1 events
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Getting broker partition info for topic wikipedia-edits
2014-08-13 18:02:42 BrokerPartitionInfo [DEBUG] Partition [wikipedia-edits,0] has leader 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Broker partitions registered for topic: wikipedia-edits are 0
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Sending 1 messages with no compression to [wikipedia-edits,0]
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sending messages with correlation id 434 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
2014-08-13 18:02:42 DefaultEventHandler [DEBUG] Producer sent messages with correlation id 434 for topics [wikipedia-edits,0] to broker 0 on 192.168.1.107:9092
{noformat}

As you can see, the only log lines are from the Kafka client, itself.

Running the job in debug mode for 13 seconds, plus the initial info level logging while starting up yielded a log size of only 88kb, which is totally acceptable.

> Turn down verbosity of debug logging
> ------------------------------------
>
>                 Key: SAMZA-379
>                 URL: https://issues.apache.org/jira/browse/SAMZA-379
>             Project: Samza
>          Issue Type: Bug
>          Components: container
>    Affects Versions: 0.8.0
>            Reporter: Chris Riccomini
>            Assignee: Chris Riccomini
>             Fix For: 0.8.0
>
>         Attachments: SAMZA-379-0.patch
>
>
> We currently use debug() logging in a lot of spaces where we should use trace() logging. This makes it really hard to debug. For example, all of the stuff in SystemConsumers that the container polls in a tight loop should be trace-level logging. Right now, turning on debugging spews way too much information in the logs.



--
This message was sent by Atlassian JIRA
(v6.2#6252)