After enabling debug logs in nginx I can see the following logs. As I can see, the timeout value is still 200 ms even in the 2nd iteration, but for any reason it is not used.
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:365 [netconf] In the while loop
2019/03/31 18:53:14 [debug] 45#0: *77 stream lua tcp socket receiveuntil iterator
2019/03/31 18:53:14 [debug] 45#0: *77 stream lua tcp socket read timeout: 200
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:367 [netconf] After the downstreamreader
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:368 [netconf] downstream err: nil
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:369 [netconf] downstream partial:nil
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:370 [netconf] downstream data:nil
2019/03/31 18:53:14 [debug] 45#0: *77 [kong] handler.lua:365 [netconf] In the while loop
2019/03/31 18:53:14 [debug] 45#0: *77 stream lua tcp socket receiveuntil iterator
2019/03/31 18:53:14 [debug] 45#0: *77 stream lua tcp socket read timeout: 200
2019/03/31 18:53:14 [debug] 45#0: *77 stream lua tcp socket read data: wait:0
2019/03/31 18:53:14 [debug] 45#0: *77 event timer add: 17: 200:1554058395055
2019/03/31 18:53:14 [debug] 45#0: *77 lua resume returned 1
2019/03/31 18:53:14 [debug] 45#0: *77 lua thread yielded
2019/03/31 18:53:14 [debug] 45#0: *77 lua run thread returned -2
2019/03/31 18:53:14 [debug] 45#0: *77 event timer del: 17: 1554058395055
2019/03/31 18:53:14 [debug] 45#0: timer delta: 0
2019/03/31 18:53:14 [debug] 45#0: worker cycle
2019/03/31 18:53:14 [debug] 45#0: epoll timer: 583
2019/03/31 18:53:15 [debug] 45#0: timer delta: 712
2019/03/31 18:53:15 [debug] 45#0: event timer del: 1096322376: 1554058395438
2019/03/31 18:53:15 [debug] 45#0: lua ngx.timer expired
2019/03/31 18:53:15 [debug] 45#0: malloc: 000055D37F3E6C20:80
2019/03/31 18:53:15 [debug] 45#0: malloc: 000055D37F3DC220:1400
2019/03/31 18:53:15 [debug] 45#0: malloc: 000055D37F3E1920:512
2019/03/31 18:53:15 [debug] 45#0: malloc: 000055D37F34ED80:408
2019/03/31 18:53:15 [debug] 45#0: posix_memalign: 000055D37F3D04E0:128 @16
2019/03/31 18:53:15 [debug] 45#0: *118 http cleanup add: 000055D37F3D0510
2019/03/31 18:53:15 [debug] 45#0: *118 lua run thread, top:0 c:1
2019/03/31 18:53:15 [debug] 45#0: fetching key "events-last" in shared dict "kong_process_events"
2019/03/31 18:53:15 [debug] 45#0: shmtx lock
2019/03/31 18:53:15 [debug] 45#0: shmtx unlock
2019/03/31 18:53:15 [debug] 45#0: *118 malloc: 000055D37F3E4000:184
2019/03/31 18:53:15 [debug] 45#0: posix_memalign: 000055D37F3DCDE0:128 @16
2019/03/31 18:53:15 [debug] 45#0: event timer add: 1087101016: 1000:1554058396567
2019/03/31 18:53:15 [debug] 45#0: *118 lua resume returned 0
2019/03/31 18:53:15 [debug] 45#0: *118 lua light thread ended normally
2019/03/31 18:53:15 [debug] 45#0: *118 lua deleting light thread
2019/03/31 18:53:15 [debug] 45#0: *118 http lua finalize fake request: 0, a:1, c:1
2019/03/31 18:53:15 [debug] 45#0: *118 http lua fake request count:1
2019/03/31 18:53:15 [debug] 45#0: *118 http lua close fake request
2019/03/31 18:53:15 [debug] 45#0: *118 lua request cleanup: forcible=0
2019/03/31 18:53:15 [debug] 45#0: *118 http lua close fake http connection 00007F44DEEC3B00
On Sunday, March 31, 2019 at 5:41:41 PM UTC+2, Laszlo Janosi wrote:
Hi,
I would like to ask for your help.
It is OpenResty 1.13.6.2.
I try using receiveuntil+settimeout on a TCP socket obtained with ngx.req.socket(true) at preread phase. I use a "while true" construct to poll the socket infinitely. Like this:
local downstream_socket, err = ngx.req.socket(true)
local reader = downstream_socket:receiveuntil(mypattern_1)
...(reader() based processing here)...
local downstreamreader = downstream_socket:receiveuntil(mypattern_2)
downstream_socket:settimeout(200)
while true do
local data = ""> local err = nil
local partial = nil
kong.log.debug("In the while loop")
data, err, partial = downstreamreader(max_msg_size)
kong.log.debug("After the downstreamreader")
kong.log.debug("downstream err: ", err)
kong.log.debug("downstream partial:", partial)
kong.log.debug("downstream data:", data)
end
It runs on Kong (which uses OpenResty inside). As you can see, I have to read data first with mypattern_1, and if it is successful I have to change to another pattern (mypattern_2), and all other traffic is expected to use this second pattern from that point.
After I successfully process the data read with mypattern_1 I get the following log pattern in the while loop:
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:365 [netconf] In the while loop
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:367 [netconf] After the downstreamreader
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:368 [netconf] downstream err: nil
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:369 [netconf] downstream partial:nil
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:370 [netconf] downstream data:nil
2019/03/31 15:09:23 [debug] 632#0: *62267 [kong] handler.lua:365 [netconf] In the while loop
Then it hangs here. As I do not send any data on the connection (after the data with mypattern_1 of course) I would expect that these logs are being written continuously, in every iteration, but it does not happen.
If any time I write data to the connection with the proper "mypattern_2" the downstreamreader() returns and I get the data so I can process that. But it seems, that the timeout value set by settimeout() is considered only once, in the first iteration, and in the next round the downstreamreader() does not consider the timeout value anymore. At least, it does not return after the configured time.
I also tried to the following:
- put the settimeout() call into the while loop, so it is called in every iteration -> no difference in the result
- re-initialize downstreamreader inside the while loop at every iteration -> no difference in the result.
I would like to see that the downstreamreader() returns after the time I configured with settimeout(), because in the same while loop I would like to process other tings if there is no data on the socket.
Could you please help where I am wrong with the usage of receiveuntil and settimeout?
Thank you!
