EMQX动作先成功，后失败。

JGS · 2024 年9 月 20 日 06:42

动作在更新后，不做任何变更就一直放在那里，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，导致动作会突然失效，并无法自动恢复正常。

JimMoen · 2024 年9 月 20 日 09:23

还请提供下其他的版本/配置/更多更详细的日志/稳定复现步骤等信息
信息不够只能靠猜了

JGS · 2024 年9 月 20 日 09:53

环境信息

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报错，需要点击更新后才正常

heeejianbo · 2024 年9 月 23 日 01:47

你好，这个看起来和 webhook 那个不是一个问题。

方便把全部的日志文件都打包上传上来吗？

JGS · 2024 年9 月 23 日 02:22

我日志文件应该怎么给你呢？

JGS · 2024 年9 月 23 日 02:41

日志文件已经私信发您了，我怀疑这是 EMQX 的 Webhook 动作或 HTTP 连接器存在会话管理机制，可能会在某个时间点自动过期，导致动作无法被正确执行，从而触发 action_not_found 错误。点击更新按钮后，连接或会话被重新建立，因此能够恢复正常。

heeejianbo · 2024 年9 月 23 日 08:03

您好，看日志是有时候这个端口/服务是不通的导致的

JGS · 2024 年9 月 23 日 08:25

我在他报错的时候，特地请求了服务是通的。这时候我不做其他操作，只需要将动作直接更新（动作不做任何修改），就可以恢复正常了，但是隔一段时间后，又会出现这个问题。

如图：这时候执行动作失败，然后我在部署emqx的服务器上，使用curl命令去请求该服务，是可以正常访问的。所以我怀疑，是该动作连接池中的连接失效了。

并且我们在3个不同的环境（2套在华为云，1套公司在自有的服务器），部署了3套完全相同的服务，都存在这个问题。

abbott_no1 · 2024 年10 月 7 日 10:45

我的版本是5.8开源的k8s部署的单节点，也遇到了莫名其妙的失败，请求是正常的，但是就是会失败，自己把连接器重新生成了一个，规则里面把动作和新的连接器绑定起来。然后就可以了。
大概率是bug