View Javadoc
1   /*
2    * Copyright 2012-2021 CodeLibs Project and the Others.
3    *
4    * Licensed under the Apache License, Version 2.0 (the "License");
5    * you may not use this file except in compliance with the License.
6    * You may obtain a copy of the License at
7    *
8    *     http://www.apache.org/licenses/LICENSE-2.0
9    *
10   * Unless required by applicable law or agreed to in writing, software
11   * distributed under the License is distributed on an "AS IS" BASIS,
12   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
13   * either express or implied. See the License for the specific language
14   * governing permissions and limitations under the License.
15   */
16  package org.codelibs.fess.helper;
17  
18  import static org.codelibs.core.stream.StreamUtil.stream;
19  
20  import java.time.LocalDateTime;
21  import java.util.ArrayList;
22  import java.util.Arrays;
23  import java.util.HashMap;
24  import java.util.List;
25  import java.util.Map;
26  import java.util.Queue;
27  import java.util.concurrent.ConcurrentLinkedQueue;
28  import java.util.concurrent.ExecutionException;
29  import java.util.concurrent.TimeUnit;
30  import java.util.stream.Collectors;
31  
32  import javax.annotation.PostConstruct;
33  import javax.servlet.http.HttpServletRequest;
34  
35  import org.apache.commons.lang3.StringUtils;
36  import org.apache.logging.log4j.LogManager;
37  import org.apache.logging.log4j.Logger;
38  import org.codelibs.core.concurrent.CommonPoolUtil;
39  import org.codelibs.core.lang.StringUtil;
40  import org.codelibs.fesen.action.update.UpdateRequest;
41  import org.codelibs.fesen.script.Script;
42  import org.codelibs.fess.Constants;
43  import org.codelibs.fess.entity.SearchLogEvent;
44  import org.codelibs.fess.entity.SearchRequestParams;
45  import org.codelibs.fess.entity.SearchRequestParams.SearchRequestType;
46  import org.codelibs.fess.es.log.exbhv.ClickLogBhv;
47  import org.codelibs.fess.es.log.exbhv.FavoriteLogBhv;
48  import org.codelibs.fess.es.log.exbhv.SearchLogBhv;
49  import org.codelibs.fess.es.log.exbhv.UserInfoBhv;
50  import org.codelibs.fess.es.log.exentity.ClickLog;
51  import org.codelibs.fess.es.log.exentity.SearchLog;
52  import org.codelibs.fess.es.log.exentity.UserInfo;
53  import org.codelibs.fess.mylasta.action.FessUserBean;
54  import org.codelibs.fess.mylasta.direction.FessConfig;
55  import org.codelibs.fess.util.ComponentUtil;
56  import org.codelibs.fess.util.DocumentUtil;
57  import org.codelibs.fess.util.QueryResponseList;
58  import org.dbflute.optional.OptionalEntity;
59  import org.dbflute.optional.OptionalThing;
60  import org.lastaflute.web.util.LaRequestUtil;
61  
62  import com.fasterxml.jackson.core.JsonProcessingException;
63  import com.fasterxml.jackson.databind.ObjectMapper;
64  import com.google.common.base.CaseFormat;
65  import com.google.common.cache.CacheBuilder;
66  import com.google.common.cache.CacheLoader;
67  import com.google.common.cache.LoadingCache;
68  
69  public class SearchLogHelper {
70      private static final Logger logger = LogManager.getLogger(SearchLogHelper.class);
71  
72      protected long userCheckInterval = 10 * 60 * 1000L;// 10 min
73  
74      protected int userInfoCacheSize = 10000;
75  
76      protected volatile Queue<SearchLog> searchLogQueue = new ConcurrentLinkedQueue<>();
77  
78      protected volatile Queue<ClickLog> clickLogQueue = new ConcurrentLinkedQueue<>();
79  
80      protected LoadingCache<String, UserInfo> userInfoCache;
81  
82      protected String loggerName = "fess.log.searchlog";
83  
84      protected Logger searchLogLogger = null;
85  
86      protected ObjectMapper objectMapper = new ObjectMapper();
87  
88      @PostConstruct
89      public void init() {
90          if (logger.isDebugEnabled()) {
91              logger.debug("Initialize {}", this.getClass().getSimpleName());
92          }
93          userInfoCache = CacheBuilder.newBuilder()//
94                  .maximumSize(userInfoCacheSize)//
95                  .expireAfterWrite(userCheckInterval, TimeUnit.MILLISECONDS)//
96                  .build(new CacheLoader<String, UserInfo>() {
97                      @Override
98                      public UserInfo load(final String key) throws Exception {
99                          return storeUserInfo(key);
100                     }
101                 });
102         searchLogLogger = LogManager.getLogger(loggerName);
103     }
104 
105     public void addSearchLog(final SearchRequestParams params, final LocalDateTime requestedTime, final String queryId, final String query,
106             final int pageStart, final int pageSize, final QueryResponseList queryResponseList) {
107 
108         final RoleQueryHelper roleQueryHelper = ComponentUtil.getRoleQueryHelper();
109         final UserInfoHelper userInfoHelper = ComponentUtil.getUserInfoHelper();
110         final SearchLog searchLog = new SearchLog();
111 
112         if (ComponentUtil.getFessConfig().isUserInfo()) {
113             final String userCode = userInfoHelper.getUserCode();
114             if (userCode != null) {
115                 searchLog.setUserSessionId(userCode);
116                 searchLog.setUserInfo(getUserInfo(userCode));
117             }
118         }
119 
120         searchLog.setRoles(roleQueryHelper.build(params.getType()).stream().toArray(n -> new String[n]));
121         searchLog.setQueryId(queryId);
122         searchLog.setHitCount(queryResponseList.getAllRecordCount());
123         searchLog.setHitCountRelation(queryResponseList.getAllRecordCountRelation());
124         searchLog.setResponseTime(queryResponseList.getExecTime());
125         searchLog.setQueryTime(queryResponseList.getQueryTime());
126         searchLog.setSearchWord(StringUtils.abbreviate(query, 1000));
127         searchLog.setRequestedAt(requestedTime);
128         searchLog.setSearchQuery(StringUtils.abbreviate(queryResponseList.getSearchQuery(), 1000));
129         searchLog.setQueryOffset(pageStart);
130         searchLog.setQueryPageSize(pageSize);
131         ComponentUtil.getRequestManager().findUserBean(FessUserBean.class).ifPresent(user -> {
132             searchLog.setUser(user.getUserId());
133         });
134 
135         final HttpServletRequest request = LaRequestUtil.getRequest();
136         searchLog.setClientIp(StringUtils.abbreviate(ComponentUtil.getViewHelper().getClientIp(request), 100));
137         searchLog.setReferer(StringUtils.abbreviate(request.getHeader("referer"), 1000));
138         searchLog.setUserAgent(StringUtils.abbreviate(request.getHeader("user-agent"), 255));
139         final Object accessType = request.getAttribute(Constants.SEARCH_LOG_ACCESS_TYPE);
140         if (Constants.SEARCH_LOG_ACCESS_TYPE_JSON.equals(accessType)) {
141             searchLog.setAccessType(Constants.SEARCH_LOG_ACCESS_TYPE_JSON);
142         } else if (Constants.SEARCH_LOG_ACCESS_TYPE_GSA.equals(accessType)) {
143             searchLog.setAccessType(Constants.SEARCH_LOG_ACCESS_TYPE_GSA);
144         } else if (Constants.SEARCH_LOG_ACCESS_TYPE_OTHER.equals(accessType)) {
145             searchLog.setAccessType(Constants.SEARCH_LOG_ACCESS_TYPE_OTHER);
146         } else if (Constants.SEARCH_LOG_ACCESS_TYPE_ADMIN.equals(accessType)) {
147             searchLog.setAccessType(Constants.SEARCH_LOG_ACCESS_TYPE_ADMIN);
148         } else {
149             searchLog.setAccessType(Constants.SEARCH_LOG_ACCESS_TYPE_WEB);
150         }
151         final Object languages = request.getAttribute(Constants.REQUEST_LANGUAGES);
152         if (languages != null) {
153             searchLog.setLanguages(StringUtils.join((String[]) languages, ","));
154         } else {
155             searchLog.setLanguages(StringUtil.EMPTY);
156         }
157         final String virtualHostKey = ComponentUtil.getVirtualHostHelper().getVirtualHostKey();
158         if (StringUtil.isNotBlank(virtualHostKey)) {
159             searchLog.setVirtualHost(virtualHostKey);
160         } else {
161             searchLog.setVirtualHost(StringUtil.EMPTY);
162         }
163 
164         @SuppressWarnings("unchecked")
165         final Map<String, List<String>> fieldLogMap = (Map<String, List<String>>) request.getAttribute(Constants.FIELD_LOGS);
166         if (fieldLogMap != null) {
167             final int queryMaxLength = ComponentUtil.getFessConfig().getQueryMaxLengthAsInteger();
168             for (final Map.Entry<String, List<String>> logEntry : fieldLogMap.entrySet()) {
169                 for (final String value : logEntry.getValue()) {
170                     searchLog.addSearchFieldLogValue(logEntry.getKey(), StringUtils.abbreviate(value, queryMaxLength));
171                 }
172             }
173         }
174 
175         addDocumentsInResponse(queryResponseList, searchLog);
176 
177         searchLogQueue.add(searchLog);
178     }
179 
180     protected void addDocumentsInResponse(final QueryResponseList queryResponseList, final SearchLog searchLog) {
181         if (ComponentUtil.getFessConfig().isLoggingSearchDocsEnabled()) {
182             queryResponseList.stream().forEach(res -> {
183                 final Map<String, Object> map = new HashMap<>();
184                 Arrays.stream(ComponentUtil.getFessConfig().getLoggingSearchDocsFieldsAsArray()).forEach(s -> map.put(s, res.get(s)));
185                 searchLog.addDocument(map);
186             });
187         }
188     }
189 
190     public void addClickLog(final ClickLog clickLog) {
191         clickLogQueue.add(clickLog);
192     }
193 
194     public void storeSearchLog() {
195         if (!searchLogQueue.isEmpty()) {
196             final Queue<SearchLog> queue = searchLogQueue;
197             searchLogQueue = new ConcurrentLinkedQueue<>();
198             processSearchLogQueue(queue);
199         }
200 
201         if (!clickLogQueue.isEmpty()) {
202             final Queue<ClickLog> queue = clickLogQueue;
203             clickLogQueue = new ConcurrentLinkedQueue<>();
204             processClickLogQueue(queue);
205         }
206     }
207 
208     public int getClickCount(final String url) {
209         final ClickLogBhv clickLogBhv = ComponentUtil.getComponent(ClickLogBhv.class);
210         return clickLogBhv.selectCount(cb -> {
211             cb.query().setUrl_Equal(url);
212         });
213     }
214 
215     public long getFavoriteCount(final String url) {
216         final FavoriteLogBhv favoriteLogBhv = ComponentUtil.getComponent(FavoriteLogBhv.class);
217         return favoriteLogBhv.selectCount(cb -> {
218             cb.query().setUrl_Equal(url);
219         });
220     }
221 
222     protected UserInfo storeUserInfo(final String userCode) {
223         final UserInfoBhv userInfoBhv = ComponentUtil.getComponent(UserInfoBhv.class);
224 
225         final LocalDateTime now = ComponentUtil.getSystemHelper().getCurrentTimeAsLocalDateTime();
226         final UserInfo userInfo = userInfoBhv.selectByPK(userCode).map(e -> {
227             e.setUpdatedAt(now);
228             return e;
229         }).orElseGet(() -> {
230             final UserInfo e = new UserInfo();
231             e.setId(userCode);
232             e.setCreatedAt(now);
233             e.setUpdatedAt(now);
234             return e;
235         });
236         CommonPoolUtil.execute(() -> userInfoBhv.insertOrUpdate(userInfo));
237         return userInfo;
238     }
239 
240     public OptionalEntity<UserInfo> getUserInfo(final String userCode) {
241         if (StringUtil.isNotBlank(userCode)) {
242             try {
243                 return OptionalEntity.of(userInfoCache.get(userCode));
244             } catch (final ExecutionException e) {
245                 if (logger.isDebugEnabled()) {
246                     logger.debug("Failed to access UserInfo cache.", e);
247                 }
248             }
249         }
250         return OptionalEntity.empty();
251     }
252 
253     protected void processSearchLogQueue(final Queue<SearchLog> queue) {
254         final FessConfig fessConfig = ComponentUtil.getFessConfig();
255         final String value = fessConfig.getPurgeByBots();
256         String[] botNames;
257         if (StringUtil.isBlank(value)) {
258             botNames = StringUtil.EMPTY_STRINGS;
259         } else {
260             botNames = value.split(",");
261         }
262 
263         final List<SearchLog> searchLogList = new ArrayList<>();
264         final Map<String, UserInfo> userInfoMap = new HashMap<>();
265         queue.stream().forEach(searchLog -> {
266             final String userAgent = searchLog.getUserAgent();
267             final boolean isBot =
268                     userAgent != null && stream(botNames).get(stream -> stream.anyMatch(botName -> userAgent.indexOf(botName) >= 0));
269             if (!isBot) {
270                 searchLog.getUserInfo().ifPresent(userInfo -> {
271                     final String code = userInfo.getId();
272                     final UserInfo oldUserInfo = userInfoMap.get(code);
273                     if (oldUserInfo != null) {
274                         userInfo.setCreatedAt(oldUserInfo.getCreatedAt());
275                     }
276                     userInfoMap.put(code, userInfo);
277                 });
278                 searchLogList.add(searchLog);
279             }
280         });
281 
282         processUserInfoLog(searchLogList, userInfoMap);
283         processSearchLog(searchLogList);
284     }
285 
286     private void processSearchLog(final List<SearchLog> searchLogList) {
287         if (!searchLogList.isEmpty()) {
288             final FessConfig fessConfig = ComponentUtil.getFessConfig();
289             storeSearchLogList(searchLogList);
290             if (fessConfig.isSuggestSearchLog()) {
291                 final SuggestHelper suggestHelper = ComponentUtil.getSuggestHelper();
292                 suggestHelper.indexFromSearchLog(searchLogList);
293             }
294             if (fessConfig.isLoggingSearchUseLogfile()) {
295                 searchLogList.forEach(this::writeSearchLogEvent);
296             }
297         }
298     }
299 
300     protected void processUserInfoLog(final List<SearchLog> searchLogList, final Map<String, UserInfo> userInfoMap) {
301         if (!userInfoMap.isEmpty()) {
302             final FessConfig fessConfig = ComponentUtil.getFessConfig();
303             final List<UserInfo> insertList = new ArrayList<>(userInfoMap.values());
304             final List<UserInfo> updateList = new ArrayList<>();
305             final UserInfoBhv userInfoBhv = ComponentUtil.getComponent(UserInfoBhv.class);
306             userInfoBhv.selectList(cb -> {
307                 cb.query().setId_InScope(userInfoMap.keySet());
308                 cb.fetchFirst(userInfoMap.size());
309             }).forEach(userInfo -> {
310                 final String code = userInfo.getId();
311                 final UserInfo entity = userInfoMap.get(code);
312                 entity.setId(userInfo.getId());
313                 entity.setCreatedAt(userInfo.getCreatedAt());
314                 updateList.add(entity);
315                 insertList.remove(entity);
316             });
317             userInfoBhv.batchInsert(insertList);
318             userInfoBhv.batchUpdate(updateList);
319             searchLogList.stream().forEach(searchLog -> {
320                 searchLog.getUserInfo().ifPresent(userInfo -> {
321                     searchLog.setUserInfoId(userInfo.getId());
322                 });
323             });
324             if (fessConfig.isLoggingSearchUseLogfile()) {
325                 insertList.forEach(this::writeSearchLogEvent);
326                 updateList.forEach(this::writeSearchLogEvent);
327             }
328         }
329     }
330 
331     protected void storeSearchLogList(final List<SearchLog> searchLogList) {
332         final SearchLogBhv searchLogBhv = ComponentUtil.getComponent(SearchLogBhv.class);
333         searchLogBhv.batchUpdate(searchLogList, op -> {
334             op.setRefreshPolicy(Constants.TRUE);
335         });
336     }
337 
338     protected void processClickLogQueue(final Queue<ClickLog> queue) {
339         final Map<String, Integer> clickCountMap = new HashMap<>();
340         final List<ClickLog> clickLogList = new ArrayList<>();
341         for (final ClickLog clickLog : queue) {
342             try {
343                 final SearchLogBhv searchLogBhv = ComponentUtil.getComponent(SearchLogBhv.class);
344                 searchLogBhv.selectEntity(cb -> {
345                     cb.query().setQueryId_Equal(clickLog.getQueryId());
346                 }).ifPresent(entity -> {
347                     clickLogList.add(clickLog);
348                     final String docId = clickLog.getDocId();
349                     Integer countObj = clickCountMap.get(docId);
350                     if (countObj == null) {
351                         countObj = 1;
352                     } else {
353                         countObj = countObj.intValue() + 1;
354                     }
355                     clickCountMap.put(docId, countObj);
356                 }).orElse(() -> {
357                     logger.warn("Not Found for SearchLog: {}", clickLog);
358                 });
359             } catch (final Exception e) {
360                 logger.warn("Failed to process: {}", clickLog, e);
361             }
362         }
363         processClickLog(clickLogList);
364 
365         updateClickFieldInIndex(clickCountMap);
366     }
367 
368     protected void updateClickFieldInIndex(final Map<String, Integer> clickCountMap) {
369         if (!clickCountMap.isEmpty()) {
370             final SearchHelper searchHelper = ComponentUtil.getSearchHelper();
371             final FessConfig fessConfig = ComponentUtil.getFessConfig();
372             try {
373                 final UpdateRequest[] updateRequests =
374                         searchHelper.getDocumentListByDocIds(clickCountMap.keySet().toArray(new String[clickCountMap.size()]),
375                                 new String[] { fessConfig.getIndexFieldDocId(), fessConfig.getIndexFieldLang() },
376                                 OptionalThing.of(FessUserBean.empty()), SearchRequestType.ADMIN_SEARCH).stream().map(doc -> {
377                                     final String id = DocumentUtil.getValue(doc, fessConfig.getIndexFieldId(), String.class);
378                                     final String docId = DocumentUtil.getValue(doc, fessConfig.getIndexFieldDocId(), String.class);
379                                     if (id != null && docId != null && clickCountMap.containsKey(docId)) {
380                                         final Integer count = clickCountMap.get(docId);
381                                         final Script script = ComponentUtil.getLanguageHelper().createScript(doc,
382                                                 "ctx._source." + fessConfig.getIndexFieldClickCount() + "+=" + count.toString());
383                                         final Map<String, Object> upsertMap = new HashMap<>();
384                                         upsertMap.put(fessConfig.getIndexFieldClickCount(), count);
385                                         return new UpdateRequest(fessConfig.getIndexDocumentUpdateIndex(), id).script(script)
386                                                 .upsert(upsertMap);
387                                     }
388                                     return null;
389                                 }).filter(req -> req != null).toArray(n -> new UpdateRequest[n]);
390                 if (updateRequests.length > 0) {
391                     searchHelper.bulkUpdate(builder -> {
392                         for (final UpdateRequest req : updateRequests) {
393                             builder.add(req);
394                         }
395                     });
396                 }
397             } catch (final Exception e) {
398                 logger.warn("Failed to update clickCounts", e);
399             }
400         }
401     }
402 
403     protected void processClickLog(final List<ClickLog> clickLogList) {
404         if (!clickLogList.isEmpty()) {
405             final FessConfig fessConfig = ComponentUtil.getFessConfig();
406             try {
407                 final ClickLogBhv clickLogBhv = ComponentUtil.getComponent(ClickLogBhv.class);
408                 clickLogBhv.batchInsert(clickLogList);
409             } catch (final Exception e) {
410                 logger.warn("Failed to insert: {}", clickLogList, e);
411             }
412             if (fessConfig.isLoggingSearchUseLogfile()) {
413                 clickLogList.forEach(this::writeSearchLogEvent);
414             }
415         }
416     }
417 
418     public void writeSearchLogEvent(final SearchLogEvent event) {
419         try {
420             final Map<String, Object> source = toSource(event);
421             searchLogLogger.info(objectMapper.writeValueAsString(source));
422         } catch (final JsonProcessingException e) {
423             logger.warn("Failed to write {}", event, e);
424         }
425     }
426 
427     protected Map<String, Object> toSource(final SearchLogEvent searchLogEvent) {
428         final Map<String, Object> source = toLowerHyphen(searchLogEvent.toSource());
429         source.put("_id", searchLogEvent.getId());
430         // source.put("version_no", searchLogEvent.getVersionNo());
431         source.put("event_type", searchLogEvent.getEventType());
432         return source;
433     }
434 
435     protected Map<String, Object> toLowerHyphen(final Map<String, Object> source) {
436         return source.entrySet().stream()
437                 .collect(Collectors.toMap(e -> CaseFormat.UPPER_CAMEL.to(CaseFormat.LOWER_UNDERSCORE, e.getKey()), e -> {
438                     final Object value = e.getValue();
439                     if (value instanceof Map) {
440                         @SuppressWarnings("unchecked")
441                         final Map<String, Object> mapValue = (Map<String, Object>) value;
442                         return toLowerHyphen(mapValue);
443                     }
444                     return e.getValue();
445                 }));
446     }
447 
448     public void setUserCheckInterval(final long userCheckInterval) {
449         this.userCheckInterval = userCheckInterval;
450     }
451 
452     public void setUserInfoCacheSize(final int userInfoCacheSize) {
453         this.userInfoCacheSize = userInfoCacheSize;
454     }
455 
456     public void setLoggerName(final String loggerName) {
457         this.loggerName = loggerName;
458     }
459 }