MQTT研究之EMQ：【EMQX使用中的一些問題記錄（1）】

時間 2019-11-06

標籤 mqtt 研究 emq emqx 使用一些問題記錄简体版

原文原文鏈接

issue 1. EMQX的共享訂閱

EMQX是一個很是強大的物聯網通訊消息總線，基於EMQX開展應用開發，要注意不少配置細節問題，這裏要說到的就是共享訂閱以及和cleanSession之間的關係問題。共享訂閱在EMQ的里程牌中出現的較早，V2的時候就已經提供了，只是那個時候只支持單節點的共享訂閱，在V3的時候才支持集羣的共享訂閱。mysql

共享訂閱功能很是實用，解決了消費者應用程序的負載均衡問題，或者說高可用問題。不然，負載均衡或者高可用問題，須要藉助於全局鎖進行消息消費過程當中的只消費一次的問題。這個實現起來，相對比較的麻煩，主要是穩定性和併發支持上要花不少精力調優。如今EMQX已經作了這個，已共享訂閱的方式爲應用程序的開發提供了便利。git

共享訂閱支持兩種方式：github

訂閱前綴            　　使用示例
$queue/                mosquitto_sub -t ‘$queue/topic’
$share/<group>/        mosquitto_sub -t ‘$share/group/topic’

目前，咱們的物聯網平臺中採用的是$share/<group>這種方式，主要有$share/dcX/yourTopic，和$share/resX/yourTopic這兩種應用場景。sql

使用共享訂閱，須要注意這裏會遇到的潛在風險，和cleanSession的配置相關（cleanSession幹什麼用，自行查閱研究），這裏我就拿咱們項目上遇到的故事，分享一下：數據庫

咱們的應用程序res部署了2個應用實例，emqx集羣也是2個節點，其實這裏和emqx集羣節點數沒有關係（理論分析）。res應用程序裏面，cleanSession設置的是false，也就是說應用程序和EMQX的mqtt鏈接斷掉後，emqx服務端還會保留session一個配置指定的時間。咱們使用的emqx是V3.1.1，默認的session有效期是2h。共享訂閱的策略是默認的random。res應用程序裏面的消費者clientId是uuid隨機生成的，每次運行都不同，一旦程序啓動後，ClientID就固定下來。
咱們的測試動做是這麼幹的，正常啓動兩個res服務a和b，一切正常，共享訂閱消息沒有問題。測試中途，將其中一個res應用a停機了，在b上繼續驗證業務邏輯，發如今b上一會收的到消息，一會又收不到消息，一樣的訂閱邏輯，爲什麼停掉了一個應用，就會出現這種現象？
上述現象發現後，大概半小時的分析，無果。而後，將停掉的res應用a再次啓動，發現，仍是會出現a，b，上一樣有可能都收不到消息，訂閱邏輯沒有問題啊，怎麼仍是解決不了問題？
開始懷疑res應用程序訂閱邏輯寫的不對，將多個topic逐個訂閱改爲數組的模式一次訂閱，繼續部署繼續測試，發現訂閱不到消息的狀況更明顯了，這咋解釋啊？

其實，當知道是res應用程序反覆啓停，在res上訂閱不到消息的現象愈加明顯。這個線索很是有價值，這就提醒了問題所在了！其實就是由於cleanSession爲false的狀況下由於ClientID在每次啓停res的時候以一個新的身份進行共享訂閱了，對於EMQX來講，至關於共享訂閱者變多了，每次啓停，就產生了一個虛擬的共享訂閱者，若咱們不注意，實際上是看不到的，由於咱們只是關注了實際的兩個res應用a和b。若你細心一點，你能夠在emqx的dashboard上可以看到不止2個訂閱者。(參看下面幾個圖)數組

圖1：正常訂閱（正常的兩個共享訂閱者）緩存

圖2：將res a應用移除（至關於在一段時間內，EMQX認爲有2個共享訂閱者，session爲超期）session

圖3 將res a移除後，又加入進來共享訂閱（至關於在一段時間內，EMQX認爲有3個共享訂閱者，session爲超期）併發

圖4 將res a移除後，加入進來，而後又移除，而後又加進來（至關於在一段時間內，EMQX認爲有4個共享訂閱者，session爲超期）app

解決這個問題，其實有兩個方向：
1. ClientID不能變化，每次res啓停都是相同的，無論何時，一個res應用，對應的ClientID要恆定不變。能夠基於app_ip+app_port+emqx_ip這種相似思路，進行鎖定ClientID。這樣EMQX這邊就不會出現虛擬的消費者鏈接。
2. 將cleanSession配置爲true，每次mqtt鏈接斷掉後，EMQX端就不要繼續保持對應鏈接的session，EMQX這裏就會當即踢掉斷線的session，不會出現潛在的接收消息的訂閱者，此種狀況下，及時ClientID每次不同，也不會出現虛擬消費者。

issue 2. ACL校驗

EMQX對於接入的鏈接，不管是想訂閱和消費，首先要通過權限校驗，符合ACL規則的，才容許進行後續的數據流轉。可是，EMQ基於插件的方式實現auth功能，這裏，咱們採用的是基於mysql實現認證和acl。其實身份認證還不是多大的問題，主要是acl比較消耗mysql的性能。尤爲是在鏈接數比較多的時候。

咱們的壓測環境下，mysql是單點庫，機器配置4C24G500G。 EMQX節點2個，在鏈接數1W以上，每一個鏈接每秒2個消息的狀況下，mysql數據庫開始出現CPU佔用比較高的現象，CPU 60%的消耗。
當時ACL表中的記錄數並非太多，才10多萬，經過show full processlist查看SQL信息，發現不少都是EMQX的emqx_auth_mysql.conf文件裏面的acl_query的語句。說明這個查詢比較頻繁，且佔用時間有點長。以爲這個不該該吧，併發不是很高啊。。。
emqx的ACL cache配置ttl是默認的1分鐘，最大緩存數量cache size是默認的32.

emqx_auth_mysql.conf中的查詢語句：auth.mysql.acl_query = select allow, ipaddr, username, clientid, access, topic from mqtt_acl where ipaddr = '%a' or username = '%u' or username = '$all' or clientid = '%c'。檢查了下這個SQL的執行計劃，獲得下面的結果：

mysql> explain select allow, ipaddr, username, clientid, access, topic from scc_mqtt_acl_1 where ipaddr = '%a' or username = '%u' or username = '$all' or clientid = '%c';
+----+-------------+----------------+------------+------+---------------------------------------+------+---------+------+--------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------------+------------+------+---------------------------------------+------+---------+------+--------+----------+-------------+
| 1 | SIMPLE | scc_mqtt_acl_1 | NULL | ALL | doubleIndex,USERNAME_IDX,CLIENTID_IDX | NULL | NULL | NULL | 201976 | 34.39 | Using where |
+----+-------------+----------------+------------+------+---------------------------------------+------+---------+------+--------+----------+-------------+
1 row in set, 1 warning (0.00 sec)

能夠看到，這裏是沒有用到索引的。即，在設備數據量很大的時候，這裏是存在隱患的，即查詢會全表掃描。說明emqx默認的關於ACL的查詢須要結合應用場景進行優化。

分析了咱們的應用場景，每一個設備接入都有本身的用戶名和密碼，ipaddr是變化的，也就是說很差進行監控管理，就不作強制要求，因此能夠忽略無論，ClientID，這個對於應用來講，也是基於必定規則進行的，不會出現重複的信息，因此，咱們也沒有作強制要求，在ACL配置的時候，主要是基於username和ClientID進行標識記錄的，username是必需要有的，ClientID不是必須的，因此，咱們的ACL查詢語句就優化了下，將原來默認的查詢where中的幾個or改了，只是一個username了。以下：

auth.mysql.acl_query = select allow, ipaddr, username, clientid, access, topic from scc_mqtt_acl_1 where username = '%u'
給數據表的username建立一個normal的索引，此時的執行計劃以下：
```
mysql> explain select allow, ipaddr, username, clientid, access, topic from scc_mqtt_acl_1 where username = '%u'; 
+----+-------------+----------------+------------+------+---------------+--------------+---------+-------+------+----------+-------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------------+------------+------+---------------+--------------+---------+-------+------+----------+-------+
| 1 | SIMPLE | scc_mqtt_acl_1 | NULL | ref | USERNAME_IDX | USERNAME_IDX | 403 | const | 1 | 100.00 | NULL |
+----+-------------+----------------+------------+------+---------------+--------------+---------+-------+------+----------+-------+
1 row in set, 1 warning (0.04 sec)
```
能夠看到，索引生效了，取代默認配置or語句，用上索引。

issue 3. emqx穩定性問題

咱們的壓測目標，就是在兩個EMQX節點集羣環境（4C16G100G）下，可以支持至少10000的TPS（每秒10000條消息被消費），目標20000個鏈接。下面的幾種case中，消費者程序是同樣的。生成消息的機制有點變化，可是消息報文大小是同樣的。

case 1.

在用V3.0.1的時候，進行壓測，併發20000TPS，100鏈接。出現下面的錯誤信息，提示消息處理不過來，EMQX將消費者進行剔除。

2019-09-11 20:44:38.916 [error] 39346787c9bc4afd990a16a2700995fd@10.95.198.25:40038 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:44:49.827 [warning] [SYSMON] large_heap warning: pid = <0.5103.0>, info: [{old_heap_block_size,6189440},
{heap_block_size,3581853},
{mbuf_size,0},
{stack_size,29},
{old_heap_size,2848687},
{heap_size,1048794}]
[{initial_call,{proc_lib,init_p,5}},
{current_function,{lists,foldl,3}},
{registered_name,[]},
{status,running},
{message_queue_len,57631},
{group_leader,<0.2133.0>},
{priority,normal},
{trap_exit,true},
{reductions,1536664490},
{last_calls,false},
{catchlevel,2},
{trace,0},
{suspending,[]},
{sequential_trace_token,[]},
{error_handler,error_handler},
{memory,83275744},
{total_heap_size,9775308},
{heap_size,3581853},
{stack_size,34},
{min_heap_size,233}]
2019-09-11 20:44:50.300 [error] 9001547605ec46648b3c485103233946@10.95.198.26:58460 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:44:57.398 [error] b34a92025fbc4c89bbe54ca22e74199f@10.95.198.25:40110 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:44:57.922 [error] a74b0c24136b4c5899dc866fe57d9173@10.95.198.25:40112 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:45:05.640 [error] 4f930fb242734f9ba22ce57c753c482b@10.95.198.26:58442 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:45:30.424 [error] 39346787c9bc4afd990a16a2700995fd@10.95.198.25:40116 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:45:32.180 [error] a74b0c24136b4c5899dc866fe57d9173@10.95.198.25:40126 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:45:32.376 [error] b34a92025fbc4c89bbe54ca22e74199f@10.95.198.25:40128 [Channel] Shutdown exceptionally due to message_queue_too_long
2019-09-11 20:45:51.497 [error] 9001547605ec46648b3c485103233946@10.95.198.26:33234 [Channel] Shutdown exceptionally due to message_queue_too_long

這個問題，在V3.0.1下測試好久，逐漸下降併發，降到13000左右纔算穩定。可是這個過程當中，遇到CPU消耗不穩定的現象，解決CPU在兩個EMQX之間很不平衡，以及調整共享訂閱的Strategy從random到round_robin啓動失敗，將版本調整到了V3.1.1

case 2.

在用V3.1.1的時候，一樣進行壓測，併發低些，可是要求鏈接數提高，至少過萬，可是模擬的設備數量不到6000就出現問題。

2019-10-09 08:42:15.479 [error] 10.95.198.31:46924 ** State machine <0.14661.18> terminating
** Last event = {timeout,15000}
** When server state  = {idle,
                            {state,esockd_transport,#Port<0.418835>,
                                {{10,95,198,31},46924},
                                undefined,running,100,
                                {pstate,external,
                                    #Fun<emqx_connection.0.73284863>,
                                    {{10,95,198,31},46924},
                                    nossl,4,<<"MQTT">>,<<>>,false,
                                    <0.14661.18>,undefined,undefined,
                                    undefined,undefined,false,#{},1048576,
                                    undefined,undefined,undefined,false,true,
                                    true,false,ignore,
                                    #{msg => 0,pkt => 0},
                                    #{msg => 0,pkt => 0},
                                    false,undefined,false,
                                    #{from_client => 0,to_client => 0},
                                    emqx_connection,#{},undefined},
                                {none,
                                    #{max_packet_size => 1048576,
                                      version => 4}},
                                {emqx_gc,
                                    #{cnt => {1000,1000},
                                      oct => {1048576,1048576}}},
                                undefined,true,undefined,undefined,undefined,
                                undefined,15000}}
** Reason for termination = exit:idle_timeout
** Callback mode = [state_functions,state_enter]
** Stacktrace =
**  [{gen_statem,loop_event_result,9,[{file,"gen_statem.erl"},{line,1158}]},
     {proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]

這個問題，研究了很長時間，開始總覺得是客戶端程序寫的有問題，改過幾種版本的消息生產者程序，都是不成功，鏈接數上不來。後來查看EMQX在Github上的issue列表，發現有關於idle_timeout的merge request（https://github.com/emqx/emqx/pull/2675），我估計是否是知道內部有錯誤，作了修改。另外，關於這個問題，有人也提了issue，只是我以爲emqx的維護者並非很nice的解答開發者的問題（https://github.com/emqx/emqx/issues/2686，這個issue的解答，我是以爲沒有說清楚的）。因而，我將版本升級到了最新版本V3.2.3，再次測試這個鏈接數的問題，到目前爲止，能夠上升到13000的鏈接數，EMQX集羣運行還算正常。

PS:

一個小小的經驗，出現下面相似這樣的警告，說明ClientID出現了重複，由於EMQX裏面不容許出現重複的ClientID，若出現，將會阻斷後接入的這個應用的接入。

2019-10-09 18:06:52.083 [warning] 1_qemqeqseq68@10.95.198.31:60514 [Channel] Discarded by 1_qemqeqseq68:<41446.2930.412>
2019-10-09 18:06:52.083 [warning] 1_qewf2p45b7k@10.95.198.31:60500 [Channel] Discarded by 1_qewf2p45b7k:<41446.2733.412>
2019-10-09 18:06:52.083 [warning] 1_qem2iltm7eo@10.95.198.31:60508 [Channel] Discarded by 1_qem2iltm7eo:<41446.32139.411>
2019-10-09 18:06:52.084 [warning] 1_qer8ey3os8w@10.95.198.31:60555 [Channel] Discarded by 1_qer8ey3os8w:<41446.19217.410>
2019-10-09 18:06:52.087 [warning] 1_qeq2zud8kqo@10.95.198.31:60536 [Channel] Discarded by 1_qeq2zud8kqo:<0.31128.411>
2019-10-09 18:06:52.088 [warning] 1_qeoe5lwdreo@10.95.198.31:60528 [Channel] Discarded by 1_qeoe5lwdreo:<0.27662.411>
2019-10-09 18:06:52.088 [warning] 1_qeo1lfw2nls@10.95.198.31:60504 [Channel] Discarded by 1_qeo1lfw2nls:<0.27702.411>
2019-10-09 18:06:52.091 [warning] 1_qex6mpfgnwg@10.95.198.31:60567 [Channel] Discarded by 1_qex6mpfgnwg:<0.27882.411>
2019-10-09 18:06:52.091 [warning] 1_qemujku3vgg@10.95.198.31:60558 [Channel] Discarded by 1_qemujku3vgg:<0.2020.412>
2019-10-09 18:06:52.091 [warning] 1_qemvx7mz3sw@10.95.198.31:60564 [Channel] Discarded by 1_qemvx7mz3sw:<41446.3072.412>