classification
Title: asyncio lost udp packets
Type: Stage:
Components: asyncio Versions: Python 3.6
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: gvanrossum, socketpair, valdemar.pavesi, vstinner, yselivanov
Priority: normal Keywords:

Created on 2016-06-08 20:17 by valdemar.pavesi, last changed 2016-07-23 17:30 by yselivanov. This issue is now closed.

Files
File name Uploaded Description Edit
calling_corotine_wihout_queue_lost_bigger.png valdemar.pavesi, 2016-06-08 23:23
Messages (15)
msg267884 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-08 20:17
hello,

I am using asyncio to handle 165 udp-packet per second

everything received by (datagram_received) will be put into a queue.

+++
124605 UDP packets send from client.

and received by server network:

dumpcap  ( filter "port 59999  and len > 100" ) 
Packets: 124605

correct number send and received.  124605

++++++

received by application:

def datagram_received(self, data, addr):

[2016-06-08 14:59:49] total udp = 124255,queue size =0
[2016-06-08 14:59:49] Got 124255 json report from server.

only 124255 received by application.

124605 - 124255 = 350 udp , received by network card , but application never got it.

+++


code:
#########################################
class UDPProtocolServerTraffica:
    
    def __init__(self):
        self.transport = None
        # heart beat timer
        self.HEARTBEAT_TIMEOUT = 10.0
        self.REPORTSHOWTOTAL_TIMEOUT=60.0
        self.MSG_UDP_HEARTBEAT = b'\x01\x00\x00\x00\x11\x00\x00\x00\x01\x00\x00\x00\x00\x05\x00\x00\x00'
        self.UDPCount = 0

    def connection_made(self, transport):
        self.transport = transport
        # traffica startup message
        self.transport.sendto(self.MSG_UDP_HEARTBEAT, (fns_remote_host, fns_remote_port))
        # start 10 seconds timeout timer
        self.h_timeout = asyncio.get_event_loop().call_later(self.HEARTBEAT_TIMEOUT, self.timeout_heartbeat)
        # show total report
        self.h_timeout = asyncio.get_event_loop().call_later(self.REPORTSHOWTOTAL_TIMEOUT, self.timeout_report_showtotal)
        
 
    def datagram_received(self, data, addr):
        #fns_mmdu_ipaddr = addr [0]
        #fns_mmdu_port = addr [1]
        Report_Id = (int.from_bytes(data[0:2], byteorder='big'))
        if Report_Id != 327:
            self.UDPCount += 1
            # send message to queue
            asyncio_queue.put_nowait(data)
  
    def pause_reading(self):
        print('pause_reading')

    def resume_reading(self):
        print('resume_reading')

    def error_received(self, exc):
        print('Error received:', exc)

    def connection_lost(self, exc):
        print('stop', exc)

    def timeout_heartbeat(self):
        self.transport.sendto(self.MSG_UDP_HEARTBEAT, (fns_remote_host, fns_remote_port))
        self.h_timeout = asyncio.get_event_loop().call_later(self.HEARTBEAT_TIMEOUT, self.timeout_heartbeat)
        #print('queue size ',asyncio_queue.qsize())
 
    def timeout_report_showtotal(self):
        self.h_timeout = asyncio.get_event_loop().call_later(self.REPORTSHOWTOTAL_TIMEOUT, self.timeout_report_showtotal)
        self.displayReportTotalCount()
        elasticsearch_get_all_reports()

    def displayReportTotalCount(self):
        logging.info('Total udp from fns: ' + str(self.UDPCount) + ' , queue size: ' + str(asyncio_queue.qsize()) )
        


regards!
Valdemar
msg267885 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-06-08 20:21
Isn't it normal for UDP to lose some packets?
msg267889 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-08 20:41
thanks Yury,

I think we could lose inside the network, but we cannot lose inside of our application.


regards!
Valdemar
msg267891 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-06-08 20:44
> I think we could lose inside the network, but we cannot lose inside of our application.

UDP is fundamentally unreliable. It *will* lose data even over UNIX sockets.
msg267892 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-08 20:45
I am not getting  any pause, or any message about buffer full.

def pause_reading(self):
    print('pause_reading')

def resume_reading(self):
    print('resume_reading')


and I cannot find a way to increase the receive buffer by asyncio.
msg267894 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-06-08 20:52
Even if you increase buffers you will lose data over UDP.  The reason can be the network, or the kernel may simply skip sending the data.

To work with buffer sizes use transport.set_write_buffer_limits
msg267895 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-08 20:52
I do understand the possibility to lose on udp.

and I am monitoring all machines involved.
I am not losing on network, I am losing between our network-card-dumpcap and read udp from socket. 

is it possible that read will be blocked and not able to read ? 
during read and write to queue?  
I do have udp packets that will come in same microsecond.
msg267896 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2016-06-08 20:56
How do you know the OS kernel isn't dropping them?
msg267928 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-08 23:23
hi,

I did made a change, removing the queue and calling corotine. and now lost udp is bigger.

 def datagram_received(self, data, addr):
           asyncio.ensure_future(process_report(data))


@asyncio.coroutine
def process_report(data):


tcmpdump got  38122
and asyncio got just 20711 

2016-06-08 18:19:23,209 [INFO] 546  Total udp from fns: 20711 , queue size: 0
2016-06-08 18:19:23,209 [INFO] 417  Got 20711 json report from traffica server



all udp received will be send by tcp to another server. (Got 20711 json report )
msg267929 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2016-06-08 23:26
You have not convinced anyone that this is asyncio's fault. I'm closing the issue. If you need help debugging this please use the python-tulip Google Group; if in the end it is found to be an asyncio issue we'll help you file a useful bug report on the asyncio GitHub project.
msg267949 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-09 02:01
thanks Guido

I will keep working with it. 

I am not able to debug between socket and asyncio-read-udp.

There is no bottleneck on cpu/memory or network card.

I cannot write debug with this heavy udp load.

if I decrease the UDP per second then this problem go away. 

I know when it will start dropping and i never got any drop inside the network. ( tcpdump to validate it ).

I will send it to python-tulip

regards!
Valdemar
msg268031 - (view) Author: valdemar pavesi (valdemar.pavesi) Date: 2016-06-09 15:33
thanks Guido and Yury

I am new on python world. I was working with automation tests, sw implemented in Delphi in 199x.

this year I got a python certification from University Texas Arlington University by EDX.

and I already wrote 4 projects in python3 ,handling heavy traffic , one related to voice over lte simulation.

thanks for all your contribution to the world without asking nothing back.


regards!
valdemar
msg268037 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2016-06-09 16:45
You're welcome Valdemar. It's a wonderful world, there's so much to learn!
Sounds like you're on the right path. Good luck!
msg271032 - (view) Author: Марк Коренберг (socketpair) * Date: 2016-07-22 20:54
@yselivanov

Can you prove that packets may be lost even in UNIX sockets ?

(it is not related to this task directly)
msg271093 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-07-23 17:30
> Can you prove that packets may be lost even in UNIX sockets ?
> (it is not related to this task directly)

Quoting wiki:

"""Like named pipes, Unix domain sockets support transmission of a reliable stream of bytes (SOCK_STREAM, compare to TCP). In addition, they support ordered and reliable transmission of datagrams (SOCK_SEQPACKET), or unordered and unreliable transmission of datagrams (SOCK_DGRAM, compare to UDP)."""

I'm also sure I saw that UDP can never be used as a reliable protocol in Stevens books.  (I'm sure you can google this too.)
History
Date User Action Args
2016-07-23 17:30:26yselivanovsetmessages: + msg271093
2016-07-22 20:54:59socketpairsetnosy: + socketpair
messages: + msg271032
2016-06-09 16:45:03gvanrossumsetmessages: + msg268037
2016-06-09 15:33:26valdemar.pavesisetmessages: + msg268031
2016-06-09 02:01:47valdemar.pavesisetmessages: + msg267949
2016-06-08 23:26:53gvanrossumsetstatus: open -> closed
resolution: not a bug
messages: + msg267929
2016-06-08 23:23:13valdemar.pavesisetfiles: + calling_corotine_wihout_queue_lost_bigger.png

messages: + msg267928
2016-06-08 20:56:26gvanrossumsetmessages: + msg267896
2016-06-08 20:52:25valdemar.pavesisetmessages: + msg267895
2016-06-08 20:52:16yselivanovsetmessages: + msg267894
2016-06-08 20:45:08valdemar.pavesisetmessages: + msg267892
2016-06-08 20:44:38yselivanovsetmessages: + msg267891
2016-06-08 20:41:25valdemar.pavesisetmessages: + msg267889
2016-06-08 20:21:28yselivanovsetmessages: + msg267885
2016-06-08 20:17:39valdemar.pavesicreate