Add thread name and ID to log4j2-defaults.xml

[minyk]

Kyuubi has many thread pools for frontends and backends. So without thread name and ID, logs are barely recognizable for each executions. Following logs are extracted from our testbed:

2023-10-16 15:33:33.356 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: backgroundOperationsLoop exiting
2023-10-16 15:33:33.358 INFO org.apache.zookeeper.ZooKeeper: Session: 0x1091d27535d0219 closed
2023-10-16 15:33:33.358 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x1091d27535d0219
2023-10-16 15:33:33.358 INFO org.apache.kyuubi.operation.LaunchEngine: Processing autouser1%40nexr.com's query[2de35865-10db-47b0-a5b5-6e47022d8c62]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.041 seconds
2023-10-16 15:33:33.362 INFO org.apache.kyuubi.operation.log.OperationLog: Creating operation log file /opt/kyuubi/work/server_operation_logs/f376c0ae-70f5-4ef5-b25b-9f76651f8113/9310c484-057a-48a8-8b77-4d6ebe17823e
2023-10-16 15:33:33.362 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [autouser1%40nexr.com:10.233.122.47] SessionHandle [f376c0ae-70f5-4ef5-b25b-9f76651f8113] - Starting to wait the launch engine operation finished
2023-10-16 15:33:33.362 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [autouser1%40nexr.com:10.233.122.47] SessionHandle [f376c0ae-70f5-4ef5-b25b-9f76651f8113] - Engine has been launched, elapsed time: 0 s
2023-10-16 15:33:33.364 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing autouser1%40nexr.com's query[9310c484-057a-48a8-8b77-4d6ebe17823e]: PENDING_STATE -> RUNNING_STATE, statement:
set spark.ndap.query.invoker=WORKFLOW
2023-10-16 15:33:33.386 INFO org.apache.kyuubi.operation.ExecuteStatement: Query[9310c484-057a-48a8-8b77-4d6ebe17823e] in FINISHED_STATE
2023-10-16 15:33:33.387 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing autouser1%40nexr.com's query[9310c484-057a-48a8-8b77-4d6ebe17823e]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.023 seconds
2023-10-16 15:33:33.389 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing autouser1%40nexr.com's query[9310c484-057a-48a8-8b77-4d6ebe17823e]: FINISHED_STATE -> CLOSED_STATE, time taken: 0.025 seconds
2023-10-16 15:33:33.391 INFO org.apache.kyuubi.client.KyuubiSyncThriftClient: TCloseOperationReq(operationHandle:TOperationHandle(operationId:THandleIdentifier(guid:AD 54 B4 22 A8 E2 43 84 84 C5 BF 77 F4 C8 42 AA, secret:C2 EE 5B 97 3E A0 41 FC AC 16 9B D7 08 ED 8F 38), operationType:EXECUTE_STATEMENT, hasResultSet:true)) succeed on engine side
2023-10-16 15:33:33.392 INFO org.apache.kyuubi.operation.log.OperationLog: Creating operation log file /opt/kyuubi/work/server_operation_logs/f376c0ae-70f5-4ef5-b25b-9f76651f8113/50015686-0028-4d9c-9ef9-d16386f0beeb
2023-10-16 15:33:33.393 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing autouser1%40nexr.com's query[50015686-0028-4d9c-9ef9-d16386f0beeb]: PENDING_STATE -> RUNNING_STATE, statement:

But, just add thread name and ID, logs are filterable for exact execution like this:

$ cat kyuubi-server.log | grep Thread-111
2023-10-16 05:40:15.844 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.kyuubi.operation.LaunchEngine: Processing autouser1's query[22ffc72b-b315-41e6-8a62-cc1fe01e6322]: PENDING_STATE -> RUNNING_STATE, statement:
2023-10-16 05:40:15.845 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting
2023-10-16 05:40:15.846 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=zookeeper-0.zookeeper-headless:2181,zookeeper-1.zookeeper-headless:2181,zookeeper-2.zookeeper-headless:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@2c31871f
2023-10-16 05:40:15.849 KyuubiSessionManager-exec-pool: Thread-111-SendThread(zookeeper-1.zookeeper-headless:2181) INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server zookeeper-1.zookeeper-headless/10.233.124.53:2181. Will not attempt to authenticate using SASL (unknown error)
2023-10-16 05:40:15.850 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [autouser1:10.233.124.7] SessionHandle [9fdf4e08-7179-4ac7-8b66-9cbd4ec84fe0] - trying to get or create engine
2023-10-16 05:40:15.850 KyuubiSessionManager-exec-pool: Thread-111-SendThread(zookeeper-1.zookeeper-headless:2181) INFO org.apache.zookeeper.ClientCnxn: Socket connection established to zookeeper-1.zookeeper-headless/10.233.124.53:2181, initiating session
2023-10-16 05:40:15.852 KyuubiSessionManager-exec-pool: Thread-111-SendThread(zookeeper-1.zookeeper-headless:2181) INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server zookeeper-1.zookeeper-headless/10.233.124.53:2181, sessionid = 0x207b8b7e6ac20a5, negotiated timeout = 40000
2023-10-16 05:40:15.852 KyuubiSessionManager-exec-pool: Thread-111-EventThread INFO org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED
2023-10-16 05:40:15.857 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.kyuubi.ha.client.zookeeper.ZookeeperDiscoveryClient: Get service instance:10.233.120.179:38117 and version:Some(1.6.1-incubating) under /kyuubi_1.6.1-incubating_USER_SPARK_SQL/autouser1/default
2023-10-16 05:40:15.871 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [autouser1:10.233.124.7] SessionHandle [9fdf4e08-7179-4ac7-8b66-9cbd4ec84fe0] - Connected to engine [10.233.120.179:38117]/[spark-87519754031b4a9cb29b42602a3e3a1d] with SessionHandle [7a3a5d60-e6fb-4afd-9c16-ca37678a2770]]
2023-10-16 05:40:15.873 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.zookeeper.ZooKeeper: Session: 0x207b8b7e6ac20a5 closed
2023-10-16 05:40:15.873 KyuubiSessionManager-exec-pool: Thread-111-EventThread INFO org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x207b8b7e6ac20a5
2023-10-16 05:40:15.873 KyuubiSessionManager-exec-pool: Thread-111 INFO org.apache.kyuubi.operation.LaunchEngine: Processing autouser1's query[22ffc72b-b315-41e6-8a62-cc1fe01e6322]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.029 seconds

I just add %tn to PatternLayout. I think we should provide this to default for more easy looking.

How about this?

Thank you.

[yaooqinn]

It looks ok to enable %tn by default, would you like to create a pull request @minyk ?

[minyk]

I'll file the issue and pr, thank you.