17 記一次 NOAUTH Authentication required
redisNotAuth 的問題
大概是上週四的時候吧, 把專案打包之後上傳到測試伺服器, 然後啟動之後 出現了此異常
問題日誌 [省略若干]
[12-08 17:52:27.579 INFO ][SingletonRedisRegionFactory.java:41] - Starting SingletonRedisRegionFactory... [12-08 17:52:27.584 INFO ][JedisTool.java:129] - Loading cache properties...path=[properties/redis.properties] [12-08 17:52:27.586 WARN ][JedisTool.java:140] - Fail to load cache properties.cachePath=properties/redis.properties java.lang.NullPointerException atjava.util.Properties$LineReader.readLine(Properties.java:434) atjava.util.Properties.load0(Properties.java:353) atjava.util.Properties.load(Properties.java:341) atorg.hibernate.cache.redis.util.JedisTool.loadCacheProperties(JedisTool.java:138) atorg.hibernate.cache.redis.SingletonRedisRegionFactory.start(SingletonRedisRegionFactory.java:45) atorg.hibernate.internal.CacheImpl.<init>(CacheImpl.java:70) atorg.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:40) atorg.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:35) atorg.hibernate.service.internal.SessionFactoryServiceRegistryImpl.initiateService(SessionFactoryServiceRegistryImpl.java:91) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:251) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:225) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:206) atorg.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:273) atorg.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1859) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl$4.perform(EntityManagerFactoryBuilderImpl.java:857) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl$4.perform(EntityManagerFactoryBuilderImpl.java:850) atorg.hibernate.boot.registry.classloading.internal.ClassLoaderServiceImpl.withTccl(ClassLoaderServiceImpl.java:425) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:849) atorg.hibernate.jpa.HibernatePersistenceProvider.createContainerEntityManagerFactory(HibernatePersistenceProvider.java:152) atorg.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:343) atorg.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:318) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1637) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) atorg.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) atorg.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) atorg.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) atorg.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) atorg.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1054) atorg.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:829) atorg.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538) atorg.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444) atorg.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326) atorg.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107) atorg.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5068) atorg.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5584) atorg.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147) atorg.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899) atorg.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875) atorg.apache.catalina.core.StandardHost.addChild(StandardHost.java:652) atorg.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1092) atorg.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1984) atjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) atjava.util.concurrent.FutureTask.run(FutureTask.java:266) atjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) atjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) atjava.lang.Thread.run(Thread.java:745) [12-08 17:52:27.590 INFO ][JedisTool.java:59] - Creating JedisClient. [12-08 17:52:27.595 INFO ][JedisTool.java:86] - Creating JedisPool. host=[localhost], port=[6379],timeout=[2000], database=[0] [12-08 17:52:27.779 INFO ][SingletonRedisRegionFactory.java:47] - Started SingletonRedisRegionFactory [12-08 17:52:27.782 INFO ][UpdateTimestampsCache.java:72] - HHH000250: Starting update timestamps cacheat region: org.hibernate.cache.spi.UpdateTimestampsCache [12-08 17:52:27.789 INFO ][JedisTool.java:129] - Loading cache properties...path=[properties/redis.properties] [12-08 17:52:27.790 WARN ][JedisTool.java:140] - Fail to load cache properties.cachePath=properties/redis.properties java.lang.NullPointerException atjava.util.Properties$LineReader.readLine(Properties.java:434) atjava.util.Properties.load0(Properties.java:353) atjava.util.Properties.load(Properties.java:341) atorg.hibernate.cache.redis.util.JedisTool.loadCacheProperties(JedisTool.java:138) atorg.hibernate.cache.redis.AbstractRedisRegionFactory.loadCacheProperties(AbstractRedisRegionFactory.java:110) atorg.hibernate.cache.redis.AbstractRedisRegionFactory.buildTimestampsRegion(AbstractRedisRegionFactory.java:173) atorg.hibernate.cache.redis.SingletonRedisRegionFactory.buildTimestampsRegion(SingletonRedisRegionFactory.java:34) atorg.hibernate.cache.spi.UpdateTimestampsCache.<init>(UpdateTimestampsCache.java:73) atorg.hibernate.internal.CacheImpl.<init>(CacheImpl.java:72) atorg.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:40) atorg.hibernate.engine.spi.CacheInitiator.initiateService(CacheInitiator.java:35) atorg.hibernate.service.internal.SessionFactoryServiceRegistryImpl.initiateService(SessionFactoryServiceRegistryImpl.java:91) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:251) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:225) atorg.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:206) atorg.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:273) atorg.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1859) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl$4.perform(EntityManagerFactoryBuilderImpl.java:857) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl$4.perform(EntityManagerFactoryBuilderImpl.java:850) atorg.hibernate.boot.registry.classloading.internal.ClassLoaderServiceImpl.withTccl(ClassLoaderServiceImpl.java:425) atorg.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:849) atorg.hibernate.jpa.HibernatePersistenceProvider.createContainerEntityManagerFactory(HibernatePersistenceProvider.java:152) atorg.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:343) atorg.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:318) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1637) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) atorg.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) atorg.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) atorg.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) atorg.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) atorg.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) atorg.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1054) atorg.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:829) atorg.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538) atorg.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444) atorg.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326) atorg.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107) atorg.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5068) atorg.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5584) atorg.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147) atorg.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899) atorg.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875) atorg.apache.catalina.core.StandardHost.addChild(StandardHost.java:652) atorg.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1092) atorg.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1984) atjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) atjava.util.concurrent.FutureTask.run(FutureTask.java:266) atjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) atjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) atjava.lang.Thread.run(Thread.java:745) 省略若干和上面重複的日誌 [12-08 17:52:28.952 WARN ][JedisClient.java:374] - Error in Cache Expiration Method. redis.clients.jedis.exceptions.JedisDataException:NOAUTH Authentication required. atredis.clients.jedis.Protocol.processError(Protocol.java:117) atredis.clients.jedis.Protocol.process(Protocol.java:151) atredis.clients.jedis.Protocol.read(Protocol.java:205) atredis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:297) atredis.clients.jedis.Connection.getBinaryMultiBulkReply(Connection.java:233) atredis.clients.jedis.BinaryJedis.zrangeByScore(BinaryJedis.java:2099) atredis.clients.jedis.BinaryJedis.zrangeByScore(BinaryJedis.java:2093) atorg.hibernate.cache.redis.jedis.JedisClient$13.execute(JedisClient.java:354) atorg.hibernate.cache.redis.jedis.JedisClient$13.execute(JedisClient.java:351) atorg.hibernate.cache.redis.jedis.JedisClient.run(JedisClient.java:612) atorg.hibernate.cache.redis.jedis.JedisClient.expire(JedisClient.java:351) atorg.hibernate.cache.redis.AbstractRedisRegionFactory$1.run(AbstractRedisRegionFactory.java:207) atjava.lang.Thread.run(Thread.java:745) [12-08 17:52:28.954 WARN ][JedisClient.java:374] - Error in Cache Expiration Method. redis.clients.jedis.exceptions.JedisDataException:NOAUTH Authentication required. atredis.clients.jedis.Protocol.processError(Protocol.java:117) atredis.clients.jedis.Protocol.process(Protocol.java:151) atredis.clients.jedis.Protocol.read(Protocol.java:205) atredis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:297) atredis.clients.jedis.Connection.getBinaryMultiBulkReply(Connection.java:233) atredis.clients.jedis.BinaryJedis.zrangeByScore(BinaryJedis.java:2099) atredis.clients.jedis.BinaryJedis.zrangeByScore(BinaryJedis.java:2093) atorg.hibernate.cache.redis.jedis.JedisClient$13.execute(JedisClient.java:354) atorg.hibernate.cache.redis.jedis.JedisClient$13.execute(JedisClient.java:351) atorg.hibernate.cache.redis.jedis.JedisClient.run(JedisClient.java:612) atorg.hibernate.cache.redis.jedis.JedisClient.expire(JedisClient.java:351) atorg.hibernate.cache.redis.AbstractRedisRegionFactory$1.run(AbstractRedisRegionFactory.java:207) atjava.lang.Thread.run(Thread.java:745) 省略若干和上面重複的日誌
當時碰到這個問題的時候, 第一反應是下載對應的原始碼跟一根 然而無奈下載的太慢, 下班了
專案中, 配置檔案中指定"properties/redis.properties"的地方 大概是有兩處, 第一處是spring指定佔位符配置的位置, 另外一處是hibernate配置redis快取的配置的位置
我一直以為是配置佔位符配置的配置的地方出現的異常
然後回家之後 想了一下, 大概是 想了三種思路
1. 在我自己的虛擬機器上面釋出下專案看看有什麼問題
2. 跟蹤JedisTool的程式碼, 嘗試解決問題
3. 既然是Properties.load報了NPE, 那麼 應該是沒有找到對應的檔案吧, 因此 使用絕對路徑應該是可以解決的, 但是 這樣不好, 作為 實在解決不了問題的一種臨時思路
然後第二天來到公司, 準備弄一弄這個問題, 然後首先是下載了原始碼, 然後跟了一下JedisTool的相關程式碼
第一個框是獲取"hibernate.cache.provider_configuration_file_resource_path"的配置, 也就是這裡的"properties/redis.properties"
第二個框, 根據特定的配置格式執行不同的載入方法, 一種是從檔案系統載入, 另外一種使用classloader進行載入
第三個框就是我們報異常的地方, 走得是classloader載入配置, 然後獲取到的inputStream為null, 然後 load的時候就報了此異常
至此, 我才發現, 原來報異常的的配置是hibernate的快取配置, 而不是spring的佔位符的配置檔案
然後因此 我昨天思考的三個思路 就只能走走程式碼了,,
但是這裡出現了一個使用絕對路徑解決此問題的一個更加明顯的解決方式, 也就是這個使用檔案系統載入配置檔案的方式
因此我最開始就是使用的這個來臨時解決此問題
然後我跟了一下程式碼, 三個環境
1. 本地使用idea的釋出web專案的方式
Jdk1.8 + apache-tomcat-8.0.37
2. 測試伺服器 : jdk1.8 + tomcat 7.0.69.0
3. 我自己的虛擬機器 : jdk 1.8 + tomcat8.5.6
我本地以及vm環境和測試環境還有一個不同在於, 前者的所有依賴的包存在於war下面的WEB-INF/lib下面, 然後測試環境的依賴包除了部分會時常變動的包[我們的common], 之外其他的包存在於$CATALINA_HOME/lib下面 [注意這個區別]
然後 看到這三個不同的classloader,我就矇蔽了, 然後就沒有想這個問題了, 然後週末的時候 無意間想到了tomcat 的類載入器的體系, 然後 畫了一下, 但是 還是沒有怎麼想通
我順著各個伺服器的環境下面的classloader的”父子關係”往上走過
發現測試環境下面的的URLClassLoader其實就是tomcat中的CommonClassloader, 當然從上面的圖中也能夠看見
然後其他兩個環境下面的WebAppClassLoader就是各個webapp對應的WebAppClassloader
但是當時 還不知所以然, 就沒多想 然後 之後就到了今天下午
此圖來自於 : http://www.cnblogs.com/jiaan-geng/p/4860432.html
然後直到今天 我們test1環境也出現了這個異常
然後我做了兩次嘗試
1. 我比較了一下test1, test2的專案war包,發現除了基本的配置檔案存在差異 以及少量的版本提交的差異之外還有一個檔案存在差異 log4j.xml, 然後我想起了之前幾天leader將log4j的minLogLevel從error更新為了info, 查了一下提交日誌, 問題好像就是在更新了之後出現的誒
我就懷疑是否是這個可能導致載入JedisTool的類載入器出現了問題,
然後我將console的info更新回error, 然後啟動專案 果然就沒有 再報這個錯誤了
然後我猛的發覺過來,之前沒有報這個錯誤是不是因為輸出級別是error所以 才沒有把異常打印出來, 然後 我開啟 檔案形式記錄的日誌[輸出級別為info],剛才的啟動過程果然也出現了這個異常,, 我擦嘞看來我們伺服器是一直在報這個錯誤,只不過是我們將其日誌輸出關了。。然後因為這個配置是hibernate的快取配置,因此沒有對業務產生影響,因此就被忽略了
2. 將JedisTool所在的包[hiebernate-redis-xx.jar]移動到當前專案的/WEB-INF/lib下面, 然後 啟動專案就好了
這裡主要是是因為拿到“hibernate.cache.provider_configuration_file_resource_path”, 去讀取資料依賴於載入JedisTools的classloader
由於在測試伺服器環境下面, 所有的依賴的包都放在了 $CATALINA_HOME/lib下面, 由CommonClassloader載入了, 然後由CommonClassloader來找”properties/redis.properties”找不到, 因此 gg了
然後其他兩個環境下面載入JedisTool是由當前專案的WebAppClassloader載入的, 然後使用該classloader尋找“properties/redis.properties”能夠找到對應的資源, 完成了正常載入
對了最初的時候,我還懷疑過是不是環境的問題,然後我把vm上的環境複製了一份然後按照test環境部署了一下,然後 之後似乎啟動專案的時候報了log4j的異常吧,然後 專案沒有啟動起來,然後 有不太想去檢查環境 就算了
完