Question About [NOTIFYME]putMessage in lock cost time(ms)=4052 #721

sN0wpeak · 2019-01-25T08:11:20Z

Question

I have used rocketmq in production env. There is some WARN in broker log when user send message to broker. Caused the message to fail to be sent. It looks like it is blocked when it is written to the page cache.

Please give me some suggestions to improve this issue. Thank you.

In our application scenario, we use much delay message than realtime message. These exceptions occur whenever we consume a lot of delayed messages. Is this related?

ENV:

Tencent cloud linux
8 CPU. 48G MEM. SSD disk
I have run broker after run os.sh. I can't set io scheduler to DEADLINE, because machine of cloud not support. default is none
broker.conf

fileReservedTime = 48
flushDiskType = ASYNC_FLUSH
sendMessageThreadPoolNums=48
messageDelayLevel=1s 5s 10s 30s 1m 2m 3m 4m 5m 6m 7m 8m 9m 10m 20m 30m 1h 2h 4h 6h 12h 1d 3h 5h 7h 8h 9h 10h 11h 13h 14h 15h 16h 17h 18h 19h 20h 21h 22h 23h 40m 50m
waitTimeMillsInSendQueue=2000
sendThreadPoolQueueCapacity=50000

JAVAOPTS is default
TPS is less than 2000

Some log

2019-01-22 11:03:02 WARN SendMessageThread_19 - [NOTIFYME]putMessage in lock cost time(ms)=4127, bodyLength=410 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3551463997150, wroteBytes=792, msgId='0A01003100002A9F0000033AE3BFFEDE', storeTimestamp=1548126178835, logicsOffset=422117414, pagecacheRT=4127, msgNum=1}

2019-01-22 11:03:02 WARN SendMessageThread_22 - putMessage not in lock eclipse time(ms)=4034, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_25 - putMessage not in lock eclipse time(ms)=4128, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_44 - putMessage not in lock eclipse time(ms)=4061, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_36 - putMessage not in lock eclipse time(ms)=4057, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_40 - putMessage not in lock eclipse time(ms)=4103, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_21 - putMessage not in lock eclipse time(ms)=4127, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_20 - putMessage not in lock eclipse time(ms)=4081, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_16 - putMessage not in lock eclipse time(ms)=4127, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_30 - putMessage not in lock eclipse time(ms)=4093, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_35 - putMessage not in lock eclipse time(ms)=4067, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_13 - putMessage not in lock eclipse time(ms)=4136, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_37 - putMessage not in lock eclipse time(ms)=3939, bodyLength=9
2019-01-22 11:03:02 WARN SendMessageThread_26 - putMessage not in lock eclipse time(ms)=4034, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_42 - putMessage not in lock eclipse time(ms)=4082, bodyLength=397
2019-01-22 11:03:02 WARN SendMessageThread_39 - putMessage not in lock eclipse time(ms)=4127, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_46 - putMessage not in lock eclipse time(ms)=4012, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_14 - putMessage not in lock eclipse time(ms)=4056, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_6 - putMessage not in lock eclipse time(ms)=4001, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_11 - putMessage not in lock eclipse time(ms)=4138, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_32 - putMessage not in lock eclipse time(ms)=4092, bodyLength=367
2019-01-22 11:03:02 WARN SendMessageThread_4 - putMessage not in lock eclipse time(ms)=4123, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_29 - putMessage not in lock eclipse time(ms)=4138, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_1 - putMessage not in lock eclipse time(ms)=4102, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_10 - putMessage not in lock eclipse time(ms)=4087, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_12 - putMessage not in lock eclipse time(ms)=4080, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_3 - putMessage not in lock eclipse time(ms)=4081, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_33 - putMessage not in lock eclipse time(ms)=4103, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_27 - putMessage not in lock eclipse time(ms)=3980, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_43 - putMessage not in lock eclipse time(ms)=3951, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_41 - putMessage not in lock eclipse time(ms)=4046, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_38 - putMessage not in lock eclipse time(ms)=3991, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_18 - putMessage not in lock eclipse time(ms)=4083, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_2 - putMessage not in lock eclipse time(ms)=4122, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_7 - putMessage not in lock eclipse time(ms)=4120, bodyLength=367
2019-01-22 11:03:02 WARN SendMessageThread_15 - putMessage not in lock eclipse time(ms)=3980, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_34 - putMessage not in lock eclipse time(ms)=4122, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_8 - putMessage not in lock eclipse time(ms)=4077, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_28 - putMessage not in lock eclipse time(ms)=4074, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_17 - putMessage not in lock eclipse time(ms)=4024, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_31 - putMessage not in lock eclipse time(ms)=3962, bodyLength=410
2019-01-22 11:03:02 WARN ScheduleMessageTimerThread - putMessage not in lock eclipse time(ms)=4128, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_47 - putMessage not in lock eclipse time(ms)=4127, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_48 - putMessage not in lock eclipse time(ms)=4083, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_45 - putMessage not in lock eclipse time(ms)=4113, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_24 - putMessage not in lock eclipse time(ms)=3951, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_19 - putMessage not in lock eclipse time(ms)=4128, bodyLength=410
2019-01-22 11:03:02 WARN SendMessageThread_9 - putMessage not in lock eclipse time(ms)=3969, bodyLength=411
2019-01-22 11:03:02 WARN SendMessageThread_5 - putMessage not in lock eclipse time(ms)=4093, bodyLength=422
2019-01-22 11:03:02 WARN SendMessageThread_23 - putMessage not in lock eclipse time(ms)=3928, bodyLength=8


2019-01-25 12:24:07 WARN SendMessageThread_21 - putMessage not in lock eclipse time(ms)=537, bodyLength=206
2019-01-25 12:24:07 WARN SendMessageThread_5 - putMessage not in lock eclipse time(ms)=509, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_28 - putMessage not in lock eclipse time(ms)=656, bodyLength=221
2019-01-25 12:24:07 WARN SendMessageThread_35 - putMessage not in lock eclipse time(ms)=602, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_10 - putMessage not in lock eclipse time(ms)=685, bodyLength=438
2019-01-25 12:24:07 WARN SendMessageThread_14 - putMessage not in lock eclipse time(ms)=597, bodyLength=523
2019-01-25 12:24:07 WARN SendMessageThread_44 - putMessage not in lock eclipse time(ms)=719, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_16 - putMessage not in lock eclipse time(ms)=509, bodyLength=200
2019-01-25 12:24:07 WARN SendMessageThread_13 - putMessage not in lock eclipse time(ms)=603, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_9 - putMessage not in lock eclipse time(ms)=587, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_18 - putMessage not in lock eclipse time(ms)=521, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_23 - putMessage not in lock eclipse time(ms)=507, bodyLength=49
2019-01-25 12:24:07 WARN SendMessageThread_31 - putMessage not in lock eclipse time(ms)=546, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_32 - putMessage not in lock eclipse time(ms)=627, bodyLength=115
2019-01-25 12:24:07 WARN ScheduleMessageTimerThread - putMessage not in lock eclipse time(ms)=722, bodyLength=273
2019-01-25 12:24:07 WARN SendMessageThread_12 - putMessage not in lock eclipse time(ms)=714, bodyLength=566
2019-01-25 12:24:07 WARN SendMessageThread_41 - putMessage not in lock eclipse time(ms)=732, bodyLength=338
2019-01-25 12:24:07 WARN SendMessageThread_1 - putMessage not in lock eclipse time(ms)=563, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_15 - putMessage not in lock eclipse time(ms)=707, bodyLength=201
2019-01-25 12:24:07 WARN SendMessageThread_40 - putMessage not in lock eclipse time(ms)=563, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_2 - putMessage not in lock eclipse time(ms)=603, bodyLength=238
2019-01-25 12:24:07 WARN SendMessageThread_17 - putMessage not in lock eclipse time(ms)=530, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_8 - putMessage not in lock eclipse time(ms)=736, bodyLength=408
2019-01-25 12:24:07 WARN SendMessageThread_11 - putMessage not in lock eclipse time(ms)=533, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_20 - putMessage not in lock eclipse time(ms)=688, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_29 - putMessage not in lock eclipse time(ms)=741, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_3 - putMessage not in lock eclipse time(ms)=508, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_7 - putMessage not in lock eclipse time(ms)=707, bodyLength=74
2019-01-25 12:24:07 WARN SendMessageThread_46 - putMessage not in lock eclipse time(ms)=688, bodyLength=259
2019-01-25 12:24:07 WARN SendMessageThread_30 - putMessage not in lock eclipse time(ms)=680, bodyLength=229
2019-01-25 12:24:07 WARN SendMessageThread_36 - putMessage not in lock eclipse time(ms)=659, bodyLength=228
2019-01-25 12:24:07 WARN SendMessageThread_34 - putMessage not in lock eclipse time(ms)=551, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_39 - putMessage not in lock eclipse time(ms)=664, bodyLength=100
2019-01-25 12:24:07 WARN SendMessageThread_4 - putMessage not in lock eclipse time(ms)=749, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_33 - [NOTIFYME]putMessage in lock cost time(ms)=723, bodyLength=99 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3637677915929, wroteBytes=398, msgId='0A01003100002A9F0000034EF67FFF19', storeTimestamp=1548390246329, logicsOffset=3777623, pagecacheRT=723, msgNum=1}
2019-01-25 12:24:07 WARN SendMessageThread_33 - putMessage not in lock eclipse time(ms)=768, bodyLength=99
2019-01-25 12:24:07 WARN SendMessageThread_42 - putMessage not in lock eclipse time(ms)=645, bodyLength=110
2019-01-25 12:24:07 WARN SendMessageThread_6 - putMessage not in lock eclipse time(ms)=580, bodyLength=200
2019-01-25 12:24:07 WARN SendMessageThread_43 - putMessage not in lock eclipse time(ms)=520, bodyLength=74
2019-01-25 12:24:07 WARN SendMessageThread_37 - putMessage not in lock eclipse time(ms)=617, bodyLength=74
2019-01-25 12:24:07 WARN SendMessageThread_27 - putMessage not in lock eclipse time(ms)=685, bodyLength=100
2019-01-25 12:24:07 WARN SendMessageThread_47 - putMessage not in lock eclipse time(ms)=627, bodyLength=559
2019-01-25 12:24:07 WARN SendMessageThread_25 - putMessage not in lock eclipse time(ms)=718, bodyLength=279
2019-01-25 12:24:07 WARN SendMessageThread_45 - putMessage not in lock eclipse time(ms)=559, bodyLength=425
2019-01-25 12:24:07 WARN SendMessageThread_26 - putMessage not in lock eclipse time(ms)=692, bodyLength=115
2019-01-25 12:24:07 WARN SendMessageThread_22 - putMessage not in lock eclipse time(ms)=602, bodyLength=446

Jan 25
sar -B 
09时00分01秒  pgpgin/s pgpgout/s   fault/s  majflt/s  pgfree/s pgscank/s pgscand/s pgsteal/s    %vmeff
09时10分01秒     53.90   2150.23    603.07      0.05   6046.29    108.76      0.00    104.54     96.12
09时20分01秒     68.76   2037.86    597.67      0.06   6079.41    135.21      0.00    127.00     93.93
09时30分01秒     41.85   1953.13    593.96      0.04   5986.48     41.96      0.00     38.02     90.60
09时40分01秒    218.06   1910.26    591.13      0.14   6039.40    176.76      0.00    162.66     92.02
09时50分01秒    259.03   2130.62    597.69      0.14   6020.30    174.67      0.00    153.54     87.90
10时00分01秒     12.83   1944.46    587.39      0.02   6002.22     75.59      0.00     67.29     89.01
10时10分01秒    334.58   2678.21    651.55      0.17   6597.55    198.01      0.00    184.85     93.36
10时20分01秒     65.39   2727.90    649.05      0.05   6533.37    143.67      0.00    133.15     92.67
10时30分01秒     71.57   2843.67    649.52      0.05   6519.89    148.09      0.00    131.89     89.07
10时40分01秒    598.96   2456.35    618.90      0.27   6377.77    271.93      0.00    238.88     87.85
10时50分01秒    681.50   3493.50    708.71      0.32   7013.90    328.37      0.00    286.70     87.31
11时00分01秒   2133.78   5041.79   1115.00      1.54  10959.66   1752.14      0.00   1504.10     85.84
11时10分01秒    710.04   4035.66    780.01      0.29  11366.08    687.29      0.00    423.10     61.56
11时20分01秒    222.00   1665.62    572.50      0.11  10287.25    158.53      0.00     99.28     62.63
11时30分01秒    189.29   1588.65    571.60      0.10  23648.61    146.99      0.00     95.86     65.22
11时40分01秒    223.05   1519.33    570.70      0.15   6894.66    293.27      0.00    115.52     39.39
11时50分01秒    235.13   1918.83    571.58      0.16   6124.60    459.42      0.00    159.91     34.81
12时00分01秒    199.34   1768.49    588.22      0.15   8396.45    153.84      0.00     72.71     47.26
12时10分01秒   1004.09   1763.49    693.69      0.46   8764.61    930.06      4.40    377.07     40.35
12时20分01秒    961.36   1533.94    580.84      0.43   8560.14    780.52      0.00    321.29     41.16
12时30分01秒   1014.18   1687.05    576.44      0.49   8590.14    457.40      1.61    270.16     58.86
12时40分01秒    993.98   1601.02    571.71      0.46   8627.73    474.87      0.00    289.02     60.86
12时50分01秒    636.37   1550.81    565.83      0.34   8576.74    243.91      0.00    239.92     98.37
13时00分01秒    256.55   1513.39    564.31      0.21   8460.28    154.36      0.00    149.51     96.85
13时10分01秒    523.77   3249.68    716.50      0.28  11102.90    285.32      0.00    278.41     97.58
13时20分01秒    750.04   3301.08    726.68      0.35  11199.65    308.59      0.00    303.10     98.22
13时30分01秒    744.75   3240.18    678.40      0.36  10701.32    418.28      0.00    299.91     71.70
13时40分01秒    969.07   2451.22    629.35      0.44  10050.09    487.96      0.00    357.73     73.31
13时50分01秒    592.18   2429.16    629.88      0.31   9914.20    442.84      0.00    290.90     65.69
14时00分01秒    448.55   1771.07    585.40      0.27   8824.74    139.92      0.00    118.98     85.03
14时10分01秒    657.93   1832.27    634.43      0.39   8736.66    295.38      0.00    248.61     84.17
平均时间:    907.71   1684.08    619.83      0.41   6832.66    409.30      0.10    316.49     77.31

The text was updated successfully, but these errors were encountered:

sN0wpeak · 2019-01-25T08:13:24Z

rocketmq version is 4.3.0

duhenglucky · 2019-01-25T11:18:10Z

@mm23504570 As you described in this issue, you deployed the RocketMQ broker in a 8 core cpu server, but as the log showed, there are more than 48 sendMessageThread in config, and as RocketMQ used spinlock as default, so you can try to adjust the sendMessageThread num to 8 to prevent more thread was blocked to obtain the spinlock, and this also will decrease you cpu utility.

And please pay more attention to your memory usage especially cache usage, please reserve relative more free memory for RocketMQ.

sN0wpeak · 2019-01-25T13:51:13Z

@duhenglucky Thank you. I will set sendMessageThread to 8 to test it.
You mean reserve relative more free memory for rocketmq.
Is this done to keep the messages being consumed in the page cache as much as possible and avoid the IO blocking caused by a lot of page steal?

icersummer · 2019-01-28T10:33:24Z

I met the same issue this morning, haven't got a solution for it. The issue is not reproducable for now. But it may occur after.

I'm running RMQ in a 2 core cpu server. And I've changed the default spinlock to reentrantLock.

sendMessageThreadPoolNums=128
useReentrantLockWhenPutMessage=true
waitTimeMillsInSendQueue=1000
defaultTopicQueueNums=16

sN0wpeak · 2019-01-28T14:07:12Z

After I changed the conf , the problem still exists.

2019-01-28 21:22:04 WARN SendMessageThread_8 - putMessage not in lock eclipse time(ms)=3019, bodyLength=520
2019-01-28 21:22:04 WARN SendMessageThread_3 - putMessage not in lock eclipse time(ms)=3023, bodyLength=70
2019-01-28 21:22:04 WARN SendMessageThread_7 - putMessage not in lock eclipse time(ms)=3019, bodyLength=115
2019-01-28 21:22:04 WARN ScheduleMessageTimerThread - putMessage not in lock eclipse time(ms)=3021, bodyLength=100
2019-01-28 21:22:04 WARN SendMessageThread_6 - putMessage not in lock eclipse time(ms)=3025, bodyLength=111
2019-01-28 21:22:04 WARN SendMessageThread_2 - putMessage not in lock eclipse time(ms)=3023, bodyLength=70
2019-01-28 21:22:04 WARN SendMessageThread_5 - putMessage not in lock eclipse time(ms)=3018, bodyLength=69
2019-01-28 21:22:04 WARN SendMessageThread_4 - [NOTIFYME]putMessage in lock cost time(ms)=3024, bodyLength=100 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3972957994955, wroteBytes=559, msgId='0A01002B00002A9F0000039D06BFFFCB', storeTimestamp=1548681721361, logicsOffset=261429845, pagecacheRT=3024, msgNum=1}
2019-01-28 21:22:04 WARN SendMessageThread_4 - putMessage not in lock eclipse time(ms)=3025, bodyLength=100
2019-01-28 21:22:04 WARN SendMessageThread_1 - putMessage not in lock eclipse time(ms)=3011, bodyLength=173

36G cache

free -m
              total        used        free      shared  buff/cache   available
Mem:          48139       11522         295         309       36321       35817
Swap:             0           0           0

gaoyf · 2019-01-29T02:40:32Z

我遇到了类似的问题，参考如下：

我参考服务器配置把broker配置修改了如下几项，就好了：

sendMessageThreadPoolNums=48
useReentrantLockWhenPutMessage=true
waitTimeMillsInSendQueue=500

icersummer · 2019-01-29T02:43:12Z

@gaoyf 你的server硬件配置怎样? 你的配置值是什么依据做出的?

sN0wpeak · 2019-01-29T04:19:38Z

@gaoyf 你的rocketmq broker有打

2019-01-22 11:03:02 WARN SendMessageThread_19 - [NOTIFYME]putMessage in lock cost time(ms)=4127, bodyLength=410 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3551463997150, wroteBytes=792, msgId='0A01003100002A9F0000033AE3BFFEDE', storeTimestamp=1548126178835, logicsOffset=422117414, pagecacheRT=4127, msgNum=1} 这种日志吗？

gaoyf · 2019-01-29T04:55:09Z

@gaoyf 你的rocketmq broker有打

2019-01-22 11:03:02 WARN SendMessageThread_19 - [NOTIFYME]putMessage in lock cost time(ms)=4127, bodyLength=410 AppendMessageResult=AppendMessageResult{status=PUT_OK, wroteOffset=3551463997150, wroteBytes=792, msgId='0A01003100002A9F0000033AE3BFFEDE', storeTimestamp=1548126178835, logicsOffset=422117414, pagecacheRT=4127, msgNum=1} 这种日志吗？

这个很久了，记不太清楚了，现在日志也没了，不过我没用定时消息。

sN0wpeak · 2019-01-29T07:42:22Z

@gaoyf 咱俩应该不是一个问题。你这个是请求在队列里堆的时间超时了被清理掉报的错

duhenglucky · 2019-02-01T03:36:11Z

@gaoyf you can try to execute os.sh and setcache.sh and open the transientStorePoolEnable config in the broker to polish this situation.

icersummer · 2019-02-04T03:08:45Z

@duhenglucky could you explain a little more detail about os.sh and setcache.sh ? It may do help, but I haven't got a full understanding of their usage.
There must be some different setting depends different situations.
Tks.

Ah39 · 2019-02-13T03:36:17Z

how much is the broker qps ??

makabakaboom · 2019-02-28T06:40:52Z

@mm23504570 不知道你后续是如何改善的，目前我们也存在这样的问题，我定位源码发现耗时主要在主从同步部分，slave节点拉取到消息后写入磁盘的时候，使用position标记位置的时候，会比较耗时

makabakaboom · 2019-02-28T09:26:19Z

@mm23504570 根据我的测试结果，我发现应该是主从同步slave使用FileChannel.position(offset)标记位置的时候，同时slave节点执行刷盘flush(false)，然后导致position调用阻塞，进而影响到了master节点主从同步阻塞引起的

sN0wpeak · 2019-03-14T02:41:40Z

I set vm.min_free_kbytes = 1000000 and resolved the problem.

you can try to execute os.sh and setcache.sh and open the transientStorePoolEnable config in the broker to polish this situation.

icersummer · 2019-04-08T01:57:10Z

@davidpdw 根据我的测试结果，我发现应该是主从同步slave使用FileChannel.position(offset)标记位置的时候，同时slave节点执行刷盘flush(false)，然后导致position调用阻塞，进而影响到了master节点主从同步阻塞引起的

能不能问下你是如何测试的? 我在调试时只能debug, 但是定位不了特别具体的耗时步骤.

icersummer · 2019-04-08T02:00:15Z

@mm23504570
8 CPU. 48G MEM. SSD disk
I set vm.min_free_kbytes = 1000000 and resolved the problem.

问下, 你这里的总计内存48G, 设置了 vm.min_free_kbytes=1G; 这样的考虑是什么? 设置后的对系统/RMQ的预期影响是什么?

makabakaboom · 2019-04-08T02:07:09Z

@icersummer 我只是添加了打印耗时代码，然后重新编译了测试的

david-z-johnson · 2019-04-18T12:00:53Z

I met the same issue, which version does this fix patched? thanks

freesky100 · 2019-07-03T09:02:39Z

@davidpdw 你是配置的同步吗。
SSD硬盘不用设置deadline，deadline只针对磁道的。我在测试环境只有在io慢的时候，才会有NOTIFYME。求解。
模式是全部异步刷盘模式。

duhenglucky added the type/question label Jan 25, 2019

sN0wpeak closed this as completed Mar 14, 2019

sysulincn mentioned this issue Sep 27, 2019

rmq sometimes starts flow control under low tps because PageCacheRT overtime #1489

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Question About [NOTIFYME]putMessage in lock cost time(ms)=4052 #721

Question About [NOTIFYME]putMessage in lock cost time(ms)=4052 #721

sN0wpeak commented Jan 25, 2019 •

edited

sN0wpeak commented Jan 25, 2019

duhenglucky commented Jan 25, 2019

sN0wpeak commented Jan 25, 2019

icersummer commented Jan 28, 2019

sN0wpeak commented Jan 28, 2019

gaoyf commented Jan 29, 2019

icersummer commented Jan 29, 2019

sN0wpeak commented Jan 29, 2019 •

edited

gaoyf commented Jan 29, 2019 •

edited

sN0wpeak commented Jan 29, 2019

duhenglucky commented Feb 1, 2019

icersummer commented Feb 4, 2019

Ah39 commented Feb 13, 2019

makabakaboom commented Feb 28, 2019

makabakaboom commented Feb 28, 2019

sN0wpeak commented Mar 14, 2019

icersummer commented Apr 8, 2019

icersummer commented Apr 8, 2019

makabakaboom commented Apr 8, 2019

david-z-johnson commented Apr 18, 2019

freesky100 commented Jul 3, 2019

Question About [NOTIFYME]putMessage in lock cost time(ms)=4052 #721

Question About [NOTIFYME]putMessage in lock cost time(ms)=4052 #721

Comments

sN0wpeak commented Jan 25, 2019 • edited

Question

ENV:

Some log

sN0wpeak commented Jan 25, 2019

duhenglucky commented Jan 25, 2019

sN0wpeak commented Jan 25, 2019

icersummer commented Jan 28, 2019

sN0wpeak commented Jan 28, 2019

gaoyf commented Jan 29, 2019

icersummer commented Jan 29, 2019

sN0wpeak commented Jan 29, 2019 • edited

gaoyf commented Jan 29, 2019 • edited

sN0wpeak commented Jan 29, 2019

duhenglucky commented Feb 1, 2019

icersummer commented Feb 4, 2019

Ah39 commented Feb 13, 2019

makabakaboom commented Feb 28, 2019

makabakaboom commented Feb 28, 2019

sN0wpeak commented Mar 14, 2019

icersummer commented Apr 8, 2019

icersummer commented Apr 8, 2019

makabakaboom commented Apr 8, 2019

david-z-johnson commented Apr 18, 2019

freesky100 commented Jul 3, 2019

sN0wpeak commented Jan 25, 2019 •

edited

sN0wpeak commented Jan 29, 2019 •

edited

gaoyf commented Jan 29, 2019 •

edited