amanraj2520 opened a new issue, #6212: URL: https://github.com/apache/kyuubi/issues/6212
### Code of Conduct - [X] I agree to follow this project's [Code of Conduct](https://www.apache.org/foundation/policies/conduct) ### Search before asking - [X] I have searched in the [issues](https://github.com/apache/kyuubi/issues?q=is%3Aissue) and found no similar issues. ### Describe the bug I am submitting a SparkSql job through spark-submit. Spark version 3.3.1 and Kyuubi version 1.8.0. I am using Open Source Spark Engine with Kyuubi Authz module running on top of the Spark Driver in client mode. The Spark job is successful, but the Spark Driver does not stop and keeps on running and I see the PolicyRefresher keeps on polling policies from Ranger. ` 2024-03-21 15:24:38 INFO metrics:473 - type=TIMER, name=application_1711026237005_0004.driver.LiveListenerBus.queue.shared.listenerProcessingTime, count=284, min=0.0023, max=1.339819, mean=0.020286872667084822, stddev=0.05805632202715145, p50=0.0137, p75=0.0187, p95=0.0348, p98=0.062102, p99=0.096101, p999=0.872013, m1_rate=2.0763548342343605, m5_rate=12.251158404462306, m15_rate=16.96949121751853, mean_rate=1.7380318685287799, rate_unit=events/second, duration_unit=milliseconds 2024-03-21 15:24:38 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint:61 - OutputCommitCoordinator stopped! 2024-03-21 15:24:38 DEBUG NettyLogger:145 - [id: 0xe822e047, L:/10.71.149.108:37177 ! R:/10.71.149.109:47670] INACTIVE 2024-03-21 15:24:38 DEBUG PoolThreadCache:224 - Freed 3 thread-local buffer(s) from thread: rpc-server-4-2 2024-03-21 15:24:38 DEBUG NettyLogger:145 - [id: 0xe822e047, L:/10.71.149.108:37177 ! R:/10.71.149.109:47670] UNREGISTERED **2024-03-21 15:24:38 INFO SparkContext:61 - Successfully stopped SparkContext** 2024-03-21 15:24:38 DEBUG PoolThreadCache:224 - Freed 10 thread-local buffer(s) from thread: rpc-server-4-3 2024-03-21 15:24:38 DEBUG PoolThreadCache:224 - Freed 5 thread-local buffer(s) from thread: shuffle-server-7-1 2024-03-21 15:24:40 DEBUG PoolThreadCache:224 - Freed 7 thread-local buffer(s) from thread: rpc-server-4-1 2024-03-21 15:24:44 DEBUG AbfsClientThrottlingAnalyzer:203 - read, 0, 0, 0, 0, 0.00, 10000, 0, 0 2024-03-21 15:24:44 DEBUG AbfsClientThrottlingAnalyzer:203 - write, 0, 200911, 0, 38, 0.00, 10000, 0, 0 2024-03-21 15:24:52 DEBUG ClientCnxn:890 - Got ping response for session id: 0x1000004f5b7010a after 1ms. 2024-03-21 15:24:54 DEBUG PolicyRefresher:503 - ==> PolicyRefresher(serviceName=service1-spark).loadRoles() 2024-03-21 15:24:54 DEBUG RangerRolesProvider:112 - ==> RangerRolesProvider(serviceName= service1-spark serviceType= spark).loadUserGroupRoles() 2024-03-21 15:24:54 DEBUG init:121 - In-Use memory: 1044293248, Free memory:2987481472 2024-03-21 15:24:54 DEBUG RangerRolesProvider:174 - ==> RangerRolesProvider(serviceName=service1-spark).loadUserGroupRolesFromAdmin() 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:193 - ==> RangerAdminRESTClient.getRolesIfUpdated(1, 1711034514018) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1287 - ==> RangerAdminRESTClient.getRolesIfUpdatedWithCookie(1, 1711034514018) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1343 - ==> RangerAdminRESTClient.getRangerRolesDownloadResponse(1, 1711034514018) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1357 - Checking Roles updated as user : [email protected] (auth:KERBEROS) 2024-03-21 15:24:54 DEBUG UserGroupInformation:1881 - PrivilegedAction [as: [email protected] (auth:KERBEROS)][action: org.apache.ranger.admin.client.RangerAdminRESTClient$16@7955b42d] java.lang.Exception: null at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1881) ~[hadoop-client-api-3.3.4.5.1.5.2.jar:?] at org.apache.ranger.admin.client.RangerAdminRESTClient.getRangerRolesDownloadResponse(RangerAdminRESTClient.java:1371) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.admin.client.RangerAdminRESTClient.getRolesIfUpdatedWithCookie(RangerAdminRESTClient.java:1294) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.admin.client.RangerAdminRESTClient.getRolesIfUpdated(RangerAdminRESTClient.java:199) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.RangerRolesProvider.loadUserGroupRolesFromAdmin(RangerRolesProvider.java:186) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.RangerRolesProvider.loadUserGroupRoles(RangerRolesProvider.java:126) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.PolicyRefresher.loadRoles(PolicyRefresher.java:507) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.PolicyRefresher.run(PolicyRefresher.java:214) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1381 - <== RangerAdminRESTClient.getRangerRolesDownloadResponse(1, 1711034514018): GET http://hn0-ingst3.aadds.XYZ.com:6080/service/roles/secure/download/service1-spark?pluginId=sparkSql%40ed10-ingst3-service1-spark&clusterName=cluster1&lastActivationTime=1711034514018&pluginCapabilities=3ffff&lastKnownRoleVersion=1 returned a response status of 304 Not Modified 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1305 - No change in Roles. secureMode=true, [email protected] (auth:KERBEROS), response={"httpStatusCode":304,"statusCode":0}, serviceName=service1-spark, lastKnownRoleVersion=1, lastActivationTimeInMillis=1711034514018 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1335 - <== RangerAdminRESTClient.getRolesIfUpdatedWithCookie(1, 1711034514018): null 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:205 - <== RangerAdminRESTClient.getRolesIfUpdated(1, 1711034514018): 2024-03-21 15:24:54 DEBUG RangerRolesProvider:201 - RangerRolesProvider(serviceName=service1-spark).run(): no update found. lastKnownRoleVersion=1 2024-03-21 15:24:54 DEBUG init:101 - [PERF] RangerRolesProvider.loadUserGroupRolesFromAdmin(serviceName=service1-spark): 42 2024-03-21 15:24:54 DEBUG RangerRolesProvider:215 - <== RangerRolesProvider(serviceName=service1-spark serviceType= spark ).loadUserGroupRolesFromAdmin() 2024-03-21 15:24:54 DEBUG init:138 - In-Use memory: 1044293248, Free memory:2987481472 2024-03-21 15:24:54 DEBUG init:101 - [PERF] RangerRolesProvider.loadUserGroupRoles(serviceName=service1-spark): 42 2024-03-21 15:24:54 DEBUG RangerRolesProvider:167 - <== RangerRolesProvider(serviceName=service1-spark).loadUserGroupRoles() 2024-03-21 15:24:54 DEBUG PolicyRefresher:510 - <== PolicyRefresher(serviceName=service1-spark).loadRoles() 2024-03-21 15:24:54 DEBUG PolicyRefresher:239 - ==> PolicyRefresher(serviceName=service1-spark).loadPolicy() 2024-03-21 15:24:54 DEBUG init:248 - In-Use memory: 1044293248, Free memory:2987481472 2024-03-21 15:24:54 DEBUG PolicyRefresher:305 - ==> PolicyRefresher(serviceName=service1-spark).loadPolicyfromPolicyAdmin() 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:172 - ==> RangerAdminRESTClient.getServicePoliciesIfUpdated(27, 1711034514212) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:919 - ==> RangerAdminRESTClient.getServicePoliciesIfUpdatedWithCookie(27, 1711034514212) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:972 - ==> RangerAdminRESTClient.getRangerAdminPolicyDownloadResponse(27, 1711034514212) 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:987 - Checking Service policy if updated as user : [email protected] (auth:KERBEROS) 2024-03-21 15:24:54 DEBUG UserGroupInformation:1881 - PrivilegedAction [as: [email protected] (auth:KERBEROS)][action: org.apache.ranger.admin.client.RangerAdminRESTClient$14@51af067e] java.lang.Exception: null at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1881) ~[hadoop-client-api-3.3.4.5.1.5.2.jar:?] at org.apache.ranger.admin.client.RangerAdminRESTClient.getRangerAdminPolicyDownloadResponse(RangerAdminRESTClient.java:1004) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.admin.client.RangerAdminRESTClient.getServicePoliciesIfUpdatedWithCookie(RangerAdminRESTClient.java:926) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.admin.client.RangerAdminRESTClient.getServicePoliciesIfUpdated(RangerAdminRESTClient.java:178) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.PolicyRefresher.loadPolicyfromPolicyAdmin(PolicyRefresher.java:317) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.PolicyRefresher.loadPolicy(PolicyRefresher.java:253) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] at org.apache.ranger.plugin.util.PolicyRefresher.run(PolicyRefresher.java:215) ~[ranger-plugins-common-2.3.0.5.1.5.2.jar:2.3.0.5.1.5.2] 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:1014 - <== RangerAdminRESTClient.getRangerAdminPolicyDownloadResponse(27, 1711034514212): GET http://hn0-ingst3.aadds.XYZ.com:6080/service/plugins/secure/policies/download/service1-spark?supportsPolicyDeltas=false&pluginId=sparkSql%40ed10-ingst3-service1-spark&clusterName=cluster1&lastActivationTime=1711034514212&pluginCapabilities=3ffff&lastKnownVersion=27 returned a response status of 304 Not Modified 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:937 - No change in policies. secureMode=true, [email protected] (auth:KERBEROS), response={"httpStatusCode":304,"statusCode":0}, serviceName=service1-spark 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:964 - <== RangerAdminRESTClient.getServicePoliciesIfUpdatedWithCookie(27, 1711034514212): null 2024-03-21 15:24:54 DEBUG RangerAdminRESTClient:184 - <== RangerAdminRESTClient.getServicePoliciesIfUpdated(27, 1711034514212): null 2024-03-21 15:24:54 DEBUG PolicyRefresher:334 - PolicyRefresher(serviceName=service1-spark).run(): no update found. lastKnownVersion=27 2024-03-21 15:24:54 DEBUG init:101 - [PERF] PolicyRefresher.loadPolicyFromPolicyAdmin(serviceName=service1-spark): 50 2024-03-21 15:24:54 DEBUG PolicyRefresher:351 - <== PolicyRefresher(serviceName=service1-spark).loadPolicyfromPolicyAdmin() 2024-03-21 15:24:54 DEBUG init:265 - In-Use memory: 1044293248, Free memory:2987481472 2024-03-21 15:24:54 DEBUG init:101 - [PERF] PolicyRefresher.loadPolicy(serviceName=service1-spark): 50 2024-03-21 15:24:54 DEBUG PolicyRefresher:298 - <== PolicyRefresher(serviceName=service1-spark).loadPolicy() ` If you see the logs, PolicyRefresher is still running even after Spark Context has stopped. This is leading to the Spark Driver not ending and therefore after sometime I have to manually kill the job. Can someone please help in this issue? ### Affects Version(s) 1.8.0 ### Kyuubi Server Log Output _No response_ ### Kyuubi Engine Log Output _No response_ ### Kyuubi Server Configurations _No response_ ### Kyuubi Engine Configurations _No response_ ### Additional context _No response_ ### Are you willing to submit PR? - [X] Yes. I would be willing to submit a PR with guidance from the Kyuubi community to fix. - [ ] No. I cannot submit a PR at this time. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
