yoho-search / yoho-search-service · Commits

Go to a project

Authored by unknown
Commit e11907793173b4375d4ba52bac8ad75665e282b5 1 parent d52725c9

update PerformanceMonitor

Inline Side-by-side
Showing 4 changed files with 86 additions and 77 deletions
1 package com.yoho.search.common.interceptor; 1 package com.yoho.search.common.interceptor;
2 2
  3 +import javax.annotation.PostConstruct;
3 import javax.servlet.http.HttpServletRequest; 4 import javax.servlet.http.HttpServletRequest;
4 import javax.servlet.http.HttpServletResponse; 5 import javax.servlet.http.HttpServletResponse;
5 6
@@ -12,6 +13,7 @@ import org.springframework.web.servlet.ModelAndView; @@ -12,6 +13,7 @@ import org.springframework.web.servlet.ModelAndView;
12 13
13 import com.yoho.core.common.monitor.ThreadProfile; 14 import com.yoho.core.common.monitor.ThreadProfile;
14 import com.yoho.core.common.utils.HttpRequestUtils; 15 import com.yoho.core.common.utils.HttpRequestUtils;
  16 +import com.yoho.search.base.monitor.PerformanceMonitor;
15 import com.yoho.search.common.downgrade.DownGradeService; 17 import com.yoho.search.common.downgrade.DownGradeService;
16 import com.yoho.search.common.utils.HttpServletRequestUtils; 18 import com.yoho.search.common.utils.HttpServletRequestUtils;
17 19
@@ -24,13 +26,20 @@ public class ControllerCostInterceptor implements HandlerInterceptor { @@ -24,13 +26,20 @@ public class ControllerCostInterceptor implements HandlerInterceptor {
24 26
25 private static final Logger CONTROLLER_COST = LoggerFactory.getLogger("CONTROLLER_COST"); 27 private static final Logger CONTROLLER_COST = LoggerFactory.getLogger("CONTROLLER_COST");
26 28
  29 + private static final Logger CONTROLLER_PERFORMANCE = LoggerFactory.getLogger("CONTROLLER_PERFORMANCE");
  30 +
27 private static final ThreadLocal<Long> startTimeThreadLocal = new NamedThreadLocal<Long>("ThreadLocal StartTime"); 31 private static final ThreadLocal<Long> startTimeThreadLocal = new NamedThreadLocal<Long>("ThreadLocal StartTime");
28 32
29 @Autowired 33 @Autowired
30 - private PerformanceMonitor monitor;  
31 - @Autowired  
32 private DownGradeService downGradeService; 34 private DownGradeService downGradeService;
33 35
  36 + private PerformanceMonitor monitor;
  37 +
  38 + @PostConstruct
  39 + void init(){
  40 + monitor = new PerformanceMonitor("CONTROLLER_PERFORMANCE",CONTROLLER_PERFORMANCE, 10);
  41 + }
  42 +
34 @Override 43 @Override
35 public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handle) throws Exception { 44 public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handle) throws Exception {
36 long beginTime = System.currentTimeMillis();// 1、开始时间 45 long beginTime = System.currentTimeMillis();// 1、开始时间
1 -package com.yoho.search.common.interceptor;  
2 -  
3 -import java.util.concurrent.Executors;  
4 -import java.util.concurrent.ScheduledExecutorService;  
5 -import java.util.concurrent.TimeUnit;  
6 -import java.util.concurrent.atomic.AtomicLong;  
7 -  
8 -import javax.annotation.PostConstruct;  
9 -  
10 -import org.slf4j.Logger;  
11 -import org.slf4j.LoggerFactory;  
12 -import org.springframework.stereotype.Component;  
13 -  
14 -@Component  
15 -public class PerformanceMonitor {  
16 -  
17 - private static final Logger logger = LoggerFactory.getLogger(PerformanceMonitor.class);  
18 - private static final Logger CONTROLLER_PERFORMANCE = LoggerFactory.getLogger("CONTROLLER_PERFORMANCE");  
19 -  
20 - private AtomicLong totalVisit = new AtomicLong(0);  
21 - private AtomicLong totalCost = new AtomicLong(0);  
22 -  
23 - private AtomicLong over500msCount = new AtomicLong(0);  
24 - private AtomicLong over1000msCount = new AtomicLong(0);  
25 -  
26 - private final int MonitorPeriodInSecond = 10;  
27 -  
28 - private final ScheduledExecutorService scheduledExecutorService = Executors.newSingleThreadScheduledExecutor();  
29 -  
30 - @PostConstruct  
31 - void init() {  
32 - scheduledExecutorService.scheduleAtFixedRate(new Runnable() {  
33 - @Override  
34 - public void run() {  
35 - logAndClear();  
36 - }  
37 - }, 0, MonitorPeriodInSecond, TimeUnit.SECONDS);  
38 - }  
39 -  
40 - private void logAndClear() {  
41 - try {  
42 - long visitCount = totalVisit.longValue();  
43 - long vostMs = totalCost.longValue();  
44 - long average = visitCount == 0 ? 0 : (vostMs / visitCount);  
45 - long over500msCnt = over500msCount.longValue();  
46 - double over500msCntPercent = visitCount == 0 ? 0 : (over500msCnt * 100L / visitCount);  
47 - long over1000msCnt = over1000msCount.longValue();  
48 - double over1000msCntPercent = visitCount == 0 ? 0 : (over1000msCnt * 100L / visitCount);  
49 - CONTROLLER_PERFORMANCE.info("Performance.Monitoring,Peroid [{}]s,totalVisit[{}],totalCost[{}] ms,AverageCost[{}]ms,over500msCount[{}][{}%],over1000msCnt[{}][{}%]", MonitorPeriodInSecond, visitCount,  
50 - vostMs, average,over500msCnt,over500msCntPercent,over1000msCnt,over1000msCntPercent);  
51 - totalVisit.set(0);  
52 - totalCost.set(0);  
53 - over500msCount.set(0);  
54 - over1000msCount.set(0);  
55 - } catch (Exception e) {  
56 - logger.error(e.getMessage(), e);  
57 - }  
58 - }  
59 -  
60 - public void addVisitCount() {  
61 - totalVisit.incrementAndGet();  
62 - }  
63 -  
64 - public void addCost(long cost) {  
65 - totalCost.addAndGet(cost);  
66 - if(cost>=1000){  
67 - over1000msCount.incrementAndGet();  
68 - }  
69 - if(cost>=500){  
70 - over500msCount.incrementAndGet();  
71 - }  
72 - }  
73 -  
74 -}  
@@ -8,17 +8,22 @@ import java.util.List; @@ -8,17 +8,22 @@ import java.util.List;
8 import java.util.Map; 8 import java.util.Map;
9 import java.util.Set; 9 import java.util.Set;
10 10
  11 +import javax.annotation.PostConstruct;
  12 +
11 import org.apache.commons.lang.StringUtils; 13 import org.apache.commons.lang.StringUtils;
12 import org.elasticsearch.action.get.GetResponse; 14 import org.elasticsearch.action.get.GetResponse;
13 import org.elasticsearch.action.get.MultiGetItemResponse; 15 import org.elasticsearch.action.get.MultiGetItemResponse;
14 import org.elasticsearch.action.get.MultiGetResponse; 16 import org.elasticsearch.action.get.MultiGetResponse;
15 import org.elasticsearch.index.query.QueryBuilder; 17 import org.elasticsearch.index.query.QueryBuilder;
  18 +import org.slf4j.Logger;
  19 +import org.slf4j.LoggerFactory;
16 import org.springframework.beans.factory.annotation.Autowired; 20 import org.springframework.beans.factory.annotation.Autowired;
17 import org.springframework.context.ApplicationEventPublisher; 21 import org.springframework.context.ApplicationEventPublisher;
18 import org.springframework.context.ApplicationEventPublisherAware; 22 import org.springframework.context.ApplicationEventPublisherAware;
19 import org.springframework.stereotype.Service; 23 import org.springframework.stereotype.Service;
20 24
21 import com.yoho.error.event.SearchEvent; 25 import com.yoho.error.event.SearchEvent;
  26 +import com.yoho.search.base.monitor.PerformanceMonitor;
22 import com.yoho.search.base.utils.EventReportEnum; 27 import com.yoho.search.base.utils.EventReportEnum;
23 import com.yoho.search.core.es.IElasticsearchClient; 28 import com.yoho.search.core.es.IElasticsearchClient;
24 import com.yoho.search.core.es.impl.YohoIndexHelper; 29 import com.yoho.search.core.es.impl.YohoIndexHelper;
@@ -28,12 +33,20 @@ import com.yoho.search.core.es.model.SearchResult; @@ -28,12 +33,20 @@ import com.yoho.search.core.es.model.SearchResult;
28 @Service 33 @Service
29 public class SearchCommonService implements ApplicationEventPublisherAware { 34 public class SearchCommonService implements ApplicationEventPublisherAware {
30 35
  36 + private static final Logger ES_PERFORMANCE = LoggerFactory.getLogger("ES_PERFORMANCE");
  37 +
31 @Autowired 38 @Autowired
32 private ESClientMgr esClientMgr; 39 private ESClientMgr esClientMgr;
33 @Autowired 40 @Autowired
34 private YohoIndexHelper yohoIndexHelper; 41 private YohoIndexHelper yohoIndexHelper;
35 42
36 private ApplicationEventPublisher publisher; 43 private ApplicationEventPublisher publisher;
  44 + private PerformanceMonitor performanceMonitor;
  45 +
  46 + @PostConstruct
  47 + void init(){
  48 + performanceMonitor = new PerformanceMonitor("ES_PERFORMANCE",ES_PERFORMANCE, 10);
  49 + }
37 50
38 @Override 51 @Override
39 public void setApplicationEventPublisher(ApplicationEventPublisher applicationEventPublisher) { 52 public void setApplicationEventPublisher(ApplicationEventPublisher applicationEventPublisher) {
@@ -65,10 +78,18 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -65,10 +78,18 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
65 * @return 78 * @return
66 */ 79 */
67 public SearchResult doSearch(final String indexName, final SearchParam searchParam) { 80 public SearchResult doSearch(final String indexName, final SearchParam searchParam) {
  81 + long begin = System.currentTimeMillis();
  82 + performanceMonitor.addVisitCount();
  83 + try {
68 IElasticsearchClient client = esClientMgr.getClient(indexName); 84 IElasticsearchClient client = esClientMgr.getClient(indexName);
69 SearchResult searchResult = client.search(indexName, indexName, searchParam); 85 SearchResult searchResult = client.search(indexName, indexName, searchParam);
70 this.publishSearchResultEvent(indexName, searchParam, searchResult); 86 this.publishSearchResultEvent(indexName, searchParam, searchResult);
71 return searchResult; 87 return searchResult;
  88 + } catch (Exception e) {
  89 + throw e;
  90 + }finally{
  91 + performanceMonitor.addCost(System.currentTimeMillis() - begin);
  92 + }
72 } 93 }
73 94
74 /** 95 /**
@@ -79,10 +100,18 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -79,10 +100,18 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
79 * @return 100 * @return
80 */ 101 */
81 public SearchResult doSearch(final List<String> indexNames, final SearchParam searchParam) { 102 public SearchResult doSearch(final List<String> indexNames, final SearchParam searchParam) {
  103 + long begin = System.currentTimeMillis();
  104 + performanceMonitor.addVisitCount();
  105 + try {
82 IElasticsearchClient client = esClientMgr.getClient(indexNames.get(0)); 106 IElasticsearchClient client = esClientMgr.getClient(indexNames.get(0));
83 SearchResult searchResult = client.search(indexNames, indexNames, searchParam); 107 SearchResult searchResult = client.search(indexNames, indexNames, searchParam);
84 this.publishSearchResultEvent(indexNames.toString(), searchParam, searchResult); 108 this.publishSearchResultEvent(indexNames.toString(), searchParam, searchResult);
85 return searchResult; 109 return searchResult;
  110 + } catch (Exception e) {
  111 + throw e;
  112 + }finally{
  113 + performanceMonitor.addCost(System.currentTimeMillis() - begin);
  114 + }
86 } 115 }
87 116
88 /** 117 /**
@@ -93,6 +122,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -93,6 +122,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
93 * @return 122 * @return
94 */ 123 */
95 public List<SearchResult> doMutiSearch(final String indexName, final List<SearchParam> searchParams) { 124 public List<SearchResult> doMutiSearch(final String indexName, final List<SearchParam> searchParams) {
  125 + long begin = System.currentTimeMillis();
  126 + performanceMonitor.addVisitCount(searchParams==null?0:searchParams.size());
  127 + try {
96 if (searchParams == null || searchParams.isEmpty()) { 128 if (searchParams == null || searchParams.isEmpty()) {
97 return new ArrayList<SearchResult>(); 129 return new ArrayList<SearchResult>();
98 } 130 }
@@ -104,6 +136,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -104,6 +136,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
104 this.publishSearchResultEvent(indexName, searchParam, searchResult); 136 this.publishSearchResultEvent(indexName, searchParam, searchResult);
105 } 137 }
106 return results; 138 return results;
  139 + } catch (Exception e) {
  140 + throw e;
  141 + }finally{
  142 + performanceMonitor.addCost(System.currentTimeMillis() - begin);
  143 + }
107 } 144 }
108 145
109 /** 146 /**
@@ -114,6 +151,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -114,6 +151,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
114 * @return 151 * @return
115 */ 152 */
116 public Map<String, Object> doGetCommon(final String indexName, final String id) { 153 public Map<String, Object> doGetCommon(final String indexName, final String id) {
  154 + long begin = System.currentTimeMillis();
  155 + performanceMonitor.addVisitCount(StringUtils.isBlank(id)?0:1);
  156 + try {
117 if (StringUtils.isBlank(id)) { 157 if (StringUtils.isBlank(id)) {
118 return null; 158 return null;
119 } 159 }
@@ -128,6 +168,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -128,6 +168,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
128 return null; 168 return null;
129 } 169 }
130 return response.getSourceAsMap(); 170 return response.getSourceAsMap();
  171 + } catch (Exception e) {
  172 + throw e;
  173 + }finally{
  174 + performanceMonitor.addCost(System.currentTimeMillis() - begin);
  175 + }
131 } 176 }
132 177
133 /** 178 /**
@@ -137,6 +182,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -137,6 +182,9 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
137 * @return 182 * @return
138 */ 183 */
139 public List<Map<String, Object>> doMultiGetCommon(final String indexName, final Collection<?> idList) throws Exception { 184 public List<Map<String, Object>> doMultiGetCommon(final String indexName, final Collection<?> idList) throws Exception {
  185 + long begin = System.currentTimeMillis();
  186 + performanceMonitor.addVisitCount(idList==null||idList.isEmpty()?0:1);
  187 + try {
140 if (idList == null || idList.isEmpty()) { 188 if (idList == null || idList.isEmpty()) {
141 return new ArrayList<Map<String, Object>>(); 189 return new ArrayList<Map<String, Object>>();
142 } 190 }
@@ -157,6 +205,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware { @@ -157,6 +205,11 @@ public class SearchCommonService implements ApplicationEventPublisherAware {
157 } 205 }
158 } 206 }
159 return results; 207 return results;
  208 + } catch (Exception e) {
  209 + throw e;
  210 + }finally{
  211 + performanceMonitor.addCost(System.currentTimeMillis() - begin);
  212 + }
160 } 213 }
161 214
162 } 215 }
@@ -148,7 +148,7 @@ @@ -148,7 +148,7 @@
148 </encoder> 148 </encoder>
149 </appender> 149 </appender>
150 150
151 - <!-- controller-cost appender --> 151 + <!-- controller-performance appender -->
152 <appender name="CONTROLLER_PERFORMANCE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender"> 152 <appender name="CONTROLLER_PERFORMANCE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
153 <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> 153 <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
154 <fileNamePattern>${catalina.home}/logs/%d{yyyy-MM-dd}/controller-performance.log</fileNamePattern> 154 <fileNamePattern>${catalina.home}/logs/%d{yyyy-MM-dd}/controller-performance.log</fileNamePattern>
@@ -163,6 +163,21 @@ @@ -163,6 +163,21 @@
163 </encoder> 163 </encoder>
164 </appender> 164 </appender>
165 165
  166 + <!-- es-performance appender -->
  167 + <appender name="ES_PERFORMANCE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
  168 + <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
  169 + <fileNamePattern>${catalina.home}/logs/%d{yyyy-MM-dd}/es-performance.log</fileNamePattern>
  170 + <!-- 日志最大的保存天数 -->
  171 + <maxHistory>${maxHistory}</maxHistory>
  172 + </rollingPolicy>
  173 + <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
  174 + <maxFileSize>${maxFileSize}</maxFileSize>
  175 + </triggeringPolicy>
  176 + <encoder>
  177 + <pattern>%-1relative - %d{HH:mm:ss.SSS} [%thread] %-5level %logger{0} -- %msg%n</pattern>
  178 + </encoder>
  179 + </appender>
  180 +
166 <!-- downgrade appender --> 181 <!-- downgrade appender -->
167 <appender name="DOWNGRADE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender"> 182 <appender name="DOWNGRADE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
168 <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> 183 <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
@@ -269,6 +284,12 @@ @@ -269,6 +284,12 @@
269 <appender-ref ref="CONTROLLER_PERFORMANCE_APPENDER"/> 284 <appender-ref ref="CONTROLLER_PERFORMANCE_APPENDER"/>
270 </logger> 285 </logger>
271 286
  287 + <!-- ES耗时统计 -->
  288 + <logger name="ES_PERFORMANCE" additivity="false">
  289 + <level value="INFO"/>
  290 + <appender-ref ref="ES_PERFORMANCE_APPENDER"/>
  291 + </logger>
  292 +
272 <!-- 降级日志 --> 293 <!-- 降级日志 -->
273 <logger name="DOWNGRADE" additivity="false"> 294 <logger name="DOWNGRADE" additivity="false">
274 <level value="INFO"/> 295 <level value="INFO"/>