g0715158 commented on issue #23805:
URL: https://github.com/apache/pulsar/issues/23805#issuecomment-2574221430
> > ### Minimal reproduce step
> > When I query the dead-letter queue information in Pulsar Manager, the
broker's GC grows rapidly. The same happens when I use admin commands.
>
> @g0715158 Please share the admin commands to reproduce the issue.
@lhotari
The following API is causing a rapid increase in GC (Garbage Collection)
time.
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-16/stats?getPreciseBacklog=false&authoritative=false&subscriptionBacklogSize=true&getEarliestTimeInBacklog=false
This phenomenon of GC time increase is particularly noticeable:
1、Not all DLQ topics lead to a significant increase in GC time. Currently,
out of all the topics in the cluster, only 2 DLQ topics are experiencing this
issue.
2、Through the logs, it was found that when there is a significant increase
in GC time, the API being called is handled by the
ForkJoinPool.commonPool-worker-2267 thread.
Partial log as follows:
2025-01-03T09:54:12,851+0800 [BookKeeperClientWorker-OrderedExecutor-43-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[pulsar/ims/persistent/17_rate_out-partition-13] Created new ledger 10720342
2025-01-03T09:54:13,911+0800
[bookkeeper-ml-scheduler-OrderedScheduler-104-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[pulsar/ims/persistent/17_rate_out-partition-13] End TrimConsumedLedgers.
ledgers=1 totalSize=194152
2025-01-03T09:54:13,911+0800
[bookkeeper-ml-scheduler-OrderedScheduler-104-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[pulsar/ims/persistent/17_rate_out-partition-13] Removing ledger 10718720 -
size: 58916963
2025-01-03T09:54:14,715+0800 [pulsar-io-4-4] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -9, ackedMessages
: -3, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/gprs/11_rate_out_b-partition-5,
name=housekeeping_session}, consumerId=1025, consumerName=6bfaa,
address=/10.33.234.38:27173}
2025-01-03T09:54:14,799+0800 [pulsar-web-37-85] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/autoftp/0x2eeeeeec_0x33333330?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:14,829+0800 [pulsar-web-37-5] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0x91111108_0x9555554c?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 3
2025-01-03T09:54:14,830+0800 [pulsar-web-37-70] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0xd999998c_0xddddddd0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:14,830+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0x9dddddd4_0xa2222218?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:14,839+0800 [pulsar-web-37-9] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0x7ffffff8_0x8444443c?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:14,839+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0xe2222214_0xe6666658?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:14,840+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0xb777776c_0xbbbbbbb0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:14,895+0800 [ForkJoinPool.commonPool-worker-2267] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-16/stats?getPreciseBacklog=false&authoritative=false&subscriptionBacklogSize=true&getEarliestTimeInBacklog=false
HTTP/1.1" 200 8071538 "-" "Pulsar-Java-v3.0.1" 100
2025-01-03T09:54:14,895+0800 [ForkJoinPool.commonPool-worker-2250] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:14
+0800] "GET
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-12/stats?getPreciseBacklog=false&authoritative=false&subscriptionBacklogSize=true&getEarliestTimeInBacklog=false
HTTP/1.1" 200 8071520 "-" "Pulsar-Java-v3.0.1" 100
2025-01-03T09:54:15,188+0800 [pulsar-web-37-141] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:15
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0x88888880_0x8cccccc4?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:15,191+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:15
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0xaaaaaaa0_0xaeeeeee4?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:15,191+0800 [pulsar-web-37-236] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:15
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0xeaaaaa9c_0xeeeeeee0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:17,132+0800 [pulsar-io-4-33] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -1, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/gprs/21_rate_out_b-partition-4,
name=housekeeping_session}, consumerId=664, consumerName=9b30a,
address=/10.33.234.138:16505}
2025-01-03T09:54:18,798+0800 [pulsar-io-4-95] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -8, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/ims/20_rate_in-partition-4,
name=controlNode-20}, consumerId=444, consumerName=ab1f8,
address=/10.33.235.42:22679}
2025-01-03T09:54:19,295+0800 [pulsar-io-4-100] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -6, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/ims/20_rate_in-partition-4,
name=controlNode-20}, consumerId=524, consumerName=68e10,
address=/10.33.235.55:26249}
2025-01-03T09:54:19,900+0800 [pulsar-io-4-100] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -73, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/ims/20_rate_in-partition-4,
name=controlNode-20}, consumerId=504, consumerName=a6fc2,
address=/10.33.235.55:26249}
2025-01-03T09:54:20,436+0800 [pulsar-io-4-18] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -1, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/gprs/21_rate_out_b-partition-4,
name=housekeeping_session}, consumerId=1004, consumerName=b5cae,
address=/10.33.234.51:62346}
2025-01-03T09:54:20,909+0800 [pulsar-io-4-100] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -100, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/ims/20_rate_in-partition-4,
name=controlNode-20}, consumerId=584, consumerName=2b966,
address=/10.33.235.55:26249}
2025-01-03T09:54:21,022+0800 [pulsar-io-4-95] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -1, ackedMessages
: -100, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/ims/20_rate_in-partition-4,
name=controlNode-20}, consumerId=484, consumerName=c0491,
address=/10.33.235.42:22679}
2025-01-03T09:54:21,901+0800 [pulsar-io-4-42] WARN
org.apache.pulsar.broker.service.Consumer - unackedMsgs is : -4, ackedMessages
: -1, consumer :
Consumer{subscription=PersistentSubscription{topic=persistent://pulsar/gprs/21_rate_out_b-partition-4,
name=housekeeping_session}, consumerId=784, consumerName=36628,
address=/10.33.234.158:24326}
2025-01-03T09:54:23,749+0800 [pulsar-web-37-19] INFO
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase -
[null][persistent://pulsar/iagw/housekeeping_session-DLQ-partition-12] Creating
subscription test at message id 9223372036854775807:9223372036854775807:-1 with
properties null
2025-01-03T09:54:23,749+0800 [pulsar-web-37-141] INFO
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase -
[null][persistent://pulsar/iagw/housekeeping_session-DLQ-partition-16] Creating
subscription test at message id 9223372036854775807:9223372036854775807:-1 with
properties null
2025-01-03T09:54:23,752+0800 [pulsar-web-37-141] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:23
+0800] "PUT
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-16/subscription/test?authoritative=false&replicated=false
HTTP/1.1" 409 50 "-" "Pulsar-Java-v3.0.1" 3
2025-01-03T09:54:23,752+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:23
+0800] "PUT
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-12/subscription/test?authoritative=false&replicated=false
HTTP/1.1" 409 50 "-" "Pulsar-Java-v3.0.1" 4
2025-01-03T09:54:27,991+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:27
+0800] "GET
/admin/v2/non-persistent/pulsar/autoftp/0x2eeeeeec_0x33333330?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:27,996+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:27
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0x91111108_0x9555554c?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:27,999+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:27
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0xd999998c_0xddddddd0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:28,004+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/iagw/0x9dddddd4_0xa2222218?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:28,008+0800 [pulsar-web-37-9] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0xe2222214_0xe6666658?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:28,010+0800 [pulsar-web-37-70] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0x7ffffff8_0x8444443c?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:28,010+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/fx/0xb777776c_0xbbbbbbb0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:28,103+0800 [ForkJoinPool.commonPool-worker-2267] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-12/stats?getPreciseBacklog=false&authoritative=false&subscriptionBacklogSize=true&getEarliestTimeInBacklog=false
HTTP/1.1" 200 8071520 "-" "Pulsar-Java-v3.0.1" 99
2025-01-03T09:54:28,110+0800 [ForkJoinPool.commonPool-worker-2250] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/persistent/pulsar/iagw/housekeeping_session-DLQ-partition-16/stats?getPreciseBacklog=false&authoritative=false&subscriptionBacklogSize=true&getEarliestTimeInBacklog=false
HTTP/1.1" 200 8071538 "-" "Pulsar-Java-v3.0.1" 105
2025-01-03T09:54:28,297+0800 [pulsar-web-37-236] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0x88888880_0x8cccccc4?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 2
2025-01-03T09:54:28,300+0800 [pulsar-web-37-140] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0xaaaaaaa0_0xaeeeeee4?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
2025-01-03T09:54:28,301+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - xx.xx.xx.xx - - [03/Jan/2025:09:54:28
+0800] "GET
/admin/v2/non-persistent/pulsar/gprs/0xeaaaaa9c_0xeeeeeee0?authoritative=false
HTTP/1.1" 200 2 "-" "Pulsar-Java-v3.0.1" 1
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
