[jira] [Updated] (KAFKA-513) Add state change log to Kafka brokers

["Swapnil Ghike (JIRA)" <ji...@apache.org>]

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

Swapnil Ghike updated KAFKA-513:
--------------------------------

    Attachment: kafka-513-v4.patch

Uploading patch v4. The comments on the merge tool are written above. Remaining comments - 

A. Logging in kafka - 
11. tried to make the log format more consistent - used [%s,%d] for printing topicAndPartition, logged correlationId when the logging statement was concerned with leaderAndIsrRequest, printed controllerId and controllerEpoch wherever needed. I have tried to ensure that there are no mistakes in the order of parameters to .format() etc, but it would be helpful if you could also scrutinize them as well.
12. Changed state change log logging level to trace, except for certain errors.
13. As you mentioned, it's an excellent idea to mention in ControllerChannelManager whether the leaderAndIsr request is become-leader or become-follower request. Added a change to log that. Added a change to do that on the broker in ReplicaManager.{makeLeader,makeFollower}.
14. Included correlationId in LeaderAndIsrRequest.toString
15. Changed PartitionStateChangeLogger to StateChangeLogger everywhere.
16. Fixed the mentioned typos.
17. Added the state change log entries that you suggested.
18. As discussed offline, kept the wrapper class around Utils.Logging. Providing a logIdent to this class will save us the trouble to specify the broker id in every state change log entry, and it will keep the logging consistent with the regular server logging.
19. The successful lifecycle of a state change request will look like the following (error/discard/abort messages can be included in this sequence in case of failures) - 

On the controller - Controller %d, epoch %d sending become-leader/follower LeaderAndIsr request with correlationId %d to broker %d for partition [%s,%d]
On a broker - [Replica Manager on Broker %d]: Handling LeaderAndIsr request correlationId %d received from controller %d epoch %d for partition [%s,%d]
On the same broker - [Replica Manager on Broker %d]: LeaderAndIsr request correlationId %d received from controller %d epoch %d starting the become-leader/follower transition for partition [%s,%d]
On the same broker - [Replica Manager on Broker %d]: Completed become-leader/follower transition for partition [%s,%d]
On the same broker - [Replica Manager on Broker %d]: Handled LeaderAndIsr request correlationId %d received from controller %d epoch %d for partition [%s,%d]
On the controller - Controller %d received response correlationId %d for a request sent to broker %d

I think KafkaApis is not the right place to include a "received leaderAndIsr request" log entry. since KafkaApis handles all types of requests. We should rather expect to directly see a "Handling LeaderAndIsr request" log entry. On the broker, we don't know whether the received leaderAndIsr request is a become-leader or become-follower request, but I guess it's ok since we log that information in the second statement as seen above and while doing that we log correlationId.

B. I included correlationId in the abstract class RequestOrResponse, probably all its derived classes should include a correlationId.

C. config/log4j.properties now uses a separate controller.log and a separate state-change.log.

D. Our kafka-run-class.sh script removes quotes passed to the command line arguments. Changed it so that the quotes can be passed as such. It's useful for passing values containing whitespaces like "2013-03-01 16:03:43,093".
                
> Add state change log to Kafka brokers
> -------------------------------------
>
>                 Key: KAFKA-513
>                 URL: https://issues.apache.org/jira/browse/KAFKA-513
>             Project: Kafka
>          Issue Type: Sub-task
>    Affects Versions: 0.8
>            Reporter: Neha Narkhede
>            Assignee: Swapnil Ghike
>            Priority: Blocker
>              Labels: p1, replication, tools
>             Fix For: 0.8
>
>         Attachments: kafka-513-v1.patch, kafka-513-v2.patch, kafka-513-v3.patch, kafka-513-v4.patch
>
>   Original Estimate: 96h
>  Remaining Estimate: 96h
>
> Once KAFKA-499 is checked in, every controller to broker communication can be modelled as a state change for one or more partitions. Every state change request will carry the controller epoch. If there is a problem with the state of some partitions, it will be good to have a tool that can create a timeline of requested and completed state changes. This will require each broker to output a state change log that has entries like
> [2012-09-10 10:06:17,280] broker 1 received request LeaderAndIsr() for partition [foo, 0] from controller 2, epoch 1
> [2012-09-10 10:06:17,350] broker 1 completed request LeaderAndIsr() for partition [foo, 0] from controller 2, epoch 1
> On controller, this will look like -
> [2012-09-10 10:06:17,198] controller 2, epoch 1, initiated state change request LeaderAndIsr() for partition [foo, 0]
> We need a tool that can collect the state change log from all brokers and create a per-partition timeline of state changes -
> [foo, 0]
> [2012-09-10 10:06:17,198] controller 2, epoch 1 initiated state change request LeaderAndIsr() 
> [2012-09-10 10:06:17,280] broker 1 received request LeaderAndIsr() from controller 2, epoch 1
> [2012-09-10 10:06:17,350] broker 1 completed request LeaderAndIsr() from controller 2, epoch 1
> This JIRA involves adding the state change log to each broker and adding the tool to create the timeline 

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira