Skip to content

Commit 37b4ba5

Browse files
jaimecaserojaimecasero
authored
Merge pull request #2893 from RestComm/restcomm-1932
Improved log statements and test case to reproduce issue
2 parents 1dc9ac2 + b6d35fd commit 37b4ba5

2 files changed

Lines changed: 125 additions & 11 deletions

File tree

‎restcomm/restcomm.interpreter/src/main/java/org/restcomm/connect/interpreter/VoiceInterpreter.java‎

Lines changed: 10 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -1233,18 +1233,15 @@ private void onCallStateChanged(Object message, ActorRef sender) throws Transiti
12331233
outboundCallResponse = event.sipResponse();
12341234
}
12351235
if(logger.isInfoEnabled()){
1236-
logger.info("VoiceInterpreter received CallStateChanged event: "+event+ " from "+(sender == call? "call" : "outboundCall")+ ", sender path: " + sender.path() +", current VI state: "+fsm.state() +" current outboundCall actor is: "+outboundCall);
1236+
String msg = String.format("VoiceInterpreter received CallStateChanged event: [%s] , from sender path: [%s] , sender is initial call: [%s] , current VI state: [%s] , current call state: [%s] , current outboundCall actor is: [%s]", event, sender.path(),(sender == call), fsm.state(), callState != null ? callState.toString() : "null", outboundCall != null ? outboundCall.path(): "null");
1237+
logger.info(msg);
12371238
}
12381239

12391240
switch (event.state()) {
12401241
case QUEUED:
12411242
//Do nothing
12421243
break;
12431244
case RINGING:
1244-
if (logger.isInfoEnabled()) {
1245-
String msg = String.format("Got 180 Ringing from outbound call %s",sender);
1246-
logger.info(msg);
1247-
}
12481245
break;
12491246
case CANCELED:
12501247
if (is(initializingBridge) || is(acquiringOutboundCallInfo) || is(bridging) || is(bridged)) {
@@ -1338,10 +1335,6 @@ private void onCallStateChanged(Object message, ActorRef sender) throws Transiti
13381335
break;
13391336
case COMPLETED:
13401337
//NO_ANSWER, COMPLETED and FAILED events are handled the same
1341-
if (logger.isInfoEnabled()) {
1342-
String msg = String.format("OnCallStateChanged, VI state %s, received %s, is it from inbound call: %s",fsm.state().toString(), callState.toString(), sender.equals(call));
1343-
logger.info(msg);
1344-
}
13451338
if (is(bridging) || is(bridged)) {
13461339
if (sender == outboundCall || sender == call) {
13471340
if(logger.isInfoEnabled()) {
@@ -2825,7 +2818,7 @@ public FinishDialing(final ActorRef source) {
28252818
public void execute(final Object message) throws Exception {
28262819
final State state = fsm.state();
28272820
if(logger.isInfoEnabled()) {
2828-
logger.info("FinishDialing, current state: " + state);
2821+
logger.info("At FinishDialing, current VI state: " + state);
28292822
}
28302823

28312824
if (message instanceof ReceiveTimeout) {
@@ -2865,7 +2858,8 @@ public void execute(final Object message) throws Exception {
28652858

28662859
if (message instanceof CallStateChanged) {
28672860
if(logger.isInfoEnabled()) {
2868-
logger.info("CallStateChanged state: "+((CallStateChanged)message).state().toString()+" ,sender: "+sender().path());
2861+
String msg = String.format("CallStateChanged state received: [%s] , sender path: [%s] , is initial call: [%s] , call state: [%s], fsm state: [%s]", ((CallStateChanged)message).toString(), sender().path(), (sender == call), callState.toString(), fsm.state());
2862+
logger.info(msg);
28692863
}
28702864
if (forking.equals(state) || finishDialing.equals(state) || is(bridged) || is(bridging) ) {
28712865
if (sender.equals(call)) {
@@ -2903,6 +2897,11 @@ public void execute(final Object message) throws Exception {
29032897
} else {
29042898
if (callState == CallStateChanged.State.IN_PROGRESS) {
29052899
call.tell(new Hangup(), self());
2900+
} else {
2901+
if (logger.isInfoEnabled()) {
2902+
String msg = String.format("Didn't sent Hangup to call because current call state is: [%s]", callState.toString());
2903+
logger.info(msg);
2904+
}
29062905
}
29072906
}
29082907
}

‎restcomm/restcomm.testsuite/src/test/java/org/restcomm/connect/testsuite/telephony/DialForkTest.java‎

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -359,6 +359,121 @@ public synchronized void testDialForkNoAnswerButHenrique() throws InterruptedExc
359359
assertEquals(0, mgcpConnections);
360360
}
361361

362+
private String dialForkFromPstn = "<Response><Dial><Client>alice</Client><Sip>sip:henrique@127.0.0.1:" + henriquePort + "</Sip></Dial></Response>";
363+
@Test
364+
public synchronized void testDialForkFromPstnNoAnswerButHenrique() throws InterruptedException, ParseException, MalformedURLException {
365+
stubFor(get(urlPathEqualTo("/1111"))
366+
.willReturn(aResponse()
367+
.withStatus(200)
368+
.withHeader("Content-Type", "text/xml")
369+
.withBody(dialForkFromPstn)));
370+
371+
// Register Alice
372+
SipURI uri = aliceSipStack.getAddressFactory().createSipURI(null, restcommContact);
373+
assertTrue(alicePhone.register(uri, "alice", "1234", aliceContact, 3600, 3600));
374+
375+
// Prepare Alice to receive call
376+
final SipCall aliceCall = alicePhone.createSipCall();
377+
aliceCall.listenForIncomingCall();
378+
379+
// Prepare Henrique phone to receive call
380+
// henriquePhone.setLoopback(true);
381+
final SipCall henriqueCall = henriquePhone.createSipCall();
382+
henriqueCall.listenForIncomingCall();
383+
384+
// Initiate a call using Bob
385+
final SipCall georgeCall = georgePhone.createSipCall();
386+
387+
georgeCall.initiateOutgoingCall(georgeContact, "sip:1111@" + restcommContact, null, body, "application", "sdp", null, null);
388+
assertLastOperationSuccess(georgeCall);
389+
390+
assertTrue(georgeCall.waitOutgoingCallResponse(5 * 1000));
391+
392+
final int response = georgeCall.getLastReceivedResponse().getStatusCode();
393+
assertTrue(response == Response.TRYING || response == Response.RINGING);
394+
if (response == Response.TRYING) {
395+
assertTrue(georgeCall.waitOutgoingCallResponse(5 * 1000));
396+
assertEquals(Response.RINGING, georgeCall.getLastReceivedResponse().getStatusCode());
397+
}
398+
399+
assertTrue(georgeCall.waitOutgoingCallResponse(5 * 1000));
400+
assertEquals(Response.OK, georgeCall.getLastReceivedResponse().getStatusCode());
401+
georgeCall.sendInviteOkAck();
402+
assertTrue(!(georgeCall.getLastReceivedResponse().getStatusCode() >= 400));
403+
404+
aliceCall.listenForCancel();
405+
406+
assertTrue(aliceCall.waitForIncomingCall(3000));
407+
assertTrue(aliceCall.sendIncomingCallResponse(Response.TRYING, "Trying-Alice", 3600));
408+
assertTrue(aliceCall.sendIncomingCallResponse(Response.RINGING, "Ringing-Alice", 3600));
409+
410+
assertTrue(henriqueCall.waitForIncomingCall(3000));
411+
assertTrue(henriqueCall.sendIncomingCallResponse(Response.TRYING, "Trying-Henrique", 3600));
412+
assertTrue(henriqueCall.sendIncomingCallResponse(Response.RINGING, "Ringing-Henrique", 3600));
413+
414+
String receivedBody = new String(henriqueCall.getLastReceivedRequest().getRawContent());
415+
assertTrue(henriqueCall.sendIncomingCallResponse(Response.OK, "OK-Henrique", 3600, receivedBody, "application", "sdp",
416+
null, null));
417+
assertTrue(henriqueCall.waitForAck(5000));
418+
419+
SipTransaction aliceCancelTransaction = aliceCall.waitForCancel(30000);
420+
assertNotNull(aliceCancelTransaction);
421+
aliceCall.respondToCancel(aliceCancelTransaction, 200, "OK-2-Cancel-Alice", 3600);
422+
423+
// Wait to cancel the other branches
424+
Thread.sleep(2000);
425+
426+
JsonObject metrics = MonitoringServiceTool.getInstance().getMetrics(deploymentUrl.toString(), adminAccountSid, adminAuthToken);
427+
int liveCalls = MonitoringServiceTool.getInstance().getStatistics(deploymentUrl.toString(), adminAccountSid, adminAuthToken);
428+
int liveCallsArraySize = MonitoringServiceTool.getInstance().getLiveCallsArraySize(deploymentUrl.toString(), adminAccountSid, adminAuthToken);
429+
assertEquals(2, liveCalls);
430+
assertEquals(2, liveCallsArraySize);
431+
432+
georgeCall.listenForDisconnect();
433+
434+
Thread.sleep(3000);
435+
436+
// hangup.
437+
438+
henriqueCall.disconnect();
439+
440+
assertTrue(georgeCall.waitForDisconnect(3000));
441+
georgeCall.respondToDisconnect();
442+
443+
assertTrue(alicePhone.unregister(aliceContact, 3600));
444+
445+
Thread.sleep(10 * 1000);
446+
447+
assertTrue(MonitoringServiceTool.getInstance().getStatistics(deploymentUrl.toString(), adminAccountSid, adminAuthToken) == 0);
448+
assertTrue(MonitoringServiceTool.getInstance().getLiveCallsArraySize(deploymentUrl.toString(), adminAccountSid, adminAuthToken) == 0);
449+
450+
logger.info("About to check the Requests");
451+
List<LoggedRequest> requests = findAll(getRequestedFor(urlPathMatching("/1111")));
452+
assertTrue(requests.size() == 1);
453+
// requests.get(0).g;
454+
String requestBody = new URL(requests.get(0).getAbsoluteUrl()).getQuery();// .getQuery();// .getBodyAsString();
455+
List<String> params = Arrays.asList(requestBody.split("&"));
456+
String callSid = "";
457+
for (String param : params) {
458+
if (param.contains("CallSid")) {
459+
callSid = param.split("=")[1];
460+
}
461+
}
462+
JsonObject cdr = RestcommCallsTool.getInstance().getCall(deploymentUrl.toString(), adminAccountSid, adminAuthToken, callSid);
463+
JsonObject jsonObj = cdr.getAsJsonObject();
464+
assertTrue(jsonObj.get("status").getAsString().equalsIgnoreCase("completed"));
465+
assertTrue(MonitoringServiceTool.getInstance().getStatistics(deploymentUrl.toString(), adminAccountSid, adminAuthToken) == 0);
466+
assertTrue(MonitoringServiceTool.getInstance().getLiveCallsArraySize(deploymentUrl.toString(), adminAccountSid, adminAuthToken) == 0);
467+
468+
metrics = MonitoringServiceTool.getInstance().getMetrics(deploymentUrl.toString(),adminAccountSid, adminAuthToken);
469+
Map<String, Integer> mgcpResources = MonitoringServiceTool.getInstance().getMgcpResources(metrics);
470+
int mgcpEndpoints = mgcpResources.get("MgcpEndpoints");
471+
int mgcpConnections = mgcpResources.get("MgcpConnections");
472+
473+
assertEquals(0, mgcpEndpoints);
474+
assertEquals(0, mgcpConnections);
475+
}
476+
362477
//Non regression test for https://telestax.atlassian.net/browse/RESTCOMM-585
363478
@Test
364479
public synchronized void testDialForkNoAnswerButFromAliceClient() throws InterruptedException, ParseException, MalformedURLException {

0 commit comments

Comments
 (0)