Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

关于V2版本内部LightCacheInside存储数据使用数组方式存在数据不同步的问题 #277

Open
YiwanGi opened this issue Feb 5, 2023 · 10 comments
Open

关于V2版本内部LightCacheInside存储数据使用数组方式存在数据不同步的问题 #277

YiwanGi opened this issue Feb 5, 2023 · 10 comments
Assignees
@crazywhalecc
Labels
2.x issue 这是一个 2.x 版本的问题 bug 意外行为或意外问题

Comments

@YiwanGi
Copy link
Contributor

YiwanGi commented Feb 5, 2023

受影响版本

2.8.6

描述

参考内部代码 CoMessage.php fun>>>yieldByWS

        $cid = Coroutine::getuid();
        $api_id = ZMAtomic::get('wait_msg_id')->add(1);
        $hang['compare'] = $compare;
        $hang['coroutine'] = $cid;
        $hang['worker_id'] = server()->worker_id;
        $hang['result'] = null;
        SpinLock::lock('wait_api');
        $wait = LightCacheInside::get('wait_api', 'wait_api');
        $wait[$api_id] = $hang;
        LightCacheInside::set('wait_api', 'wait_api', $wait);
        SpinLock::unlock('wait_api');
        $id = swoole_timer_after($timeout * 1000, function () use ($api_id) {
            $r = LightCacheInside::get('wait_api', 'wait_api')[$api_id] ?? null;
            if (is_array($r)) {
                Coroutine::resume($r['coroutine']);
            }
        });
        Coroutine::suspend();
        SpinLock::lock('wait_api');
        $sess = LightCacheInside::get('wait_api', 'wait_api');
        $result = $sess[$api_id]['result'] ?? null;
        unset($sess[$api_id]);
        LightCacheInside::set('wait_api', 'wait_api', $sess);
        SpinLock::unlock('wait_api');
        swoole_timer_clear($id);
        if ($result === null) {
            return false;
        }
        return $result;

由于内部采用 $wait[$api_id] 方式进行存取值 在协程高频情况下 可能会存在丢失部分消息回执的情况(例如go()多机器人调用api，或多机器人群发消息等情况。参见复现方式)

该缓存类使用的是swoole的Table方式 参见官方文档 也警告不要使用数组方式存取数据
该内部类方法在多处均有使用 可能需要修改多处代码 TODO

复现步骤

        $all = OneBotV11::getAllRobot();
        foreach ($all as $bot) {
            $list = $bot->getGroupList();
            if ($list === false) {
                Console::error('群列表获取失败');
            }
            foreach ($list['data'] ?? [] as $group) {
                $rt = $bot->setPrefix(OneBotV11::API_ASYNC)->sendGroupMsg($group['group_id'],'test');
            }
        }

封装该群发消息，在多处使用，高频情况下获取群列表可能出现返回false

解决方案

内部缓存使用swoole的Table应避免使用数组方式读写数据，修改局部应用代码为独立Table表 并使用$api_id(参考)为key。

附加信息

No response
@YiwanGi YiwanGi added the bug 意外行为或意外问题 label Feb 5, 2023
@crazywhalecc
Copy link
Member

这里看确实可以直接用api id做key，但是上下应该是设置了自旋锁的，不应该出现抢占情况。你在实际运行时可以找到它是哪个地方返回的 false 吗？

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 5, 2023

我已在上游函数添加多处日志捕获，如果再次出现，我会在此处进行回复。

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 6, 2023 •
edited 

[02-06 13:12:50] [S] [#0] [123456789] onConnect！
string(49) "请求获取群列表 echo2---2023-02-06 13:13:02"
string(49) "请求获取群列表 echo4---2023-02-06 13:13:02"
string(49) "请求获取群列表 echo6---2023-02-06 13:13:06"
string(49) "请求获取群列表 echo8---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo10---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo12---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo14---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo16---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo18---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo20---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo22---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo24---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo26---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo28---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo30---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo32---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo34---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo36---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo38---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo40---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo42---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo44---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo46---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo48---2023-02-06 13:13:06"
string(33) "未接收45---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo50---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo52---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo54---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo56---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo58---2023-02-06 13:13:06"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":200,"member_count":3}],"echo":45,"retcode":0,"status":"ok"}
string(33) "未接收43---2023-02-06 13:13:06"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":2000,"member_count":238}],"echo":43,"retcode":0,"status":"ok"}
string(33) "未接收57---2023-02-06 13:13:06"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":200,"member_count":3}],"echo":57,"retcode":0,"status":"ok"}
string(33) "未接收53---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo60---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo62---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo64---2023-02-06 13:13:06"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":200,"member_count":3}],"echo":53,"retcode":0,"status":"ok"}
string(33) "未接收61---2023-02-06 13:13:06"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":200,"member_count":3}],"echo":61,"retcode":0,"status":"ok"}
string(50) "请求获取群列表 echo66---2023-02-06 13:13:06"
string(50) "请求获取群列表 echo68---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo70---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo72---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo74---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo76---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo78---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo80---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo82---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo84---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo86---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo88---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo90---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo92---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo94---2023-02-06 13:13:26"
string(50) "请求获取群列表 echo96---2023-02-06 13:13:26"
string(33) "未接收81---2023-02-06 13:13:26"
未接收{"data":[{"group_create_time":0,"group_id":123,"group_level":0,"group_name":"群名称","max_member_count":2000,"member_count":238}],"echo":81,"retcode":0,"status":"ok"}
string(50) "请求获取群列表 echo98---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo100---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo102---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo104---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo108---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo110---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo112---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo114---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo116---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo118---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo120---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo122---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo124---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo126---2023-02-06 13:13:26"
string(51) "请求获取群列表 echo128---2023-02-06 13:13:28"
string(51) "请求获取群列表 echo130---2023-02-06 13:13:28"
string(36) "调用失败58---2023-02-06 13:13:36"
调用失败{"data":{"action":"get_group_list","echo":57},"time":1675660386.567887,"self_id":"123456","echo":57,"compare":["echo"],"coroutine":83,"worker_id":0,"result":null}
[ZMRobot.getGroupList] *False*
string(36) "调用失败46---2023-02-06 13:13:36"
调用失败{"data":{"action":"get_group_list","echo":45},"time":1675660386.564692,"self_id":"123456","echo":45,"compare":["echo"],"coroutine":84,"worker_id":0,"result":null}
[ZMRobot.getGroupList] *False*
string(36) "调用失败44---2023-02-06 13:13:36"
调用失败{"data":{"action":"get_group_list","echo":43},"time":1675660386.564605,"self_id":"123456","echo":43,"compare":["echo"],"coroutine":87,"worker_id":0,"result":null}
[ZMRobot.getGroupList] *False*
string(51) "请求获取群列表 echo132---2023-02-06 13:13:36"
string(36) "调用失败54---2023-02-06 13:13:36"
调用失败{"data":{"action":"get_group_list","echo":53},"time":1675660386.567733,"self_id":"123456","echo":53,"compare":["echo"],"coroutine":85,"worker_id":0,"result":null}
[ZMRobot.getGroupList] *False*
string(36) "调用失败62---2023-02-06 13:13:36"
调用失败{"data":{"action":"get_group_list","echo":61},"time":1675660386.574583,"self_id":"123456","echo":61,"compare":["echo"],"coroutine":80,"worker_id":0,"result":null}
[ZMRobot.getGroupList] *False*

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 6, 2023

image
image

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 6, 2023

从日志来看 确实是数据不同步的问题 gocq已经返回调用信息 但未被接收 从而导致调用在30秒后超时

@crazywhalecc crazywhalecc added the 2.x issue 这是一个 2.x 版本的问题 label Feb 6, 2023
@crazywhalecc
Copy link
Member 

        $all = OneBotV11::getAllRobot();
        foreach ($all as $bot) {
            $list = $bot->getGroupList();
            if ($list === false) {
                Console::error('群列表获取失败');
            }
            foreach ($list['data'] ?? [] as $group) {
                $rt = $bot->setPrefix(OneBotV11::API_ASYNC)->sendGroupMsg($group['group_id'],'test');
            }
        }

请问这段代码，我的理解是遍历所有接入的机器人并群发机器人加入的所有群，异步发送消息。一般来说框架只会连接个位数的机器人，这里是在 GetGroupList 上接收不到还是 sendGroupMsg 接收不到呢？

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 7, 2023 

        $all = OneBotV11::getAllRobot();
        foreach ($all as $bot) {
            $list = $bot->getGroupList();
            if ($list === false) {
                Console::error('群列表获取失败');
            }
            foreach ($list['data'] ?? [] as $group) {
                $rt = $bot->setPrefix(OneBotV11::API_ASYNC)->sendGroupMsg($group['group_id'],'test');
            }
        }

请问这段代码，我的理解是遍历所有接入的机器人并群发机器人加入的所有群，异步发送消息。一般来说框架只会连接个位数的机器人，这里是在 GetGroupList 上接收不到还是 sendGroupMsg 接收不到呢？

是获取群列表失败 从日志来看调用群列表 gocqhttp是已经返回了调用结果的 但是由于数据不同步 并没有被存储返回导致 GetGroupList 在30秒后超时了

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Feb 20, 2023

该问题属于偶尔（例如使用go()协程时）出现 正常情况应该不会触发 在不修改当前代码的情况下
应该可以在resumeByWS() $last === null时 （新增一个Table表储存未被处理的数据，并为其设置60s过期） 在调用超时时再从该表内获取结果数据 以解决该问题

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Mar 23, 2023

swoole.log
``
[2023-03-23 07:42:50 *28974.3] WARNING TableRow::set_value(): [key=wait_api,field=value]string value is too long

@YiwanGi
Copy link
Contributor Author

YiwanGi commented Jun 5, 2023

swoole.log `` [2023-03-23 07:42:50 *28974.3] 警告 TableRow::set_value(): [key=wait_api,field=value]string value is too long

#361

@YiwanGi YiwanGi mentioned this issue Oct 21, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@crazywhalecc crazywhalecc

Labels
2.x issue 这是一个 2.x 版本的问题 bug 意外行为或意外问题
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@crazywhalecc @YiwanGi