Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[MME] ERROR: AddressSanitizer: heap-use-after-free on address #2404

Closed
dcollin5 opened this issue Aug 19, 2020 · 7 comments
Closed

[MME] ERROR: AddressSanitizer: heap-use-after-free on address #2404

dcollin5 opened this issue Aug 19, 2020 · 7 comments
Assignees
@ssanadhya
Labels
component: agw Access gateway-related issue

Comments

@dcollin5
Copy link

Your Environment

Running srsLTE eNB + srsUE - and connecting into the AGW VM container for the epc.

srsLTE UE has the following parameters:
[usim]
mode = soft
algo = milenage
opc = 63bfa50ee6523365ff14c1f45f88737d
k = 00112233445566778899aabbccddeeff
imsi = 001010123456780
imei = 353490069873319

[note - we are not using the --lte-auth-opc due to another recent post https://github.com//issues/1907]
(python) vagrant@magma-dev:~$ subscriber_cli.py get IMSI001010123456780
sid {
id: "001010123456780"
}
gsm {
}
lte {
state: ACTIVE
auth_key: "\000\021"3DUfw\210\231\252\273\314\335\356\377"
}
state {
lte_auth_next_seq: 2
}

similar to this issue "#1907" our GRPC service call is failing

magma@state.service - Magma state service
Loaded: loaded (/etc/systemd/system/magma@.service; disabled; vendor preset: enabled)
Active: active (running) since Wed 2020-08-19 16:47:55 UTC; 1h 42min ago
Main PID: 10410 (python3)
Tasks: 16 (limit: 4915)
Memory: 27.3M (limit: 300.0M)
CGroup: /system.slice/system-magma.slice/magma@state.service
└─10410 python3 -m magma.state.main

Aug 19 18:29:00 magma-dev state[10410]: ERROR:root:GRPC call failed for initial state re-sync: <_Rendezvous of RPC that terminated with:
Aug 19 18:29:00 magma-dev state[10410]: status = StatusCode.CANCELLED
Aug 19 18:29:00 magma-dev state[10410]: details = "Received http2 header with status: 503"
Aug 19 18:29:00 magma-dev state[10410]: debug_error_string = "{"created":"@1597861740.365663605","description":"Received http2 :status header with non-200 OK status","file":"src/core/ext/filters/http/client/http_client_filter.cc","file_line":100,"grpc_message":
Aug 19 18:29:00 magma-dev state[10410]: >
Aug 19 18:30:00 magma-dev state[10410]: ERROR:root:GRPC call failed for initial state re-sync: <_Rendezvous of RPC that terminated with:
Aug 19 18:30:00 magma-dev state[10410]: status = StatusCode.CANCELLED
Aug 19 18:30:00 magma-dev state[10410]: details = "Received http2 header with status: 503"
Aug 19 18:30:00 magma-dev state[10410]: debug_error_string = "{"created":"@1597861800.387183000","description":"Received http2 :status header with non-200 OK status","file":"src/core/ext/filters/http/client/http_client_filter.cc","file_line":100,"grpc_message":
Aug 19 18:30:00 magma-dev state[10410]: >

vagrant@magma-dev:~/magma$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description: Debian GNU/Linux 9.12 (stretch)
Release: 9.12
Codename: stretch

  • Version:
    git rev-parse HEAD
    120da52

  • Affected Component: Orchestrator, Access Gateway, or NMS
    AGW VM
    We are trying to connect the AGW to the external interface.

  • Affected Subcomponent: Orchestrator pod/service or AGW service
    MME

  • Deployment Environment: e.g. AWS (orc8r), local docker-compose (orc8r), bare-metal (AGW), Vagrant (AGW)
    Large OpenStack Virtual Machine - following these instructions: https://magma.github.io/magma/docs/basics/quick_start_guide

Describe the Issue

A clear and concise description of what the bug is.

Running the srsLTE UE to attach to the srsLTE eNB
Aug 19 18:20:12 magma-dev mme[16659]: [INFO] Sending S6A-AUTHENTICATION_INFORMATION_REQUEST with IMSI: 001010123456780
Aug 19 18:20:13 magma-dev subscriberdb[10393]: INFO:root:Auth success: 001010123456780
Aug 19 18:20:13 magma-dev mme[16659]: [INFO] Received S6A-AUTHENTICATION_INFORMATION_ANSWER for IMSI: 001010123456780; Status: ; StatusCode: 2001

Then the MME fails with AddressSanitizer

Aug 19 18:20:13 magma-dev mme[16659]: ==16659==ERROR: AddressSanitizer: heap-use-after-free on address 0x6110001d3ac8 at pc 0x5564574407f8 bp 0x7f5acea85ed0 sp 0x7f5acea85ec8
Aug 19 18:20:13 magma-dev mme[16659]: READ of size 8 at 0x6110001d3ac8 thread T11
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.144889 16626 sctpd_downlink_impl.cpp:69] SctpdDownlinkImpl::SendDl starting

To Reproduce

  1. Following the steps on this website: https://magma.github.io/magma/docs/basics/quick_start_guide

We download the magma as follow
git clone -b v1.1.0 https://github.com/magma/magma.git

NOTE: I will try get the latest now.

  1. Once the Vagrant container is up, you need to run the following commands to support access to the enb.
    You will need to set the MAC address of the Vagrant interface to the mac address of the host OpenStack VM interface passed. For example:
    sudo ifconfig eth1 hw ether fa:16:3e:e4:a9:63
    Also, you need to set the interface to promisc mode, otherwise it is not seen by other nodes in the network:
    sudo ifconfig eth1 promisc

  2. add subscribers
    cd ~/magma/lte/gateway
    vagrant ssh magma

magtivate
subscriber_cli.py add --lte-auth-key 00112233445566778899aabbccddeeff IMSI001010123456789
subscriber_cli.py add --lte-auth-key 00112233445566778899aabbccddeeff IMSI001010123456780

  1. eNB /etc/magma/gateway.mconfig
    "enodebd": {
    "@type": "type.googleapis.com/magma.mconfig.EnodebD",
    "bandwidthMhz": 20,
    "specialSubframePattern": 7,
    "earfcndl": 3400,
    "logLevel": "INFO",
    "plmnidList": "00101",
    "pci": 260,
    "allowEnodebTransmit": true,
    "subframeAssignment": 2,
    "tac": 1
    },

Note, I dont know what PCI is??

Expected behavior
UE should attach and I get an IP address. Note, srsLTE eNB and srsUE attach works perfectly with srsEPC.

Screenshots
If applicable, add screenshots to help explain your problem.

Additional context
Add any other context about the problem here (e.g. logs).

Aug 19 18:20:03 magma-dev policydb[10395]: ERROR:root:Error! Streaming from the cloud failed! [StatusCode.CANCELLED] Received http2 header with status: 503
Aug 19 18:20:03 magma-dev control_proxy[10484]: 2020-08-19T18:20:03.170Z [127.0.0.1 -> streamer-controller.magma.test,8443] "POST /magma.orc8r.Streamer/GetUpdates HTTP/2" 503 160bytes 0.000s
Aug 19 18:20:03 magma-dev policydb[10395]: ERROR:root:Error! Streaming from the cloud failed! [StatusCode.CANCELLED] Received http2 header with status: 503
Aug 19 18:20:04 magma-dev magmad[10349]: DEBUG:root:Unattended upgrade status is 0
Aug 19 18:20:07 magma-dev magmad[10349]: DEBUG:root:Failed to ping 8.8.8.8 with error: Could not find statistics header in ping output
Aug 19 18:20:08 magma-dev magmad[10349]: ERROR:root:GetChallenge error! [StatusCode.NOT_FOUND] Gateway with hwid 0725a2af-6d47-471d-8ec3-0f5524a9d8f6 is not registered: Not found
Aug 19 18:20:08 magma-dev magmad[10349]: INFO:root:Retrying bootstrap in 30 seconds
Aug 19 18:20:08 magma-dev control_proxy[10484]: 2020-08-19T18:20:08.436Z [127.0.0.1 -> state-controller.magma.test,8443] "POST /magma.orc8r.StateService/ReportStates HTTP/2" 503 160bytes 0.000s
Aug 19 18:20:08 magma-dev magmad[10349]: ERROR:root:Checkin Error! Failed to report states. [StatusCode.CANCELLED] Received http2 header with status: 503
Aug 19 18:20:08 magma-dev magmad[10349]: INFO:root:StateReporting (Checkin) failure threshold met, remediating...
Aug 19 18:20:08 magma-dev magmad[10349]: ERROR:root:Error making SSL connection: No such file or directory, [Errno 2] No such file or directory
Aug 19 18:20:08 magma-dev magmad[10349]: ERROR:root:Bootstrapping due to invalid cert
Aug 19 18:20:08 magma-dev magmad[10349]: ERROR:root:GetChallenge error! [StatusCode.NOT_FOUND] Gateway with hwid 0725a2af-6d47-471d-8ec3-0f5524a9d8f6 is not registered: Not found
Aug 19 18:20:08 magma-dev magmad[10349]: INFO:root:Retrying bootstrap in 30 seconds
Aug 19 18:20:12 magma-dev sctpd[16621]: I0819 18:20:12.863967 16687 sctp_connection.cpp:168] HandleClientSock sd = 22
Aug 19 18:20:12 magma-dev sctpd[16621]: I0819 18:20:12.864261 16687 sctp_connection.cpp:221] [sd:22] msg of len 66 on 36:1
Aug 19 18:20:12 magma-dev mme[16659]: [INFO] Sending S6A-AUTHENTICATION_INFORMATION_REQUEST with IMSI: 001010123456780
Aug 19 18:20:13 magma-dev subscriberdb[10393]: INFO:root:Auth success: 001010123456780
Aug 19 18:20:13 magma-dev mme[16659]: [INFO] Received S6A-AUTHENTICATION_INFORMATION_ANSWER for IMSI: 001010123456780; Status: ; StatusCode: 2001
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.046509 16686 sctpd_downlink_impl.cpp:69] SctpdDownlinkImpl::SendDl starting
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.084077 16687 sctp_connection.cpp:168] HandleClientSock sd = 22
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.084383 16687 sctp_connection.cpp:221] [sd:22] msg of len 49 on 36:1
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.115772 16626 sctpd_downlink_impl.cpp:69] SctpdDownlinkImpl::SendDl starting
Aug 19 18:20:13 magma-dev mme[16659]: =================================================================
Aug 19 18:20:13 magma-dev mme[16659]: ==16659==ERROR: AddressSanitizer: heap-use-after-free on address 0x6110001d3ac8 at pc 0x5564574407f8 bp 0x7f5acea85ed0 sp 0x7f5acea85ec8
Aug 19 18:20:13 magma-dev mme[16659]: READ of size 8 at 0x6110001d3ac8 thread T11
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.144889 16626 sctpd_downlink_impl.cpp:69] SctpdDownlinkImpl::SendDl starting
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.327524 16687 sctp_connection.cpp:168] HandleClientSock sd = 22
Aug 19 18:20:13 magma-dev sctpd[16621]: I0819 18:20:13.327770 16687 sctp_connection.cpp:221] [sd:22] msg of len 19 on 36:1
Aug 19 18:20:13 magma-dev mme[16659]: #0 0x5564574407f7 in EmmCommonProcedureInitiated /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:148
Aug 19 18:20:13 magma-dev mme[16659]: #1 0x5564573ef798 in emm_fsm_process /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_fsm.c:257
Aug 19 18:20:13 magma-dev mme[16659]: #2 0x55645744d61f in emm_reg_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_reg.c:93
Aug 19 18:20:13 magma-dev mme[16659]: #3 0x5564573f0f06 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:96
Aug 19 18:20:13 magma-dev mme[16659]: #4 0x5564573be971 in emm_proc_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:815
Aug 19 18:20:13 magma-dev mme[16659]: #5 0x55645744c78f in emm_recv_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:1065
Aug 19 18:20:13 magma-dev mme[16659]: #6 0x556457434c33 in _emm_as_recv /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:459
Aug 19 18:20:13 magma-dev mme[16659]: #7 0x556457437020 in _emm_as_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:753
Aug 19 18:20:13 magma-dev mme[16659]: #8 0x556457433b1f in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:215
Aug 19 18:20:13 magma-dev mme[16659]: #9 0x5564573f1042 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:112
Aug 19 18:20:13 magma-dev mme[16659]: #10 0x556457397b46 in nas_proc_ul_transfer_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:345
Aug 19 18:20:13 magma-dev mme[16659]: #11 0x55645718dee8 in mme_app_thread /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:118
Aug 19 18:20:13 magma-dev mme[16659]: #12 0x7f5ae2cd74a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
Aug 19 18:20:13 magma-dev mme[16659]: #13 0x7f5adee0cd0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
Aug 19 18:20:13 magma-dev mme[16659]: 0x6110001d3ac8 is located 8 bytes inside of 216-byte region [0x6110001d3ac0,0x6110001d3b98)
Aug 19 18:20:13 magma-dev mme[16659]: freed by thread T11 here:
Aug 19 18:20:13 magma-dev mme[16659]: #0 0x7f5ae31baa10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
Aug 19 18:20:13 magma-dev mme[16659]: #1 0x55645704b893 in free_wrapper /home/vagrant/magma/lte/gateway/c/oai/common/dynamic_memory_check.c:47
Aug 19 18:20:13 magma-dev mme[16659]: #2 0x556457413ba3 in nas_delete_common_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_procedures.c:401
Aug 19 18:20:13 magma-dev mme[16659]: #3 0x556457440709 in EmmCommonProcedureInitiated /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:143
Aug 19 18:20:13 magma-dev mme[16659]: #4 0x5564573ef798 in emm_fsm_process /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_fsm.c:257
Aug 19 18:20:13 magma-dev mme[16659]: #5 0x55645744d61f in emm_reg_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_reg.c:93
Aug 19 18:20:13 magma-dev mme[16659]: #6 0x5564573f0f06 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:96
Aug 19 18:20:13 magma-dev mme[16659]: #7 0x5564573be971 in emm_proc_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:815
Aug 19 18:20:13 magma-dev mme[16659]: #8 0x55645744c78f in emm_recv_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:1065
Aug 19 18:20:13 magma-dev mme[16659]: #9 0x556457434c33 in _emm_as_recv /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:459
Aug 19 18:20:13 magma-dev mme[16659]: #10 0x556457437020 in _emm_as_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:753
Aug 19 18:20:13 magma-dev mme[16659]: #11 0x556457433b1f in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:215
Aug 19 18:20:13 magma-dev mme[16659]: #12 0x5564573f1042 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:112
Aug 19 18:20:13 magma-dev mme[16659]: #13 0x556457397b46 in nas_proc_ul_transfer_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:345
Aug 19 18:20:13 magma-dev mme[16659]: #14 0x55645718dee8 in mme_app_thread /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:118
Aug 19 18:20:13 magma-dev mme[16659]: #15 0x7f5ae2cd74a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
Aug 19 18:20:13 magma-dev mme[16659]: previously allocated by thread T11 here:
Aug 19 18:20:13 magma-dev mme[16659]: #0 0x7f5ae31baed0 in calloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1ed0)
Aug 19 18:20:13 magma-dev mme[16659]: #1 0x556457416b70 in nas_new_authentication_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_procedures.c:767
Aug 19 18:20:13 magma-dev mme[16659]: #2 0x5564573b7838 in emm_proc_authentication /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:279
Aug 19 18:20:13 magma-dev mme[16659]: #3 0x5564573a9a77 in _emm_start_attach_proc_authentication /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:1210
Aug 19 18:20:13 magma-dev mme[16659]: #4 0x5564573a914f in _emm_attach_run_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:1139
Aug 19 18:20:13 magma-dev mme[16659]: #5 0x5564573a6129 in emm_proc_attach_request /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:585
Aug 19 18:20:13 magma-dev mme[16659]: #6 0x556457448296 in emm_recv_attach_request /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:397
Aug 19 18:20:13 magma-dev mme[16659]: #7 0x556457437eaa in _emm_as_establish_req /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:885
Aug 19 18:20:13 magma-dev mme[16659]: #8 0x556457433bae in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:220
Aug 19 18:20:13 magma-dev mme[16659]: #9 0x5564573f1042 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:112
Aug 19 18:20:13 magma-dev mme[16659]: #10 0x556457397364 in nas_proc_establish_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:196
Aug 19 18:20:13 magma-dev mme[16659]: #11 0x55645719639e in mme_app_handle_initial_ue_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_bearer.c:772
Aug 19 18:20:13 magma-dev mme[16659]: #12 0x55645718e4a2 in mme_app_thread /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:195
Aug 19 18:20:13 magma-dev mme[16659]: #13 0x7f5ae2cd74a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
Aug 19 18:20:13 magma-dev mme[16659]: Thread T11 created by T0 here:
Aug 19 18:20:13 magma-dev mme[16659]: #0 0x7f5ae3129f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
Aug 19 18:20:13 magma-dev mme[16659]: #1 0x556457749ac2 in itti_create_task /home/vagrant/magma/lte/gateway/c/oai/lib/itti/intertask_interface.c:567
Aug 19 18:20:13 magma-dev mme[16659]: #2 0x55645718fa77 in mme_app_init /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:465
Aug 19 18:20:13 magma-dev mme[16659]: #3 0x556457046201 in main /home/vagrant/magma/lte/gateway/c/oai/oai_mme/oai_mme.c:101
Aug 19 18:20:13 magma-dev mme[16659]: #4 0x7f5aded442e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
Aug 19 18:20:13 magma-dev mme[16659]: SUMMARY: AddressSanitizer: heap-use-after-free /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:148 in EmmCommonProcedureInitiated
Aug 19 18:20:13 magma-dev mme[16659]: Shadow bytes around the buggy address:
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032700: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032710: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032720: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032730: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032740: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: =>0x0c2280032750: fa fa fa fa fa fa fa fa fd[fd]fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032760: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032770: fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032780: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c2280032790: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: 0x0c22800327a0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
Aug 19 18:20:13 magma-dev mme[16659]: Shadow byte legend (one shadow byte represents 8 application bytes):
Aug 19 18:20:13 magma-dev mme[16659]: Addressable: 00
Aug 19 18:20:13 magma-dev mme[16659]: Partially addressable: 01 02 03 04 05 06 07
Aug 19 18:20:13 magma-dev mme[16659]: Heap left redzone: fa
Aug 19 18:20:13 magma-dev mme[16659]: Heap right redzone: fb
Aug 19 18:20:13 magma-dev mme[16659]: Freed heap region: fd
Aug 19 18:20:13 magma-dev mme[16659]: Stack left redzone: f1
Aug 19 18:20:13 magma-dev mme[16659]: Stack mid redzone: f2
Aug 19 18:20:13 magma-dev mme[16659]: Stack right redzone: f3
Aug 19 18:20:13 magma-dev mme[16659]: Stack partial redzone: f4
Aug 19 18:20:13 magma-dev mme[16659]: Stack after return: f5
Aug 19 18:20:13 magma-dev mme[16659]: Stack use after scope: f8
Aug 19 18:20:13 magma-dev mme[16659]: Global redzone: f9
Aug 19 18:20:13 magma-dev mme[16659]: Global init order: f6
Aug 19 18:20:13 magma-dev mme[16659]: Poisoned by user: f7
Aug 19 18:20:13 magma-dev mme[16659]: Container overflow: fc
Aug 19 18:20:13 magma-dev mme[16659]: Array cookie: ac
Aug 19 18:20:13 magma-dev mme[16659]: Intra object redzone: bb
Aug 19 18:20:13 magma-dev mme[16659]: ASan internal: fe
Aug 19 18:20:13 magma-dev mme[16659]: Left alloca redzone: ca
Aug 19 18:20:13 magma-dev mme[16659]: Right alloca redzone: cb
Aug 19 18:20:13 magma-dev mme[16659]: ==16659==ABORTING
Aug 19 18:20:13 magma-dev systemd[1]: magma@mme.service: Main process exited, code=exited, status=1/FAILURE
Aug 19 18:20:14 magma-dev systemd[1]: magma@mme.service: Unit entered failed state.
Aug 19 18:20:14 magma-dev systemd[1]: magma@mme.service: Failed with result 'exit-code'.
Aug 19 18:20:14 magma-dev magmad[10349]: DEBUG:root:Unattended upgrade status is 0
Aug 19 18:20:16 magma-dev sctpd[16621]: I0819 18:20:16.023422 16687 sctp_connection.cpp:168] HandleClientSock sd = 22
Aug 19 18:20:16 magma-dev sctpd[16621]: I0819 18:20:16.023798 16687 sctp_connection.cpp:221] [sd:22] msg of len 66 on 36:1
Aug 19 18:20:16 magma-dev sctpd[16621]: I0819 18:20:16.025650 16687 sctpd_uplink_client.cpp:33] sctpul.sendul error
Aug 19 18:20:16 magma-dev sctpd[16621]: I0819 18:20:16.025689 16687 sctpd_uplink_client.cpp:34] grpc error (14): OS Error
Aug 19 18:20:18 magma-dev magmad[10349]: ERROR:root:GetServiceInfo Error for mme! [StatusCode.UNAVAILABLE] Connect Failed
Aug 19 18:20:19 magma-dev systemd[1]: magma@mme.service: Service hold-off time over, scheduling restart.
Aug 19 18:20:19 magma-dev systemd[1]: Stopped Magma OAI MME service.
Aug 19 18:20:19 magma-dev systemd[1]: Stopping Magma pipelined service...
Aug 19 18:20:19 magma-dev systemd[1]: Stopping Magma session manager service...
Aug 19 18:20:19 magma-dev pipelined[16637]: INFO:root:Stopping pipelined with reason SIGTERM...
Aug 19 18:20:19 magma-dev systemd[1]: Stopping Magma sctpd service...
Aug 19 18:20:19 magma-dev mobilityd[16596]: INFO:root:Stopping mobilityd with reason SIGTERM...
Aug 19 18:20:19 magma-dev systemd[1]: Stopping Magma mobilityd service...
Aug 19 18:20:19 magma-dev systemd[1]: Stopped Magma session manager service.
Aug 19 18:20:19 magma-dev systemd[1]: Started Magma session manager service.
Aug 19 18:20:19 magma-dev systemd[1]: Stopped Magma sctpd service.
Aug 19 18:20:19 magma-dev systemd[1]: Starting Magma sctpd service...
Aug 19 18:20:19 magma-dev sctpd[18721]: /bin/cp: cannot stat '/usr/local/share/sctpd/version': No such file or directory
Aug 19 18:20:19 magma-dev systemd[1]: Started Magma sctpd service.
Aug 19 18:20:19 magma-dev sessiond[18714]: [/home/vagrant/magma/orc8r/gateway/c/common/config/ServiceConfigLoader.cpp:30] Override file not found for service sessiond
Aug 19 18:20:19 magma-dev sessiond[18714]: I0819 18:20:19.981189 18714 magma_logging.h:28] Setting verbosity to 4
Aug 19 18:20:19 magma-dev sessiond[18714]: [/home/vagrant/

daemon.log
mme.log
syslog.log
@dcollin5
Copy link
Author

I have been stuck with this issue for a quite a while now and cant get past it. So help much appreciated.

@dcollin5
Copy link
Author

I just tried it with the latest master code and got the same problem:
git rev-parse HEAD
9a9665e

20 09:32:59 magma-dev sessiond[6267]: I0820 09:32:59.575745 6267 LocalSessionManagerHandler.cpp:77] Succeeded in updating session after no reporting
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.442436 6356 sctp_connection.cpp:172] HandleClientSock sd = 17
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.442474 6356 sctp_connection.cpp:225] [sd:17] msg of len 66 on 15:1
Aug 20 09:33:00 magma-dev mme[6321]: [INFO] Sending S6A-AUTHENTICATION_INFORMATION_REQUEST with IMSI: 001010123456780
Aug 20 09:33:00 magma-dev subscriberdb[5649]: INFO:root:Auth success: 001010123456780
Aug 20 09:33:00 magma-dev mme[6321]: [INFO] Received S6A-AUTHENTICATION_INFORMATION_ANSWER for IMSI: 001010123456780; Status: ; StatusCode: 2001
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.495740 6265 sctpd_downlink_impl.cpp:73] SctpdDownlinkImpl::SendDl starting
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.522171 6356 sctp_connection.cpp:172] HandleClientSock sd = 17
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.522240 6356 sctp_connection.cpp:225] [sd:17] msg of len 49 on 15:1
Aug 20 09:33:00 magma-dev mme[6321]: =================================================================
Aug 20 09:33:00 magma-dev mme[6321]: ==6321==ERROR: AddressSanitizer: heap-use-after-free on address 0x61100013d848 at pc 0x562d1432d34d bp 0x7f9d8be2cb60 sp 0x7f9d8be2cb58
Aug 20 09:33:00 magma-dev mme[6321]: READ of size 8 at 0x61100013d848 thread T16
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.534740 6265 sctpd_downlink_impl.cpp:73] SctpdDownlinkImpl::SendDl starting
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.542721 6265 sctpd_downlink_impl.cpp:73] SctpdDownlinkImpl::SendDl starting
Aug 20 09:33:00 magma-dev mme[6321]: #0 0x562d1432d34c in EmmCommonProcedureInitiated /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:141
Aug 20 09:33:00 magma-dev mme[6321]: #1 0x562d142dc004 in emm_fsm_process /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_fsm.c:246
Aug 20 09:33:00 magma-dev mme[6321]: #2 0x562d1433a174 in emm_reg_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_reg.c:87
Aug 20 09:33:00 magma-dev mme[6321]: #3 0x562d142dd772 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:89
Aug 20 09:33:00 magma-dev mme[6321]: #4 0x562d142aae71 in emm_proc_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:761
Aug 20 09:33:00 magma-dev mme[6321]: #5 0x562d143392e4 in emm_recv_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:1002
Aug 20 09:33:00 magma-dev mme[6321]: #6 0x562d14321788 in _emm_as_recv /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:413
Aug 20 09:33:00 magma-dev mme[6321]: #7 0x562d14323b75 in _emm_as_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:678
Aug 20 09:33:00 magma-dev mme[6321]: #8 0x562d14320674 in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:180
Aug 20 09:33:00 magma-dev mme[6321]: #9 0x562d142dd8ae in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:105
Aug 20 09:33:00 magma-dev mme[6321]: #10 0x562d14283f7e in nas_proc_ul_transfer_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:326
Aug 20 09:33:00 magma-dev mme[6321]: #11 0x562d140752f4 in handle_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:97
Aug 20 09:33:00 magma-dev mme[6321]: #12 0x7f9d9e5587bd in zloop_start (/usr/lib/x86_64-linux-gnu/libczmq.so.4+0x287bd)
Aug 20 09:33:00 magma-dev mme[6321]: #13 0x562d14076daa in mme_app_thread /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:441
Aug 20 09:33:00 magma-dev mme[6321]: #14 0x7f9da0b4f4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
Aug 20 09:33:00 magma-dev mme[6321]: #15 0x7f9d9cec5d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
Aug 20 09:33:00 magma-dev mme[6321]: 0x61100013d848 is located 8 bytes inside of 216-byte region [0x61100013d840,0x61100013d918)
Aug 20 09:33:00 magma-dev mme[6321]: freed by thread T16 here:
Aug 20 09:33:00 magma-dev mme[6321]: #0 0x7f9da1032a10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
Aug 20 09:33:00 magma-dev mme[6321]: #1 0x562d13f98bbd in free_wrapper /home/vagrant/magma/lte/gateway/c/oai/common/dynamic_memory_check.c:47
Aug 20 09:33:00 magma-dev mme[6321]: #2 0x562d14300644 in nas_delete_common_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_procedures.c:358
Aug 20 09:33:00 magma-dev mme[6321]: #3 0x562d1432d25e in EmmCommonProcedureInitiated /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:137
Aug 20 09:33:00 magma-dev mme[6321]: #4 0x562d142dc004 in emm_fsm_process /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_fsm.c:246
Aug 20 09:33:00 magma-dev mme[6321]: #5 0x562d1433a174 in emm_reg_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_reg.c:87
Aug 20 09:33:00 magma-dev mme[6321]: #6 0x562d142dd772 in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:89
Aug 20 09:33:00 magma-dev mme[6321]: #7 0x562d142aae71 in emm_proc_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:761
Aug 20 09:33:00 magma-dev mme[6321]: #8 0x562d143392e4 in emm_recv_authentication_failure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:1002
Aug 20 09:33:00 magma-dev mme[6321]: #9 0x562d14321788 in _emm_as_recv /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:413
Aug 20 09:33:00 magma-dev mme[6321]: #10 0x562d14323b75 in _emm_as_data_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:678
Aug 20 09:33:00 magma-dev mme[6321]: #11 0x562d14320674 in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:180
Aug 20 09:33:00 magma-dev mme[6321]: #12 0x562d142dd8ae in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:105
Aug 20 09:33:00 magma-dev mme[6321]: #13 0x562d14283f7e in nas_proc_ul_transfer_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:326
Aug 20 09:33:00 magma-dev mme[6321]: #14 0x562d140752f4 in handle_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:97
Aug 20 09:33:00 magma-dev mme[6321]: #15 0x7f9d9e5587bd in zloop_start (/usr/lib/x86_64-linux-gnu/libczmq.so.4+0x287bd)
Aug 20 09:33:00 magma-dev mme[6321]: previously allocated by thread T16 here:
Aug 20 09:33:00 magma-dev mme[6321]: #0 0x7f9da1032ed0 in calloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1ed0)
Aug 20 09:33:00 magma-dev mme[6321]: #1 0x562d14303634 in nas_new_authentication_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_procedures.c:713
Aug 20 09:33:00 magma-dev mme[6321]: #2 0x562d142a3d38 in emm_proc_authentication /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Authentication.c:258
Aug 20 09:33:00 magma-dev mme[6321]: #3 0x562d14295f6a in _emm_start_attach_proc_authentication /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:1179
Aug 20 09:33:00 magma-dev mme[6321]: #4 0x562d14295642 in _emm_attach_run_procedure /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:1116
Aug 20 09:33:00 magma-dev mme[6321]: #5 0x562d14292546 in emm_proc_attach_request /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/Attach.c:578
Aug 20 09:33:00 magma-dev mme[6321]: #6 0x562d14334deb in emm_recv_attach_request /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_recv.c:384
Aug 20 09:33:00 magma-dev mme[6321]: #7 0x562d143249ff in _emm_as_establish_req /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:802
Aug 20 09:33:00 magma-dev mme[6321]: #8 0x562d14320703 in emm_as_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_as.c:185
Aug 20 09:33:00 magma-dev mme[6321]: #9 0x562d142dd8ae in emm_sap_send /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/emm_sap.c:105
Aug 20 09:33:00 magma-dev mme[6321]: #10 0x562d1428379c in nas_proc_establish_ind /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/nas_proc.c:185
Aug 20 09:33:00 magma-dev mme[6321]: #11 0x562d1407d9bd in mme_app_handle_initial_ue_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_bearer.c:723
Aug 20 09:33:00 magma-dev mme[6321]: #12 0x562d140758f9 in handle_message /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:176
Aug 20 09:33:00 magma-dev mme[6321]: #13 0x7f9d9e5587bd in zloop_start (/usr/lib/x86_64-linux-gnu/libczmq.so.4+0x287bd)
Aug 20 09:33:00 magma-dev mme[6321]: Thread T16 created by T0 here:
Aug 20 09:33:00 magma-dev mme[6321]: #0 0x7f9da0fa1f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
Aug 20 09:33:00 magma-dev mme[6321]: #1 0x562d14722e57 in itti_create_task /home/vagrant/magma/lte/gateway/c/oai/lib/itti/intertask_interface.c:303
Aug 20 09:33:00 magma-dev mme[6321]: #2 0x562d14076fa3 in mme_app_init /home/vagrant/magma/lte/gateway/c/oai/tasks/mme_app/mme_app_main.c:461
Aug 20 09:33:00 magma-dev mme[6321]: #3 0x562d13f92be9 in main /home/vagrant/magma/lte/gateway/c/oai/oai_mme/oai_mme.c:119
Aug 20 09:33:00 magma-dev mme[6321]: #4 0x7f9d9cdfd2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
Aug 20 09:33:00 magma-dev mme[6321]: SUMMARY: AddressSanitizer: heap-use-after-free /home/vagrant/magma/lte/gateway/c/oai/tasks/nas/emm/sap/EmmCommonProcedureInitiated.c:141 in EmmCommonProcedureInitiated
Aug 20 09:33:00 magma-dev mme[6321]: Shadow bytes around the buggy address:
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fab0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fac0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fad0: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fae0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001faf0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: =>0x0c228001fb00: fa fa fa fa fa fa fa fa fd[fd]fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fb10: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fb20: fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fb30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fb40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: 0x0c228001fb50: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
Aug 20 09:33:00 magma-dev mme[6321]: Shadow byte legend (one shadow byte represents 8 application bytes):
Aug 20 09:33:00 magma-dev mme[6321]: Addressable: 00
Aug 20 09:33:00 magma-dev mme[6321]: Partially addressable: 01 02 03 04 05 06 07
Aug 20 09:33:00 magma-dev mme[6321]: Heap left redzone: fa
Aug 20 09:33:00 magma-dev mme[6321]: Heap right redzone: fb
Aug 20 09:33:00 magma-dev mme[6321]: Freed heap region: fd
Aug 20 09:33:00 magma-dev mme[6321]: Stack left redzone: f1
Aug 20 09:33:00 magma-dev mme[6321]: Stack mid redzone: f2
Aug 20 09:33:00 magma-dev mme[6321]: Stack right redzone: f3
Aug 20 09:33:00 magma-dev mme[6321]: Stack partial redzone: f4
Aug 20 09:33:00 magma-dev mme[6321]: Stack after return: f5
Aug 20 09:33:00 magma-dev mme[6321]: Stack use after scope: f8
Aug 20 09:33:00 magma-dev mme[6321]: Global redzone: f9
Aug 20 09:33:00 magma-dev mme[6321]: Global init order: f6
Aug 20 09:33:00 magma-dev mme[6321]: Poisoned by user: f7
Aug 20 09:33:00 magma-dev mme[6321]: Container overflow: fc
Aug 20 09:33:00 magma-dev mme[6321]: Array cookie: ac
Aug 20 09:33:00 magma-dev mme[6321]: Intra object redzone: bb
Aug 20 09:33:00 magma-dev mme[6321]: ASan internal: fe
Aug 20 09:33:00 magma-dev mme[6321]: Left alloca redzone: ca
Aug 20 09:33:00 magma-dev mme[6321]: Right alloca redzone: cb
Aug 20 09:33:00 magma-dev mme[6321]: ==6321==ABORTING
Aug 20 09:33:00 magma-dev systemd[1]: magma@mme.service: Main process exited, code=exited, status=1/FAILURE
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.742297 6356 sctp_connection.cpp:172] HandleClientSock sd = 17
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.742332 6356 sctp_connection.cpp:225] [sd:17] msg of len 19 on 15:1
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.742867 6356 sctpd_uplink_client.cpp:37] sctpul.sendul error
Aug 20 09:33:00 magma-dev sctpd[6258]: I0820 09:33:00.742879 6356 sctpd_uplink_client.cpp:38] grpc error (14): OS Error
Aug 20 09:33:01 magma-dev systemd[1]: magma@mme.service: Unit entered failed state.
Aug 20 09:33:01 magma-dev systemd[1]: magma@mme.service: Failed with result 'exit-code'.

@dcollin5
Copy link
Author

For anyone else coming into a similar issue I was able to rectify the issue with the latest code.
Note: The original error is still valid for magma v1.1.0 however.

  1. I got the latest code.
    git clone https://github.com/magma/magma.git

  2. repeat the rest of the steps above to support network interfaces.

  3. in the GUI, add the UE.
    "root":{7 items
    "active_apns":[1 item
    0:
    "srslte"
    ]
    "config":{1 item
    "lte":{5 items
    "auth_algo":"MILENAGE"
    "auth_key":"ABEiM0RVZneImaq7zN3u/w=="
    "auth_opc":"Y7+lDuZSM2X/FMH0X4hzfQ=="
    "state":"ACTIVE"
    "sub_profile":"default"
    }
    }
    "id":"IMSI001010123456780"
    "lte":{5 items
    "auth_algo":"MILENAGE"
    "auth_key":"ABEiM0RVZneImaq7zN3u/w=="
    "auth_opc":"Y7+lDuZSM2X/FMH0X4hzfQ=="
    "state":"ACTIVE"
    "sub_profile":"default"
    }
    "monitoring":{}0 items
    "name":"33638060010"
    "state":{1 item
    "directory":{1 item
    "location_history":[1 item
    0:
    "663425c5-dc93-4ab0-8acf-ae6cf03478fe"
    ]
    }
    }
    }
    IMPORTANT: Make sure to add the OPC parameter, otherwise you get: "11:27:20.672516 [NAS ] [W] Network authentication failure"
    IMPORTANT: Make sure to add an APN, otherwise you will get the following message on the UE:
    "11:35:52.312242 [NAS ] [W] Received Attach Reject. Cause= 13"

  4. Add Network with the following parameters to support srslte.
    Network

Network ID: test
Network Name: Test Network
Network Type: lte
Add Description: Test network

EPC

Policy Enfourcement Enabled: Disabled
LTE Auth AMF: gAA=
MCC: 001
MNC: 01
TAC: 1

RAN

bandwidth:20
Band Type: TDD
EARFCNDL: 44590. [this URL proved useful when selecting EARFCNDL where band is 42]
Special Subframe Pattern: 7
Subfrane Assignment: 2

  1. start the UE and eNB.

@ssanadhya
Copy link
Collaborator

ssanadhya commented Aug 20, 2020 •
edited
Loading

@dcollin5 , thanks for the detailed report on this issue.

Was the issue resolved after adding the OPC? That is, does the "heap-use-after-free" error recur if you remove the OPC?

Which GUI are you referring to for adding UE?

@ssanadhya ssanadhya self-assigned this Aug 20, 2020
@ssanadhya ssanadhya added the component: agw Access gateway-related issue label Aug 20, 2020
@ssanadhya ssanadhya changed the title ERROR: AddressSanitizer: heap-use-after-free on address [MME] ERROR: AddressSanitizer: heap-use-after-free on address Aug 20, 2020
@ssanadhya ssanadhya mentioned this issue Aug 20, 2020
Merged
@dcollin5
Copy link
Author

  1. I mean the NMS UI GUI to add the subscriber.
  2. Without the OPc code i get the following error from the UE: - Warning: Network authentication failure
    iristest@ue:~$ sudo srsue
    Reading configuration file /home/iristest/.config/srslte/ue.conf...

Built in Release mode using commit f02bfe2cf on branch master.

Opening 1 channels in RF device=default with args=default
[INFO] [UHD] linux; GNU C++ version 7.5.0; Boost_106501; UHD_3.14.0.HEAD-0-g6875d061
[INFO] [LOGGING] Fastpath logging disabled at runtime.
Opening USRP channels=1, args: type=b200,master_clock_rate=23.04e6
[INFO] [B200] Detected Device: B210
[INFO] [B200] Operating over USB 3.
[INFO] [B200] Initialize CODEC control...
[INFO] [B200] Initialize Radio control...
[INFO] [B200] Performing register loopback test...
[INFO] [B200] Register loopback test passed
[INFO] [B200] Performing register loopback test...
[INFO] [B200] Register loopback test passed
[INFO] [B200] Asking for clock rate 23.040000 MHz...
[INFO] [B200] Actually got clock rate 23.040000 MHz.
Waiting PHY to initialize ... done!
Attaching UE...
.
Found Cell: Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.5 KHz
Found PLMN: Id=00101, TAC=1
Random Access Transmission: seq=24, ra-rnti=0x2
Random Access Complete. c-rnti=0x46, ta=1
RRC Connected
Warning: Network authentication failure
Received RRC Connection Release (releaseCause: other)
RRC IDLE
^CStopping ..
.
Found Cell: Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.3 KHz
Found PLMN: Id=00101, TAC=1
Random Access Transmission: seq=48, ra-rnti=0x2
Random Access Complete. c-rnti=0x47, ta=1
RRC Connected
^Z
[1]+ Stopped sudo srsue
iristest@ue:~$

UE Without OPC

11:27:20.672484 [NAS ] [I] DL SRB1 PDU
0000: 07 52 00 3e 6a a0 ed ab dc ee ea 87 7c bb 0e ac
0010: f5 8b 6f 10 b4 c7 dd 63 8d 01 80 00 b0 1f ea bf
11:27:20.672489 [NAS ] [I] DL SRB1 Decrypted PDU
0000: 07 52 00 3e 6a a0 ed ab dc ee ea 87 7c bb 0e ac
0010: f5 8b 6f 10 b4 c7 dd 63 8d 01 80 00 b0 1f ea bf
11:27:20.672493 [NAS ] [I] Received Authentication Request
11:27:20.672495 [NAS ] [I] MCC=61441, MNC=65281
11:27:20.672496 [NAS ] [D] Authentication request RAND
0000: 3e 6a a0 ed ab dc ee ea 87 7c bb 0e ac f5 8b 6f
11:27:20.672499 [NAS ] [D] Authentication request AUTN
0000: b4 c7 dd 63 8d 01 80 00 b0 1f ea bf ef 50 0e bd
11:27:20.672516 [NAS ] [W] Network authentication failure
11:27:20.672519 [PHY1] [I] [ 9939] PUCCH: cc=0, tti_tx=9943, rnti=0x46, f=1a, n_pucch=16, ack=1
11:27:20.672555 [PHY1] [D] [ 9939] SNR=39.1 dB, RSRP=-58.1 dBm sync=in-sync from channel estimator
11:27:20.672694 [NAS ] [I] Sending authentication failure.
11:27:20.672717 [RRC ] [D] SRB1 - Tx ulInformationTransfer (6 B)
0000: 48 00 60 eb 82 80
11:27:20.672726 [RRC ] [D] Content:

  1. I added back the opc code and subscriber says the following:
    (python) vagrant@magma-dev:~$ subscriber_cli.py get IMSI001010123456780
    sid {
    id: "001010123456780"
    }
    lte {
    state: ACTIVE
    auth_key: "\000\021"3DUfw\210\231\252\273\314\335\356\377"
    auth_opc: "c\277\245\016\346R3e\377\024\301\364_\210s}"
    }
    network_id {
    id: "test"
    }
    state {
    lte_auth_next_seq: 51
    }
    sub_profile: "default"
    non_3gpp {
    apn_config {
    service_selection: "srslte"
    qos_profile {
    class_id: 9
    priority_level: 15
    }
    ambr {
    max_bandwidth_ul: 1000000
    max_bandwidth_dl: 1000000
    }
    }
    }

(python) vagrant@magma-dev:~$

  1. I removed the APN, and i get the following error Received Attach Reject. Cause= 13

(python) vagrant@magma-dev:~$ subscriber_cli.py get IMSI001010123456780
sid {
id: "001010123456780"
}
lte {
state: ACTIVE
auth_key: "\000\021"3DUfw\210\231\252\273\314\335\356\377"
auth_opc: "c\277\245\016\346R3e\377\024\301\364_\210s}"
}
network_id {
id: "test"
}
state {
lte_auth_next_seq: 51
}
sub_profile: "default"
non_3gpp {
}

So its not the APN either.

  1. The heap-use-after-free exception could be because of the RAN configuration. srsLTE uses dl_earfcn = 3400. So I added the following info.
    bandwidth:20
    Band Type: TDD
    EARFCNDL: 44590. [this URL proved useful when selecting EARFCNDL where band is 42]
    Special Subframe Pattern: 7
    Subfrane Assignment: 2

Ill compile everything again and see if i can reproduce it, and what fixed it.

@ssanadhya
Copy link
Collaborator

ssanadhya commented Aug 21, 2020 •
edited
Loading

Thanks @dcollin5 ! I was able to reproduce the issue with the test case in #2415 . It is fixed in the latest master.

For the OPC, note that subscriberdb needs both LTE auth_key and OP for a subscriber to compute the OPC internally. I see that while using the subscirber_cli you only added LTE auth_key, hence the auth failure. If you don't have the OP value, then you need to add the OPC.

Please close the issue once you confirm that it is resolved in your setup.

@ssanadhya
Copy link
Collaborator

@dcollin5 closing this issue for now. Please re-open if you observe it in your setup.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@ssanadhya ssanadhya

Labels
component: agw Access gateway-related issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ssanadhya @dcollin5