LinkageError问题处理（DataLink项目）

拼搏现实的明天。 2022-09-09 14:50 64阅读 0赞

### LinkageError问题处理 ###

*  一、问题日志现象
 *  二、解决方法
 *  三、问题背景
 *  四、参考

# 一、问题日志现象 #

2021-09-02 16:03:32.096 [Task-1-Wirter-writer-rdbms] INFO  com.ucar.datalink.worker.core.runtime.WorkerTaskWriter - TaskWriter-writer-rdbms has stopped executing.
    2021-09-02 16:03:32.097 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.worker.core.runtime.WorkerTaskReader - TaskReader-reader-mysql has stopped executing.
    Exception in thread "Task-1-Wirter-writer-kafka" com.google.common.util.concurrent.ExecutionError: java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of com/ucar/datalink/worker/core/util/classloader/DevPluginClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2201) at com.google.common.cache.LocalCache.get(LocalCache.java:3937) at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3941) at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4824) at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4830) at com.ucar.datalink.worker.api.task.TaskWriter.doPush(TaskWriter.java:77) at com.ucar.datalink.worker.api.task.TaskWriter.push(TaskWriter.java:63) at com.ucar.datalink.worker.core.runtime.WorkerTaskWriter.execute(WorkerTaskWriter.java:74) at com.ucar.datalink.worker.core.runtime.WorkerTask.doRun(WorkerTask.java:186) at com.ucar.datalink.worker.core.runtime.WorkerTask.run(WorkerTask.java:234) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of com/ucar/datalink/worker/core/util/classloader/DevPluginClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature
    	at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:335)
    	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:283)
    	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:304)
    	at com.ucar.datalink.writer.kafka.handle.RdbEventRecordHandler.<clinit>(RdbEventRecordHandler.java:30)
    	at com.ucar.datalink.writer.kafka.KafkaTaskWriter.getHandler(KafkaTaskWriter.java:20)
    	at com.ucar.datalink.worker.api.task.TaskWriter$1.load(TaskWriter.java:39)
    	at com.ucar.datalink.worker.api.task.TaskWriter$1.load(TaskWriter.java:36)
    	at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527)
    	at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319)
    	at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282)
    	at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197)
    	... 10 more
    2021-09-02 16:03:32.758 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.MysqlTaskPositionManager - Mysql Task Position Manager shutdown.
    2021-09-02 16:03:32.758 [Task-Container-pool-2] INFO  c.ucar.datalink.worker.core.runtime.TaskPositionManager - Position is discarded for task 1
    2021-09-02 16:03:32.760 [WorkerKeeper] INFO  c.u.datalink.worker.core.runtime.coordinate.WorkerKeeper - Starting task 1
    2021-09-02 16:03:32.760 [WorkerKeeper] INFO  com.ucar.datalink.worker.core.runtime.Worker - Preparing task 1.
    2021-09-02 16:03:32.761 [WorkerKeeper] INFO  com.ucar.datalink.biz.service.impl.MediaServiceImpl - Mapping cache has been cleared for taskId:1
    2021-09-02 16:03:32.761 [WorkerKeeper] INFO  com.ucar.datalink.worker.core.runtime.Worker - Creating task 1.
    2021-09-02 16:03:32.761 [WorkerKeeper] INFO  com.ucar.datalink.worker.core.runtime.Worker - Initializing task 1, reader parameter is { "@type":"com.ucar.datalink.domain.plugin.reader.mysql.MysqlReaderParameter","batchTimeout":-1,"blackFilter":".*\\._.*","ddlSync":true,"defaultConnectionTimeoutInSeconds":30,"detectingIntervalInSeconds":3,"detectingRetryTimes":3,"detectingSQL":"select 1","detectingTimeoutThresholdInSeconds":30,"dump":false,"dumpDetail":false,"fallbackIntervalInSeconds":60,"groupSinkMode":"Coordinate","gtidEnable":false,"mediaSourceId":1,"memoryStorageBufferMemUnit":1024,"memoryStorageBufferSize":32768,"messageBatchSize":2000,"multiplexingRead":false,"parallel":false,"perfStatistic":false,"pluginClass":"com.ucar.datalink.reader.mysql.MysqlTaskReader","pluginListenerClass":"com.ucar.datalink.reader.mysql.MysqlTaskReaderListener","pluginName":"reader-mysql","receiveBufferSize":65536,"sendBufferSize":65536,"startTimeStamps":1628668800000,"supportedSourceTypes":Set["MYSQL"]}, writer parameter is [{ "@type":"com.ucar.datalink.domain.plugin.writer.rdbms.RdbmsWriterParameter","batchSize":50,"dryRun":false,"maxRetryTimes":3,"merging":false,"perfStatistic":false,"pluginClass":"com.ucar.datalink.writer.rdbms.RdbmsTaskWriter","pluginListenerClass":"com.ucar.datalink.writer.rdbms.RdbmsTaskWriterListener","pluginName":"writer-rdbms","poolSize":5,"retryMode":"Always","supportedSourceTypes":Set["SQLSERVER","SDDL","MYSQL","POSTGRESQL"],"syncAutoAddColumn":true,"syncMode":"TablePartlyOrdered","useBatch":false,"useUpsert":false},{ "@type":"com.ucar.datalink.domain.plugin.writer.kafka.KafkaWriterParameter","batchSize":50,"dryRun":false,"maxRetryTimes":3,"merging":true,"partitionMode":"COLUMN","perfStatistic":false,"pluginClass":"com.ucar.datalink.writer.kafka.KafkaTaskWriter","pluginListenerClass":"com.ucar.datalink.writer.kafka.KafkaTaskWriterListener","pluginName":"writer-kafka","poolSize":5,"retryMode":"Always","serializeMode":"Hessian","supportedSourceTypes":Set["KAFKA"],"syncAutoAddColumn":true,"useBatch":true}].
    2021-09-02 16:03:32.762 [WorkerKeeper] INFO  com.ucar.datalink.worker.core.runtime.Worker - Submitting task 1.
    2021-09-02 16:03:32.762 [WorkerKeeper] INFO  com.ucar.datalink.worker.core.runtime.Worker - Saving task 1.
    2021-09-02 16:03:32.762 [qtp253722034-34] INFO  c.u.d.worker.core.runtime.rest.resources.TasksResource - Restart task succeed,with id 1
    2021-09-02 16:03:32.765 [Task-1-Wirter-writer-rdbms] INFO  com.ucar.datalink.worker.core.runtime.WorkerTaskWriter - TaskWriter-writer-rdbms finished initialization and start.
    2021-09-02 16:03:32.765 [Task-1-Wirter-writer-kafka] INFO  com.ucar.datalink.worker.core.runtime.WorkerTaskWriter - TaskWriter-writer-kafka finished initialization and start.
    2021-09-02 16:03:32.766 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.MysqlTaskReader - there is no task shadow to process.
    2021-09-02 16:03:32.766 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.MysqlTaskPositionManager - Mysql Task Position Manager started.
    2021-09-02 16:03:32.773 [qtp253722034-34] INFO  com.ucar.datalink.worker.core.runtime.rest.RestServer - 10.10.12.43 - - [02/九月/2021:08:03:31 +0000] "POST /tasks/1/restart HTTP/1.1" 204 -  937
    2021-09-02 16:03:32.793 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.CanalReaderFilterBuilder - The filter for destination 1-main is test1.t_dl_test_attr,test1.t_dl_test_source.
    2021-09-02 16:03:32.795 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.CanalReader - multiplexing read switch for destination 1-main is false.
    2021-09-02 16:03:32.796 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.CanalReader - init eventSink begin...
    2021-09-02 16:03:32.796 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.CanalReader - init eventSink end! 
    	 load CanalEventSink:com.alibaba.otter.canal.sink.entry.EntryEventSink
    2021-09-02 16:03:32.796 [Task-1-Reader-reader-mysql] INFO  c.u.d.reader.mysql.extend.CustomCanalInstanceWithManager - init eventParser begin...
    2021-09-02 16:03:32.796 [Task-1-Reader-reader-mysql] INFO  c.u.d.reader.mysql.extend.CustomCanalInstanceWithManager - init event parser in common mode.
    2021-09-02 16:03:32.796 [Task-1-Reader-reader-mysql] INFO  c.u.d.reader.mysql.extend.CustomCanalInstanceWithManager - init eventParser end! 
    	 load CanalEventParser:com.alibaba.otter.canal.parse.inbound.mysql.MysqlEventParser
    2021-09-02 16:03:32.797 [Task-1-Reader-reader-mysql] WARN  c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table filter : ^test1.t_dl_test_source$|^test1.t_dl_test_attr$
    2021-09-02 16:03:32.797 [Task-1-Reader-reader-mysql] WARN  c.a.o.canal.parse.inbound.mysql.dbsync.LogEventConvert - --> init table black filter : ^.*\._.*$
    2021-09-02 16:03:32.797 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.reader.mysql.CanalReaderMetaManager - ClientIdentity is initialized for destination 1-main.
    2021-09-02 16:03:32.798 [Task-1-Reader-reader-mysql] INFO  com.ucar.datalink.worker.core.runtime.WorkerTaskReader - TaskReader-reader-mysql finished initialization and start.
    2021-09-02 16:03:37.807 [destination = 1-main , address = localhost/127.0.0.1:3306 , EventParser] WARN  c.a.otter.canal.parse.inbound.mysql.MysqlEventParser - ---> begin to find start position, it will be long time for reset or first position
    2021-09-02 16:03:37.808 [destination = 1-main , address = localhost/127.0.0.1:3306 , EventParser] WARN  c.a.otter.canal.parse.inbound.mysql.MysqlEventParser - prepare to find start position just last position
     { "identity":{ "slaveId":-1,"sourceAddress":{ "address":"localhost","port":3306}},"postion":{ "gtid":"","included":false,"journalName":"mysql-bin.000007","position":500106,"serverId":1,"timestamp":1630569779000}}
    2021-09-02 16:03:37.808 [destination = 1-main , address = localhost/127.0.0.1:3306 , EventParser] WARN  c.a.otter.canal.parse.inbound.mysql.MysqlEventParser - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.000007,position=500106,serverId=1,gtid=,timestamp=1630569779000] cost : 1ms , the next step is binlog dump
    2021-09-02 16:03:37.821 [Task-1-Wirter-writer-rdbms] INFO  com.ucar.datalink.worker.api.handle.AbstractHandler - CorePoolSize for recordChunkExecutor is 1.
    2021-09-02 16:03:37.822 [Task-1-Wirter-writer-kafka] ERROR com.ucar.datalink.worker.core.runtime.WorkerTask - Task 1 threw an uncaught and unrecoverable errors
    com.google.common.util.concurrent.ExecutionError: java.lang.NoClassDefFoundError: Could not initialize class com.ucar.datalink.writer.kafka.handle.RdbEventRecordHandler
    	at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2201) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache.get(LocalCache.java:3937) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3941) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4824) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4830) ~[guava-18.0.jar:na]
    	at com.ucar.datalink.worker.api.task.TaskWriter.doPush(TaskWriter.java:77) ~[classes/:na]
    	at com.ucar.datalink.worker.api.task.TaskWriter.push(TaskWriter.java:63) ~[classes/:na]
    	at com.ucar.datalink.worker.core.runtime.WorkerTaskWriter.execute(WorkerTaskWriter.java:74) ~[classes/:na]
    	at com.ucar.datalink.worker.core.runtime.WorkerTask.doRun(WorkerTask.java:186) [classes/:na]
    	at com.ucar.datalink.worker.core.runtime.WorkerTask.run(WorkerTask.java:234) [classes/:na]
    	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_271]
    Caused by: java.lang.NoClassDefFoundError: Could not initialize class com.ucar.datalink.writer.kafka.handle.RdbEventRecordHandler
    	at com.ucar.datalink.writer.kafka.KafkaTaskWriter.getHandler(KafkaTaskWriter.java:20) ~[classes/:na]
    	at com.ucar.datalink.worker.api.task.TaskWriter$1.load(TaskWriter.java:39) ~[classes/:na]
    	at com.ucar.datalink.worker.api.task.TaskWriter$1.load(TaskWriter.java:36) ~[classes/:na]
    	at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282) ~[guava-18.0.jar:na]
    	at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197) ~[guava-18.0.jar:na]
    	... 10 common frames omitted

# 二、解决方法 #

在这两个依赖包下增加了依赖排除后，重新编译打包，问题不出现了。

<dependency>
                <groupId>com.caucho</groupId>
                <artifactId>hessian</artifactId>
                <version>4.0.7</version>
                <exclusions>
                    <exclusion>
                        <artifactId>slf4j-api</artifactId>
                        <groupId>org.slf4j</groupId>
                    </exclusion>
                </exclusions>
            </dependency>
    
            <dependency>
                <groupId>org.apache.kafka</groupId>
                <artifactId>kafka-clients</artifactId>
                <version>2.2.1</version>
                <exclusions>
                    <exclusion>
                        <artifactId>slf4j-api</artifactId>
                        <groupId>org.slf4j</groupId>
                    </exclusion>
                </exclusions>
            </dependency>

# 三、问题背景 #

该问题出现在datalink开源项目中，插件场景中有自定义类加载器，以下是类加载器类图  
![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16_pic_center]

![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16]  
类加载器继续结构  
![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16 1]

按条件debug  
![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16 2]

# 四、参考 #

[类似问题][Link 1]

[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16_pic_center]: /images/20220829/3789e02e262d4e4884cfe7fbae043f33.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16]: /images/20220829/20a822daecc9430f9a2735e5be845c9c.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16 1]: /images/20220829/bf3ea2e1ae03412589396869d69c0c78.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBA5bGx5beF_size_20_color_FFFFFF_t_70_g_se_x_16 2]: /images/20220829/1aa6a399a19b41ce9be0e08a2cddd82c.png
[Link 1]: https://stackoverflow.com/questions/18127431/spring-java-lang-linkageerror-loader-constraint-violation-loader-previously-in