You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@phoenix.apache.org by "Yeonseop Kim (JIRA)" <ji...@apache.org> on 2017/01/04 13:18:59 UTC
[jira] [Comment Edited] (PHOENIX-3553) Zookeeper connection should
be closed immediately after DefaultStatisticsCollector's collecting stats
done
[ https://issues.apache.org/jira/browse/PHOENIX-3553?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15798247#comment-15798247 ]
Yeonseop Kim edited comment on PHOENIX-3553 at 1/4/17 1:18 PM:
---------------------------------------------------------------
ScanType.COMPACT_DROP_DELETES is determined in DefaultCompactor and CompactionRequest class
{code:title=DefaultCompactor.java|borderStyle=solid}
public List<Path> compact(final CompactionRequest request,
CompactionThroughputController throughputController, User user) throws IOException {
...
ScanType scanType =
request.isAllFiles() ? ScanType.COMPACT_DROP_DELETES : ScanType.COMPACT_RETAIN_DELETES;
...
{code}
{code:title=CompactionRequest.java|borderStyle=solid}
public boolean isAllFiles() {
return this.isMajor == DisplayCompactionType.MAJOR
|| this.isMajor == DisplayCompactionType.ALL_FILES;
}
public boolean isMajor() {
return this.isMajor == DisplayCompactionType.MAJOR;
}
{code}
Following is real HBase log (v1.1.8) from my site.
You can find that during compaction, 2 zookeeper connections are established, but only one connection is closed.
(sessionid=0x259160941a6fa5d,0x259160941a6fa5e)
Last line of log tell us that this compaction is DisplayCompactionType.ALL_FILES type compaction, not DisplayCompactionType.MAJOR.
There should be a word "major" appeared in the last line for the compaction type to be DisplayCompactionType.MAJOR.
{noformat}
2016-12-23 16:48:31,112 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] regionserver.HStore: Starting compaction of 6 file(s) in L#0 of TEST.TEST_TABLE,\x0DTCCLN78\x00K4571038A\x00MA_RES_RMV_INTRA_CHUCK\x0009\x00TCCLN78,1482479246551.044fb02eb5f873b692730b2dcbe76e13. into tmpdir=hdfs://ichbig/hbase/data/default/TEST.TEST_TABLE/044fb02eb5f873b692730b2dcbe76e13/.tmp, totalSize=25.8 M
2016-12-23 16:48:31,195 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7a261ee connecting to ZooKeeper ensemble=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181
2016-12-23 16:48:31,195 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.ZooKeeper: Initiating client connection, connectString=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181 sessionTimeout=90000 watcher=hconnection-0x7a261ee0x0, quorum=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181, baseZNode=/hbase
2016-12-23 16:48:31,197 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Opening socket connection to server ichbig-01-005/172.16.252.25:2181. Will not attempt to authenticate using SASL (unknown error)
2016-12-23 16:48:31,197 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Socket connection established to ichbig-01-005/172.16.252.25:2181, initiating session
2016-12-23 16:48:31,204 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Session establishment complete on server ichbig-01-005/172.16.252.25:2181, sessionid = 0x259160941a6fa5d, negotiated timeout = 90000
2016-12-23 16:48:31,207 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7cdbb8b2 connecting to ZooKeeper ensemble=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181
2016-12-23 16:48:31,207 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.ZooKeeper: Initiating client connection, connectString=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181 sessionTimeout=90000 watcher=hconnection-0x7cdbb8b20x0, quorum=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181, baseZNode=/hbase
2016-12-23 16:48:31,208 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Opening socket connection to server ichbig-01-005/172.16.252.25:2181. Will not attempt to authenticate using SASL (unknown error)
2016-12-23 16:48:31,208 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Socket connection established to ichbig-01-005/172.16.252.25:2181, initiating session
2016-12-23 16:48:31,215 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Session establishment complete on server ichbig-01-005/172.16.252.25:2181, sessionid = 0x259160941a6fa5e, negotiated timeout = 90000
2016-12-23 16:48:31,223 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] hfile.CacheConfig: blockCache=org.apache.hadoop.hbase.io.hfile.CombinedBlockCache@7a2e3a98, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2016-12-23 16:48:35,542 INFO [phoenix-update-statistics-0] client.ConnectionManager$HConnectionImplementation: Closing zookeeper sessionid=0x259160941a6fa5d
2016-12-23 16:48:35,549 INFO [phoenix-update-statistics-0] zookeeper.ZooKeeper: Session: 0x259160941a6fa5d closed
2016-12-23 16:48:35,549 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-EventThread] zookeeper.ClientCnxn: EventThread shut down
2016-12-23 16:48:35,900 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] regionserver.HStore: Completed compaction of 6 (all) file(s) in L#0 of TEST.TEST_TABLE,\x0DTCCLN78\x00K4571038A\x00MA_RES_RMV_INTRA_CHUCK\x0009\x00TCCLN78,1482479246551.044fb02eb5f873b692730b2dcbe76e13. into 2b6043fc7d584afabfdd74f7b4e16c8d(size=16.8 M), total size for store is 16.8 M. This selection was in queue for 0sec, and took 4sec to execute.
{noformat}
was (Author: nilkis):
ScanType.COMPACT_DROP_DELETES is determined in DefaultCompactor and CompactionRequest class
{code:title=DefaultCompactor.java|borderStyle=solid}
public List<Path> compact(final CompactionRequest request,
CompactionThroughputController throughputController, User user) throws IOException {
...
ScanType scanType =
request.isAllFiles() ? ScanType.COMPACT_DROP_DELETES : ScanType.COMPACT_RETAIN_DELETES;
...
{code}
{code:title=CompactionRequest.java|borderStyle=solid}
public boolean isAllFiles() {
return this.isMajor == DisplayCompactionType.MAJOR
|| this.isMajor == DisplayCompactionType.ALL_FILES;
}
public boolean isMajor() {
return this.isMajor == DisplayCompactionType.MAJOR;
}
{code}
Following is real HBase log (v1.1.8) from my site.
You can find that during compaction, 2 zookeeper connections are established, but only one connection is closed.
(sessionid=0x259160941a6fa5d,0x259160941a6fa5e)
Last line of log tell us that this compaction is DisplayCompactionType.ALL_FILES type compaction, not DisplayCompactionType.MAJOR.
There should be a word "major" appeared in the last line for the compaction type to be DisplayCompactionType.MAJOR.
{noformat}
2016-12-23 16:48:31,112 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] regionserver.HStore: Starting compaction of 6 file(s) in L#0 of TEST.TEST_TABLE,\x0DTCCLN78\x00K4571038A\x00MA_RES_RMV_INTRA_CHUCK\x0009\x00TCCLN78,1482479246551.044fb02eb5f873b692730b2dcbe76e13. into tmpdir=hdfs://ichbig/hbase/data/default/TEST.TEST_TABLE/044fb02eb5f873b692730b2dcbe76e13/.tmp, totalSize=25.8 M
2016-12-23 16:48:31,195 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7a261ee connecting to ZooKeeper ensemble=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181
2016-12-23 16:48:31,195 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.ZooKeeper: Initiating client connection, connectString=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181 sessionTimeout=90000 watcher=hconnection-0x7a261ee0x0, quorum=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181, baseZNode=/hbase
2016-12-23 16:48:31,197 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Opening socket connection to server ichbig-01-005/172.16.252.25:2181. Will not attempt to authenticate using SASL (unknown error)
2016-12-23 16:48:31,197 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Socket connection established to ichbig-01-005/172.16.252.25:2181, initiating session
2016-12-23 16:48:31,204 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Session establishment complete on server ichbig-01-005/172.16.252.25:2181, sessionid = 0x259160941a6fa5d, negotiated timeout = 90000
2016-12-23 16:48:31,207 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7cdbb8b2 connecting to ZooKeeper ensemble=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181
2016-12-23 16:48:31,207 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] zookeeper.ZooKeeper: Initiating client connection, connectString=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181 sessionTimeout=90000 watcher=hconnection-0x7cdbb8b20x0, quorum=ichbig-01-004:2181,ichbig-01-005:2181,ichbig-02-005:2181,ichbig-01-006:2181,ichbig-02-006:2181, baseZNode=/hbase
2016-12-23 16:48:31,208 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Opening socket connection to server ichbig-01-005/172.16.252.25:2181. Will not attempt to authenticate using SASL (unknown error)
2016-12-23 16:48:31,208 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Socket connection established to ichbig-01-005/172.16.252.25:2181, initiating session
2016-12-23 16:48:31,215 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-SendThread(ichbig-01-005:2181)] zookeeper.ClientCnxn: Session establishment complete on server ichbig-01-005/172.16.252.25:2181, sessionid = 0x259160941a6fa5e, negotiated timeout = 90000
2016-12-23 16:48:31,223 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] hfile.CacheConfig: blockCache=org.apache.hadoop.hbase.io.hfile.CombinedBlockCache@7a2e3a98, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2016-12-23 16:48:35,542 INFO [phoenix-update-statistics-0] client.ConnectionManager$HConnectionImplementation: Closing zookeeper sessionid=0x259160941a6fa5d
2016-12-23 16:48:35,549 INFO [phoenix-update-statistics-0] zookeeper.ZooKeeper: Session: 0x259160941a6fa5d closed
2016-12-23 16:48:35,549 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607-EventThread] zookeeper.ClientCnxn: EventThread shut down
2016-12-23 16:48:35,900 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] regionserver.HStore: Completed compaction of 6 (all) file(s) in L#0 of TEST.TEST_TABLE,\x0DTCCLN78\x00K4571038A\x00MA_RES_RMV_INTRA_CHUCK\x0009\x00TCCLN78,1482479246551.044fb02eb5f873b692730b2dcbe76e13. into 2b6043fc7d584afabfdd74f7b4e16c8d(size=16.8 M), total size for store is 16.8 M. This selection was in queue for 0sec, and took 4sec to execute.
2016-12-23 16:48:35,901 INFO [regionserver/myhost/172.16.252.78:16020-shortCompactions-1482479243607] regionserver.CompactSplitThread: Completed compaction: Request = regionName=TEST.TEST_TABLE,\x0DTCCLN78\x00K4571038A\x00MA_RES_RMV_INTRA_CHUCK\x0009\x00TCCLN78,1482479246551.044fb02eb5f873b692730b2dcbe76e13., storeName=L#0, fileCount=6, fileSize=25.8 M, priority=4, time=12099382904170064; duration=4sec
{noformat}
> Zookeeper connection should be closed immediately after DefaultStatisticsCollector's collecting stats done
> ----------------------------------------------------------------------------------------------------------
>
> Key: PHOENIX-3553
> URL: https://issues.apache.org/jira/browse/PHOENIX-3553
> Project: Phoenix
> Issue Type: Bug
> Affects Versions: 4.9.0
> Reporter: Yeonseop Kim
> Labels: stats, zookeeper
> Fix For: 4.10.0
>
> Attachments: PHOENIX-3553.patch
>
>
> In every minor compaction job of HBase,
> org.apache.phoenix.schema.stats.DefaultStatisticsCollector.initGuidePostDepth() is called,
> and SYSTEM.CATALOG table is open to get guidepost width via
> htable = env.getTable(
> SchemaUtil.getPhysicalTableName(PhoenixDatabaseMetaData.SYSTEM_CATALOG_NAME_BYTES, env.getConfiguration()));
> This function call creates one zookeeper connection to get cluster id.
> DefaultStatisticsCollector doesn't close this zookeeper connection immediately after get guidepost width, and the zookeeper connection remains alive until HRegion is closed.
> This is not a problem with small number of Regions, but when number of Region is large and upsert operation is frequent, the number of zookeeper connection gradually increases to hundreds, and the zookeeper server nodes experience short of available TCP/IP ports.
> This zookeeper connection should be closed immediately after get guidepost width.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)