MongoSocketReadTimeoutException: Timeout while receiving message问题解决

喜欢ヅ旅行 2023-05-28 15:41 1阅读 0赞

由提示可知 是读取消息时超时，因为我们项目配置的SocketTimeOut是5秒，也就是说，是在读取5秒后，还未返回响应，就报了这个异常。

怀疑两个原因：

1.因为锁的原因，比如说写锁阻塞，其他读锁都只能等待。

2.怀疑是查询慢的问题

排查步骤如下，首先进入Mongodb对应DB

执行db.currentOp()  查看目前正在执行的所有查询语句

##当前语句有没有在等待锁 false即为否
    "waitingForLock" : false,
    //当前整个服务器 整个库 整个表的读锁数和写锁数
    "lockStats" : {
       "Global" : {
         "acquireCount" : {
            "r" : NumberLong(56),
            "w" : NumberLong(56)
            }
        },
        "Database" : {
            "acquireCount" : {
                 "w" : NumberLong(56)
             }
        },
        "Collection" : {
             "acquireCount" : {
             "w" : NumberLong(56)
         }
       }
    }

看到几个语句的waitingForLock都是False，所以暂时排除锁的原因。

然后排查 查询慢的原因 1没有用到索引 2,有用到索引，但是索引符合到的数据量很多，导致也很慢

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0FBQTgyMQ_size_16_color_FFFFFF_t_70][]

通过查询日志 PlanSummay:IXSCAN\{operUid:1\} 表示它有用到operUid索引，通过keysExamined跟docsExamined可以知道，索引到的数据量很大，都是1万条多条。

因为当前索引是单索引，在多条件查询时，首先用operUid查到1万多条数据，然后再根据条件过滤掉记录。

因为常用的查询字段是operUid roomId type 所以我建了这三个字段的联合索引

然后用以下语句来实验下效果。

db.COLLECTION\_NAME.explain("executionStats").find(\{operUid:70002431,type:1,endTime: \{ $exists:false \},roomId:70228589\})

尽管查询条件多了一个非索引字段endTime ，但执行毫秒数从6650，keysExamined28303 变成执行毫秒数11 totalKeysExamined 321 所以联合索引还是起到很大作用。

然后再看看应用的日志，从加了复合索引后，就没再报这个异常，即问题得以解决。

PS:.setProfilingLevel可以设值为0(不打开慢日志) 1 打开慢日志（默认执行超过100ms的才会记录) 2所有执行都会记录

setProfilingLevel(级别,毫秒数) setProfilingLevel(1,1000)就是只记录超过1秒的记录

在执行db.system.profile.drop() 前要关闭慢日志 setProfilingLevel(0)

PPS:打开慢日志记录，会影响CPU跟IO 如果CPU升高或者IO读写频繁可能跟这个原因有关,MYSQL也是。

参考相关博文，感谢相关博主：

[https://www.cnblogs.com/zhouqinxiong/p/5554779.html][https_www.cnblogs.com_zhouqinxiong_p_5554779.html]

[https://www.jb51.net/article/123713.htm][https_www.jb51.net_article_123713.htm]

[https://www.cnblogs.com/duhuo/articles/4762933.html][https_www.cnblogs.com_duhuo_articles_4762933.html]

[https://www.jb51.net/article/137119.htm][https_www.jb51.net_article_137119.htm]

[https://blog.csdn.net/user\_longling/article/details/83957085][https_blog.csdn.net_user_longling_article_details_83957085]

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0FBQTgyMQ_size_16_color_FFFFFF_t_70]: /images/20230528/0f1ee7314eeb4c1cb351d3959df8d97b.png
[https_www.cnblogs.com_zhouqinxiong_p_5554779.html]: https://www.cnblogs.com/zhouqinxiong/p/5554779.html
[https_www.jb51.net_article_123713.htm]: https://www.jb51.net/article/123713.htm
[https_www.cnblogs.com_duhuo_articles_4762933.html]: https://www.cnblogs.com/duhuo/articles/4762933.html
[https_www.jb51.net_article_137119.htm]: https://www.jb51.net/article/137119.htm
[https_blog.csdn.net_user_longling_article_details_83957085]: https://blog.csdn.net/user_longling/article/details/83957085