Adding filter to /: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,372 INFO ServerInfo [Thread-28]: Adding filter to /api: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,376 INFO ServerInfo [Thread-28]: Adding filter to /metrics: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,377 INFO ServerInfo [Thread-28]: Adding filter to /jobs/job/kill: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,378 INFO ServerInfo [Thread-28]: Adding filter to /stages/stage/kill: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,383 INFO ServerInfo [Thread-28]: Adding filter to /metrics/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,384 INFO ServerInfo [Thread-28]: Adding filter to /metrics/prometheus: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:58,456 INFO RequestHedgingRMFailoverProxyProvider [main]: Created wrapped proxy for [rm1, rm2] 2023-11-13 03:45:58,457 INFO YarnRMClient [main]: Registering the ApplicationMaster 2023-11-13 03:45:58,461 INFO RequestHedgingRMFailoverProxyProvider [main]: Looking for the active RM in [rm1, rm2]... 2023-11-13 03:45:58,569 INFO RequestHedgingRMFailoverProxyProvider [main]: Found active RM [rm2] 2023-11-13 03:45:58,574 INFO ApplicationMaster [main]: Preparing Local resources 2023-11-13 03:45:58,714 INFO ApplicationMaster [main]: =============================================================================== Default YARN executor launch context: env: CLASSPATH -> /usr/lib/library-manager/bin/libraries/scala/*{{PWD}}{{PWD}}/__spark_conf__{{PWD}}/__spark_libs__/*/opt/spark/jars/*{{PWD}}/__spark_conf__/__hadoop_conf__ SPARK_YARN_STAGING_DIR -> wasbs://c9c91c6c-a690-4768-8e62-85c452fde267@uok5052eb0xs0p2mha69bgq0.blob.core.windows.net/user/trusted-service-user/trusted-service-user/.sparkStaging/application_1699846537913_0004 JAVA_TOOL_OPTIONS -> -Djdk.jar.maxSignatureFileSize=2147483639 PATH -> /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin:/usr/local/cuda-11.5/bin:/home/trusted-service-user/cluster-env/env/bin:/home/trusted-service-user/cluster-env/synapse_trident_r/bin SPARK_USER -> trusted-service-user SPARKR_INLINE_SESSION_LEVEL_ENABLE -> true SPARK_HOME -> /opt/spark PYTHONPATH -> /opt/spark/python/lib/pyspark.zip/opt/spark/python/lib/py4j-0.10.7-src.zip/opt/spark/python/lib/pyspark.zip/opt/spark/python/lib/py4j-0.10.7-src.zip command: LD_LIBRARY_PATH=\"/usr/hdp/current/hadoop-client/lib/native:$LD_LIBRARY_PATH\" \ {{JAVA_HOME}}/bin/java \ -server \ -Xmx28672m \ '-XX:+IgnoreUnrecognizedVMOptions' \ '--add-opens=java.base/java.lang=ALL-UNNAMED' \ '--add-opens=java.base/java.lang.invoke=ALL-UNNAMED' \ '--add-opens=java.base/java.lang.reflect=ALL-UNNAMED' \ '--add-opens=java.base/java.io=ALL-UNNAMED' \ '--add-opens=java.base/java.net=ALL-UNNAMED' \ '--add-opens=java.base/java.nio=ALL-UNNAMED' \ '--add-opens=java.base/java.util=ALL-UNNAMED' \ '--add-opens=java.base/java.util.concurrent=ALL-UNNAMED' \ '--add-opens=java.base/java.util.concurrent.atomic=ALL-UNNAMED' \ '--add-opens=java.base/sun.nio.ch=ALL-UNNAMED' \ '--add-opens=java.base/sun.nio.cs=ALL-UNNAMED' \ '--add-opens=java.base/sun.security.action=ALL-UNNAMED' \ '--add-opens=java.base/sun.util.calendar=ALL-UNNAMED' \ '--add-opens=java.security.jgss/sun.security.krb5=ALL-UNNAMED' \ '-Dlog4j2.configurationFile=file:/usr/hdp/current/spark3-client/conf/executor-log4j2.properties' \ '-Djavax.xml.parsers.SAXParserFactory=com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl' \ '-XX:+UseG1GC' \ -Djava.io.tmpdir={{PWD}}/tmp \ '-Dspark.driver.port=33491' \ '-Dspark.synapse.history.rpc.port=18082' \ '-Dspark.ui.port=0' \ '-Dspark.history.ui.port=18080' \ -Dspark.yarn.app.container.log.dir= \ -XX:OnOutOfMemoryError='kill %p' \ org.apache.spark.executor.YarnCoarseGrainedExecutorBackend \ --driver-url \ spark://CoarseGrainedScheduler@vm-17182087:33491 \ --executor-id \ \ --hostname \ \ --cores \ 4 \ --app-id \ application_1699846537913_0004 \ --resourceProfileId \ 0 \ 1>/stdout \ 2>/stderr resources: sparkr -> resource { scheme: "wasbs" host: "uok5052eb0xs0p2mha69bgq0.blob.core.windows.net" port: -1 file: "/user/trusted-service-user/trusted-service-user/.sparkStaging/application_1699846537913_0004/sparkr.zip" userInfo: "c9c91c6c-a690-4768-8e62-85c452fde267" } size: 1187704 timestamp: 1699847148000 type: ARCHIVE visibility: PRIVATE __spark_conf__ -> resource { scheme: "wasbs" host: "uok5052eb0xs0p2mha69bgq0.blob.core.windows.net" port: -1 file: "/user/trusted-service-user/trusted-service-user/.sparkStaging/application_1699846537913_0004/__spark_conf__.zip" userInfo: "c9c91c6c-a690-4768-8e62-85c452fde267" } size: 341891 timestamp: 1699847149000 type: ARCHIVE visibility: PRIVATE =============================================================================== 2023-11-13 03:45:58,732 INFO YarnAllocator [main]: Yarn Executor Decommissioning Enabled 2023-11-13 03:45:58,746 INFO YarnAllocator [main]: Resource profile 0 doesn't exist, adding it 2023-11-13 03:45:58,782 INFO Configuration [main]: resource-types.xml not found 2023-11-13 03:45:58,783 INFO ResourceUtils [main]: Unable to find 'resource-types.xml'. 2023-11-13 03:45:58,794 INFO YarnSchedulerBackend$YarnSchedulerEndpoint [dispatcher-event-loop-2]: ApplicationMaster registered as NettyRpcEndpointRef(spark://YarnAM@vm-17182087:33491) 2023-11-13 03:45:58,801 INFO YarnAllocator [main]: Will request 1 executor container(s) for ResourceProfile Id: 0, each with 4 core(s) and 29056 MB memory. with custom resources: 2023-11-13 03:45:58,822 INFO YarnAllocator [main]: Submitted 1 unlocalized container requests. 2023-11-13 03:45:59,139 INFO DefaultsConfigSparkListener [spark-listener-group-shared]: Persisted __spark_conf_merge_records__.json 2023-11-13 03:45:59,155 INFO ApplicationMaster [main]: Started progress reporter thread with (heartbeat : 1000, initial allocation : 200) intervals 2023-11-13 03:45:59,157 INFO YarnClusterSchedulerBackend [Thread-28]: SchedulerBackend is ready for scheduling beginning after reached minRegisteredResourcesRatio: 0.0 2023-11-13 03:45:59,158 INFO YarnClusterScheduler [Thread-28]: YarnClusterScheduler.postStartHook done 2023-11-13 03:45:59,174 INFO SparkContext [Thread-28]: Initialized SparkContextAfterInit plugin org.apache.spark.microsoft.tools.api.plugin.MSToolsSparkContextAfterInitPlugin. 2023-11-13 03:45:59,183 INFO HiveConf [Thread-28]: Found configuration file file:/mnt/var/hadoop/tmp/nm-local-dir/usercache/trusted-service-user/filecache/13/__spark_conf__.zip/__hadoop_conf__/hive-site.xml 2023-11-13 03:45:59,283 INFO SharedState [Thread-28]: Setting hive.metastore.warehouse.dir ('abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse') to the value of spark.sql.warehouse.dir. 2023-11-13 03:45:59,326 WARN AzureBlobFileSystemStore [Thread-28]: checkDnsEntry: idrrosterstoragedev.dfs.core.windows.net not found in the file /etc/hosts. 2023-11-13 03:45:59,331 INFO SessionTokenBasedTokenProvider [Thread-28]: Setting up conf 2023-11-13 03:45:59,332 INFO SessionTokenBasedTokenProvider [Thread-28]: SessionTokenBasedTokenProvider initialized 2023-11-13 03:45:59,336 INFO AbfsConfiguration [Thread-28]: AbfsClientRetryPolicy: fulljitter 2023-11-13 03:45:59,382 INFO SharedState [Thread-28]: Warehouse path is 'abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse'. 2023-11-13 03:45:59,392 INFO YarnAllocator [Reporter]: Launching container container_1699846537913_0004_01_000002 on host vm-ca663215 for executor with ID 1 for ResourceProfile Id 0 2023-11-13 03:45:59,394 INFO ServerInfo [Thread-28]: Adding filter to /SQL: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:59,396 INFO ServerInfo [Thread-28]: Adding filter to /SQL/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:59,396 INFO YarnAllocator [Reporter]: Received 1 containers from YARN, launching executors on 1 of them. 2023-11-13 03:45:59,397 INFO ServerInfo [Thread-28]: Adding filter to /SQL/execution: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:59,398 INFO ServerInfo [Thread-28]: Adding filter to /SQL/execution/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:59,401 INFO ServerInfo [Thread-28]: Adding filter to /static/sql: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:45:59,411 INFO ExecutorRunnable [ContainerLauncher-0]: Initializing service data for shuffle service using name 'spark_shuffle' 2023-11-13 03:46:03,510 INFO YarnSchedulerBackend$YarnDriverEndpoint [dispatcher-CoarseGrainedScheduler]: Registered executor NettyRpcEndpointRef(spark-client://Executor) (10.0.0.6:47824) with ID 1, ResourceProfileId 0 2023-11-13 03:46:03,529 WARN SQLConf [spark-listener-group-shared]: The SQL config 'spark.sql.legacy.replaceDatabricksSparkAvro.enabled' has been deprecated in Spark v3.2 and may be removed in the future. Use `.format("avro")` in `DataFrameWriter` or `DataFrameReader` instead. 2023-11-13 03:46:03,535 WARN SQLConf [spark-listener-group-shared]: The SQL config 'spark.sql.legacy.replaceDatabricksSparkAvro.enabled' has been deprecated in Spark v3.2 and may be removed in the future. Use `.format("avro")` in `DataFrameWriter` or `DataFrameReader` instead. 2023-11-13 03:46:03,652 INFO BlockManagerMasterEndpoint [dispatcher-BlockManagerMaster]: Registering block manager vm-ca663215:32777 with 16.6 GiB RAM, BlockManagerId(1, vm-ca663215, 32777, None) 2023-11-13 03:46:04,011 WARN SQLConf [Thread-28]: The SQL config 'spark.sql.legacy.replaceDatabricksSparkAvro.enabled' has been deprecated in Spark v3.2 and may be removed in the future. Use `.format("avro")` in `DataFrameWriter` or `DataFrameReader` instead. 2023-11-13 03:46:04,013 WARN SQLConf [Thread-28]: The SQL config 'spark.sql.legacy.replaceDatabricksSparkAvro.enabled' has been deprecated in Spark v3.2 and may be removed in the future. Use `.format("avro")` in `DataFrameWriter` or `DataFrameReader` instead. 2023-11-13 03:46:04,109 INFO StateStoreCoordinatorRef [Thread-28]: Registered StateStoreCoordinator endpoint 2023-11-13 03:46:04,124 INFO ServerInfo [Thread-28]: Adding filter to /StreamingQuery: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:46:04,126 INFO ServerInfo [Thread-28]: Adding filter to /StreamingQuery/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:46:04,127 INFO ServerInfo [Thread-28]: Adding filter to /StreamingQuery/statistics: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:46:04,128 INFO ServerInfo [Thread-28]: Adding filter to /StreamingQuery/statistics/json: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:46:04,130 INFO ServerInfo [Thread-28]: Adding filter to /static/sql: org.apache.hadoop.yarn.server.webproxy.amfilter.AmIpFilter 2023-11-13 03:46:07,375 INFO TridentCoreProxy [Thread-28]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:07,539 INFO TridentCoreProxy [Thread-28]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:07,540 INFO TridentCoreProxy [Thread-28]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:10,021 INFO LighterServerPlugin [Thread-94]: Loaded Lighter server plugin: org.apache.spark.lighter.DefaultLighterServerPlugin 2023-11-13 03:46:10,486 WARN SparkSession [Thread-94]: Using an existing Spark session; only runtime SQL configurations will take effect. 2023-11-13 03:46:10,497 WARN SparkSession [Thread-94]: Using an existing Spark session; only runtime SQL configurations will take effect. 2023-11-13 03:46:11,552 WARN DefaultTimer [Thread-94]: Can not service-load a timer. Using JavaTimer instead. 2023-11-13 03:46:11,569 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:init-getContext|cost:1022|language:python|productType:synapse] done 2023-11-13 03:46:11,575 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,577 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,580 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,581 INFO notebookUtils [Thread-94]: productType synapse 2023-11-13 03:46:11,590 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,593 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,602 INFO notebookUtils [pool-42-thread-2]: [mount operation] refresh workspace level mounts. 2023-11-13 03:46:11,603 INFO TridentCoreProxy [pool-42-thread-2]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,603 INFO notebookUtils [pool-42-thread-2]: [mount operation] get workspace level mounts.call:/mountApi/versions/2019-01-01/productTypes/synapse/workspaces/idr-synapse-centralus-dev/mount 2023-11-13 03:46:11,605 INFO notebookUtils [pool-42-thread-2]: start execute request getWorkspaceMounts - /mountApi/versions/2019-01-01/productTypes/synapse/workspaces/idr-synapse-centralus-dev/mount attempt 1/3 2023-11-13 03:46:11,606 INFO TridentCoreProxy [pool-42-thread-2]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,606 INFO notebookUtils [pool-42-thread-2]: [NotebookServiceClient][get] request url - https://tokenservice2.centralus.azuresynapse.net/api/v1/proxy/mountApi/versions/2019-01-01/productTypes/synapse/workspaces/idr-synapse-centralus-dev/mount with correlation id 3576892b-cf88-4304-b77a-633ceaf62fba 2023-11-13 03:46:11,608 INFO notebookUtils [pool-42-thread-1]: get hostresolver ip address - 10.0.0.4 2023-11-13 03:46:11,612 INFO TridentCoreProxy [pool-42-thread-2]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:11,619 INFO credentials$ [pool-42-thread-2]: Calling TokenLibrary GetAccessToken 2023-11-13 03:46:11,620 INFO Utilities$ [pool-42-thread-2]: Trying to determine if cluster type 2023-11-13 03:46:11,627 INFO TokenLibrary [pool-42-thread-2]: Attempting to fetch access token from cache 2023-11-13 03:46:11,629 INFO InMemoryCacheClient [pool-42-thread-2]: Token not found in in-memory cache 2023-11-13 03:46:11,649 INFO TokenLibrary [pool-42-thread-2]: Invoking token service to fetch access token 2023-11-13 03:46:11,683 INFO TokenLibrary [pool-42-thread-2]: Fetching access token - requestId:1fce3a46-5d62-4efa-9585-b728826c0cb8, hostName:vm-17182087, ProcessName:13546@vm-17182087 2023-11-13 03:46:11,684 INFO TokenLibrary [pool-42-thread-2]: Attempting request to token service. 4 attempt(s) remaining. 2023-11-13 03:46:12,029 INFO finagle [pool-42-thread-2]: Finagle version 19.5.1 (rev=21b8a8b3eeca571eedc7094df53d5eb806856b61) built at 20190520-194112 2023-11-13 03:46:12,138 INFO TokenLibrary [pool-42-thread-2]: Create client with TLS validation disabled 2023-11-13 03:46:12,155 INFO MasterPubSubConnectionPool [redisson-netty-2-5]: 1 connections initialized for 10.0.0.4/10.0.0.4:6379 2023-11-13 03:46:12,170 INFO MasterConnectionPool [redisson-netty-2-10]: 4 connections initialized for 10.0.0.4/10.0.0.4:6379 2023-11-13 03:46:12,299 INFO notebookUtils [pool-42-thread-1]: [telemetry][info][funcName:RefreshSessionToken|cost:701|traceId:9c2d457b-e2dc-42ef-8585-3e3614940c43|productType:synapse] done 2023-11-13 03:46:12,722 INFO TokenLibrary [finagle/netty4-1-1]: Got response from server in 1038ms 2023-11-13 03:46:12,723 INFO TokenLibrary [finagle/netty4-1-1]: POST success with status code: 'OK' (200). 2023-11-13 03:46:13,263 INFO InMemoryCacheClient [finagle/netty4-1-1]: Token successfully cached in memory 2023-11-13 03:46:13,271 INFO notebookUtils [pool-42-thread-2]: [getToken] Done to get Synapse aadToken via TokenLibrary, costs - 1659ms 2023-11-13 03:46:13,275 INFO env [pool-42-thread-2]: Getting userId (mssparkutils) 2023-11-13 03:46:13,295 INFO TridentCoreProxy [pool-42-thread-2]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:13,298 INFO TridentCoreProxy [pool-42-thread-2]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:13,298 INFO notebookUtils [pool-42-thread-2]: region is centralus, domain is: azuresynapse.net. 2023-11-13 03:46:13,299 WARN notebookUtils [pool-42-thread-2]: NBS endpoint is https://exec.nbs.centralus.azuresynapse.net by splicing 2023-11-13 03:46:13,462 INFO notebookUtils [pool-42-thread-2]: execute request successfully for getWorkspaceMounts - /mountApi/versions/2019-01-01/productTypes/synapse/workspaces/idr-synapse-centralus-dev/mount. 2023-11-13 03:46:13,466 INFO notebookUtils [pool-42-thread-2]: [telemetry][info][funcName:RefreshMountPoints|cost:1863|traceId:8c459855-47ea-4b3c-b277-0b6322a0f6a2|productType:synapse] done 2023-11-13 03:46:13,504 INFO notebookUtils [Thread-94]: Redisson client has been shutdown successfully. 2023-11-13 03:46:13,504 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:personalizeSession|cost:1910|traceId:55bc8484-a495-498c-a431-156deadf64ff|productType:synapse] done 2023-11-13 03:46:13,506 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:init-callJvm|cost:1935|language:python|productType:synapse] done 2023-11-13 03:46:13,506 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:init-setWorkDir|cost:0|language:python|productType:synapse] done 2023-11-13 03:46:13,507 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:initializeLHContext|cost:2970|language:python|productType:synapse] done 2023-11-13 03:46:13,520 INFO TridentCoreProxy [Thread-94]: Found following file system configurations: {fs.defaultFS=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net, spark.sql.warehouse.dir=abfss://idr-synapse-dev@idrrosterstoragedev.dfs.core.windows.net/synapse/workspaces/idr-synapse-centralus-dev/warehouse} 2023-11-13 03:46:14,214 INFO notebookUtils [Thread-94]: [telemetry][info][funcName:prepare|cost:705|language:python] done 2023-11-13 03:46:15,198 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,201 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,201 INFO InMemoryCacheClient [Thread-94]: Token not found in in-memory cache 2023-11-13 03:46:15,202 INFO TokenLibraryLinkedService [Thread-94]: Invoking token service to fetch access token 2023-11-13 03:46:15,203 INFO TokenLibraryLinkedService [Thread-94]: Fetching access token - requestId:0644aabd-36b9-4cbb-9763-e8e2c31a27cc, hostName:vm-17182087, ProcessName:13546@vm-17182087 2023-11-13 03:46:15,203 INFO TokenLibraryLinkedService [Thread-94]: Attempting request to token service. 4 attempt(s) remaining. 2023-11-13 03:46:15,204 INFO TokenLibraryLinkedService [Thread-94]: Create client with TLS validation disabled 2023-11-13 03:46:15,277 INFO TokenLibraryLinkedService [finagle/netty4-1-2]: Got response from server in 74ms 2023-11-13 03:46:15,278 INFO TokenLibraryLinkedService [finagle/netty4-1-2]: POST success with status code: 'OK' (200). 2023-11-13 03:46:15,280 INFO InMemoryCacheClient [finagle/netty4-1-2]: Token successfully cached in memory 2023-11-13 03:46:15,281 INFO TokenLibraryLinkedService [finagle/netty4-1-2]: Create client with TLS validation disabled 2023-11-13 03:46:15,289 INFO TokenLibraryLinkedService [finagle/netty4-1-2]: Fetching AKV secret 2023-11-13 03:46:15,395 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,396 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,398 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,399 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,400 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,400 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,401 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,443 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,444 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,445 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,447 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,448 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,448 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,449 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,511 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,512 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,513 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,515 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,516 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,516 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,517 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,553 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,554 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,555 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,557 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,557 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,558 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,558 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,604 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,604 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,606 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,607 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,608 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,608 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,609 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,655 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,656 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,657 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,659 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,659 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,659 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,660 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,756 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,757 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,758 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,760 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,760 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,760 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,761 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,800 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,801 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:15,802 INFO Utilities$ [Thread-94]: Trying to determine if cluster type 2023-11-13 03:46:15,803 INFO TokenLibraryLinkedService [Thread-94]: Attempting to fetch access token from cache 2023-11-13 03:46:15,803 INFO InMemoryCacheClient [Thread-94]: Token successfully fetched from in-memory cache 2023-11-13 03:46:15,804 INFO TokenLibraryLinkedService [Thread-94]: Obtained access token from cache 2023-11-13 03:46:15,804 INFO TokenLibraryLinkedService [Thread-94]: Fetching AKV secret 2023-11-13 03:46:15,844 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Caching AKV secret) 2023-11-13 03:46:15,844 INFO TokenLibraryLinkedService [finagle/netty4-1-3]: Obtained AKV secret 2023-11-13 03:46:22,811 INFO SynapseMLPandasLogger [Thread-94]: Fsspec_wrapper call 2023-11-13 03:46:22,820 INFO SynapseMLPandasLogger [Thread-94]: Authentication credentials passed as storage_options. 2023-11-13 03:46:22,829 INFO SynapseMLPandasLogger [Thread-94]: Assigned account_host successfully 2023-11-13 03:46:22,839 INFO SynapseMLPandasLogger [Thread-94]: Using public blob url 2023-11-13 04:00:54,755 INFO SparkUI [RPC-Handler-6]: Stopped Spark web UI at http://vm-17182087:33325 2023-11-13 04:00:54,779 INFO YarnAllocator [dispatcher-event-loop-2]: Driver requested a total number of 0 executor(s), reset all resource profile ids 2023-11-13 04:00:54,781 INFO YarnClusterSchedulerBackend [RPC-Handler-6]: Shutting down all executors 2023-11-13 04:00:54,781 INFO YarnSchedulerBackend$YarnDriverEndpoint [dispatcher-CoarseGrainedScheduler]: Asking each executor to shut down 2023-11-13 04:00:54,791 INFO AsyncEventQueue [RPC-Handler-6]: appStatus requested to stop with 0 events 2023-11-13 04:00:54,792 INFO AsyncEventQueue [RPC-Handler-6]: shared requested to stop with 0 events 2023-11-13 04:00:54,792 INFO AsyncEventQueue [RPC-Handler-6]: executorManagement requested to stop with 0 events 2023-11-13 04:00:54,794 INFO AsyncEventQueue [RPC-Handler-6]: eventLog requested to stop with 0 events 2023-11-13 04:00:54,795 INFO AsyncEventQueue [RPC-Handler-6]: sparkRpcHistoryServer requested to stop with 0 events 2023-11-13 04:00:54,798 INFO AsyncEventQueue [spark-listener-group-shared-terminate]: Initiated shared terminate thread with 10000 ms 2023-11-13 04:00:54,798 INFO AsyncEventQueue [RPC-Handler-6]: streams requested to stop with 0 events 2023-11-13 04:00:54,798 INFO AsyncEventQueue [spark-listener-group-sparkRpcHistoryServer-terminate]: Initiated sparkRpcHistoryServer terminate thread with 10000 ms 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.disk.diskSpaceUsed_MB, value=0 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxMem_MB, value=32135 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxOffHeapMem_MB, value=0 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxOnHeapMem_MB, value=32135 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.memUsed_MB, value=0 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.offHeapMemUsed_MB, value=0 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.onHeapMemUsed_MB, value=0 2023-11-13 04:00:54,803 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingMem_MB, value=32135 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingOffHeapMem_MB, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingOnHeapMem_MB, value=32135 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.job.activeJobs, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.job.allJobs, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.failedStages, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.runningStages, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.waitingStages, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.DirectPoolMemory, value=268410 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.JVMHeapMemory, value=3254595040 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.JVMOffHeapMemory, value=244421384 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MajorGCCount, value=6 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MajorGCTime, value=1071 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MappedPoolMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MinorGCCount, value=22 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MinorGCTime, value=897 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapExecutionMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapStorageMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapUnifiedMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapExecutionMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapStorageMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapUnifiedMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeJVMRSSMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeJVMVMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeOtherRSSMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeOtherVMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreePythonRSSMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreePythonVMemory, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.TotalGCTime, value=1968 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.JVMCPU.jvmCpuTime, value=1154500000000 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.size, value=0 2023-11-13 04:00:54,804 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.size, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.size, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.size, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.size, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.size, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-MarkSweep.count, value=6 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-MarkSweep.time, value=1071 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-Scavenge.count, value=22 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-Scavenge.time, value=897 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.capacity, value=186994 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.count, value=13 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.used, value=186997 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.committed, value=5745147904 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.init, value=1056964608 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.max, value=26724532224 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.usage, value=0.12469031151113778 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.used, value=3332290248 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.capacity, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.count, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.used, value=0 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.committed, value=260542464 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.init, value=2555904 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.max, value=-1 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.usage, value=-2.45074072E8 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.used, value=245074072 2023-11-13 04:00:54,805 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.committed, value=65339392 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.init, value=2555904 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.max, value=251658240 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.usage, value=0.2577173868815104 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.used, value=64856704 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.committed, value=21061632 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.init, value=0 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.max, value=1073741824 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.usage, value=0.0185701847076416 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.used, value=19939584 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.committed, value=174141440 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.init, value=0 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.max, value=-1 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.usage, value=0.9203885301511231 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.used, value=160277784 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.committed, value=2227699712 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.init, value=264241152 2023-11-13 04:00:54,806 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.max, value=9494855680 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.usage, value=0.19141106439650488 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.used, value=1817420432 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.used-after-gc, value=0 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.committed, value=3273129984 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.init, value=704643072 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.max, value=20043530240 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.usage, value=0.06422182323107568 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.used, value=1287232056 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.used-after-gc, value=757190256 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.committed, value=244318208 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.init, value=44040192 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.max, value=244318208 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.usage, value=0.9317265457349786 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.used, value=227637760 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.used-after-gc, value=227637760 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.committed, value=6005690368 2023-11-13 04:00:54,807 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.init, value=1059520512 2023-11-13 04:00:54,808 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.max, value=26724532223 2023-11-13 04:00:54,808 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.used, value=3577373000 2023-11-13 04:00:54,808 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.fileCacheHits, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.filesDiscovered, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveCallsTimerSumMilliSec, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveClientCalls, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.parallelListingJobCount, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.partitionsFetched, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.numEventsPosted, count=205 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.numDroppedEvents, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.numDroppedEvents, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.numDroppedEvents, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.numDroppedEvents, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.numDroppedEvents, count=0 2023-11-13 04:00:54,809 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.numDroppedEvents, count=0 2023-11-13 04:00:54,812 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.compilationTime, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:54,812 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.generatedClassSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:54,812 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.generatedMethodSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:54,812 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.sourceCodeSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:54,816 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.DAGScheduler.messageProcessingTime, count=1, min=3.263187, max=3.263187, mean=3.263187, stddev=0.0, p50=3.263187, p75=3.263187, p95=3.263187, p98=3.263187, p99=3.263187, p999=3.263187, m1_rate=6.281092580701629E-9, m5_rate=1.7301984934632537E-4, m15_rate=4.1447222734196495E-4, mean_rate=0.0011141377115921457, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,816 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveCallTimer, count=0, min=0.0, max=0.0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0, m1_rate=0.0, m5_rate=0.0, m15_rate=0.0, mean_rate=0.0, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,817 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.com.microsoft.hdinsight.spark.metrics.SparkMetricsListener, count=205, min=0.0357, max=587.930265, mean=0.06324980267470741, stddev=0.21229548016206784, p50=0.0476, p75=0.057099, p95=0.222099, p98=0.222099, p99=0.222099, p999=0.222099, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22863730248058245, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,817 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.com.microsoft.impulse.analyze.eventLog.ImpulseListener, count=205, min=0.0014, max=25.327199, mean=0.049976270007032676, stddev=0.1776974499794672, p50=0.0018, p75=0.0022, p95=0.705198, p98=0.705198, p99=0.705198, p999=0.705198, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22863747287099684, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,817 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.HeartbeatReceiver, count=205, min=6.0E-4, max=11.543354, mean=0.003629389604026141, stddev=0.006084854625098194, p50=0.0024, p75=0.0026, p95=0.0215, p98=0.0215, p99=0.0215, p999=0.0215, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22838792426989865, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,818 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.input.AdviseInputListener, count=205, min=5.0E-4, max=0.934897, mean=0.001963874242223215, stddev=0.003472039027397778, p50=0.0011, p75=0.0013, p95=0.014699, p98=0.014699, p99=0.014699, p999=0.014699, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.2283828732282471, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,818 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.input.MetricsServiceListener, count=205, min=5.0E-4, max=2.757189, mean=8.6438150264945E-4, stddev=9.883771565460193E-4, p50=8.0E-4, p75=9.0E-4, p95=0.0017, p98=0.0017, p99=0.0017, p999=0.0017, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22863723745583592, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,818 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.output.AdviseListener, count=205, min=9.0E-4, max=11.253255, mean=0.004921848436035722, stddev=0.007272311266879202, p50=0.0032, p75=0.0035, p95=0.0281, p98=0.0281, p99=0.0281, p999=0.0281, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.2283758347154944, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,819 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.deploy.history.rpc.app.RpcAppListener, count=205, min=0.083199, max=61.364357, mean=0.24769463644447176, stddev=0.26413506068551434, p50=0.190299, p75=0.230999, p95=1.183696, p98=1.183696, p99=1.183696, p999=1.183696, m1_rate=0.20832896038971738, m5_rate=0.2465355794328549, m15_rate=0.50675601186031, mean_rate=0.22855699698940152, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,819 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.diagnostic.configuration.DefaultsConfigSparkListener, count=205, min=5.0E-4, max=636.933171, mean=0.0010419886515351897, stddev=0.20246756593147539, p50=8.0E-4, p75=9.0E-4, p95=0.0025, p98=0.0025, p99=0.0045, p999=0.0045, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.228506769049924, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,819 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.listeners.LogAnalyticsSparkListener, count=205, min=0.0051, max=0.519998, mean=0.048625612469536006, stddev=0.1277559920426589, p50=0.014099, p75=0.0154, p95=0.519998, p98=0.519998, p99=0.519998, p999=0.519998, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22863677833116278, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,820 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.listeners.SparkObservabilityListener, count=205, min=8.0E-4, max=13.468846, mean=0.01741323686908522, stddev=0.05604988208621536, p50=0.0018, p75=0.002, p95=0.222899, p98=0.222899, p99=0.222899, p999=0.222899, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22850661495185148, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,820 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.scheduler.EventLoggingListener, count=283, min=0.0012, max=99.107803, mean=2.322071982664257, stddev=12.509103055163857, p50=0.009, p75=0.0108, p95=0.0284, p98=69.91662, p99=69.91662, p999=69.91662, m1_rate=0.41625398159081284, m5_rate=0.4007136539655776, m15_rate=0.6494954472674159, mean_rate=0.3154379310007684, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,820 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.SparkSession$$anon$1, count=200, min=5.0E-4, max=0.0321, mean=0.0028877013106640994, stddev=0.007919188127654504, p50=7.0E-4, p75=9.0E-4, p95=0.0321, p98=0.0321, p99=0.0321, p999=0.0321, m1_rate=0.208328729064452, m5_rate=0.2152957565433306, m15_rate=0.2827261928349317, mean_rate=0.22332806272922082, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,820 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.execution.streaming.StreamingQueryListenerBus, count=198, min=5.0E-4, max=0.0116, mean=0.001652629208559088, stddev=4.88313337597446E-4, p50=0.0016, p75=0.0021, p95=0.0024, p98=0.0024, p99=0.0026, p999=0.0028, m1_rate=0.20832865678827367, m5_rate=0.20500083520299042, m15_rate=0.20832823614185725, mean_rate=0.2222952225906497, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,821 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.execution.ui.SQLAppStatusListener, count=200, min=0.0014, max=2.271191, mean=0.004011516710515512, stddev=0.001290508148180611, p50=0.0042, p75=0.0048, p95=0.0053, p98=0.0064, p99=0.0064, p999=0.0064, m1_rate=0.208328729064452, m5_rate=0.2152957565433306, m15_rate=0.2827261928349317, mean_rate=0.22335604646134163, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,821 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.util.ExecutionListenerBus, count=398, min=1.0E-4, max=0.174699, mean=6.406853178886916E-4, stddev=0.005213911680828183, p50=5.0E-4, p75=6.0E-4, p95=9.0E-4, p98=0.001, p99=0.001, p999=0.0085, m1_rate=0.4166574706910892, m5_rate=0.43093755278535395, m15_rate=0.5662813301245468, mean_rate=0.44682961022933626, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,821 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.status.AppStatusListener, count=205, min=0.0145, max=21.324415, mean=0.07197753074439554, stddev=0.053224985905563585, p50=0.090899, p75=0.123399, p95=0.138899, p98=0.1425, p99=0.147199, p999=0.344699, m1_rate=0.20000044631421846, m5_rate=0.24479685518024144, m15_rate=0.5060043462765247, mean_rate=0.22822626764312928, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,821 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.ui.EnhancementAppStatusListener, count=205, min=5.0E-4, max=41.879333, mean=0.2403654681680612, stddev=0.8840658907385498, p50=8.0E-4, p75=0.001, p95=3.503186, p98=3.503186, p99=3.503186, p999=3.503186, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22850230884375916, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.listenerProcessingTime, count=205, min=0.0339, max=21.419615, mean=0.09263961326509938, stddev=0.04929619326229976, p50=0.107299, p75=0.139699, p95=0.157299, p98=0.157299, p99=0.167299, p999=0.364499, m1_rate=0.20000044631421846, m5_rate=0.24479685518024144, m15_rate=0.5060043462765247, mean_rate=0.2282258713758651, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.listenerProcessingTime, count=205, min=0.0034, max=99.165703, mean=4.788741256502146, stddev=17.64826730265202, p50=0.0072, p75=0.0091, p95=69.93032, p98=69.93032, p99=69.93032, p999=69.93032, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22849691530735836, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.listenerProcessingTime, count=205, min=0.0054, max=12.230952, mean=0.01778565657231402, stddev=0.00739116225001151, p50=0.0163, p75=0.0189, p95=0.0367, p98=0.0367, p99=0.0367, p999=0.0367, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.2283866690836131, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.listenerProcessingTime, count=205, min=0.1049, max=695.014339, mean=0.5001238781617449, stddev=1.347580926286964, p50=0.143199, p75=0.153399, p95=5.343478, p98=5.343478, p99=5.343478, p999=5.343478, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22837484397222674, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.listenerProcessingTime, count=205, min=0.087799, max=61.418056, mean=0.2554738472990244, stddev=0.2666280544376684, p50=0.197899, p75=0.251299, p95=1.200696, p98=1.200696, p99=1.200696, p999=1.200696, m1_rate=0.20832896038971738, m5_rate=0.2465355794328549, m15_rate=0.50675601186031, mean_rate=0.2285560434825772, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:54,822 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.listenerProcessingTime, count=198, min=0.0032, max=0.214199, mean=0.009024511596856655, stddev=0.004106924913715692, p50=0.0078, p75=0.0121, p95=0.0146, p98=0.0219, p99=0.0219, p999=0.0244, m1_rate=0.20832865678827367, m5_rate=0.20500083520299042, m15_rate=0.20832823614185725, mean_rate=0.222294643364055, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,132 INFO MapOutputTrackerMasterEndpoint [dispatcher-event-loop-3]: MapOutputTrackerMasterEndpoint stopped! 2023-11-13 04:00:55,618 INFO MemoryStore [RPC-Handler-6]: MemoryStore cleared 2023-11-13 04:00:55,618 INFO BlockManager [RPC-Handler-6]: BlockManager stopped 2023-11-13 04:00:55,626 INFO BlockManagerMaster [RPC-Handler-6]: BlockManagerMaster stopped 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.disk.diskSpaceUsed_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxOffHeapMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.maxOnHeapMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.memUsed_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.offHeapMemUsed_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.onHeapMemUsed_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingOffHeapMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.BlockManager.memory.remainingOnHeapMem_MB, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.job.activeJobs, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.job.allJobs, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.failedStages, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.runningStages, value=0 2023-11-13 04:00:55,627 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.DAGScheduler.stage.waitingStages, value=0 2023-11-13 04:00:55,628 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.DirectPoolMemory, value=268410 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.JVMHeapMemory, value=3254595040 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.JVMOffHeapMemory, value=244421384 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MajorGCCount, value=6 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MajorGCTime, value=1071 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MappedPoolMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MinorGCCount, value=22 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.MinorGCTime, value=897 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapExecutionMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapStorageMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OffHeapUnifiedMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapExecutionMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapStorageMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.OnHeapUnifiedMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeJVMRSSMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeJVMVMemory, value=0 2023-11-13 04:00:55,630 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeOtherRSSMemory, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreeOtherVMemory, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreePythonRSSMemory, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.ProcessTreePythonVMemory, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.ExecutorMetrics.TotalGCTime, value=1968 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.JVMCPU.jvmCpuTime, value=1155960000000 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.size, value=0 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-MarkSweep.count, value=6 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-MarkSweep.time, value=1071 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-Scavenge.count, value=22 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.PS-Scavenge.time, value=897 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.capacity, value=186994 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.count, value=13 2023-11-13 04:00:55,631 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.direct.used, value=186997 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.committed, value=5745147904 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.init, value=1056964608 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.max, value=26724532224 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.usage, value=0.13328344616641025 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.heap.used, value=3561937752 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.capacity, value=0 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.count, value=0 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.mapped.used, value=0 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.committed, value=261394432 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.init, value=2555904 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.max, value=-1 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.usage, value=-2.45905896E8 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.non-heap.used, value=245905896 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.committed, value=65667072 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.init, value=2555904 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.max, value=251658240 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.usage, value=0.25939839680989585 2023-11-13 04:00:55,632 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Code-Cache.used, value=65280768 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.committed, value=21061632 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.init, value=0 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.max, value=1073741824 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.usage, value=0.018622778356075287 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Compressed-Class-Space.used, value=19996056 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.committed, value=174665728 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.init, value=0 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.max, value=-1 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.usage, value=0.9196991409785897 2023-11-13 04:00:55,633 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.Metaspace.used, value=160639920 2023-11-13 04:00:55,635 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.committed, value=2227699712 2023-11-13 04:00:55,635 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.init, value=264241152 2023-11-13 04:00:55,635 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.max, value=9494855680 2023-11-13 04:00:55,635 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.usage, value=0.21559758304825546 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.used, value=2047067936 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Eden-Space.used-after-gc, value=0 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.committed, value=3273129984 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.init, value=704643072 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.max, value=20043530240 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.usage, value=0.06422182323107568 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.used, value=1287232056 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Old-Gen.used-after-gc, value=757190256 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.committed, value=244318208 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.init, value=44040192 2023-11-13 04:00:55,638 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.max, value=244318208 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.usage, value=0.9317265457349786 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.used, value=227637760 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.pools.PS-Survivor-Space.used-after-gc, value=227637760 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.committed, value=6006542336 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.init, value=1059520512 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.max, value=26724532223 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=GAUGE, name=application_1699846537913_0004.driver.jvm.total.used, value=3807898328 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.fileCacheHits, count=0 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.filesDiscovered, count=0 2023-11-13 04:00:55,639 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveCallsTimerSumMilliSec, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveClientCalls, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.parallelListingJobCount, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.HiveExternalCatalog.partitionsFetched, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.numEventsPosted, count=205 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.numDroppedEvents, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.numDroppedEvents, count=0 2023-11-13 04:00:55,640 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.numDroppedEvents, count=0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.numDroppedEvents, count=0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.numDroppedEvents, count=0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=COUNTER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.numDroppedEvents, count=0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.compilationTime, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.generatedClassSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.generatedMethodSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:55,641 INFO metrics [RPC-Handler-6]: type=HISTOGRAM, name=application_1699846537913_0004.driver.CodeGenerator.sourceCodeSize, count=0, min=0, max=0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0 2023-11-13 04:00:55,642 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.DAGScheduler.messageProcessingTime, count=1, min=3.263187, max=3.263187, mean=3.263187, stddev=0.0, p50=3.263187, p75=3.263187, p95=3.263187, p98=3.263187, p99=3.263187, p999=3.263187, m1_rate=6.281092580701629E-9, m5_rate=1.7301984934632537E-4, m15_rate=4.1447222734196495E-4, mean_rate=0.001113113806758314, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,642 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.HiveExternalCatalog.hiveCallTimer, count=0, min=0.0, max=0.0, mean=0.0, stddev=0.0, p50=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0, m1_rate=0.0, m5_rate=0.0, m15_rate=0.0, mean_rate=0.0, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,642 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.com.microsoft.hdinsight.spark.metrics.SparkMetricsListener, count=205, min=0.0357, max=587.930265, mean=0.06324980267470741, stddev=0.21229548016206784, p50=0.0476, p75=0.057099, p95=0.222099, p98=0.222099, p99=0.222099, p999=0.222099, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22842698270174208, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,642 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.com.microsoft.impulse.analyze.eventLog.ImpulseListener, count=205, min=0.0014, max=25.327199, mean=0.049976270007032676, stddev=0.1776974499794672, p50=0.0018, p75=0.0022, p95=0.705198, p98=0.705198, p99=0.705198, p999=0.705198, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22842713824532673, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,643 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.HeartbeatReceiver, count=205, min=6.0E-4, max=11.543354, mean=0.003629389604026141, stddev=0.006084854625098194, p50=0.0024, p75=0.0026, p95=0.0215, p98=0.0215, p99=0.0215, p999=0.0215, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22817805142500203, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,643 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.input.AdviseInputListener, count=205, min=5.0E-4, max=0.934897, mean=0.001963874242223215, stddev=0.003472039027397778, p50=0.0011, p75=0.0013, p95=0.014699, p98=0.014699, p99=0.014699, p999=0.014699, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22817292171414869, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,645 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.input.MetricsServiceListener, count=205, min=5.0E-4, max=2.757189, mean=8.6438150264945E-4, stddev=9.883771565460193E-4, p50=8.0E-4, p75=9.0E-4, p95=0.0017, p98=0.0017, p99=0.0017, p999=0.0017, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.2284268018837175, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,645 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.advise.output.AdviseListener, count=205, min=9.0E-4, max=11.253255, mean=0.004921848436035722, stddev=0.007272311266879202, p50=0.0032, p75=0.0035, p95=0.0281, p98=0.0281, p99=0.0281, p999=0.0281, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22816570128157473, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,645 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.deploy.history.rpc.app.RpcAppListener, count=205, min=0.083199, max=61.364357, mean=0.24769463644447176, stddev=0.26413506068551434, p50=0.190299, p75=0.230999, p95=1.183696, p98=1.183696, p99=1.183696, p999=1.183696, m1_rate=0.20832896038971738, m5_rate=0.2465355794328549, m15_rate=0.50675601186031, mean_rate=0.2283465298637369, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,646 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.diagnostic.configuration.DefaultsConfigSparkListener, count=205, min=5.0E-4, max=636.933171, mean=0.0010419886515351897, stddev=0.20246756593147539, p50=8.0E-4, p75=9.0E-4, p95=0.0025, p98=0.0025, p99=0.0045, p999=0.0045, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22829641128373013, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,646 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.listeners.LogAnalyticsSparkListener, count=205, min=0.0051, max=0.519998, mean=0.048625612469536006, stddev=0.1277559920426589, p50=0.014099, p75=0.0154, p95=0.519998, p98=0.519998, p99=0.519998, p999=0.519998, m1_rate=0.20832895974486895, m5_rate=0.24653257304291798, m15_rate=0.5067536770298199, mean_rate=0.22842618475267285, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,646 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.listeners.SparkObservabilityListener, count=205, min=8.0E-4, max=13.468846, mean=0.01741323686908522, stddev=0.05604988208621536, p50=0.0018, p75=0.002, p95=0.222899, p98=0.222899, p99=0.222899, p999=0.222899, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22829626524873195, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,646 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.scheduler.EventLoggingListener, count=283, min=0.0012, max=99.107803, mean=2.322071982664257, stddev=12.509103055163857, p50=0.009, p75=0.0108, p95=0.0284, p98=69.91662, p99=69.91662, p999=69.91662, m1_rate=0.41625398159081284, m5_rate=0.4007136539655776, m15_rate=0.6494954472674159, mean_rate=0.31514754689067903, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,647 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.SparkSession$$anon$1, count=200, min=5.0E-4, max=0.0321, mean=0.0028877013106640994, stddev=0.007919188127654504, p50=7.0E-4, p75=9.0E-4, p95=0.0321, p98=0.0321, p99=0.0321, p999=0.0321, m1_rate=0.208328729064452, m5_rate=0.2152957565433306, m15_rate=0.2827261928349317, mean_rate=0.22312207911385537, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,647 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.execution.streaming.StreamingQueryListenerBus, count=198, min=5.0E-4, max=0.0116, mean=0.001652629208559088, stddev=4.88313337597446E-4, p50=0.0016, p75=0.0021, p95=0.0024, p98=0.0024, p99=0.0026, p999=0.0028, m1_rate=0.20832865678827367, m5_rate=0.20500083520299042, m15_rate=0.20832823614185725, mean_rate=0.22208899648425742, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,648 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.execution.ui.SQLAppStatusListener, count=200, min=0.0014, max=2.271191, mean=0.004011516710515512, stddev=0.001290508148180611, p50=0.0042, p75=0.0048, p95=0.0053, p98=0.0064, p99=0.0064, p999=0.0064, m1_rate=0.208328729064452, m5_rate=0.2152957565433306, m15_rate=0.2827261928349317, mean_rate=0.2231499248005222, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,648 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.sql.util.ExecutionListenerBus, count=398, min=1.0E-4, max=0.174699, mean=6.406853178886916E-4, stddev=0.005213911680828183, p50=5.0E-4, p75=6.0E-4, p95=9.0E-4, p98=0.001, p99=0.001, p999=0.0085, m1_rate=0.4166574706910892, m5_rate=0.43093755278535395, m15_rate=0.5662813301245468, mean_rate=0.4464150912060376, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,648 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.status.AppStatusListener, count=205, min=0.0145, max=21.324415, mean=0.07197753074439554, stddev=0.053224985905563585, p50=0.090899, p75=0.123399, p95=0.138899, p98=0.1425, p99=0.147199, p999=0.344699, m1_rate=0.20000044631421846, m5_rate=0.24479685518024144, m15_rate=0.5060043462765247, mean_rate=0.22801631235112826, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,648 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.listenerProcessingTime.org.apache.spark.ui.EnhancementAppStatusListener, count=205, min=5.0E-4, max=41.879333, mean=0.2403654681680612, stddev=0.8840658907385498, p50=8.0E-4, p75=0.001, p95=3.503186, p98=3.503186, p99=3.503186, p999=3.503186, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22829184640766104, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,649 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.appStatus.listenerProcessingTime, count=205, min=0.0339, max=21.419615, mean=0.09263961326509938, stddev=0.04929619326229976, p50=0.107299, p75=0.139699, p95=0.157299, p98=0.157299, p99=0.167299, p999=0.364499, m1_rate=0.20000044631421846, m5_rate=0.24479685518024144, m15_rate=0.5060043462765247, mean_rate=0.22801590948311604, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,649 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.eventLog.listenerProcessingTime, count=205, min=0.0034, max=99.165703, mean=4.788741256502146, stddev=17.64826730265202, p50=0.0072, p75=0.0091, p95=69.93032, p98=69.93032, p99=69.93032, p999=69.93032, m1_rate=0.20832896103456575, m5_rate=0.24653858582279206, m15_rate=0.506758346690801, mean_rate=0.22828640234922692, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,652 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.executorManagement.listenerProcessingTime, count=205, min=0.0054, max=12.230952, mean=0.01778565657231402, stddev=0.00739116225001151, p50=0.0163, p75=0.0189, p95=0.0367, p98=0.0367, p99=0.0367, p999=0.0367, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22817564591971481, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,652 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.shared.listenerProcessingTime, count=205, min=0.1049, max=695.014339, mean=0.5001238781617449, stddev=1.347580926286964, p50=0.143199, p75=0.153399, p95=5.343478, p98=5.343478, p99=5.343478, p999=5.343478, m1_rate=0.20832896173545407, m5_rate=0.2465416427391118, m15_rate=0.5067606945286711, mean_rate=0.22816380636135003, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,653 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.sparkRpcHistoryServer.listenerProcessingTime, count=205, min=0.087799, max=61.418056, mean=0.2554738472990244, stddev=0.2666280544376684, p50=0.197899, p75=0.251299, p95=1.200696, p98=1.200696, p99=1.200696, p999=1.200696, m1_rate=0.20832896038971738, m5_rate=0.2465355794328549, m15_rate=0.50675601186031, mean_rate=0.22834466363023412, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,653 INFO metrics [RPC-Handler-6]: type=TIMER, name=application_1699846537913_0004.driver.LiveListenerBus.queue.streams.listenerProcessingTime, count=198, min=0.0032, max=0.214199, mean=0.009024511596856655, stddev=0.004106924913715692, p50=0.0078, p75=0.0121, p95=0.0146, p98=0.0219, p99=0.0219, p999=0.0244, m1_rate=0.20832865678827367, m5_rate=0.20500083520299042, m15_rate=0.20832823614185725, mean_rate=0.22208764316515656, rate_unit=events/second, duration_unit=milliseconds 2023-11-13 04:00:55,663 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint [dispatcher-event-loop-3]: OutputCommitCoordinator stopped! 2023-11-13 04:00:55,690 INFO SparkContext [RPC-Handler-6]: Successfully stopped SparkContext 2023-11-13 04:00:55,756 INFO SparkContext [RPC-Handler-6]: SparkContext already stopped. 2023-11-13 04:00:55,773 INFO ApplicationMaster [Driver]: Final app status: SUCCEEDED, exitCode: 0 2023-11-13 04:00:55,780 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numContainersPendingAllocate, value=0 2023-11-13 04:00:55,781 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numExecutorsFailed, value=0 2023-11-13 04:00:55,781 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numExecutorsRunning, value=1 2023-11-13 04:00:55,781 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numLocalityAwareTasks, value=0 2023-11-13 04:00:55,781 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numReleasedContainers, value=0 2023-11-13 04:00:55,781 WARN AbstractChannelHandlerContext [RPC-Handler-6]: An exception 'java.lang.IllegalArgumentException: not existed channel:[id: 0x93816b56, L:/10.0.0.4:10001 ! R:/10.0.0.4:56238]' [enable DEBUG level for full stacktrace] was thrown by a user handler's exceptionCaught() method while handling the following exception: java.lang.IllegalArgumentException: not existed channel:[id: 0x93816b56, L:/10.0.0.4:10001 ! R:/10.0.0.4:56238] at org.apache.livy.rsc.rpc.RpcDispatcher.getRpc(RpcDispatcher.java:67) at org.apache.livy.rsc.rpc.RpcDispatcher.channelInactive(RpcDispatcher.java:85) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) at org.apache.livy.rsc.rpc.Rpc$5.channelInactive(Rpc.java:244) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:392) at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:357) at io.netty.handler.codec.ByteToMessageCodec.channelInactive(ByteToMessageCodec.java:118) at org.apache.livy.rsc.rpc.KryoMessageCodec.channelInactive(KryoMessageCodec.java:100) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:813) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at java.lang.Thread.run(Thread.java:750) 2023-11-13 04:00:55,781 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numContainersPendingAllocate, value=0 2023-11-13 04:00:55,782 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numExecutorsFailed, value=0 2023-11-13 04:00:55,782 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numExecutorsRunning, value=1 2023-11-13 04:00:55,782 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numLocalityAwareTasks, value=0 2023-11-13 04:00:55,782 INFO metrics [main]: type=GAUGE, name=application_1699846537913_0004.applicationMaster.numReleasedContainers, value=0 2023-11-13 04:00:55,801 INFO MetricsServiceListener [shutdown-hook-0]: Shutting down metrics service writer thread java.util.concurrent.RejectedExecutionException: Task scala.concurrent.impl.CallbackRunnable@634fce57 rejected from java.util.concurrent.ThreadPoolExecutor@59eaa9a4[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 40] at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063) at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830) at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379) at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:668) at scala.concurrent.impl.ExecutionContextImpl$$anon$4.execute(ExecutionContextImpl.scala:138) at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:72) at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1(Promise.scala:288) at scala.concurrent.impl.Promise$DefaultPromise.$anonfun$tryComplete$1$adapted(Promise.scala:288) at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:288) at scala.concurrent.Promise.complete(Promise.scala:53) at scala.concurrent.Promise.complete$(Promise.scala:52) at scala.concurrent.impl.Promise$DefaultPromise.complete(Promise.scala:187) at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33) at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:750) 2023-11-13 04:00:55,977 INFO ApplicationMaster [shutdown-hook-0]: Unregistering ApplicationMaster with SUCCEEDED 2023-11-13 04:00:55,986 INFO AMRMClientImpl [shutdown-hook-0]: Waiting for application to be successfully unregistered. 2023-11-13 04:00:56,089 INFO ApplicationMaster [shutdown-hook-0]: Deleting staging directory wasbs://c9c91c6c-a690-4768-8e62-85c452fde267@uok5052eb0xs0p2mha69bgq0.blob.core.windows.net/user/trusted-service-user/trusted-service-user/.sparkStaging/application_1699846537913_0004 2023-11-13 04:00:56,112 WARN AzureFileSystemThreadPoolExecutor [shutdown-hook-0]: Disabling threads for Delete operation as thread count 0 is <= 1 2023-11-13 04:00:56,125 INFO AzureFileSystemThreadPoolExecutor [shutdown-hook-0]: Time taken for Delete operation is: 13 ms with threads: 0 2023-11-13 04:00:56,152 INFO RpcAppSparkContextServer [shutdown-hook-0]: Closing remote SparkContext service at 10.0.0.4:18083, remoteSparkContext/remoteSparkContextEndpoint 2023-11-13 04:00:56,170 INFO ShutdownHookManager [shutdown-hook-0]: Shutdown hook called 2023-11-13 04:00:56,171 INFO ShutdownHookManager [shutdown-hook-0]: Deleting directory /mnt/var/hadoop/tmp/nm-local-dir/usercache/trusted-service-user/appcache/application_1699846537913_0004/spark-638a676a-577e-4bdd-94e4-4252a6322742 2023-11-13 04:00:56,182 INFO ShutdownHookManager [shutdown-hook-0]: Deleting directory /mnt/var/hadoop/tmp/nm-local-dir/usercache/trusted-service-user/appcache/application_1699846537913_0004/spark-638a676a-577e-4bdd-94e4-4252a6322742/pyspark-f7fc16a8-8b66-405d-bbdd-d94131668352 2023-11-13 04:00:56,194 INFO RpcAppSender [shutdown-hook-0]: Closing RPC app sender 2023-11-13 04:00:56,194 INFO RpcAppSender [shutdown-hook-0]: Sending remaining events 2023-11-13 04:00:56,200 INFO RpcAppSender [shutdown-hook-0]: Sent RPC app end event of application_1699846537913_0004/1 2023-11-13 04:00:56,212 INFO RpcAppSender [shutdown-hook-0]: RPC app sender closed 2023-11-13 04:00:56,212 INFO RpcAppEventQueue [shutdown-hook-0]: Max number of events in queue: 6.