druid拋出的異常------javax.management.InstanceAlreadyExistsException引發的一系列探索
最近項目中有個定時任務的需求，定時檢查mysql數據與etcd數據的一致性，具體實現細節就不說了，今天要說的就是實現過程中遇到了druid拋出的異常，以及解決的過程
異常
異常詳細信息
五月 05, 2017 4:16:00 下午 com.alibaba.druid.proxy.DruidDriver warn 警告: register druid-driver mbean error javax.management.InstanceAlreadyExistsException: com.alibaba.druid:type=DruidDriver at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:View Code437) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) at com.alibaba.druid.proxy.DruidDriver.registerDriver(DruidDriver.java:99) at com.alibaba.druid.proxy.DruidDriver$1.run(DruidDriver.java:84) at java.security.AccessController.doPrivileged(Native Method) at com.alibaba.druid.proxy.DruidDriver.<clinit>(DruidDriver.java:81) at com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:579) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:986) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:982) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:102) at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:211) at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:447) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656) at com.huawei.wgp.task.TaskDbEtcdConsistencyCheck$$EnhancerBySpringCGLIB$$e1d6d636.consistencyCheck(<generated>) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 五月 05, 2017 4:16:00 下午 com.alibaba.druid.stat.DruidDataSourceStatManager error 嚴重: register mbean error javax.management.InstanceAlreadyExistsException: com.alibaba.druid:type=DruidDataSourceStat at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) at com.alibaba.druid.stat.DruidDataSourceStatManager.addDataSource(DruidDataSourceStatManager.java:139) at com.alibaba.druid.pool.DruidDataSource$1.run(DruidDataSource.java:1446) at java.security.AccessController.doPrivileged(Native Method) at com.alibaba.druid.pool.DruidDataSource.registerMbean(DruidDataSource.java:1442) at com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:706) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:986) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:982) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:102) at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:211) at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:447) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656) at com.huawei.wgp.task.TaskDbEtcdConsistencyCheck$$EnhancerBySpringCGLIB$$e1d6d636.consistencyCheck(<generated>) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745)
出現場景
當前開發只是定時任務，那麽工程啟動後一直在等定時任務的啟動，沒有進行其他任何的操作，而一旦定時任務啟動就出現如上異常信息，但是定時任務正常執行完成，並且不影響應用的其他任何服務，就和沒拋異常一樣！
從druid下手分析
程序員多多少少都有強迫癥，看不得出現異常。雖說上述的異常不影響應用，但拋出來了就給我一種不爽的感覺，強迫自己解決它。
所有的異常信息都將矛頭指向了druid，那麽我們就從druid下手。很幸運，網上這方面的資料有不少，最後在druid的github上找到了javax.management.InstanceAlreadyExistsException異常的問題和CentOS release 6.5 總是拋InstanceAlreadyExistsException這兩篇issue，一篇說把spring的自動探測關閉掉，一篇說應用容器中同一實例被啟動了兩遍，引起的並發執行了兩個定時任務；同一實例被啟動了兩遍，這個應該不可能，就不去探究了（真不用探究嗎）；那麽我們將spring的自動探測關閉掉試試，結果定時任務還是執行了兩遍。按照網上提供的其他方式也沒能解決這個問題，本以為這個問題要求助領導了，可上天還是眷顧我的。
一次偶然的巧合，我在定時任務啟動前，從瀏覽器請求了我的應用，再當定時任務啟動的時候，異常沒有產生，更巧合的是，數據庫中的數據在瀏覽器上顯示重復了，也就說定時任務產生了兩份相同的數據插入到了數據庫中，定時任務還是執行了兩次！ 這麽說來，異常的產生和druid沒關系，很有可能是定時任務的原因。
那麽問題就轉移了，從druid轉移到定時任務了。
從定時任務下手分析
1、不加定時任務
<?xml version="1.0" encoding="UTF-8"?> <beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:context="http://www.springframework.org/schema/context" xmlns:task="http://www.springframework.org/schema/task" xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.1.xsd http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.1.xsd http://www.springframework.org/schema/task http://www.springframework.org/schema/task/spring-task-3.1.xsd"> <!-- <bean id="taskDbEtcdConsistencyCheck" class="com.yzb.wgp.task.TaskDbEtcdConsistencyCheck" /> <task:scheduled-tasks scheduler="schedulerDbEtcdConsistencyCheck"> <task:scheduled ref="taskDbEtcdConsistencyCheck" method="consistencyCheck" cron="0 58 23 * * ?" /> </task:scheduled-tasks> <task:scheduler id="schedulerDbEtcdConsistencyCheck" pool-size="2" /> --> </beans>
結果是：啟動之後，不請求應用則dataSource-1不初始化，請求應用，dataSource-1只初始化一次
五月 08, 2017 8:56:12 上午 com.alibaba.druid.pool.DruidDataSource info
信息: {dataSource-1} inited
這個很好理解，連接池采用了懶加載，真正用到的時候才初始化
2、加定時任務
a)、定時任務啟動前，向應用SLBAdmin發送請求
結果是：請求的時候初始化dataSource-1一次，接著執行一次定時任務，然後又初始化一次dataSource-1，最後執行一次定時任務
五月 08, 2017 9:21:02 上午 com.alibaba.druid.pool.DruidDataSource info 信息: {dataSource-1} inited 定時任務... 五月 08, 2017 9:22:00 上午 com.alibaba.druid.pool.DruidDataSource info 信息: {dataSource-1} inited 定時任務...
這就有了疑問：
1、定時任務為什麽啟動了2次
2、dataSource-1為什麽會初始化2次，照理說應該只初始化一次，這個兩次是怎麽出現的了，感覺初始化3次都比初始化2次好理解(一次初始化對應所有前端請求，另外2次初始化分別對應兩次定時任務)
3、沒有拋異常：javax.management.InstanceAlreadyExistsException，這又是為什麽了
b)、定時任務啟動前，不向應用SLBAdmin發送任何請求
結果是：先出現異常 ，再初始化dataSource-1兩次，最後定時任務執行兩次
異常信息：略，在上面有 五月 08, 2017 9:38:00 上午 com.alibaba.druid.pool.DruidDataSource info 信息: {dataSource-1} inited 五月 08, 2017 9:38:00 上午 com.alibaba.druid.pool.DruidDataSource info 信息: {dataSource-1} inited 定時任務... 定時任務...
這也有了疑問：
1、這裏為什麽出現異常，而且這個異常沒有終止應用程序，應用程序還是能夠正常提供服務
2、為什麽是初始化dataSource-1兩次後調用兩次定時任務，而不是像a)那樣初始化一次dataSource-1，調用一次定時任務，再初始化一次dataSource-1，再調用一次定時任務
3、分析
<bean id="taskDbEtcdConsistencyCheck" class="com.yzb.wgp.task.TaskDbEtcdConsistencyCheck" />
<task:scheduled-tasks>
<task:scheduled ref="taskDbEtcdConsistencyCheck" method="consistencyCheck" cron="0 07 10 * * ?" />
</task:scheduled-tasks>
<task:scheduler id="schedulerConsistencyCheck" pool-size="1"/>
System.out.println("Thread-id=" + Thread.currentThread().getId() + " ThreadName=" + Thread.currentThread().getName() + " : 定時任務...");
將執行定時任務的線程id及線程名打印出來，配置及打印代碼如上，結果和 2、加定時任務 一樣， 只是有我們需要的信息：
Thread-id=17 ThreadName=pool-1-thread-1 : 定時任務...
Thread-id=18 ThreadName=pool-2-thread-1 : 定時任務...
線程id不同，線程池也不同，那麽就說明這是兩個不同的線程(線程名相同只是spring采用了默認的命名規則，如果我們在配置文件中指定線程的名字，那麽線程名也是相同的)，這就證明不是同一個線程調用了兩次目標方法，那麽問題又來了：怎麽會產生兩個定時任務的線程了
我們來列舉下可能兩個線程的產生的場景：
i、配置了兩個定時任務，目標類和目標方法是同一個，同時同一時間點執行，像如下配置
<bean id="taskDbEtcdConsistencyCheck" class="com.huawei.wgp.task.TaskDbEtcdConsistencyCheck" />
<task:scheduled-tasks>
<task:scheduled ref="taskDbEtcdConsistencyCheck" method="consistencyCheck" cron="0 07 10 * * ?" />
<task:scheduled ref="taskDbEtcdConsistencyCheck" method="consistencyCheck" cron="0 07 10 * * ?" />
</task:scheduled-tasks>
<task:scheduler id="schedulerConsistencyCheck" pool-size="2"/>
ii、應用中只有一個定時任務，但是應用被tomcat啟動了兩遍
i場景很容易排除，定時任務的配置文件內容很少，很容易排查；但是ii場景是怎麽產生的了，那麽我們去看下tomcat的應用列表
a)、不加定時任務
b)、定時任務啟動前，向應用SLBAdmin發送請求
c)、定時任務啟動前，不向應用SLBAdmin發送請求
註意上面三張圖片中標紅的地方，理論上來講，每張圖片的第二處標紅的地方是不應該出現的，也就是Path為wgp-Web的那一行應該是不存在的，那麽它是怎麽出現的了？ 我們來看下我們的工程
這種不一致是怎麽產生的了，工程名和發布路徑一開始都是叫wgp-Web，後面發布路徑改成了SLBAdmin，而工程名沒有改，就導致了這種不一致。那麽我們將工程名也改成SLBAdmin，再看看tomcat應用列表
應用列表正常，而SLBAdmin應用也達到了預料中的正常，既沒有拋出異常，定時任務也只在定點執行了一次。
疑問解答
定時任務啟動前，向應用SLBAdmin發送請求
1、定時任務為什麽啟動了2次
解答：應用容器中同一實例被啟動了兩遍，導致並發執行了兩個定時任務。
2、dataSource-1為什麽會初始化2次，照理說應該只初始化一次，這個兩次是怎麽出現的了，感覺初始化3次都比初始化2次好理解(一次初始化對應所有前端請求，另外2次初始化分別對應兩次定時任務)
解答：因為在定時任務啟動前請求了應用SLBAdmin，spring初始化了SLBAdmin的dataSource-1，當SLBAdmin定時任務啟動的時候，就不會再去初始化SLBAdmin的dataSource-1了；但是容器中還存在wgp-Web的定時任務，當到達定點時，SLBAdmin的定時任務和wgp-Web的定時任務會同時並發啟動，由於wgp-Web的dataSource-1還沒有初始化，所以定時任務執行時初始化wgp-Web的dataSource-1。
3、沒有拋異常：javax.management.InstanceAlreadyExistsException，這又是為什麽了
解答：dataSource-1的初始化不是同時並發進行的，SLBAdmin在請求的時候初始化dataSource-1，在定時任務執行前，而wgp-Web是在定時任務啟動的時候初始化的， spring會根據這個時間差來使得兩次連接池的獲取指向同一個連接池。這個答案是我猜想的，真正知道原因的朋友可以留個言！
定時任務啟動前，不向應用SLBAdmin發送請求
1、這裏為什麽出現異常，而且這個異常沒有終止應用程序，應用程序還是能夠正常提供服務
解答：dataSource-1的初始化是同時並發進行的，這個更應該說是spring的bug，spring將實現了符合MBean規範的beans註冊到mbeanserver中，但沒處理好異常，所以悲劇了； 也就是說druid是沒有問題的，那麽服務是能正常提供的。
2、為什麽是初始化dataSource-1兩次後調用兩次定時任務，而不是像a)那樣初始化一次dataSource-1，調用一次定時任務，再初始化一次dataSource-1，再調用一次定時任務
解答：兩個定時任務是在同一個定點執行，所以dataSource-1的初始化是同時並發進行的； 而a)中SLBAdmin是在定時任務執行前響應了請求，並初始化了dataSource-1，wgp-Web是在定時任務執行時初始化的dataSource-1。
為什麽之前的版本沒有出現這個問題了：之前的版本沒有定時任務，另外，轉測試版本和上線版本的Path與Display Name是一致的，都是SLBAdmin
總結
問題產生的根本原因還真是：同一實例被啟動了兩遍，Path為/SLBAdmin啟動一次，Path為/wgp-Web啟動一次，
開發過程中最好保證工程名與發布路徑保證一直，避免不必要的麻煩
參考
https://github.com/alibaba/druid/issues/1200
https://github.com/alibaba/druid/issues/538
http://jingyan.baidu.com/article/48206aeaf9422e216ad6b39b.html
https://my.oschina.net/superkangning/blog/467487
druid拋出的異常------javax.management.InstanceAlreadyExistsException引發的一系列探索