RestComm / media-core

RMS - Restcomm Media Server for Real Time Cloud Communications
http://www.restcomm.com/
GNU Affero General Public License v3.0
163 stars 124 forks source link

Exception while Dial Record #25

Closed gvagenas closed 9 years ago

gvagenas commented 9 years ago

Starting Restcomm and then Jitsi calls RCML apps that Dials client BOB with RECORD=TRUE

First two calls are ok, clients are connected and record is working. Third call (always the third call and next calls) fails with the following:

15:37:00,571 DEBUG [MgcpProvider] Dispatching message 15:37:00,572 INFO [MGCP] tx=147483701 Started, message= RQNT mobicents/ivr/3@192.168.1.151:2427, call agent = gvagenas-Latitude-E6520/192.168.1.151:2727 15:37:00,572 DEBUG [MgcpProvider] Receive message 346 bytes length 15:37:00,572 DEBUG [MgcpProvider] Parsing message: RQNT 147483702 mobicents/ivr/3@192.168.1.151:2427 MGCP 1.0 N:restcomm@192.168.1.151:2727 X:14 S:AU/pr(ri=file:///data/workspace/temp/731/Mobicents-Restcomm-JBoss-AS7-7.3.1.675/standalone/deployments/restcomm.war/recordings/RE845045f7a1dd41caaf57d56417c4237b.wav cb=true prt=50 pst=50 rlt=3600000 eik=1234567890*# mn=12 mx=12) R:AU/oc(N),AU/of(N)

15:37:00,572 DEBUG [MgcpProvider] Dispatching message 15:37:00,572 INFO [MGCP] tx=147483702 Started, message= RQNT mobicents/ivr/3@192.168.1.151:2427, call agent = gvagenas-Latitude-E6520/192.168.1.151:2727 15:37:00,574 ERROR [MGCP] tx=147483702 Failed org.mobicents.media.server.mgcp.tx.cmd.MgcpCommandException at org.mobicents.media.server.mgcp.tx.cmd.NotificationRequestCmd$Request.perform(NotificationRequestCmd.java:151) at org.mobicents.media.server.scheduler.Task.run(Task.java:122) at org.mobicents.media.server.scheduler.Scheduler$WorkerThread.run(Scheduler.java:420)

And then full of :

gvagenas [3:40 PM] 15:37:00,592 WARN [RtcpHandler] RTCP timer already canceled. Scheduled report was canceled and cannot be re-scheduled. 15:37:00,592 DEBUG [MgcpProvider] Dispatching message 15:37:00,592 INFO [MGCP] tx=147483703 Started, message= DLCX mobicents/bridge/5@192.168.1.151:2427, call agent = gvagenas-Latitude-E6520/192.168.1.151:2727 15:37:00,593 DEBUG [MediaChannel] audio channel 1224799310 is closed 15:37:00,593 DEBUG [RtcpHandler] Could not send RTCP_BYE packet because channel is closed or disconnected. 15:37:00,593 DEBUG [ResourcesPool] Released rtp connection,pool size:10,free:9 15:37:00,593 INFO [MGCP] tx=147483703 was executed normaly 15:37:00,871 WARN [JitterBuffer] Buffer overflow! 15:37:00,891 WARN [JitterBuffer] Buffer overflow! 15:37:00,911 WARN [JitterBuffer] Buffer overflow! 15:37:00,931 WARN [JitterBuffer] Buffer overflow! 15:37:00,951 WARN [JitterBuffer] Buffer overflow! 15:37:00,971 WARN [JitterBuffer] Buffer overflow! 15:37:00,991 WARN [JitterBuffer] Buffer overflow! 15:37:01,012 WARN [JitterBuffer] Buffer overflow! 15:37:01,032 WARN [JitterBuffer] Buffer overflow! 15:37:01,052 WARN [JitterBuffer] Buffer overflow! 15:37:01,072 WARN [JitterBuffer] Buffer overflow! 15:37:01,092 WARN [JitterBuffer] Buffer overflow! 15:37:01,112 WARN [JitterBuffer] Buffer overflow! 15:37:01,131 WARN [JitterBuffer] Buffer overflow! 15:37:01,151 WARN [JitterBuffer] Buffer overflow! 15:37:01,171 WARN [JitterBuffer] Buffer overflow! 15:37:01,191 WARN [JitterBuffer] Buffer overflow! 15:37:01,212 WARN [JitterBuffer] Buffer overflow! 15:37:01,232 WARN [JitterBuffer] Buffer overflow! 15:37:01,252 WARN [JitterBuffer] Buffer overflow! 15:37:01,272 WARN [JitterBuffer] Buffer overflow! 15:37:01,291 WARN [JitterBuffer] Buffer overflow! 15:37:01,312 WARN [JitterBuffer] Buffer overflow! 15:37:01,332 WARN [JitterBuffer] Buffer overflow! 15:37:01,352 WARN [JitterBuffer] Buffer overflow! 15:37:01,372 WARN [JitterBuffer] Buffer overflow! 15:37:01,392 WARN [JitterBuffer] Buffer overflow! 15:37:01,411 WARN [JitterBuffer] Buffer overflow! 15:37:01,432 WARN [JitterBuffer] Buffer overflow! 15:37:01,452 WARN [JitterBuffer] Buffer overflow! 15:37:01,472 WARN [JitterBuffer] Buffer overflow! 15:37:01,492 WARN [JitterBuffer] Buffer overflow! 15:37:01,511 WARN [JitterBuffer] Buffer overflow! 15:37:01,531 WARN [JitterBuffer] Buffer overflow! 15:37:01,551 WARN [JitterBuffer] Buffer overflow! 15:37:01,572 WARN [JitterBuffer] Buffer overflow! 15:37:01,591 WARN [JitterBuffer] Buffer overflow! 15:37:01,612 WARN [JitterBuffer] Buffer overflow! 15:37:01,631 WARN [JitterBuffer] Buffer overflow! 15:37:01,652 WARN [JitterBuffer] Buffer overflow! 15:37:01,671 WARN [JitterBuffer] Buffer overflow! 15:37:01,692 WARN [JitterBuffer] Buffer overflow! 15:37:01,712 WARN [JitterBuffer] Buffer overflow! 15:37:01,732 WARN [JitterBuffer] Buffer overflow! 15:37:01,751 WARN [JitterBuffer] Buffer overflow! 15:37:01,771 WARN [JitterBuffer] Buffer overflow! 15:37:01,791 WARN [JitterBuffer] Buffer overflow! 15:37:01,812 WARN [JitterBuffer] Buffer overflow! 15:37:01,832 WARN [JitterBuffer] Buffer overflow! 15:37:01,852 WARN [JitterBuffer] Buffer overflow! 15:37:01,872 WARN [JitterBuffer] Buffer overflow! 15:37:01,892 WARN [JitterBuffer] Buffer overflow! 15:37:01,912 WARN [JitterBuffer] Buffer overflow! 15:37:01,931 WARN [JitterBuffer] Buffer overflow! 15:37:01,952 WARN [JitterBuffer] Buffer overflow! 15:37:01,972 WARN [JitterBuffer] Buffer overflow! 15:37:01,992 WARN [JitterBuffer] Buffer overflow! 15:37:02,011 WARN [JitterBuffer] Buffer overflow! 15:37:02,032 WARN [JitterBuffer] Buffer overflow! 15:37:02,051 WARN [JitterBuffer] Buffer overflow!

gvagenas commented 9 years ago

Log file: https://gist.github.com/gvagenas/6b8707f249fe3bc4b517

hrosa commented 9 years ago

After taking a tcpdump trace, I noticed that RestComm is sending an MGCP RQNT (EndSignal) to stop the ringing. This request defines two events (AU/oc, AU/of) in the RequestedEvents parameter. Unfortunately the EndSignal specification does not support any events.

So, the issue is on RestComm side because the request is malformed. To fix the issue, the following line should be deleted:

https://github.com/Mobicents/RestComm/blob/master/restcomm/restcomm.mgcp/src/main/java/org/mobicents/servlet/restcomm/mgcp/IvrEndpoint.java#L102