Failed to add to Pollset error

[Mario Ziljak]

Hi Arsen,

We are using UniMRCP library v1.0.0 to communicate with NUANCE speech recognition server.

We are using MRCPv2 client version.

Recently, there was reported issue that when connection is being established with NUANCE it fails on: Failed To add to Pollset error.

This is excerpt from the logs:

We try to define Grammar for Voice recognition session with NUANCE:

Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00001778] [MRCP] Entering MRCPSession::defineGrammar callid=0x1e7c63ac3b3a0238
Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00001778] [UniMRCP] Create MRCP Handle 0x269fe9b0 [ccu-v2]
Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00001778] [UniMRCP] Create Channel 0x269fe9b0 <new>
Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Receive App Request 0x269fe9b0 <new> [2]
Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Add MRCP Handle 0x269fe9b0 <new>
Dec 02 08:11:17.232 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Add Control Channel 0x269fe9b0 <new@speechrecog>
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Send Offer 0x269fe9b0 <new> [c:1 a:1 v:0] to ccuavcs01nua.ccu.domain:5062
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Local SDP 0x269fe9b0 <new>
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] v=0^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] o=UniMRCPClient 0 0 IN IP4 212.227.217.142^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] s=-^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] c=IN IP4 212.227.217.142^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] t=0 0^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] m=application 9 TCP/MRCPv2 1^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=setup:active^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=connection:existing^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=resource:speechrecog^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=cmid:1^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] m=audio 21206 RTP/AVP 8^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=rtpmap:8 PCMA/8000^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=sendonly^M
Dec 02 08:11:17.233 CCUAVCS01 VCS: [0x00000950] a=mid:1^M
Dec 02 08:11:17.244 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] Receive SIP Event [nua_i_state] Status 0 INVITE sent

We get response from NUANCE:

Dec 02 08:11:17.279 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] Receive SIP Event [nua_r_invite] Status 200 OK
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] Receive SIP Event [nua_i_state] Status 200 OK
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] SIP Call State 0x269fe9b0 [ready]
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] Remote SDP 0x269fe9b0 <new>
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] v=0^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] o=- 1417504277 1417504277 IN IP4 212.227.217.158^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] s=Nuance MRCP session V2^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] c=IN IP4 212.227.217.158^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] t=0 0^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] a=session-timeout:120000^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] m=application 6075 TCP/MRCPv2 1^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] a=cmid:1^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] a=setup:passive^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] a=connection:new^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] a=channel:1936870@speechrecog^M
Dec 02 08:11:17.280 CCUAVCS01 VCS: [0x000011c8] m=audio 8402 RTP/AVP 8 0 122 100^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=rtpmap:8 pcma/8000^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=rtpmap:0 pcmu/8000^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=rtpmap:122 l16/8000^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=rtpmap:100 telephone-event/8000^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=fmtp:100 0-15^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=recvonly^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] a=mid:1^M
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x000011c8] [UniMRCP] Receive SIP Event [nua_i_active] Status 200 Call active
Dec 02 08:11:17.281 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Receive Answer 0x269fe9b0 <new> [c:1 a:1 v:0]

However we fail to Add connection to Pollset and Session establishment fails:

Dec 02 08:11:17.283 CCUAVCS01 VCS: [0x000009a0] [UniMRCP] Failed to Add to Pollset 212.227.217.142:63339 <-> 212.227.217.158:6075
Dec 02 08:11:17.283 CCUAVCS01 VCS: [0x000009a0] [UniMRCP] Failed to Establish TCP/MRCPv2 Connection
Dec 02 08:11:17.283 CCUAVCS01 VCS: [0x00000950] [UniMRCP] Raise App Response 0x269fe9b0 <1936870> [2] FAILURE [1]
Dec 02 08:11:17.283 CCUAVCS01 VCS: [0x00000950] [MRCP] OnSessionConnected session=0x2a366e98
Dec 02 08:11:17.283 CCUAVCS01 VCS: [0x00000950] [MRCP] OnSessionConnected failed, session=0x269fe9b0 status: 1

Now important facts:

If Server running UniMRCP is restarted then everything works as expected.

If Server is left running and receiving calls over certain period of time (for example ~3 weeks or so) it will start to report this same message and fail to make connections.

Again, restart will solve this issue.

This would somehow implicate that possibly connections are not released propperly and over time collection grows (pollset) which causes failures eventually.

Is there any known issue that would maybe relate to this behaviour on this version?

Thanks,

Mario

[Arsen Chaloyan]

Hi Mario,

On Wed, Dec 17, 2014 at 8:11 AM, Mario Ziljak <mazi...@gmail.com> wrote:

Hi Arsen,

We are using UniMRCP library v1.0.0 to communicate with NUANCE speech recognition server.

We are using MRCPv2 client version.

 

You are not alone. This is quite a common and known to work setup. Perhaps the version you are running is old, although it doesn't mean that 1.0.0 is vulnerable to the described problem.

I understand your point and this clearly indicates that some of the session/connection objects remain in use. Having spent many hours debugging the client stack in a similar setup, I don't see how this sort of issue can be caused by the client library. I am not aware of your application, but I would expect the application doesn't terminate and destroy sessions under some circumstances. And the one which comes to my mind is a session being terminated by NSS due to a timeout (see the one outlined above). Do you handle session termination event in your application? Are you sure that session_terminate() is eventually called for all the sessions you create?

 

This would somehow implicate that possibly connections are not released propperly and over time collection grows (pollset) which causes failures eventually.

That is right and indeed the error in pollset is just a side effect but not the root cause.

Is there any known issue that would maybe relate to this behaviour on this version?

Nothing in particular. Anyway, I'd recommend to try the latest release. The upgrade should not cause any issues unless you have some local modifications in the code. If you continue to experience the same problem, provide additional information such as OS, average load, anything specific to your use case.

Thanks,

Mario

--
You received this message because you are subscribed to the Google Groups "UniMRCP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to unimrcp+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Arsen Chaloyan
Author of UniMRCP
http://www.unimrcp.org

[Mario Ziljak]

Hi Arsen,

Thanks for your quick response and help for this issue. 

We have raised in the meantime max-connections-count setting in regard to our research on peak loads regard simultaneous calls, so we are also testing this now. This from what we have seen in fact seem to be definitely one of the reasons for this behaviour. 

So we are tracking it now over time to try to rule out this pattern with restarts and working/non working states.

So far as i can see we are handling appropriately  session_terminate(), however i will do more testing and debugging in this direction also. Session being terminated by NSS is in fact great hint of something that could go wrong also in this sense.

In any case when we close this with some resolution, i will update on it so it will maybe be usefull to someone else.

Thanks again for support, and for more than great work with UniMRCP library in general,

Best Regards,

Mario

[Mario Ziljak]

Hi Arsen,

Just to update on this as promised.

After peak testing, and synchronizing max-connections-count with maximum simultaneous calls allowed on server, it seems that issue does not occur anymore. So in fact fixing it this way by increasing max-connections-count appropriately was obviously only problem we had.

In any case thanks for your help and time, and lets hope this also helps someone else in the future, because it is easy to fix when you know what is going on.

Best Regards,

Mario 

[Arsen Chaloyan]

Hi Mario,

Thanks for the update. Glad everything works as intended.

--

You received this message because you are subscribed to the Google Groups "UniMRCP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to unimrcp+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.