Problem with 'resource temporarily unavailable'

Edward King edk at cendatsys.com
Fri Jan 17 18:24:56 CET 2003


OK... changed the timeout to 100ms ( usleep(100000) ) and now I'm 
getting the following log entrys on the box sending data out with rsync 
--bwlimit=10 (10KB/sec bandwidth limit):

Jan 17 10:23:02 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms
Jan 17 10:24:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms
Jan 17 10:25:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms
Jan 17 10:26:03 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms
Jan 17 10:27:01 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms
Jan 17 10:28:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(10.1.1.5 port 2007) failed: waiting 100ms

Nothing shows on the receiving side -- data is moving cleanly.  When I 
remove the bandwidth limitation (this should be a good stress test) I get:



looking at the /proc/net/dev file for the tun device on 10.1.1.5 shows 
the following stats:
Fri Jan 17 11:08:24 CST 2003
Inter-|   Receive                                                |  Transmit
 face |bytes    packets errs drop fifo frame compressed 
multicast|bytes    packets errs drop fifo colls carrier compressed
stv100: 6630235    6856    0    0    0     0          0         0   
263340    3988    0    0    0     0       0          0


Fri Jan 17 11:15:31 CST 2003
Inter-|   Receive                                                |  Transmit
 face |bytes    packets errs drop fifo frame compressed 
multicast|bytes    packets errs drop fifo colls carrier compressed
stv100:16240751   16792    0    0    0     0          0         0   
965142    9786    0    0    0     0       0          0

so between these two dumps it transferred 21.9KB/sec.  This is the log 
from the client during the same time frame -- still getting the 'failed: 
waiting' message every minute,  but now the second attempt also fails 
every couple of times causing the connection to drop for 30 seconds (I 
did a ping from another telnet,  lost 30 packets when 'Resource 
temporarily unavailable' popped up in the log -- also showed packets 
with 'wrong data byte' when traffic ws really heavy).

Jan 17 10:36:01 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:36:02 stv100 tinc.stv100[16132]: Metadata socket error for vpn 
(216.47.252.142 port 2007): Connection reset by peer
Jan 17 10:36:15 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:37:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:37:23 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: Resource temporarily unavailable
Jan 17 10:37:59 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:38:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:39:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:39:21 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: Resource temporarily unavailable
Jan 17 10:39:54 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:40:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:40:51 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: Resource temporarily unavailable
Jan 17 10:41:22 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:42:00 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:43:01 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms
Jan 17 10:43:14 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: Resource temporarily unavailable
Jan 17 10:44:26 stv100 tinc.stv100[16132]: Sending meta data to vpn 
(216.47.252.142 port 2007) failed: waiting 100ms

Does my usleep command stop all tinc traffic or just metadata traffic? 
 If it's all stopped, there should be little else going through on the 
network.  Maybe a loop to try 3 times before failing with 'temporarily 
unavailable', progressively longer delays, etc.  

The code change does help -- I only got one 'Bogus data received' error 
on 10.1.1.5, no other errors at all.  Transfer speed is also up (22K vs 
4K without the pause/retry).



Guus Sliepen wrote:

>On Wed, Jan 15, 2003 at 01:10:24PM -0600, Edward King wrote:
>
>  
>
>>We've got problems running tinc over DSL lines using low cost 
>>routers/modems (at leat I think it's a hardware problem.)
>>
>>We get error messages such as the following:
>>
>>Jan 15 11:36:05 stv100 tinc.stv100[2784]: Sending meta data to vpn 
>>(162.37.22.162 port 2007) failed: Resource temporarily unavailable
>>    
>>
>
>That usually indicates that no more network buffers are available,
>either because the machine is really low on memory or if more data is
>being sent out by tinc than the network can handle.
>
>tinc normally shouldn't send very much meta data (only a ping once a
>minute and some updates if a connection to another tinc daemon is made
>or broken) unless you're using the TCPonly option. Is it really
>necessary for you to use it? What kind of traffic are you sending over
>the VPN?
>
>  
>
>>I've added a delay to meta.c so if it errors out, retry in 1 second 
>>(using usleep(1000)).  I also made an it log every time it was going to 
>>retry and if it fails, log the failure.  the code looks like this:
>>    
>>
>
>usleep(1000) sleeps for 1 millisecond.
>
>  
>
>>we also changed the mtu on both sides to 1000 -- hoping to possibly 
>>remove problems there.
>>    
>>
>
>That probably doesn't matter much.
>
>  
>
>>We now get lots of 'will retry in 1000ms' messages, and very few 
>>'failed' messages.  
>>    
>>
>
>That's interesting.
>
>  
>
>>There are more messages on the sending side of 'Metadata socket error 
>>for vpn' Connection reset by peer' and the other side showing 'Bogus 
>>data received'
>>    
>>
>
>You really shouldn't see that unless errors were introduced in the TCP
>stream... Do those errors also occur less frequently with the usleep()
>than without?
>
>  
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://brouwer.uvt.nl/pipermail/tinc/attachments/20030117/79d00932/attachment.html


More information about the Tinc mailing list