You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@pulsar.apache.org by Wesley Peng <we...@pengfamily.de> on 2021/02/01 05:58:16 UTC
CPU consuming question
I deployed a standalone pulsar server on a two cores VPS, which was new installed.
Even there is not any jobs running on pulsar, it still consumes CPU about 15+%.
'top' shows the java process takes it.
Can you help explain this? Thank you.
Regards.
Re: CPU consuming question
Posted by Wesley Peng <we...@pengfamily.de>.
OK let me try.
Thank you @Sijie.
On Wed, Feb 3, 2021, at 1:11 PM, Sijie Guo wrote:
> Ah, I see. I am guessing most of the CPU cycles are burned by the table service.
>
> You can try to disable that feature as it is still under developer preview mode. You can run standalone as `bin/pulsar standalone --no-stream-storage`.
>
> - Sijie
>
>
> On Sun, Jan 31, 2021 at 10:52 PM Wesley Peng <we...@pengfamily.de> wrote:
>> __
>> Can you help check with log output?
>>
>> $ tail -f pulsar-standalone-PresentSpicy-VM.log
>> 14:45:14.281 [main-EventThread] INFO org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT added log segment (logrecs_000000000000000001 : [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]) to cache.
>> 14:45:14.297 [DLM-/stream/storage-OrderedScheduler-1-0] INFO org.apache.distributedlog.BKLogWriteHandler - Deleting ledger [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0] for 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT:<default>
>> 14:45:14.301 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO org.apache.distributedlog.impl.ZKLogSegmentMetadataStore - Delete segment : [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]
>> 14:45:14.331 [main-EventThread] INFO org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/<default>/allocation moved version from -1 to 0.
>> 14:45:14.349 [io-checkpoint-scheduler-OrderedScheduler-1-0] INFO org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksdbCheckpointTask - Delete remote checkpoint 0352d14e-8a42-4453-89ed-1fbf34051b76 from checkpoint store at 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76
>> 14:45:33.435 [pulsar-web-68-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:45:33 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
>> 14:46:03.429 [pulsar-web-68-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:46:03 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 6
>> 14:46:33.441 [pulsar-web-68-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:46:33 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
>> 14:47:03.431 [pulsar-web-68-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:47:03 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 7
>>
>>
>> Thank you
>> Regards.
>>
>>
>> On Mon, Feb 1, 2021, at 2:30 PM, Sijie Guo wrote:
>>> Hi Wesley,
>>>
>>> The CPU usage might be coming from some background tasks. Do you happen to have the log of the standalone server? This might give some insights to the problem.
>>>
>>> - Sijie
>>>
>>> On Sun, Jan 31, 2021 at 9:58 PM Wesley Peng <we...@pengfamily.de> wrote:
>>>> __
>>>> I deployed a standalone pulsar server on a two cores VPS, which was new installed.
>>>> Even there is not any jobs running on pulsar, it still consumes CPU about 15+%.
>>>> 'top' shows the java process takes it.
>>>>
>>>> Can you help explain this? Thank you.
>>>>
>>>> Regards.
>>
Re: CPU consuming question
Posted by Sijie Guo <gu...@gmail.com>.
Ah, I see. I am guessing most of the CPU cycles are burned by the table
service.
You can try to disable that feature as it is still under developer preview
mode. You can run standalone as `bin/pulsar standalone --no-stream-storage`.
- Sijie
On Sun, Jan 31, 2021 at 10:52 PM Wesley Peng <we...@pengfamily.de> wrote:
> Can you help check with log output?
>
> $ tail -f pulsar-standalone-PresentSpicy-VM.log
>
> 14:45:14.281 [main-EventThread] INFO org.apache.distributedlog.logsegment.PerStreamLogSegmentCache
> -
> 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT
> added log segment (logrecs_000000000000000001 : [LogSegmentId:279,
> firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID,
> completionTime:1612161014650, recordCount:1, regionId:0, status:0,
> logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false,
> minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0},
> startSequenceId:0]) to cache.
>
> 14:45:14.297 [DLM-/stream/storage-OrderedScheduler-1-0] INFO org.apache.distributedlog.BKLogWriteHandler
> - Deleting ledger [LogSegmentId:279, firstTxId:16, lastTxId:16,
> version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650,
> recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1,
> lastEntryId:0, lastSlotId:0, inprogress:false,
> minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0},
> startSequenceId:0] for
> 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT:<default>
>
> 14:45:14.301 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO org.apache.distributedlog.impl.ZKLogSegmentMetadataStore
> - Delete segment : [LogSegmentId:279, firstTxId:16, lastTxId:16,
> version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650,
> recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1,
> lastEntryId:0, lastSlotId:0, inprogress:false,
> minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0},
> startSequenceId:0]
>
> 14:45:14.331 [main-EventThread] INFO org.apache.distributedlog.bk.SimpleLedgerAllocator
> - Ledger allocator for
> /stream/storage/000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/<default>/allocation
> moved version from -1 to 0.
>
> 14:45:14.349 [io-checkpoint-scheduler-OrderedScheduler-1-0] INFO org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksdbCheckpointTask
> - Delete remote checkpoint 0352d14e-8a42-4453-89ed-1fbf34051b76 from
> checkpoint store at
> 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76
>
> 14:45:33.435 [pulsar-web-68-5] INFO org.eclipse.jetty.server.RequestLog
> - 127.0.0.1 - - [01/Feb/2021:14:45:33 +0800] "GET
> /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false
> HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
>
> 14:46:03.429 [pulsar-web-68-1] INFO org.eclipse.jetty.server.RequestLog
> - 127.0.0.1 - - [01/Feb/2021:14:46:03 +0800] "GET
> /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false
> HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 6
>
> 14:46:33.441 [pulsar-web-68-6] INFO org.eclipse.jetty.server.RequestLog
> - 127.0.0.1 - - [01/Feb/2021:14:46:33 +0800] "GET
> /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false
> HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
>
> 14:47:03.431 [pulsar-web-68-8] INFO org.eclipse.jetty.server.RequestLog
> - 127.0.0.1 - - [01/Feb/2021:14:47:03 +0800] "GET
> /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false
> HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 7
>
>
> Thank you
> Regards.
>
>
> On Mon, Feb 1, 2021, at 2:30 PM, Sijie Guo wrote:
>
> Hi Wesley,
>
> The CPU usage might be coming from some background tasks. Do you happen to
> have the log of the standalone server? This might give some insights to the
> problem.
>
> - Sijie
>
> On Sun, Jan 31, 2021 at 9:58 PM Wesley Peng <we...@pengfamily.de> wrote:
>
>
> I deployed a standalone pulsar server on a two cores VPS, which was new
> installed.
> Even there is not any jobs running on pulsar, it still consumes CPU about
> 15+%.
> 'top' shows the java process takes it.
>
> Can you help explain this? Thank you.
>
> Regards.
>
>
>
Re: CPU consuming question
Posted by Wesley Peng <we...@pengfamily.de>.
Can you help check with log output?
$ tail -f pulsar-standalone-PresentSpicy-VM.log
14:45:14.281 [main-EventThread] INFO org.apache.distributedlog.logsegment.PerStreamLogSegmentCache - 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT added log segment (logrecs_000000000000000001 : [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]) to cache.
14:45:14.297 [DLM-/stream/storage-OrderedScheduler-1-0] INFO org.apache.distributedlog.BKLogWriteHandler - Deleting ledger [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0] for 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/CURRENT:<default>
14:45:14.301 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO org.apache.distributedlog.impl.ZKLogSegmentMetadataStore - Delete segment : [LogSegmentId:279, firstTxId:16, lastTxId:16, version:VERSION_V5_SEQUENCE_ID, completionTime:1612161014650, recordCount:1, regionId:0, status:0, logSegmentSequenceNumber:1, lastEntryId:0, lastSlotId:0, inprogress:false, minActiveDLSN:DLSN{logSegmentSequenceNo=1, entryId=0, slotId=0}, startSequenceId:0]
14:45:14.331 [main-EventThread] INFO org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator for /stream/storage/000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76/<default>/allocation moved version from -1 to 0.
14:45:14.349 [io-checkpoint-scheduler-OrderedScheduler-1-0] INFO org.apache.bookkeeper.statelib.impl.rocksdb.checkpoint.RocksdbCheckpointTask - Delete remote checkpoint 0352d14e-8a42-4453-89ed-1fbf34051b76 from checkpoint store at 000000000000000001/000000000000000001/000000000000000000/checkpoints/0352d14e-8a42-4453-89ed-1fbf34051b76
14:45:33.435 [pulsar-web-68-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:45:33 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
14:46:03.429 [pulsar-web-68-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:46:03 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 6
14:46:33.441 [pulsar-web-68-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:46:33 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 10
14:47:03.431 [pulsar-web-68-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [01/Feb/2021:14:47:03 +0800] "GET /admin/v2/persistent/public/functions/coordinate/stats?getPreciseBacklog=false HTTP/1.1" 200 1401 "-" "Pulsar-Java-v2.7.0" 7
Thank you
Regards.
On Mon, Feb 1, 2021, at 2:30 PM, Sijie Guo wrote:
> Hi Wesley,
>
> The CPU usage might be coming from some background tasks. Do you happen to have the log of the standalone server? This might give some insights to the problem.
>
> - Sijie
>
> On Sun, Jan 31, 2021 at 9:58 PM Wesley Peng <we...@pengfamily.de> wrote:
>> __
>> I deployed a standalone pulsar server on a two cores VPS, which was new installed.
>> Even there is not any jobs running on pulsar, it still consumes CPU about 15+%.
>> 'top' shows the java process takes it.
>>
>> Can you help explain this? Thank you.
>>
>> Regards.
Re: CPU consuming question
Posted by Sijie Guo <gu...@gmail.com>.
Hi Wesley,
The CPU usage might be coming from some background tasks. Do you happen to
have the log of the standalone server? This might give some insights to the
problem.
- Sijie
On Sun, Jan 31, 2021 at 9:58 PM Wesley Peng <we...@pengfamily.de> wrote:
> I deployed a standalone pulsar server on a two cores VPS, which was new
> installed.
> Even there is not any jobs running on pulsar, it still consumes CPU about
> 15+%.
> 'top' shows the java process takes it.
>
> Can you help explain this? Thank you.
>
> Regards.
>