动作在更新后,不做任何变更就一直放在那里,emqx在前面一百多次的动作都能成功,但到后面就会变成失败。这时候什么其他操作都没有,直接更新动作,就会恢复正常,但是过一段时间又会这样重复出现。查看日志报错如下:[error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>,但是查看服务正常,用postman请求该url能正常启用,没任何问题,怀疑是emqx纯在某些bug,导致动作会突然失效,并无法自动恢复正常。
还请提供下其他的版本/配置/更多更详细的日志/稳定复现步骤等信息
信息不够只能靠猜了
环境信息
- EMQ X 版本:开源版 v5.7.2
- 操作系统及版本:centos7.9
emqx报错日志
2024-09-19T20:18:44.391109+08:00 [warning] msg: alarm_is_activated, message: <<“resource down: #{error => closed,status => disconnected}”>>, name: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:18:55.809857+08:00 [error] tag: ERROR, msg: send_error, id: <<“action:http:client_disconnected:connector:http:device_links”>>, reason: {recoverable_error,<<“channel: "action:http:client_disconnected:connector:http:device_links" not operational”>>}
2024-09-19T20:18:59.392445+08:00 [warning] msg: alarm_is_deactivated, name: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:19:10.810889+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:19:10.811093+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:19:44.617511+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:19:44.617688+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:20:14.495212+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:20:32.344863+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 1}
2024-09-19T20:23:13.588140+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:23:13.588369+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:24:41.006017+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:24:41.006260+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:25:26.113281+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:25:32.349810+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 1}
2024-09-19T20:25:36.132899+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:25:36.133117+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:26:22.295350+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:26:24.034473+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:26:29.969744+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:26:32.350873+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 3}
2024-09-19T20:26:33.907938+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:26:33.908140+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:27:57.092668+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:27:57.092847+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:29:17.307141+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:29:17.307366+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:30:16.847835+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:30:16.848044+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:35:12.151884+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:35:12.152078+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:36:03.908857+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:36:03.909037+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:36:23.147734+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:36:32.360859+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 1}
2024-09-19T20:36:50.445989+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:36:50.446266+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:37:13.809905+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:37:30.024806+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:37:32.361809+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 2}
2024-09-19T20:38:07.966508+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:38:07.966690+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:39:06.804459+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:39:06.804647+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:39:22.995585+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:39:32.363805+08:00 [warning] msg: log_events_throttled_during_last_period, period: 1 minutes, 0 seconds, dropped: #{<<“unrecoverable_resource_error:action:http:client_disconnected:connector:http:device_links”>> => 1}
2024-09-19T20:40:49.460475+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:40:49.460646+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:43:57.734537+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:43:57.734712+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:45:42.020914+08:00 [error] msg: action_not_found, connector: <<“connector:http:device_links”>>, action_id: <<“action:http:client_disconnected:connector:http:device_links”>>
2024-09-19T20:45:42.021125+08:00 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:client_disconnected:connector:http:device_links”>>
日志中说资源无法访问,但是我们确认过,资源没有任何问题,而且在这之前这个规则动作是可以正常访问这个资源的,隔一段时间才会出现这个访问资源失败的异常。
规则配置
复现步骤
无法手动复现,服务部署好后放在那边几天,请求的目标服务并未做任何改动,就会出现这个现象。我在论坛也有看到类似的问题提问,在5.0.x版本就出现了这个问题,但是好像暂未修复,帖子链接如下:数据桥接webhook报错,需要点击更新后才正常
你好,这个看起来和 webhook 那个不是一个问题。
方便把全部的日志文件都打包上传上来吗?
我日志文件应该怎么给你呢?
日志文件已经私信发您了,我怀疑这是 EMQX 的 Webhook 动作或 HTTP 连接器存在会话管理机制,可能会在某个时间点自动过期,导致动作无法被正确执行,从而触发 action_not_found
错误。点击更新按钮后,连接或会话被重新建立,因此能够恢复正常。
我在他报错的时候,特地请求了服务是通的。这时候我不做其他操作,只需要将动作直接更新(动作不做任何修改),就可以恢复正常了,但是隔一段时间后,又会出现这个问题。
如图:这时候执行动作失败,然后我在部署emqx的服务器上,使用curl命令去请求该服务,是可以正常访问的。所以我怀疑,是该动作连接池中的连接失效了。
并且我们在3个不同的环境(2套在华为云,1套公司在自有的服务器),部署了3套完全相同的服务,都存在这个问题。
我的版本是5.8开源的k8s部署的单节点,也遇到了莫名其妙的失败,请求是正常的,但是就是会失败,自己把连接器重新生成了一个,规则里面把动作和新的连接器绑定起来。然后就可以了。
大概率是bug
这个问题有解决掉吗?我也出现了
没解决,官方也没个所以然的答复。。。
您好,这个是一个 bug 来的,我们已经修了。
应该会包含在:5.8.2 里面麻烦到时也验证一下。
包括在内了
今天早上我用的5.8.2也有问题
方便给一下日志吗,顺便说一下详细的重现步骤,因为这个bug本来就是很少出现的
我周一给客户安装的5.8.2
然后今天早上客户就告诉我出问题了,现象一模一样,把connector disable/enable 一下就好了,然后不是所有的连接都有问题,只有一部分数据没法转发,有些数据转发还是可以的。
2024-11-20T03:46:42.899238+10:30 [warning] msg: alarm_is_activated, message: <<“resource down: #{error => closed,status => disconnected}”>>, name: <<“action:http:msg:connector:http:hardware”>>
2024-11-20T03:46:57.900246+10:30 [warning] msg: alarm_is_deactivated, name: <<“action:http:msg:connector:http:hardware”>>
2024-11-20T03:47:12.121636+10:30 [error] msg: action_not_found, connector: <<“connector:http:hardware”>>, action_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-20T03:47:12.121908+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-20T03:47:37.151704+10:30 [error] msg: action_not_found, connector: <<“connector:http:hardware”>>, action_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-20T03:47:37.151978+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: action_not_found, resource_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-18T12:08:38.407655+10:30 [warning] msg: alarm_is_deactivated, name: <<“connector:http:hardware”>>
2024-11-18T12:08:38.408278+10:30 [warning] msg: alarm_is_deactivated, name: <<“action:http:msg:connector:http:hardware”>>
2024-11-18T12:08:39.335599+10:30 [error] msg: http_connector_do_request_failed, reason: {unrecoverable_error,#{body => <<“{"message":"Request method ‘POST’ not supported","status":400,"timestamp":"2024-11-18 12:08:39"}”>>,headers => [{<<“vary”>>,<<“Origin”>>},{<<“vary”>>,<<“Access-Control-Request-Method”>>},{<<“vary”>>,<<“Access-Control-Request-Headers”>>},{<<“x-content-type-options”>>,<<“nosniff”>>},{<<“x-xss-protection”>>,<<“1; mode=block”>>},{<<“cache-control”>>,<<“no-cache, no-store, max-age=0, must-revalidate”>>},{<<“pragma”>>,<<“no-cache”>>},{<<“expires”>>,<<“0”>>},{<<“content-type”>>,<<“application/json;charset=UTF-8”>>},{<<“content-length”>>,<<“96”>>},{<<“date”>>,<<“Mon, 18 Nov 2024 01:38:38 GMT”>>},{<<“connection”>>,<<“close”>>}],status_code => 400}}, request: {[<<>>,47,<<>>],[{<<“type”>>,<<“emq”>>},{<<“content-type”>>,<<“application/json”>>},{<<“token”>>,<<“4EE166FEFE453B0F4FEA9276A6080D3B”>>}],<<“******”>>}, connector: <<“connector:http:hardware”>>, note: the request body is redacted due to security reasons
2024-11-18T12:08:39.336614+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: {unrecoverable_error,#{body => <<“{"message":"Request method ‘POST’ not supported","status":400,"timestamp":"2024-11-18 12:08:39"}”>>,headers => [{<<“vary”>>,<<“Origin”>>},{<<“vary”>>,<<“Access-Control-Request-Method”>>},{<<“vary”>>,<<“Access-Control-Request-Headers”>>},{<<“x-content-type-options”>>,<<“nosniff”>>},{<<“x-xss-protection”>>,<<“1; mode=block”>>},{<<“cache-control”>>,<<“no-cache, no-store, max-age=0, must-revalidate”>>},{<<“pragma”>>,<<“no-cache”>>},{<<“expires”>>,<<“0”>>},{<<“content-type”>>,<<“application/json;charset=UTF-8”>>},{<<“content-length”>>,<<“96”>>},{<<“date”>>,<<“Mon, 18 Nov 2024 01:38:38 GMT”>>},{<<“connection”>>,<<“close”>>}],status_code => 400}}, resource_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-18T12:08:39.364629+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: {unrecoverable_error,#{body => <<“{"message":"Request method ‘POST’ not supported","status":400,"timestamp":"2024-11-18 12:08:39"}”>>,headers => [{<<“vary”>>,<<“Origin”>>},{<<“vary”>>,<<“Access-Control-Request-Method”>>},{<<“vary”>>,<<“Access-Control-Request-Headers”>>},{<<“x-content-type-options”>>,<<“nosniff”>>},{<<“x-xss-protection”>>,<<“1; mode=block”>>},{<<“cache-control”>>,<<“no-cache, no-store, max-age=0, must-revalidate”>>},{<<“pragma”>>,<<“no-cache”>>},{<<“expires”>>,<<“0”>>},{<<“content-type”>>,<<“application/json;charset=UTF-8”>>},{<<“content-length”>>,<<“96”>>},{<<“date”>>,<<“Mon, 18 Nov 2024 01:38:38 GMT”>>},{<<“connection”>>,<<“close”>>}],status_code => 400}}, resource_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-18T12:09:05.871710+10:30 [warning] msg: log_events_throttled_during_last_period, dropped: #{<<“unrecoverable_resource_error:action:http:msg:connector:http:hardware”>> => 8}, period: 1 minutes, 0 seconds
2024-11-18T12:09:16.779582+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: {unrecoverable_error,#{body => <<“{"message":"Request method ‘POST’ not supported","status":400,"timestamp":"2024-11-18 12:09:16"}”>>,headers => [{<<“vary”>>,<<“Origin”>>},{<<“vary”>>,<<“Access-Control-Request-Method”>>},{<<“vary”>>,<<“Access-Control-Request-Headers”>>},{<<“x-content-type-options”>>,<<“nosniff”>>},{<<“x-xss-protection”>>,<<“1; mode=block”>>},{<<“cache-control”>>,<<“no-cache, no-store, max-age=0, must-revalidate”>>},{<<“pragma”>>,<<“no-cache”>>},{<<“expires”>>,<<“0”>>},{<<“content-type”>>,<<“application/json;charset=UTF-8”>>},{<<“content-length”>>,<<“96”>>},{<<“date”>>,<<“Mon, 18 Nov 2024 01:39:16 GMT”>>},{<<“connection”>>,<<“close”>>}],status_code => 400}}, resource_id: <<“action:http:msg:connector:http:hardware”>>
2024-11-18T12:09:56.796061+10:30 [error] tag: AUTHZ, clientid: EZYH482407600005, msg: match_rule_error, peername: 49.179.126.15:2305, username: EZYH482407600005, reason: invalid_rule, type: mysql, value: #{}, explain: missing ‘permission’ or ‘action’ field, rule: [<<“uNB0bUmXoappZi4S”>>]
2024-11-18T12:10:05.873018+10:30 [warning] msg: log_events_throttled_during_last_period, dropped: #{<<“unrecoverable_resource_error:action:http:msg:connector:http:hardware”>> => 2}, period: 1 minutes, 0 seconds
2024-11-18T12:10:16.797032+10:30 [error] tag: RESOURCE, msg: unrecoverable_resource_error, reason: {unrecoverable_error,#{body => <<“{"message":"Request method ‘POST’ not supported","status":400,"timestamp":"2024-11-18 12:10:16"}”>>,headers => [{<<“vary”>>,<<“Origin”>>},{<<“vary”>>,<<“Access-Control-Request-Method”>>},{<<“vary”>>,<<“Access-Control-Request-Headers”>>},{<<“x-content-type-options”>>,<<“nosniff”>>},{<<“x-xss-protection”>>,<<“1; mode=block”>>},{<<“cache-control”>>,<<“no-cache, no-store, max-age=0, must-revalidate”>>},{<<“pragma”>>,<<“no-cache”>>},{<<“expires”>>,<<“0”>>},{<<“content-type”>>,<<“application/json;charset=UTF-8”>>},{<<“content-length”>>,<<“96”>>},{<<“date”>>,<<“Mon, 18 Nov 2024 01:40:16 GMT”>>},{<<“connection”>>,<<“close”>>}],status_code => 400}}, resource_id: <<“action:http:msg:connector:http:hardware”>>
能发全的日志么,这个实在是看不出来。
econnrefused, 这应该是 http server 真的连不上了才出的问题。