You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@thrift.apache.org by "Jens Geyer (Jira)" <ji...@apache.org> on 2022/03/06 11:37:00 UTC
[jira] [Resolved] (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:all-tabpanel ]
Jens Geyer resolved THRIFT-5494.
--------------------------------
Fix Version/s: 0.17.0
Resolution: Fixed
> 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
> Assignee: wangfan
> Priority: Major
> Fix For: 0.17.0
>
> Attachments: image-2022-02-24-11-31-50-880.png, image-2022-02-24-11-40-14-321.png, image-2022-02-24-11-45-24-002.png, image-2022-02-24-11-49-57-579.png
>
> Time Spent: 4h 20m
> Remaining Estimate: 0h
>
> 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)