sip: tweak failure reporting for SIP messages

Help developers by logging message matching failures in detail.

Change-Id: Id48016657ebb83953fe74f65332f318edf8f75e6
diff --git a/sip/SIP_Tests.ttcn b/sip/SIP_Tests.ttcn
index 58000d5..935eed3 100644
--- a/sip/SIP_Tests.ttcn
+++ b/sip/SIP_Tests.ttcn
@@ -188,11 +188,32 @@
 	g_cp := omit
 }
 
+altstep as_SIP_expect_resp(template PDU_SIP_Response sip_expect) runs on ConnHdlr
+{
+	[] SIP.receive(sip_expect);
+	[] SIP.receive {
+		log("FAIL: expected SIP message ", sip_expect);
+		Misc_Helpers.f_shutdown(__BFILE__, __LINE__, fail, "Received unexpected SIP message");
+	}
+}
+
+function f_SIP_expect_req(template PDU_SIP_Request sip_expect) runs on ConnHdlr return PDU_SIP_Request
+{
+	var PDU_SIP_Request rx;
+	alt {
+		[] SIP.receive(sip_expect) -> value rx;
+		[] SIP.receive {
+			log("FAIL: expected SIP message ", sip_expect);
+			Misc_Helpers.f_shutdown(__BFILE__, __LINE__, fail, "Received unexpected SIP message");
+		}
+	}
+	return rx;
+}
+
 /* Establish a mobile terminated call described in 'cp' */
 function f_establish_mt(inout CallPars cp) runs on ConnHdlr {
 	var template SipAddr sip_addr_gsm := tr_SipAddr_from_val(cp.comp.sip_url_gsm);
 	var template SipAddr sip_addr_ext := tr_SipAddr_from_val(cp.comp.sip_url_ext);
-	var PDU_SIP_Response sip_resp;
 	var MNCC_PDU mncc;
 
 	/* Ask MNCC_Emulation to "expect" a call to the given called number */
@@ -202,8 +223,8 @@
 	SIP.send(ts_SIP_INVITE(cp.comp.sip_call_id, cp.comp.sip_url_ext, cp.comp.sip_url_gsm,
 				cp.comp.sip_seq_nr, cp.comp.sip_body));
 	/* OSC -> SIP */
-	SIP.receive(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
-				    "INVITE", 100, ?, "Trying", *));
+	as_SIP_expect_resp(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
+					   "INVITE", 100, ?, "Trying", *));
 
 	alt {
 	/* MSC <- OSC: OSC generates MNCC_SETUP_REQ from INVITE */
@@ -231,33 +252,23 @@
 	/* MSC -> OSC: After MS is ringing and sent CC ALERTING */
 	MNCC.send(ts_MNCC_ALERT_ind(cp.mncc_call_id));
 	SIP.clear;
-	alt {
-	[] SIP.receive(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
-				       "INVITE", 180, ?, "Ringing", *));
-	[] SIP.receive {
-		setverdict(fail, "Received unexpected respose");
-		SIP.send(ts_SIP_ACK(cp.comp.sip_call_id, cp.comp.sip_url_ext, cp.comp.sip_url_gsm,
-				    cp.comp.sip_seq_nr, omit));
-		mtc.stop;
-		}
-	}
+
+	as_SIP_expect_resp(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
+					   "INVITE", 180, ?, "Ringing", *));
 
 	/* MSC -> OSC: After MT user has picked up and sent CC CONNECT */
 	MNCC.send(ts_MNCC_SETUP_CNF(cp.mncc_call_id));
 
 	SIP.clear;
-	interleave {
 	/* MSC <- OSC: OSC asks MSC to connect its RTP stream to remote end */
-	[] MNCC.receive(tr_MNCC_RTP_CONNECT(cp.mncc_call_id, f_addrstr2addr(cp.sip_rtp_addr), cp.sip_rtp_port)) {}
+	MNCC.receive(tr_MNCC_RTP_CONNECT(cp.mncc_call_id, f_addrstr2addr(cp.sip_rtp_addr), cp.sip_rtp_port));
+
 	/* OSC -> SIP: OSC confirms call establishment to SIP side */
-	[] SIP.receive(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, ?,
-					"INVITE", 200, ?, "OK", ?)) -> value sip_resp {
-						if (not match(sip_resp.messageBody, pattern "*" & cp.cn_rtp_addr & "*")) {
-							setverdict(fail, "wrong ip addr sent in SIP SDP, not containing ", cp.cn_rtp_addr);
-							mtc.stop;
-						}
-					}
-	}
+	as_SIP_expect_resp(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, contact_addr := ?,
+					   method := "INVITE", status_code := 200,
+					   seq_nr := ?, reason := "OK",
+					   body := pattern "*" & cp.cn_rtp_addr & "*"));
+
 	/* OSC <- SIP: SIP world acknowledges "200 OK" */
 	SIP.send(ts_SIP_ACK(cp.comp.sip_call_id, cp.comp.sip_url_ext, cp.comp.sip_url_gsm,
 			    cp.comp.sip_seq_nr, omit));
@@ -287,12 +298,13 @@
 		mncc.u.rtp.rtp_port := cp.cn_rtp_port;
 		MNCC.send(mncc);
 		}
+
 	/* OSC -> SIP: Send INVITE with GSM side IP/Port in SDP */
-	SIP.receive(tr_SIP_INVITE(?, sip_addr_gsm, sip_addr_ext, ?, ?)) -> value sip_req {
-		cp.comp.sip_url_gsm.params := sip_req.msgHeader.fromField.fromParams;
-		cp.comp.sip_call_id := sip_req.msgHeader.callId.callid;
-		seq_nr := sip_req.msgHeader.cSeq.seqNumber;
-		}
+	sip_req := f_SIP_expect_req(tr_SIP_INVITE(?, sip_addr_gsm, sip_addr_ext, ?, ?));
+	cp.comp.sip_url_gsm.params := sip_req.msgHeader.fromField.fromParams;
+	cp.comp.sip_call_id := sip_req.msgHeader.callId.callid;
+	seq_nr := sip_req.msgHeader.cSeq.seqNumber;
+
 	/* OSC <- SIP: Notify call is proceeding */
 	SIP.send(ts_SIP_Response(cp.comp.sip_call_id, cp.comp.sip_url_gsm, cp.comp.sip_url_ext,
 				 "INVITE", 100, seq_nr, "Trying", sip_req.msgHeader.via));
@@ -328,10 +340,11 @@
 	SIP.clear;
 	/* MSC -> OSC: Simulate a CC DISCONNET from the MT user */
 	MNCC.send(ts_MNCC_DISC_ind(cp.mncc_call_id, ts_MNCC_cause(0)));
+
 	/* OSC -> SIP: Expect BYE from OSC to SIP side */
-	SIP.receive(tr_SIP_BYE(cp.comp.sip_call_id, sip_addr_gsm, sip_addr_ext, ?, *)) -> value sip_req {
-		cp.comp.sip_url_gsm.params := sip_req.msgHeader.fromField.fromParams;
-	}
+	sip_req := f_SIP_expect_req(tr_SIP_BYE(cp.comp.sip_call_id, sip_addr_gsm, sip_addr_ext, ?, *));
+	cp.comp.sip_url_gsm.params := sip_req.msgHeader.fromField.fromParams;
+
 	/* OSC <- SIP: Acknowledge the BYE */
 	SIP.send(ts_SIP_Response(cp.comp.sip_call_id, cp.comp.sip_url_gsm, cp.comp.sip_url_ext,
 					 "BYE", 200, sip_req.msgHeader.cSeq.seqNumber, "OK",
@@ -354,8 +367,8 @@
 	/* MSC -> OSC: Indicate GSM side release */
 	MNCC.send(ts_MNCC_REL_ind(cp.mncc_call_id, ts_MNCC_cause(0)));
 	/* OSC -> SIP: Confirmation to SIP side */
-	SIP.receive(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
-				    "BYE", 200, cp.comp.sip_seq_nr, "OK", omit));
+	as_SIP_expect_resp(tr_SIP_Response(cp.comp.sip_call_id, sip_addr_ext, sip_addr_gsm, *,
+					   "BYE", 200, cp.comp.sip_seq_nr, "OK", omit));
 }
 
 /* Successful MT Call, which is subsequently released by GSM side */