现象
我们发版都是多组服务器每次发一组,验一组,然后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可能会怀疑到这个地方
如: