gateway-worker 并发场景下的查询结果混乱,是变量污染问题吗?

shyer886

问题描述

gateway-worker 并发场景下,查询数据库的结果返回混乱.

程序代码

在gateway-worker中实际执行的laravel代码,使用了orm 的with关联, 查询用户A,B的信息:

$selfUser = User::query()->with('userInfo')->where(['uuid' => $selfUuid])->first();
info('$selfUuid='.$selfUuid);   //查询用户A $UUID= 956498 的用户信息
info($selfUser);

$targetUser = User::query()->with('userInfo')->where(['uuid' => $targetUuid])->first();
info('$targetUuid='.$targetUuid);   //查询用户B $UUID= 724129的用户信息
info($targetUser);

返回的结果却是用户C的信息:

[2023-12-12 14:17:11] prod.INFO: $selfUuid=956498
[2023-12-12 14:17:11] prod.INFO: {"id":3,"uuid":371006,"register_device_type":0,"register_device_imei":"E0B993E56CC","register_ip":"221.234.178.221","created_at":"2023-12-07 16:18:35","updated_at":"2023-12-12 12:18:36","deleted_at":null,"user_info":null}

[2023-12-12 14:17:11] prod.INFO: $targetUuid=724129
[2023-12-12 14:17:11] prod.INFO: {"id":3,"uuid":371006,"register_device_type":0,"register_device_imei":"E0B993E56CC","register_ip":"221.234.178.221","created_at":"2023-12-07 16:18:35","updated_at":"2023-12-12 12:18:36","deleted_at":null,"user_info":null}

框架执行时候输出的sql:

   [2023-12-12 14:17:11] time: 0.08 ms; sql: select * from `user` where (`uuid` = "956498") and `user`.`deleted_at` is null limit 1;    //查询956498的用户信息
    [2023-12-12 14:17:11] time: 2.27 ms; sql: select * from `user_info` where `user_info`.`uuid` in ("371006") and `user_info`.`deleted_at` is null;    //with查询956498用户的扩展信息, 但是框架执行的时候,变成了用户C的UUID 371006

    [2023-12-12 14:17:11] time: 0.05 ms; sql: select * from `user` where (`uuid` = "724129") and `user`.`deleted_at` is null limit 1;   //查询 724129 的用户信息
    [2023-12-12 14:17:11] time: 2.2 ms; sql: select * from `user_info` where `user_info`.`uuid` in ("371006") and `user_info`.`deleted_at` is null; //with查询 724129 用户的扩展信息, 但是框架执行的时候,变成了用户C的UUID 371006

重现问题的步骤

此bug不是必现,多数时候框架是正常运行 , 但是一旦触发这种混乱查询 ,就会大面积的使线上其他用户的查询, 全部返回这条异常ID的结果.必须通过重启gateway-worker,才能使其它人的查询结果再次正常.

看了gateway-worker的运行日志,没有报错信息.
请教下版主,这种情况是gateway-worker的变量污染吗?应该怎么处理呢?

操作系统环境及workerman/webman等具体版本

php: 8.1.19
gateway-worker: 3.1.4

662 2 0
2个回答

walkor 打赏

写业务都是临时变量,不存在变量污染问题。
从你上面的代码看不会出现错乱问题。

但是日志记录可能会错乱,因为每个进程都在不断的记录日志,写到一个文件里会错乱是正常的,不影响业务。

  • shyer886 2023-12-12

    不是根据sql日志看出来的代码异常, 而是代码本身执行的结果是异常的.所以才输出sql日志查看,结果发现sql语句不对劲.然后重启gateway-worker结果集就正常了. 那这个如果不是变量污染的问题,那会不会是MySQL链接的问题? 每次出现这种问题, 连调试都没法调试, 比如上述代码,特别简答, 就是根据uid查询用户信息, 可是输入的ID是正确的, 代码执行的结却是错误的.调试都没办法调试,而只要一重启gateway-worker就又好了,能提供几个方向,启发下怎么定位这种问题根源吗...

  • shyer886 2023-12-12

    像上面的代码,并不是复杂逻辑,但是打印输出的结果就是异常的,也按照手册装了event扩展, 改了linux参数, gateway-worker 80%的时间也都是正常运行的, 偶尔会触发这种ID查询的结果异常的问题, 但每次触发这种异常都会大面积影响其他用户,就只能重启gateway-worker...而上面的逻辑也没复杂封装,实在太过简单.连调试都无从调试起...

  • walkor 2023-12-12

    大概排查方向
    1、定时器里不要用$_SESSION超级变量
    2、数据库不要在启动脚本里直接初始化,要在onWorkerStart里初始化
    3、看下是不是使用了什么特殊的扩展

  • shyer886 2023-12-12

    看起来②的试错最快,我按照②①③的顺序,先研究下laravel的orm怎么手动在onWorkerStart中初始化,感谢版主的启示

  • shyer886 2023-12-13

    bug已解决,把所有composer包卸载后,重新require了最简支撑,未再触发此bug,应该是之前使用的某个包引起的.感谢版主.

meows

为毛我感觉你这ORM 写得不太对呢

with() 查询几乎是整个表in(id集合)查询
你这指定用户查询信息不应该是

$user = User::where('uid', '724129')->firstOrFail();
$data = $user->load(['userInfo']);
  • shyer886 2023-12-13

    实际执行的sql是一样的,with是查出关联数据,并在这次调用时把关联数据也返回;load也查了关联数据,只是并未在这次调用时返回关联数据,在后续使用时才加载而已.预加载和懒加载的区别.

×
🔝