RestComm / Restcomm-Connect

The Open Source Cloud Communications Platform
http://www.restcomm.com/
GNU Affero General Public License v3.0
244 stars 215 forks source link

Restcomm Sends [SIP/2.0 500 Server Internal Error] for voiceApp with no error #2013

Open maria-farooq opened 7 years ago

maria-farooq commented 7 years ago

On cloud we had a sample application that was just calling an external service. it has no dial, say or play verbs in it. App is mapped on a did and when calling that DID restcomm send SIP/2.0 500 Server Internal Error despite that everything went fine for execution of external service. after adding a say verb in app rcml, restcomm starting behaving normally.

PCAP Flow

Caller -> RC : SIP/SDP-Invite
RC -> Caller : SIP 180 Ringing
RC -> Caller : SIP 500 Server Internal Error

Why RC is unable to send 200 OK after ringing?

As per Call fsm:

This is a valid use case, that an application only execute an external service step and do nothing else.

Any thoughts on it @deruelle @gvagenas

maria-farooq commented 7 years ago

https://telestax.atlassian.net/browse/RESTCOMM-837

deruelle commented 7 years ago

@maria-farooq what does the External Service returns to RVD which in turn should return a valid RCML to RC, ie which RCML did VoiceInterpreter got ?

maria-farooq commented 7 years ago

@deruelle as i explained in my last message, we get an End tag Here is an example of such RCML

<Response/>

Here are some logs for more clarity

06:40:23,440 INFO  [org.restcomm.connect.interpreter.VoiceInterpreter] (RestComm-akka.actor.default-dispatcher-1773)  ********** VoiceInterpreter's akka://RestComm/user/supervisor/$L4g Current State: downloading rcml
, Processing Message: org.restcomm.connect.commons.patterns.Observing
06:40:23,555 INFO  [org.restcomm.connect.rvd.http.resources.RvdController] (http-/10.0.0.17:443-13) Received Restcomm POST request
06:40:23,634 INFO  [org.restcomm.connect.rvd.model.steps.es.ExternalServiceStep] (http-/10.0.0.17:443-13) Requesting from url: https://hook.io/leftyb/inbound_pstn_monitor
06:40:23,856 INFO  [org.restcomm.connect.interpreter.VoiceInterpreter] (RestComm-akka.actor.default-dispatcher-1773)  ********** VoiceInterpreter's akka://RestComm/user/supervisor/$L4g Current State: downloading rcml
, Processing Message: org.restcomm.connect.http.client.DownloaderResponse
06:40:23,857 INFO  [org.restcomm.connect.interpreter.VoiceInterpreter] (RestComm-akka.actor.default-dispatcher-1773) Downloader response is success, moving to Ready state
06:40:23,857 INFO  [org.restcomm.connect.commons.faulttolerance.RestcommSupervisor] (RestComm-akka.actor.default-dispatcher-1773)  ********** RestcommSupervisor akka://RestComm/user/supervisor Processing Message: akka.actor.Props
06:40:23,857 INFO  [org.restcomm.connect.interpreter.VoiceInterpreter] (RestComm-akka.actor.default-dispatcher-1775)  ********** VoiceInterpreter's akka://RestComm/user/supervisor/$L4g Current State: ready
, Processing Message: org.restcomm.connect.interpreter.rcml.End
06:40:23,857 INFO  [org.restcomm.connect.interpreter.VoiceInterpreter] (RestComm-akka.actor.default-dispatcher-1775) End tag received will move to hangup the call, VI state: ready
06:40:23,857 INFO  [org.restcomm.connect.telephony.Call] (RestComm-akka.actor.default-dispatcher-1775) ********** Call's akka://RestComm/user/supervisor/$M4g Current State: "ringing direction: inbound
06:40:23,857 INFO  [org.restcomm.connect.telephony.Call] (RestComm-akka.actor.default-dispatcher-1775) ********** Call akka://RestComm/user/supervisor/$M4g Processing Message: "org.restcomm.connect.telephony.api.Hangup sender : akka://RestComm/user/supervisor/$L4g
06:40:23,858 INFO  [org.restcomm.connect.telephony.Call] (RestComm-akka.actor.default-dispatcher-1775) About to send BYE, session state: EARLY
maria-farooq commented 7 years ago

complete logs: https://app.box.com/files/0/f/22768409585/500_internal_error

deruelle commented 7 years ago

It seems the behavior of sending an error response is correct then I would use SIP Error code 603 Decline in that case instead of 500 with a Reason Header Empty RCML

anhntnguyen commented 7 years ago

Hi @maria-farooq

I'm trying to fix this issue. I have commit the code to my branch, but I need your help to review it a bit.

Link: https://github.com/anhntnguyen/Restcomm-Connect/commit/e0d1b116ce33342ab07d537ed437ddf71d2c987e

I also tried to run testsuite, after 3 hours it still did not stop, so I manually stoped it: the result at that time is Total: 321, failed: 20, error: 0. All of test related to: CallLifecycleAnswerDelayTest and CallLifecycleTest are all passed. I Dont know why I have 20 testcase fail, the testsuite run too long time to have the result. So I would like you to help me to review a bit. Please give me comment if you have any idea.

I just worry about this modification from me: https://github.com/anhntnguyen/Restcomm-Connect/commit/e0d1b116ce33342ab07d537ed437ddf71d2c987e#diff-0d615773a2b644bc6552d46e6c2498c8L2125

gvagenas commented 7 years ago

Hi @anhntnguyen thanks for your contribution. You don't need to run the full testsuite. Make sure that all tests in CallLifecycleTest are passing (including the new one you provided) and then create an PR. One of the team members will plan for a PR review on that.

Thanks

gvagenas commented 7 years ago

Also @anhntnguyen , keep in mind that every PR should contain the patch for the issue, one or more non-regression test cases (that before the patch is failing and applying the patch is passing) and if the patch is for a new feature, PR should include documentation.

Thanks George

anhntnguyen commented 7 years ago

@maria-farooq @gvagenas I have created a new PR for #1848 and #2013: Here is the link: https://github.com/RestComm/Restcomm-Connect/pull/2097 Please help me to review and give me comments.