诸多原因,我们的程序往往不能解释其本身,再者,我们也不能苛求调用者读(懂)我们的程序逻辑。所以,我们需要给代码添加注释。好的代码注释规范是不可或缺的,尤其是要给类和方法添加注释。
今天下午生产环境优付OMS服务出现故障,从tomcat的catalina.log里发现java.lang.OutOfMemoryError: GC overhead limit exceeded,组内各伙伴齐参与,来查找原因。
其中一个线索是,如下sql频繁执行,导致日志量激增超过1G。
2021-04-13 13:35:01.023 [DEBUG] [http-apr-8480-exec-9] [com.yft.mapper.TMerchantDAO.selectMerchantByMerId:132] ==> Preparing: select * from T_MERCHANT where MER_ID=? 2021-04-13 13:35:01.024 [DEBUG] [http-apr-8480-exec-9] [com.yft.mapper.TMerchantDAO.selectMerchantByMerId:132] ==> Parameters: 89900000617916182868(String) 2021-04-13 13:35:01.025 [TRACE] [http-apr-8480-exec-9] [com.yft.mapper.TMerchantDAO.selectMerchantByMerId:138] <== Columns: ID, MER_ID, MER_NAME, PROVINCE, CITY, COUNTY, REG_ADDR, LEGAL_PERSON, LEGAL_ID_CARD, AUTH_MOBILE, AUTH_EMAIL, SIGNING_PLAT_TYPE, DOMAIN_NAME, RECORD_NO, APP_NAME, APP_MARKET, MCC_1, MCC_2, BUSINESS_NAME, BUSINESS_MOBILE, BUSINESS_EMAIL, FINANCE_NAME, FINANCE_MOBILE, FINANCE_EMAIL, IT_NAME, IT_MOBILE, IT_EMAIL, IT_QQ, POST_NAME, POST_MOBILE, CONTRACT_POST_ADDR, AGENT_ID, SALE_ID, SETTLE_ACC_NAME, SETTLE_ACC_BANK, SETTLE_ACC_NO, SETTLE_CYCLE, SETTLE_TYPE, LEVY_ID, CUS_CONTRACT_TYPE, TAX_COMPANY, TAX_NO, TAX_ADDR, TAX_MOBILE, TAX_OPEN_BANK, TAX_ACC, STATE, AUDIT_STATE, PAY_CHANNEL, FILE_PATH, FIRST_AUDIT_TIME, REVIEW_AUDIT_TIME, MEMO, CREATE_TIME, UPDATE_TIME, OPERATOR, FIRST_AUDITOR, REVIEW_AUDITOR, SUBMIT_TIME, OPEN_TIME, CONTRACT_FILE_PATH, MINI_PIC_PATH, OTHER_NAME, MER_BEAR_TAX, INVOICE_TYPE, IS_SET_AUDIT, SIGNING_PARAM_VALID, CHECK_TYPE, CHECK_MOBILES, MERCHANT_TYPE, GROUP_MER_ID, AUTH_MSG, AGREEMENT_TYPE, IS_CONFIRM, IS_DELIVER, IS_CONFIRM_PROJECT, ENTERPRISE_ID
从jdk的jvisualvm里分析当时的dump,观察到当时内存里有许多TMerchantVO、TMerchant对象。
通过查程序,这个TMerchantDAO#selectMerchantByMerId方法有20多处调用,由于是外采的老系统,以及后续需求迭代缺乏有效管控,造成我们短时间内不能定位每个调用的具体用途。而服务的log文件还在不断增大,20分钟就会增加0.1G,当然,可想而知db压力也不小。当务之急,the Number One Priority,有必要赶紧立刻马上减少这个方法的执行次数。
@Service @Slf4j public class TMerchantServiceImpl implements TMerchantService { @Override public TMerchant selectMerchantByMerId(Map<String, Object> map) { return tMerchantDAO.selectMerchantByMerId(map); } }
想到的方案自然是用缓存。
刚好,项目里有redis工具类JedisUtils。于是,三下五除二,修改程序为如下版本,并找了两个小伙伴review,没发现什么问题,立即找运维先合代码重启服务。
@Service @Slf4j public class TMerchantServiceImpl implements TMerchantService { @Override public TMerchant selectMerchantByMerId(Map<String, Object> map) { // return tMerchantDAO.selectMerchantByMerId(map); return selectMerchantByMerId_Cache(map); } public TMerchant selectMerchantByMerId_Cache(Map<String, Object> map) { String merId = String.valueOf(map.get("merId")); String key="TMerchant:".concat(merId); if(JedisUtils.exists(key)){ logger.info("read from redis. key={}", key); return (TMerchant) JedisUtils.getObject(key); } else { TMerchant tMerchant = tMerchantDAO.selectMerchantByMerId(map); JedisUtils.setObject(key, tMerchant, 30); return tMerchant; } } }
重启之后,日志不再激增,不过,奇怪的是,log里并未发现read from redis. key=。因为有其他的事情处理,困扰了一下午的这个问题,到晚上下班后,经过本地编写testcase测试才发现,上面调用JedisUtils的exists(String)是不对的,而应该调用JedisUtils的另一个方法existsObject(String)。。。而我当时却并未注意到还有existsObject(String)这个方法,只是快速扫了一下exists(String),感觉没问题就用上了。。。
如下是JedisUtils里这两个方法的定义
/** * 缓存是否存在 * @param key 键 * @return */ public static boolean exists(String key) { boolean result = false; Jedis jedis = null; try { jedis = getResource(); result = jedis.exists(key); logger.debug("exists {}", key); } catch (Exception e) { logger.warn("exists {}", key, e); } finally { returnResource(jedis); } return result; } /** * 缓存是否存在 * @param key 键 * @return */ public static boolean existsObject(String key) { boolean result = false; Jedis jedis = null; try { jedis = getResource(); result = jedis.exists(getBytesKey(key)); logger.debug("existsObject {}", key); } catch (Exception e) { logger.warn("existsObject {}", key, e); } finally { returnResource(jedis); } return result; }
单看这样的方法注释,很难说未来别人使用的时候不会出现我踩的这个坑呀!
于是乎,我完善了一下方法的注释,见下方,我觉得,如果日后还有人踩到这个坑的话,我只能呵呵嘿嘿哈哈了。
/** * 缓存是否存在 * 注意与{@link #existsObject(String)}的区别,本方法适用于set设置值,而后者适用于通过setObject来设置值 * @param key 键 * @return */ public static boolean exists(String key) { boolean result = false; Jedis jedis = null; try { jedis = getResource(); result = jedis.exists(key); logger.debug("exists {}", key); } catch (Exception e) { logger.warn("exists {}", key, e); } finally { returnResource(jedis); } return result; } /** * 缓存是否存在 * 注意与{@link #exists(String)}的区别,本方法适用于setObject设置值,而后者适用于通过set来设置值 * @param key 键 * @return */ public static boolean existsObject(String key) { boolean result = false; Jedis jedis = null; try { jedis = getResource(); result = jedis.exists(getBytesKey(key)); logger.debug("existsObject {}", key); } catch (Exception e) { logger.warn("existsObject {}", key, e); } finally { returnResource(jedis); } return result; }
后话:为什么服务重启完之后,log不再激增了,通过查看日志,那个select * from T_MERCHANT where MER_ID=?的方法不再执行了。显然,kill掉进程后,那些工作线程也都跟着死掉了。重启后,没有业务操作触发这个方法的执行,所以,日志量不再激增了。