[ 
https://issues.apache.org/jira/browse/HIVE-24552?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17252438#comment-17252438
 ] 

Yongzhi Chen commented on HIVE-24552:
-------------------------------------

To prevent the connections accumulation, we should close HiveMetaStoreClient in 
the load dynamic partition task. So each thread can close its own HMS 
connection right after use, not wait for the finalizer to close them. 

> Possible HMS connections leak or accumulation in loadDynamicPartitions
> ----------------------------------------------------------------------
>
>                 Key: HIVE-24552
>                 URL: https://issues.apache.org/jira/browse/HIVE-24552
>             Project: Hive
>          Issue Type: Bug
>          Components: Metastore
>            Reporter: Yongzhi Chen
>            Assignee: Yongzhi Chen
>            Priority: Major
>
> When loadDynamicPartitions (Hive.java) is called, it generates several 
> threads to handle FileMove. These threads may generate HiveMetaStore 
> connections. These connections may not be closed in time and cause many 
> accumulated connections. Following is the log got from running insert 
> overwrites many times, you can see these threads created new HMS connections, 
> and the total number of open connections is large. And the finalizer closes 
> the connections and sometimes had errors:
> {noformat}
> <14>1 2020-12-15T17:06:15.894Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-14"] Opened a connection to metastore, 
> current connections: 44021
> <14>1 2020-12-15T17:06:15.894Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-14"] Connected to metastore.
> <14>1 2020-12-15T17:06:15.894Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.RetryingMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-14"] RetryingMetaStoreClient proxy=class 
> org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient 
> ugi=hive/[email protected] (auth:KERBEROS) retries=24 delay=5 
> lifetime=0
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-5"] Opened a connection to metastore, 
> current connections: 44022
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-5"] Connected to metastore.
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.RetryingMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-5"] RetryingMetaStoreClient proxy=class 
> org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient 
> ugi=hive/[email protected] (auth:KERBEROS) retries=24 delay=5 
> lifetime=0
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-6"] Opened a connection to metastore, 
> current connections: 44023
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-6"] Connected to metastore.
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.RetryingMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-6"] RetryingMetaStoreClient proxy=class 
> org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient 
> ugi=hive/[email protected] (auth:KERBEROS) retries=24 delay=5 
> lifetime=0
> <14>1 2020-12-15T17:06:15.895Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" 
> thread="load-dynamic-partitionsToAdd-3"] Opened a connection to metastore, 
> current connections: 44024
> ....
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43904
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43903
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43902
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43901
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43900
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43899
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43898
> <14>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="metastore.HiveMetaStoreClient" level="INFO" thread="Finalizer"] Closed 
> a connection to metastore, current connections: 43897
> <12>1 2020-12-15T17:05:38.485Z hiveserver2-0 hiveserver2 1 
> a3671b96-74fb-4ee9-b186-aeff0de0bbec [mdc@18060 
> class="transport.TIOStreamTransport" level="WARN" thread="Finalizer"] Error 
> closing output stream.
> java.net.SocketException: Socket closed
>       at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118)
>       at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
>       at 
> java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
>       at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
>       at java.io.FilterOutputStream.close(FilterOutputStream.java:158)
>       at 
> org.apache.thrift.transport.TIOStreamTransport.close(TIOStreamTransport.java:110)
>       at org.apache.thrift.transport.TSocket.close(TSocket.java:235)
>       at 
> org.apache.thrift.transport.TSaslTransport.close(TSaslTransport.java:400)
>       at 
> org.apache.thrift.transport.TSaslClientTransport.close(TSaslClientTransport.java:37)
>       at 
> org.apache.hadoop.hive.metastore.security.TFilterTransport.close(TFilterTransport.java:52)
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.close(HiveMetaStoreClient.java:729)
>       at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>       at java.lang.reflect.Method.invoke(Method.java:498)
>       at 
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:212)
>       at com.sun.proxy.$Proxy59.close(Unknown Source)
>       at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>       at java.lang.reflect.Method.invoke(Method.java:498)
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient$SynchronizedHandler.invoke(HiveMetaStoreClient.java:3411)
>       at com.sun.proxy.$Proxy59.close(Unknown Source)
>       at org.apache.hadoop.hive.ql.metadata.Hive.close(Hive.java:540)
>       at org.apache.hadoop.hive.ql.metadata.Hive.finalize(Hive.java:512)
>       at java.lang.System$2.invokeFinalize(System.java:1273)
>       at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:102)
>       at java.lang.ref.Finalizer.access$100(Finalizer.java:34)
>       at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:217)
> {noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Reply via email to