You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@bookkeeper.apache.org by GitBox <gi...@apache.org> on 2017/11/29 21:44:07 UTC

[GitHub] dlg99 opened a new issue #791: Bookkeeper client allocates a lot of short-lived objects

dlg99 opened a new issue #791: Bookkeeper client allocates a lot of short-lived objects
URL: https://github.com/apache/bookkeeper/issues/791
 
 
   We (Salesforce) upgraded NIC on our perf cluster to 20gbps  (as 10gbps had become a bottleneck) and could not get throughput to go above 15gbps. Proxy (our bk client/java app) used about 18 cores out of 36 (1800% CPU utilization in 'top').
   
   Upon the investigation I've noticed that GC runs roughly 2 times per second (111 GCs in 60seconds) with GC pause of about 20ms.
   
   From profiler (skipping proxy internal stacks) one can see that roughly 7G/sec are coming from protobuf + digest manager (see below), plus some extra (excluded here) from internal code.
   
   I have some changes in work that reduced allocations to ~1.1GB/sec, need to finish some extra perf benchmarks. Changes include upgrade to protobuf 3.4 w/proto2 with use of unsafe wrappers. 
   With these changes throughput went up close to 20gbps. CPU utilization is lower but still high (~1500%) with a lot of it coming from crc32, subject to another investigation/tuning/.. 
   Majority (90%) of 1.1GB/sec are still coming from protobuf and it looks like the only other thing I can try there is to move to proto3 code gen. Quick prototype shown that simple move to proto3 (and its reduced immutability guarantees) results in flapping tests so the change is not that safe and requires more work, thus excluded form scope at this moment.
   
   
   Top TLAB allocations, expanded to minimal relevant stacks (in 60 sec interval):
   --------
   Stack Trace	TLABs	Total TLAB Size(bytes)	Pressure(%)
   bk-shade.com.google.proto_2.6.1.CodedInputStream.readRawBytesSlowPath(int)	347,980	192,147,664,488	35.738
      bk-shade.com.google.proto_2.6.1.CodedInputStream.readBytes()	347,980	192,147,664,488	35.738
         org.apache.bookkeeper.proto.BookkeeperProtocol$ReadResponse.<init>(CodedInputStream, ExtensionRegistryLite)	347,980	192,147,664,488	35.738
   java.util.zip.CRC32.update(ByteBuffer)	36,317	97,655,274,184	18.163
      org.apache.bookkeeper.client.CRC32DigestManager.update(ByteBuf)	36,317	97,655,274,184	18.163
         org.apache.bookkeeper.client.DigestManager.verifyDigest(long, ByteBuf, boolean)	36,317	97,655,274,184	18.163
   bk-shade.com.google.proto_2.6.1.ByteString.copyFrom(byte[], int, int)	15,601	50,946,922,616	9.476
      bk-shade.com.google.proto_2.6.1.ByteString.copyFrom(byte[])	15,595	50,946,907,320	9.476
         org.apache.bookkeeper.proto.PerChannelBookieClient.addEntry(long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	15,595	50,946,907,320	9.476
      bk-shade.com.google.proto_2.6.1.TextFormat.unescapeBytes(CharSequence)	6	15,296	0
   org.apache.bookkeeper.proto.PerChannelBookieClient.addEntry(long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	15,528	50,528,061,008	9.398
      org.apache.bookkeeper.proto.BookieClient$2.operationComplete(int, PerChannelBookieClient)	15,528	50,528,061,008	9.398
         org.apache.bookkeeper.proto.BookieClient$2.operationComplete(int, Object)	15,528	50,528,061,008	9.398      org.apache.bookkeeper.proto.PerChannelBookieClient.completeOperation(BookkeeperInternalCallbacks$GenericCallback, int)	15,528	50,528,061,008	9.398            org.apache.bookkeeper.proto.PerChannelBookieClient.connectIfNeededAndDoOp(BookkeeperInternalCallbacks$GenericCallback)	15,528	50,528,061,008	9.398               org.apache.bookkeeper.proto.DefaultPerChannelBookieClientPool.obtain(BookkeeperInternalCallbacks$GenericCallback, long)	15,528	50,528,061,008	9.398
                     org.apache.bookkeeper.proto.BookieClient.addEntry(BookieSocketAddress, long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	15,528	50,528,061,008	9.398
                        org.apache.bookkeeper.client.PendingAddOp.sendWriteRequest(int)	15,528	50,528,061,008	9.398
   bk-shade.com.google.proto_2.6.1.CodedInputStream.<init>(InputStream)	24,594	13,702,219,976	2.548
      bk-shade.com.google.proto_2.6.1.CodedInputStream.newInstance(InputStream)	24,594	13,702,219,976	2.548
         bk-shade.com.google.proto_2.6.1.AbstractParser.parsePartialFrom(InputStream, ExtensionRegistryLite)	24,594	13,702,219,976	2.548
            bk-shade.com.google.proto_2.6.1.AbstractParser.parseFrom(InputStream, ExtensionRegistryLite)	24,594	13,702,219,976	2.548
               bk-shade.com.google.proto_2.6.1.AbstractParser.parseFrom(InputStream, ExtensionRegistryLite)	24,594	13,702,219,976	2.548
                  org.apache.bookkeeper.proto.BookkeeperProtocol$Response.parseFrom(InputStream, ExtensionRegistryLite)	24,594	13,702,219,976	2.548                org.apache.bookkeeper.proto.BookieProtoEncoding$ResponseEnDecoderV3.decode(ByteBuf)	24,594	13,702,219,976	2.548
   io.netty.buffer.AbstractByteBuf.slice(int, int)	1,286	3,807,799,016	0.708
      io.netty.buffer.AbstractUnpooledSlicedByteBuf.slice(int, int)	1,263	3,746,733,704	0.697
         org.apache.bookkeeper.client.DigestManager.verifyDigest(long, ByteBuf, boolean)	1,263	3,746,733,704	0.697
   
   
   Top allocations outside of TLAB (in 60 sec interval):
   ------------
   Stack Trace	Objects	Total Size(bytes)	Pressure(%)
   bk-shade.com.google.proto_2.6.1.CodedInputStream.readRawBytesSlowPath(int)	161,115	10,544,910,872	6.288
      bk-shade.com.google.proto_2.6.1.CodedInputStream.readBytes()	161,115	10,544,910,872	6.288
         org.apache.bookkeeper.proto.BookkeeperProtocol$ReadResponse.<init>(CodedInputStream, ExtensionRegistryLite)	161,115	10,544,910,872	6.288
   java.util.zip.CRC32.update(ByteBuffer)	114,243	7,599,834,224	4.532
      org.apache.bookkeeper.client.CRC32DigestManager.update(ByteBuf)	114,243	7,599,834,224	4.532
   bk-shade.com.google.proto_2.6.1.ByteString.copyFrom(byte[], int, int)	2,440	929,957,352	0.555
      bk-shade.com.google.proto_2.6.1.ByteString.copyFrom(byte[])	2,440	929,957,352	0.555
         org.apache.bookkeeper.proto.PerChannelBookieClient.addEntry(long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	2,440	929,957,352	0.555
   org.apache.bookkeeper.proto.PerChannelBookieClient.addEntry(long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	2,045	735,510,048	0.439
      org.apache.bookkeeper.proto.BookieClient$2.operationComplete(int, PerChannelBookieClient)	2,045	735,510,048	0.439
         org.apache.bookkeeper.proto.BookieClient$2.operationComplete(int, Object)	2,045	735,510,048	0.439
            org.apache.bookkeeper.proto.PerChannelBookieClient.completeOperation(BookkeeperInternalCallbacks$GenericCallback, int)	2,045	735,510,048	0.439
               org.apache.bookkeeper.proto.PerChannelBookieClient.connectIfNeededAndDoOp(BookkeeperInternalCallbacks$GenericCallback)	2,045	735,510,048	0.439
                  org.apache.bookkeeper.proto.DefaultPerChannelBookieClientPool.obtain(BookkeeperInternalCallbacks$GenericCallback, long)	2,045	735,510,048	0.439
                     org.apache.bookkeeper.proto.BookieClient.addEntry(BookieSocketAddress, long, byte[], long, ByteBuf, BookkeeperInternalCallbacks$WriteCallback, Object, int)	2,045	735,510,048	0.439
                        org.apache.bookkeeper.client.PendingAddOp.sendWriteRequest(int)	2,045	735,510,048	0.439
                           org.apache.bookkeeper.client.PendingAddOp.initiate(ByteBuf)	2,045	735,510,048	0.439
   

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services