calejost / unimrcp

Automatically exported from code.google.com/p/unimrcp
Apache License 2.0
0 stars 0 forks source link

Some problems about occupied udp ports and mrcpServer 'Push Request to Queue'? #167

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
What version of the product are you using? On what operating system?

The version of the product is unimrcp-1.1.0
operating system is Centos6.

Please provide any additional information below.
2014-04-04 09:12:44:294583 [INFO]   Receive SIP Event [nua_i_invite] Status 100 
Trying
2014-04-04 09:12:44:294618 [INFO]   Receive SIP Event [nua_i_state] Status 100 
Trying
2014-04-04 09:12:44:294630 [NOTICE] SIP Call State  [received]
2014-04-04 09:12:44:294677 [INFO]   Create Session 0x7f6f1801be08 <new> [uni2]
2014-04-04 09:12:44:294692 [INFO]   Remote SDP 0x7f6f1801be08 <new>
v=0
o=- 839025498 839025498 IN IP4 172.17.1.66
s=VRSASR
t=0 0
m=application 9 TCP/MRCPv2
c=IN IP4 172.17.1.66
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 17304 RTP/AVP 0 8
c=IN IP4 172.17.1.66
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=sendonly
a=mid:1

2014-04-04 09:12:44:294758 [DEBUG]  Signal Message to [MRCP Server] 
[0x1801e6d0;1;0]
2014-04-04 09:12:44:294796 [DEBUG]  Process Message [MRCP Server] 
[0x1801e6d0;1;0]
2014-04-04 09:12:44:294832 [DEBUG]  Dispatch Signaling Message [0]
2014-04-04 09:12:44:294845 [NOTICE] Add Session <39f2cb30bb9611e3>
2014-04-04 09:12:44:294854 [INFO]   Receive Offer 0x7f6f1801be08 
<39f2cb30bb9611e3> [c:1 a:1 v:0]
2014-04-04 09:12:44:294877 [DEBUG]  Add Control Channel 0x7f6f1801be08 
<39f2cb30bb9611e3@speechrecog> [0]
2014-04-04 09:12:44:294886 [DEBUG]  Signal Message to [MRCPv2-Agent-1] 
[0x30004ad0;1;0]
2014-04-04 09:12:44:294901 [DEBUG]  Add Media Termination 0x7f6f1801be08 
<39f2cb30bb9611e3@rtp-tm> [0]
2014-04-04 09:12:44:294910 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2014-04-04 09:12:44:294915 [DEBUG]  Signal Message to [Media-Engine-1] 
[0x30003260;1;0]
2014-04-04 09:12:44:294928 [DEBUG]  Process Message [MRCPv2-Agent-1] 
[0x30004ad0;1;0]
2014-04-04 09:12:44:294938 [DEBUG]  Wait for Messages [MRCP Server]
2014-04-04 09:12:44:294951 [INFO]   Add Pending Control Channel 
<39f2cb30bb9611e3@speechrecog> [10]
2014-04-04 09:12:44:294972 [DEBUG]  Signal Message to [MRCP Server] 
[0x20021eb0;2;0]
2014-04-04 09:12:44:294987 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
2014-04-04 09:12:44:294989 [DEBUG]  Process Message [MRCP Server] 
[0x20021eb0;2;0]
2014-04-04 09:12:44:295010 [DEBUG]  Control Channel Modified 0x7f6f1801be08 
<39f2cb30bb9611e3@speechrecog>
2014-04-04 09:12:44:295021 [DEBUG]  Wait for Messages [MRCP Server]
2014-04-04 09:12:44:303700 [DEBUG]  Process Message [Media-Engine-1] 
[0x30003260;1;0]
2014-04-04 09:12:44:303745 [DEBUG]  Add Media Context 0x7f6f1801be08
2014-04-04 09:12:44:303919 [INFO]   Enable RTP Session 172.17.1.24:5500
2014-04-04 09:12:44:303948 [DEBUG]  Create Linear Audio Bridge 0x7f6f1801be08
2014-04-04 09:12:44:303966 [INFO]   Open RTP Receiver 172.17.1.24:5500 <- 
172.17.1.66:17304 playout [50 ms] bounds [0 - 600 ms] adaptive [1] skew 
detection [1]
2014-04-04 09:12:44:304011 [INFO]   Media Path 0x7f6f1801be08 
Source->[PCMU/8000/1]->Decoder->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Sink
2014-04-04 09:12:44:304023 [DEBUG]  Signal Message to [MRCP Server] 
[0x100930b0;4;0]
2014-04-04 09:12:44:304086 [DEBUG]  Process Message [MRCP Server] 
[0x100930b0;4;0]
2014-04-04 09:12:44:304130 [DEBUG]  Media Termination Modified 0x7f6f1801be08 
<39f2cb30bb9611e3@media-tm>
2014-04-04 09:12:44:304138 [DEBUG]  Media Termination Modified 0x7f6f1801be08 
<39f2cb30bb9611e3@rtp-tm>
2014-04-04 09:12:44:304148 [DEBUG]  Signal Message to [Pachira MRCP connector] 
[0x30003260;1;0]
2014-04-04 09:12:44:304160 [DEBUG]  Wait for Messages [MRCP Server]
2014-04-04 09:12:45:504534 [INFO]   Receive SIP Event [nua_i_options] Status 
100 Trying
2014-04-04 09:12:45:504575 [INFO]   Resource Discovery SDP
[v=0
o=PachiraMRCPServer 0 0 IN IP4 172.17.1.24
s=-
c=IN IP4 172.17.1.24
t=0 0
m=application 0 TCP/MRCPv2 1
a=resource:speechsynth
a=resource:speechrecog
m=audio 0 RTP/AVP 0 8 96 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 L16/8000
a=rtpmap:101 telephone-event/8000
]

2014-04-04 09:12:47:229806 [INFO]   Receive SIP Event [nua_i_cancel] Status 200 
OK
2014-04-04 09:12:47:229899 [INFO]   Receive SIP Event [nua_i_state] Status 487 
Request Terminated
2014-04-04 09:12:47:229921 [NOTICE] SIP Call State 0x7f6f1801be08 [terminated]
2014-04-04 09:12:47:229943 [DEBUG]  Signal Message to [MRCP Server] 
[0x1801e6d0;1;2]
2014-04-04 09:12:47:229966 [INFO]   Receive SIP Event [nua_i_terminated] Status 
487 Request Terminated
2014-04-04 09:12:47:229970 [DEBUG]  Process Message [MRCP Server] 
[0x1801e6d0;1;2]
2014-04-04 09:12:47:230010 [DEBUG]  Push Request to Queue 0x7f6f1801be08 
<39f2cb30bb9611e3>

--------------------------------------------------------------------------------
-------------------------------------
Hi Arsen,
I would like to know that,how the mrcpServer will deal with the queue after it 
'Push Request to Queue'.And when the mrcpServer Push Request to Queue, some udp 
ports will be occupied.
The attach is bellow.
best

Original issue reported on code.google.com by chengchu...@gmail.com on 10 Apr 2014 at 11:30

Attachments:

GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
oh,I see.It will deal with the queue.
But why after the flow of the above log,some udp ports will be occupied until 
exit the mrcpServer.

What circumstance the mrcpServer can frequently receive 'SIP Event 
[nua_i_cancel] Status'?

Original comment by chengchu...@gmail.com on 11 Apr 2014 at 8:06

GoogleCodeExporter commented 8 years ago
The occupied UPD ports are just a side effect of the real problem. The real 
problem is in the plugin which stopped responding to the server requests 
starting from 

2014-04-04 09:10:28:983806 [DEBUG]  Process Message [Pachira MRCP connector] 
[0x10090f80;1;0]

Pay attention to the following sequence of traces.

[DEBUG]  Signal Message to [Pachira MRCP connector]
[DEBUG]  Process Message [Pachira MRCP connector]
[DEBUG]  Wait for Messages [Pachira MRCP connector]

The statement Signal Message is logged when the server sends a message to the 
plugin. The statement Process Message is logged before the plugin starts 
processing of the message. And finally the statement Wait for Messages is 
logged when the processing has been completed and the corresponding callback 
has been returned.

For the mentioned above Process Message statement, which happened at 2014-04-04 
09:10:28:983806, there was no response, neither the callback returned. All the 
consecutive Signal Message requests were not been processed either.

This could happen because of a dead lock in the plugin. Or it's also possible 
that the function gets into an infinite loop!

Original comment by achalo...@gmail.com on 11 Apr 2014 at 9:28

GoogleCodeExporter commented 8 years ago
This actually was not a defect but a request for clarification.

Original comment by achalo...@gmail.com on 12 Aug 2014 at 1:19