[lte][agw] Fix T3489 handling (magma#3818)

* Add T3489 tests

Introduce a new test to validate T3489 expiry.

Credit to ulaskozat for the diff

Testing done:
Verified that an ASAN use after free occurs on timer expiry

=7031==ERROR: AddressSanitizer: heap-use-after-free on address 0x603000093460 at pc 0x555807545462 bp 0x7f87093fd2b0 sp 0x7f87093fd2a8
WRITE of size 8 at 0x603000093460 thread T16
    #0 0x555807545461 in nas_stop_T3489 /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/esm_data_context.c:101
    #1 0x5558075c47c5 in esm_proc_esm_information_response /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/esm_information.c:119
    #2 0x55580759339b in esm_recv_information_response /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/sap/esm_recv.c:575
    #3 0x555807551fba in _esm_sap_recv /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/sap/esm_sap.c:679
    #4 0x555807550f33 in esm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/sap/esm_sap.c:283
    #5 0x5558075195a0 in lowerlayer_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/LowerLayer.c:276
    #6 0x55580757848f in _emm_as_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:688
    #7 0x555807574ec4 in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:180
    #8 0x55580753147f in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:105
    #9 0x5558074d74fc in nas_proc_ul_transfer_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:326
    #10 0x5558071bd634 in handle_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:97
    #11 0x7f871bb277bd in zloop_start (/usr/lib/x86_64-linux-gnu/libczmq.so.4+0x287bd)
    #12 0x5558071bf169 in mme_app_thread /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:447
    #13 0x7f871e11f4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #14 0x7f871a494d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)

0x603000093460 is located 0 bytes inside of 32-byte region [0x603000093460,0x603000093480)
freed by thread T16 here:
    #0 0x7f871e602a10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
    #1 0x5558070dc054 in free_wrapper /home/vagrant/magma/lte/gateway/c/oai/common/dynamic_memory_check.c:47
    #2 0x555807545496 in nas_stop_T3489 /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/esm_data_context.c:103
    #3 0x5558075c517a in _esm_information /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/esm_information.c:269
    #4 0x5558075c4e15 in _esm_information_t3489_handler /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/esm/esm_information.c:199
    #5 0x5558074e2e8a in mme_app_nas_timer_handle_signal_expiry /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/util/nas_timer.c:100
    #6 0x5558071be2d2 in handle_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:235
    #7 0x7f871bb277bd in zloop_start (/usr/lib/x86_64-linux-gnu/libczmq.so.4+0x287bd)

Signed-off-by: Amar Padmanabhan <[email protected]>

* Invalidate the T3849 timer id while processing esm information retransmit

The _esm_information function stops the existing T3849 timer as referenced
by the esm_ctxt datastructure timer before rescheduling a new T3849 timer
when it requests for the esm info from a UE.
Stopping the timer has a side effect of freeing up the UE related
retransmission data associated with it. This causes issues during
the T3849 timer expiry handling as the cancelled timer and the rescheduled
one reuse the same retransmission data datastructure.

Fix this by unsetting the T3849 timer in the handling of the timer expiry
as the esm_ctxt is not associated with any valid timers anymore. Further
as the timer is a oneshot timer it will be cleaned up after the processing
of the timer callback.

Signed-off-by: Amar Padmanabhan <[email protected]>

Author: Amar Padmanabhan

lte/gateway/c/oai/tasks/nas/esm/esm_information.c

@@ -193,6 +193,9 @@ static void _esm_information_t3489_handler(void* args, imsi64_t* imsi64) {
 
     *imsi64 = esm_ebr_timer_data->ctx->_imsi64;
     if (esm_ebr_timer_data->count < ESM_INFORMATION_COUNTER_MAX) {
+      // Unset the timer id maintained in the esm_ctx, as the timer is no
+      // longer valid.
+      esm_ebr_timer_data->ctx->esm_ctx.T3489.id = NAS_TIMER_INACTIVE_ID;
       /*
        * Re-send deactivate EPS bearer context request message to the UE
        */
@@ -228,19 +231,21 @@ static void _esm_information_t3489_handler(void* args, imsi64_t* imsi64) {
 
 /****************************************************************************
  **                                                                        **
- ** Name:    _esm_information()                                  **
+ ** Name:    _esm_information()                                            **
  **                                                                        **
  ** Description: Sends DEACTIVATE EPS BEREAR CONTEXT REQUEST message and   **
- **      starts timer T3489                                        **
+ **      starts timer T3489.                                               **
+ **      Function also clearns out any existing T3489 timers referenced    **
+ **      by the esm_ctx datastructure.                                     **
  **                                                                        **
- ** Inputs:  ue_id:      UE local identifier                        **
- **      ebi:       EPS bearer identity                        **
- **      msg:       Encoded ESM message to be sent             **
- **      Others:    None                                       **
+ ** Inputs:  ue_id:      UE local identifier                               **
+ **      ebi:       EPS bearer identity                                    **
+ **      msg:       Encoded ESM message to be sent                         **
+ **      Others:    None                                                   **
  **                                                                        **
  ** Outputs:     None                                                      **
- **      Return:    RETURNok, RETURNerror                      **
- **      Others:    T3489                                      **
+ **      Return:    RETURNok, RETURNerror                                  **
+ **      Others:    T3489                                                  **
  **                                                                        **
  ***************************************************************************/
 static int _esm_information(

lte/gateway/python/integ_tests/s1aptests/test_attach_esm_information_timerexpiration.py

@@ -0,0 +1,149 @@
+"""
+Copyright 2020 The Magma Authors.
+
+This source code is licensed under the BSD-style license found in the
+LICENSE file in the root directory of this source tree.
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+"""
+
+import unittest
+
+import s1ap_types
+import time
+
+from integ_tests.s1aptests import s1ap_wrapper
+import ctypes
+
+
+class TestEsmInformation(unittest.TestCase):
+    def setUp(self):
+        self._s1ap_wrapper = s1ap_wrapper.TestWrapper()
+
+    def tearDown(self):
+        self._s1ap_wrapper.cleanup()
+
+    def test_esm_information_timerexpiration(self):
+        """ Testing of sending Esm Information procedure """
+        num_ues = 1
+        num_of_expires = 2
+
+        self._s1ap_wrapper.configUEDevice(num_ues)
+        print("************************* sending Attach Request for ue-id : 1")
+        attach_req = s1ap_types.ueAttachRequest_t()
+        attach_req.ue_Id = 1
+        sec_ctxt = s1ap_types.TFW_CREATE_NEW_SECURITY_CONTEXT
+        id_type = s1ap_types.TFW_MID_TYPE_IMSI
+        eps_type = s1ap_types.TFW_EPS_ATTACH_TYPE_EPS_ATTACH
+        attach_req.mIdType = id_type
+        attach_req.epsAttachType = eps_type
+        attach_req.useOldSecCtxt = sec_ctxt
+
+        # enabling ESM Information transfer flag
+        attach_req.eti.pres = 1
+        attach_req.eti.esm_info_transfer_flag = 1
+
+        print("Sending Attach Request ue-id", attach_req.ue_Id)
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_ATTACH_REQUEST, attach_req
+        )
+
+        response = self._s1ap_wrapper.s1_util.get_response()
+        self.assertEqual(
+            response.msg_type, s1ap_types.tfwCmd.UE_AUTH_REQ_IND.value
+        )
+        print("Received auth req ind ")
+
+        auth_res = s1ap_types.ueAuthResp_t()
+        auth_res.ue_Id = 1
+        sqn_recvd = s1ap_types.ueSqnRcvd_t()
+        sqn_recvd.pres = 0
+        auth_res.sqnRcvd = sqn_recvd
+        print("Sending Auth Response ue-id", auth_res.ue_Id)
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_AUTH_RESP, auth_res
+        )
+
+        response = self._s1ap_wrapper.s1_util.get_response()
+        self.assertEqual(
+            response.msg_type, s1ap_types.tfwCmd.UE_SEC_MOD_CMD_IND.value
+        )
+        print("Received Security Mode Command ue-id", auth_res.ue_Id)
+
+        time.sleep(1)
+
+        sec_mode_complete = s1ap_types.ueSecModeComplete_t()
+        sec_mode_complete.ue_Id = 1
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_SEC_MOD_COMPLETE, sec_mode_complete
+        )
+
+        for i in range(num_of_expires):
+            # Esm Information Request indication
+            print(
+                "Received Esm Information Request ue-id", sec_mode_complete.ue_Id
+            )
+            response = self._s1ap_wrapper.s1_util.get_response()
+            self.assertEqual(
+                response.msg_type, s1ap_types.tfwCmd.UE_ESM_INFORMATION_REQ.value
+            )
+            esm_info_req = response.cast(s1ap_types.ueEsmInformationReq_t)
+
+        # Sending Esm Information Response
+        print(
+            "Sending Esm Information Response ue-id", sec_mode_complete.ue_Id
+        )
+        esm_info_response = s1ap_types.ueEsmInformationRsp_t()
+        esm_info_response.ue_Id = 1
+        esm_info_response.tId = esm_info_req.tId
+        esm_info_response.pdnAPN_pr.pres = 1
+        s = "magma.ipv4"
+        esm_info_response.pdnAPN_pr.len = len(s)
+        esm_info_response.pdnAPN_pr.pdn_apn = (ctypes.c_ubyte * 100)(
+            *[ctypes.c_ubyte(ord(c)) for c in s[:100]]
+        )
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_ESM_INFORMATION_RSP, esm_info_response
+        )
+
+        response = self._s1ap_wrapper.s1_util.get_response()
+        self.assertEqual(
+            response.msg_type, s1ap_types.tfwCmd.INT_CTX_SETUP_IND.value
+        )
+        response = self._s1ap_wrapper.s1_util.get_response()
+        self.assertEqual(
+            response.msg_type, s1ap_types.tfwCmd.UE_ATTACH_ACCEPT_IND.value
+        )
+
+        # Trigger Attach Complete
+        attach_complete = s1ap_types.ueAttachComplete_t()
+        attach_complete.ue_Id = 1
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_ATTACH_COMPLETE, attach_complete
+        )
+        # Wait on EMM Information from MME
+        self._s1ap_wrapper._s1_util.receive_emm_info()
+
+        print("*** Running UE detach ***")
+        # Now detach the UE
+        detach_req = s1ap_types.uedetachReq_t()
+        detach_req.ue_Id = 1
+        detach_req.ueDetType = (
+            s1ap_types.ueDetachType_t.UE_SWITCHOFF_DETACH.value
+        )
+        self._s1ap_wrapper._s1_util.issue_cmd(
+            s1ap_types.tfwCmd.UE_DETACH_REQUEST, detach_req
+        )
+        # Wait for UE context release command
+        response = self._s1ap_wrapper.s1_util.get_response()
+        self.assertEqual(
+            response.msg_type, s1ap_types.tfwCmd.UE_CTX_REL_IND.value
+        )
+
+
+if __name__ == "__main__":
+    unittest.main()