log CC timeouts

Change-Id: I857b4b15ebf75cf253697e96d358128620923221
---
M src/libmsc/gsm_04_08_cc.c
M tests/msc_vlr/msc_vlr_test_call.err
2 files changed, 5 insertions(+), 0 deletions(-)


git pull ssh://gerrit.osmocom.org:29418/osmo-msc refs/changes/07/30107/1

diff --git a/src/libmsc/gsm_04_08_cc.c b/src/libmsc/gsm_04_08_cc.c
index 99174de..771ddbc 100644
--- a/src/libmsc/gsm_04_08_cc.c
+++ b/src/libmsc/gsm_04_08_cc.c
@@ -398,6 +398,8 @@
 	int l4_location = GSM48_CAUSE_LOC_PRN_S_LU;
 	struct gsm_mncc mo_rel, l4_rel;
 
+	LOG_TRANS(trans, LOGL_INFO, "Timeout of T%x\n", trans->cc.Tcurrent);
+
 	memset(&mo_rel, 0, sizeof(struct gsm_mncc));
 	mo_rel.callref = trans->callref;
 	memset(&l4_rel, 0, sizeof(struct gsm_mncc));
diff --git a/tests/msc_vlr/msc_vlr_test_call.err b/tests/msc_vlr/msc_vlr_test_call.err
index ec1b233..5ee7176 100644
--- a/tests/msc_vlr/msc_vlr_test_call.err
+++ b/tests/msc_vlr/msc_vlr_test_call.err
@@ -1723,6 +1723,7 @@
 - DTAP matches expected message
 DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
 - Total time passed: 10.000023 s
+DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000002 tid-8) Timeout of T308
 DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000002 tid-8) starting timer T308 with 10 seconds
 DIUCS msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: Sending DTAP: CC GSM48_MT_CC_RELEASE
 DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: RAN encode: DTAP on UTRAN-Iu
@@ -2151,6 +2152,7 @@
 DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
 - Despite our repeated CC Release Requests, the MS does not respond anymore
 - Total time passed: 10.000023 s
+DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000003 tid-8) Timeout of T308
 DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000003 tid-8) starting timer T308 with 10 seconds
 DIUCS msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: Sending DTAP: CC GSM48_MT_CC_RELEASE
 DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: RAN encode: DTAP on UTRAN-Iu
@@ -2159,6 +2161,7 @@
 DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
 - The CC Release times out and we still properly clear the conn
 - Total time passed: 20.000046 s
+DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000003 tid-8) Timeout of T308
 DCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000003 tid-8) Freeing transaction
 DMNCC trans(CC:RELEASE_REQ IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ callref-0x80000003 tid-8) tx MNCC_REL_CNF
   MSC --> MNCC: callref 0x80000003: MNCC_REL_CNF

