默认延时的问题 about chinadns-ng

[bzzjh]

我也遇到了，默认5秒 也经常报
ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 12924
并且连续报了以后，就会core dumped

[bzzjh]

修改奥了-o 10 以后再-r 打开了多线程，运行了2个chinadns-ng进程后，发现稳了很多

[zfl9]

默认超时5秒并没有问题，你们出问题只是因为你们的可信dns不稳定，总是丢包导致的。

[zfl9]

不建议设置超长的超时时间，比如10秒。实际上如果10秒上游都没有响应，都没必要等待它的结果了。客户端自己会重试的，没有必要设置这么长的超时时间。这么做只会积累没必要的查询上下文数据在chinadns-ng内存里面，反倒会增加coredump的风险。coredump产生的原因应该是unique_msgid溢出导致的，因为这个字段只有16位长，最大也就是65535。当内存中的请求上下文数量超过此值时就可会产生内存错误。按理来说我确实应该在收到dns查询请求时先检查hashtable容量是否足够，但是我现在还没这么做，因为我觉得不应该会堆积65535个请求在内存中。

[zfl9]

可以适当指定 --repeat-times 选项，比如3或者5。一次性向可信dns上游发送多个重复查询请求，可以在一定程度上减轻timeout的问题。而不是设置超长的timeout时间，这不是一个好的做法。

[bzzjh]

多谢回复，也许是梯子不稳定导致的。我尝试使用--repeat-times。
另外请问下，我运行以下命令：
((./chinadns-ng -r -b 0.0.0.0 -l 5453 -c 223.5.5.5 -t 192.168.100.253#5553 -g gfwlist.txt -o 10 -v ) >chinadns-ng.log1 &)
在log1文件里没发现类似
ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid
是不是-v 后err信息无法输入到log1里，也可能是因为-o 10秒了 很难在超时了

[zfl9]

也可能是因为-o 10秒了 很难在超时了?

也许是吧。如果真的这样，我倒觉得你这个梯子是真的慢，5秒都没法返回查询结果。

[bzzjh]

哈哈，最近梯子都不是很稳了

[bzzjh]

依旧就这个问题继续讨论下，
这2天一直在测试，发现假如当可信DNS出现问题的时候（理解为梯子挂了），chinadns-ng进程过一会就会自动挂掉，进程不存在了都。猜测是因为超时导致的，不知道这是不是一个问题。多谢！

[zfl9]

日志呢？你设置的超时多长

[bzzjh]

默认的超时时间5秒
我手动关闭了梯子，导致可信DNS挂掉，这样Chinadns-ng就不停的刷
ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 583

估计当时是因为msgid到顶了，直接coredump了，我猜测的，因为当时进程挂掉 我去看日志没有发现相关的记录。

[bzzjh]

我觉得是否可以考虑加入一个机制，来保护chinadns-ng不会coredump，因为假如客户端很多的话，可信或者国内DNS任何一个挂掉的话，会很快的将msgid刷到65535，到顶，这样进程就死了
不过修改起来是很麻烦的，同时非常感谢作者的分享。

[zfl9]

可以，有时间加上，条数达到65535的时候直接拒绝服务，收到的包全部丢掉。

[bzzjh]

可以，有时间加上，条数达到65535的时候直接拒绝服务，收到的包全部丢掉。

多谢了！那假如达到65535后，上游的DNS之后恢复了，chinadns-ng还会继续工作吧？

[zfl9]

是的

[bzzjh]

今天调试的时候，chinadns-ng上游仅仅断开了5分钟，我看日志msgid只到了3000多，chinadns-ng进程就自己没了（开了两个进程，其他都是默认参数）

[zfl9]

你有很多客户端？你自己能大概估计这5分钟有多少dns解析请求？大概有多少

[bzzjh]

没有很多客户端请求，是在家里测试的，最多四个客户端。我也挺奇怪为啥msgid就到了3000多。而且也不是连续的
chinadns-ng-work$ cat chinadns-ng.log2
2020-03-30 15:56:46 INF: [main] local listen addr: 0.0.0.0#5453
2020-03-30 15:56:46 INF: [main] chinadns server#1: 211.137.58.20#53
2020-03-30 15:56:46 INF: [main] trustdns server#1: 192.168.100.253#5553
2020-03-30 15:56:46 INF: [main] ipset ip4 setname: chnroute
2020-03-30 15:56:46 INF: [main] ipset ip6 setname: chnroute6
2020-03-30 15:56:46 INF: [main] dns query timeout: 5 seconds
2020-03-30 15:56:46 INF: [main] gfwlist entries count: 5640
2020-03-30 15:56:46 INF: [main] enable repeat mode, times: 3
2020-03-30 15:56:46 INF: [main] cur judgment mode: fast mode
2020-03-30 15:56:46 INF: [main] enable SO_REUSEPORT feature
2020-03-30 18:30:55 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 685
2020-03-30 20:06:06 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1011
2020-03-30 20:06:46 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1014
2020-03-30 20:51:08 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1160
2020-03-30 22:21:08 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1373
2020-03-30 22:45:51 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1398
2020-03-30 23:51:08 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1460
2020-03-31 02:01:58 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1577
2020-03-31 02:20:51 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1592
2020-03-31 03:40:21 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1654
2020-03-31 04:50:51 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1689
2020-03-31 05:06:07 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1703
2020-03-31 09:14:58 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 1985
2020-03-31 09:48:27 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 2090
2020-03-31 09:49:40 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 2111
2020-03-31 10:20:52 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 2256
2020-03-31 12:51:45 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 2717
2020-03-31 12:51:48 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 2724
2020-03-31 15:53:27 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 3293
2020-03-31 16:24:55 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 3400
2020-03-31 16:25:00 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 3402
2020-03-31 16:25:00 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 3403
2020-03-31 16:25:00 ERR: [handle_timeout_event] upstream dns server reply timeout, unique msgid: 3404

调试时间就在16:25分左右。

[zfl9]

你做的操作就是手动把上游down了？还是

[zfl9]

我也挺奇怪为啥msgid就到了3000多。而且也不是连续的

我大概说下unique_msg_id是如何计算以及做什么用的。进程启动后(unique_msg_id初始为0)：

1. 收到第一个query，将该query的msg_id替换为unique_msg_id当前的值（也就是0），同时记住原来的msg_id。然后unique_msg_id自增（此时值为1）。
2. 收到第二个query，将该query的msg_id替换为unique_msg_id当前的值（也就是1），同时记住原来的msg_id。然后unique_msg_id自增（此时值为2）。
3. 以此类推。这个unique_msg_id是从0开始自增的，数据类型是uint16_t，一共16位，超过65535后会回绕到0，继续自增，1.2.3.4.5...。unique_msg_id是hashmap的key，用来获取与之关联的query信息（用来拿到原先的msg_id以及其他信息等等）。所以不是说unique_msg_id回绕到0就会出问题，实际上出问题的情况是，hashmap中存在与之相同的unique_msg_id，这时候就会出现hash_key冲突，而uthash默认就没有执行冲突检查，所以会导致coredump。那什么时候会出现相同的unique_msg_id？显然是hashmap中的query_ctx数量达到了65535了。query_ctx删除的时机是：上游返回了，且结果已被采纳。或者是上游超时了，那么timer会自动把这个ctx删了，防止资源泄漏。

[bzzjh]

是的，我上游可信dns修改配置加重启进程，前后应该有5分钟左右。

[bzzjh]

我也挺奇怪为啥msgid就到了3000多。而且也不是连续的

我大概说下unique_msg_id是如何计算以及做什么用的。进程启动后(unique_msg_id初始为0)：

1. 收到第一个query，将该query的msg_id替换为unique_msg_id当前的值（也就是0），同时记住原来的msg_id。然后unique_msg_id自增（此时值为1）。
2. 收到第二个query，将该query的msg_id替换为unique_msg_id当前的值（也就是1），同时记住原来的msg_id。然后unique_msg_id自增（此时值为2）。
3. 以此类推。这个unique_msg_id是从0开始自增的，数据类型是uint16_t，一共16位，超过65535后会回绕到0，继续自增，1.2.3.4.5...。unique_msg_id是hashmap的key，用来获取与之关联的query信息（用来拿到原先的msg_id以及其他信息等等）。所以不是说unique_msg_id回绕到0就会出问题，实际上出问题的情况是，hashmap中存在与之相同的unique_msg_id，这时候就会出现hash_key冲突，而uthash默认就没有执行冲突检查，所以会导致coredump。那什么时候会出现相同的unique_msg_id？显然是hashmap中的query_ctx数量达到了65535了。query_ctx删除的时机是：上游返回了，且结果已被采纳。或者是上游超时了，那么timer会自动把这个ctx删了，防止资源泄漏。

多谢这么详细的回复，我消化下，那以后上游可信调试的时候，我顺便也去重启或者再运行一次chinadns-ng.再次感谢伟大作者，多谢！

[zfl9]

更新再试下吧？看看是否还会出现coredump（因为看你描述不是很确定是不是这个问题）。

[zfl9]

@bzzjh

[bzzjh]

更新再试下吧？看看是否还会出现coredump（因为看你描述不是很确定是不是这个问题）。

好的，多谢！

[zfl9]

意外发现另外一个可能的导致coredump的bug，已经改了，再更新测试下稳定性。

[zfl9]

b20

[bzzjh]

意外发现另外一个可能的导致coredump的bug，已经改了，再更新测试下稳定性。

多谢！
之前的更新后运行到现在暂时没出现问题