Luasocket select/timeout problems on UDP

classic Classic list List threaded Threaded
15 messages Options
Reply | Threaded
Open this post in threaded view
|

Luasocket select/timeout problems on UDP

Jim Mellander
My application asynchronously receives UDP packets from several sources,
but timeouts seem to be problematic.  My code looks like this:

-- Initialize
for i=1,5 do            -- FIXME: count shouldnt be hard coded
         local udp
         host=datasources[i].host
         port=datasources[i].port
         DEBUG("Binding to host '" ..host.. "' and port " ..port.. "...")
         udp = assert(socket.udp())
         assert(udp:setsockname(host, port))
         ip, port = udp:getsockname()
         assert(ip, port)
         DEBUG("Waiting for packets on " .. ip .. ":" .. port .. "...")
         receive_sockets[i] = udp
end

while 1 do

        socket_timeout = whatever -- Computed timeout

         -- Make sure each individual socket has the same timeout
         for i=1,5 do    -- FIXME, remove hardcode
                 local udp = receive_sockets[i]
                 assert(udp:settimeout(socket_timeout))
         end

         -- Wait on sockets
         local readable,writable,e=socket.select(receive_sockets, nil,
socket_timeout)

         local src,_
         for src,_ in ipairs(readable) do
                 local udp=receive_sockets[src]

                 local dgram, ip, port = udp:receivefrom()
                 if dgram then
                        DEBUG("Packet received on "..ip.."/"..port.." "..string.len(dgram).."
bytes")
                        process_dgram(dgram)
                 end
         end
end



=========================================================

What happens is that the select waits for the computed timeout, despite
the fact that packets are being recieved in the interim (verified by
capturing packets via tcpdump).  I recompile luasocket to use poll
instead of select, but the problem persists.

Using Luasocket 2.0, Luajit 1.1.0 (problem also occurs on Lua 5.1) on
Freebsd 4.10









--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

Always borrow money from a pessimist; he doesn't expect to be paid back.

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

This works fine on Mac OS X 10.4.6 and on Linux 2.6.15. Can you try this
code on your machine?

     http://www.cs.princeton.edu/~diego/udp

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander
flood.lua continually prints:

udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4
udp{unconnected}: 0x807fed4
4


whilst server.lua gives:

Binding to host '127.0.0.1' and port 8081...
Waiting for packets on 127.0.0.1:8081...
Binding to host '127.0.0.1' and port 8082...
Waiting for packets on 127.0.0.1:8082...
Binding to host '127.0.0.1' and port 8083...
Waiting for packets on 127.0.0.1:8083...
Binding to host '127.0.0.1' and port 8084...
Waiting for packets on 127.0.0.1:8084...
Binding to host '127.0.0.1' and port 8085...
Waiting for packets on 127.0.0.1:8085...
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes
Packet received on 127.0.0.1/2193 4 bytes



Doesn't look right..






Diego Nehab wrote:

> Hi,
>
> This works fine on Mac OS X 10.4.6 and on Linux 2.6.15. Can you try this
> code on your machine?
>
>     http://www.cs.princeton.edu/~diego/udp
>
> Regards,
> Diego.
>

--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

This login session: $13.99

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

> flood.lua continually prints:
[snip]

This it what it should print.

> whilst server.lua gives:
>
> Binding to host '127.0.0.1' and port 8081...
> Waiting for packets on 127.0.0.1:8081...
> Binding to host '127.0.0.1' and port 8082...
> Waiting for packets on 127.0.0.1:8082...
> Binding to host '127.0.0.1' and port 8083...
> Waiting for packets on 127.0.0.1:8083...
> Binding to host '127.0.0.1' and port 8084...
> Waiting for packets on 127.0.0.1:8084...
> Binding to host '127.0.0.1' and port 8085...
> Waiting for packets on 127.0.0.1:8085...
> Packet received on 127.0.0.1/2193 4 bytes
> Packet received on 127.0.0.1/2193 4 bytes
> Packet received on 127.0.0.1/2193 4 bytes
> Packet received on 127.0.0.1/2193 4 bytes

Did you notice how fast these packets arrive? If select is blocking
until timeout, they should come every second. If select returns whenever
a packet arrives, they should come every 1/2 second. What is it in your
system? As I said, on Linux and on Mac OS X, this works, and the packet
messages come every 1/2 second.

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander


Diego Nehab wrote:
<snip>

>
> Did you notice how fast these packets arrive? If select is blocking
> until timeout, they should come every second. If select returns whenever
> a packet arrives, they should come every 1/2 second. What is it in your
> system? As I said, on Linux and on Mac OS X, this works, and the packet
> messages come every 1/2 second.
>
> Regards,
> Diego.
>

I modified flood.lua to send n bytes when it is sending to
datasources[n], and modified server.lua to print the unix timestamp, now
I get:


1144798013 Binding to host '127.0.0.1' and port 8081...
1144798013 Waiting for packets on 127.0.0.1:8081...
1144798013 Binding to host '127.0.0.1' and port 8082...
1144798013 Waiting for packets on 127.0.0.1:8082...
1144798013 Binding to host '127.0.0.1' and port 8083...
1144798013 Waiting for packets on 127.0.0.1:8083...
1144798013 Binding to host '127.0.0.1' and port 8084...
1144798013 Waiting for packets on 127.0.0.1:8084...
1144798013 Binding to host '127.0.0.1' and port 8085...
1144798013 Waiting for packets on 127.0.0.1:8085...
1144798013 Packet received from 127.0.0.1/1365 1 bytes
1144798013 Packet received from 127.0.0.1/1365 1 bytes
1144798014 Packet received from 127.0.0.1/1365 1 bytes
1144798014 Packet received from 127.0.0.1/1365 2 bytes
1144798014 Packet received from 127.0.0.1/1365 3 bytes
1144798014 Packet received from 127.0.0.1/1365 4 bytes
1144798014 Packet received from 127.0.0.1/1365 1 bytes
1144798014 Packet received from 127.0.0.1/1365 2 bytes
1144798014 Packet received from 127.0.0.1/1365 3 bytes
1144798014 Packet received from 127.0.0.1/1365 4 bytes
1144798015 Packet received from 127.0.0.1/1365 1 bytes
1144798015 Packet received from 127.0.0.1/1365 2 bytes
1144798015 Packet received from 127.0.0.1/1365 3 bytes
1144798015 Packet received from 127.0.0.1/1365 4 bytes
1144798016 Packet received from 127.0.0.1/1365 1 bytes
1144798016 Packet received from 127.0.0.1/1365 2 bytes
1144798016 Packet received from 127.0.0.1/1365 3 bytes
1144798016 Packet received from 127.0.0.1/1365 4 bytes
1144798016 Packet received from 127.0.0.1/1365 1 bytes
1144798016 Packet received from 127.0.0.1/1365 2 bytes
1144798016 Packet received from 127.0.0.1/1365 3 bytes
1144798016 Packet received from 127.0.0.1/1365 4 bytes
1144798017 Packet received from 127.0.0.1/1365 1 bytes
1144798017 Packet received from 127.0.0.1/1365 2 bytes
1144798017 Packet received from 127.0.0.1/1365 3 bytes
1144798017 Packet received from 127.0.0.1/1365 4 bytes
1144798017 Packet received from 127.0.0.1/1365 1 bytes
1144798017 Packet received from 127.0.0.1/1365 2 bytes
1144798017 Packet received from 127.0.0.1/1365 3 bytes
1144798017 Packet received from 127.0.0.1/1365 4 bytes

The timing seems faster than expected, and the 5th expected datasource
is not seem.  Does this give any insight into the problem?

--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

Nothing will dispel enthusiasm like a small admission fee.
                -- Kim Hubbard

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander
Jim Mellander wrote:

>
>
> Diego Nehab wrote:
> <snip>
>
>>
>> Did you notice how fast these packets arrive? If select is blocking
>> until timeout, they should come every second. If select returns whenever
>> a packet arrives, they should come every 1/2 second. What is it in your
>> system? As I said, on Linux and on Mac OS X, this works, and the packet
>> messages come every 1/2 second.
>>
>> Regards,
>> Diego.
>>
>
> I modified flood.lua to send n bytes when it is sending to
> datasources[n], and modified server.lua to print the unix timestamp, now
> I get:
>
>
> 1144798013 Binding to host '127.0.0.1' and port 8081...
> 1144798013 Waiting for packets on 127.0.0.1:8081...
> 1144798013 Binding to host '127.0.0.1' and port 8082...
> 1144798013 Waiting for packets on 127.0.0.1:8082...
> 1144798013 Binding to host '127.0.0.1' and port 8083...
> 1144798013 Waiting for packets on 127.0.0.1:8083...
> 1144798013 Binding to host '127.0.0.1' and port 8084...
> 1144798013 Waiting for packets on 127.0.0.1:8084...
> 1144798013 Binding to host '127.0.0.1' and port 8085...
> 1144798013 Waiting for packets on 127.0.0.1:8085...
> 1144798013 Packet received from 127.0.0.1/1365 1 bytes
> 1144798013 Packet received from 127.0.0.1/1365 1 bytes
> 1144798014 Packet received from 127.0.0.1/1365 1 bytes
> 1144798014 Packet received from 127.0.0.1/1365 2 bytes
> 1144798014 Packet received from 127.0.0.1/1365 3 bytes
> 1144798014 Packet received from 127.0.0.1/1365 4 bytes
> 1144798014 Packet received from 127.0.0.1/1365 1 bytes
> 1144798014 Packet received from 127.0.0.1/1365 2 bytes
> 1144798014 Packet received from 127.0.0.1/1365 3 bytes
> 1144798014 Packet received from 127.0.0.1/1365 4 bytes
> 1144798015 Packet received from 127.0.0.1/1365 1 bytes
> 1144798015 Packet received from 127.0.0.1/1365 2 bytes
> 1144798015 Packet received from 127.0.0.1/1365 3 bytes
> 1144798015 Packet received from 127.0.0.1/1365 4 bytes
> 1144798016 Packet received from 127.0.0.1/1365 1 bytes
> 1144798016 Packet received from 127.0.0.1/1365 2 bytes
> 1144798016 Packet received from 127.0.0.1/1365 3 bytes
> 1144798016 Packet received from 127.0.0.1/1365 4 bytes
> 1144798016 Packet received from 127.0.0.1/1365 1 bytes
> 1144798016 Packet received from 127.0.0.1/1365 2 bytes
> 1144798016 Packet received from 127.0.0.1/1365 3 bytes
> 1144798016 Packet received from 127.0.0.1/1365 4 bytes
> 1144798017 Packet received from 127.0.0.1/1365 1 bytes
> 1144798017 Packet received from 127.0.0.1/1365 2 bytes
> 1144798017 Packet received from 127.0.0.1/1365 3 bytes
> 1144798017 Packet received from 127.0.0.1/1365 4 bytes
> 1144798017 Packet received from 127.0.0.1/1365 1 bytes
> 1144798017 Packet received from 127.0.0.1/1365 2 bytes
> 1144798017 Packet received from 127.0.0.1/1365 3 bytes
> 1144798017 Packet received from 127.0.0.1/1365 4 bytes
>
> The timing seems faster than expected, and the 5th expected datasource
> is not seem.  Does this give any insight into the problem?
>

Actually, I guess the timing is OK, since we're sleeping for .5 secs
after sending all packets, but the 5th datasource is being skipped.

BTW - I have luasocket compiled to use the poll syscall instead of
select, in hopes of fixing my problem, but so far, no luck...


--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

The goal of science is to build better mousetraps.  The goal of nature
is to build better mice.

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

>> The timing seems faster than expected, and the 5th expected datasource is
>> not seem.  Does this give any insight into the problem?
>
> Actually, I guess the timing is OK, since we're sleeping for .5 secs after
> sending all packets, but the 5th datasource is being skipped.

Your original complaint was about the timing, right? Can you revert to
the original LuaSocket and test if the timing is correct?

> BTW - I have luasocket compiled to use the poll syscall instead of select, in
> hopes of fixing my problem, but so far, no luck...

I have no experience with BSD, but I don't expect select to be broken.

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
In reply to this post by Jim Mellander
Hi,

I checked the code again on Mac OS X and Linux. It works as expected.

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander
In reply to this post by Diego Nehab-3
Hi Diego:

Thanks for your continuing assistance.  My complaint is not entirely the
timing, but would be more precisely the timing to accurately receive all
the data - I've had to run a tight loop polling all the sockets, as
select seems not to accurately return the status of all the sockets.

I've changed flood.lua to only send to 2 sockets, and server.lua binding
to all 5.  Here we see server.lua only seeing the first socket:

1144856783 Binding to host '127.0.0.1' and port 8081...
1144856783 Waiting for packets on 127.0.0.1:8081...
1144856783 Binding to host '127.0.0.1' and port 8082...
1144856783 Waiting for packets on 127.0.0.1:8082...
1144856783 Binding to host '127.0.0.1' and port 8083...
1144856783 Waiting for packets on 127.0.0.1:8083...
1144856783 Binding to host '127.0.0.1' and port 8084...
1144856783 Waiting for packets on 127.0.0.1:8084...
1144856783 Binding to host '127.0.0.1' and port 8085...
1144856783 Waiting for packets on 127.0.0.1:8085...
1144856784 Packet received from 127.0.0.1/2568 1 bytes
1144856784 Packet received from 127.0.0.1/2568 1 bytes
1144856785 Packet received from 127.0.0.1/2568 1 bytes
1144856785 Packet received from 127.0.0.1/2568 1 bytes
1144856786 Packet received from 127.0.0.1/2568 1 bytes
1144856786 Packet received from 127.0.0.1/2568 1 bytes


This, along with the previous info (not setting #5 when 5 sockets are
being used) suggests that the status for the *last* socket in the select
is not being returned accurately.  Above run made with SOCKET_POLL
defined when building luasocket, causing it to use the poll system call.
   Running 'top' shows the process in 'poll' most of the time, as
expected (LUASOCKET_DEBUG also defined)

(Time passes)

OK, luasocket recompiled with SOCKET_POLL undefined, top shows process
in'select' most of the time, same behavior:

1144857761 Binding to host '127.0.0.1' and port 8081...
1144857761 Waiting for packets on 127.0.0.1:8081...
1144857761 Binding to host '127.0.0.1' and port 8082...
1144857761 Waiting for packets on 127.0.0.1:8082...
1144857761 Binding to host '127.0.0.1' and port 8083...
1144857761 Waiting for packets on 127.0.0.1:8083...
1144857761 Binding to host '127.0.0.1' and port 8084...
1144857761 Waiting for packets on 127.0.0.1:8084...
1144857761 Binding to host '127.0.0.1' and port 8085...
1144857761 Waiting for packets on 127.0.0.1:8085...
1144857761 Packet received from 127.0.0.1/3304 1 bytes
1144857761 Packet received from 127.0.0.1/3304 1 bytes
1144857762 Packet received from 127.0.0.1/3304 1 bytes
1144857762 Packet received from 127.0.0.1/3304 1 bytes
1144857763 Packet received from 127.0.0.1/3304 1 bytes
1144857763 Packet received from 127.0.0.1/3304 1 bytes
1144857764 Packet received from 127.0.0.1/3304 1 bytes
1144857764 Packet received from 127.0.0.1/3304 1 bytes
1144857765 Packet received from 127.0.0.1/3304 1 bytes
1144857765 Packet received from 127.0.0.1/3304 1 bytes
1144857766 Packet received from 127.0.0.1/3304 1 bytes
1144857766 Packet received from 127.0.0.1/3304 1 bytes

It looks like an off-by-one error.  BTW - I note (or think I do,
anyway), that defining SOCKET_POLL only changes the timeout function for
an individual socket (socket_waitfd), but the actual lua select function
will always use select in any event.

As a dreadful hack I changed:
ret = select(n, rfds, wfds, efds, t >= 0.0 ? &tv: NULL);

to

ret = select(1024, rfds, wfds, efds, t >= 0.0 ? &tv: NULL);

in socket_select.c to see if that would make a difference, to no avail.

Running truss on the running 'lua server.lua' gives in a recurring pattern:

select(0x400,0xbfbff630,0xbfbff5b0,0x0,0xbfbff510) = 1 (0x1)
gettimeofday(0xbfbfd624,0x0)                     = 0 (0x0)
recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) ERR#35
'Resource temporarily unavailable'
gettimeofday(0xbfbfd494,0x0)                     = 0 (0x0)
select(0x4,0xbfbfd590,0x0,0x0,0xbfbfd500)        = 1 (0x1)
recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) = 1 (0x1)
gettimeofday(0xbfbff638,0x0)                     = 0 (0x0)
write(1,0x80ad000,55)                            = 55 (0x37)
gettimeofday(0xbfbff504,0x0)                     = 0 (0x0)
gettimeofday(0xbfbff4b4,0x0)                     = 0 (0x0)
select(0x400,0xbfbff630,0xbfbff5b0,0x0,0xbfbff510) = 1 (0x1)
gettimeofday(0xbfbfd624,0x0)                     = 0 (0x0)
recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) ERR#35
'Resource temporarily unavailable'


I note that select() is only returning 1, indicating that only 1 socket
is readable, and the first socket that recvfrom() attempts is a failure,
but the next select() & recvfrom() works.

I'll dig further, but I find it hard to believe that it is a Freebsd bug
(I'm a bit biased, since the BSD networking code was developed here at
LBL).  Perhaps there's an interpretation difference in the expected
parameters.



Diego Nehab wrote:

> Hi,
>
>>> The timing seems faster than expected, and the 5th expected
>>> datasource is not seem.  Does this give any insight into the problem?
>>
>>
>> Actually, I guess the timing is OK, since we're sleeping for .5 secs
>> after sending all packets, but the 5th datasource is being skipped.
>
>
> Your original complaint was about the timing, right? Can you revert to
> the original LuaSocket and test if the timing is correct?
>
>> BTW - I have luasocket compiled to use the poll syscall instead of
>> select, in hopes of fixing my problem, but so far, no luck...
>
>
> I have no experience with BSD, but I don't expect select to be broken.
>
> Regards,
> Diego.
>

--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

Never be afraid to tell the world who you are.
                -- Anonymous

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

> I'll dig further, but I find it hard to believe that it is a Freebsd bug (I'm
> a bit biased, since the BSD networking code was developed here at LBL).
> Perhaps there's an interpretation difference in the expected parameters.

I have been exchanging e-mails privately with Jonathan Gray, and he does
not confirm your problem.

     -- Jonathan Gray Wrote:
     On OpenBSD amd64 -current with

     gray's machine$ pkg_info | fgrep lua
     lua-5.0.2p6         powerful, light-weight programming language
     luacompat-5.1r4     compatibility module for lua 5.1
     luasocket-2.0p1     network support for the lua language

     0.00012803077697754 (should be 0.5, but unoffical patch messes things up)
     Packet received on 127.0.0.1/36630 1 bytes
     Packet received on 127.0.0.1/36630 2 bytes
     Packet received on 127.0.0.1/36630 3 bytes
     Packet received on 127.0.0.1/36630 4 bytes
     Packet received on 127.0.0.1/36630 5 bytes
     0.00011992454528809
     ...

Also, we noticed unofficial patches to LuaSocket in the OpenBSD
distribution that caused at least one bug. I don't have access to
OpenBSD, nor can I control this kind of patch.

Can you two please help me figure this one out?

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

Could this be a LuaSocket issue with Lua 5.1??? Hmmmm. Will check later
tonight.

Regards,
Diego.
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander
In reply to this post by Jim Mellander
I verified the code to work perfectly on Linux using Lua 5.1.  There
presumably is a bug in the interaction with FreeBSD.  I'm going to be
looking into it.

Jim Mellander wrote:

> Hi Diego:
>
> Thanks for your continuing assistance.  My complaint is not entirely the
> timing, but would be more precisely the timing to accurately receive all
> the data - I've had to run a tight loop polling all the sockets, as
> select seems not to accurately return the status of all the sockets.
>
> I've changed flood.lua to only send to 2 sockets, and server.lua binding
> to all 5.  Here we see server.lua only seeing the first socket:
>
> 1144856783 Binding to host '127.0.0.1' and port 8081...
> 1144856783 Waiting for packets on 127.0.0.1:8081...
> 1144856783 Binding to host '127.0.0.1' and port 8082...
> 1144856783 Waiting for packets on 127.0.0.1:8082...
> 1144856783 Binding to host '127.0.0.1' and port 8083...
> 1144856783 Waiting for packets on 127.0.0.1:8083...
> 1144856783 Binding to host '127.0.0.1' and port 8084...
> 1144856783 Waiting for packets on 127.0.0.1:8084...
> 1144856783 Binding to host '127.0.0.1' and port 8085...
> 1144856783 Waiting for packets on 127.0.0.1:8085...
> 1144856784 Packet received from 127.0.0.1/2568 1 bytes
> 1144856784 Packet received from 127.0.0.1/2568 1 bytes
> 1144856785 Packet received from 127.0.0.1/2568 1 bytes
> 1144856785 Packet received from 127.0.0.1/2568 1 bytes
> 1144856786 Packet received from 127.0.0.1/2568 1 bytes
> 1144856786 Packet received from 127.0.0.1/2568 1 bytes
>
>
> This, along with the previous info (not setting #5 when 5 sockets are
> being used) suggests that the status for the *last* socket in the select
> is not being returned accurately.  Above run made with SOCKET_POLL
> defined when building luasocket, causing it to use the poll system call.
>   Running 'top' shows the process in 'poll' most of the time, as
> expected (LUASOCKET_DEBUG also defined)
>
> (Time passes)
>
> OK, luasocket recompiled with SOCKET_POLL undefined, top shows process
> in'select' most of the time, same behavior:
>
> 1144857761 Binding to host '127.0.0.1' and port 8081...
> 1144857761 Waiting for packets on 127.0.0.1:8081...
> 1144857761 Binding to host '127.0.0.1' and port 8082...
> 1144857761 Waiting for packets on 127.0.0.1:8082...
> 1144857761 Binding to host '127.0.0.1' and port 8083...
> 1144857761 Waiting for packets on 127.0.0.1:8083...
> 1144857761 Binding to host '127.0.0.1' and port 8084...
> 1144857761 Waiting for packets on 127.0.0.1:8084...
> 1144857761 Binding to host '127.0.0.1' and port 8085...
> 1144857761 Waiting for packets on 127.0.0.1:8085...
> 1144857761 Packet received from 127.0.0.1/3304 1 bytes
> 1144857761 Packet received from 127.0.0.1/3304 1 bytes
> 1144857762 Packet received from 127.0.0.1/3304 1 bytes
> 1144857762 Packet received from 127.0.0.1/3304 1 bytes
> 1144857763 Packet received from 127.0.0.1/3304 1 bytes
> 1144857763 Packet received from 127.0.0.1/3304 1 bytes
> 1144857764 Packet received from 127.0.0.1/3304 1 bytes
> 1144857764 Packet received from 127.0.0.1/3304 1 bytes
> 1144857765 Packet received from 127.0.0.1/3304 1 bytes
> 1144857765 Packet received from 127.0.0.1/3304 1 bytes
> 1144857766 Packet received from 127.0.0.1/3304 1 bytes
> 1144857766 Packet received from 127.0.0.1/3304 1 bytes
>
> It looks like an off-by-one error.  BTW - I note (or think I do,
> anyway), that defining SOCKET_POLL only changes the timeout function for
> an individual socket (socket_waitfd), but the actual lua select function
> will always use select in any event.
>
> As a dreadful hack I changed:
> ret = select(n, rfds, wfds, efds, t >= 0.0 ? &tv: NULL);
>
> to
>
> ret = select(1024, rfds, wfds, efds, t >= 0.0 ? &tv: NULL);
>
> in socket_select.c to see if that would make a difference, to no avail.
>
> Running truss on the running 'lua server.lua' gives in a recurring pattern:
>
> select(0x400,0xbfbff630,0xbfbff5b0,0x0,0xbfbff510) = 1 (0x1)
> gettimeofday(0xbfbfd624,0x0)                     = 0 (0x0)
> recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) ERR#35
> 'Resource temporarily unavailable'
> gettimeofday(0xbfbfd494,0x0)                     = 0 (0x0)
> select(0x4,0xbfbfd590,0x0,0x0,0xbfbfd500)        = 1 (0x1)
> recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) = 1 (0x1)
> gettimeofday(0xbfbff638,0x0)                     = 0 (0x0)
> write(1,0x80ad000,55)                            = 55 (0x37)
> gettimeofday(0xbfbff504,0x0)                     = 0 (0x0)
> gettimeofday(0xbfbff4b4,0x0)                     = 0 (0x0)
> select(0x400,0xbfbff630,0xbfbff5b0,0x0,0xbfbff510) = 1 (0x1)
> gettimeofday(0xbfbfd624,0x0)                     = 0 (0x0)
> recvfrom(0x3,0xbfbfd6a0,0x2000,0x0,0xbfbff6a0,0xbfbfd68c) ERR#35
> 'Resource temporarily unavailable'
>
>
> I note that select() is only returning 1, indicating that only 1 socket
> is readable, and the first socket that recvfrom() attempts is a failure,
> but the next select() & recvfrom() works.
>
> I'll dig further, but I find it hard to believe that it is a Freebsd bug
> (I'm a bit biased, since the BSD networking code was developed here at
> LBL).  Perhaps there's an interpretation difference in the expected
> parameters.
>
>
>
> Diego Nehab wrote:
>
>> Hi,
>>
>>>> The timing seems faster than expected, and the 5th expected
>>>> datasource is not seem.  Does this give any insight into the problem?
>>>
>>>
>>>
>>> Actually, I guess the timing is OK, since we're sleeping for .5 secs
>>> after sending all packets, but the 5th datasource is being skipped.
>>
>>
>>
>> Your original complaint was about the timing, right? Can you revert to
>> the original LuaSocket and test if the timing is correct?
>>
>>> BTW - I have luasocket compiled to use the poll syscall instead of
>>> select, in hopes of fixing my problem, but so far, no luck...
>>
>>
>>
>> I have no experience with BSD, but I don't expect select to be broken.
>>
>> Regards,
>> Diego.
>>
>

--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

Never face facts; if you do you'll never get up in the morning.
                -- Marlo Thomas

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jim Mellander
I modified server.lua again to print the allegedly readable sockets, and
to print out if no datagram was actually available - it only seems to
see 1, 2, & 3 out of the 5 that it should be seeing.  Additionally, when
flood.lua is killed, the sockets 1 & 2 still are returned by select as
readable

1144870525 Packet received from 127.0.0.1/3009 1 bytes
1144870525 Packet received from 127.0.0.1/3009 2 bytes
1144870525 Packet received from 127.0.0.1/3009 3 bytes
1144870525 Readable sockets are: 1 2 3
1144870526 Packet received from 127.0.0.1/3009 1 bytes
1144870526 Packet received from 127.0.0.1/3009 2 bytes
1144870526 Packet received from 127.0.0.1/3009 3 bytes
1144870526 Readable sockets are: 1 2 3
1144870527 Socket says readable, but no dgram on 1
1144870527 Packet received from 127.0.0.1/3009 2 bytes
1144870527 Packet received from 127.0.0.1/3009 3 bytes
1144870527 Readable sockets are: 1 2 3   <-- flood.lua killed.
1144870528 Socket says readable, but no dgram on 1
1144870529 Socket says readable, but no dgram on 2
1144870529 Packet received from 127.0.0.1/3009 3 bytes
1144870529 Readable sockets are: 1 2
1144870530 Socket says readable, but no dgram on 1
1144870531 Socket says readable, but no dgram on 2
1144870531 Readable sockets are: 1 2
1144870532 Socket says readable, but no dgram on 1
1144870533 Socket says readable, but no dgram on 2
1144870533 Readable sockets are: 1 2
1144870534 Socket says readable, but no dgram on 1
1144870535 Socket says readable, but no dgram on 2
1144870535 Readable sockets are: 1 2
1144870536 Socket says readable, but no dgram on 1
1144870537 Socket says readable, but no dgram on 2
etc.

--
Jim Mellander
Incident Response Manager
Computer Protection Program
Lawrence Berkeley National Laboratory
(510) 486-7204

Your fortune for today is:

He hadn't a single redeeming vice. -- Oscar Wilde

Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Jonathan Gray
In reply to this post by Diego Nehab-3
On Wed, Apr 12, 2006 at 03:02:04PM -0400, Diego Nehab wrote:

> Hi,
>
> >I'll dig further, but I find it hard to believe that it is a Freebsd bug
> >(I'm a bit biased, since the BSD networking code was developed here at
> >LBL). Perhaps there's an interpretation difference in the expected
> >parameters.
>
> I have been exchanging e-mails privately with Jonathan Gray, and he does
> not confirm your problem.
>
A

>     -- Jonathan Gray Wrote:
>     On OpenBSD amd64 -current with
>
>     gray's machine$ pkg_info | fgrep lua
>     lua-5.0.2p6         powerful, light-weight programming language
>     luacompat-5.1r4     compatibility module for lua 5.1
>     luasocket-2.0p1     network support for the lua language
>
>     0.00012803077697754 (should be 0.5, but unoffical patch messes things
>     up)
>     Packet received on 127.0.0.1/36630 1 bytes
>     Packet received on 127.0.0.1/36630 2 bytes
>     Packet received on 127.0.0.1/36630 3 bytes
>     Packet received on 127.0.0.1/36630 4 bytes
>     Packet received on 127.0.0.1/36630 5 bytes
>     0.00011992454528809
>     ...
>
> Also, we noticed unofficial patches to LuaSocket in the OpenBSD
> distribution that caused at least one bug. I don't have access to
> OpenBSD, nor can I control this kind of patch.

The offending patch has been removed in the latest iteration of the package.

# pkg_info | fgrep lua
lua-5.0.2p6         powerful, light-weight programming language
luacompat-5.1r4     compatibility module for lua 5.1
luasocket-2.0p2     network support for the lua language

0.5091028213501
Packet received on 127.0.0.1/19142 1 bytes
Packet received on 127.0.0.1/19142 2 bytes
Packet received on 127.0.0.1/19142 3 bytes
Packet received on 127.0.0.1/19142 4 bytes
0.50853610038757
Packet received on 127.0.0.1/19142 1 bytes
Packet received on 127.0.0.1/19142 2 bytes
Packet received on 127.0.0.1/19142 3 bytes
Packet received on 127.0.0.1/19142 4 bytes
0.51022005081177
Packet received on 127.0.0.1/19142 1 bytes
Packet received on 127.0.0.1/19142 2 bytes
Packet received on 127.0.0.1/19142 3 bytes
Packet received on 127.0.0.1/19142 4 bytes
0.50990200042725
Packet received on 127.0.0.1/19142 1 bytes
Packet received on 127.0.0.1/19142 2 bytes
Packet received on 127.0.0.1/19142 3 bytes
Packet received on 127.0.0.1/19142 4 bytes
0.50990581512451
Reply | Threaded
Open this post in threaded view
|

Re: Luasocket select/timeout problems on UDP

Diego Nehab-3
Hi,

> The offending patch has been removed in the latest iteration of the package.

I don't feel offended. :)

> 0.5091028213501
> Packet received on 127.0.0.1/19142 1 bytes
> Packet received on 127.0.0.1/19142 2 bytes
> Packet received on 127.0.0.1/19142 3 bytes
> Packet received on 127.0.0.1/19142 4 bytes

OK, so now without the patch, you only see 4 received
packets per cycle? This is sad. Can any of you give me a
shell so I can debug this? All I need is gcc, vi and make.

Regards,
Diego.