1. 程式人生 > >一次壓測情況下Solr部分效能調整

一次壓測情況下Solr部分效能調整

在將solr模糊詞搜尋從 copyfield方式修改為 qf(query function)之後,其query的效能降低不少。原來是採用將所有需要搜尋的欄位都copy至同一個欄位中,最近要根據模糊匹配結果的權重分析,這種方式根本無法滿足要求,所以就採用了query function,這樣就能定義不同欄位的權重了,例如我們qf可以如下定義:
product_name^2.0 category_name^1.5 category_name1^1.5
   搜尋出來的結果會根據不同匹配的評分進行相似度排序。 但在效能測試過程中,其非常耗費記憶體,在solr查詢服務中,我們打開了solr的搜尋日誌 solr.log,搜尋日誌的格式大概如下:
2016-10-19 13:31:26.955 INFO  (qtp1455021010-596) [c:product s:shard1 r:core_node1 x:product] o.a.s.c.S.Request [product] webapp=/solr path=/select params={sort=salesVolume+desc&fl=product_id,salesVolume&start=0&q=brand_id:403+OR+category_id:141&wt=javabin&version=2&rows=100} hits=3098 status=0 QTime=3
2016-10-19 13:31:28.618 INFO  (qtp1455021010-594) [c:product s:shard1 r:core_node1 x:product] o.a.s.c.S.Request [product] webapp=/solr path=/select params={mm=100&facet=true&sort=psfixstock+DESC,salesVolume+DESC&facet.mincount=1&facet.limit=-1&wt=javabin&version=2&rows=10&fl=product_id&facet.query=price:[*+TO+500]&facet.query=price:[500+TO+1000]&facet.query=price:[1000+TO+2000]&facet.query=price:[2000+TO+5000]&facet.query=price:[5000+TO+10000]&facet.query=price:[10000+TO+*]&start=0&q=*:*+AND+(category_id:243+OR+category_path:243)+AND+-category_path:309+AND+brand_id:401+AND+good_stop:0+AND+product_stop:0+AND+is_check:1+AND+status:1&facet.field=category_id&facet.field=brand_id&facet.field=color_id&facet.field=gender&facet.field=ctype&qt=/select&fq=price:[1000+TO+*]&fq=psfixstock:[1+TO+*]} hits=17 status=0 QTime=5
2016-10-19 13:31:30.867 INFO  (qtp1455021010-614) [c:product s:shard1 r:core_node1 x:product] o.a.s.c.S.Request [product] webapp=/solr path=/select params={mm=100&facet=true&sort=price+ASC,goods_id+DESC&facet.mincount=1&facet.limit=-1&wt=javabin&version=2&rows=10&fl=product_id&facet.query=price:[*+TO+500]&facet.query=price:[500+TO+1000]&facet.query=price:[1000+TO+2000]&facet.query=price:[2000+TO+5000]&facet.query=price:[5000+TO+10000]&facet.query=price:[10000+TO+*]&start=0&q=*:*+AND+(category_id:10+OR+category_path:10)+AND+-category_path:309+AND+color_id:10+AND+gender:(0)+AND+good_stop:0+AND+product_stop:0+AND+is_check:1+AND+status:1&facet.field=category_id&facet.field=brand_id&facet.field=color_id&facet.field=gender&facet.field=ctype&qt=/select&fq=price:[5000+TO+*]&fq=psfixstock:[1+TO+*]} hits=9 status=0 QTime=7
2016-10-19 13:31:32.877 INFO  (qtp1455021010-594) [c:product s:shard1 r:core_node1 x:product] o.a.s.c.S.Request [product] webapp=/solr path=/select params={mm=100&facet=true&sort=psfixstock+DESC,salesVolume+DESC&facet.mincount=1&facet.limit=-1&wt=javabin&version=2&rows=10&fl=product_id&facet.query=price:[*+TO+500]&facet.query=price:[500+TO+1000]&facet.query=price:[1000+TO+2000]&facet.query=price:[2000+TO+5000]&facet.query=price:[5000+TO+10000]&facet.query=price:[10000+TO+*]&start=0&q=*:*+AND+(category_id:60+OR+category_path:60)+AND+-category_path:309+AND+brand_id:61+AND+gender:(0)+AND+good_stop:0+AND+product_stop:0+AND+is_check:1+AND+status:1&facet.field=category_id&facet.field=brand_id&facet.field=color_id&facet.field=gender&facet.field=ctype&qt=/select&fq=price:[*+TO+*]&fq=psfixstock:[1+TO+*]} hits=5 status=0 QTime=8
2016-10-19 13:31:42.896 INFO  (qtp1455021010-89) [c:product s:shard1 r:core_node1 x:product] o.a.s.c.S.Request [product] webapp=/solr path=/select params={mm=100&facet=true&sort=psfixstock+DESC,salesVolume+DESC&facet.mincount=1&facet.limit=-1&wt=javabin&version=2&rows=10&fl=product_id&facet.query=price:[*+TO+500]&facet.query=price:[500+TO+1000]&facet.query=price:[1000+TO+2000]&facet.query=price:[2000+TO+5000]&facet.query=price:[5000+TO+10000]&facet.query=price:[10000+TO+*]&start=0&q=*:*+AND+-category_path:309+AND+brand_id:323+AND+color_id:3+AND+good_stop:0+AND+product_stop:0+AND+is_check:1+AND+status:1&facet.field=category_id&facet.field=brand_id&facet.field=color_id&facet.field=gender&facet.field=ctype&qt=/select&fq=price:[*+TO+*]&fq=psfixstock:[1+TO+*]} hits=3 status=0 QTime=4
  為了合理統計出query的QTime,編寫了一個python指令碼,用來線上分析每次solr查詢的QTime和對應的查詢條件:  
import sys
 
if __name__ == '__main__':
    input_file = sys.argv[1]
 
    min_time = 0 if len(sys.argv) < 3 else int(sys.argv[2])
 
    try:
        with open(input_file) as file:
            while (1):
                line = file.readline().strip()
                if not line:
                    break
                splits = line.split(" ")
                if not splits[len(splits) - 1].startswith("QTime"):
                    continue
                q_time = int(splits[len(splits) - 1].replace('\n', '').replace('QTime=', ''))
                if q_time <= min_time:
                    continue
 
                date = splits[0]
                time = splits[1]
                params = splits[13].split("&")
 
                dict = {}
                for param in params:
                    keyValuePair = param.split("=")
                    dict[keyValuePair[0]] = keyValuePair[1]
 
                query = dict.get('q', None)
                if query:
                    print "%s - %s , QTime=% 5d, Query = %s" % (date, time, q_time, query)
    except IOError as error:
        print error
  該指令碼中可以分析solr.log中的日誌並過濾出大於某端時間(毫秒)的QTime。經過分析發現此時的QTime大於1000ms的佔據很大比例,說明我們配置的query function效能並不理想,至少相對於copy field來說。 通過jvisualvm監測發現full gc發生的頻率非常高,cpu佔用居高不下,請求響應時間發生抖動,且抖動的時候都是在該伺服器的CPU使用率下降時發生的。 將線上的堆疊dump出來,經過JProfiler分析的hprof檔案,佔據大頭的都是solr、lucene相關的類:


 
  而且發現另外一個情況,老年代用400M左右常駐記憶體,而通常老年代漲到500M左右時就會發生一次Full GC(發生得非常頻繁)。 需要我們調整JVM內部各個部分記憶體佔用的比例,但收效甚微,接近10:1(MinorGC:FullGC)的GC,過多的FullGC次數使得應用程式的整體處理請求速度變慢:  

  初步分析覺得應該是Survivor的空間不足以存放某個大物件,使得新生代未被回收的物件直接晉升到老年代導致頻繁GC,但是調高SurvivorRatio比例之後,發現該問題仍然沒有得到解決。 當前solr的GC回收策略為CMSGC,據網上查詢的該垃圾回收策略,可能會出現promotion failed和concurrent mode failure,經過我們檢視當天的壓測日誌,確實這種情況非常多:
> grep "concurrent mode failure" solr_gc_log_20161018_* | wc -l
4919
> grep "promotion failed" solr_gc_log_20161018_* | wc -l
127
  網上推薦的做法是: http://blog.csdn.net/chenleixing/article/details/46706039 寫道 promotion failed是在進行Minor GC時,survivor space放不下、物件只能放入老年代,而此時老年代也放不下造成的;concurrent mode failure是在執行CMS GC的過程中同時有物件要放入老年代,而此時老年代空間不足造成的(有時候“空間不足”是CMS GC時當前的浮動垃圾過多導致暫時性的空間不足觸發Full GC)。
應對措施為:增大survivor space、老年代空間或調低觸發併發GC的比率,但在JDK 5.0+、6.0+的版本中有可能會由於JDK的bug29導致CMS在remark完畢後很久才觸發sweeping動作。對於這種狀況,可通過設定-XX: CMSMaxAbortablePrecleanTime=5(單位為ms)來避免。   但經過綜合考慮,沒有能夠正常調通該種策略,決定提升JVM的程序Heap記憶體至3.5G,並將原有響應式CMSGC替換成吞吐量優先的方式,減少FullGC次數和總體時間:
-Xmn2048m \
-XX:-UseAdaptiveSizePolicy \
-XX:SurvivorRatio=4 \
-XX:TargetSurvivorRatio=90 \
-XX:MaxTenuringThreshold=8 \
-XX:+UseParallelGC -XX:+UseParallelOldGC
經過這樣調整後:Heap總體記憶體為3.5G,老年代1.5G,新生代總體2G,Eden區1.3G,兩個Survivor區分別為300M。 但是空間提高之後也會出現其他的問題,發現老年代空間導致的一個重大問題就是,單次FullGC的時間會變得非常大,第一次gc時間居然超過5s,這也是由於單次回收的空間過高引起的:

  原來總是以為是survivor區的空間不夠大,當調大之後發現也不是這個問題,不過這種情況下執行一段時間後,總體還算是比較穩定,次數和時間也控制下來了,只不過進行FullGC時可能會發生STW(Stop The World),引起較長時間的停頓,如果是CMS方式就不會出現這種問題。 SurvivorRatio=2的設定也並不是非常合理,後續還是將其降低為4-5。

   經過solr部分的測試,基本的結論還是比較符合預期的,相同條件下,對於analysed欄位(進行分詞操作的),其響應時間(Response Time)會比非analysed欄位長很多,尤其是在壓測條件下(圖中最後一行就是模糊匹配,其他兩個為精確匹配)。

   SolrCloud導致的另外一些問題 經過solrCloud線上和測試環境對比驗證,發現線上的多臺服務效能居然要比單臺要低,經過資料比對分析發現,我們當前的資料量還沒有達到需要進行分片的要求,分片反而會導致效能下降,下面是我們當前的core部署結構,分成兩個shard

  在solr的debugQuery模式下,可以看到最終的QTime為兩個QTime增加後的總和還要多一點,多出的時間應該是合併結果的時間。在資料量比較大的情況下,多分片會降低某一臺伺服器的負載。 如果將其做成單個shard,通過zookeeper連線solrCloud,增加replica的情況下,則只會將壓力打到單臺伺服器上,這樣做雖然比分片要快(在小資料集的情況下),但造成了服務資源的浪費。

  我們決定採用折中方案,使用solrCloud來保證4臺solr伺服器的資料一致性(我們當前的資料變化不頻繁),然後每臺應用伺服器選擇一臺solr伺服器進行單機連線,這樣也有一個問題就是損失了高可用性,但是在電商做活動期間,這樣臨時做是沒有問題的,但需要保證每臺伺服器的其他core都是存在全面的資料,否則會出現某些節點沒有對應core的錯誤。