ngx.socket.tcp 的一点疑问

[赵安家]

问题背景

openresty/lua-resty-core#ngx.socket.tcp cannot send msg to logstash

cloudflare/lua-resty-logger-socket#cannot send log to logstash by tcp protocol

想基于cloudflare/lua-resty-logger-socket使用tcp协议将log写入到logstash. (udp 有64K 大小限制? google对这个说法也是莫衷一是 https://www.google.com/search?q=udp+payload+maximum+size ，不过 https://www.elastic.co/guide/en/logstash/current/plugins-inputs-udp.html#plugins-inputs-udp-buffer_size  buffer_size默认是65536 (1024*64=65536))

但是在测试中发现，如果将sock:setkeepalive 中的timeout设置为0，根据 文档 tcpsock:setkeepalive 中所说， 

> If the 0 value is given, then the timeout interval is unlimited.

如果timeout为0，则永不过期，本身没啥问题，但是在写入logstash中，如果timeout为0，则数据无法落到logstash中，(但是此时如果service openresty reload  logstash会将之前发送的一并打印出来),同时根据tcpdump或者wireshark的抓包显示，每次sock:send都有发送数据给logstash

如果timeout>0,而且logstash的tcp input plugin的codec plugin 设置为plain，则logstash可以将msg及时打印出来。

但是如果是tcp的codec plugin 设置为json或者json_lines，则还需要在 msg后追加换行符  类似这样 sock:send(msg .. "\\n")

我本身对tcp，udp协议一窍不通，虽然用tcpdump或者wireshark进行了抓包，但是也看不出啥问题来。

是ngx.socket.tcp在通信中没有向服务端通信时发送终止符(? 我也不太清楚专业术语)，还是说ngx.socket.tcp本身没问题，可能是logstash在处理时有问题。

在使用telnet 进行模拟通信的时候，logstash 都正常能接受数据，哪怕是用curl 请求logstash的开的tcp端口，也可以正常接受数据。

求大神指点。

[Zexuan Luo]

logstash 的 tcp input 里面，json或json_lines都是需要有一个换行符才能触发事件的生成。
有试过 timeout=0，且 codec plugin 设置为 plain，logstash 能把 msg 及时打印出来吗？

另外，按你的描述，
> 但是此时如果service openresty reload  logstash会将之前发送的一并打印出来

看样子 logstash 应该收到了，只是没有触发对应的事件。建议运行 logstash 的时候，加上 --debug 选项，看看具体是什么情况？

--
--
邮件来自列表“openresty”,专用于技术讨论!
订阅: 请发空白邮件到 openresty+subscribe@googlegroups.com
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+unsubscribe@googlegroups.com
归档: http://groups.google.com/group/openresty
官网: http://openresty.org/
仓库: https://github.com/agentzh/ngx_openresty
教程: http://openresty.org/download/agentzh-nginx-tutorials-zhcn.html

[赵安家]

感谢回复，刚刚issues上春哥回复，使用linux nc命令监听tcp端口发现有msg发过来(即使timeout为0)，看样子应该是logstash的问题，设置成plain可以及时打印出来，设置json，或者json_lines，需要追加换行符

发自网易邮箱大师

订阅: 请发空白邮件到 openresty...@googlegroups.com
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+...@googlegroups.com

[赵安家]

经过我的测试，发现之所以curl或者telnet可以直接写入logstash而ngx.socket.tcp不行，原因在于，telnet会自动追加换行符，curl走的是http协议，而header等也是用换行符来分割。

详见 https://github.com/openresty/lua-resty-core/issues/142#issuecomment-328410830

同时我发现，跟timeout是否等于0其实关系不大，只需要在msg后 .. "\\n" 追加换行符，logstash就都可以正确接受并处理。看起来logstash是以换行符作为一次tcp请求中止的标示。

但是通过 nc -ul 5044 监听udp报文发现，如果是udp协议发送，即使没有换行符，logstash也可以正确接受，很费解。

看了一下codec的源码，一头雾水 (ruby) 

codec json

https://github.com/logstash-plugins/logstash-codec-json/blob/master/lib/logstash/codecs/json.rb

codec json_lines

https://github.com/logstash-plugins/logstash-codec-json_lines/blob/master/lib/logstash/codecs/json_lines.rb

codec plain

https://github.com/logstash-plugins/logstash-codec-plain/blob/master/lib/logstash/codecs/plain.rb


在input tcp plugin

https://github.com/logstash-plugins/logstash-input-tcp/blob/master/lib/logstash/inputs/tcp.rb#L248 有根据换行符split

而在input udp plugin中没有split("\r\n")

https://github.com/logstash-plugins/logstash-input-udp/blob/master/lib/logstash/inputs/udp.rb

在 2017年9月11日星期一 UTC+8上午11:14:28，Zexuan Luo写道：

logstash 的 tcp input 里面，json或json_lines都是需要有一个换行符才能触发事件的生成。
有试过 timeout=0，且 codec plugin 设置为 plain，logstash 能把 msg 及时打印出来吗？

另外，按你的描述，
> 但是此时如果service openresty reload  logstash会将之前发送的一并打印出来

看样子 logstash 应该收到了，只是没有触发对应的事件。建议运行 logstash 的时候，加上 --debug 选项，看看具体是什么情况？

在 2017年9月10日 下午9:36，赵安家 <anji...@gmail.com>写道：

问题背景

openresty/lua-resty-core#ngx.socket.tcp cannot send msg to logstash

cloudflare/lua-resty-logger-socket#cannot send log to logstash by tcp protocol

想基于cloudflare/lua-resty-logger-socket使用tcp协议将log写入到logstash. (udp 有64K 大小限制? google对这个说法也是莫衷一是 https://www.google.com/search?q=udp+payload+maximum+size ，不过 https://www.elastic.co/guide/en/logstash/current/plugins-inputs-udp.html#plugins-inputs-udp-buffer_size  buffer_size默认是65536 (1024*64=65536))

但是在测试中发现，如果将sock:setkeepalive 中的timeout设置为0，根据 文档 tcpsock:setkeepalive 中所说， 

> If the 0 value is given, then the timeout interval is unlimited.

如果timeout为0，则永不过期，本身没啥问题，但是在写入logstash中，如果timeout为0，则数据无法落到logstash中，(但是此时如果service openresty reload  logstash会将之前发送的一并打印出来),同时根据tcpdump或者wireshark的抓包显示，每次sock:send都有发送数据给logstash

如果timeout>0,而且logstash的tcp input plugin的codec plugin 设置为plain，则logstash可以将msg及时打印出来。

但是如果是tcp的codec plugin 设置为json或者json_lines，则还需要在 msg后追加换行符  类似这样 sock:send(msg .. "\\n")

我本身对tcp，udp协议一窍不通，虽然用tcpdump或者wireshark进行了抓包，但是也看不出啥问题来。

是ngx.socket.tcp在通信中没有向服务端通信时发送终止符(? 我也不太清楚专业术语)，还是说ngx.socket.tcp本身没问题，可能是logstash在处理时有问题。

在使用telnet 进行模拟通信的时候，logstash 都正常能接受数据，哪怕是用curl 请求logstash的开的tcp端口，也可以正常接受数据。

求大神指点。

--
--
邮件来自列表“openresty”,专用于技术讨论!

订阅: 请发空白邮件到 openresty...@googlegroups.com
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+...@googlegroups.com

[Zexuan Luo]

正好我以前看过一部分 logstash 的代码，所以对于这一块还算熟悉。

刚刚抽空看了下代码
https://github.com/elastic/logstash/blob/458910bcb9db9441dbb9b851ea52fd79108727c1/logstash-core/lib/logstash/inputs/base.rb#L124
fix_streaming_codecs 这个方法会把 json codec 换成 json_lines codec 这种带分隔符的 codec
注意 tcp 是 streaming 的，如果在 input tcp 里面配置了 json codec，等价于配置了 json_lines codec。

然后在
https://github.com/logstash-plugins/logstash-codec-json_lines/blob/master/lib/logstash/codecs/json_lines.rb#L40
@buffer.extract(data).each

这里 buffer 来自于 logstash/util/buftok

而
https://github.com/elastic/logstash/blob/master/logstash-core/lib/logstash/util/buftok.rb#L60
extract 这个方法，会根据分隔符，这里就是换行符了，去 split 输入的 data。剩余部分（就是找不到分隔符的部分）会加到 @input 这个实例变量中来。


所以我猜测 codec 为 json/json_lines 且 input 为 tcp 时，logstash 会等待换行符来标记一次发送的结束。如果一直不发送换行符，数据就一直堆积在 @input 里面，只有在退出的时候才输出。

订阅: 请发空白邮件到 openresty+subscribe@googlegroups.com
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+unsubscribe@googlegroups.com

[赵安家]

非常感谢您的耐心解答，看ruby一头雾水啊。跟类C语言完全不是一个风格。哈哈

这次因为这个问题也学到了很多东西。再次感谢 : )

在 2017年9月11日星期一 UTC+8下午3:05:51，Zexuan Luo写道：

[00 00]

真的是一个难以想象的问题，没想到最后加一个\n解决……之前一直以为 lua_code_cache on/off 对flush buffer有影响（在我这确实是这个现象，lua_code_cache off就能正常写入，on就不行）