WeiYe-Jing / datax-web

DataX集成可视化页面,选择数据源即可一键生成数据同步任务,支持RDBMS、Hive、HBase、ClickHouse、MongoDB等数据源,批量创建RDBMS数据同步任务,集成开源调度系统,支持分布式、增量同步数据、实时查看运行日志、监控执行器资源、KILL运行进程、数据源信息加密等。
https://segmentfault.com/u/weiye_jing/articles
MIT License
5.57k stars 2.15k forks source link

偶现报错:XxlRpcException: xxl-rpc, request timeout at #68

Closed ZengRL closed 4 years ago

ZengRL commented 4 years ago

出现频率:偶现(低于1%) 邮件报错信息: msg:com.wugui.datax.rpc.util.XxlRpcException: xxl-rpc, request timeout at:1585273504252, request:XxlRpcRequest{requestId='761c6e38-1401-4a1c-b345-01ca66684054', createMillisTime=1585273501247, accessToken='', className='com.wugui.datatx.core.biz.ExecutorBiz', methodName='run', parameterTypes=[class com.wugui.datatx.core.biz.model.TriggerParam], parameters=[TriggerParam{jobId=152, executorHandler='executorJobHandler', executorParams='', executorBlockStrategy='DISCARD_LATER', executorTimeout=0, logId=2551329, logDateTime=1585273501000, glueType='BEAN', glueSource='null', glueUpdatetime=1582114646000, broadcastIndex=0, broadcastTotal=1, jobJson={ "job": { "setting": { "speed": { "channel": 16 } }, "content": [ { "reader": { "name": "mysqlreader", "parameter": { "username": "ods_readonly", "password": "IEOIXNo3QCKDbI4n1VYdYpSlGqGfmR3d", "connection": [ { "jdbcUrl": [ "jdbc:mysql://rm-2zen18ooiq4wsn0rj.mysql.rds.aliyuncs.com:3306/trade_hebei_prod?serverTimezone=Asia/Shanghai&useLegacyDatetimeCode=false&useSSL=false&nullNamePatternMatchesAll=true&useUnicode=true&characterEncoding=UTF-8" ], "querySql": [ "select id,created_by_id,created_time,updated_by_id,updated_time,data_flag,goods_47_kind_id,replace_kind_id,hxProductId,medicalAreaId,pack_convert_factor,replace_goods_id,replace_type,stand_spec_mg,superviseId,medicalConfigId,batch_type from p_goods_47_kind_replace_relation where (created_time >= FROM_UNIXTIME(${lastTime}-60) and created_time < FROM_UNIXTIME(${currentTime})) or (updated_time >= FROM_UNIXTIME(${lastTime}-60) and updated_time < FROM_UNIXTIME(${currentTime}))" ] } ] } }, "writer": { "name": "kafkawriter", "parameter": { "ack": "all", "batchSize": 2000000, "bootstrapServers": "192.168.1.246:9092,192.168.1.249:9092,192.168.1.248:9092", "fieldDelimiter": "#", "keySerializer": "org.apache.kafka.common.serialization.StringSerializer", "retries": 0, "transactionalId": "hb_trd_p_goods_47_kind_replace_relation_prod_trans_id", "topic": "hb_trd_p_goods_47_kind_replace_relation_prod_1", "writeType": "csv", "valueSerializer": "org.apache.kafka.common.serialization.StringSerializer", "columns": [ { "name": "id", "type": "Long" } ] } } } ] } }, processId=null, replaceParam=-DlastTime='%s' -DcurrentTime='%s', jvmParam=, startTime=Fri Mar 27 09:30:01 CST 2020, triggerTime=Fri Mar 27 09:45:01 CST 2020}], version='null'} at com.wugui.datax.rpc.remoting.net.params.XxlRpcFutureResponse.get(XxlRpcFutureResponse.java:120) at com.wugui.datax.rpc.remoting.invoker.reference.XxlRpcReferenceBean$1.invoke(XxlRpcReferenceBean.java:242) at com.sun.proxy.$Proxy164.run(Unknown Source) at com.wugui.datax.admin.core.trigger.JobTrigger.runExecutor(JobTrigger.java:204) at com.wugui.datax.admin.core.trigger.JobTrigger.processTrigger(JobTrigger.java:156) at com.wugui.datax.admin.core.trigger.JobTrigger.trigger(JobTrigger.java:73) at com.wugui.datax.admin.core.thread.JobTriggerPoolHelper.lambda$addTrigger$0(JobTriggerPoolHelper.java:88) 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)

waterWang commented 4 years ago

1,是否admin关闭了? 2.是否网络抖动

ZengRL commented 4 years ago

1,是否admin关闭了? 2.是否网络抖动

1、没有 2、不排除网络抖动,不过上线半个月了每天都会有几个异常

Mr-Zhen-xiwang commented 4 years ago

有遇到相同的问题,两个秒级调度的定时任务每天都会报request timeout,查询服务器日志,发现根本没有发送调度请求

WeiYe-Jing commented 4 years ago

异常信息和上面记录的完全一致吗,任务有设置超时时间吗,任务的配置信息可以截图或者详细说明下吗?我本地测试没复现这个问题。

Mr-Zhen-xiwang commented 4 years ago

异常信息一样的,xxl的版本是2.1.2,任务超时时间设置的默认,而且不是任务执行超时,是请求调度超时,每天都有大约1%的调度请求超时,查询服务器的日志根本没有的超时执行的 image

DREAM0000 commented 4 years ago

执行一个任务,每分钟执行一次,第一次执行成功,后续执行都显示调度失败,设置超时时间为5分钟也没效果 image image

WeiYe-Jing commented 4 years ago

执行一个任务,每分钟执行一次,第一次执行成功,后续执行都显示调度失败,设置超时时间为5分钟也没效果 image image

admin的日志和executor看了吗,有异常信息吗

WeiYe-Jing commented 4 years ago

执行一个任务,每分钟执行一次,第一次执行成功,后续执行都显示调度失败,设置超时时间为5分钟也没效果 image image

admin的日志和executor看了吗,有异常信息吗

执行一个任务,每分钟执行一次,第一次执行成功,后续执行都显示调度失败,设置超时时间为5分钟也没效果 image image

admin的日志和executor看了吗,有异常信息吗

只在这边有看到日志,日志都是执行成功的,没有调度失败的日志 image

我指的admin和executor日志是logback中配置的项目日志,不是任务运行的日志

DREAM0000 commented 4 years ago

exectuor没有报错信息,admin的报错信息如下所示:

2020-07-13 18:16:05,025 ERROR [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-1167215718] c.w.d.admin.core.trigger.JobTrigger [JobTrigger.java : 243] >>>>>>>>>>> datax-web trigger error, please check if the executor[127.0.0.1:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: xxl-rpc, request timeout at:1594635365023, request:XxlRpcRequest{requestId='5ac012fb-3863-421e-b69d-b8b636fa4f32', createMillisTime=1594635360021, accessToken='', className='com.wugui.datatx.core.biz.ExecutorBiz', methodName='run', parameterTypes=[class com.wugui.datatx.core.biz.model.TriggerParam], parameters=[TriggerParam{jobId=5, executorHandler='executorJobHandler', executorParams='', executorBlockStrategy='SERIAL_EXECUTION', executorTimeout=5, logId=8599, logDateTime=1594635360000, glueType='BEAN', glueSource='null', glueUpdatetime=1594632973000, broadcastIndex=0, broadcastTotal=1, jobJson={"job":{"content":[{"reader":{"parameter":{"password":"zmmydp","column":["\"ID0000\"","\"AAB069\"","\"DQBM00\"","\"DQMC00\"","\"CBRS00\"","\"JYRS00\"","\"SJGXSJ\""],"connection":[{"jdbcUrl":["jdbc:oracle:thin:@192.168.44.56:1521/mzjz"],"table":["BI_XJYJK_D_A"]}],"splitPk":"","username":"zmmydp"},"name":"oraclereader"},"writer":{"parameter":{"password":"xmjyjc","column":["\"ID0000\"","\"AAB069\"","\"DQBM00\"","\"DQMC00\"","\"CBRS00\"","\"JYRS00\"","\"SJGXSJ\""],"connection":[{"jdbcUrl":"jdbc:oracle:thin:@192.168.44.56:1521/mzjz","table":["BI_XJYJK_D_A"]}],"username":"xmjyjc"},"name":"oraclewriter"}}],"setting":{"errorLimit":{"record":0,"percentage":0.02},"speed":{"byte":1048576,"channel":3}}}}, processId=null, replaceParam=null, jvmParam=, startTime=null, triggerTime=null, partitionInfo=null, replaceParamType=null, startId=0, endId=0, incrementType=0}], version='null'} at com.wugui.datax.rpc.remoting.net.params.XxlRpcFutureResponse.get(XxlRpcFutureResponse.java:122) at com.wugui.datax.rpc.remoting.invoker.reference.XxlRpcReferenceBean.lambda$getObject$0(XxlRpcReferenceBean.java:252) at com.sun.proxy.$Proxy171.run(Unknown Source) at com.wugui.datax.admin.core.trigger.JobTrigger.runExecutor(JobTrigger.java:241) at com.wugui.datax.admin.core.trigger.JobTrigger.processTrigger(JobTrigger.java:188) at com.wugui.datax.admin.core.trigger.JobTrigger.trigger(JobTrigger.java:84) at com.wugui.datax.admin.core.thread.JobTriggerPoolHelper.lambda$addTrigger$0(JobTriggerPoolHelper.java:85) 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)

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

DREAM0000 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的 这是设置定时一分钟执行一次才会这样,要是设置成5分钟执行一次,就不会出现请求不通的问题了,都是正常执行。

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的 这是设置定时一分钟执行一次才会这样,要是设置成5分钟执行一次,就不会出现请求不通的问题了,都是正常执行。

目前配置了多少任务每分钟执行一次,项目部署的环境可以描述下吗,我们环境有很多30秒执行一次的任务,没遇到这个问题。

DREAM0000 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的 这是设置定时一分钟执行一次才会这样,要是设置成5分钟执行一次,就不会出现请求不通的问题了,都是正常执行。

目前配置了多少任务每分钟执行一次,项目部署的环境可以描述下吗,我们环境有很多30秒执行一次的任务,没遇到这个问题。

目前只配置了单个任务每分钟执行一次,都是在windows本机跑的,就是第一次执行成功,第二次开始都显示调度失败。那我之后部署到服务器上再看一下会不会有这个问题吧,谢谢了。

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的 这是设置定时一分钟执行一次才会这样,要是设置成5分钟执行一次,就不会出现请求不通的问题了,都是正常执行。

目前配置了多少任务每分钟执行一次,项目部署的环境可以描述下吗,我们环境有很多30秒执行一次的任务,没遇到这个问题。

目前只配置了单个任务每分钟执行一次,都是在windows本机跑的,就是第一次执行成功,第二次开始都显示调度失败。那我之后部署到服务器上再看一下会不会有这个问题吧,谢谢了。

不客气,部署之后如果没问题,麻烦回复下这个问题,谢谢!

zhengsw91 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

可以自己定义,telnet看看端口是不是通的

zhengsw91 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

可以自己定义,telnet看看端口是不是通的

ping是没问题的。 自己加了一行日志 @Override protected void channelRead0(ChannelHandlerContext ctx, FullHttpResponse msg) throws Exception { // valid status if (!HttpResponseStatus.OK.equals(msg.status())) { logger.error("错误信息:"+msg.toString()); throw new XxlRpcException("xxl-rpc response status invalid."); }

10:52:41.530 admin [nioEventLoopGroup-12-1] ERROR c.w.d.r.r.n.i.n.c.NettyHttpClientHandler - 错误信息:DefaultFullHttpResponse(decodeResult: failure(java.lang.IllegalArgumentException: invalid version format: SSH-2.0-OPENSSH_7.4), version: HTTP/1.0, content: UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeHeapByteBuf(ridx: 0, widx: 0, cap: 0))

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

可以自己定义,telnet看看端口是不是通的

ping是没问题的。 自己加了一行日志 @override protected void channelRead0(ChannelHandlerContext ctx, FullHttpResponse msg) throws Exception { // valid status if (!HttpResponseStatus.OK.equals(msg.status())) { logger.error("错误信息:"+msg.toString()); throw new XxlRpcException("xxl-rpc response status invalid."); }

10:52:41.530 admin [nioEventLoopGroup-12-1] ERROR c.w.d.r.r.n.i.n.c.NettyHttpClientHandler - 错误信息:DefaultFullHttpResponse(decodeResult: failure(java.lang.IllegalArgumentException: invalid version format: SSH-2.0-OPENSSH_7.4), version: HTTP/1.0, content: UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeHeapByteBuf(ridx: 0, widx: 0, cap: 0))

ping没意义,用telnet

zhengsw91 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

可以自己定义,telnet看看端口是不是通的

ping是没问题的。 自己加了一行日志 @override protected void channelRead0(ChannelHandlerContext ctx, FullHttpResponse msg) throws Exception { // valid status if (!HttpResponseStatus.OK.equals(msg.status())) { logger.error("错误信息:"+msg.toString()); throw new XxlRpcException("xxl-rpc response status invalid."); } 10:52:41.530 admin [nioEventLoopGroup-12-1] ERROR c.w.d.r.r.n.i.n.c.NettyHttpClientHandler - 错误信息:DefaultFullHttpResponse(decodeResult: failure(java.lang.IllegalArgumentException: invalid version format: SSH-2.0-OPENSSH_7.4), version: HTTP/1.0, content: UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeHeapByteBuf(ridx: 0, widx: 0, cap: 0))

ping没意义,用telnet

说错,telnet 9999端口是ok的

WeiYe-Jing commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的

你好, 10:35:00.027 admin [datax-web, admin JobTriggerPoolHelper-fastTriggerPool-239846919] ERROR c.w.d.a.c.t.JobTrigger - >>>>>>>>>>> datax-web trigger error, please check if the executor[172.20.23.23:9999] is running. com.wugui.datax.rpc.util.XxlRpcException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /172.20.23.23:9999 部署到服务器,跑不通。 9999端口有什么要求。还是随便定义一个

可以自己定义,telnet看看端口是不是通的

ping是没问题的。 自己加了一行日志 @override protected void channelRead0(ChannelHandlerContext ctx, FullHttpResponse msg) throws Exception { // valid status if (!HttpResponseStatus.OK.equals(msg.status())) { logger.error("错误信息:"+msg.toString()); throw new XxlRpcException("xxl-rpc response status invalid."); } 10:52:41.530 admin [nioEventLoopGroup-12-1] ERROR c.w.d.r.r.n.i.n.c.NettyHttpClientHandler - 错误信息:DefaultFullHttpResponse(decodeResult: failure(java.lang.IllegalArgumentException: invalid version format: SSH-2.0-OPENSSH_7.4), version: HTTP/1.0, content: UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeHeapByteBuf(ridx: 0, widx: 0, cap: 0))

ping没意义,用telnet

说错,telnet 9999端口是ok的

看看executor服务的日志,有没有异常,这个问题应该和issue描述的不是同一类问题

DREAM0000 commented 4 years ago

datax-web trigger error, please check if the executor[127.0.0.1:9999] is running

从日志看问题是executor丢失,admin请求executor超时,127.0.0.1:9999这个时间应该是请求不通的 这是设置定时一分钟执行一次才会这样,要是设置成5分钟执行一次,就不会出现请求不通的问题了,都是正常执行。

目前配置了多少任务每分钟执行一次,项目部署的环境可以描述下吗,我们环境有很多30秒执行一次的任务,没遇到这个问题。

目前只配置了单个任务每分钟执行一次,都是在windows本机跑的,就是第一次执行成功,第二次开始都显示调度失败。那我之后部署到服务器上再看一下会不会有这个问题吧,谢谢了。

不客气,部署之后如果没问题,麻烦回复下这个问题,谢谢! 服务器部署测试了,定时任务都正常,不会出现本地环境每分钟执行一次,第二次开始执行显示调度失败的问题。