1

I made a load test for rocketmq, then I found a lot of long call,the long call cost much more then 100ms.But I read the source code of the long call,the main cost is the writing of bytebuffer. The core code like this:

public AppendMessageResult doAppend(final long fileFromOffset,
     final ByteBuffer byteBuffer, final int maxBlank, 
     final MessageExtBrokerInner msgInner) {//from CommitLog.java
    ...
    final long beginTimeMills = CommitLog.this.defaultMessageStore.now();
    byteBuffer.put(this.msgStoreItemMemory.array(), 0, msgLen);

    AppendMessageResult result = new AppendMessageResult(AppendMessageStatus.PUT_OK, wroteOffset, msgLen, msgId,
        msgInner.getStoreTimestamp(), queueOffset, CommitLog.this.defaultMessageStore.now() - beginTimeMills);
    return result;
}

The log show the CommitLog.this.defaultMessageStore.now() - beginTimeMills(pagecacheRT in the log below) cost more than 100ms.

2018-04-09 00:24:41 WARN SendMessageThread_1 - [NOTIFYME]putMessage in lock cost time(ms)=517 nano time(ms)=516, bodyLength=130 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3113603972920, wroteBytes=128, msgId='0A0C240300002A9F000002D4F1423F38', storeTimestamp=1523204680621, logicsOffset=11016755, pagecacheRT=517, msgNum=1}

The pagecacheRT is the put operation time cost.Then I saw the byteBuffer initialize code, like this:

public void init() {
        for (int i = 0; i < poolSize; i++) {
            ByteBuffer byteBuffer = ByteBuffer.allocateDirect(fileSize);

            final long address = ((DirectBuffer) byteBuffer).address();
            Pointer pointer = new Pointer(address);
            LibC.INSTANCE.mlock(pointer, new NativeLong(fileSize));

            availableBuffers.offer(byteBuffer);
        }
    }

The bytebuffer just is a directBuffer. My test environment is a pyhsical machine with 32 processor and 96G memory,And write bytes is 125byte pre write. I saw the monitor during the load test, the CPU and disk is very healthy.I don't think this problem is casued by the implements of rocketmq.Because the main code is very simple,just is the above section code.

But I cannot understand why a writing of memory can cost so much time.Is there any way to understanding these or something?

Thanks in advance!

yuzhou.li
  • 31
  • 3
  • It's not a lot to go on, such as the rest of your code –it's not an [MCVE](https://stackoverflow.com/help/mcve)– or the number of bytes you're writing. And what does "32C96G" mean? – SeverityOne Apr 08 '18 at 09:15
  • sorry,this is my first question on stackoverflow. "32C96G" means the number of cpu processor is 32,and the physical memory is 96G. Let me complete the code – yuzhou.li Apr 08 '18 at 16:07
  • I don't know RocketMQ, but I do know networks. Are you talking across the internet to a server somewhere? In that case 100ms latencies are perfectly normal. – Thomas Apr 08 '18 at 16:39
  • No,just write the bytes into the memory without any other operation – yuzhou.li Apr 08 '18 at 16:40
  • You mean `byteBuffer.put(this.msgStoreItemMemory.array(), 0, msgLen);` It looks like you are converting to an array and then copying from the array. Why not covert to an array and then use ByteBuffer::wrap? – K.Nicholas Apr 08 '18 at 19:12
  • I know what you mean.But this buffer also add many other metadata like offset, message size before this operation.Although I'm agree with your opinion, I want to know why this operation cost so much. – yuzhou.li Apr 09 '18 at 08:47

0 Answers0