Hi! I notice the strange behavior of HBase during reading and writing simultaneously.
About my cluster: Master and 16 regionservers, quorum of 3 zookeepers, gigabit ethernet, all nodes are in same subnet. Data is read from a table containing ~100 millions binary records (images). I use Cloudera-cdh3u2 hadoop distro and Oracle JDK-1.6.0 update 26 About read: I'm reading data from HBase to server A using Java-app written in Netty, directly from Hbase using native objects and methods. Speed of reading is 1.2-10 thousands requests per second. For reading I use Jmeter, all requests are distributed evenly among all regionservers. About write: Data comes from servers B and C in bulk mode every minute, size is 90-100 MB. For data recording I use local hbase-thrift on source hosts which is configured to communicate with cluster's zookeeper quorum. So, data is recording into regionservers directly bypassing the master server. About problem: Normally response time for read request is ~30 milliseconds, but 1 time per 1-3 min I see very large response delays on server A.(1-8 secs). This occurs at random regionserver, each time at different one, and at random region, each time at different one too. Part of log from reading host: 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.433sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.393sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.219sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.339sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.246sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.359sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.346sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.197sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.383sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.205sec) request to hbase: /?key=bd71769b0aa6406e24ee948bc789a46b85e77116 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key bd71769b0aa6406e24ee948bc789a46b85e77116 locate on address: hd-16:60020, regioninfo: images,bccccccccccccccccccccccccccccccccccccc86,1325059350066.77574daf582ff29f16bd3c0f1628dfcf. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.33sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.364sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.168sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.209sec) request to hbase: /?key=022142ffbfab5825223488378cff8db8d455005a 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 022142ffbfab5825223488378cff8db8d455005a locate on address: hd-16:60020, regioninfo: images,0199999999999999999999999999999999999999,1325058729876.48e77eb08590018acc60c4e2b2bde218. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.192sec) request to hbase: /?key=bcda6745963faeaf825a8a80b6817352f8cceb87 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key bcda6745963faeaf825a8a80b6817352f8cceb87 locate on address: hd-16:60020, regioninfo: images,bccccccccccccccccccccccccccccccccccccc86,1325059350066.77574daf582ff29f16bd3c0f1628dfcf. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.17sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.186sec) request to hbase: /?key=9db4b4f2a1ccf495214f8f03c522edba500e062b 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Key 9db4b4f2a1ccf495214f8f03c522edba500e062b locate on address: hd-16:60020, regioninfo: images,9d9a591ebb50ff0a2a83c0eedf8a7ea4f6334738,1325059724340.730ce4bd61fd984e666ed53a34806225. 12/01/19 10:20:02 WARN search.ImageNettyServerRequestHandler: Long time (2.169sec) request to hbase: /?key=01de935e5c6da618ce9d4f8f278bf137c7eb214b Disabling record operations at other hosts (B and C) doesn't solve this problem, but delays occur less frequently and for a shorter period when recording is disabled. There are no errors or warns in any regionserver logs. Time of bulk writing is different from time delays occur when. Time of region compacting is different from time delays occur when too. My questions: If I'm doing something wrong, what is it? Is there way to fix this float delays? Where should I look for the cause of this trouble? Any ideas are welcome, thanks in advance! -- Best regards, Paul
