You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@thrift.apache.org by "joecqupt (Jira)" <ji...@apache.org> on 2022/02/15 13:34:00 UTC
[jira] [Commented] (THRIFT-5494) byte count of FrameBuffer(AbstractNonblockingServer.readBufferBytesAllocated) is not subtracted
[ https://issues.apache.org/jira/browse/THRIFT-5494?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17492613#comment-17492613 ]
joecqupt commented on THRIFT-5494:
----------------------------------
libthrift allocate buffer(size of frame size + 4) after read frame size and increase value of readBufferBytesAllocated. it will keep until connection closed or response ready.
as you said: What may be the reason why the readbufferbytesallocated has not decreased?
1. it is reading frame data
2. response not ready
> byte count of FrameBuffer(AbstractNonblockingServer.readBufferBytesAllocated) is not subtracted
> -----------------------------------------------------------------------------------------------
>
> Key: THRIFT-5494
> URL: https://issues.apache.org/jira/browse/THRIFT-5494
> Project: Thrift
> Issue Type: Bug
> Components: Java - Library
> Affects Versions: 0.9.1
> Reporter: shanzhongkai
> Priority: Major
>
> AbstractNonblockingServer.readbufferbytesallocated is used to indicate “How many bytes are currently allocated to read buffers.”, however, we find that readbufferbytesallocated does not decrease as expected in rare cases. we added the following logs in FrameBuffer.read:
> {code:java}
> // if this frame will push us over the memory limit, then return.
> // with luck, more memory will free up the next time around.
> LOGGER.info("print readBufferBytesAllocated: {}, {}", readBufferBytesAllocated.get(), frameSize);
> if (readBufferBytesAllocated.get() + frameSize > MAX_READ_BUFFER_BYTES) {
> return true;
> } {code}
> and we found:
> {panel}
> 2022-01-04,11:30:06,795 \{Thread-104} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:06,795 \{Thread-106} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 144
> 2022-01-04,11:30:06,795 \{Thread-107} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 51315
> 2022-01-04,11:30:06,795 \{Thread-118} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:06,795 \{Thread-121} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:06,795 \{Thread-124} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 360495
> 2022-01-04,11:30:06,795 \{Thread-107} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141441140, 140
> 2022-01-04,11:30:06,807 \{Thread-114} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 257970
> 2022-01-04,11:30:06,823 \{Thread-112} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 139
> 2022-01-04,11:30:06,839 \{Thread-110} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 30308
> 2022-01-04,11:30:06,843 \{Thread-110} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 34608
> 2022-01-04,11:30:06,868 \{Thread-120} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 162
> 2022-01-04,11:30:06,872 \{Thread-107} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 144
> 2022-01-04,11:30:06,879 \{Thread-125} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 279360
> 2022-01-04,11:30:06,918 \{Thread-106} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 118
> 2022-01-04,11:30:06,924 \{Thread-104} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 158
> 2022-01-04,11:30:06,971 \{Thread-115} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 36964
> 2022-01-04,11:30:06,974 \{Thread-115} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 129
> 2022-01-04,11:30:07,033 \{Thread-121} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,036 \{Thread-112} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 26714
> 2022-01-04,11:30:07,038 \{Thread-121} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,074 \{Thread-107} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 33878
> 2022-01-04,11:30:07,079 \{Thread-120} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 162
> 2022-01-04,11:30:07,113 \{Thread-122} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,149 \{Thread-108} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 26607
> 2022-01-04,11:30:07,192 \{Thread-110} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 31055
> 2022-01-04,11:30:07,244 \{Thread-114} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 166
> 2022-01-04,11:30:07,260 \{Thread-121} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,288 \{Thread-106} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 108
> 2022-01-04,11:30:07,417 \{Thread-124} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,441 \{Thread-110} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:07,469 \{Thread-115} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 35387
> 2022-01-04,11:30:07,571 \{Thread-121} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,571 \{Thread-122} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 131
> 2022-01-04,11:30:07,571 \{Thread-105} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,571 \{Thread-102} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 143
> 2022-01-04,11:30:07,571 \{Thread-117} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 125
> 2022-01-04,11:30:07,615 \{Thread-114} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 885819
> 2022-01-04,11:30:07,623 \{Thread-116} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141914545, 36155
> 2022-01-04,11:30:07,624 \{Thread-112} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141914545, 16293
> 2022-01-04,11:30:07,636 \{Thread-107} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 1119
> 2022-01-04,11:30:07,683 \{Thread-106} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 131
> 2022-01-04,11:30:07,686 \{Thread-123} [INFO] libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print readBufferBytesAllocated: 141028722, 7875
> {panel}
> It seems that readbufferbytesallocated has not decreased as expected. The ultimate performance of this problem is that the CPU is getting higher and higher, because the cache is less and less, the incoming large requests cannot allocate the cache, resulting in the large requests falling into an endless loop.
>
> [https://issues.apache.org/jira/projects/THRIFT/issues/THRIFT-5468?filter=allopenissues]
> The problem in this link is different from ours, because this problem has been fixed in 0.9.1. What may be the reason why the readbufferbytesallocated has not decreased?
--
This message was sent by Atlassian Jira
(v8.20.1#820001)