Duplicate logs observer in cruise control

[saeedya]

On below link
https://github.com/linkedin/cruise-control/blob/137b1fe0552c4aa49ebc900b75786eeee033bbe7/cruise-control/src/main/java/com/linkedin/kafka/cruisecontrol/servlet/handler/async/AbstractAsyncRequest.java
In the method "CruiseControlResponse" , i can see some duplicate logs. This my sample log file:

6231 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:34.908+00:00", "severity": "info", "message": "### Processing async request CruiseControlStateRequest.", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": {"file": "### AbstractAsyncRequest.java", "line": "49", }}
6232 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:34.908+00:00", "severity": "info", "message": "### Processing async request CruiseControlStateRequest.", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": {"file": "### AbstractAsyncRequest.java", "line": "49", }}
6299 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:35.066+00:00", "severity": "info", "message": "### Computation is completed for async request: /state.", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": {"file": "### AbstractAsyncRequest.java", "line": "57", }}
6300 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:35.066+00:00", "severity": "info", "message": ### "Computation is completed for async request: /state.", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": {"file": ### "AbstractAsyncRequest.java", "line": "57", }}
6301 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:35.094+00:00", "severity": "info", ### "message": "127.0.0.1 - user [02/Feb/2024:14:49:34 +0000] "GET /kafkacruiseco ntrol/state HTTP/1.1" 200 1095", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": ### {"file": "Slf4jRequestLogWriter.java ", "line": "62", }}
6302 {"version": "1.2.0", "timestamp": "2024-02-02T14:49:35.094+00:00", "severity": "info", ### "message": "127.0.0.1 - user [02/Feb/2024:14:49:34 +0000] "GET /kafkacruiseco ntrol/state HTTP/1.1" 200 1095", "metadata": {"container_name": "cruise-control", "pod_name": "extra_data": ### {"file": "Slf4jRequestLogWriter.java ", "line": "62", }}

Regards,
Saeed

[saeedya]

Hi @scholzj
Can you please help me with this?
Kind Regards,
Saeed

[scholzj]

I have no idea I'm afraid - I do not know much about Cruise Control.

[marcelloromani]

Why do you think there's duplication? What would you change in the log message?

[vasilisa-za]

Root cause of the issue seems to be log4j configuration here. kafkaCruiseControlFile appender added for both root and com.linkedin.kafka.cruisecontrol loggers, resulting in messaged being appended twice.

Verified by running by simple test locally:

1. Same appender added for two intersected loggers results in duplicated message:
   

2. Commenting out appender for one of the loggers removes message duplication:
   

[vasilisa-za]

Looks like original intent of logging everything into console and additionally com.linkedin.kafka.cruisecontrol into dedicated file appender was broken in this PR.

Could you please assign this issue to me, so I could raise a PR to fix it?