search

benoitc / erlang-nat

implements NAT handling facilities for Erlang applications
Other
57 stars 10 forks source link

eagain when sending packet in natupnp v2 #25

Closed Vagabond closed 3 years ago

Vagabond commented 5 years ago 
no match of right hand value {error,eagain} in natupnp_v2:discover1/3 line 57 in context child_terminated

https://github.com/benoitc/erlang-nat/blob/master/src/natupnp_v2.erl#L57

benoitc commented 5 years ago

We could probably ignore and retry when it is happening, but in which context does it happening? has some process exited?

benoitc commented 5 years ago

Looking back at the code we can probably sleep a little when we go back on sending : https://github.com/benoitc/erlang-nat/blob/e5e8ada57e85db60b9ec0903e5bf8342c1c6a6e5/src/natupnp_v2.erl#L76

Vagabond commented 5 years ago

Yeah, I think this is caused by the udp send buffer being full.

benoitc commented 5 years ago

hrm how could it be? Do you know if they matched another UPNP endpoint in the loop?

Vagabond commented 5 years ago

I'm not sure, it's not very clear what is happening.

benoitc commented 5 years ago

so I am seeing different 2 possible fixes:

  1. we increase the buffer, the default is 9216 bytes on my system. 
    8> {ok, Sock} = gen_udp:open(0, [{active, once}, inet, binary]). 
{ok,#Port<0.5>}
9> inet:getopts(Sock,  [sndbuf]). 
{ok,[{sndbuf,9216}]}
10>

We could increase to 131072. (128 bsl 10) . What is the default on your system?

  1. retry on EAGAIN. That would also do the trick IMO.

Thoughts?

Vagabond commented 5 years ago

It's very confusing, maybe it is a packet size/MTU problem?

(miner@127.0.0.1)3> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"hello">>).
ok
(miner@127.0.0.1)4> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"hello">>).
ok
(miner@127.0.0.1)5> nat:discover().
** exception exit: {badmatch,{error,eagain}}
     in function  natupnp_v2:discover1/3 (natupnp_v2.erl, line 57)
     in call from natupnp_v2:discover/0 (natupnp_v2.erl, line 47)
     in call from nat:discover_worker/3 (nat.erl, line 145)
=ERROR REPORT==== 3-Jul-2019::19:55:34.591822 ===
Error in process <7058.15493.1> on node 'miner@127.0.0.1' with exit value:
{{badmatch,{error,eagain}},
 [{natupnp_v2,discover1,3,[{file,"natupnp_v2.erl"},{line,57}]},
  {natupnp_v2,discover,0,[{file,"natupnp_v2.erl"},{line,47}]},
  {nat,discover_worker,3,[{file,"nat.erl"},{line,145}]}]}
Vagabond commented 5 years ago

I'm, really not sure:

(miner@127.0.0.1)8> {ok, Sock} = gen_udp:open(0, [{active, once}, inet, binary]).
{ok,#Port<0.50616>}
(miner@127.0.0.1)9> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"M-SEARCH * HTTP/1.1\r\nHOST: 239.255.255.250:1900\r\nMAN: \"ssdp:discover\"\r\nST: urn:schemas-upnp-org:device:InternetGatewayDevice:2\r\nMX: 3\r\n\r\n">>).
ok
(miner@127.0.0.1)10> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"M-SEARCH * HTTP/1.1\r\nHOST: 239.255.255.250:1900\r\nMAN: \"ssdp:discover\"\r\nST: urn:schemas-upnp-org:device:InternetGatewayDevice:2\r\nMX: 3\r\n\r\n">>).
ok
(miner@127.0.0.1)11> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"M-SEARCH * HTTP/1.1\r\nHOST: 239.255.255.250:1900\r\nMAN: \"ssdp:discover\"\r\nST: urn:schemas-upnp-org:device:InternetGatewayDevice:2\r\nMX: 3\r\n\r\n">>).
ok
(miner@127.0.0.1)12> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"M-SEARCH * HTTP/1.1\r\nHOST: 239.255.255.250:1900\r\nMAN: \"ssdp:discover\"\r\nST: urn:schemas-upnp-org:device:InternetGatewayDevice:2\r\nMX: 3\r\n\r\n">>).
ok
(miner@127.0.0.1)13> ok = gen_udp:send(Sock, "239.255.255.250", 1900, <<"M-SEARCH * HTTP/1.1\r\nHOST: 239.255.255.250:1900\r\nMAN: \"ssdp:discover\"\r\nST: urn:schemas-upnp-org:device:InternetGatewayDevice:2\r\nMX: 3\r\n\r\n">>).
ok

(miner@127.0.0.1)14> nat:discover().
=ERROR REPORT==== 3-Jul-2019::19:59:50.012792 ===
Error in process <7058.15753.1> on node 'miner@127.0.0.1' with exit value:
{{badmatch,{error,eagain}},
 [{natupnp_v2,discover1,3,[{file,"natupnp_v2.erl"},{line,57}]},
  {natupnp_v2,discover,0,[{file,"natupnp_v2.erl"},{line,47}]},
  {nat,discover_worker,3,[{file,"nat.erl"},{line,145}]}]}

** exception exit: {badmatch,{error,eagain}}
     in function  natupnp_v2:discover1/3 (natupnp_v2.erl, line 57)
     in call from natupnp_v2:discover/0 (natupnp_v2.erl, line 47)
     in call from nat:discover_worker/3 (nat.erl, line 145)
benoitc commented 5 years ago

@Vagabond Is this happening during one call to nat:discover/0 ? Did you already have this error before the 0.3.1 release?

Vagabond commented 5 years ago

I hadn't noticed it before, but I wasn't paying too much attention so I can't really tell..

benoitc commented 5 years ago

@Vagabond can you try #27 and let me know?

benoitc commented 5 years ago

also can you provide me the return of 

16> inet:getopts(Sock2, [sndbuf, recbuf]). 
{ok,[{sndbuf,9216},{recbuf,8192}]}

and the mTU you have. On my machine I can't reproduce the issue.

Vagabond commented 5 years ago 
(miner@127.0.0.1)1> nat:discover().
=ERROR REPORT==== 10-Jul-2019::16:41:30.931694 ===
Error in process <7058.2437.1> on node 'miner@127.0.0.1' with exit value:
{{badmatch,{error,eagain}},
 [{natupnp_v2,discover1,3,[{file,"natupnp_v2.erl"},{line,57}]},
  {natupnp_v2,discover,0,[{file,"natupnp_v2.erl"},{line,47}]},
  {nat,discover_worker,3,[{file,"nat.erl"},{line,145}]}]}

** exception exit: {badmatch,{error,eagain}}
     in function  natupnp_v2:discover1/3 (natupnp_v2.erl, line 57)
     in call from natupnp_v2:discover/0 (natupnp_v2.erl, line 47)
     in call from nat:discover_worker/3 (nat.erl, line 145)
(miner@127.0.0.1)2> {ok, Sock} = gen_udp:open(0, [{active, true}, inet, binary]).
{ok,#Port<0.9022>}
(miner@127.0.0.1)3> inet:getopts(Sock, [sndbuf, recbuf]).
{ok,[{sndbuf,212992},{recbuf,16384}]}
Vagabond commented 5 years ago

MTU is 1500 on this interface, AFAICT.

# ifconfig
eth0      Link encap:Ethernet  HWaddr B8:27:EB:3F:7D:B3
          UP BROADCAST MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:9995 errors:0 dropped:0 overruns:0 frame:0
          TX packets:9995 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:919698 (898.1 KiB)  TX bytes:919698 (898.1 KiB)

wlan0     Link encap:Ethernet  HWaddr B8:27:EB:6A:28:E6
          inet addr:192.168.1.2  Bcast:192.168.1.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1366969 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1563409 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:1177624043 (1.0 GiB)  TX bytes:1201086515 (1.1 GiB)
WilliamTakeshi commented 3 years ago

Hello everyone,

I am having the same problem with Elixir, I am trying to use this lib but when I do

:nat.discover()
** (EXIT from #PID<0.550.0>) shell process exited with reason: an exception was raised:
    ** (MatchError) no match of right hand side value: {:error, :eagain}
        (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/natupnp_v2.erl:57: :natupnp_v2.discover1/3
        (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/natupnp_v2.erl:47: :natupnp_v2.discover/0
        (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/nat.erl:145: :nat.discover_worker/3
13:25:22.202 [error] Process #PID<0.556.0> raised an exception
** (MatchError) no match of right hand side value: {:error, :eagain}
    (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/natupnp_v2.erl:57: :natupnp_v2.discover1/3
    (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/natupnp_v2.erl:47: :natupnp_v2.discover/0
    (nat 0.4.1) /home/william/projects/swarm/iot-broker-elixir/deps/nat/src/nat.erl:145: :nat.discover_worker/3

The weird part is that sending the message using the interactive shell it works

iex(1)> {:ok, socket} = :gen_udp.open(0, [:inet, :binary, active: :once])
{:ok, #Port<0.27>}
iex(2)> :gen_udp.send(socket, '239.255.255.250', 1900, "hello")
:ok

I tried https://github.com/benoitc/erlang-nat/pull/27 but it doesnt work. Retrying didnt work either, the error happens everytime on my machine