[nanomsg] Issue in NanoMsg Library - TCP Socket receive buffers are getting full

  • From: "Anurag Khare" <dmarc-noreply@xxxxxxxxxxxxx> ("anurag.khare")
  • To: "nanomsg@xxxxxxxxxxxxx" <nanomsg@xxxxxxxxxxxxx>
  • Date: Mon, 4 Apr 2022 10:34:58 +0000

Hi Team,

We are using the nano messaging library for TCP communication.
We are observing the below behavior in a process:-
Way of nano msg library usage in our application code:-

  *   We have created 1 thread thread calls below APIs:-
     *   nn_socket -> with domain "AF_SP" and protocol as "NN_PULL"
     *   nn_bind -> with tcp://IP:Port
     *   While (1)
     *   nn_poll -> FD returned by nn_socket, num of fd 1, timeout as 2000
     *   Once we get out of nn_poll then thread calls nn_recv same fd as 
returned by nn_socket, buffer address, max buf length, 0)
     *   Once thread receives data then thread submits the same to queue and 
sends signal to other thread to process the same.
  *   Since this a TCP connection so multiple peers connects to this IP and 
Port and each connected socket can have the data.

Observed Issue:-
The issue that we observed is that sometimes these TCP connected socket's 
receive buffer queues are reaching to a very high number, like 32715385. By 
checking the pstack output it is observed that either this application level 
thread (that uses nanomsg) is waiting on nn_poll OR actually receiving data 
from socket using nn_recv. However there is another thread most probably the 
worker thread of nanomsg (count is 1), this thread is either always waiting on 
epoll_wait OR it is waiting of a lock in the nn_ctx_enter function.
Since the user level thread is almost free (either on nn_poll or nn_recv) and 
as sometimes observed that nanomsg worker thread is waiting on some lock (lock 
of ctxt), so we are suspecting that because multiple threads (our thread as 
well nanomsg worker thread) working on same socket simultaneously so it is 
introducing delays (due to lock wait) and this may be the reason that over a 
period of time the sock recv buffers gets full.

Some more inputs are that outr application uses nanomsg library for for 
multiple TCP servers in the same way as mentioned above, while we observed that 
nano msg worker thread is same for all these sockets, can this introduce to 
delays and lead us to this problem?

Kindly note that this is not the deadlock but due to some reason threads are 
not processing the received messages as fast as it should be.

Backtrace of both the threads
NanoMsg Worker Thread
Thread 40 (Thread 0x7fa321d5e700 (LWP 13043)):
#0  0x00007fa334c3454d in __lll_lock_wait () from /usr/lib64/libpthread.so.0
#1  0x00007fa334c2fe9b in _L_lock_883 () from /usr/lib64/libpthread.so.0
#2  0x00007fa334c2fd68 in pthread_mutex_lock () from /usr/lib64/libpthread.so.0
#3  0x0000000000896262 in nn_mutex_lock (self=0x1e4abc00) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/utils/mutex.c:88
#4  0x00000000008935e0 in nn_ctx_enter (self=0x1e4abc00) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/ctx.c:48
#5  0x0000000000894646 in nn_worker_routine (arg=0x281de80 <self+64>) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/worker_posix.inc:247
#6  0x0000000000896960 in nn_thread_main_routine (arg=0x281e068 <self+552>) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/utils/thread_posix.inc:35
#7  0x00007fa334c2dea5 in start_thread () from /usr/lib64/libpthread.so.0
#8  0x00007fa3322da8cd in clone () from /usr/lib64/libc.so.6

Application level thread
Thread 35 (Thread 0x7fa31f559700 (LWP 13049)):
#0  0x00007fa334c34bad in recvmsg () from /usr/lib64/libpthread.so.0
#1  0x00000000008b978e in nn_usock_recv_raw (self=0x20aa7870, buf=0x1eb1034d, 
len=0x7fa31f3544b0) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/usock_posix.inc:1118
#2  0x00000000008b77d4 in nn_usock_recv (self=0x20aa7870, buf=0x1eb102a8, 
len=536, fd=0x0) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/usock_posix.inc:472
#3  0x00000000008ac72c in nn_stcp_handler (self=0x20aa7ae8, src=1, type=4, 
srcptr=0x20aa7870) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/transports/tcp/stcp.c:353
#4  0x00000000008938be in nn_fsm_feed (self=0x20aa7ae8, src=1, type=4, 
srcptr=0x20aa7870) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/fsm.c:83
#5  0x000000000089387a in nn_fsm_event_process (self=0x20aa7a70) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/fsm.c:77
#6  0x0000000000893648 in nn_ctx_leave (self=0x1e4aa580) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/aio/ctx.c:63
#7  0x0000000000891db1 in nn_sock_recv (self=0x1e4aa508, msg=0x7fa31f354660, 
flags=0) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/core/sock.c:702
#8  0x000000000088f96a in nn_recvmsg (s=7, msghdr=0x7fa31f354760, flags=0) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/core/global.c:887
#9  0x000000000088f385 in nn_recv (s=7, buf=0x7fa31f354bd0, len=2294, flags=0) 
at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/3rd-party/nanomsg/src/core/global.c:710
#10 0x00000000005e12b3 in vcmNpsIcmMsgRecv (compId=VCM_NPS_COMP_ID_CPE, 
channelId=9, maxBufLen=2270, apBuf=0x2ed3c910, apBufLen=0x7fa31f555094, 
apInstId=0x7fa31f555090) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/src/VcmNpsIcm.cpp:2980
#11 0x00000000005b9cfd in __vcmNpsIcmRecv (aCompId=VCM_NPS_COMP_ID_CPE, 
aChannelId=9 '\t', aMaxBufLen=2270, apBuf=0x2ed3c910 "", 
apBufLen=0x7fa31f555094, apInstId=0x7fa31f555090) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/src/VcmNps.cpp:9699
#12 0x00000000005709c8 in vcmRifIcmBeGtpcS5SgwDataIndCb (arg=0x7fa31f555990) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-rif/main/src/VcmRifCallbacks.cpp:702
#13 0x00000000005dff35 in vcmNpsIcmInterfaceCreate (apIntf=0x394cd08) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/src/VcmNpsIcm.cpp:2487
#14 0x000000000059e95c in vcmNpsIntfCreate (args=0x394cd08) at 
/home/build/P7.9.3.396/vcm-gerrit/vcm-nps/src/VcmNps.cpp:532
#15 0x00007fa334c2dea5 in start_thread () from /usr/lib64/libpthread.so.0
#16 0x00007fa3322da8cd in clone () from /usr/lib64/libc.so.6


Kindly have a look and let us know if our usage on nanomsg library is having 
any issue or is there any other issue in nano msg library?
Also, if you can share the role of this worker thread in receiving the message 
then it will be helpful.

Please share if some other info is required.

Thanks
Anurag
________________________________
This e-mail message may contain confidential or proprietary information of 
Mavenir Systems, Inc. or its affiliates and is intended solely for the use of 
the intended recipient(s). If you are not the intended recipient of this 
message, you are hereby notified that any review, use or distribution of this 
information is absolutely prohibited and we request that you delete all copies 
in your control and contact us by e-mailing to security@xxxxxxxxxxx. This 
message contains the views of its author and may not necessarily reflect the 
views of Mavenir Systems, Inc. or its affiliates, who employ systems to monitor 
email messages, but make no representation that such messages are authorized, 
secure, uncompromised, or free from computer viruses, malware, or other 
defects. Thank You

Other related posts:

  • » [nanomsg] Issue in NanoMsg Library - TCP Socket receive buffers are getting full - Anurag Khare