一次mysql驅動版本不一致導致的問題 Arthas
阿新 • • 發佈：2022-05-30
現象
我們發版都是多組伺服器每次發一組,驗一組,然後nginx停掉流量保證使用者不會請求到這組機器,同時dubbo內部做版本隔離
1.某天發版出現大量異常 奇怪的除了新版本報錯,老版本也報這個錯
當時很擔心無法做回退,嘗試停掉新的發老的就不再報錯,因為考慮到全發新的 啟動時間太長,影響使用者使用選擇了放棄發版後續測試環境模擬 復現排查,慶幸測試環境按照同樣方式復現了
[DubboServerHandler-10.42.5.55:20930-thread-5] 709810 ERROR 2022-05-30 10:49:03,553 com.ewei.support.spring.hibernate.HibernateTemplate:49 <0><T1531105378825478144> doExecute error, sql=SELECT provider0_.id AS id1_88_0_, provider0_.alone_domain AS alone_do2_88_0_, provider0_.contact_name AS contact_3_88_0_, provider0_.contact_phone AS contact_4_88_0_, provider0_.created_at AS created_5_88_0_ , provider0_.employees AS employee6_88_0_, provider0_.independent AS independ7_88_0_, provider0_.is_alone_domain_checked AS is_alone8_88_0_, provider0_.is_info_completed AS is_info_9_88_0_, provider0_.is_open_helpcenter AS is_open10_88_0_ , provider0_.is_open_resources AS is_open11_88_0_, provider0_.is_open_sms_notify AS is_open12_88_0_, provider0_.name AS name13_88_0_, provider0_.phone AS phone14_88_0_, provider0_.record_number AS record_15_88_0_ , provider0_.sub_domain AS sub_dom16_88_0_, provider0_.update_at AS update_17_88_0_, provider0_.valid AS valid18_88_0_, provider0_.wx_cropid AS wx_crop19_88_0_ FROM provider provider0_ WHERE provider0_.id= 7893 org.springframework.orm.hibernate4.HibernateObjectRetrievalFailureException: No row with the given identifier exists: [com.ewei.account.api.entity.Provider#7893]; nested exception is org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [com.ewei.account.api.entity.Provider#7893] at org.springframework.orm.hibernate4.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:194) at org.springframework.orm.hibernate4.HibernateTemplate.doExecute(HibernateTemplate.java:343) at com.ewei.support.spring.hibernate.HibernateTemplate.doExecute(HibernateTemplate.java:32) at org.springframework.orm.hibernate4.HibernateTemplate.executeWithNativeSession(HibernateTemplate.java:308) at org.springframework.orm.hibernate4.HibernateTemplate$$FastClassBySpringCGLIB$$9cb7880b.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:708) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.budo.graph.druid.spring.aop.interceptor.BudoGraphDruidSpringAopInterceptor.invoke(BudoGraphDruidSpringAopInterceptor.java:58) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:644) at com.ewei.support.spring.hibernate.HibernateTemplate$$EnhancerBySpringCGLIB$$37b9f0f6.executeWithNativeSession(<generated>) at com.ewei.support.dao.hibernate.HibernateDao.findByHql(HibernateDao.java:242) at com.ewei.support.dao.hibernate.AbstractDao.findByHql(AbstractDao.java:82) at com.ewei.helpcenter.dao.impl.HelpCenterDaoImpl.findByProviderId(HelpCenterDaoImpl.java:39) at com.ewei.helpcenter.dao.impl.HelpCenterDaoImpl$$FastClassBySpringCGLIB$$6ed9eff7.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:708) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.budo.graph.druid.spring.aop.interceptor.BudoGraphDruidSpringAopInterceptor.invoke(BudoGraphDruidSpringAopInterceptor.java:58) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:644) at com.ewei.helpcenter.dao.impl.HelpCenterDaoImpl$$EnhancerBySpringCGLIB$$9ed95b34.findByProviderId(<generated>) at com.ewei.helpcenter.service.impl.HelpCenterServiceImpl.findByProviderId(HelpCenterServiceImpl.java:101) at com.ewei.helpcenter.service.impl.HelpCenterServiceImpl$$FastClassBySpringCGLIB$$43f95f97.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:708) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.budo.graph.druid.spring.aop.interceptor.BudoGraphDruidSpringAopInterceptor.invoke(BudoGraphDruidSpringAopInterceptor.java:58) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.cache.interceptor.CacheInterceptor$1.invoke(CacheInterceptor.java:52) at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:185) at org.springframework.cache.interceptor.CacheInterceptor.invoke(CacheInterceptor.java:60) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:644) at com.ewei.helpcenter.service.impl.HelpCenterServiceImpl$$EnhancerBySpringCGLIB$$38be7f2c.findByProviderId(<generated>) at com.alibaba.dubbo.common.bytecode.Wrapper16.invokeMethod(Wrapper16.java) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:45) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:71) at com.alibaba.dubbo.config.invoker.DelegateProviderMetaDataInvoker.invoke(DelegateProviderMetaDataInvoker.java:48) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:52) at org.budo.dubbo.protocol.http.exception.filter.BudoExceptionFilter.invoke(BudoExceptionFilter.java:45) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.ewei.support.dubbo.filter.entitywriteback.ProviderSideEntityWriteBackFilter.invoke(ProviderSideEntityWriteBackFilter.java:26) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.ewei.support.dubbo.filter.anchor.ProviderSideLoggerAnchorFilter.invoke(ProviderSideLoggerAnchorFilter.java:27) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:41) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:77) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at org.budo.graph.druid.dubbo.filter.BudoGraphDruidDubboProviderSideFilter.invoke(BudoGraphDruidDubboProviderSideFilter.java:88) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:74) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.ewei.common.tlog.EweiTLogDubboFilter.invoke(EweiTLogDubboFilter.java:64) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:131) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:37) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:37) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:68) at org.budo.dubbo.protocol.dubbo.AbstractBudoDubboProtocol$1.reply(AbstractBudoDubboProtocol.java:100) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:96) at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:168) at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:50) at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:79) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [com.ewei.account.api.entity.Provider#7893] at org.hibernate.internal.SessionFactoryImpl$1$1.handleEntityNotFound(SessionFactoryImpl.java:253) at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:218) at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:274) at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:150) at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1070) at org.hibernate.internal.SessionImpl.internalLoad(SessionImpl.java:989) at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:716) at org.hibernate.type.EntityType.resolve(EntityType.java:502) at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:170) at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:144) at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.performTwoPhaseLoad(AbstractRowReader.java:244) at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.finishUp(AbstractRowReader.java:215) at org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl.extractResults(ResultSetProcessorImpl.java:140) at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:138) at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:102) at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.loadEntityBatch(AbstractLoadPlanBasedEntityLoader.java:145) at org.hibernate.loader.entity.plan.LegacyBatchingEntityLoaderBuilder$LegacyBatchingEntityLoader.load(LegacyBatchingEntityLoaderBuilder.java:116) at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4126) at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:502) at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:467) at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:212) at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:274) at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:150) at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1070) at org.hibernate.internal.SessionImpl.internalLoad(SessionImpl.java:989) at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:716) at org.hibernate.type.EntityType.resolve(EntityType.java:502) at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:170) at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:144) at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:1114) at org.hibernate.loader.Loader.processResultSet(Loader.java:972) at org.hibernate.loader.Loader.doQuery(Loader.java:920) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:354) at org.hibernate.loader.Loader.doList(Loader.java:2553) at org.hibernate.loader.Loader.doList(Loader.java:2539) at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2369) at org.hibernate.loader.Loader.list(Loader.java:2364) at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:496) at com.ewei.support.hibernate.hql.internal.ast.AbstractQueryTranslator.list(AbstractQueryTranslator.java:325) at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:231) at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1264) at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103) at org.hibernate.internal.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:966) at com.ewei.support.hibernate.wrapper.QueryWrapper.uniqueResult(QueryWrapper.java:160) at com.ewei.support.dao.hibernate.HibernateDao$3.doInHibernate(HibernateDao.java:248) at org.springframework.orm.hibernate4.HibernateTemplate.doExecute(HibernateTemplate.java:340) ... 73 more
1.因為是hibernate這種錯誤一般是級聯查詢沒有查詢到資料導致的,我們去資料庫查詢資料發現有資料
3.懷疑是hibernate級聯沒查詢到資料 或者底層發sql到資料庫服務出現了啥問題
如:
1.最終傳送sql的引數不一致
2.查詢到資料，在框架內部處理過程中resultSet被讀了。或者讀出資料處理過程中丟掉了
級聯觸發位置 org.hibernate.engine.internal.TwoPhaseLoad#doInitializeEntity #級聯複用連線的地方 org.hibernate.engine.jdbc.internal.LogicalConnectionImpl#getConnection #代理的statement com.alibaba.druid.pool.DruidPooledPreparedStatement#DruidPooledPreparedStatement #執行statement的地方 org.hibernate.engine.jdbc.internal.ResultSetReturnImpl#extract(java.sql.PreparedStatement) #最終statement com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl#executeQuery -> com.alibaba.druid.filter.FilterChainImpl#preparedStatement_executeQuery
4.跟原始碼跟到最終傳送sql的statement sql和資料都是一致,通過Arthas增加日誌發現確實沒有查詢到資料
準備嘗試使用tcp抓包看發給mysql 的包裡面sql和引數正常不
5.後面發現老版本和新版本驅動不一致
非spring boot看lib spring boot專案解壓jar包看lib依賴
6.想起內部框架在做版本統一的時候升級過版本
之前依賴版本都是單獨定義的一個定義的是5.1.18一個定義的是5.1.40 然後統一通過父pom繼承改成了5.1.40
6.統一了mysql版本不再報錯
問題原因
專案mysql驅動版本不一致導致的
mysql-connector-java 老版本5.1.18 新版本5.1.40 其他版本不得而知沒搭配過
只有使用阿里雲資料庫的情況會這樣,改成普通自建資料庫沒有出現錯誤
反思
1.版本改動，每個改動還是要記錄一下change-log,當時想著這種版本升級理論是不會出問題 就沒有記,如果寫了change-log如果早點回頭看change-log可能會懷疑到這個地方
如: