Snowflake Connector log statements are in a different format than the configured Kafka Connect log format

[yarmiganosca]

Example of Snowflake Connector log statement:

[SecurityManager-1(2981)] INFO net.snowflake.ingest.connection.SecurityManager - Creating Token with subject OPTORO.STAGING_KAFKA_CONNECT

Example of Kafka Connect log statement:

{"timestamp":"2020-01-02 11:12:33,806","level":"INFO","logger":"org.apache.kafka.connect.runtime.rest.RestServer","thread":"qtp1871312485-27317","message":"127.0.0.1 - - [02/Jan/2020:11:12:33 +0000] \"GET /connectors HTTP/1.1\" 200 255  1"}

This prevents us from ingesting the Connector's log statements into our logging pipeline.

[yarmiganosca]

It also prevents us from even knowing when events that triggered log line actually happened, which is a bit of a problem.

[sfc-gh-zli]

That component, SecurityManager, belongs to Snowflake Ingest SDK https://github.com/snowflakedb/snowflake-ingest-java. Please file an issue in their repo if this hasn't been fixed.

[seruman]

@sfc-gh-zli besides SecurityManager, if multiple connectors are running on the same Kafka Connect cluster, there's no way to distinguish their logs.

2020-06-16 17:49:51,416 INFO   ||  
[SF_KAFKA_CONNECTOR] SnowflakeSinkTask[ID:0]:put 220 records   [com.snowflake.kafka.connector.SnowflakeSinkTask]

"2020-06-16 17:52:48,184 INFO   ||  
[SF_KAFKA_CONNECTOR] searched 4 files in ingest report, found 3   [com.snowflake.kafka.connector.internal.SnowflakeIngestionServiceV1]

Also log aggregators usually uses new line to separate new logs. Using new lines inside sometimes causes our log aggregator to merge them to following lines.

eg, following lines ingested as a single log;

2020-06-16 17:52:34,940 INFO   ||  
[SF_KAFKA_CONNECTOR] SnowflakeSinkTask[ID:0]:preCommit   [com.snowflake.kafka.connector.SnowflakeSinkTask]
[task-thread-$connector_name-0] INFO net.snowflake.ingest.SimpleIngestManager - Sending Request UUID - 

[sfc-gh-zli]

Yes, currently it's hard to distinguish their logs. That could be an improvement on our todo list. But we don't have new lines in any log messages. The second issue could be caused by the additional thread of the connector. [task-thread-$connector_name-0] INFO net.snowflake.ingest.SimpleIngestManager - Sending Request UUID - This log is printed by the flusher thread inside the connector,

[seruman]

Seems like it prepends new line to each log here; https://github.com/snowflakedb/snowflake-kafka-connector/blob/1cab4698ff6784db096d49627f077d9f61d80b72/src/main/java/com/snowflake/kafka/connector/internal/Logging.java#L137-L140

But like you said reason might be Snowflake Ingest SDK

[sfc-gh-zli]

I see. We did that for users to easily filter out logs printed by the connector.

[kguelseven]

Hi folks. I just stumbled over this issue. The prepended newlines break the expectations of log collectors and visualizers (in our case Splunk). What is the reason for the new line as shown above? One could actually include the SF_LOG_TAG without the new lines and lines would still be easily filterable.

[sfc-gh-rcheng]

We've updated our logging to use Apache's MDC context. Please take a look at the new logging style if needed. Closing this issue out due to age - please reopen if further discussion is needed.