Align log levels with Confluent standards

[harpaj]

Is your feature request related to a problem? Please describe. The current log levels are logging information at any write process. This is for our usecase with very high throughput writes creating extremely high amounts of logs (for us more than 1GB per hour). It can of course be controlled by raising the log level to WARN, but I would still call this behaviour unexpected.

According to the logging standards from Confluent any logs per event should be logged at DEBUG or TRACE level.

[2024-02-27 10:39:27,500] INFO doLogic - Topic: [DE_PosLoop_AW_Act_Pos], Partition: [0], MinOffset: [13520], MaxOffset: [13520], Records: [1] (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,512] INFO Response Summary - Written Bytes: [78], Written Rows: [6] - (QueryId: [16c296a2-4d7e-4f9c-8241-49e4ec77d00a]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,513] INFO ClickHouse URL: http://clickhouse:8123/kiwa (com.clickhouse.kafka.connect.sink.db.helper.ClickHouseHelperClient)
[2024-02-27 10:39:27,514] INFO batchSize: 6 data ms: 8 send ms: 92 (QueryId: [16c296a2-4d7e-4f9c-8241-49e4ec77d00a]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,514] INFO doInsert - Records: [1] - Topic: [DE_PosLoop_AW_Act_Pos], Partition: [0], MinOffset: [13520], MaxOffset: [13520], (QueryId: [bf27d377-1550-4852-9605-80ef5dd33c5e]) (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,514] INFO Trying to insert [1] records to table name [`DE_PosLoop_AW_Act_Pos`] (QueryId: [bf27d377-1550-4852-9605-80ef5dd33c5e]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
enableDbTopicSplit: false
[2024-02-27 10:39:27,515] INFO Response Summary - Written Bytes: [13], Written Rows: [1] - (QueryId: [c6a50798-43ae-4ec9-a26e-0f2df9bfbd91]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,505] INFO Response Summary - Written Bytes: [39], Written Rows: [3] - (QueryId: [45d69584-3007-4968-adc6-6947de00c657]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,515] INFO batchSize: 1 data ms: 79 send ms: 111 (QueryId: [c6a50798-43ae-4ec9-a26e-0f2df9bfbd91]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,516] INFO batchSize: 3 data ms: 290 send ms: 82 (QueryId: [45d69584-3007-4968-adc6-6947de00c657]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,516] INFO doLogic - Topic: [DE_PosLoop_AW_Cnt_Sta], Partition: [0], MinOffset: [13436], MaxOffset: [13439], Records: [4] (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,516] INFO doInsert - Records: [4] - Topic: [DE_PosLoop_AW_Cnt_Sta], Partition: [0], MinOffset: [13436], MaxOffset: [13439], (QueryId: [76caed6a-d4d8-4baa-ba49-5c58dbc13128]) (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,516] INFO Trying to insert [4] records to table name [`DE_PosLoop_AW_Cnt_Sta`] (QueryId: [76caed6a-d4d8-4baa-ba49-5c58dbc13128]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
enableDbTopicSplit: false
[2024-02-27 10:39:27,511] INFO Response Summary - Written Bytes: [13], Written Rows: [1] - (QueryId: [44f0fa8f-d734-4b98-bb04-d7da8e63f127]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,518] INFO batchSize: 1 data ms: 121 send ms: 80 (QueryId: [44f0fa8f-d734-4b98-bb04-d7da8e63f127]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,518] INFO doLogic - Topic: [DE_SpdLoop_AW_Act_Pos], Partition: [0], MinOffset: [13414], MaxOffset: [13419], Records: [6] (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,519] INFO doInsert - Records: [6] - Topic: [DE_SpdLoop_AW_Act_Pos], Partition: [0], MinOffset: [13414], MaxOffset: [13419], (QueryId: [3384369b-2a38-46d5-a363-353627eb4fe0]) (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,519] INFO Trying to insert [6] records to table name [`DE_SpdLoop_AW_Act_Pos`] (QueryId: [3384369b-2a38-46d5-a363-353627eb4fe0]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
enableDbTopicSplit: false
[2024-02-27 10:39:27,510] INFO Response Summary - Written Bytes: [52], Written Rows: [4] - (QueryId: [345cb56e-05c3-4bfe-8846-e3cc909d3ec7]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,520] INFO batchSize: 4 data ms: 125 send ms: 91 (QueryId: [345cb56e-05c3-4bfe-8846-e3cc909d3ec7]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
[2024-02-27 10:39:27,521] INFO doLogic - Topic: [DE_SpdLoop_AW_Set_Pos], Partition: [0], MinOffset: [13296], MaxOffset: [13297], Records: [2] (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,522] INFO doInsert - Records: [2] - Topic: [DE_SpdLoop_AW_Set_Pos], Partition: [0], MinOffset: [13296], MaxOffset: [13297], (QueryId: [94beacf1-79c9-4a2f-93ad-f1019ae782c8]) (com.clickhouse.kafka.connect.sink.processing.Processing)
[2024-02-27 10:39:27,522] INFO Trying to insert [2] records to table name [`DE_SpdLoop_AW_Set_Pos`] (QueryId: [94beacf1-79c9-4a2f-93ad-f1019ae782c8]) (com.clickhouse.kafka.connect.sink.db.ClickHouseWriter)
enableDbTopicSplit: false

Describe the solution you'd like I would like the Confluent standards being followed and messages that occur for very regular events not to be printed at INFO but instead a lower level.

Describe alternatives you've considered It could be left like it is, maybe with a note in the Logging section of the documentation that explains the use of each log level in the connector.

Additional context For the enableDbTopicSplit: false line that can be seen in the example above I already created a PR #334.

[Paultagoras]

Hi @harpaj thanks for submitting this - will discuss with folks on the team. It's helpful to have some logs to be able to pair request/response, but we might be too chatty with them (especially at volume).

Thanks!

[Paultagoras]

Wondering if this might help with your log size @harpaj - since you can customize log level, are you able to customize the formatter? Using %c{1.} can apparently reduce the size of the class name being printed (as seen here) and that might help reduce some of the volume.

That said, we'll update the documentation to include more details around what we log and why and see if there's a way to cut back on some entries. Thanks for letting us know!