EMQX动作先成功,后失败。


动作在更新后,不做任何变更就一直放在那里,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的release版本有对应的镜像吗?当前docker hub上 [5.8.2-beta.1]是否包含上述修复?

5.8.2-beta.1

包括在内了

今天早上我用的5.8.2也有问题