Upgrade loggers in srsepc (#2167)

* Started logger replacement in epc main.

* Replaced loggers in nas and s1ap.

* Replace loggers in nas statics.

* Replaced loggers in s1ap ctx mngmt.

* Replace loggers in s1ap erab mngmt.

* Replaced loggers in s1ap mngmt proc.

* Replaced loggers in s1ap nas transport.

* Replaced loggers in s1ap paging.

* Replaced loggers in mme.

* Replaced loggers in mme gtpc.

* Started removing logger injection in init functions and cleaned up argument passing to nas statics.

* Remove logger injection from mme and s1ap.

* Replaced loggers in the hss class.

* Replaced loggers in gtpc.

* Replaced loggers in GTPU and SPGW.

* Replaced loggers in MBMS.
master
faluco 4 years ago committed by GitHub
parent 5981469f9f
commit c18e35bc93
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

@ -23,6 +23,7 @@
#include "srslte/common/log.h" #include "srslte/common/log.h"
#include "srslte/common/log_filter.h" #include "srslte/common/log_filter.h"
#include "srslte/interfaces/epc_interfaces.h" #include "srslte/interfaces/epc_interfaces.h"
#include "srslte/srslog/srslog.h"
#include <cstddef> #include <cstddef>
#include <fstream> #include <fstream>
#include <map> #include <map>
@ -68,7 +69,7 @@ class hss : public hss_interface_nas
public: public:
static hss* get_instance(void); static hss* get_instance(void);
static void cleanup(void); static void cleanup(void);
int init(hss_args_t* hss_args, srslte::log_filter* hss_log); int init(hss_args_t* hss_args);
void stop(void); void stop(void);
virtual bool gen_auth_info_answer(uint64_t imsi, uint8_t* k_asme, uint8_t* autn, uint8_t* rand, uint8_t* xres); virtual bool gen_auth_info_answer(uint64_t imsi, uint8_t* k_asme, uint8_t* autn, uint8_t* rand, uint8_t* xres);
@ -111,7 +112,7 @@ private:
std::string db_file; std::string db_file;
/*Logs*/ /*Logs*/
srslte::log_filter* m_hss_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("HSS");
uint16_t mcc; uint16_t mcc;
uint16_t mnc; uint16_t mnc;

@ -24,6 +24,7 @@
#include "srslte/common/log_filter.h" #include "srslte/common/log_filter.h"
#include "srslte/common/logmap.h" #include "srslte/common/logmap.h"
#include "srslte/common/threads.h" #include "srslte/common/threads.h"
#include "srslte/srslog/srslog.h"
#include "srslte/srslte.h" #include "srslte/srslte.h"
#include <cstddef> #include <cstddef>
@ -73,6 +74,7 @@ private:
bool m_running; bool m_running;
srslte::byte_buffer_pool* m_pool; srslte::byte_buffer_pool* m_pool;
srslte::log_ref m_mbms_gw_log; srslte::log_ref m_mbms_gw_log;
srslog::basic_logger& m_logger = srslog::fetch_basic_logger("MBMS");
bool m_sgi_mb_up; bool m_sgi_mb_up;
int m_sgi_mb_if; int m_sgi_mb_if;

@ -46,10 +46,7 @@ public:
static mme* get_instance(void); static mme* get_instance(void);
static void cleanup(void); static void cleanup(void);
int init(mme_args_t* args, int init(mme_args_t* args);
srslte::log_filter* nas_log,
srslte::log_filter* s1ap_log,
srslte::log_filter* mme_gtpc_log);
void stop(); void stop();
int get_s1_mme(); int get_s1_mme();
void run_thread(); void run_thread();
@ -77,9 +74,7 @@ private:
void handle_timer_expire(int timer_fd); void handle_timer_expire(int timer_fd);
// Logs // Logs
srslte::log_filter* m_nas_log; srslog::basic_logger& m_s1ap_logger = srslog::fetch_basic_logger("S1AP");
srslte::log_filter* m_s1ap_log;
srslte::log_filter* m_mme_gtpc_log;
}; };
} // namespace srsepc } // namespace srsepc

@ -37,7 +37,7 @@ public:
static mme_gtpc* get_instance(); static mme_gtpc* get_instance();
bool init(srslte::log_filter* mme_gtpc_log); bool init();
bool send_s11_pdu(const srslte::gtpc_pdu& pdu); bool send_s11_pdu(const srslte::gtpc_pdu& pdu);
void handle_s11_pdu(srslte::byte_buffer_t* msg); void handle_s11_pdu(srslte::byte_buffer_t* msg);
@ -56,8 +56,8 @@ public:
private: private:
mme_gtpc() = default; mme_gtpc() = default;
srslte::log_filter* m_mme_gtpc_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("MME GTPC");
s1ap* m_s1ap; s1ap* m_s1ap;
uint32_t m_next_ctrl_teid; uint32_t m_next_ctrl_teid;
std::map<uint32_t, uint64_t> m_mme_ctr_teid_to_imsi; std::map<uint32_t, uint64_t> m_mme_ctr_teid_to_imsi;

@ -18,6 +18,7 @@
#include "srslte/common/buffer_pool.h" #include "srslte/common/buffer_pool.h"
#include "srslte/common/security.h" #include "srslte/common/security.h"
#include "srslte/interfaces/epc_interfaces.h" #include "srslte/interfaces/epc_interfaces.h"
#include "srslte/srslog/srslog.h"
#include <netinet/sctp.h> #include <netinet/sctp.h>
namespace srsepc { namespace srsepc {
@ -141,7 +142,7 @@ typedef struct {
class nas class nas
{ {
public: public:
nas(const nas_init_t& args, const nas_if_t& itf, srslte::log* nas_log); nas(const nas_init_t& args, const nas_if_t& itf);
void reset(); void reset();
/*********************** /***********************
@ -152,16 +153,14 @@ public:
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
static bool handle_imsi_attach_request_unknown_ue(uint32_t enb_ue_s1ap_id, static bool handle_imsi_attach_request_unknown_ue(uint32_t enb_ue_s1ap_id,
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
const LIBLTE_MME_ATTACH_REQUEST_MSG_STRUCT& attach_req, const LIBLTE_MME_ATTACH_REQUEST_MSG_STRUCT& attach_req,
const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req, const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
static bool handle_imsi_attach_request_known_ue(nas* nas_ctx, static bool handle_imsi_attach_request_known_ue(nas* nas_ctx,
uint32_t enb_ue_s1ap_id, uint32_t enb_ue_s1ap_id,
@ -170,16 +169,14 @@ public:
const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req, const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
static bool handle_guti_attach_request_unknown_ue(uint32_t enb_ue_s1ap_id, static bool handle_guti_attach_request_unknown_ue(uint32_t enb_ue_s1ap_id,
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
const LIBLTE_MME_ATTACH_REQUEST_MSG_STRUCT& attach_req, const LIBLTE_MME_ATTACH_REQUEST_MSG_STRUCT& attach_req,
const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req, const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
static bool handle_guti_attach_request_known_ue(nas* nas_ctx, static bool handle_guti_attach_request_known_ue(nas* nas_ctx,
uint32_t enb_ue_s1ap_id, uint32_t enb_ue_s1ap_id,
@ -188,8 +185,7 @@ public:
const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req, const LIBLTE_MME_PDN_CONNECTIVITY_REQUEST_MSG_STRUCT& pdn_con_req,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
// Service request messages // Service request messages
static bool handle_service_request(uint32_t m_tmsi, static bool handle_service_request(uint32_t m_tmsi,
@ -197,8 +193,7 @@ public:
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
// Dettach request messages // Dettach request messages
static bool handle_detach_request(uint32_t m_tmsi, static bool handle_detach_request(uint32_t m_tmsi,
@ -206,8 +201,7 @@ public:
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
// Tracking area update request messages // Tracking area update request messages
static bool handle_tracking_area_update_request(uint32_t m_tmsi, static bool handle_tracking_area_update_request(uint32_t m_tmsi,
@ -215,8 +209,7 @@ public:
struct sctp_sndrcvinfo* enb_sri, struct sctp_sndrcvinfo* enb_sri,
srslte::byte_buffer_t* nas_rx, srslte::byte_buffer_t* nas_rx,
const nas_init_t& args, const nas_init_t& args,
const nas_if_t& itf, const nas_if_t& itf);
srslte::log* nas_log);
/* Uplink NAS messages handling */ /* Uplink NAS messages handling */
bool handle_attach_request(srslte::byte_buffer_t* nas_rx); bool handle_attach_request(srslte::byte_buffer_t* nas_rx);
@ -258,12 +251,12 @@ public:
sec_ctx_t m_sec_ctx = {}; sec_ctx_t m_sec_ctx = {};
private: private:
srslte::byte_buffer_pool* m_pool = nullptr; srslte::byte_buffer_pool* m_pool = nullptr;
srslte::log* m_nas_log = nullptr; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("NAS");
gtpc_interface_nas* m_gtpc = nullptr; gtpc_interface_nas* m_gtpc = nullptr;
s1ap_interface_nas* m_s1ap = nullptr; s1ap_interface_nas* m_s1ap = nullptr;
hss_interface_nas* m_hss = nullptr; hss_interface_nas* m_hss = nullptr;
mme_interface_nas* m_mme = nullptr; mme_interface_nas* m_mme = nullptr;
uint16_t m_mcc = 0; uint16_t m_mcc = 0;
uint16_t m_mnc = 0; uint16_t m_mnc = 0;

@ -27,6 +27,7 @@
#include "srslte/common/log.h" #include "srslte/common/log.h"
#include "srslte/common/s1ap_pcap.h" #include "srslte/common/s1ap_pcap.h"
#include "srslte/interfaces/epc_interfaces.h" #include "srslte/interfaces/epc_interfaces.h"
#include "srslte/srslog/srslog.h"
#include <arpa/inet.h> #include <arpa/inet.h>
#include <map> #include <map>
#include <netinet/sctp.h> #include <netinet/sctp.h>
@ -49,7 +50,7 @@ public:
static void cleanup(); static void cleanup();
int enb_listen(); int enb_listen();
int init(s1ap_args_t s1ap_args, srslte::log_filter* s1ap_log, srslte::log_filter* nas_log); int init(s1ap_args_t s1ap_args);
void stop(); void stop();
int get_s1_mme(); int get_s1_mme();
@ -86,9 +87,8 @@ public:
uint32_t allocate_m_tmsi(uint64_t imsi); uint32_t allocate_m_tmsi(uint64_t imsi);
virtual uint64_t find_imsi_from_m_tmsi(uint32_t m_tmsi); virtual uint64_t find_imsi_from_m_tmsi(uint32_t m_tmsi);
s1ap_args_t m_s1ap_args; s1ap_args_t m_s1ap_args;
srslte::log_filter* m_s1ap_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
srslte::log_filter* m_nas_log;
s1ap_mngmt_proc* m_s1ap_mngmt_proc; s1ap_mngmt_proc* m_s1ap_mngmt_proc;
s1ap_nas_transport* m_s1ap_nas_transport; s1ap_nas_transport* m_s1ap_nas_transport;

@ -43,8 +43,8 @@ private:
s1ap_ctx_mngmt_proc(); s1ap_ctx_mngmt_proc();
virtual ~s1ap_ctx_mngmt_proc(); virtual ~s1ap_ctx_mngmt_proc();
s1ap* m_s1ap; s1ap* m_s1ap;
srslte::log_filter* m_s1ap_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
s1ap_args_t m_s1ap_args; s1ap_args_t m_s1ap_args;

@ -48,8 +48,8 @@ private:
s1ap_erab_mngmt_proc(); s1ap_erab_mngmt_proc();
virtual ~s1ap_erab_mngmt_proc(); virtual ~s1ap_erab_mngmt_proc();
s1ap* m_s1ap = nullptr; s1ap* m_s1ap = nullptr;
srslte::log_filter* m_s1ap_log = nullptr; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
s1ap_args_t m_s1ap_args; s1ap_args_t m_s1ap_args;

@ -16,6 +16,7 @@
#include "srslte/asn1/s1ap.h" #include "srslte/asn1/s1ap.h"
#include "srslte/common/common.h" #include "srslte/common/common.h"
#include "srslte/common/log_filter.h" #include "srslte/common/log_filter.h"
#include "srslte/srslog/srslog.h"
namespace srsepc { namespace srsepc {
@ -41,8 +42,8 @@ private:
s1ap_mngmt_proc(); s1ap_mngmt_proc();
virtual ~s1ap_mngmt_proc(); virtual ~s1ap_mngmt_proc();
s1ap* m_s1ap; s1ap* m_s1ap;
srslte::log_filter* m_s1ap_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
int m_s1mme; int m_s1mme;
s1ap_args_t m_s1ap_args; s1ap_args_t m_s1ap_args;

@ -40,7 +40,7 @@ private:
s1ap_nas_transport(); s1ap_nas_transport();
virtual ~s1ap_nas_transport(); virtual ~s1ap_nas_transport();
srslte::log* m_s1ap_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
srslte::byte_buffer_pool* m_pool; srslte::byte_buffer_pool* m_pool;
s1ap* m_s1ap; s1ap* m_s1ap;

@ -16,6 +16,7 @@
#include "srslte/common/buffer_pool.h" #include "srslte/common/buffer_pool.h"
#include "srslte/common/common.h" #include "srslte/common/common.h"
#include "srslte/common/log_filter.h" #include "srslte/common/log_filter.h"
#include "srslte/srslog/srslog.h"
namespace srsepc { namespace srsepc {
@ -36,9 +37,9 @@ public:
bool send_paging(uint64_t imsi, uint16_t erab_to_setup); bool send_paging(uint64_t imsi, uint16_t erab_to_setup);
private: private:
mme* m_mme; mme* m_mme;
s1ap* m_s1ap; s1ap* m_s1ap;
srslte::log_filter* m_s1ap_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("S1AP");
s1ap_args_t m_s1ap_args; s1ap_args_t m_s1ap_args;
srslte::byte_buffer_pool* m_pool; srslte::byte_buffer_pool* m_pool;

@ -15,6 +15,7 @@
#include "srsepc/hdr/spgw/spgw.h" #include "srsepc/hdr/spgw/spgw.h"
#include "srslte/asn1/gtpc.h" #include "srslte/asn1/gtpc.h"
#include "srslte/interfaces/epc_interfaces.h" #include "srslte/interfaces/epc_interfaces.h"
#include "srslte/srslog/srslog.h"
#include <set> #include <set>
#include <sys/socket.h> #include <sys/socket.h>
#include <sys/un.h> #include <sys/un.h>
@ -26,11 +27,7 @@ class spgw::gtpc : public gtpc_interface_gtpu
public: public:
gtpc(); gtpc();
virtual ~gtpc(); virtual ~gtpc();
int init(spgw_args_t* args, int init(spgw_args_t* args, spgw* spgw, gtpu_interface_gtpc* gtpu, const std::map<std::string, uint64_t>& ip_to_imsi);
spgw* spgw,
gtpu_interface_gtpc* gtpu,
srslte::log_filter* gtpc_log,
const std::map<std::string, uint64_t>& ip_to_imsi);
void stop(); void stop();
int init_s11(spgw_args_t* args); int init_s11(spgw_args_t* args);
@ -85,7 +82,7 @@ public:
std::set<uint32_t> m_ue_ip_addr_pool; std::set<uint32_t> m_ue_ip_addr_pool;
std::map<uint64_t, struct in_addr> m_imsi_to_ip; std::map<uint64_t, struct in_addr> m_imsi_to_ip;
srslte::log_filter* m_gtpc_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("SPGW GTPC");
srslte::byte_buffer_pool* m_pool; srslte::byte_buffer_pool* m_pool;
}; };

@ -18,6 +18,7 @@
#include "srslte/common/buffer_pool.h" #include "srslte/common/buffer_pool.h"
#include "srslte/common/logmap.h" #include "srslte/common/logmap.h"
#include "srslte/interfaces/epc_interfaces.h" #include "srslte/interfaces/epc_interfaces.h"
#include "srslte/srslog/srslog.h"
#include <cstddef> #include <cstddef>
#include <queue> #include <queue>
@ -63,6 +64,8 @@ public:
// UE is attached without an active user-plane // UE is attached without an active user-plane
// for downlink notifications. // for downlink notifications.
srslog::basic_logger& m_logger = srslog::fetch_basic_logger("GTPU");
//:TODO: remove this once srslte common code loggers have been upgraded.
srslte::log_ref m_gtpu_log; srslte::log_ref m_gtpu_log;
private: private:

@ -24,6 +24,7 @@
#include "srslte/common/log_filter.h" #include "srslte/common/log_filter.h"
#include "srslte/common/logmap.h" #include "srslte/common/logmap.h"
#include "srslte/common/threads.h" #include "srslte/common/threads.h"
#include "srslte/srslog/srslog.h"
#include <cstddef> #include <cstddef>
#include <queue> #include <queue>
@ -60,11 +61,7 @@ class spgw : public srslte::thread
public: public:
static spgw* get_instance(void); static spgw* get_instance(void);
static void cleanup(void); static void cleanup(void);
int init(spgw_args_t* args, int init(spgw_args_t* args, srslte::log_ref gtpu_log, const std::map<std::string, uint64_t>& ip_to_imsi);
srslte::log_ref gtpu_log,
srslte::log_filter* gtpc_log,
srslte::log_filter* spgw_log,
const std::map<std::string, uint64_t>& ip_to_imsi);
void stop(); void stop();
void run_thread(); void run_thread();
@ -85,7 +82,7 @@ private:
gtpu* m_gtpu; gtpu* m_gtpu;
// Logs // Logs
srslte::log_filter* m_spgw_log; srslog::basic_logger& m_logger = srslog::fetch_basic_logger("SPGW");
}; };
} // namespace srsepc } // namespace srsepc

@ -54,11 +54,9 @@ void hss::cleanup()
pthread_mutex_unlock(&hss_instance_mutex); pthread_mutex_unlock(&hss_instance_mutex);
} }
int hss::init(hss_args_t* hss_args, srslte::log_filter* hss_log) int hss::init(hss_args_t* hss_args)
{ {
srand(time(NULL)); srand(time(NULL));
/*Init loggers*/
m_hss_log = hss_log;
/*Read user information from DB*/ /*Read user information from DB*/
if (read_db_file(hss_args->db_file) == false) { if (read_db_file(hss_args->db_file) == false) {
@ -71,7 +69,7 @@ int hss::init(hss_args_t* hss_args, srslte::log_filter* hss_log)
db_file = hss_args->db_file; db_file = hss_args->db_file;
m_hss_log->info("HSS Initialized. DB file %s, MCC: %d, MNC: %d\n", hss_args->db_file.c_str(), mcc, mnc); m_logger.info("HSS Initialized. DB file %s, MCC: %d, MNC: %d", hss_args->db_file.c_str(), mcc, mnc);
srslte::console("HSS Initialized.\n"); srslte::console("HSS Initialized.\n");
return 0; return 0;
} }
@ -90,7 +88,7 @@ bool hss::read_db_file(std::string db_filename)
if (!m_db_file.is_open()) { if (!m_db_file.is_open()) {
return false; return false;
} }
m_hss_log->info("Opened DB file: %s\n", db_filename.c_str()); m_logger.info("Opened DB file: %s", db_filename.c_str());
std::string line; std::string line;
while (std::getline(m_db_file, line)) { while (std::getline(m_db_file, line)) {
@ -98,8 +96,8 @@ bool hss::read_db_file(std::string db_filename)
uint column_size = 10; uint column_size = 10;
std::vector<std::string> split = split_string(line, ','); std::vector<std::string> split = split_string(line, ',');
if (split.size() != column_size) { if (split.size() != column_size) {
m_hss_log->error("Error parsing UE database. Wrong number of columns in .csv\n"); m_logger.error("Error parsing UE database. Wrong number of columns in .csv");
m_hss_log->error("Columns: %zd, Expected %d.\n", split.size(), column_size); m_logger.error("Columns: %zd, Expected %d.", split.size(), column_size);
srslte::console("\nError parsing UE database. Wrong number of columns in user database CSV.\n"); srslte::console("\nError parsing UE database. Wrong number of columns in user database CSV.\n");
srslte::console("Perhaps you are using an old user_db.csv?\n"); srslte::console("Perhaps you are using an old user_db.csv?\n");
@ -113,7 +111,7 @@ bool hss::read_db_file(std::string db_filename)
} else if (split[1] == std::string("mil")) { } else if (split[1] == std::string("mil")) {
ue_ctx->algo = HSS_ALGO_MILENAGE; ue_ctx->algo = HSS_ALGO_MILENAGE;
} else { } else {
m_hss_log->error("Neither XOR nor MILENAGE configured.\n"); m_logger.error("Neither XOR nor MILENAGE configured.");
return false; return false;
} }
ue_ctx->imsi = strtoull(split[2].c_str(), nullptr, 10); ue_ctx->imsi = strtoull(split[2].c_str(), nullptr, 10);
@ -126,22 +124,22 @@ bool hss::read_db_file(std::string db_filename)
ue_ctx->op_configured = false; ue_ctx->op_configured = false;
get_uint_vec_from_hex_str(split[5], ue_ctx->opc, 16); get_uint_vec_from_hex_str(split[5], ue_ctx->opc, 16);
} else { } else {
m_hss_log->error("Neither OP nor OPc configured.\n"); m_logger.error("Neither OP nor OPc configured.");
return false; return false;
} }
get_uint_vec_from_hex_str(split[6], ue_ctx->amf, 2); get_uint_vec_from_hex_str(split[6], ue_ctx->amf, 2);
get_uint_vec_from_hex_str(split[7], ue_ctx->sqn, 6); get_uint_vec_from_hex_str(split[7], ue_ctx->sqn, 6);
m_hss_log->debug("Added user from DB, IMSI: %015" PRIu64 "\n", ue_ctx->imsi); m_logger.debug("Added user from DB, IMSI: %015" PRIu64 "", ue_ctx->imsi);
m_hss_log->debug_hex(ue_ctx->key, 16, "User Key : "); m_logger.debug(ue_ctx->key, 16, "User Key : ");
if (ue_ctx->op_configured) { if (ue_ctx->op_configured) {
m_hss_log->debug_hex(ue_ctx->op, 16, "User OP : "); m_logger.debug(ue_ctx->op, 16, "User OP : ");
} }
m_hss_log->debug_hex(ue_ctx->opc, 16, "User OPc : "); m_logger.debug(ue_ctx->opc, 16, "User OPc : ");
m_hss_log->debug_hex(ue_ctx->amf, 2, "AMF : "); m_logger.debug(ue_ctx->amf, 2, "AMF : ");
m_hss_log->debug_hex(ue_ctx->sqn, 6, "SQN : "); m_logger.debug(ue_ctx->sqn, 6, "SQN : ");
ue_ctx->qci = (uint16_t)strtol(split[8].c_str(), nullptr, 10); ue_ctx->qci = (uint16_t)strtol(split[8].c_str(), nullptr, 10);
m_hss_log->debug("Default Bearer QCI: %d\n", ue_ctx->qci); m_logger.debug("Default Bearer QCI: %d", ue_ctx->qci);
if (split[9] == std::string("dynamic")) { if (split[9] == std::string("dynamic")) {
ue_ctx->static_ip_addr = "0.0.0.0"; ue_ctx->static_ip_addr = "0.0.0.0";
@ -150,13 +148,13 @@ bool hss::read_db_file(std::string db_filename)
if (inet_pton(AF_INET, split[9].c_str(), buf)) { if (inet_pton(AF_INET, split[9].c_str(), buf)) {
if (m_ip_to_imsi.insert(std::make_pair(split[9], ue_ctx->imsi)).second) { if (m_ip_to_imsi.insert(std::make_pair(split[9], ue_ctx->imsi)).second) {
ue_ctx->static_ip_addr = split[9]; ue_ctx->static_ip_addr = split[9];
m_hss_log->info("static ip addr %s\n", ue_ctx->static_ip_addr.c_str()); m_logger.info("static ip addr %s", ue_ctx->static_ip_addr.c_str());
} else { } else {
m_hss_log->info("duplicate static ip addr %s\n", split[9].c_str()); m_logger.info("duplicate static ip addr %s", split[9].c_str());
return false; return false;
} }
} else { } else {
m_hss_log->info("invalid static ip addr %s, %s\n", split[9].c_str(), strerror(errno)); m_logger.info("invalid static ip addr %s, %s", split[9].c_str(), strerror(errno));
return false; return false;
} }
} }
@ -185,7 +183,7 @@ bool hss::write_db_file(std::string db_filename)
if (!m_db_file.is_open()) { if (!m_db_file.is_open()) {
return false; return false;
} }
m_hss_log->info("Opened DB file: %s\n", db_filename.c_str()); m_logger.info("Opened DB file: %s", db_filename.c_str());
// Write comment info // Write comment info
m_db_file << "# \n" m_db_file << "# \n"
@ -249,11 +247,11 @@ bool hss::write_db_file(std::string db_filename)
bool hss::gen_auth_info_answer(uint64_t imsi, uint8_t* k_asme, uint8_t* autn, uint8_t* rand, uint8_t* xres) bool hss::gen_auth_info_answer(uint64_t imsi, uint8_t* k_asme, uint8_t* autn, uint8_t* rand, uint8_t* xres)
{ {
m_hss_log->debug("Generating AUTH info answer\n"); m_logger.debug("Generating AUTH info answer");
hss_ue_ctx_t* ue_ctx = get_ue_ctx(imsi); hss_ue_ctx_t* ue_ctx = get_ue_ctx(imsi);
if (ue_ctx == nullptr) { if (ue_ctx == nullptr) {
srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi); srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi);
m_hss_log->error("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi); m_logger.error("User not found at HSS. IMSI: %015" PRIu64 "", imsi);
return false; return false;
} }
@ -291,24 +289,24 @@ void hss::gen_auth_info_answer_milenage(hss_ue_ctx_t* ue_ctx,
srslte::security_milenage_f2345(k, opc, rand, xres, ck, ik, ak); srslte::security_milenage_f2345(k, opc, rand, xres, ck, ik, ak);
m_hss_log->debug_hex(k, 16, "User Key : "); m_logger.debug(k, 16, "User Key : ");
m_hss_log->debug_hex(opc, 16, "User OPc : "); m_logger.debug(opc, 16, "User OPc : ");
m_hss_log->debug_hex(rand, 16, "User Rand : "); m_logger.debug(rand, 16, "User Rand : ");
m_hss_log->debug_hex(xres, 8, "User XRES: "); m_logger.debug(xres, 8, "User XRES: ");
m_hss_log->debug_hex(ck, 16, "User CK: "); m_logger.debug(ck, 16, "User CK: ");
m_hss_log->debug_hex(ik, 16, "User IK: "); m_logger.debug(ik, 16, "User IK: ");
m_hss_log->debug_hex(ak, 6, "User AK: "); m_logger.debug(ak, 6, "User AK: ");
srslte::security_milenage_f1(k, opc, rand, sqn, amf, mac); srslte::security_milenage_f1(k, opc, rand, sqn, amf, mac);
m_hss_log->debug_hex(sqn, 6, "User SQN : "); m_logger.debug(sqn, 6, "User SQN : ");
m_hss_log->debug_hex(mac, 8, "User MAC : "); m_logger.debug(mac, 8, "User MAC : ");
// Generate K_asme // Generate K_asme
srslte::security_generate_k_asme(ck, ik, ak, sqn, mcc, mnc, k_asme); srslte::security_generate_k_asme(ck, ik, ak, sqn, mcc, mnc, k_asme);
m_hss_log->debug("User MCC : %x MNC : %x \n", mcc, mnc); m_logger.debug("User MCC : %x MNC : %x ", mcc, mnc);
m_hss_log->debug_hex(k_asme, 32, "User k_asme : "); m_logger.debug(k_asme, 32, "User k_asme : ");
// Generate AUTN (autn = sqn ^ ak |+| amf |+| mac) // Generate AUTN (autn = sqn ^ ak |+| amf |+| mac)
for (int i = 0; i < 6; i++) { for (int i = 0; i < 6; i++) {
@ -320,7 +318,7 @@ void hss::gen_auth_info_answer_milenage(hss_ue_ctx_t* ue_ctx,
for (int i = 0; i < 8; i++) { for (int i = 0; i < 8; i++) {
autn[8 + i] = mac[i]; autn[8 + i] = mac[i];
} }
m_hss_log->debug_hex(autn, 16, "User AUTN: "); m_logger.debug(autn, 16, "User AUTN: ");
// Set last RAND // Set last RAND
ue_ctx->set_last_rand(rand); ue_ctx->set_last_rand(rand);
@ -363,13 +361,13 @@ void hss::gen_auth_info_answer_xor(hss_ue_ctx_t* ue_ctx, uint8_t* k_asme, uint8_
ak[i] = xdout[i + 3]; ak[i] = xdout[i + 3];
} }
m_hss_log->debug_hex(k, 16, "User Key : "); m_logger.debug(k, 16, "User Key : ");
m_hss_log->debug_hex(opc, 16, "User OPc : "); m_logger.debug(opc, 16, "User OPc : ");
m_hss_log->debug_hex(rand, 16, "User Rand : "); m_logger.debug(rand, 16, "User Rand : ");
m_hss_log->debug_hex(xres, 8, "User XRES: "); m_logger.debug(xres, 8, "User XRES: ");
m_hss_log->debug_hex(ck, 16, "User CK: "); m_logger.debug(ck, 16, "User CK: ");
m_hss_log->debug_hex(ik, 16, "User IK: "); m_logger.debug(ik, 16, "User IK: ");
m_hss_log->debug_hex(ak, 6, "User AK: "); m_logger.debug(ak, 6, "User AK: ");
// Generate cdout // Generate cdout
for (i = 0; i < 6; i++) { for (i = 0; i < 6; i++) {
@ -384,8 +382,8 @@ void hss::gen_auth_info_answer_xor(hss_ue_ctx_t* ue_ctx, uint8_t* k_asme, uint8_
mac[i] = xdout[i] ^ cdout[i]; mac[i] = xdout[i] ^ cdout[i];
} }
m_hss_log->debug_hex(sqn, 6, "User SQN : "); m_logger.debug(sqn, 6, "User SQN : ");
m_hss_log->debug_hex(mac, 8, "User MAC : "); m_logger.debug(mac, 8, "User MAC : ");
// Generate AUTN (autn = sqn ^ ak |+| amf |+| mac) // Generate AUTN (autn = sqn ^ ak |+| amf |+| mac)
for (int i = 0; i < 6; i++) { for (int i = 0; i < 6; i++) {
@ -401,8 +399,8 @@ void hss::gen_auth_info_answer_xor(hss_ue_ctx_t* ue_ctx, uint8_t* k_asme, uint8_
// Generate K_asme // Generate K_asme
srslte::security_generate_k_asme(ck, ik, ak, sqn, mcc, mnc, k_asme); srslte::security_generate_k_asme(ck, ik, ak, sqn, mcc, mnc, k_asme);
m_hss_log->debug("User MCC : %x MNC : %x \n", mcc, mnc); m_logger.debug("User MCC : %x MNC : %x ", mcc, mnc);
m_hss_log->debug_hex(k_asme, 32, "User k_asme : "); m_logger.debug(k_asme, 32, "User k_asme : ");
// Generate AUTN (autn = sqn ^ ak |+| amf |+| mac) // Generate AUTN (autn = sqn ^ ak |+| amf |+| mac)
for (int i = 0; i < 6; i++) { for (int i = 0; i < 6; i++) {
@ -415,7 +413,7 @@ void hss::gen_auth_info_answer_xor(hss_ue_ctx_t* ue_ctx, uint8_t* k_asme, uint8_
autn[8 + i] = mac[i]; autn[8 + i] = mac[i];
} }
m_hss_log->debug_hex(autn, 8, "User AUTN: "); m_logger.debug(autn, 8, "User AUTN: ");
// Set last RAND // Set last RAND
ue_ctx->set_last_rand(rand); ue_ctx->set_last_rand(rand);
@ -426,23 +424,23 @@ bool hss::gen_update_loc_answer(uint64_t imsi, uint8_t* qci)
{ {
std::map<uint64_t, std::unique_ptr<hss_ue_ctx_t> >::iterator ue_ctx_it = m_imsi_to_ue_ctx.find(imsi); std::map<uint64_t, std::unique_ptr<hss_ue_ctx_t> >::iterator ue_ctx_it = m_imsi_to_ue_ctx.find(imsi);
if (ue_ctx_it == m_imsi_to_ue_ctx.end()) { if (ue_ctx_it == m_imsi_to_ue_ctx.end()) {
m_hss_log->info("User not found. IMSI: %015" PRIu64 "\n", imsi); m_logger.info("User not found. IMSI: %015" PRIu64 "", imsi);
srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi); srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi);
return false; return false;
} }
const std::unique_ptr<hss_ue_ctx_t>& ue_ctx = ue_ctx_it->second; const std::unique_ptr<hss_ue_ctx_t>& ue_ctx = ue_ctx_it->second;
m_hss_log->info("Found User %015" PRIu64 "\n", imsi); m_logger.info("Found User %015" PRIu64 "", imsi);
*qci = ue_ctx->qci; *qci = ue_ctx->qci;
return true; return true;
} }
bool hss::resync_sqn(uint64_t imsi, uint8_t* auts) bool hss::resync_sqn(uint64_t imsi, uint8_t* auts)
{ {
m_hss_log->debug("Re-syncing SQN\n"); m_logger.debug("Re-syncing SQN");
hss_ue_ctx_t* ue_ctx = get_ue_ctx(imsi); hss_ue_ctx_t* ue_ctx = get_ue_ctx(imsi);
if (ue_ctx == nullptr) { if (ue_ctx == nullptr) {
srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi); srslte::console("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi);
m_hss_log->error("User not found at HSS. IMSI: %015" PRIu64 "\n", imsi); m_logger.error("User not found at HSS. IMSI: %015" PRIu64 "", imsi);
return false; return false;
} }
@ -461,7 +459,7 @@ bool hss::resync_sqn(uint64_t imsi, uint8_t* auts)
void hss::resync_sqn_xor(hss_ue_ctx_t* ue_ctx, uint8_t* auts) void hss::resync_sqn_xor(hss_ue_ctx_t* ue_ctx, uint8_t* auts)
{ {
m_hss_log->error("XOR SQN synchronization not supported yet\n"); m_logger.error("XOR SQN synchronization not supported yet");
srslte::console("XOR SQNs synchronization not supported yet\n"); srslte::console("XOR SQNs synchronization not supported yet\n");
return; return;
} }
@ -490,30 +488,30 @@ void hss::resync_sqn_milenage(hss_ue_ctx_t* ue_ctx, uint8_t* auts)
mac_s[i] = auts[i + 6]; mac_s[i] = auts[i + 6];
} }
m_hss_log->debug_hex(k, 16, "User Key : "); m_logger.debug(k, 16, "User Key : ");
m_hss_log->debug_hex(opc, 16, "User OPc : "); m_logger.debug(opc, 16, "User OPc : ");
m_hss_log->debug_hex(amf, 2, "User AMF : "); m_logger.debug(amf, 2, "User AMF : ");
m_hss_log->debug_hex(last_rand, 16, "User Last Rand : "); m_logger.debug(last_rand, 16, "User Last Rand : ");
m_hss_log->debug_hex(auts, 16, "AUTS : "); m_logger.debug(auts, 16, "AUTS : ");
m_hss_log->debug_hex(sqn_ms_xor_ak, 6, "SQN xor AK : "); m_logger.debug(sqn_ms_xor_ak, 6, "SQN xor AK : ");
m_hss_log->debug_hex(mac_s, 8, "MAC : "); m_logger.debug(mac_s, 8, "MAC : ");
srslte::security_milenage_f5_star(k, opc, last_rand, ak); srslte::security_milenage_f5_star(k, opc, last_rand, ak);
m_hss_log->debug_hex(ak, 6, "Resynch AK : "); m_logger.debug(ak, 6, "Resynch AK : ");
uint8_t sqn_ms[6]; uint8_t sqn_ms[6];
for (int i = 0; i < 6; i++) { for (int i = 0; i < 6; i++) {
sqn_ms[i] = sqn_ms_xor_ak[i] ^ ak[i]; sqn_ms[i] = sqn_ms_xor_ak[i] ^ ak[i];
} }
m_hss_log->debug_hex(sqn_ms, 6, "SQN MS : "); m_logger.debug(sqn_ms, 6, "SQN MS : ");
m_hss_log->debug_hex(sqn, 6, "SQN HE : "); m_logger.debug(sqn, 6, "SQN HE : ");
uint8_t mac_s_tmp[8]; uint8_t mac_s_tmp[8];
uint8_t dummy_amf[2] = {}; uint8_t dummy_amf[2] = {};
srslte::security_milenage_f1_star(k, opc, last_rand, sqn_ms, dummy_amf, mac_s_tmp); srslte::security_milenage_f1_star(k, opc, last_rand, sqn_ms, dummy_amf, mac_s_tmp);
m_hss_log->debug_hex(mac_s_tmp, 8, "MAC calc : "); m_logger.debug(mac_s_tmp, 8, "MAC calc : ");
ue_ctx->set_sqn(sqn_ms); ue_ctx->set_sqn(sqn_ms);
return; return;
@ -522,8 +520,8 @@ void hss::resync_sqn_milenage(hss_ue_ctx_t* ue_ctx, uint8_t* auts)
void hss::increment_ue_sqn(hss_ue_ctx_t* ue_ctx) void hss::increment_ue_sqn(hss_ue_ctx_t* ue_ctx)
{ {
increment_sqn(ue_ctx->sqn, ue_ctx->sqn); increment_sqn(ue_ctx->sqn, ue_ctx->sqn);
m_hss_log->debug("Incremented SQN -- IMSI: %015" PRIu64 "\n", ue_ctx->imsi); m_logger.debug("Incremented SQN -- IMSI: %015" PRIu64 "", ue_ctx->imsi);
m_hss_log->debug_hex(ue_ctx->sqn, 6, "SQN: "); m_logger.debug(ue_ctx->sqn, 6, "SQN: ");
} }
void hss::increment_sqn(uint8_t* sqn, uint8_t* next_sqn) void hss::increment_sqn(uint8_t* sqn, uint8_t* next_sqn)
@ -598,7 +596,7 @@ hss_ue_ctx_t* hss::get_ue_ctx(uint64_t imsi)
{ {
std::map<uint64_t, std::unique_ptr<hss_ue_ctx_t> >::iterator ue_ctx_it = m_imsi_to_ue_ctx.find(imsi); std::map<uint64_t, std::unique_ptr<hss_ue_ctx_t> >::iterator ue_ctx_it = m_imsi_to_ue_ctx.find(imsi);
if (ue_ctx_it == m_imsi_to_ue_ctx.end()) { if (ue_ctx_it == m_imsi_to_ue_ctx.end()) {
m_hss_log->info("User not found. IMSI: %015" PRIu64 "\n", imsi); m_logger.info("User not found. IMSI: %015" PRIu64 "", imsi);
return nullptr; return nullptr;
} }

@ -391,14 +391,14 @@ int main(int argc, char* argv[])
return SRSLTE_ERROR; return SRSLTE_ERROR;
} }
srslte::srslog_wrapper log_wrapper(*chan); srslte::srslog_wrapper log_wrapper(*chan);
srslog::set_default_sink(*log_sink);
// Start the log backend. // Start the log backend.
srslog::init(); srslog::init();
if (args.log_args.filename != "stdout") { if (args.log_args.filename != "stdout") {
log_wrapper.log_char("\n\n"); auto& epc_logger = srslog::fetch_basic_logger("EPC", false);
log_wrapper.log_char(get_build_string().c_str()); epc_logger.info("\n\n%s\n--- Software Radio Systems EPC log ---\n\n", get_build_string().c_str());
log_wrapper.log_char("\n--- Software Radio Systems EPC log ---\n\n");
} }
srslte::logmap::set_default_logger(&log_wrapper); srslte::logmap::set_default_logger(&log_wrapper);
@ -408,50 +408,71 @@ int main(int argc, char* argv[])
nas_log.init("NAS ", &log_wrapper); nas_log.init("NAS ", &log_wrapper);
nas_log.set_level(level(args.log_args.nas_level)); nas_log.set_level(level(args.log_args.nas_level));
nas_log.set_hex_limit(args.log_args.nas_hex_limit); nas_log.set_hex_limit(args.log_args.nas_hex_limit);
auto& nas_logger = srslog::fetch_basic_logger("NAS", false);
nas_logger.set_level(srslog::str_to_basic_level(args.log_args.nas_level));
nas_logger.set_hex_dump_max_size(args.log_args.nas_hex_limit);
srslte::log_filter s1ap_log; srslte::log_filter s1ap_log;
s1ap_log.init("S1AP", &log_wrapper); s1ap_log.init("S1AP", &log_wrapper);
s1ap_log.set_level(level(args.log_args.s1ap_level)); s1ap_log.set_level(level(args.log_args.s1ap_level));
s1ap_log.set_hex_limit(args.log_args.s1ap_hex_limit); s1ap_log.set_hex_limit(args.log_args.s1ap_hex_limit);
auto& s1ap_logger = srslog::fetch_basic_logger("S1AP", false);
s1ap_logger.set_level(srslog::str_to_basic_level(args.log_args.s1ap_level));
s1ap_logger.set_hex_dump_max_size(args.log_args.s1ap_hex_limit);
srslte::log_filter mme_gtpc_log; srslte::log_filter mme_gtpc_log;
mme_gtpc_log.init("MME GTPC", &log_wrapper); mme_gtpc_log.init("MME GTPC", &log_wrapper);
mme_gtpc_log.set_level(level(args.log_args.mme_gtpc_level)); mme_gtpc_log.set_level(level(args.log_args.mme_gtpc_level));
mme_gtpc_log.set_hex_limit(args.log_args.mme_gtpc_hex_limit); mme_gtpc_log.set_hex_limit(args.log_args.mme_gtpc_hex_limit);
auto& mme_gtpc_logger = srslog::fetch_basic_logger("MME GTPC", false);
mme_gtpc_logger.set_level(srslog::str_to_basic_level(args.log_args.mme_gtpc_level));
mme_gtpc_logger.set_hex_dump_max_size(args.log_args.mme_gtpc_hex_limit);
srslte::log_filter hss_log; srslte::log_filter hss_log;
hss_log.init("HSS ", &log_wrapper); hss_log.init("HSS ", &log_wrapper);
hss_log.set_level(level(args.log_args.hss_level)); hss_log.set_level(level(args.log_args.hss_level));
hss_log.set_hex_limit(args.log_args.hss_hex_limit); hss_log.set_hex_limit(args.log_args.hss_hex_limit);
auto& hss_logger = srslog::fetch_basic_logger("HSS", false);
hss_logger.set_level(srslog::str_to_basic_level(args.log_args.hss_level));
hss_logger.set_hex_dump_max_size(args.log_args.hss_hex_limit);
srslte::log_filter spgw_gtpc_log; srslte::log_filter spgw_gtpc_log;
spgw_gtpc_log.init("SPGW GTPC", &log_wrapper); spgw_gtpc_log.init("SPGW GTPC", &log_wrapper);
spgw_gtpc_log.set_level(level(args.log_args.spgw_gtpc_level)); spgw_gtpc_log.set_level(level(args.log_args.spgw_gtpc_level));
spgw_gtpc_log.set_hex_limit(args.log_args.spgw_gtpc_hex_limit); spgw_gtpc_log.set_hex_limit(args.log_args.spgw_gtpc_hex_limit);
auto& spgw_gtpc_logger = srslog::fetch_basic_logger("SPGW GTPC", false);
spgw_gtpc_logger.set_level(srslog::str_to_basic_level(args.log_args.spgw_gtpc_level));
spgw_gtpc_logger.set_hex_dump_max_size(args.log_args.spgw_gtpc_hex_limit);
srslte::log_ref gtpu_log{"GTPU"}; srslte::log_ref gtpu_log{"GTPU"};
gtpu_log->set_level(level(args.log_args.mme_gtpc_level)); gtpu_log->set_level(level(args.log_args.mme_gtpc_level));
gtpu_log->set_hex_limit(args.log_args.mme_gtpc_hex_limit); gtpu_log->set_hex_limit(args.log_args.mme_gtpc_hex_limit);
auto& gtpu_logger = srslog::fetch_basic_logger("GTPU", false);
gtpu_logger.set_level(srslog::str_to_basic_level(args.log_args.gtpu_level));
gtpu_logger.set_hex_dump_max_size(args.log_args.gtpu_hex_limit);
srslte::log_filter spgw_log; srslte::log_filter spgw_log;
spgw_log.init("SPGW", &log_wrapper); spgw_log.init("SPGW", &log_wrapper);
spgw_log.set_level(level(args.log_args.spgw_level)); spgw_log.set_level(level(args.log_args.spgw_level));
spgw_log.set_hex_limit(args.log_args.spgw_hex_limit); spgw_log.set_hex_limit(args.log_args.spgw_hex_limit);
auto& spgw_logger = srslog::fetch_basic_logger("SPGW", false);
spgw_logger.set_level(srslog::str_to_basic_level(args.log_args.spgw_level));
spgw_logger.set_hex_dump_max_size(args.log_args.spgw_hex_limit);
hss* hss = hss::get_instance(); hss* hss = hss::get_instance();
if (hss->init(&args.hss_args, &hss_log)) { if (hss->init(&args.hss_args)) {
cout << "Error initializing HSS" << endl; cout << "Error initializing HSS" << endl;
exit(1); exit(1);
} }
mme* mme = mme::get_instance(); mme* mme = mme::get_instance();
if (mme->init(&args.mme_args, &nas_log, &s1ap_log, &mme_gtpc_log)) { if (mme->init(&args.mme_args)) {
cout << "Error initializing MME" << endl; cout << "Error initializing MME" << endl;
exit(1); exit(1);
} }
spgw* spgw = spgw::get_instance(); spgw* spgw = spgw::get_instance();
if (spgw->init(&args.spgw_args, gtpu_log, &spgw_gtpc_log, &spgw_log, hss->get_ip_to_imsi())) { if (spgw->init(&args.spgw_args, gtpu_log, hss->get_ip_to_imsi())) {
cout << "Error initializing SP-GW" << endl; cout << "Error initializing SP-GW" << endl;
exit(1); exit(1);
} }

@ -196,12 +196,14 @@ int main(int argc, char* argv[])
return SRSLTE_ERROR; return SRSLTE_ERROR;
} }
srslte::srslog_wrapper log_wrapper(*chan); srslte::srslog_wrapper log_wrapper(*chan);
srslog::set_default_sink(*log_sink);
// Start the log backend. // Start the log backend.
srslog::init(); srslog::init();
if (args.log_args.filename != "stdout") { if (args.log_args.filename != "stdout") {
log_wrapper.log_char("\n--- Software Radio Systems MBMS log ---\n\n"); auto& mbms_gw_logger = srslog::fetch_basic_logger("MBMS GW", false);
mbms_gw_logger.info("\n--- Software Radio Systems MBMS log ---\n\n");
} }
srslte::logmap::set_default_logger(&log_wrapper); srslte::logmap::set_default_logger(&log_wrapper);
@ -209,6 +211,9 @@ int main(int argc, char* argv[])
srslte::log_ref mbms_gw_log{"MBMS"}; srslte::log_ref mbms_gw_log{"MBMS"};
mbms_gw_log->set_level(level(args.log_args.mbms_gw_level)); mbms_gw_log->set_level(level(args.log_args.mbms_gw_level));
mbms_gw_log->set_hex_limit(args.log_args.mbms_gw_hex_limit); mbms_gw_log->set_hex_limit(args.log_args.mbms_gw_hex_limit);
auto& mbms_gw_logger = srslog::fetch_basic_logger("MBMS", false);
mbms_gw_logger.set_level(srslog::str_to_basic_level(args.log_args.mbms_gw_level));
mbms_gw_logger.set_hex_dump_max_size(args.log_args.mbms_gw_hex_limit);
mbms_gw* mbms_gw = mbms_gw::get_instance(); mbms_gw* mbms_gw = mbms_gw::get_instance();
if (mbms_gw->init(&args.mbms_gw_args, mbms_gw_log)) { if (mbms_gw->init(&args.mbms_gw_args, mbms_gw_log)) {

@ -71,16 +71,16 @@ int mbms_gw::init(mbms_gw_args_t* args, srslte::log_ref mbms_gw_log)
err = init_sgi_mb_if(args); err = init_sgi_mb_if(args);
if (err != SRSLTE_SUCCESS) { if (err != SRSLTE_SUCCESS) {
srslte::console("Error initializing SGi-MB.\n"); srslte::console("Error initializing SGi-MB.\n");
m_mbms_gw_log->error("Error initializing SGi-MB.\n"); m_logger.error("Error initializing SGi-MB.");
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
err = init_m1_u(args); err = init_m1_u(args);
if (err != SRSLTE_SUCCESS) { if (err != SRSLTE_SUCCESS) {
srslte::console("Error initializing SGi-MB.\n"); srslte::console("Error initializing SGi-MB.\n");
m_mbms_gw_log->error("Error initializing SGi-MB.\n"); m_logger.error("Error initializing SGi-MB.");
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
m_mbms_gw_log->info("MBMS GW Initiated\n"); m_logger.info("MBMS GW Initiated");
srslte::console("MBMS GW Initiated\n"); srslte::console("MBMS GW Initiated\n");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -90,7 +90,7 @@ void mbms_gw::stop()
if (m_running) { if (m_running) {
if (m_sgi_mb_up) { if (m_sgi_mb_up) {
close(m_sgi_mb_if); close(m_sgi_mb_if);
m_mbms_gw_log->info("Closed SGi-MB interface\n"); m_logger.info("Closed SGi-MB interface");
} }
m_running = false; m_running = false;
thread_cancel(); thread_cancel();
@ -109,9 +109,9 @@ int mbms_gw::init_sgi_mb_if(mbms_gw_args_t* args)
// Construct the TUN device // Construct the TUN device
m_sgi_mb_if = open("/dev/net/tun", O_RDWR); m_sgi_mb_if = open("/dev/net/tun", O_RDWR);
m_mbms_gw_log->info("TUN file descriptor = %d\n", m_sgi_mb_if); m_logger.info("TUN file descriptor = %d", m_sgi_mb_if);
if (m_sgi_mb_if < 0) { if (m_sgi_mb_if < 0) {
m_mbms_gw_log->error("Failed to open TUN device: %s\n", strerror(errno)); m_logger.error("Failed to open TUN device: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
@ -123,23 +123,23 @@ int mbms_gw::init_sgi_mb_if(mbms_gw_args_t* args)
ifr.ifr_ifrn.ifrn_name[IFNAMSIZ - 1] = '\0'; ifr.ifr_ifrn.ifrn_name[IFNAMSIZ - 1] = '\0';
if (ioctl(m_sgi_mb_if, TUNSETIFF, &ifr) < 0) { if (ioctl(m_sgi_mb_if, TUNSETIFF, &ifr) < 0) {
m_mbms_gw_log->error("Failed to set TUN device name: %s\n", strerror(errno)); m_logger.error("Failed to set TUN device name: %s", strerror(errno));
close(m_sgi_mb_if); close(m_sgi_mb_if);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} else { } else {
m_mbms_gw_log->debug("Set TUN device name: %s\n", args->sgi_mb_if_name.c_str()); m_logger.debug("Set TUN device name: %s", args->sgi_mb_if_name.c_str());
} }
// Bring up the interface // Bring up the interface
int sgi_mb_sock = socket(AF_INET, SOCK_DGRAM, 0); int sgi_mb_sock = socket(AF_INET, SOCK_DGRAM, 0);
if (sgi_mb_sock < 0) { if (sgi_mb_sock < 0) {
m_mbms_gw_log->error("Failed to bring up socket: %s\n", strerror(errno)); m_logger.error("Failed to bring up socket: %s", strerror(errno));
close(m_sgi_mb_if); close(m_sgi_mb_if);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
if (ioctl(sgi_mb_sock, SIOCGIFFLAGS, &ifr) < 0) { if (ioctl(sgi_mb_sock, SIOCGIFFLAGS, &ifr) < 0) {
m_mbms_gw_log->error("Failed to bring up interface: %s\n", strerror(errno)); m_logger.error("Failed to bring up interface: %s", strerror(errno));
close(m_sgi_mb_if); close(m_sgi_mb_if);
close(sgi_mb_sock); close(sgi_mb_sock);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -147,7 +147,7 @@ int mbms_gw::init_sgi_mb_if(mbms_gw_args_t* args)
ifr.ifr_flags |= IFF_UP | IFF_RUNNING; ifr.ifr_flags |= IFF_UP | IFF_RUNNING;
if (ioctl(sgi_mb_sock, SIOCSIFFLAGS, &ifr) < 0) { if (ioctl(sgi_mb_sock, SIOCSIFFLAGS, &ifr) < 0) {
m_mbms_gw_log->error("Failed to set socket flags: %s\n", strerror(errno)); m_logger.error("Failed to set socket flags: %s", strerror(errno));
close(sgi_mb_sock); close(sgi_mb_sock);
close(m_sgi_mb_if); close(m_sgi_mb_if);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -160,8 +160,8 @@ int mbms_gw::init_sgi_mb_if(mbms_gw_args_t* args)
addr->sin_port = 0; addr->sin_port = 0;
if (ioctl(sgi_mb_sock, SIOCSIFADDR, &ifr) < 0) { if (ioctl(sgi_mb_sock, SIOCSIFADDR, &ifr) < 0) {
m_mbms_gw_log->error( m_logger.error(
"Failed to set TUN interface IP. Address: %s, Error: %s\n", args->sgi_mb_if_addr.c_str(), strerror(errno)); "Failed to set TUN interface IP. Address: %s, Error: %s", args->sgi_mb_if_addr.c_str(), strerror(errno));
close(m_sgi_mb_if); close(m_sgi_mb_if);
close(sgi_mb_sock); close(sgi_mb_sock);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -170,7 +170,7 @@ int mbms_gw::init_sgi_mb_if(mbms_gw_args_t* args)
ifr.ifr_netmask.sa_family = AF_INET; ifr.ifr_netmask.sa_family = AF_INET;
((struct sockaddr_in*)&ifr.ifr_netmask)->sin_addr.s_addr = inet_addr(args->sgi_mb_if_mask.c_str()); ((struct sockaddr_in*)&ifr.ifr_netmask)->sin_addr.s_addr = inet_addr(args->sgi_mb_if_mask.c_str());
if (ioctl(sgi_mb_sock, SIOCSIFNETMASK, &ifr) < 0) { if (ioctl(sgi_mb_sock, SIOCSIFNETMASK, &ifr) < 0) {
m_mbms_gw_log->error("Failed to set TUN interface Netmask. Error: %s\n", strerror(errno)); m_logger.error("Failed to set TUN interface Netmask. Error: %s", strerror(errno));
close(m_sgi_mb_if); close(m_sgi_mb_if);
close(sgi_mb_sock); close(sgi_mb_sock);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -187,7 +187,7 @@ int mbms_gw::init_m1_u(mbms_gw_args_t* args)
struct sockaddr_in addr; struct sockaddr_in addr;
m_m1u = socket(AF_INET, SOCK_DGRAM, 0); m_m1u = socket(AF_INET, SOCK_DGRAM, 0);
if (m_m1u < 0) { if (m_m1u < 0) {
m_mbms_gw_log->error("Failed to open socket: %s\n", strerror(errno)); m_logger.error("Failed to open socket: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
m_m1u_up = true; m_m1u_up = true;
@ -195,10 +195,10 @@ int mbms_gw::init_m1_u(mbms_gw_args_t* args)
/* set no loopback */ /* set no loopback */
char loopch = 0; char loopch = 0;
if (setsockopt(m_m1u, IPPROTO_IP, IP_MULTICAST_LOOP, (char*)&loopch, sizeof(char)) < 0) { if (setsockopt(m_m1u, IPPROTO_IP, IP_MULTICAST_LOOP, (char*)&loopch, sizeof(char)) < 0) {
m_mbms_gw_log->error("Failed to disable loopback: %s\n", strerror(errno)); m_logger.error("Failed to disable loopback: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} else { } else {
m_mbms_gw_log->debug("Loopback disabled\n"); m_logger.debug("Loopback disabled");
} }
/* Set local interface for outbound multicast packets*/ /* Set local interface for outbound multicast packets*/
@ -206,7 +206,7 @@ int mbms_gw::init_m1_u(mbms_gw_args_t* args)
struct in_addr local_if; struct in_addr local_if;
local_if.s_addr = inet_addr(args->m1u_multi_if.c_str()); local_if.s_addr = inet_addr(args->m1u_multi_if.c_str());
if (setsockopt(m_m1u, IPPROTO_IP, IP_MULTICAST_IF, (char*)&local_if, sizeof(struct in_addr)) < 0) { if (setsockopt(m_m1u, IPPROTO_IP, IP_MULTICAST_IF, (char*)&local_if, sizeof(struct in_addr)) < 0) {
m_mbms_gw_log->error("Error %s setting multicast interface %s.\n", strerror(errno), args->m1u_multi_if.c_str()); m_logger.error("Error %s setting multicast interface %s.", strerror(errno), args->m1u_multi_if.c_str());
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} else { } else {
printf("Multicast interface specified. Address: %s\n", args->m1u_multi_if.c_str()); printf("Multicast interface specified. Address: %s\n", args->m1u_multi_if.c_str());
@ -222,7 +222,7 @@ int mbms_gw::init_m1_u(mbms_gw_args_t* args)
m_m1u_multi_addr.sin_family = AF_INET; m_m1u_multi_addr.sin_family = AF_INET;
m_m1u_multi_addr.sin_port = htons(GTPU_RX_PORT + 1); m_m1u_multi_addr.sin_port = htons(GTPU_RX_PORT + 1);
m_m1u_multi_addr.sin_addr.s_addr = inet_addr(args->m1u_multi_addr.c_str()); m_m1u_multi_addr.sin_addr.s_addr = inet_addr(args->m1u_multi_addr.c_str());
m_mbms_gw_log->info("Initialized M1-U\n"); m_logger.info("Initialized M1-U");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -243,7 +243,7 @@ void mbms_gw::run_thread()
} while (n == -1 && errno == EAGAIN); } while (n == -1 && errno == EAGAIN);
if (n < 0) { if (n < 0) {
m_mbms_gw_log->error("Error reading from TUN interface. Error: %s\n", strerror(errno)); m_logger.error("Error reading from TUN interface. Error: %s", strerror(errno));
} else { } else {
msg->N_bytes = n; msg->N_bytes = n;
handle_sgi_md_pdu(msg); handle_sgi_md_pdu(msg);
@ -266,14 +266,14 @@ void mbms_gw::handle_sgi_md_pdu(srslte::byte_buffer_t* msg)
// Sanity Check IP packet // Sanity Check IP packet
if (msg->N_bytes < 20) { if (msg->N_bytes < 20) {
m_mbms_gw_log->error("IPv4 min len: %d, drop msg len %d\n", 20, msg->N_bytes); m_logger.error("IPv4 min len: %d, drop msg len %d", 20, msg->N_bytes);
return; return;
} }
// IP Headers // IP Headers
struct iphdr* iph = (struct iphdr*)msg->msg; struct iphdr* iph = (struct iphdr*)msg->msg;
if (iph->version != 4) { if (iph->version != 4) {
m_mbms_gw_log->info("IPv6 not supported yet.\n"); m_logger.info("IPv6 not supported yet.");
return; return;
} }
@ -286,7 +286,7 @@ void mbms_gw::handle_sgi_md_pdu(srslte::byte_buffer_t* msg)
if (n < 0) { if (n < 0) {
srslte::console("Error writing to M1-U socket.\n"); srslte::console("Error writing to M1-U socket.\n");
} else { } else {
m_mbms_gw_log->debug("Sent %d Bytes\n", msg->N_bytes); m_logger.debug("Sent %d Bytes", msg->N_bytes);
} }
} }

@ -53,32 +53,24 @@ void mme::cleanup(void)
pthread_mutex_unlock(&mme_instance_mutex); pthread_mutex_unlock(&mme_instance_mutex);
} }
int mme::init(mme_args_t* args, int mme::init(mme_args_t* args)
srslte::log_filter* nas_log,
srslte::log_filter* s1ap_log,
srslte::log_filter* mme_gtpc_log)
{ {
/*Init logger*/
m_nas_log = nas_log;
m_s1ap_log = s1ap_log;
m_mme_gtpc_log = mme_gtpc_log;
/*Init S1AP*/ /*Init S1AP*/
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
if (m_s1ap->init(args->s1ap_args, nas_log, s1ap_log)) { if (m_s1ap->init(args->s1ap_args)) {
m_s1ap_log->error("Error initializing MME S1APP\n"); m_s1ap_logger.error("Error initializing MME S1APP");
exit(-1); exit(-1);
} }
/*Init GTP-C*/ /*Init GTP-C*/
m_mme_gtpc = mme_gtpc::get_instance(); m_mme_gtpc = mme_gtpc::get_instance();
if (!m_mme_gtpc->init(m_mme_gtpc_log)) { if (!m_mme_gtpc->init()) {
srslte::console("Error initializing GTP-C\n"); srslte::console("Error initializing GTP-C\n");
exit(-1); exit(-1);
} }
/*Log successful initialization*/ /*Log successful initialization*/
m_s1ap_log->info("MME Initialized. MCC: 0x%x, MNC: 0x%x\n", args->s1ap_args.mcc, args->s1ap_args.mnc); m_s1ap_logger.info("MME Initialized. MCC: 0x%x, MNC: 0x%x", args->s1ap_args.mcc, args->s1ap_args.mnc);
srslte::console("MME Initialized. MCC: 0x%x, MNC: 0x%x\n", args->s1ap_args.mcc, args->s1ap_args.mnc); srslte::console("MME Initialized. MCC: 0x%x, MNC: 0x%x\n", args->s1ap_args.mcc, args->s1ap_args.mnc);
return 0; return 0;
} }
@ -126,35 +118,35 @@ void mme::run_thread()
for (std::vector<mme_timer_t>::iterator it = timers.begin(); it != timers.end(); ++it) { for (std::vector<mme_timer_t>::iterator it = timers.begin(); it != timers.end(); ++it) {
FD_SET(it->fd, &m_set); FD_SET(it->fd, &m_set);
max_fd = std::max(max_fd, it->fd); max_fd = std::max(max_fd, it->fd);
m_s1ap_log->debug("Adding Timer fd %d to fd_set\n", it->fd); m_s1ap_logger.debug("Adding Timer fd %d to fd_set", it->fd);
} }
m_s1ap_log->debug("Waiting for S1-MME or S11 Message\n"); m_s1ap_logger.debug("Waiting for S1-MME or S11 Message");
int n = select(max_fd + 1, &m_set, NULL, NULL, NULL); int n = select(max_fd + 1, &m_set, NULL, NULL, NULL);
if (n == -1) { if (n == -1) {
m_s1ap_log->error("Error from select\n"); m_s1ap_logger.error("Error from select");
} else if (n) { } else if (n) {
// Handle S1-MME // Handle S1-MME
if (FD_ISSET(s1mme, &m_set)) { if (FD_ISSET(s1mme, &m_set)) {
rd_sz = sctp_recvmsg(s1mme, pdu->msg, sz, (struct sockaddr*)&enb_addr, &fromlen, &sri, &msg_flags); rd_sz = sctp_recvmsg(s1mme, pdu->msg, sz, (struct sockaddr*)&enb_addr, &fromlen, &sri, &msg_flags);
if (rd_sz == -1 && errno != EAGAIN) { if (rd_sz == -1 && errno != EAGAIN) {
m_s1ap_log->error("Error reading from SCTP socket: %s", strerror(errno)); m_s1ap_logger.error("Error reading from SCTP socket: %s", strerror(errno));
} else if (rd_sz == -1 && errno == EAGAIN) { } else if (rd_sz == -1 && errno == EAGAIN) {
m_s1ap_log->debug("Socket timeout reached"); m_s1ap_logger.debug("Socket timeout reached");
} else { } else {
if (msg_flags & MSG_NOTIFICATION) { if (msg_flags & MSG_NOTIFICATION) {
// Received notification // Received notification
union sctp_notification* notification = (union sctp_notification*)pdu->msg; union sctp_notification* notification = (union sctp_notification*)pdu->msg;
m_s1ap_log->debug("SCTP Notification %d\n", notification->sn_header.sn_type); m_s1ap_logger.debug("SCTP Notification %d", notification->sn_header.sn_type);
if (notification->sn_header.sn_type == SCTP_SHUTDOWN_EVENT) { if (notification->sn_header.sn_type == SCTP_SHUTDOWN_EVENT) {
m_s1ap_log->info("SCTP Association Shutdown. Association: %d\n", sri.sinfo_assoc_id); m_s1ap_logger.info("SCTP Association Shutdown. Association: %d", sri.sinfo_assoc_id);
srslte::console("SCTP Association Shutdown. Association: %d\n", sri.sinfo_assoc_id); srslte::console("SCTP Association Shutdown. Association: %d\n", sri.sinfo_assoc_id);
m_s1ap->delete_enb_ctx(sri.sinfo_assoc_id); m_s1ap->delete_enb_ctx(sri.sinfo_assoc_id);
} }
} else { } else {
// Received data // Received data
pdu->N_bytes = rd_sz; pdu->N_bytes = rd_sz;
m_s1ap_log->info("Received S1AP msg. Size: %d\n", pdu->N_bytes); m_s1ap_logger.info("Received S1AP msg. Size: %d", pdu->N_bytes);
m_s1ap->handle_s1ap_rx_pdu(pdu, &sri); m_s1ap->handle_s1ap_rx_pdu(pdu, &sri);
} }
} }
@ -167,7 +159,7 @@ void mme::run_thread()
// Handle NAS Timers // Handle NAS Timers
for (std::vector<mme_timer_t>::iterator it = timers.begin(); it != timers.end();) { for (std::vector<mme_timer_t>::iterator it = timers.begin(); it != timers.end();) {
if (FD_ISSET(it->fd, &m_set)) { if (FD_ISSET(it->fd, &m_set)) {
m_s1ap_log->info("Timer expired\n"); m_s1ap_logger.info("Timer expired");
uint64_t exp; uint64_t exp;
rd_sz = read(it->fd, &exp, sizeof(uint64_t)); rd_sz = read(it->fd, &exp, sizeof(uint64_t));
m_s1ap->expire_nas_timer(it->type, it->imsi); m_s1ap->expire_nas_timer(it->type, it->imsi);
@ -178,7 +170,7 @@ void mme::run_thread()
} }
} }
} else { } else {
m_s1ap_log->debug("No data from select.\n"); m_s1ap_logger.debug("No data from select.");
} }
} }
return; return;
@ -189,7 +181,7 @@ void mme::run_thread()
*/ */
bool mme::add_nas_timer(int timer_fd, nas_timer_type type, uint64_t imsi) bool mme::add_nas_timer(int timer_fd, nas_timer_type type, uint64_t imsi)
{ {
m_s1ap_log->debug("Adding NAS timer to MME. IMSI %" PRIu64 ", Type %d, Fd: %d\n", imsi, type, timer_fd); m_s1ap_logger.debug("Adding NAS timer to MME. IMSI %" PRIu64 ", Type %d, Fd: %d", imsi, type, timer_fd);
mme_timer_t timer; mme_timer_t timer;
timer.fd = timer_fd; timer.fd = timer_fd;
@ -220,12 +212,12 @@ bool mme::remove_nas_timer(nas_timer_type type, uint64_t imsi)
} }
} }
if (it == timers.end()) { if (it == timers.end()) {
m_s1ap_log->warning("Could not find timer to remove. IMSI %" PRIu64 ", Type %d\n", imsi, type); m_s1ap_logger.warning("Could not find timer to remove. IMSI %" PRIu64 ", Type %d", imsi, type);
return false; return false;
} }
// removing timer // removing timer
m_s1ap_log->debug("Removing NAS timer from MME. IMSI %" PRIu64 ", Type %d, Fd: %d\n", imsi, type, it->fd); m_s1ap_logger.debug("Removing NAS timer from MME. IMSI %" PRIu64 ", Type %d, Fd: %d", imsi, type, it->fd);
FD_CLR(it->fd, &m_set); FD_CLR(it->fd, &m_set);
close(it->fd); close(it->fd);
timers.erase(it); timers.erase(it);

@ -24,21 +24,18 @@ mme_gtpc* mme_gtpc::get_instance()
return instance.get(); return instance.get();
} }
bool mme_gtpc::init(srslte::log_filter* mme_gtpc_log) bool mme_gtpc::init()
{ {
/*Init log*/
m_mme_gtpc_log = mme_gtpc_log;
m_next_ctrl_teid = 1; m_next_ctrl_teid = 1;
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
if (!init_s11()) { if (!init_s11()) {
m_mme_gtpc_log->error("Error Initializing MME S11 Interface\n"); m_logger.error("Error Initializing MME S11 Interface");
return false; return false;
} }
m_mme_gtpc_log->info("MME GTP-C Initialized\n"); m_logger.info("MME GTP-C Initialized");
srslte::console("MME GTP-C Initialized\n"); srslte::console("MME GTP-C Initialized\n");
return true; return true;
} }
@ -51,12 +48,12 @@ bool mme_gtpc::init_s11()
char spgw_addr_name[] = "@spgw_s11"; char spgw_addr_name[] = "@spgw_s11";
// Logs // Logs
m_mme_gtpc_log->info("Initializing MME S11 interface.\n"); m_logger.info("Initializing MME S11 interface.");
// Open Socket // Open Socket
m_s11 = socket(AF_UNIX, SOCK_DGRAM, 0); m_s11 = socket(AF_UNIX, SOCK_DGRAM, 0);
if (m_s11 < 0) { if (m_s11 < 0) {
m_mme_gtpc_log->error("Error opening UNIX socket. Error %s\n", strerror(errno)); m_logger.error("Error opening UNIX socket. Error %s", strerror(errno));
return false; return false;
} }
@ -68,7 +65,7 @@ bool mme_gtpc::init_s11()
// Bind socket to address // Bind socket to address
if (bind(m_s11, (const struct sockaddr*)&m_mme_addr, sizeof(m_mme_addr)) == -1) { if (bind(m_s11, (const struct sockaddr*)&m_mme_addr, sizeof(m_mme_addr)) == -1) {
m_mme_gtpc_log->error("Error binding UNIX socket. Error %s\n", strerror(errno)); m_logger.error("Error binding UNIX socket. Error %s", strerror(errno));
return false; return false;
} }
@ -78,7 +75,7 @@ bool mme_gtpc::init_s11()
snprintf(m_spgw_addr.sun_path, sizeof(m_spgw_addr.sun_path), "%s", spgw_addr_name); snprintf(m_spgw_addr.sun_path, sizeof(m_spgw_addr.sun_path), "%s", spgw_addr_name);
m_spgw_addr.sun_path[0] = '\0'; m_spgw_addr.sun_path[0] = '\0';
m_mme_gtpc_log->info("MME S11 Initialized\n"); m_logger.info("MME S11 Initialized");
srslte::console("MME S11 Initialized\n"); srslte::console("MME S11 Initialized\n");
return true; return true;
} }
@ -86,28 +83,28 @@ bool mme_gtpc::init_s11()
bool mme_gtpc::send_s11_pdu(const srslte::gtpc_pdu& pdu) bool mme_gtpc::send_s11_pdu(const srslte::gtpc_pdu& pdu)
{ {
int n; int n;
m_mme_gtpc_log->debug("Sending S-11 GTP-C PDU\n"); m_logger.debug("Sending S-11 GTP-C PDU");
// TODO Add GTP-C serialization code // TODO Add GTP-C serialization code
// Send S11 message to SPGW // Send S11 message to SPGW
n = sendto(m_s11, &pdu, sizeof(pdu), 0, (const sockaddr*)&m_spgw_addr, sizeof(m_spgw_addr)); n = sendto(m_s11, &pdu, sizeof(pdu), 0, (const sockaddr*)&m_spgw_addr, sizeof(m_spgw_addr));
if (n < 0) { if (n < 0) {
m_mme_gtpc_log->error("Error sending to socket. Error %s\n", strerror(errno)); m_logger.error("Error sending to socket. Error %s", strerror(errno));
srslte::console("Error sending to socket. Error %s\n", strerror(errno)); srslte::console("Error sending to socket. Error %s\n", strerror(errno));
return false; return false;
} else { } else {
m_mme_gtpc_log->debug("MME S11 Sent %d Bytes.\n", n); m_logger.debug("MME S11 Sent %d Bytes.", n);
} }
return true; return true;
} }
void mme_gtpc::handle_s11_pdu(srslte::byte_buffer_t* msg) void mme_gtpc::handle_s11_pdu(srslte::byte_buffer_t* msg)
{ {
m_mme_gtpc_log->debug("Received S11 message\n"); m_logger.debug("Received S11 message");
srslte::gtpc_pdu* pdu; srslte::gtpc_pdu* pdu;
pdu = (srslte::gtpc_pdu*)msg->msg; pdu = (srslte::gtpc_pdu*)msg->msg;
m_mme_gtpc_log->debug("MME Received GTP-C PDU. Message type %s\n", srslte::gtpc_msg_type_to_str(pdu->header.type)); m_logger.debug("MME Received GTP-C PDU. Message type %s", srslte::gtpc_msg_type_to_str(pdu->header.type));
switch (pdu->header.type) { switch (pdu->header.type) {
case srslte::GTPC_MSG_TYPE_CREATE_SESSION_RESPONSE: case srslte::GTPC_MSG_TYPE_CREATE_SESSION_RESPONSE:
handle_create_session_response(pdu); handle_create_session_response(pdu);
@ -119,14 +116,14 @@ void mme_gtpc::handle_s11_pdu(srslte::byte_buffer_t* msg)
handle_downlink_data_notification(pdu); handle_downlink_data_notification(pdu);
break; break;
default: default:
m_mme_gtpc_log->error("Unhandled GTP-C Message type\n"); m_logger.error("Unhandled GTP-C Message type");
} }
return; return;
} }
bool mme_gtpc::send_create_session_request(uint64_t imsi) bool mme_gtpc::send_create_session_request(uint64_t imsi)
{ {
m_mme_gtpc_log->info("Sending Create Session Request.\n"); m_logger.info("Sending Create Session Request.");
srslte::console("Sending Create Session Request.\n"); srslte::console("Sending Create Session Request.\n");
struct srslte::gtpc_pdu cs_req_pdu; struct srslte::gtpc_pdu cs_req_pdu;
// Initialize GTP-C message to zero // Initialize GTP-C message to zero
@ -145,8 +142,8 @@ bool mme_gtpc::send_create_session_request(uint64_t imsi)
// Control TEID allocated // Control TEID allocated
cs_req->sender_f_teid.teid = get_new_ctrl_teid(); cs_req->sender_f_teid.teid = get_new_ctrl_teid();
m_mme_gtpc_log->info("Next MME control TEID: %d\n", m_next_ctrl_teid); m_logger.info("Next MME control TEID: %d", m_next_ctrl_teid);
m_mme_gtpc_log->info("Allocated MME control TEID: %d\n", cs_req->sender_f_teid.teid); m_logger.info("Allocated MME control TEID: %d", cs_req->sender_f_teid.teid);
srslte::console("Creating Session Response -- IMSI: %" PRIu64 "\n", imsi); srslte::console("Creating Session Response -- IMSI: %" PRIu64 "\n", imsi);
srslte::console("Creating Session Response -- MME control TEID: %d\n", cs_req->sender_f_teid.teid); srslte::console("Creating Session Response -- MME control TEID: %d\n", cs_req->sender_f_teid.teid);
@ -163,12 +160,11 @@ bool mme_gtpc::send_create_session_request(uint64_t imsi)
// Check whether this UE is already registed // Check whether this UE is already registed
std::map<uint64_t, struct gtpc_ctx>::iterator it = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, struct gtpc_ctx>::iterator it = m_imsi_to_gtpc_ctx.find(imsi);
if (it != m_imsi_to_gtpc_ctx.end()) { if (it != m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->warning("Create Session Request being called for an UE with an active GTP-C connection.\n"); m_logger.warning("Create Session Request being called for an UE with an active GTP-C connection.");
m_mme_gtpc_log->warning("Deleting previous GTP-C connection.\n"); m_logger.warning("Deleting previous GTP-C connection.");
std::map<uint32_t, uint64_t>::iterator jt = m_mme_ctr_teid_to_imsi.find(it->second.mme_ctr_fteid.teid); std::map<uint32_t, uint64_t>::iterator jt = m_mme_ctr_teid_to_imsi.find(it->second.mme_ctr_fteid.teid);
if (jt == m_mme_ctr_teid_to_imsi.end()) { if (jt == m_mme_ctr_teid_to_imsi.end()) {
m_mme_gtpc_log->error("Could not find IMSI from MME Ctrl TEID. MME Ctr TEID: %d\n", m_logger.error("Could not find IMSI from MME Ctrl TEID. MME Ctr TEID: %d", it->second.mme_ctr_fteid.teid);
it->second.mme_ctr_fteid.teid);
} else { } else {
m_mme_ctr_teid_to_imsi.erase(jt); m_mme_ctr_teid_to_imsi.erase(jt);
} }
@ -194,15 +190,15 @@ bool mme_gtpc::send_create_session_request(uint64_t imsi)
bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu) bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu)
{ {
struct srslte::gtpc_create_session_response* cs_resp = &cs_resp_pdu->choice.create_session_response; struct srslte::gtpc_create_session_response* cs_resp = &cs_resp_pdu->choice.create_session_response;
m_mme_gtpc_log->info("Received Create Session Response\n"); m_logger.info("Received Create Session Response");
srslte::console("Received Create Session Response\n"); srslte::console("Received Create Session Response\n");
if (cs_resp_pdu->header.type != srslte::GTPC_MSG_TYPE_CREATE_SESSION_RESPONSE) { if (cs_resp_pdu->header.type != srslte::GTPC_MSG_TYPE_CREATE_SESSION_RESPONSE) {
m_mme_gtpc_log->warning("Could not create GTPC session. Not a create session response\n"); m_logger.warning("Could not create GTPC session. Not a create session response");
// TODO Handle error // TODO Handle error
return false; return false;
} }
if (cs_resp->cause.cause_value != srslte::GTPC_CAUSE_VALUE_REQUEST_ACCEPTED) { if (cs_resp->cause.cause_value != srslte::GTPC_CAUSE_VALUE_REQUEST_ACCEPTED) {
m_mme_gtpc_log->warning("Could not create GTPC session. Create Session Request not accepted\n"); m_logger.warning("Could not create GTPC session. Create Session Request not accepted");
// TODO Handle error // TODO Handle error
return false; return false;
} }
@ -210,12 +206,12 @@ bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu)
// Get IMSI from the control TEID // Get IMSI from the control TEID
std::map<uint32_t, uint64_t>::iterator id_it = m_mme_ctr_teid_to_imsi.find(cs_resp_pdu->header.teid); std::map<uint32_t, uint64_t>::iterator id_it = m_mme_ctr_teid_to_imsi.find(cs_resp_pdu->header.teid);
if (id_it == m_mme_ctr_teid_to_imsi.end()) { if (id_it == m_mme_ctr_teid_to_imsi.end()) {
m_mme_gtpc_log->warning("Could not find IMSI from Ctrl TEID.\n"); m_logger.warning("Could not find IMSI from Ctrl TEID.");
return false; return false;
} }
uint64_t imsi = id_it->second; uint64_t imsi = id_it->second;
m_mme_gtpc_log->info("MME GTPC Ctrl TEID %" PRIu64 ", IMSI %" PRIu64 "\n", cs_resp_pdu->header.teid, imsi); m_logger.info("MME GTPC Ctrl TEID %" PRIu64 ", IMSI %" PRIu64 "", cs_resp_pdu->header.teid, imsi);
// Get S-GW Control F-TEID // Get S-GW Control F-TEID
srslte::gtp_fteid_t sgw_ctr_fteid = {}; srslte::gtp_fteid_t sgw_ctr_fteid = {};
@ -224,30 +220,30 @@ bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu)
// Get S-GW S1-u F-TEID // Get S-GW S1-u F-TEID
if (cs_resp->eps_bearer_context_created.s1_u_sgw_f_teid_present == false) { if (cs_resp->eps_bearer_context_created.s1_u_sgw_f_teid_present == false) {
m_mme_gtpc_log->error("Did not receive SGW S1-U F-TEID in create session response\n"); m_logger.error("Did not receive SGW S1-U F-TEID in create session response");
return false; return false;
} }
srslte::console("Create Session Response -- SPGW control TEID %d\n", sgw_ctr_fteid.teid); srslte::console("Create Session Response -- SPGW control TEID %d\n", sgw_ctr_fteid.teid);
m_mme_gtpc_log->info("Create Session Response -- SPGW control TEID %d\n", sgw_ctr_fteid.teid); m_logger.info("Create Session Response -- SPGW control TEID %d", sgw_ctr_fteid.teid);
in_addr s1u_addr; in_addr s1u_addr;
s1u_addr.s_addr = cs_resp->eps_bearer_context_created.s1_u_sgw_f_teid.ipv4; s1u_addr.s_addr = cs_resp->eps_bearer_context_created.s1_u_sgw_f_teid.ipv4;
srslte::console("Create Session Response -- SPGW S1-U Address: %s\n", inet_ntoa(s1u_addr)); srslte::console("Create Session Response -- SPGW S1-U Address: %s\n", inet_ntoa(s1u_addr));
m_mme_gtpc_log->info("Create Session Response -- SPGW S1-U Address: %s\n", inet_ntoa(s1u_addr)); m_logger.info("Create Session Response -- SPGW S1-U Address: %s", inet_ntoa(s1u_addr));
// Check UE Ipv4 address was allocated // Check UE Ipv4 address was allocated
if (cs_resp->paa_present != true) { if (cs_resp->paa_present != true) {
m_mme_gtpc_log->error("PDN Adress Allocation not present\n"); m_logger.error("PDN Adress Allocation not present");
return false; return false;
} }
if (cs_resp->paa.pdn_type != srslte::GTPC_PDN_TYPE_IPV4) { if (cs_resp->paa.pdn_type != srslte::GTPC_PDN_TYPE_IPV4) {
m_mme_gtpc_log->error("IPv6 not supported yet\n"); m_logger.error("IPv6 not supported yet");
return false; return false;
} }
// Save create session response info to E-RAB context // Save create session response info to E-RAB context
nas* nas_ctx = m_s1ap->find_nas_ctx_from_imsi(imsi); nas* nas_ctx = m_s1ap->find_nas_ctx_from_imsi(imsi);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_mme_gtpc_log->error("Could not find UE context. IMSI %015" PRIu64 "\n", imsi); m_logger.error("Could not find UE context. IMSI %015" PRIu64 "", imsi);
return false; return false;
} }
emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx; emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx;
@ -261,7 +257,7 @@ bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu)
std::map<uint64_t, struct gtpc_ctx>::iterator it_g = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, struct gtpc_ctx>::iterator it_g = m_imsi_to_gtpc_ctx.find(imsi);
if (it_g == m_imsi_to_gtpc_ctx.end()) { if (it_g == m_imsi_to_gtpc_ctx.end()) {
// Could not find GTP-C Context // Could not find GTP-C Context
m_mme_gtpc_log->error("Could not find GTP-C context\n"); m_logger.error("Could not find GTP-C context");
return false; return false;
} }
gtpc_ctx_t* gtpc_ctx = &it_g->second; gtpc_ctx_t* gtpc_ctx = &it_g->second;
@ -279,13 +275,13 @@ bool mme_gtpc::handle_create_session_response(srslte::gtpc_pdu* cs_resp_pdu)
bool mme_gtpc::send_modify_bearer_request(uint64_t imsi, uint16_t erab_to_modify, srslte::gtp_fteid_t* enb_fteid) bool mme_gtpc::send_modify_bearer_request(uint64_t imsi, uint16_t erab_to_modify, srslte::gtp_fteid_t* enb_fteid)
{ {
m_mme_gtpc_log->info("Sending GTP-C Modify bearer request\n"); m_logger.info("Sending GTP-C Modify bearer request");
srslte::gtpc_pdu mb_req_pdu; srslte::gtpc_pdu mb_req_pdu;
std::memset(&mb_req_pdu, 0, sizeof(mb_req_pdu)); std::memset(&mb_req_pdu, 0, sizeof(mb_req_pdu));
std::map<uint64_t, gtpc_ctx_t>::iterator it = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, gtpc_ctx_t>::iterator it = m_imsi_to_gtpc_ctx.find(imsi);
if (it == m_imsi_to_gtpc_ctx.end()) { if (it == m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->error("Modify bearer request for UE without GTP-C connection\n"); m_logger.error("Modify bearer request for UE without GTP-C connection");
return false; return false;
} }
srslte::gtp_fteid_t sgw_ctr_fteid = it->second.sgw_ctr_fteid; srslte::gtp_fteid_t sgw_ctr_fteid = it->second.sgw_ctr_fteid;
@ -300,10 +296,10 @@ bool mme_gtpc::send_modify_bearer_request(uint64_t imsi, uint16_t erab_to_modify
mb_req->eps_bearer_context_to_modify.s1_u_enb_f_teid.ipv4 = enb_fteid->ipv4; mb_req->eps_bearer_context_to_modify.s1_u_enb_f_teid.ipv4 = enb_fteid->ipv4;
mb_req->eps_bearer_context_to_modify.s1_u_enb_f_teid.teid = enb_fteid->teid; mb_req->eps_bearer_context_to_modify.s1_u_enb_f_teid.teid = enb_fteid->teid;
m_mme_gtpc_log->info("GTP-C Modify bearer request -- S-GW Control TEID %d\n", sgw_ctr_fteid.teid); m_logger.info("GTP-C Modify bearer request -- S-GW Control TEID %d", sgw_ctr_fteid.teid);
struct in_addr addr; struct in_addr addr;
addr.s_addr = enb_fteid->ipv4; addr.s_addr = enb_fteid->ipv4;
m_mme_gtpc_log->info("GTP-C Modify bearer request -- S1-U TEID 0x%x, IP %s\n", enb_fteid->teid, inet_ntoa(addr)); m_logger.info("GTP-C Modify bearer request -- S1-U TEID 0x%x, IP %s", enb_fteid->teid, inet_ntoa(addr));
// Send msg to SPGW // Send msg to SPGW
send_s11_pdu(mb_req_pdu); send_s11_pdu(mb_req_pdu);
@ -315,12 +311,12 @@ void mme_gtpc::handle_modify_bearer_response(srslte::gtpc_pdu* mb_resp_pdu)
uint32_t mme_ctrl_teid = mb_resp_pdu->header.teid; uint32_t mme_ctrl_teid = mb_resp_pdu->header.teid;
std::map<uint32_t, uint64_t>::iterator imsi_it = m_mme_ctr_teid_to_imsi.find(mme_ctrl_teid); std::map<uint32_t, uint64_t>::iterator imsi_it = m_mme_ctr_teid_to_imsi.find(mme_ctrl_teid);
if (imsi_it == m_mme_ctr_teid_to_imsi.end()) { if (imsi_it == m_mme_ctr_teid_to_imsi.end()) {
m_mme_gtpc_log->error("Could not find IMSI from control TEID\n"); m_logger.error("Could not find IMSI from control TEID");
return; return;
} }
uint8_t ebi = mb_resp_pdu->choice.modify_bearer_response.eps_bearer_context_modified.ebi; uint8_t ebi = mb_resp_pdu->choice.modify_bearer_response.eps_bearer_context_modified.ebi;
m_mme_gtpc_log->debug("Activating EPS bearer with id %d\n", ebi); m_logger.debug("Activating EPS bearer with id %d", ebi);
m_s1ap->activate_eps_bearer(imsi_it->second, ebi); m_s1ap->activate_eps_bearer(imsi_it->second, ebi);
return; return;
@ -328,7 +324,7 @@ void mme_gtpc::handle_modify_bearer_response(srslte::gtpc_pdu* mb_resp_pdu)
bool mme_gtpc::send_delete_session_request(uint64_t imsi) bool mme_gtpc::send_delete_session_request(uint64_t imsi)
{ {
m_mme_gtpc_log->info("Sending GTP-C Delete Session Request request. IMSI %" PRIu64 "\n", imsi); m_logger.info("Sending GTP-C Delete Session Request request. IMSI %" PRIu64 "", imsi);
srslte::gtpc_pdu del_req_pdu; srslte::gtpc_pdu del_req_pdu;
std::memset(&del_req_pdu, 0, sizeof(del_req_pdu)); std::memset(&del_req_pdu, 0, sizeof(del_req_pdu));
srslte::gtp_fteid_t sgw_ctr_fteid; srslte::gtp_fteid_t sgw_ctr_fteid;
@ -337,7 +333,7 @@ bool mme_gtpc::send_delete_session_request(uint64_t imsi)
// Get S-GW Ctr TEID // Get S-GW Ctr TEID
std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi);
if (it_ctx == m_imsi_to_gtpc_ctx.end()) { if (it_ctx == m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->error("Could not find GTP-C context to remove\n"); m_logger.error("Could not find GTP-C context to remove");
return false; return false;
} }
@ -350,7 +346,7 @@ bool mme_gtpc::send_delete_session_request(uint64_t imsi)
srslte::gtpc_delete_session_request* del_req = &del_req_pdu.choice.delete_session_request; srslte::gtpc_delete_session_request* del_req = &del_req_pdu.choice.delete_session_request;
del_req->cause.cause_value = srslte::GTPC_CAUSE_VALUE_ISR_DEACTIVATION; del_req->cause.cause_value = srslte::GTPC_CAUSE_VALUE_ISR_DEACTIVATION;
m_mme_gtpc_log->info("GTP-C Delete Session Request -- S-GW Control TEID %d\n", sgw_ctr_fteid.teid); m_logger.info("GTP-C Delete Session Request -- S-GW Control TEID %d", sgw_ctr_fteid.teid);
// Send msg to SPGW // Send msg to SPGW
send_s11_pdu(del_req_pdu); send_s11_pdu(del_req_pdu);
@ -358,7 +354,7 @@ bool mme_gtpc::send_delete_session_request(uint64_t imsi)
// Delete GTP-C context // Delete GTP-C context
std::map<uint32_t, uint64_t>::iterator it_imsi = m_mme_ctr_teid_to_imsi.find(mme_ctr_fteid.teid); std::map<uint32_t, uint64_t>::iterator it_imsi = m_mme_ctr_teid_to_imsi.find(mme_ctr_fteid.teid);
if (it_imsi == m_mme_ctr_teid_to_imsi.end()) { if (it_imsi == m_mme_ctr_teid_to_imsi.end()) {
m_mme_gtpc_log->error("Could not find IMSI from MME ctr TEID"); m_logger.error("Could not find IMSI from MME ctr TEID");
} else { } else {
m_mme_ctr_teid_to_imsi.erase(it_imsi); m_mme_ctr_teid_to_imsi.erase(it_imsi);
} }
@ -369,7 +365,7 @@ bool mme_gtpc::send_delete_session_request(uint64_t imsi)
void mme_gtpc::send_release_access_bearers_request(uint64_t imsi) void mme_gtpc::send_release_access_bearers_request(uint64_t imsi)
{ {
// The GTP-C connection will not be torn down, just the user plane bearers. // The GTP-C connection will not be torn down, just the user plane bearers.
m_mme_gtpc_log->info("Sending GTP-C Release Access Bearers Request\n"); m_logger.info("Sending GTP-C Release Access Bearers Request");
srslte::gtpc_pdu rel_req_pdu; srslte::gtpc_pdu rel_req_pdu;
std::memset(&rel_req_pdu, 0, sizeof(rel_req_pdu)); std::memset(&rel_req_pdu, 0, sizeof(rel_req_pdu));
srslte::gtp_fteid_t sgw_ctr_fteid; srslte::gtp_fteid_t sgw_ctr_fteid;
@ -377,7 +373,7 @@ void mme_gtpc::send_release_access_bearers_request(uint64_t imsi)
// Get S-GW Ctr TEID // Get S-GW Ctr TEID
std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi);
if (it_ctx == m_imsi_to_gtpc_ctx.end()) { if (it_ctx == m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->error("Could not find GTP-C context to remove\n"); m_logger.error("Could not find GTP-C context to remove");
return; return;
} }
sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid; sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid;
@ -389,7 +385,7 @@ void mme_gtpc::send_release_access_bearers_request(uint64_t imsi)
header->type = srslte::GTPC_MSG_TYPE_RELEASE_ACCESS_BEARERS_REQUEST; header->type = srslte::GTPC_MSG_TYPE_RELEASE_ACCESS_BEARERS_REQUEST;
srslte::gtpc_release_access_bearers_request* rel_req = &rel_req_pdu.choice.release_access_bearers_request; srslte::gtpc_release_access_bearers_request* rel_req = &rel_req_pdu.choice.release_access_bearers_request;
m_mme_gtpc_log->info("GTP-C Release Access Berarers Request -- S-GW Control TEID %d\n", sgw_ctr_fteid.teid); m_logger.info("GTP-C Release Access Berarers Request -- S-GW Control TEID %d", sgw_ctr_fteid.teid);
// Send msg to SPGW // Send msg to SPGW
send_s11_pdu(rel_req_pdu); send_s11_pdu(rel_req_pdu);
@ -403,16 +399,16 @@ bool mme_gtpc::handle_downlink_data_notification(srslte::gtpc_pdu* dl_not_pdu)
srslte::gtpc_downlink_data_notification* dl_not = &dl_not_pdu->choice.downlink_data_notification; srslte::gtpc_downlink_data_notification* dl_not = &dl_not_pdu->choice.downlink_data_notification;
std::map<uint32_t, uint64_t>::iterator imsi_it = m_mme_ctr_teid_to_imsi.find(mme_ctrl_teid); std::map<uint32_t, uint64_t>::iterator imsi_it = m_mme_ctr_teid_to_imsi.find(mme_ctrl_teid);
if (imsi_it == m_mme_ctr_teid_to_imsi.end()) { if (imsi_it == m_mme_ctr_teid_to_imsi.end()) {
m_mme_gtpc_log->error("Could not find IMSI from control TEID\n"); m_logger.error("Could not find IMSI from control TEID");
return false; return false;
} }
if (!dl_not->eps_bearer_id_present) { if (!dl_not->eps_bearer_id_present) {
m_mme_gtpc_log->error("No EPS bearer Id in downlink data notification\n"); m_logger.error("No EPS bearer Id in downlink data notification");
return false; return false;
} }
uint8_t ebi = dl_not->eps_bearer_id; uint8_t ebi = dl_not->eps_bearer_id;
m_mme_gtpc_log->debug("Downlink Data Notification -- IMSI: %015" PRIu64 ", EBI %d\n", imsi_it->second, ebi); m_logger.debug("Downlink Data Notification -- IMSI: %015" PRIu64 ", EBI %d", imsi_it->second, ebi);
m_s1ap->send_paging(imsi_it->second, ebi); m_s1ap->send_paging(imsi_it->second, ebi);
return true; return true;
@ -420,7 +416,7 @@ bool mme_gtpc::handle_downlink_data_notification(srslte::gtpc_pdu* dl_not_pdu)
void mme_gtpc::send_downlink_data_notification_acknowledge(uint64_t imsi, enum srslte::gtpc_cause_value cause) void mme_gtpc::send_downlink_data_notification_acknowledge(uint64_t imsi, enum srslte::gtpc_cause_value cause)
{ {
m_mme_gtpc_log->debug("Sending GTP-C Data Notification Acknowledge. Cause %d\n", cause); m_logger.debug("Sending GTP-C Data Notification Acknowledge. Cause %d", cause);
srslte::gtpc_pdu not_ack_pdu; srslte::gtpc_pdu not_ack_pdu;
srslte::gtp_fteid_t sgw_ctr_fteid; srslte::gtp_fteid_t sgw_ctr_fteid;
std::memset(&not_ack_pdu, 0, sizeof(not_ack_pdu)); std::memset(&not_ack_pdu, 0, sizeof(not_ack_pdu));
@ -428,7 +424,7 @@ void mme_gtpc::send_downlink_data_notification_acknowledge(uint64_t imsi, enum s
// get s-gw ctr teid // get s-gw ctr teid
std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi);
if (it_ctx == m_imsi_to_gtpc_ctx.end()) { if (it_ctx == m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->error("could not find gtp-c context to remove\n"); m_logger.error("could not find gtp-c context to remove");
return; return;
} }
sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid; sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid;
@ -441,7 +437,7 @@ void mme_gtpc::send_downlink_data_notification_acknowledge(uint64_t imsi, enum s
srslte::gtpc_downlink_data_notification_acknowledge* not_ack = srslte::gtpc_downlink_data_notification_acknowledge* not_ack =
&not_ack_pdu.choice.downlink_data_notification_acknowledge; &not_ack_pdu.choice.downlink_data_notification_acknowledge;
m_mme_gtpc_log->info("gtp-c downlink data notification acknowledge -- s-gw control teid %d\n", sgw_ctr_fteid.teid); m_logger.info("gtp-c downlink data notification acknowledge -- s-gw control teid %d", sgw_ctr_fteid.teid);
// send msg to spgw // send msg to spgw
send_s11_pdu(not_ack_pdu); send_s11_pdu(not_ack_pdu);
@ -450,7 +446,7 @@ void mme_gtpc::send_downlink_data_notification_acknowledge(uint64_t imsi, enum s
bool mme_gtpc::send_downlink_data_notification_failure_indication(uint64_t imsi, enum srslte::gtpc_cause_value cause) bool mme_gtpc::send_downlink_data_notification_failure_indication(uint64_t imsi, enum srslte::gtpc_cause_value cause)
{ {
m_mme_gtpc_log->debug("Sending GTP-C Data Notification Failure Indication. Cause %d\n", cause); m_logger.debug("Sending GTP-C Data Notification Failure Indication. Cause %d", cause);
srslte::gtpc_pdu not_fail_pdu; srslte::gtpc_pdu not_fail_pdu;
srslte::gtp_fteid_t sgw_ctr_fteid; srslte::gtp_fteid_t sgw_ctr_fteid;
std::memset(&not_fail_pdu, 0, sizeof(not_fail_pdu)); std::memset(&not_fail_pdu, 0, sizeof(not_fail_pdu));
@ -458,7 +454,7 @@ bool mme_gtpc::send_downlink_data_notification_failure_indication(uint64_t imsi,
// get s-gw ctr teid // get s-gw ctr teid
std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi); std::map<uint64_t, gtpc_ctx_t>::iterator it_ctx = m_imsi_to_gtpc_ctx.find(imsi);
if (it_ctx == m_imsi_to_gtpc_ctx.end()) { if (it_ctx == m_imsi_to_gtpc_ctx.end()) {
m_mme_gtpc_log->error("could not find gtp-c context to send paging failure\n"); m_logger.error("could not find gtp-c context to send paging failure");
return false; return false;
} }
sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid; sgw_ctr_fteid = it_ctx->second.sgw_ctr_fteid;
@ -472,7 +468,7 @@ bool mme_gtpc::send_downlink_data_notification_failure_indication(uint64_t imsi,
srslte::gtpc_downlink_data_notification_failure_indication* not_fail = srslte::gtpc_downlink_data_notification_failure_indication* not_fail =
&not_fail_pdu.choice.downlink_data_notification_failure_indication; &not_fail_pdu.choice.downlink_data_notification_failure_indication;
not_fail->cause.cause_value = cause; not_fail->cause.cause_value = cause;
m_mme_gtpc_log->info("Downlink Data Notification Failure Indication -- SP-GW control teid %d\n", sgw_ctr_fteid.teid); m_logger.info("Downlink Data Notification Failure Indication -- SP-GW control teid %d", sgw_ctr_fteid.teid);
// send msg to spgw // send msg to spgw
send_s11_pdu(not_fail_pdu); send_s11_pdu(not_fail_pdu);

File diff suppressed because it is too large Load Diff

@ -52,7 +52,7 @@ void s1ap::cleanup(void)
pthread_mutex_unlock(&s1ap_instance_mutex); pthread_mutex_unlock(&s1ap_instance_mutex);
} }
int s1ap::init(s1ap_args_t s1ap_args, srslte::log_filter* nas_log, srslte::log_filter* s1ap_log) int s1ap::init(s1ap_args_t s1ap_args)
{ {
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
@ -60,10 +60,6 @@ int s1ap::init(s1ap_args_t s1ap_args, srslte::log_filter* nas_log, srslte::log_f
srslte::s1ap_mccmnc_to_plmn(s1ap_args.mcc, s1ap_args.mnc, &m_plmn); srslte::s1ap_mccmnc_to_plmn(s1ap_args.mcc, s1ap_args.mnc, &m_plmn);
m_next_m_tmsi = rand(); m_next_m_tmsi = rand();
// Init log
m_nas_log = nas_log;
m_s1ap_log = s1ap_log;
// Get pointer to the HSS // Get pointer to the HSS
m_hss = hss::get_instance(); m_hss = hss::get_instance();
@ -89,7 +85,7 @@ int s1ap::init(s1ap_args_t s1ap_args, srslte::log_filter* nas_log, srslte::log_f
if (m_pcap_enable) { if (m_pcap_enable) {
m_pcap.open(s1ap_args.pcap_filename.c_str()); m_pcap.open(s1ap_args.pcap_filename.c_str());
} }
m_s1ap_log->info("S1AP Initialized\n"); m_logger.info("S1AP Initialized");
return 0; return 0;
} }
@ -100,7 +96,7 @@ void s1ap::stop()
} }
std::map<uint16_t, enb_ctx_t*>::iterator enb_it = m_active_enbs.begin(); std::map<uint16_t, enb_ctx_t*>::iterator enb_it = m_active_enbs.begin();
while (enb_it != m_active_enbs.end()) { while (enb_it != m_active_enbs.end()) {
m_s1ap_log->info("Deleting eNB context. eNB Id: 0x%x\n", enb_it->second->enb_id); m_logger.info("Deleting eNB context. eNB Id: 0x%x", enb_it->second->enb_id);
srslte::console("Deleting eNB context. eNB Id: 0x%x\n", enb_it->second->enb_id); srslte::console("Deleting eNB context. eNB Id: 0x%x\n", enb_it->second->enb_id);
delete enb_it->second; delete enb_it->second;
m_active_enbs.erase(enb_it++); m_active_enbs.erase(enb_it++);
@ -108,7 +104,7 @@ void s1ap::stop()
std::map<uint64_t, nas*>::iterator ue_it = m_imsi_to_nas_ctx.begin(); std::map<uint64_t, nas*>::iterator ue_it = m_imsi_to_nas_ctx.begin();
while (ue_it != m_imsi_to_nas_ctx.end()) { while (ue_it != m_imsi_to_nas_ctx.end()) {
m_s1ap_log->info("Deleting UE EMM context. IMSI: %015" PRIu64 "\n", ue_it->first); m_logger.info("Deleting UE EMM context. IMSI: %015" PRIu64 "", ue_it->first);
srslte::console("Deleting UE EMM context. IMSI: %015" PRIu64 "\n", ue_it->first); srslte::console("Deleting UE EMM context. IMSI: %015" PRIu64 "\n", ue_it->first);
delete ue_it->second; delete ue_it->second;
m_imsi_to_nas_ctx.erase(ue_it++); m_imsi_to_nas_ctx.erase(ue_it++);
@ -143,7 +139,7 @@ int s1ap::enb_listen()
struct sockaddr_in s1mme_addr; struct sockaddr_in s1mme_addr;
struct sctp_event_subscribe evnts; struct sctp_event_subscribe evnts;
m_s1ap_log->info("S1-MME Initializing\n"); m_logger.info("S1-MME Initializing");
sock_fd = socket(AF_INET, SOCK_SEQPACKET, IPPROTO_SCTP); sock_fd = socket(AF_INET, SOCK_SEQPACKET, IPPROTO_SCTP);
if (sock_fd == -1) { if (sock_fd == -1) {
srslte::console("Could not create SCTP socket\n"); srslte::console("Could not create SCTP socket\n");
@ -169,7 +165,7 @@ int s1ap::enb_listen()
err = bind(sock_fd, (struct sockaddr*)&s1mme_addr, sizeof(s1mme_addr)); err = bind(sock_fd, (struct sockaddr*)&s1mme_addr, sizeof(s1mme_addr));
if (err != 0) { if (err != 0) {
close(sock_fd); close(sock_fd);
m_s1ap_log->error("Error binding SCTP socket\n"); m_logger.error("Error binding SCTP socket");
srslte::console("Error binding SCTP socket\n"); srslte::console("Error binding SCTP socket\n");
return -1; return -1;
} }
@ -178,7 +174,7 @@ int s1ap::enb_listen()
err = listen(sock_fd, SOMAXCONN); err = listen(sock_fd, SOMAXCONN);
if (err != 0) { if (err != 0) {
close(sock_fd); close(sock_fd);
m_s1ap_log->error("Error in SCTP socket listen\n"); m_logger.error("Error in SCTP socket listen");
srslte::console("Error in SCTP socket listen\n"); srslte::console("Error in SCTP socket listen\n");
return -1; return -1;
} }
@ -188,16 +184,16 @@ int s1ap::enb_listen()
bool s1ap::s1ap_tx_pdu(const asn1::s1ap::s1ap_pdu_c& pdu, struct sctp_sndrcvinfo* enb_sri) bool s1ap::s1ap_tx_pdu(const asn1::s1ap::s1ap_pdu_c& pdu, struct sctp_sndrcvinfo* enb_sri)
{ {
m_s1ap_log->debug("Transmitting S1AP PDU. eNB SCTP association Id: %d\n", enb_sri->sinfo_assoc_id); m_logger.debug("Transmitting S1AP PDU. eNB SCTP association Id: %d", enb_sri->sinfo_assoc_id);
srslte::unique_byte_buffer_t buf = srslte::allocate_unique_buffer(*m_pool); srslte::unique_byte_buffer_t buf = srslte::allocate_unique_buffer(*m_pool);
if (buf == nullptr) { if (buf == nullptr) {
m_s1ap_log->error("Fatal Error: Couldn't allocate buffer for S1AP PDU.\n"); m_logger.error("Fatal Error: Couldn't allocate buffer for S1AP PDU.");
return false; return false;
} }
asn1::bit_ref bref(buf->msg, buf->get_tailroom()); asn1::bit_ref bref(buf->msg, buf->get_tailroom());
if (pdu.pack(bref) != asn1::SRSASN_SUCCESS) { if (pdu.pack(bref) != asn1::SRSASN_SUCCESS) {
m_s1ap_log->error("Could not pack S1AP PDU correctly.\n"); m_logger.error("Could not pack S1AP PDU correctly.");
return false; return false;
} }
buf->N_bytes = bref.distance_bytes(); buf->N_bytes = bref.distance_bytes();
@ -205,7 +201,7 @@ bool s1ap::s1ap_tx_pdu(const asn1::s1ap::s1ap_pdu_c& pdu, struct sctp_sndrcvinfo
ssize_t n_sent = sctp_send(m_s1mme, buf->msg, buf->N_bytes, enb_sri, MSG_NOSIGNAL); ssize_t n_sent = sctp_send(m_s1mme, buf->msg, buf->N_bytes, enb_sri, MSG_NOSIGNAL);
if (n_sent == -1) { if (n_sent == -1) {
srslte::console("Failed to send S1AP PDU. Error: %s\n", strerror(errno)); srslte::console("Failed to send S1AP PDU. Error: %s\n", strerror(errno));
m_s1ap_log->error("Failed to send S1AP PDU. Error: %s \n", strerror(errno)); m_logger.error("Failed to send S1AP PDU. Error: %s ", strerror(errno));
return false; return false;
} }
@ -227,25 +223,25 @@ void s1ap::handle_s1ap_rx_pdu(srslte::byte_buffer_t* pdu, struct sctp_sndrcvinfo
s1ap_pdu_t rx_pdu; s1ap_pdu_t rx_pdu;
asn1::cbit_ref bref(pdu->msg, pdu->N_bytes); asn1::cbit_ref bref(pdu->msg, pdu->N_bytes);
if (rx_pdu.unpack(bref) != asn1::SRSASN_SUCCESS) { if (rx_pdu.unpack(bref) != asn1::SRSASN_SUCCESS) {
m_s1ap_log->error("Failed to unpack received PDU\n"); m_logger.error("Failed to unpack received PDU");
return; return;
} }
switch (rx_pdu.type().value) { switch (rx_pdu.type().value) {
case s1ap_pdu_t::types_opts::init_msg: case s1ap_pdu_t::types_opts::init_msg:
m_s1ap_log->info("Received Initiating PDU\n"); m_logger.info("Received Initiating PDU");
handle_initiating_message(rx_pdu.init_msg(), enb_sri); handle_initiating_message(rx_pdu.init_msg(), enb_sri);
break; break;
case s1ap_pdu_t::types_opts::successful_outcome: case s1ap_pdu_t::types_opts::successful_outcome:
m_s1ap_log->info("Received Succeseful Outcome PDU\n"); m_logger.info("Received Succeseful Outcome PDU");
handle_successful_outcome(rx_pdu.successful_outcome()); handle_successful_outcome(rx_pdu.successful_outcome());
break; break;
case s1ap_pdu_t::types_opts::unsuccessful_outcome: case s1ap_pdu_t::types_opts::unsuccessful_outcome:
m_s1ap_log->info("Received Unsucceseful Outcome PDU\n"); m_logger.info("Received Unsucceseful Outcome PDU");
// TODO handle_unsuccessfuloutcome(&rx_pdu.choice.unsuccessfulOutcome); // TODO handle_unsuccessfuloutcome(&rx_pdu.choice.unsuccessfulOutcome);
break; break;
default: default:
m_s1ap_log->error("Unhandled PDU type %d\n", rx_pdu.type().value); m_logger.error("Unhandled PDU type %d", rx_pdu.type().value);
} }
} }
@ -255,23 +251,23 @@ void s1ap::handle_initiating_message(const asn1::s1ap::init_msg_s& msg, struct s
switch (msg.value.type().value) { switch (msg.value.type().value) {
case init_msg_type_opts_t::s1_setup_request: case init_msg_type_opts_t::s1_setup_request:
m_s1ap_log->info("Received S1 Setup Request.\n"); m_logger.info("Received S1 Setup Request.");
m_s1ap_mngmt_proc->handle_s1_setup_request(msg.value.s1_setup_request(), enb_sri); m_s1ap_mngmt_proc->handle_s1_setup_request(msg.value.s1_setup_request(), enb_sri);
break; break;
case init_msg_type_opts_t::init_ue_msg: case init_msg_type_opts_t::init_ue_msg:
m_s1ap_log->info("Received Initial UE Message.\n"); m_logger.info("Received Initial UE Message.");
m_s1ap_nas_transport->handle_initial_ue_message(msg.value.init_ue_msg(), enb_sri); m_s1ap_nas_transport->handle_initial_ue_message(msg.value.init_ue_msg(), enb_sri);
break; break;
case init_msg_type_opts_t::ul_nas_transport: case init_msg_type_opts_t::ul_nas_transport:
m_s1ap_log->info("Received Uplink NAS Transport Message.\n"); m_logger.info("Received Uplink NAS Transport Message.");
m_s1ap_nas_transport->handle_uplink_nas_transport(msg.value.ul_nas_transport(), enb_sri); m_s1ap_nas_transport->handle_uplink_nas_transport(msg.value.ul_nas_transport(), enb_sri);
break; break;
case init_msg_type_opts_t::ue_context_release_request: case init_msg_type_opts_t::ue_context_release_request:
m_s1ap_log->info("Received UE Context Release Request Message.\n"); m_logger.info("Received UE Context Release Request Message.");
m_s1ap_ctx_mngmt_proc->handle_ue_context_release_request(msg.value.ue_context_release_request(), enb_sri); m_s1ap_ctx_mngmt_proc->handle_ue_context_release_request(msg.value.ue_context_release_request(), enb_sri);
break; break;
default: default:
m_s1ap_log->error("Unhandled S1AP intiating message: %s\n", msg.value.type().to_string().c_str()); m_logger.error("Unhandled S1AP intiating message: %s", msg.value.type().to_string().c_str());
srslte::console("Unhandled S1APintiating message: %s\n", msg.value.type().to_string().c_str()); srslte::console("Unhandled S1APintiating message: %s\n", msg.value.type().to_string().c_str());
} }
} }
@ -282,22 +278,22 @@ void s1ap::handle_successful_outcome(const asn1::s1ap::successful_outcome_s& msg
switch (msg.value.type().value) { switch (msg.value.type().value) {
case successful_outcome_type_opts_t::init_context_setup_resp: case successful_outcome_type_opts_t::init_context_setup_resp:
m_s1ap_log->info("Received Initial Context Setup Response.\n"); m_logger.info("Received Initial Context Setup Response.");
m_s1ap_ctx_mngmt_proc->handle_initial_context_setup_response(msg.value.init_context_setup_resp()); m_s1ap_ctx_mngmt_proc->handle_initial_context_setup_response(msg.value.init_context_setup_resp());
break; break;
case successful_outcome_type_opts_t::ue_context_release_complete: case successful_outcome_type_opts_t::ue_context_release_complete:
m_s1ap_log->info("Received UE Context Release Complete\n"); m_logger.info("Received UE Context Release Complete");
m_s1ap_ctx_mngmt_proc->handle_ue_context_release_complete(msg.value.ue_context_release_complete()); m_s1ap_ctx_mngmt_proc->handle_ue_context_release_complete(msg.value.ue_context_release_complete());
break; break;
default: default:
m_s1ap_log->error("Unhandled successful outcome message: %s\n", msg.value.type().to_string().c_str()); m_logger.error("Unhandled successful outcome message: %s", msg.value.type().to_string().c_str());
} }
} }
// eNB Context Managment // eNB Context Managment
void s1ap::add_new_enb_ctx(const enb_ctx_t& enb_ctx, const struct sctp_sndrcvinfo* enb_sri) void s1ap::add_new_enb_ctx(const enb_ctx_t& enb_ctx, const struct sctp_sndrcvinfo* enb_sri)
{ {
m_s1ap_log->info("Adding new eNB context. eNB ID %d\n", enb_ctx.enb_id); m_logger.info("Adding new eNB context. eNB ID %d", enb_ctx.enb_id);
std::set<uint32_t> ue_set; std::set<uint32_t> ue_set;
enb_ctx_t* enb_ptr = new enb_ctx_t; enb_ctx_t* enb_ptr = new enb_ctx_t;
*enb_ptr = enb_ctx; *enb_ptr = enb_ctx;
@ -323,11 +319,11 @@ void s1ap::delete_enb_ctx(int32_t assoc_id)
std::map<uint16_t, enb_ctx_t*>::iterator it_ctx = m_active_enbs.find(enb_id); std::map<uint16_t, enb_ctx_t*>::iterator it_ctx = m_active_enbs.find(enb_id);
if (it_ctx == m_active_enbs.end() || it_assoc == m_sctp_to_enb_id.end()) { if (it_ctx == m_active_enbs.end() || it_assoc == m_sctp_to_enb_id.end()) {
m_s1ap_log->error("Could not find eNB to delete. Association: %d\n", assoc_id); m_logger.error("Could not find eNB to delete. Association: %d", assoc_id);
return; return;
} }
m_s1ap_log->info("Deleting eNB context. eNB Id: 0x%x\n", enb_id); m_logger.info("Deleting eNB context. eNB Id: 0x%x", enb_id);
srslte::console("Deleting eNB context. eNB Id: 0x%x\n", enb_id); srslte::console("Deleting eNB context. eNB Id: 0x%x\n", enb_id);
// Delete connected UEs ctx // Delete connected UEs ctx
@ -345,41 +341,41 @@ bool s1ap::add_nas_ctx_to_imsi_map(nas* nas_ctx)
{ {
std::map<uint64_t, nas*>::iterator ctx_it = m_imsi_to_nas_ctx.find(nas_ctx->m_emm_ctx.imsi); std::map<uint64_t, nas*>::iterator ctx_it = m_imsi_to_nas_ctx.find(nas_ctx->m_emm_ctx.imsi);
if (ctx_it != m_imsi_to_nas_ctx.end()) { if (ctx_it != m_imsi_to_nas_ctx.end()) {
m_s1ap_log->error("UE Context already exists. IMSI %015" PRIu64 "\n", nas_ctx->m_emm_ctx.imsi); m_logger.error("UE Context already exists. IMSI %015" PRIu64 "", nas_ctx->m_emm_ctx.imsi);
return false; return false;
} }
if (nas_ctx->m_ecm_ctx.mme_ue_s1ap_id != 0) { if (nas_ctx->m_ecm_ctx.mme_ue_s1ap_id != 0) {
std::map<uint32_t, nas*>::iterator ctx_it2 = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id); std::map<uint32_t, nas*>::iterator ctx_it2 = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id);
if (ctx_it2 != m_mme_ue_s1ap_id_to_nas_ctx.end() && ctx_it2->second != nas_ctx) { if (ctx_it2 != m_mme_ue_s1ap_id_to_nas_ctx.end() && ctx_it2->second != nas_ctx) {
m_s1ap_log->error("Context identified with IMSI does not match context identified by MME UE S1AP Id.\n"); m_logger.error("Context identified with IMSI does not match context identified by MME UE S1AP Id.");
return false; return false;
} }
} }
m_imsi_to_nas_ctx.insert(std::pair<uint64_t, nas*>(nas_ctx->m_emm_ctx.imsi, nas_ctx)); m_imsi_to_nas_ctx.insert(std::pair<uint64_t, nas*>(nas_ctx->m_emm_ctx.imsi, nas_ctx));
m_s1ap_log->debug("Saved UE context corresponding to IMSI %015" PRIu64 "\n", nas_ctx->m_emm_ctx.imsi); m_logger.debug("Saved UE context corresponding to IMSI %015" PRIu64 "", nas_ctx->m_emm_ctx.imsi);
return true; return true;
} }
bool s1ap::add_nas_ctx_to_mme_ue_s1ap_id_map(nas* nas_ctx) bool s1ap::add_nas_ctx_to_mme_ue_s1ap_id_map(nas* nas_ctx)
{ {
if (nas_ctx->m_ecm_ctx.mme_ue_s1ap_id == 0) { if (nas_ctx->m_ecm_ctx.mme_ue_s1ap_id == 0) {
m_s1ap_log->error("Could not add UE context to MME UE S1AP map. MME UE S1AP ID 0 is not valid.\n"); m_logger.error("Could not add UE context to MME UE S1AP map. MME UE S1AP ID 0 is not valid.");
return false; return false;
} }
std::map<uint32_t, nas*>::iterator ctx_it = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id); std::map<uint32_t, nas*>::iterator ctx_it = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id);
if (ctx_it != m_mme_ue_s1ap_id_to_nas_ctx.end()) { if (ctx_it != m_mme_ue_s1ap_id_to_nas_ctx.end()) {
m_s1ap_log->error("UE Context already exists. MME UE S1AP Id %015" PRIu64 "\n", nas_ctx->m_emm_ctx.imsi); m_logger.error("UE Context already exists. MME UE S1AP Id %015" PRIu64 "", nas_ctx->m_emm_ctx.imsi);
return false; return false;
} }
if (nas_ctx->m_emm_ctx.imsi != 0) { if (nas_ctx->m_emm_ctx.imsi != 0) {
std::map<uint32_t, nas*>::iterator ctx_it2 = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id); std::map<uint32_t, nas*>::iterator ctx_it2 = m_mme_ue_s1ap_id_to_nas_ctx.find(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id);
if (ctx_it2 != m_mme_ue_s1ap_id_to_nas_ctx.end() && ctx_it2->second != nas_ctx) { if (ctx_it2 != m_mme_ue_s1ap_id_to_nas_ctx.end() && ctx_it2->second != nas_ctx) {
m_s1ap_log->error("Context identified with MME UE S1AP Id does not match context identified by IMSI.\n"); m_logger.error("Context identified with MME UE S1AP Id does not match context identified by IMSI.");
return false; return false;
} }
} }
m_mme_ue_s1ap_id_to_nas_ctx.insert(std::pair<uint32_t, nas*>(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id, nas_ctx)); m_mme_ue_s1ap_id_to_nas_ctx.insert(std::pair<uint32_t, nas*>(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id, nas_ctx));
m_s1ap_log->debug("Saved UE context corresponding to MME UE S1AP Id %d\n", nas_ctx->m_ecm_ctx.mme_ue_s1ap_id); m_logger.debug("Saved UE context corresponding to MME UE S1AP Id %d", nas_ctx->m_ecm_ctx.mme_ue_s1ap_id);
return true; return true;
} }
@ -387,16 +383,16 @@ bool s1ap::add_ue_to_enb_set(int32_t enb_assoc, uint32_t mme_ue_s1ap_id)
{ {
std::map<int32_t, std::set<uint32_t> >::iterator ues_in_enb = m_enb_assoc_to_ue_ids.find(enb_assoc); std::map<int32_t, std::set<uint32_t> >::iterator ues_in_enb = m_enb_assoc_to_ue_ids.find(enb_assoc);
if (ues_in_enb == m_enb_assoc_to_ue_ids.end()) { if (ues_in_enb == m_enb_assoc_to_ue_ids.end()) {
m_s1ap_log->error("Could not find eNB from eNB SCTP association %d\n", enb_assoc); m_logger.error("Could not find eNB from eNB SCTP association %d", enb_assoc);
return false; return false;
} }
std::set<uint32_t>::iterator ue_id = ues_in_enb->second.find(mme_ue_s1ap_id); std::set<uint32_t>::iterator ue_id = ues_in_enb->second.find(mme_ue_s1ap_id);
if (ue_id != ues_in_enb->second.end()) { if (ue_id != ues_in_enb->second.end()) {
m_s1ap_log->error("UE with MME UE S1AP Id already exists %d\n", mme_ue_s1ap_id); m_logger.error("UE with MME UE S1AP Id already exists %d", mme_ue_s1ap_id);
return false; return false;
} }
ues_in_enb->second.insert(mme_ue_s1ap_id); ues_in_enb->second.insert(mme_ue_s1ap_id);
m_s1ap_log->debug("Added UE with MME-UE S1AP Id %d to eNB with association %d\n", mme_ue_s1ap_id, enb_assoc); m_logger.debug("Added UE with MME-UE S1AP Id %d to eNB with association %d", mme_ue_s1ap_id, enb_assoc);
return true; return true;
} }
@ -433,8 +429,8 @@ void s1ap::release_ues_ecm_ctx_in_enb(int32_t enb_assoc)
emm_ctx_t* emm_ctx = &nas_ctx->second->m_emm_ctx; emm_ctx_t* emm_ctx = &nas_ctx->second->m_emm_ctx;
ecm_ctx_t* ecm_ctx = &nas_ctx->second->m_ecm_ctx; ecm_ctx_t* ecm_ctx = &nas_ctx->second->m_ecm_ctx;
m_s1ap_log->info( m_logger.info(
"Releasing UE context. IMSI: %015" PRIu64 ", UE-MME S1AP Id: %d\n", emm_ctx->imsi, ecm_ctx->mme_ue_s1ap_id); "Releasing UE context. IMSI: %015" PRIu64 ", UE-MME S1AP Id: %d", emm_ctx->imsi, ecm_ctx->mme_ue_s1ap_id);
if (emm_ctx->state == EMM_STATE_REGISTERED) { if (emm_ctx->state == EMM_STATE_REGISTERED) {
m_mme_gtpc->send_delete_session_request(emm_ctx->imsi); m_mme_gtpc->send_delete_session_request(emm_ctx->imsi);
emm_ctx->state = EMM_STATE_DEREGISTERED; emm_ctx->state = EMM_STATE_DEREGISTERED;
@ -452,7 +448,7 @@ bool s1ap::release_ue_ecm_ctx(uint32_t mme_ue_s1ap_id)
{ {
nas* nas_ctx = find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_s1ap_log->error("Cannot release UE ECM context, UE not found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); m_logger.error("Cannot release UE ECM context, UE not found. MME-UE S1AP Id: %d", mme_ue_s1ap_id);
return false; return false;
} }
ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx; ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx;
@ -460,13 +456,13 @@ bool s1ap::release_ue_ecm_ctx(uint32_t mme_ue_s1ap_id)
// Delete UE within eNB UE set // Delete UE within eNB UE set
std::map<int32_t, uint16_t>::iterator it = m_sctp_to_enb_id.find(ecm_ctx->enb_sri.sinfo_assoc_id); std::map<int32_t, uint16_t>::iterator it = m_sctp_to_enb_id.find(ecm_ctx->enb_sri.sinfo_assoc_id);
if (it == m_sctp_to_enb_id.end()) { if (it == m_sctp_to_enb_id.end()) {
m_s1ap_log->error("Could not find eNB for UE release request.\n"); m_logger.error("Could not find eNB for UE release request.");
return false; return false;
} }
uint16_t enb_id = it->second; uint16_t enb_id = it->second;
std::map<int32_t, std::set<uint32_t> >::iterator ue_set = m_enb_assoc_to_ue_ids.find(ecm_ctx->enb_sri.sinfo_assoc_id); std::map<int32_t, std::set<uint32_t> >::iterator ue_set = m_enb_assoc_to_ue_ids.find(ecm_ctx->enb_sri.sinfo_assoc_id);
if (ue_set == m_enb_assoc_to_ue_ids.end()) { if (ue_set == m_enb_assoc_to_ue_ids.end()) {
m_s1ap_log->error("Could not find the eNB's UEs.\n"); m_logger.error("Could not find the eNB's UEs.");
return false; return false;
} }
ue_set->second.erase(mme_ue_s1ap_id); ue_set->second.erase(mme_ue_s1ap_id);
@ -477,7 +473,7 @@ bool s1ap::release_ue_ecm_ctx(uint32_t mme_ue_s1ap_id)
ecm_ctx->mme_ue_s1ap_id = 0; ecm_ctx->mme_ue_s1ap_id = 0;
ecm_ctx->enb_ue_s1ap_id = 0; ecm_ctx->enb_ue_s1ap_id = 0;
m_s1ap_log->info("Released UE ECM Context.\n"); m_logger.info("Released UE ECM Context.");
return true; return true;
} }
@ -485,7 +481,7 @@ bool s1ap::delete_ue_ctx(uint64_t imsi)
{ {
nas* nas_ctx = find_nas_ctx_from_imsi(imsi); nas* nas_ctx = find_nas_ctx_from_imsi(imsi);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_s1ap_log->info("Cannot delete UE context, UE not found. IMSI: %" PRIu64 "\n", imsi); m_logger.info("Cannot delete UE context, UE not found. IMSI: %" PRIu64 "", imsi);
return false; return false;
} }
@ -497,7 +493,7 @@ bool s1ap::delete_ue_ctx(uint64_t imsi)
// Delete UE context // Delete UE context
m_imsi_to_nas_ctx.erase(imsi); m_imsi_to_nas_ctx.erase(imsi);
delete nas_ctx; delete nas_ctx;
m_s1ap_log->info("Deleted UE Context.\n"); m_logger.info("Deleted UE Context.");
return true; return true;
} }
@ -506,22 +502,22 @@ void s1ap::activate_eps_bearer(uint64_t imsi, uint8_t ebi)
{ {
std::map<uint64_t, nas*>::iterator ue_ctx_it = m_imsi_to_nas_ctx.find(imsi); std::map<uint64_t, nas*>::iterator ue_ctx_it = m_imsi_to_nas_ctx.find(imsi);
if (ue_ctx_it == m_imsi_to_nas_ctx.end()) { if (ue_ctx_it == m_imsi_to_nas_ctx.end()) {
m_s1ap_log->error("Could not activate EPS bearer: Could not find UE context\n"); m_logger.error("Could not activate EPS bearer: Could not find UE context");
return; return;
} }
// Make sure NAS is active // Make sure NAS is active
uint32_t mme_ue_s1ap_id = ue_ctx_it->second->m_ecm_ctx.mme_ue_s1ap_id; uint32_t mme_ue_s1ap_id = ue_ctx_it->second->m_ecm_ctx.mme_ue_s1ap_id;
std::map<uint32_t, nas*>::iterator it = m_mme_ue_s1ap_id_to_nas_ctx.find(mme_ue_s1ap_id); std::map<uint32_t, nas*>::iterator it = m_mme_ue_s1ap_id_to_nas_ctx.find(mme_ue_s1ap_id);
if (it == m_mme_ue_s1ap_id_to_nas_ctx.end()) { if (it == m_mme_ue_s1ap_id_to_nas_ctx.end()) {
m_s1ap_log->error("Could not activate EPS bearer: ECM context seems to be missing\n"); m_logger.error("Could not activate EPS bearer: ECM context seems to be missing");
return; return;
} }
ecm_ctx_t* ecm_ctx = &ue_ctx_it->second->m_ecm_ctx; ecm_ctx_t* ecm_ctx = &ue_ctx_it->second->m_ecm_ctx;
esm_ctx_t* esm_ctx = &ue_ctx_it->second->m_esm_ctx[ebi]; esm_ctx_t* esm_ctx = &ue_ctx_it->second->m_esm_ctx[ebi];
if (esm_ctx->state != ERAB_CTX_SETUP) { if (esm_ctx->state != ERAB_CTX_SETUP) {
m_s1ap_log->error( m_logger.error(
"Could not be activate EPS Bearer, bearer in wrong state: MME S1AP Id %d, EPS Bearer id %d, state %d\n", "Could not be activate EPS Bearer, bearer in wrong state: MME S1AP Id %d, EPS Bearer id %d, state %d",
mme_ue_s1ap_id, mme_ue_s1ap_id,
ebi, ebi,
esm_ctx->state); esm_ctx->state);
@ -535,7 +531,7 @@ void s1ap::activate_eps_bearer(uint64_t imsi, uint8_t ebi)
esm_ctx->state = ERAB_ACTIVE; esm_ctx->state = ERAB_ACTIVE;
ecm_ctx->state = ECM_STATE_CONNECTED; ecm_ctx->state = ECM_STATE_CONNECTED;
m_s1ap_log->info("Activated EPS Bearer: Bearer id %d\n", ebi); m_logger.info("Activated EPS Bearer: Bearer id %d", ebi);
return; return;
} }
@ -545,7 +541,7 @@ uint32_t s1ap::allocate_m_tmsi(uint64_t imsi)
m_next_m_tmsi = (m_next_m_tmsi + 1) % UINT32_MAX; m_next_m_tmsi = (m_next_m_tmsi + 1) % UINT32_MAX;
m_tmsi_to_imsi.insert(std::pair<uint32_t, uint64_t>(m_tmsi, imsi)); m_tmsi_to_imsi.insert(std::pair<uint32_t, uint64_t>(m_tmsi, imsi));
m_s1ap_log->debug("Allocated M-TMSI 0x%x to IMSI %015" PRIu64 ",\n", m_tmsi, imsi); m_logger.debug("Allocated M-TMSI 0x%x to IMSI %015" PRIu64 ",", m_tmsi, imsi);
return m_tmsi; return m_tmsi;
} }
@ -553,10 +549,10 @@ uint64_t s1ap::find_imsi_from_m_tmsi(uint32_t m_tmsi)
{ {
std::map<uint32_t, uint64_t>::iterator it = m_tmsi_to_imsi.find(m_tmsi); std::map<uint32_t, uint64_t>::iterator it = m_tmsi_to_imsi.find(m_tmsi);
if (it != m_tmsi_to_imsi.end()) { if (it != m_tmsi_to_imsi.end()) {
m_s1ap_log->debug("Found IMSI %015" PRIu64 " from M-TMSI 0x%x\n", it->second, m_tmsi); m_logger.debug("Found IMSI %015" PRIu64 " from M-TMSI 0x%x", it->second, m_tmsi);
return it->second; return it->second;
} else { } else {
m_s1ap_log->debug("Could not find IMSI from M-TMSI 0x%x\n", m_tmsi); m_logger.debug("Could not find IMSI from M-TMSI 0x%x", m_tmsi);
return 0; return 0;
} }
} }
@ -567,18 +563,18 @@ void s1ap::print_enb_ctx_info(const std::string& prefix, const enb_ctx_t& enb_ct
if (enb_ctx.enb_name_present) { if (enb_ctx.enb_name_present) {
srslte::console("%s - eNB Name: %s, eNB id: 0x%x\n", prefix.c_str(), enb_ctx.enb_name.c_str(), enb_ctx.enb_id); srslte::console("%s - eNB Name: %s, eNB id: 0x%x\n", prefix.c_str(), enb_ctx.enb_name.c_str(), enb_ctx.enb_id);
m_s1ap_log->info("%s - eNB Name: %s, eNB id: 0x%x\n", prefix.c_str(), enb_ctx.enb_name.c_str(), enb_ctx.enb_id); m_logger.info("%s - eNB Name: %s, eNB id: 0x%x", prefix.c_str(), enb_ctx.enb_name.c_str(), enb_ctx.enb_id);
} else { } else {
srslte::console("%s - eNB Id 0x%x\n", prefix.c_str(), enb_ctx.enb_id); srslte::console("%s - eNB Id 0x%x\n", prefix.c_str(), enb_ctx.enb_id);
m_s1ap_log->info("%s - eNB Id 0x%x\n", prefix.c_str(), enb_ctx.enb_id); m_logger.info("%s - eNB Id 0x%x", prefix.c_str(), enb_ctx.enb_id);
} }
srslte::mcc_to_string(enb_ctx.mcc, &mcc_str); srslte::mcc_to_string(enb_ctx.mcc, &mcc_str);
srslte::mnc_to_string(enb_ctx.mnc, &mnc_str); srslte::mnc_to_string(enb_ctx.mnc, &mnc_str);
m_s1ap_log->info("%s - MCC:%s, MNC:%s, PLMN: %d\n", prefix.c_str(), mcc_str.c_str(), mnc_str.c_str(), enb_ctx.plmn); m_logger.info("%s - MCC:%s, MNC:%s, PLMN: %d", prefix.c_str(), mcc_str.c_str(), mnc_str.c_str(), enb_ctx.plmn);
srslte::console("%s - MCC:%s, MNC:%s\n", prefix.c_str(), mcc_str.c_str(), mnc_str.c_str()); srslte::console("%s - MCC:%s, MNC:%s\n", prefix.c_str(), mcc_str.c_str(), mnc_str.c_str());
for (int i = 0; i < enb_ctx.nof_supported_ta; i++) { for (int i = 0; i < enb_ctx.nof_supported_ta; i++) {
for (int j = 0; i < enb_ctx.nof_supported_ta; i++) { for (int j = 0; i < enb_ctx.nof_supported_ta; i++) {
m_s1ap_log->info("%s - TAC %d, B-PLMN 0x%x\n", prefix.c_str(), enb_ctx.tacs[i], enb_ctx.bplmns[i][j]); m_logger.info("%s - TAC %d, B-PLMN 0x%x", prefix.c_str(), enb_ctx.tacs[i], enb_ctx.bplmns[i][j]);
srslte::console("%s - TAC %d, B-PLMN 0x%x\n", prefix.c_str(), enb_ctx.tacs[i], enb_ctx.bplmns[i][j]); srslte::console("%s - TAC %d, B-PLMN 0x%x\n", prefix.c_str(), enb_ctx.tacs[i], enb_ctx.bplmns[i][j]);
} }
} }
@ -602,7 +598,7 @@ bool s1ap::send_initial_context_setup_request(uint64_t imsi, uint16_t erab_to_se
{ {
nas* nas_ctx = find_nas_ctx_from_imsi(imsi); nas* nas_ctx = find_nas_ctx_from_imsi(imsi);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_s1ap_log->error("Error finding NAS context when sending initial context Setup Request\n"); m_logger.error("Error finding NAS context when sending initial context Setup Request");
return false; return false;
} }
m_s1ap_ctx_mngmt_proc->send_initial_context_setup_request(nas_ctx, erab_to_setup); m_s1ap_ctx_mngmt_proc->send_initial_context_setup_request(nas_ctx, erab_to_setup);
@ -614,7 +610,7 @@ bool s1ap::send_ue_context_release_command(uint32_t mme_ue_s1ap_id)
{ {
nas* nas_ctx = find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_s1ap_log->error("Error finding NAS context when sending UE Context Setup Release\n"); m_logger.error("Error finding NAS context when sending UE Context Setup Release");
return false; return false;
} }
m_s1ap_ctx_mngmt_proc->send_ue_context_release_command(nas_ctx); m_s1ap_ctx_mngmt_proc->send_ue_context_release_command(nas_ctx);
@ -652,7 +648,7 @@ bool s1ap::expire_nas_timer(enum nas_timer_type type, uint64_t imsi)
{ {
nas* nas_ctx = find_nas_ctx_from_imsi(imsi); nas* nas_ctx = find_nas_ctx_from_imsi(imsi);
if (nas_ctx == NULL) { if (nas_ctx == NULL) {
m_s1ap_log->error("Error finding NAS context to handle timer\n"); m_logger.error("Error finding NAS context to handle timer");
return false; return false;
} }
bool err = nas_ctx->expire_timer(type); bool err = nas_ctx->expire_timer(type);

@ -57,14 +57,13 @@ void s1ap_ctx_mngmt_proc::init()
{ {
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
m_mme_gtpc = mme_gtpc::get_instance(); m_mme_gtpc = mme_gtpc::get_instance();
m_s1ap_log = m_s1ap->m_s1ap_log;
m_s1ap_args = m_s1ap->m_s1ap_args; m_s1ap_args = m_s1ap->m_s1ap_args;
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
} }
bool s1ap_ctx_mngmt_proc::send_initial_context_setup_request(nas* nas_ctx, uint16_t erab_to_setup) bool s1ap_ctx_mngmt_proc::send_initial_context_setup_request(nas* nas_ctx, uint16_t erab_to_setup)
{ {
m_s1ap_log->info("Preparing to send Initial Context Setup request\n"); m_logger.info("Preparing to send Initial Context Setup request");
// Get UE Context/E-RAB Context to setup // Get UE Context/E-RAB Context to setup
emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx; emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx;
@ -130,13 +129,13 @@ bool s1ap_ctx_mngmt_proc::send_initial_context_setup_request(nas* nas_ctx, uint1
for (uint8_t i = 0; i < 32; ++i) { for (uint8_t i = 0; i < 32; ++i) {
in_ctx_req.security_key.value.data()[31 - i] = sec_ctx->k_enb[i]; in_ctx_req.security_key.value.data()[31 - i] = sec_ctx->k_enb[i];
} }
m_s1ap_log->info_hex(sec_ctx->k_enb, 32, "Initial Context Setup Request -- Key eNB (k_enb)\n"); m_logger.info(sec_ctx->k_enb, 32, "Initial Context Setup Request -- Key eNB (k_enb)");
srslte::unique_byte_buffer_t nas_buffer = allocate_unique_buffer(*m_pool); srslte::unique_byte_buffer_t nas_buffer = allocate_unique_buffer(*m_pool);
if (emm_ctx->state == EMM_STATE_DEREGISTERED) { if (emm_ctx->state == EMM_STATE_DEREGISTERED) {
// Attach procedure initiated from an attach request // Attach procedure initiated from an attach request
srslte::console("Adding attach accept to Initial Context Setup Request\n"); srslte::console("Adding attach accept to Initial Context Setup Request\n");
m_s1ap_log->info("Adding attach accept to Initial Context Setup Request\n"); m_logger.info("Adding attach accept to Initial Context Setup Request");
nas_ctx->pack_attach_accept(nas_buffer.get()); nas_ctx->pack_attach_accept(nas_buffer.get());
// Add nas message to context setup request // Add nas message to context setup request
@ -146,7 +145,7 @@ bool s1ap_ctx_mngmt_proc::send_initial_context_setup_request(nas* nas_ctx, uint1
} }
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &ecm_ctx->enb_sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &ecm_ctx->enb_sri)) {
m_s1ap_log->error("Error sending Initial Context Setup Request.\n"); m_logger.error("Error sending Initial Context Setup Request.");
return false; return false;
} }
@ -156,19 +155,19 @@ bool s1ap_ctx_mngmt_proc::send_initial_context_setup_request(nas* nas_ctx, uint1
struct in_addr addr; struct in_addr addr;
addr.s_addr = htonl(erab_ctx_req.transport_layer_address.to_number()); addr.s_addr = htonl(erab_ctx_req.transport_layer_address.to_number());
srslte::console("Sent Initial Context Setup Request. E-RAB id %d \n", erab_ctx_req.erab_id); srslte::console("Sent Initial Context Setup Request. E-RAB id %d \n", erab_ctx_req.erab_id);
m_s1ap_log->info( m_logger.info(
"Initial Context -- S1-U TEID 0x%" PRIx64 ". IP %s \n", erab_ctx_req.gtp_teid.to_number(), inet_ntoa(addr)); "Initial Context -- S1-U TEID 0x%" PRIx64 ". IP %s ", erab_ctx_req.gtp_teid.to_number(), inet_ntoa(addr));
m_s1ap_log->info("Initial Context Setup Request -- eNB UE S1AP Id %d, MME UE S1AP Id %" PRIu64 "\n", m_logger.info("Initial Context Setup Request -- eNB UE S1AP Id %d, MME UE S1AP Id %" PRIu64 "",
in_ctx_req.enb_ue_s1ap_id.value.value, in_ctx_req.enb_ue_s1ap_id.value.value,
in_ctx_req.mme_ue_s1ap_id.value.value); in_ctx_req.mme_ue_s1ap_id.value.value);
m_s1ap_log->info("Initial Context Setup Request -- E-RAB id %d\n", erab_ctx_req.erab_id); m_logger.info("Initial Context Setup Request -- E-RAB id %d", erab_ctx_req.erab_id);
m_s1ap_log->info("Initial Context Setup Request -- S1-U TEID 0x%" PRIu64 ". IP %s \n", m_logger.info("Initial Context Setup Request -- S1-U TEID 0x%" PRIu64 ". IP %s ",
erab_ctx_req.gtp_teid.to_number(), erab_ctx_req.gtp_teid.to_number(),
inet_ntoa(addr)); inet_ntoa(addr));
m_s1ap_log->info("Initial Context Setup Request -- S1-U TEID 0x%" PRIu64 ". IP %s \n", m_logger.info("Initial Context Setup Request -- S1-U TEID 0x%" PRIu64 ". IP %s ",
erab_ctx_req.gtp_teid.to_number(), erab_ctx_req.gtp_teid.to_number(),
inet_ntoa(addr)); inet_ntoa(addr));
m_s1ap_log->info("Initial Context Setup Request -- QCI %d\n", erab_ctx_req.erab_level_qos_params.qci); m_logger.info("Initial Context Setup Request -- QCI %d", erab_ctx_req.erab_level_qos_params.qci);
return true; return true;
} }
@ -178,7 +177,7 @@ bool s1ap_ctx_mngmt_proc::handle_initial_context_setup_response(
uint32_t mme_ue_s1ap_id = in_ctxt_resp.protocol_ies.mme_ue_s1ap_id.value.value; uint32_t mme_ue_s1ap_id = in_ctxt_resp.protocol_ies.mme_ue_s1ap_id.value.value;
nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == nullptr) { if (nas_ctx == nullptr) {
m_s1ap_log->error("Could not find UE's context in active UE's map\n"); m_logger.error("Could not find UE's context in active UE's map");
return false; return false;
} }
@ -199,7 +198,7 @@ bool s1ap_ctx_mngmt_proc::handle_initial_context_setup_response(
// Make sure we requested the context setup // Make sure we requested the context setup
esm_ctx_t* esm_ctx = &nas_ctx->m_esm_ctx[erab_id]; esm_ctx_t* esm_ctx = &nas_ctx->m_esm_ctx[erab_id];
if (esm_ctx->state != ERAB_CTX_REQUESTED) { if (esm_ctx->state != ERAB_CTX_REQUESTED) {
m_s1ap_log->error("E-RAB requested was not previously requested %d\n", erab_id); m_logger.error("E-RAB requested was not previously requested %d", erab_id);
return false; return false;
} }
@ -215,11 +214,11 @@ bool s1ap_ctx_mngmt_proc::handle_initial_context_setup_response(
tmp_addr.s_addr = esm_ctx->enb_fteid.ipv4; tmp_addr.s_addr = esm_ctx->enb_fteid.ipv4;
const char* err = inet_ntop(AF_INET, &tmp_addr, enb_addr_str, INET_ADDRSTRLEN); const char* err = inet_ntop(AF_INET, &tmp_addr, enb_addr_str, INET_ADDRSTRLEN);
if (err == nullptr) { if (err == nullptr) {
m_s1ap_log->error("Error converting IP to string\n"); m_logger.error("Error converting IP to string");
} }
m_s1ap_log->info("E-RAB Context Setup. E-RAB id %d\n", esm_ctx->erab_id); m_logger.info("E-RAB Context Setup. E-RAB id %d", esm_ctx->erab_id);
m_s1ap_log->info("E-RAB Context -- eNB TEID 0x%x, eNB Address %s\n", esm_ctx->enb_fteid.teid, enb_addr_str); m_logger.info("E-RAB Context -- eNB TEID 0x%x, eNB Address %s", esm_ctx->enb_fteid.teid, enb_addr_str);
srslte::console("E-RAB Context Setup. E-RAB id %d\n", esm_ctx->erab_id); srslte::console("E-RAB Context Setup. E-RAB id %d\n", esm_ctx->erab_id);
srslte::console("E-RAB Context -- eNB TEID 0x%x; eNB GTP-U Address %s\n", esm_ctx->enb_fteid.teid, enb_addr_str); srslte::console("E-RAB Context -- eNB TEID 0x%x; eNB GTP-U Address %s\n", esm_ctx->enb_fteid.teid, enb_addr_str);
} }
@ -236,12 +235,12 @@ bool s1ap_ctx_mngmt_proc::handle_ue_context_release_request(const asn1::s1ap::ue
struct sctp_sndrcvinfo* enb_sri) struct sctp_sndrcvinfo* enb_sri)
{ {
uint32_t mme_ue_s1ap_id = ue_rel.protocol_ies.mme_ue_s1ap_id.value.value; uint32_t mme_ue_s1ap_id = ue_rel.protocol_ies.mme_ue_s1ap_id.value.value;
m_s1ap_log->info("Received UE Context Release Request. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); m_logger.info("Received UE Context Release Request. MME-UE S1AP Id: %d", mme_ue_s1ap_id);
srslte::console("Received UE Context Release Request. MME-UE S1AP Id %d\n", mme_ue_s1ap_id); srslte::console("Received UE Context Release Request. MME-UE S1AP Id %d\n", mme_ue_s1ap_id);
nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == nullptr) { if (nas_ctx == nullptr) {
m_s1ap_log->info("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); m_logger.info("No UE context to release found. MME-UE S1AP Id: %d", mme_ue_s1ap_id);
srslte::console("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); srslte::console("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id);
return false; return false;
} }
@ -254,7 +253,7 @@ bool s1ap_ctx_mngmt_proc::handle_ue_context_release_request(const asn1::s1ap::ue
send_ue_context_release_command(nas_ctx); send_ue_context_release_command(nas_ctx);
} else { } else {
// No ECM Context to release // No ECM Context to release
m_s1ap_log->info("UE is not ECM connected. No need to release S1-U. MME UE S1AP Id %d\n", mme_ue_s1ap_id); m_logger.info("UE is not ECM connected. No need to release S1-U. MME UE S1AP Id %d", mme_ue_s1ap_id);
// Make sure E-RABS are marked as DEACTIVATED. // Make sure E-RABS are marked as DEACTIVATED.
for (esm_ctx_t& esm_ctx : nas_ctx->m_esm_ctx) { for (esm_ctx_t& esm_ctx : nas_ctx->m_esm_ctx) {
esm_ctx.state = ERAB_DEACTIVATED; esm_ctx.state = ERAB_DEACTIVATED;
@ -271,8 +270,8 @@ bool s1ap_ctx_mngmt_proc::send_ue_context_release_command(nas* nas_ctx)
ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx; ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx;
if (ecm_ctx->state != ECM_STATE_CONNECTED) { if (ecm_ctx->state != ECM_STATE_CONNECTED) {
m_s1ap_log->error("UE is not ECM connected. No send context release command. MME UE S1AP Id %d\n", m_logger.error("UE is not ECM connected. No send context release command. MME UE S1AP Id %d",
ecm_ctx->mme_ue_s1ap_id); ecm_ctx->mme_ue_s1ap_id);
return false; return false;
} }
@ -290,7 +289,7 @@ bool s1ap_ctx_mngmt_proc::send_ue_context_release_command(nas* nas_ctx)
if (active_erabs) { if (active_erabs) {
// There are active E-RABs, send release access mearers request // There are active E-RABs, send release access mearers request
srslte::console("There are active E-RABs, send release access bearers request\n"); srslte::console("There are active E-RABs, send release access bearers request\n");
m_s1ap_log->info("There are active E-RABs, send release access bearers request\n"); m_logger.info("There are active E-RABs, send release access bearers request");
// The handle_release_access_bearers_response function will make sure to mark E-RABS DEACTIVATED // The handle_release_access_bearers_response function will make sure to mark E-RABS DEACTIVATED
// It will release the UEs downstream S1-u and keep the upstream S1-U connection active. // It will release the UEs downstream S1-u and keep the upstream S1-U connection active.
@ -318,7 +317,7 @@ bool s1ap_ctx_mngmt_proc::send_ue_context_release_command(nas* nas_ctx)
// Send Reply to eNB // Send Reply to eNB
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &nas_ctx->m_ecm_ctx.enb_sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &nas_ctx->m_ecm_ctx.enb_sri)) {
m_s1ap_log->error("Error sending UE Context Release Command.\n"); m_logger.error("Error sending UE Context Release Command.");
return false; return false;
} }
@ -328,19 +327,19 @@ bool s1ap_ctx_mngmt_proc::send_ue_context_release_command(nas* nas_ctx)
bool s1ap_ctx_mngmt_proc::handle_ue_context_release_complete(const asn1::s1ap::ue_context_release_complete_s& rel_comp) bool s1ap_ctx_mngmt_proc::handle_ue_context_release_complete(const asn1::s1ap::ue_context_release_complete_s& rel_comp)
{ {
uint32_t mme_ue_s1ap_id = rel_comp.protocol_ies.mme_ue_s1ap_id.value.value; uint32_t mme_ue_s1ap_id = rel_comp.protocol_ies.mme_ue_s1ap_id.value.value;
m_s1ap_log->info("Received UE Context Release Complete. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); m_logger.info("Received UE Context Release Complete. MME-UE S1AP Id: %d", mme_ue_s1ap_id);
srslte::console("Received UE Context Release Complete. MME-UE S1AP Id %d\n", mme_ue_s1ap_id); srslte::console("Received UE Context Release Complete. MME-UE S1AP Id %d\n", mme_ue_s1ap_id);
nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == nullptr) { if (nas_ctx == nullptr) {
m_s1ap_log->info("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); m_logger.info("No UE context to release found. MME-UE S1AP Id: %d", mme_ue_s1ap_id);
srslte::console("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id); srslte::console("No UE context to release found. MME-UE S1AP Id: %d\n", mme_ue_s1ap_id);
return false; return false;
} }
// Delete UE context // Delete UE context
m_s1ap->release_ue_ecm_ctx(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id); m_s1ap->release_ue_ecm_ctx(nas_ctx->m_ecm_ctx.mme_ue_s1ap_id);
m_s1ap_log->info("UE Context Release Completed.\n"); m_logger.info("UE Context Release Completed.");
srslte::console("UE Context Release Completed.\n"); srslte::console("UE Context Release Completed.\n");
return true; return true;
} }

@ -56,7 +56,6 @@ void s1ap_erab_mngmt_proc::cleanup()
void s1ap_erab_mngmt_proc::init() void s1ap_erab_mngmt_proc::init()
{ {
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
m_s1ap_log = m_s1ap->m_s1ap_log;
m_s1ap_args = m_s1ap->m_s1ap_args; m_s1ap_args = m_s1ap->m_s1ap_args;
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
} }
@ -66,7 +65,7 @@ bool s1ap_erab_mngmt_proc::send_erab_release_command(uint32_t enb_
std::vector<uint16_t> erabs_to_release, std::vector<uint16_t> erabs_to_release,
struct sctp_sndrcvinfo enb_sri) struct sctp_sndrcvinfo enb_sri)
{ {
m_s1ap_log->info("Preparing to send E-RAB Release Command\n"); m_logger.info("Preparing to send E-RAB Release Command");
// Prepare reply PDU // Prepare reply PDU
s1ap_pdu_t tx_pdu; s1ap_pdu_t tx_pdu;
@ -86,11 +85,11 @@ bool s1ap_erab_mngmt_proc::send_erab_release_command(uint32_t enb_
erab_rel_cmd.erab_to_be_released_list.value[i].value.erab_item().cause.set(asn1::s1ap::cause_c::types::misc); erab_rel_cmd.erab_to_be_released_list.value[i].value.erab_item().cause.set(asn1::s1ap::cause_c::types::misc);
erab_rel_cmd.erab_to_be_released_list.value[i].value.erab_item().cause.misc() = erab_rel_cmd.erab_to_be_released_list.value[i].value.erab_item().cause.misc() =
asn1::s1ap::cause_misc_opts::unspecified; asn1::s1ap::cause_misc_opts::unspecified;
m_s1ap_log->info("Sending release comman to %d\n", erabs_to_release[i]); m_logger.info("Sending release comman to %d", erabs_to_release[i]);
} }
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_sri)) {
m_s1ap_log->error("Error sending Initial Context Setup Request.\n"); m_logger.error("Error sending Initial Context Setup Request.");
return false; return false;
} }
return true; return true;
@ -102,7 +101,7 @@ bool s1ap_erab_mngmt_proc::send_erab_modify_request(uint32_t
srslte::byte_buffer_t* nas_msg, srslte::byte_buffer_t* nas_msg,
struct sctp_sndrcvinfo enb_sri) struct sctp_sndrcvinfo enb_sri)
{ {
m_s1ap_log->info("Preparing to send E-RAB Modify Command\n"); m_logger.info("Preparing to send E-RAB Modify Command");
// Prepare reply PDU // Prepare reply PDU
s1ap_pdu_t tx_pdu; s1ap_pdu_t tx_pdu;
@ -132,12 +131,12 @@ bool s1ap_erab_mngmt_proc::send_erab_modify_request(uint32_t
asn1::s1ap::pre_emption_vulnerability_opts::not_pre_emptable; asn1::s1ap::pre_emption_vulnerability_opts::not_pre_emptable;
erab_to_mod.nas_pdu.resize(nas_msg->N_bytes); erab_to_mod.nas_pdu.resize(nas_msg->N_bytes);
memcpy(erab_to_mod.nas_pdu.data(), nas_msg->msg, nas_msg->N_bytes); memcpy(erab_to_mod.nas_pdu.data(), nas_msg->msg, nas_msg->N_bytes);
m_s1ap_log->info("Sending release comman to E-RAB Id %d\n", erab_it->first); m_logger.info("Sending release comman to E-RAB Id %d", erab_it->first);
i++; i++;
} }
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_sri)) {
m_s1ap_log->error("Error sending Initial Context Setup Request.\n"); m_logger.error("Error sending Initial Context Setup Request.");
return false; return false;
} }
return true; return true;

@ -52,7 +52,6 @@ void s1ap_mngmt_proc::cleanup(void)
void s1ap_mngmt_proc::init(void) void s1ap_mngmt_proc::init(void)
{ {
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
m_s1ap_log = m_s1ap->m_s1ap_log;
m_s1mme = m_s1ap->get_s1_mme(); m_s1mme = m_s1ap->get_s1_mme();
m_s1ap_args = m_s1ap->m_s1ap_args; m_s1ap_args = m_s1ap->m_s1ap_args;
} }
@ -61,18 +60,18 @@ bool s1ap_mngmt_proc::handle_s1_setup_request(const asn1::s1ap::s1_setup_request
struct sctp_sndrcvinfo* enb_sri) struct sctp_sndrcvinfo* enb_sri)
{ {
srslte::console("Received S1 Setup Request.\n"); srslte::console("Received S1 Setup Request.\n");
m_s1ap_log->info("Received S1 Setup Request.\n"); m_logger.info("Received S1 Setup Request.");
enb_ctx_t enb_ctx = {}; enb_ctx_t enb_ctx = {};
if (!unpack_s1_setup_request(msg, &enb_ctx)) { if (!unpack_s1_setup_request(msg, &enb_ctx)) {
m_s1ap_log->error("Malformed S1 Setup Request\n"); m_logger.error("Malformed S1 Setup Request");
return false; return false;
} }
// Store SCTP sendrecv info // Store SCTP sendrecv info
memcpy(&enb_ctx.sri, enb_sri, sizeof(struct sctp_sndrcvinfo)); memcpy(&enb_ctx.sri, enb_sri, sizeof(struct sctp_sndrcvinfo));
m_s1ap_log->debug("eNB SCTP association Id: %d\n", enb_sri->sinfo_assoc_id); m_logger.debug("eNB SCTP association Id: %d", enb_sri->sinfo_assoc_id);
// Log S1 Setup Request Info // Log S1 Setup Request Info
m_s1ap->print_enb_ctx_info(std::string("S1 Setup Request"), enb_ctx); m_s1ap->print_enb_ctx_info(std::string("S1 Setup Request"), enb_ctx);
@ -89,18 +88,18 @@ bool s1ap_mngmt_proc::handle_s1_setup_request(const asn1::s1ap::s1_setup_request
// Check matching PLMNs // Check matching PLMNs
if (enb_ctx.plmn != m_s1ap->get_plmn()) { if (enb_ctx.plmn != m_s1ap->get_plmn()) {
srslte::console("Sending S1 Setup Failure - Unknown PLMN\n"); srslte::console("Sending S1 Setup Failure - Unknown PLMN\n");
m_s1ap_log->warning("Sending S1 Setup Failure - Unknown PLMN\n"); m_logger.warning("Sending S1 Setup Failure - Unknown PLMN");
send_s1_setup_failure(asn1::s1ap::cause_misc_opts::unknown_plmn, enb_sri); send_s1_setup_failure(asn1::s1ap::cause_misc_opts::unknown_plmn, enb_sri);
} else if (!tac_match) { } else if (!tac_match) {
srslte::console("Sending S1 Setup Failure - No matching TAC\n"); srslte::console("Sending S1 Setup Failure - No matching TAC\n");
m_s1ap_log->warning("Sending S1 Setup Failure - No matching TAC\n"); m_logger.warning("Sending S1 Setup Failure - No matching TAC");
send_s1_setup_failure(asn1::s1ap::cause_misc_opts::unspecified, enb_sri); send_s1_setup_failure(asn1::s1ap::cause_misc_opts::unspecified, enb_sri);
} else { } else {
enb_ctx_t* enb_ptr = m_s1ap->find_enb_ctx(enb_ctx.enb_id); enb_ctx_t* enb_ptr = m_s1ap->find_enb_ctx(enb_ctx.enb_id);
if (enb_ptr != nullptr) { if (enb_ptr != nullptr) {
// eNB already registered // eNB already registered
// TODO replace enb_ctx // TODO replace enb_ctx
m_s1ap_log->warning("eNB Already registered\n"); m_logger.warning("eNB Already registered");
} else { } else {
// new eNB // new eNB
m_s1ap->add_new_enb_ctx(enb_ctx, enb_sri); m_s1ap->add_new_enb_ctx(enb_ctx, enb_sri);
@ -108,7 +107,7 @@ bool s1ap_mngmt_proc::handle_s1_setup_request(const asn1::s1ap::s1_setup_request
send_s1_setup_response(m_s1ap_args, enb_sri); send_s1_setup_response(m_s1ap_args, enb_sri);
srslte::console("Sending S1 Setup Response\n"); srslte::console("Sending S1 Setup Response\n");
m_s1ap_log->info("Sending S1 Setup Response\n"); m_logger.info("Sending S1 Setup Response");
} }
return true; return true;
} }
@ -185,7 +184,7 @@ bool s1ap_mngmt_proc::send_s1_setup_failure(asn1::s1ap::cause_misc_opts::options
bool s1ap_mngmt_proc::send_s1_setup_response(s1ap_args_t s1ap_args, struct sctp_sndrcvinfo* enb_sri) bool s1ap_mngmt_proc::send_s1_setup_response(s1ap_args_t s1ap_args, struct sctp_sndrcvinfo* enb_sri)
{ {
m_s1ap_log->debug("Sending S1 Setup Response\n"); m_logger.debug("Sending S1 Setup Response");
s1ap_pdu_t tx_pdu; s1ap_pdu_t tx_pdu;
tx_pdu.set_successful_outcome().load_info_obj(ASN1_S1AP_ID_S1_SETUP); tx_pdu.set_successful_outcome().load_info_obj(ASN1_S1AP_ID_S1_SETUP);
@ -219,9 +218,9 @@ bool s1ap_mngmt_proc::send_s1_setup_response(s1ap_args_t s1ap_args, struct sctp_
s1_resp.relative_mme_capacity.value = 255; s1_resp.relative_mme_capacity.value = 255;
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, enb_sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, enb_sri)) {
m_s1ap_log->error("Error sending S1 Setup Response.\n"); m_logger.error("Error sending S1 Setup Response.");
} else { } else {
m_s1ap_log->debug("S1 Setup Response sent\n"); m_logger.debug("S1 Setup Response sent");
} }
return true; return true;
} }

@ -56,9 +56,8 @@ void s1ap_nas_transport::cleanup(void)
void s1ap_nas_transport::init() void s1ap_nas_transport::init()
{ {
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
m_s1ap_log = m_s1ap->m_s1ap_log; m_pool = srslte::byte_buffer_pool::get_instance();
m_pool = srslte::byte_buffer_pool::get_instance();
// Init NAS args // Init NAS args
m_nas_init.mcc = m_s1ap->m_s1ap_args.mcc; m_nas_init.mcc = m_s1ap->m_s1ap_args.mcc;
@ -94,7 +93,7 @@ bool s1ap_nas_transport::handle_initial_ue_message(const asn1::s1ap::init_ue_msg
liblte_mme_parse_msg_header((LIBLTE_BYTE_MSG_STRUCT*)nas_msg, &pd, &msg_type); liblte_mme_parse_msg_header((LIBLTE_BYTE_MSG_STRUCT*)nas_msg, &pd, &msg_type);
srslte::console("Initial UE message: %s\n", liblte_nas_msg_type_to_string(msg_type)); srslte::console("Initial UE message: %s\n", liblte_nas_msg_type_to_string(msg_type));
m_s1ap_log->info("Initial UE message: %s\n", liblte_nas_msg_type_to_string(msg_type)); m_logger.info("Initial UE message: %s", liblte_nas_msg_type_to_string(msg_type));
if (init_ue.protocol_ies.s_tmsi_present) { if (init_ue.protocol_ies.s_tmsi_present) {
srslte::uint8_to_uint32(init_ue.protocol_ies.s_tmsi.value.m_tmsi.data(), &m_tmsi); srslte::uint8_to_uint32(init_ue.protocol_ies.s_tmsi.value.m_tmsi.data(), &m_tmsi);
@ -103,29 +102,26 @@ bool s1ap_nas_transport::handle_initial_ue_message(const asn1::s1ap::init_ue_msg
switch (msg_type) { switch (msg_type) {
case LIBLTE_MME_MSG_TYPE_ATTACH_REQUEST: case LIBLTE_MME_MSG_TYPE_ATTACH_REQUEST:
srslte::console("Received Initial UE message -- Attach Request\n"); srslte::console("Received Initial UE message -- Attach Request\n");
m_s1ap_log->info("Received Initial UE message -- Attach Request\n"); m_logger.info("Received Initial UE message -- Attach Request");
err = nas::handle_attach_request(enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if, m_s1ap->m_nas_log); err = nas::handle_attach_request(enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if);
break; break;
case LIBLTE_MME_SECURITY_HDR_TYPE_SERVICE_REQUEST: case LIBLTE_MME_SECURITY_HDR_TYPE_SERVICE_REQUEST:
srslte::console("Received Initial UE message -- Service Request\n"); srslte::console("Received Initial UE message -- Service Request\n");
m_s1ap_log->info("Received Initial UE message -- Service Request\n"); m_logger.info("Received Initial UE message -- Service Request");
err = nas::handle_service_request( err = nas::handle_service_request(m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if);
m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if, m_s1ap->m_nas_log);
break; break;
case LIBLTE_MME_MSG_TYPE_DETACH_REQUEST: case LIBLTE_MME_MSG_TYPE_DETACH_REQUEST:
srslte::console("Received Initial UE message -- Detach Request\n"); srslte::console("Received Initial UE message -- Detach Request\n");
m_s1ap_log->info("Received Initial UE message -- Detach Request\n"); m_logger.info("Received Initial UE message -- Detach Request");
err = err = nas::handle_detach_request(m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if);
nas::handle_detach_request(m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if, m_s1ap->m_nas_log);
break; break;
case LIBLTE_MME_MSG_TYPE_TRACKING_AREA_UPDATE_REQUEST: case LIBLTE_MME_MSG_TYPE_TRACKING_AREA_UPDATE_REQUEST:
srslte::console("Received Initial UE message -- Tracking Area Update Request\n"); srslte::console("Received Initial UE message -- Tracking Area Update Request\n");
m_s1ap_log->info("Received Initial UE message -- Tracking Area Update Request\n"); m_logger.info("Received Initial UE message -- Tracking Area Update Request");
err = nas::handle_tracking_area_update_request( err = nas::handle_tracking_area_update_request(m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if);
m_tmsi, enb_ue_s1ap_id, enb_sri, nas_msg, m_nas_init, m_nas_if, m_s1ap->m_nas_log);
break; break;
default: default:
m_s1ap_log->info("Unhandled Initial UE Message 0x%x \n", msg_type); m_logger.info("Unhandled Initial UE Message 0x%x ", msg_type);
srslte::console("Unhandled Initial UE Message 0x%x \n", msg_type); srslte::console("Unhandled Initial UE Message 0x%x \n", msg_type);
err = false; err = false;
} }
@ -145,11 +141,11 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
// Get UE NAS context // Get UE NAS context
nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id); nas* nas_ctx = m_s1ap->find_nas_ctx_from_mme_ue_s1ap_id(mme_ue_s1ap_id);
if (nas_ctx == nullptr) { if (nas_ctx == nullptr) {
m_s1ap_log->warning("Received uplink NAS, but could not find UE NAS context. MME-UE S1AP id: %d\n", mme_ue_s1ap_id); m_logger.warning("Received uplink NAS, but could not find UE NAS context. MME-UE S1AP id: %d", mme_ue_s1ap_id);
return false; return false;
} }
m_s1ap_log->debug("Received uplink NAS and found UE NAS context. MME-UE S1AP id: %d\n", mme_ue_s1ap_id); m_logger.debug("Received uplink NAS and found UE NAS context. MME-UE S1AP id: %d", mme_ue_s1ap_id);
emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx; emm_ctx_t* emm_ctx = &nas_ctx->m_emm_ctx;
ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx; ecm_ctx_t* ecm_ctx = &nas_ctx->m_ecm_ctx;
sec_ctx_t* sec_ctx = &nas_ctx->m_sec_ctx; sec_ctx_t* sec_ctx = &nas_ctx->m_sec_ctx;
@ -169,7 +165,7 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED || sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED ||
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_WITH_NEW_EPS_SECURITY_CONTEXT || sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_WITH_NEW_EPS_SECURITY_CONTEXT ||
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT)) { sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT)) {
m_s1ap_log->error("Unhandled security header type in Uplink NAS Transport: %d\n", sec_hdr_type); m_logger.error("Unhandled security header type in Uplink NAS Transport: %d", sec_hdr_type);
m_pool->deallocate(nas_msg); m_pool->deallocate(nas_msg);
return false; return false;
} }
@ -182,18 +178,18 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT) { sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT) {
mac_valid = nas_ctx->integrity_check(nas_msg); mac_valid = nas_ctx->integrity_check(nas_msg);
if (mac_valid == false) { if (mac_valid == false) {
m_s1ap_log->warning("Invalid MAC message. Even if security header indicates integrity protection (Maybe: " m_logger.warning("Invalid MAC message. Even if security header indicates integrity protection (Maybe: "
"Identity Response or Authentication Response)\n"); "Identity Response or Authentication Response)");
} }
} }
// Decrypt message if indicated // Decrypt message if indicated
if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED || if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED ||
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT) { sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT) {
m_s1ap_log->debug_hex(nas_msg->msg, nas_msg->N_bytes, "Encrypted"); m_logger.debug(nas_msg->msg, nas_msg->N_bytes, "Encrypted");
nas_ctx->cipher_decrypt(nas_msg); nas_ctx->cipher_decrypt(nas_msg);
msg_encrypted = true; msg_encrypted = true;
m_s1ap_log->debug_hex(nas_msg->msg, nas_msg->N_bytes, "Decrypted"); m_logger.debug(nas_msg->msg, nas_msg->N_bytes, "Decrypted");
} }
// Now parse message header and handle message // Now parse message header and handle message
@ -207,8 +203,8 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
// This can happen with integrity protected identity reponse messages // This can happen with integrity protected identity reponse messages
if (!(msg_type == LIBLTE_MME_MSG_TYPE_IDENTITY_RESPONSE && if (!(msg_type == LIBLTE_MME_MSG_TYPE_IDENTITY_RESPONSE &&
sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY)) { sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY)) {
m_s1ap_log->warning( m_logger.warning(
"Uplink NAS: could not find security context for integrity protected message. MME-UE S1AP id: %d\n", "Uplink NAS: could not find security context for integrity protected message. MME-UE S1AP id: %d",
mme_ue_s1ap_id); mme_ue_s1ap_id);
m_pool->deallocate(nas_msg); m_pool->deallocate(nas_msg);
return false; return false;
@ -227,24 +223,24 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
// - DETACH REQUEST; // - DETACH REQUEST;
// - DETACH ACCEPT; // - DETACH ACCEPT;
// - TRACKING AREA UPDATE REQUEST. // - TRACKING AREA UPDATE REQUEST.
m_s1ap_log->info("UL NAS: sec_hdr_type: %s, mac_vaild: %s, msg_encrypted: %s\n", m_logger.info("UL NAS: sec_hdr_type: %s, mac_vaild: %s, msg_encrypted: %s",
liblte_nas_sec_hdr_type_to_string(sec_hdr_type), liblte_nas_sec_hdr_type_to_string(sec_hdr_type),
mac_valid == true ? "yes" : "no", mac_valid == true ? "yes" : "no",
msg_encrypted == true ? "yes" : "no"); msg_encrypted == true ? "yes" : "no");
switch (msg_type) { switch (msg_type) {
case LIBLTE_MME_MSG_TYPE_ATTACH_REQUEST: case LIBLTE_MME_MSG_TYPE_ATTACH_REQUEST:
m_s1ap_log->info("UL NAS: Attach Request\n"); m_logger.info("UL NAS: Attach Request");
srslte::console("UL NAS: Attach Resquest\n"); srslte::console("UL NAS: Attach Resquest\n");
nas_ctx->handle_attach_request(nas_msg); nas_ctx->handle_attach_request(nas_msg);
break; break;
case LIBLTE_MME_MSG_TYPE_IDENTITY_RESPONSE: case LIBLTE_MME_MSG_TYPE_IDENTITY_RESPONSE:
m_s1ap_log->info("UL NAS: Received Identity Response\n"); m_logger.info("UL NAS: Received Identity Response");
srslte::console("UL NAS: Received Identity Response\n"); srslte::console("UL NAS: Received Identity Response\n");
nas_ctx->handle_identity_response(nas_msg); nas_ctx->handle_identity_response(nas_msg);
break; break;
case LIBLTE_MME_MSG_TYPE_AUTHENTICATION_RESPONSE: case LIBLTE_MME_MSG_TYPE_AUTHENTICATION_RESPONSE:
m_s1ap_log->info("UL NAS: Received Authentication Response\n"); m_logger.info("UL NAS: Received Authentication Response");
srslte::console("UL NAS: Received Authentication Response\n"); srslte::console("UL NAS: Received Authentication Response\n");
nas_ctx->handle_authentication_response(nas_msg); nas_ctx->handle_authentication_response(nas_msg);
// In case of a successful authentication response, security mode command follows. // In case of a successful authentication response, security mode command follows.
@ -255,19 +251,19 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
break; break;
// Authentication failure with the option sync failure can be sent not integrity protected // Authentication failure with the option sync failure can be sent not integrity protected
case LIBLTE_MME_MSG_TYPE_AUTHENTICATION_FAILURE: case LIBLTE_MME_MSG_TYPE_AUTHENTICATION_FAILURE:
m_s1ap_log->info("UL NAS: Authentication Failure\n"); m_logger.info("UL NAS: Authentication Failure");
srslte::console("UL NAS: Authentication Failure\n"); srslte::console("UL NAS: Authentication Failure\n");
nas_ctx->handle_authentication_failure(nas_msg); nas_ctx->handle_authentication_failure(nas_msg);
break; break;
// Detach request can be sent not integrity protected when "power off" option is used // Detach request can be sent not integrity protected when "power off" option is used
case LIBLTE_MME_MSG_TYPE_DETACH_REQUEST: case LIBLTE_MME_MSG_TYPE_DETACH_REQUEST:
m_s1ap_log->info("UL NAS: Detach Request\n"); m_logger.info("UL NAS: Detach Request");
srslte::console("UL NAS: Detach Request\n"); srslte::console("UL NAS: Detach Request\n");
// TODO: check integrity protection in detach request // TODO: check integrity protection in detach request
nas_ctx->handle_detach_request(nas_msg); nas_ctx->handle_detach_request(nas_msg);
break; break;
case LIBLTE_MME_MSG_TYPE_SECURITY_MODE_COMPLETE: case LIBLTE_MME_MSG_TYPE_SECURITY_MODE_COMPLETE:
m_s1ap_log->info("UL NAS: Received Security Mode Complete\n"); m_logger.info("UL NAS: Received Security Mode Complete");
srslte::console("UL NAS: Received Security Mode Complete\n"); srslte::console("UL NAS: Received Security Mode Complete\n");
if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT && if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED_WITH_NEW_EPS_SECURITY_CONTEXT &&
mac_valid == true) { mac_valid == true) {
@ -275,45 +271,45 @@ bool s1ap_nas_transport::handle_uplink_nas_transport(const asn1::s1ap::ul_nas_tr
} else { } else {
// Security Mode Complete was not integrity protected // Security Mode Complete was not integrity protected
srslte::console("Security Mode Complete %s. Discard message.\n", srslte::console("Security Mode Complete %s. Discard message.\n",
(mac_valid ? "not integrity protected" : "invalid integrity")); (mac_valid ? "not integrity protected" : "invalid integrity"));
m_s1ap_log->warning("Security Mode Complete %s. Discard message.\n", m_logger.warning("Security Mode Complete %s. Discard message.",
(mac_valid ? "not integrity protected" : "invalid integrity")); (mac_valid ? "not integrity protected" : "invalid integrity"));
increase_ul_nas_cnt = false; increase_ul_nas_cnt = false;
} }
break; break;
case LIBLTE_MME_MSG_TYPE_ATTACH_COMPLETE: case LIBLTE_MME_MSG_TYPE_ATTACH_COMPLETE:
m_s1ap_log->info("UL NAS: Received Attach Complete\n"); m_logger.info("UL NAS: Received Attach Complete");
srslte::console("UL NAS: Received Attach Complete\n"); srslte::console("UL NAS: Received Attach Complete\n");
if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED && mac_valid == true) { if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED && mac_valid == true) {
nas_ctx->handle_attach_complete(nas_msg); nas_ctx->handle_attach_complete(nas_msg);
} else { } else {
// Attach Complete was not integrity protected // Attach Complete was not integrity protected
srslte::console("Attach Complete not integrity protected. Discard message.\n"); srslte::console("Attach Complete not integrity protected. Discard message.\n");
m_s1ap_log->warning("Attach Complete not integrity protected. Discard message.\n"); m_logger.warning("Attach Complete not integrity protected. Discard message.");
increase_ul_nas_cnt = false; increase_ul_nas_cnt = false;
} }
break; break;
case LIBLTE_MME_MSG_TYPE_ESM_INFORMATION_RESPONSE: case LIBLTE_MME_MSG_TYPE_ESM_INFORMATION_RESPONSE:
m_s1ap_log->info("UL NAS: Received ESM Information Response\n"); m_logger.info("UL NAS: Received ESM Information Response");
srslte::console("UL NAS: Received ESM Information Response\n"); srslte::console("UL NAS: Received ESM Information Response\n");
if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED && mac_valid == true) { if (sec_hdr_type == LIBLTE_MME_SECURITY_HDR_TYPE_INTEGRITY_AND_CIPHERED && mac_valid == true) {
nas_ctx->handle_esm_information_response(nas_msg); nas_ctx->handle_esm_information_response(nas_msg);
} else { } else {
// Attach Complete was not integrity protected // Attach Complete was not integrity protected
srslte::console("ESM Information Response %s. Discard message.\n", srslte::console("ESM Information Response %s. Discard message.\n",
(mac_valid ? "not integrity protected" : "invalid integrity")); (mac_valid ? "not integrity protected" : "invalid integrity"));
m_s1ap_log->warning("ESM Information Response %s. Discard message.\n", m_logger.warning("ESM Information Response %s. Discard message.",
(mac_valid ? "not integrity protected" : "invalid integrity")); (mac_valid ? "not integrity protected" : "invalid integrity"));
increase_ul_nas_cnt = false; increase_ul_nas_cnt = false;
} }
break; break;
case LIBLTE_MME_MSG_TYPE_TRACKING_AREA_UPDATE_REQUEST: case LIBLTE_MME_MSG_TYPE_TRACKING_AREA_UPDATE_REQUEST:
m_s1ap_log->info("UL NAS: Tracking Area Update Request\n"); m_logger.info("UL NAS: Tracking Area Update Request");
srslte::console("UL NAS: Tracking Area Update Request\n"); srslte::console("UL NAS: Tracking Area Update Request\n");
nas_ctx->handle_tracking_area_update_request(nas_msg); nas_ctx->handle_tracking_area_update_request(nas_msg);
break; break;
default: default:
m_s1ap_log->warning("Unhandled NAS integrity protected message %s\n", liblte_nas_msg_type_to_string(msg_type)); m_logger.warning("Unhandled NAS integrity protected message %s", liblte_nas_msg_type_to_string(msg_type));
srslte::console("Unhandled NAS integrity protected message %s\n", liblte_nas_msg_type_to_string(msg_type)); srslte::console("Unhandled NAS integrity protected message %s\n", liblte_nas_msg_type_to_string(msg_type));
m_pool->deallocate(nas_msg); m_pool->deallocate(nas_msg);
return false; return false;
@ -333,10 +329,10 @@ bool s1ap_nas_transport::send_downlink_nas_transport(uint32_t enb_
srslte::byte_buffer_t* nas_msg, srslte::byte_buffer_t* nas_msg,
struct sctp_sndrcvinfo enb_sri) struct sctp_sndrcvinfo enb_sri)
{ {
m_s1ap_log->debug("Sending message to eNB with SCTP association %d. MME UE S1AP ID %d, eNB UE S1AP ID %d\n", m_logger.debug("Sending message to eNB with SCTP association %d. MME UE S1AP ID %d, eNB UE S1AP ID %d",
enb_sri.sinfo_assoc_id, enb_sri.sinfo_assoc_id,
mme_ue_s1ap_id, mme_ue_s1ap_id,
enb_ue_s1ap_id); enb_ue_s1ap_id);
// Setup initiating message // Setup initiating message
s1ap_pdu_t tx_pdu; s1ap_pdu_t tx_pdu;

@ -28,14 +28,13 @@ void s1ap_paging::init()
{ {
m_s1ap = s1ap::get_instance(); m_s1ap = s1ap::get_instance();
m_mme = mme::get_instance(); m_mme = mme::get_instance();
m_s1ap_log = m_s1ap->m_s1ap_log;
m_s1ap_args = m_s1ap->m_s1ap_args; m_s1ap_args = m_s1ap->m_s1ap_args;
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
} }
bool s1ap_paging::send_paging(uint64_t imsi, uint16_t erab_to_setup) bool s1ap_paging::send_paging(uint64_t imsi, uint16_t erab_to_setup)
{ {
m_s1ap_log->info("Preparing to Page UE -- IMSI %015" PRIu64 "\n", imsi); m_logger.info("Preparing to Page UE -- IMSI %015" PRIu64 "", imsi);
// Prepare reply PDU // Prepare reply PDU
s1ap_pdu_t tx_pdu; s1ap_pdu_t tx_pdu;
@ -45,7 +44,7 @@ bool s1ap_paging::send_paging(uint64_t imsi, uint16_t erab_to_setup)
// Getting UE NAS Context // Getting UE NAS Context
nas* nas_ctx = m_s1ap->find_nas_ctx_from_imsi(imsi); nas* nas_ctx = m_s1ap->find_nas_ctx_from_imsi(imsi);
if (nas_ctx == nullptr) { if (nas_ctx == nullptr) {
m_s1ap_log->error("Could not find UE to page NAS context\n"); m_logger.error("Could not find UE to page NAS context");
return false; return false;
} }
@ -73,7 +72,7 @@ bool s1ap_paging::send_paging(uint64_t imsi, uint16_t erab_to_setup)
// Start T3413 // Start T3413
if (!nas_ctx->start_timer(T_3413)) { if (!nas_ctx->start_timer(T_3413)) {
m_s1ap_log->error("Could not start T3413 -- Aborting paging\n"); m_logger.error("Could not start T3413 -- Aborting paging");
// TODO Send data notification failure to SPGW // TODO Send data notification failure to SPGW
return false; return false;
} }
@ -82,7 +81,7 @@ bool s1ap_paging::send_paging(uint64_t imsi, uint16_t erab_to_setup)
it++) { it++) {
enb_ctx_t* enb_ctx = it->second; enb_ctx_t* enb_ctx = it->second;
if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_ctx->sri)) { if (!m_s1ap->s1ap_tx_pdu(tx_pdu, &enb_ctx->sri)) {
m_s1ap_log->error("Error paging to eNB. eNB Id: 0x%x.\n", enb_ctx->enb_id); m_logger.error("Error paging to eNB. eNB Id: 0x%x.", enb_ctx->enb_id);
return false; return false;
} }
} }

@ -45,15 +45,11 @@ spgw::gtpc::~gtpc()
int spgw::gtpc::init(spgw_args_t* args, int spgw::gtpc::init(spgw_args_t* args,
spgw* spgw, spgw* spgw,
gtpu_interface_gtpc* gtpu, gtpu_interface_gtpc* gtpu,
srslte::log_filter* gtpc_log,
const std::map<std::string, uint64_t>& ip_to_imsi) const std::map<std::string, uint64_t>& ip_to_imsi)
{ {
int err; int err;
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
// Init log
m_gtpc_log = gtpc_log;
// Init interfaces // Init interfaces
m_spgw = spgw; m_spgw = spgw;
m_gtpu = gtpu; m_gtpu = gtpu;
@ -75,7 +71,7 @@ int spgw::gtpc::init(spgw_args_t* args,
// Limit paging queue // Limit paging queue
m_max_paging_queue = args->max_paging_queue; m_max_paging_queue = args->max_paging_queue;
m_gtpc_log->info("SPGW S11 Initialized.\n"); m_logger.info("SPGW S11 Initialized.");
srslte::console("SPGW S11 Initialized.\n"); srslte::console("SPGW S11 Initialized.\n");
return 0; return 0;
} }
@ -84,7 +80,7 @@ void spgw::gtpc::stop()
{ {
std::map<uint32_t, spgw_tunnel_ctx*>::iterator it = m_teid_to_tunnel_ctx.begin(); std::map<uint32_t, spgw_tunnel_ctx*>::iterator it = m_teid_to_tunnel_ctx.begin();
while (it != m_teid_to_tunnel_ctx.end()) { while (it != m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->info("Deleting SP-GW GTP-C Tunnel. IMSI: %015" PRIu64 "\n", it->second->imsi); m_logger.info("Deleting SP-GW GTP-C Tunnel. IMSI: %015" PRIu64 "", it->second->imsi);
srslte::console("Deleting SP-GW GTP-C Tunnel. IMSI: %015" PRIu64 "\n", it->second->imsi); srslte::console("Deleting SP-GW GTP-C Tunnel. IMSI: %015" PRIu64 "\n", it->second->imsi);
delete it->second; delete it->second;
m_teid_to_tunnel_ctx.erase(it++); m_teid_to_tunnel_ctx.erase(it++);
@ -99,12 +95,12 @@ int spgw::gtpc::init_s11(spgw_args_t* args)
char mme_addr_name[] = "@mme_s11"; char mme_addr_name[] = "@mme_s11";
// Logs // Logs
m_gtpc_log->info("Initializing SPGW S11 interface.\n"); m_logger.info("Initializing SPGW S11 interface.");
// Open Socket // Open Socket
m_s11 = socket(AF_UNIX, SOCK_DGRAM, 0); m_s11 = socket(AF_UNIX, SOCK_DGRAM, 0);
if (m_s11 < 0) { if (m_s11 < 0) {
m_gtpc_log->error("Error opening UNIX socket. Error %s\n", strerror(errno)); m_logger.error("Error opening UNIX socket. Error %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
@ -122,7 +118,7 @@ int spgw::gtpc::init_s11(spgw_args_t* args)
// Bind socket to address // Bind socket to address
if (bind(m_s11, (const struct sockaddr*)&m_spgw_addr, sizeof(m_spgw_addr)) == -1) { if (bind(m_s11, (const struct sockaddr*)&m_spgw_addr, sizeof(m_spgw_addr)) == -1) {
m_gtpc_log->error("Error binding UNIX socket. Error %s\n", strerror(errno)); m_logger.error("Error binding UNIX socket. Error %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
@ -130,16 +126,16 @@ int spgw::gtpc::init_s11(spgw_args_t* args)
bool spgw::gtpc::send_s11_pdu(const srslte::gtpc_pdu& pdu) bool spgw::gtpc::send_s11_pdu(const srslte::gtpc_pdu& pdu)
{ {
m_gtpc_log->debug("SPGW Sending S11 PDU! N_Bytes: %zd\n", sizeof(pdu)); m_logger.debug("SPGW Sending S11 PDU! N_Bytes: %zd", sizeof(pdu));
// TODO add serialization code here // TODO add serialization code here
// Send S11 message to MME // Send S11 message to MME
int n = sendto(m_s11, &pdu, sizeof(pdu), 0, (const sockaddr*)&m_mme_addr, sizeof(m_mme_addr)); int n = sendto(m_s11, &pdu, sizeof(pdu), 0, (const sockaddr*)&m_mme_addr, sizeof(m_mme_addr));
if (n < 0) { if (n < 0) {
m_gtpc_log->error("Error sending to socket. Error %s", strerror(errno)); m_logger.error("Error sending to socket. Error %s", strerror(errno));
return false; return false;
} else { } else {
m_gtpc_log->debug("SPGW S11 Sent %d Bytes.\n", n); m_logger.debug("SPGW S11 Sent %d Bytes.", n);
} }
return true; return true;
} }
@ -149,7 +145,7 @@ void spgw::gtpc::handle_s11_pdu(srslte::byte_buffer_t* msg)
// TODO add deserialization code here // TODO add deserialization code here
srslte::gtpc_pdu* pdu = (srslte::gtpc_pdu*)msg->msg; srslte::gtpc_pdu* pdu = (srslte::gtpc_pdu*)msg->msg;
srslte::console("Received GTP-C PDU. Message type: %s\n", srslte::gtpc_msg_type_to_str(pdu->header.type)); srslte::console("Received GTP-C PDU. Message type: %s\n", srslte::gtpc_msg_type_to_str(pdu->header.type));
m_gtpc_log->debug("Received GTP-C PDU. Message type: %s\n", srslte::gtpc_msg_type_to_str(pdu->header.type)); m_logger.debug("Received GTP-C PDU. Message type: %s", srslte::gtpc_msg_type_to_str(pdu->header.type));
switch (pdu->header.type) { switch (pdu->header.type) {
case srslte::GTPC_MSG_TYPE_CREATE_SESSION_REQUEST: case srslte::GTPC_MSG_TYPE_CREATE_SESSION_REQUEST:
handle_create_session_request(pdu->choice.create_session_request); handle_create_session_request(pdu->choice.create_session_request);
@ -171,14 +167,14 @@ void spgw::gtpc::handle_s11_pdu(srslte::byte_buffer_t* msg)
pdu->choice.downlink_data_notification_failure_indication); pdu->choice.downlink_data_notification_failure_indication);
break; break;
default: default:
m_gtpc_log->error("Unhandled GTP-C message type\n"); m_logger.error("Unhandled GTP-C message type");
} }
return; return;
} }
void spgw::gtpc::handle_create_session_request(const struct srslte::gtpc_create_session_request& cs_req) void spgw::gtpc::handle_create_session_request(const struct srslte::gtpc_create_session_request& cs_req)
{ {
m_gtpc_log->info("SPGW Received Create Session Request\n"); m_logger.info("SPGW Received Create Session Request");
spgw_tunnel_ctx_t* tunnel_ctx; spgw_tunnel_ctx_t* tunnel_ctx;
int default_bearer_id = 5; int default_bearer_id = 5;
// Check if IMSI has active GTP-C and/or GTP-U // Check if IMSI has active GTP-C and/or GTP-U
@ -189,7 +185,7 @@ void spgw::gtpc::handle_create_session_request(const struct srslte::gtpc_create_
srslte::console("SPGW: Deleted previous context.\n"); srslte::console("SPGW: Deleted previous context.\n");
} }
m_gtpc_log->info("Creating new GTP-C context\n"); m_logger.info("Creating new GTP-C context");
tunnel_ctx = create_gtpc_ctx(cs_req); tunnel_ctx = create_gtpc_ctx(cs_req);
// Create session response message // Create session response message
@ -223,7 +219,7 @@ void spgw::gtpc::handle_create_session_request(const struct srslte::gtpc_create_
cs_resp->paa.pdn_type = srslte::GTPC_PDN_TYPE_IPV4; cs_resp->paa.pdn_type = srslte::GTPC_PDN_TYPE_IPV4;
cs_resp->paa.ipv4_present = true; cs_resp->paa.ipv4_present = true;
cs_resp->paa.ipv4 = tunnel_ctx->ue_ipv4; cs_resp->paa.ipv4 = tunnel_ctx->ue_ipv4;
m_gtpc_log->info("Sending Create Session Response\n"); m_logger.info("Sending Create Session Response");
// Send Create session response to MME // Send Create session response to MME
send_s11_pdu(cs_resp_pdu); send_s11_pdu(cs_resp_pdu);
@ -233,13 +229,13 @@ void spgw::gtpc::handle_create_session_request(const struct srslte::gtpc_create_
void spgw::gtpc::handle_modify_bearer_request(const struct srslte::gtpc_header& mb_req_hdr, void spgw::gtpc::handle_modify_bearer_request(const struct srslte::gtpc_header& mb_req_hdr,
const struct srslte::gtpc_modify_bearer_request& mb_req) const struct srslte::gtpc_modify_bearer_request& mb_req)
{ {
m_gtpc_log->info("Received Modified Bearer Request\n"); m_logger.info("Received Modified Bearer Request");
// Get control tunnel info from mb_req PDU // Get control tunnel info from mb_req PDU
uint32_t ctrl_teid = mb_req_hdr.teid; uint32_t ctrl_teid = mb_req_hdr.teid;
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID %d to modify\n", ctrl_teid); m_logger.warning("Could not find TEID %d to modify", ctrl_teid);
return; return;
} }
spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second; spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second;
@ -248,22 +244,21 @@ void spgw::gtpc::handle_modify_bearer_request(const struct srslte::gtpc_header&
tunnel_ctx->dw_user_fteid.teid = mb_req.eps_bearer_context_to_modify.s1_u_enb_f_teid.teid; tunnel_ctx->dw_user_fteid.teid = mb_req.eps_bearer_context_to_modify.s1_u_enb_f_teid.teid;
tunnel_ctx->dw_user_fteid.ipv4 = mb_req.eps_bearer_context_to_modify.s1_u_enb_f_teid.ipv4; tunnel_ctx->dw_user_fteid.ipv4 = mb_req.eps_bearer_context_to_modify.s1_u_enb_f_teid.ipv4;
// Set up actual tunnel // Set up actual tunnel
m_gtpc_log->info("Setting Up GTP-U tunnel. Tunnel info: \n"); m_logger.info("Setting Up GTP-U tunnel. Tunnel info: ");
struct in_addr addr; struct in_addr addr;
addr.s_addr = tunnel_ctx->ue_ipv4; addr.s_addr = tunnel_ctx->ue_ipv4;
m_gtpc_log->info("IMSI: %015" PRIu64 ", UE IP: %s \n", tunnel_ctx->imsi, inet_ntoa(addr)); m_logger.info("IMSI: %015" PRIu64 ", UE IP: %s ", tunnel_ctx->imsi, inet_ntoa(addr));
m_gtpc_log->info("S-GW Rx Ctrl TEID 0x%x, MME Rx Ctrl TEID 0x%x\n", m_logger.info(
tunnel_ctx->up_ctrl_fteid.teid, "S-GW Rx Ctrl TEID 0x%x, MME Rx Ctrl TEID 0x%x", tunnel_ctx->up_ctrl_fteid.teid, tunnel_ctx->dw_ctrl_fteid.teid);
tunnel_ctx->dw_ctrl_fteid.teid); m_logger.info("S-GW Rx Ctrl IP (NA), MME Rx Ctrl IP (NA)");
m_gtpc_log->info("S-GW Rx Ctrl IP (NA), MME Rx Ctrl IP (NA)\n");
struct in_addr addr2; struct in_addr addr2;
addr2.s_addr = tunnel_ctx->up_user_fteid.ipv4; addr2.s_addr = tunnel_ctx->up_user_fteid.ipv4;
m_gtpc_log->info("S-GW Rx User TEID 0x%x, S-GW Rx User IP %s\n", tunnel_ctx->up_user_fteid.teid, inet_ntoa(addr2)); m_logger.info("S-GW Rx User TEID 0x%x, S-GW Rx User IP %s", tunnel_ctx->up_user_fteid.teid, inet_ntoa(addr2));
struct in_addr addr3; struct in_addr addr3;
addr3.s_addr = tunnel_ctx->dw_user_fteid.ipv4; addr3.s_addr = tunnel_ctx->dw_user_fteid.ipv4;
m_gtpc_log->info("eNB Rx User TEID 0x%x, eNB Rx User IP %s\n", tunnel_ctx->dw_user_fteid.teid, inet_ntoa(addr3)); m_logger.info("eNB Rx User TEID 0x%x, eNB Rx User IP %s", tunnel_ctx->dw_user_fteid.teid, inet_ntoa(addr3));
// Setup IP to F-TEID map // Setup IP to F-TEID map
m_gtpu->modify_gtpu_tunnel(tunnel_ctx->ue_ipv4, tunnel_ctx->dw_user_fteid, tunnel_ctx->up_ctrl_fteid.teid); m_gtpu->modify_gtpu_tunnel(tunnel_ctx->ue_ipv4, tunnel_ctx->dw_user_fteid, tunnel_ctx->up_ctrl_fteid.teid);
@ -271,7 +266,7 @@ void spgw::gtpc::handle_modify_bearer_request(const struct srslte::gtpc_header&
// Mark paging as done & send queued packets // Mark paging as done & send queued packets
if (tunnel_ctx->paging_pending == true) { if (tunnel_ctx->paging_pending == true) {
tunnel_ctx->paging_pending = false; tunnel_ctx->paging_pending = false;
m_gtpc_log->debug("Modify Bearer Request received after Downling Data Notification was sent\n"); m_logger.debug("Modify Bearer Request received after Downling Data Notification was sent");
srslte::console("Modify Bearer Request received after Downling Data Notification was sent\n"); srslte::console("Modify Bearer Request received after Downling Data Notification was sent\n");
m_gtpu->send_all_queued_packets(tunnel_ctx->dw_user_fteid, tunnel_ctx->paging_queue); m_gtpu->send_all_queued_packets(tunnel_ctx->dw_user_fteid, tunnel_ctx->paging_queue);
} }
@ -303,7 +298,7 @@ void spgw::gtpc::handle_delete_session_request(const srslte::gtpc_header&
uint32_t ctrl_teid = header.teid; uint32_t ctrl_teid = header.teid;
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID 0x%x to delete session\n", ctrl_teid); m_logger.warning("Could not find TEID 0x%x to delete session", ctrl_teid);
return; return;
} }
spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second; spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second;
@ -320,7 +315,7 @@ void spgw::gtpc::handle_release_access_bearers_request(const srslte::gtpc_header
uint32_t ctrl_teid = header.teid; uint32_t ctrl_teid = header.teid;
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID 0x%x to release bearers\n", ctrl_teid); m_logger.warning("Could not find TEID 0x%x to release bearers", ctrl_teid);
return; return;
} }
spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second; spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second;
@ -333,7 +328,7 @@ void spgw::gtpc::handle_release_access_bearers_request(const srslte::gtpc_header
bool spgw::gtpc::send_downlink_data_notification(uint32_t spgw_ctr_teid) bool spgw::gtpc::send_downlink_data_notification(uint32_t spgw_ctr_teid)
{ {
m_gtpc_log->debug("Sending Downlink Notification Request\n"); m_logger.debug("Sending Downlink Notification Request");
struct srslte::gtpc_pdu dl_not_pdu; struct srslte::gtpc_pdu dl_not_pdu;
std::memset(&dl_not_pdu, 0, sizeof(dl_not_pdu)); std::memset(&dl_not_pdu, 0, sizeof(dl_not_pdu));
@ -343,14 +338,14 @@ bool spgw::gtpc::send_downlink_data_notification(uint32_t spgw_ctr_teid)
// Find MME Ctrl TEID // Find MME Ctrl TEID
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(spgw_ctr_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(spgw_ctr_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID 0x%x to send downlink notification.\n", spgw_ctr_teid); m_logger.warning("Could not find TEID 0x%x to send downlink notification.", spgw_ctr_teid);
return false; return false;
} }
spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second; spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second;
// Check if there is no Paging already pending. // Check if there is no Paging already pending.
if (tunnel_ctx->paging_pending == true) { if (tunnel_ctx->paging_pending == true) {
m_gtpc_log->debug("UE Downlink Data Notification still pending.\n"); m_logger.debug("UE Downlink Data Notification still pending.");
return false; return false;
} }
@ -376,13 +371,13 @@ void spgw::gtpc::handle_downlink_data_notification_acknowledge(
const srslte::gtpc_header& header, const srslte::gtpc_header& header,
const srslte::gtpc_downlink_data_notification_acknowledge& not_ack) const srslte::gtpc_downlink_data_notification_acknowledge& not_ack)
{ {
m_gtpc_log->debug("Handling downlink data notification acknowledge\n"); m_logger.debug("Handling downlink data notification acknowledge");
// Find tunel ctxt // Find tunel ctxt
uint32_t ctrl_teid = header.teid; uint32_t ctrl_teid = header.teid;
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID 0x%x to handle notification acknowldge\n", ctrl_teid); m_logger.warning("Could not find TEID 0x%x to handle notification acknowldge", ctrl_teid);
return; return;
} }
spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second; spgw_tunnel_ctx_t* tunnel_ctx = tunnel_it->second;
@ -390,11 +385,11 @@ void spgw::gtpc::handle_downlink_data_notification_acknowledge(
not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_ALREADY_RE_ATTACHED || not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_ALREADY_RE_ATTACHED ||
not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UNABLE_TO_PAGE_UE || not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UNABLE_TO_PAGE_UE ||
not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UNABLE_TO_PAGE_UE_DUE_TO_SUSPENSION) { not_ack.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UNABLE_TO_PAGE_UE_DUE_TO_SUSPENSION) {
m_gtpc_log->warning("Downlink Data Notification Acknowledge indicates failure.\n"); m_logger.warning("Downlink Data Notification Acknowledge indicates failure.");
free_all_queued_packets(tunnel_ctx); free_all_queued_packets(tunnel_ctx);
tunnel_ctx->paging_pending = false; tunnel_ctx->paging_pending = false;
} else if (not_ack.cause.cause_value != srslte::GTPC_CAUSE_VALUE_REQUEST_ACCEPTED) { } else if (not_ack.cause.cause_value != srslte::GTPC_CAUSE_VALUE_REQUEST_ACCEPTED) {
m_gtpc_log->warning("Invalid cause in Downlink Data Notification Acknowledge.\n"); m_logger.warning("Invalid cause in Downlink Data Notification Acknowledge.");
free_all_queued_packets(tunnel_ctx); free_all_queued_packets(tunnel_ctx);
tunnel_ctx->paging_pending = false; tunnel_ctx->paging_pending = false;
} }
@ -405,12 +400,12 @@ void spgw::gtpc::handle_downlink_data_notification_failure_indication(
const srslte::gtpc_header& header, const srslte::gtpc_header& header,
const srslte::gtpc_downlink_data_notification_failure_indication& not_fail) const srslte::gtpc_downlink_data_notification_failure_indication& not_fail)
{ {
m_gtpc_log->debug("Handling downlink data notification failure indication\n"); m_logger.debug("Handling downlink data notification failure indication");
// Find tunel ctxt // Find tunel ctxt
uint32_t ctrl_teid = header.teid; uint32_t ctrl_teid = header.teid;
std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid); std::map<uint32_t, spgw_tunnel_ctx_t*>::iterator tunnel_it = m_teid_to_tunnel_ctx.find(ctrl_teid);
if (tunnel_it == m_teid_to_tunnel_ctx.end()) { if (tunnel_it == m_teid_to_tunnel_ctx.end()) {
m_gtpc_log->warning("Could not find TEID 0x%x to handle notification failure indication\n", ctrl_teid); m_logger.warning("Could not find TEID 0x%x to handle notification failure indication", ctrl_teid);
return; return;
} }
@ -418,10 +413,9 @@ void spgw::gtpc::handle_downlink_data_notification_failure_indication(
if (not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_NOT_RESPONDING || if (not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_NOT_RESPONDING ||
not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_SERVICE_DENIED || not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_SERVICE_DENIED ||
not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_ALREADY_RE_ATTACHED) { not_fail.cause.cause_value == srslte::GTPC_CAUSE_VALUE_UE_ALREADY_RE_ATTACHED) {
m_gtpc_log->debug("Downlink Data Notification failure indication cause: %d.\n", not_fail.cause.cause_value); m_logger.debug("Downlink Data Notification failure indication cause: %d.", not_fail.cause.cause_value);
} else { } else {
m_gtpc_log->warning("Invalid cause in Downlink Data Notification Failure Indication %d\n", m_logger.warning("Invalid cause in Downlink Data Notification Failure Indication %d", not_fail.cause.cause_value);
not_fail.cause.cause_value);
} }
free_all_queued_packets(tunnel_ctx); free_all_queued_packets(tunnel_ctx);
tunnel_ctx->paging_pending = false; tunnel_ctx->paging_pending = false;
@ -471,7 +465,7 @@ bool spgw::gtpc::delete_gtpc_ctx(uint32_t ctrl_teid)
{ {
spgw_tunnel_ctx_t* tunnel_ctx; spgw_tunnel_ctx_t* tunnel_ctx;
if (!m_teid_to_tunnel_ctx.count(ctrl_teid)) { if (!m_teid_to_tunnel_ctx.count(ctrl_teid)) {
m_gtpc_log->error("Could not find GTP context to delete.\n"); m_logger.error("Could not find GTP context to delete.");
return false; return false;
} }
tunnel_ctx = m_teid_to_tunnel_ctx[ctrl_teid]; tunnel_ctx = m_teid_to_tunnel_ctx[ctrl_teid];
@ -495,23 +489,22 @@ bool spgw::gtpc::queue_downlink_packet(uint32_t ctrl_teid, srslte::byte_buffer_t
{ {
spgw_tunnel_ctx_t* tunnel_ctx; spgw_tunnel_ctx_t* tunnel_ctx;
if (!m_teid_to_tunnel_ctx.count(ctrl_teid)) { if (!m_teid_to_tunnel_ctx.count(ctrl_teid)) {
m_gtpc_log->error("Could not find GTP context to queue.\n"); m_logger.error("Could not find GTP context to queue.");
goto pkt_discard; goto pkt_discard;
} }
tunnel_ctx = m_teid_to_tunnel_ctx[ctrl_teid]; tunnel_ctx = m_teid_to_tunnel_ctx[ctrl_teid];
if (!tunnel_ctx->paging_pending) { if (!tunnel_ctx->paging_pending) {
m_gtpc_log->error("Paging not pending. Not queueing packet\n"); m_logger.error("Paging not pending. Not queueing packet");
goto pkt_discard; goto pkt_discard;
} }
if (tunnel_ctx->paging_queue.size() < m_max_paging_queue) { if (tunnel_ctx->paging_queue.size() < m_max_paging_queue) {
tunnel_ctx->paging_queue.push(msg); tunnel_ctx->paging_queue.push(msg);
m_gtpc_log->debug( m_logger.debug(
"Queued packet. IMSI %" PRIu64 ", Packets in Queue %zd\n", tunnel_ctx->imsi, tunnel_ctx->paging_queue.size()); "Queued packet. IMSI %" PRIu64 ", Packets in Queue %zd", tunnel_ctx->imsi, tunnel_ctx->paging_queue.size());
} else { } else {
m_gtpc_log->debug("Paging queue full. IMSI %" PRIu64 ", Packets in Queue %zd\n", m_logger.debug(
tunnel_ctx->imsi, "Paging queue full. IMSI %" PRIu64 ", Packets in Queue %zd", tunnel_ctx->imsi, tunnel_ctx->paging_queue.size());
tunnel_ctx->paging_queue.size());
goto pkt_discard; goto pkt_discard;
} }
return true; return true;
@ -524,12 +517,12 @@ pkt_discard:
bool spgw::gtpc::free_all_queued_packets(spgw_tunnel_ctx_t* tunnel_ctx) bool spgw::gtpc::free_all_queued_packets(spgw_tunnel_ctx_t* tunnel_ctx)
{ {
if (!tunnel_ctx->paging_pending) { if (!tunnel_ctx->paging_pending) {
m_gtpc_log->warning("Freeing queue with paging not pending.\n"); m_logger.warning("Freeing queue with paging not pending.");
} }
while (!tunnel_ctx->paging_queue.empty()) { while (!tunnel_ctx->paging_queue.empty()) {
srslte::byte_buffer_t* pkt = tunnel_ctx->paging_queue.front(); srslte::byte_buffer_t* pkt = tunnel_ctx->paging_queue.front();
m_gtpc_log->debug("Dropping packet. Bytes %d\n", pkt->N_bytes); m_logger.debug("Dropping packet. Bytes %d", pkt->N_bytes);
m_pool->deallocate(pkt); m_pool->deallocate(pkt);
tunnel_ctx->paging_queue.pop(); tunnel_ctx->paging_queue.pop();
} }
@ -542,9 +535,9 @@ int spgw::gtpc::init_ue_ip(spgw_args_t* args, const std::map<std::string, uint64
// check for collision w/our ip address // check for collision w/our ip address
if (iter != ip_to_imsi.end()) { if (iter != ip_to_imsi.end()) {
m_gtpc_log->error("SPGW: static ip addr %s for imsi %015" PRIu64 ", is reserved for the epc tun interface\n", m_logger.error("SPGW: static ip addr %s for imsi %015" PRIu64 ", is reserved for the epc tun interface",
iter->first.c_str(), iter->first.c_str(),
iter->second); iter->second);
return SRSLTE_ERROR_OUT_OF_BOUNDS; return SRSLTE_ERROR_OUT_OF_BOUNDS;
} }
@ -553,8 +546,8 @@ int spgw::gtpc::init_ue_ip(spgw_args_t* args, const std::map<std::string, uint64
struct in_addr in_addr; struct in_addr in_addr;
in_addr.s_addr = inet_addr(iter->first.c_str()); in_addr.s_addr = inet_addr(iter->first.c_str());
if (!m_imsi_to_ip.insert(std::make_pair(iter->second, in_addr)).second) { if (!m_imsi_to_ip.insert(std::make_pair(iter->second, in_addr)).second) {
m_gtpc_log->error( m_logger.error(
"SPGW: duplicate imsi %015" PRIu64 " for static ip address %s.\n", iter->second, iter->first.c_str()); "SPGW: duplicate imsi %015" PRIu64 " for static ip address %s.", iter->second, iter->first.c_str());
return SRSLTE_ERROR_OUT_OF_BOUNDS; return SRSLTE_ERROR_OUT_OF_BOUNDS;
} }
} }
@ -567,12 +560,12 @@ int spgw::gtpc::init_ue_ip(spgw_args_t* args, const std::map<std::string, uint64
std::map<std::string, uint64_t>::const_iterator iter = ip_to_imsi.find(inet_ntoa(ue_addr)); std::map<std::string, uint64_t>::const_iterator iter = ip_to_imsi.find(inet_ntoa(ue_addr));
if (iter != ip_to_imsi.end()) { if (iter != ip_to_imsi.end()) {
m_gtpc_log->debug("SPGW: init_ue_ip ue ip addr %s is reserved for imsi %015" PRIu64 ", not adding to pool\n", m_logger.debug("SPGW: init_ue_ip ue ip addr %s is reserved for imsi %015" PRIu64 ", not adding to pool",
iter->first.c_str(), iter->first.c_str(),
iter->second); iter->second);
} else { } else {
m_ue_ip_addr_pool.insert(ue_addr.s_addr); m_ue_ip_addr_pool.insert(ue_addr.s_addr);
m_gtpc_log->debug("SPGW: init_ue_ip ue ip addr %s is added to pool\n", inet_ntoa(ue_addr)); m_logger.debug("SPGW: init_ue_ip ue ip addr %s is added to pool", inet_ntoa(ue_addr));
} }
} }
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
@ -585,15 +578,15 @@ in_addr_t spgw::gtpc::get_new_ue_ipv4(uint64_t imsi)
std::map<uint64_t, struct in_addr>::const_iterator iter = m_imsi_to_ip.find(imsi); std::map<uint64_t, struct in_addr>::const_iterator iter = m_imsi_to_ip.find(imsi);
if (iter != m_imsi_to_ip.end()) { if (iter != m_imsi_to_ip.end()) {
ue_addr = iter->second; ue_addr = iter->second;
m_gtpc_log->info("SPGW: get_new_ue_ipv4 static ip addr %s\n", inet_ntoa(ue_addr)); m_logger.info("SPGW: get_new_ue_ipv4 static ip addr %s", inet_ntoa(ue_addr));
} else { } else {
if (m_ue_ip_addr_pool.empty()) { if (m_ue_ip_addr_pool.empty()) {
m_gtpc_log->error("SPGW: ue address pool is empty\n"); m_logger.error("SPGW: ue address pool is empty");
ue_addr.s_addr = 0; ue_addr.s_addr = 0;
} else { } else {
ue_addr.s_addr = *m_ue_ip_addr_pool.begin(); ue_addr.s_addr = *m_ue_ip_addr_pool.begin();
m_ue_ip_addr_pool.erase(ue_addr.s_addr); m_ue_ip_addr_pool.erase(ue_addr.s_addr);
m_gtpc_log->info("SPGW: get_new_ue_ipv4 pool ip addr %s\n", inet_ntoa(ue_addr)); m_logger.info("SPGW: get_new_ue_ipv4 pool ip addr %s", inet_ntoa(ue_addr));
} }
} }
return ue_addr.s_addr; return ue_addr.s_addr;

@ -69,7 +69,7 @@ int spgw::gtpu::init(spgw_args_t* args, spgw* spgw, gtpc_interface_gtpu* gtpc, s
return err; return err;
} }
m_gtpu_log->info("SPGW GTP-U Initialized.\n"); m_logger.info("SPGW GTP-U Initialized.");
srslte::console("SPGW GTP-U Initialized.\n"); srslte::console("SPGW GTP-U Initialized.\n");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -97,9 +97,9 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
// Construct the TUN device // Construct the TUN device
m_sgi = open("/dev/net/tun", O_RDWR); m_sgi = open("/dev/net/tun", O_RDWR);
m_gtpu_log->info("TUN file descriptor = %d\n", m_sgi); m_logger.info("TUN file descriptor = %d", m_sgi);
if (m_sgi < 0) { if (m_sgi < 0) {
m_gtpu_log->error("Failed to open TUN device: %s\n", strerror(errno)); m_logger.error("Failed to open TUN device: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
@ -110,7 +110,7 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
ifr.ifr_ifrn.ifrn_name[IFNAMSIZ - 1] = '\0'; ifr.ifr_ifrn.ifrn_name[IFNAMSIZ - 1] = '\0';
if (ioctl(m_sgi, TUNSETIFF, &ifr) < 0) { if (ioctl(m_sgi, TUNSETIFF, &ifr) < 0) {
m_gtpu_log->error("Failed to set TUN device name: %s\n", strerror(errno)); m_logger.error("Failed to set TUN device name: %s", strerror(errno));
close(m_sgi); close(m_sgi);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
@ -118,7 +118,7 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
// Bring up the interface // Bring up the interface
sgi_sock = socket(AF_INET, SOCK_DGRAM, 0); sgi_sock = socket(AF_INET, SOCK_DGRAM, 0);
if (ioctl(sgi_sock, SIOCGIFFLAGS, &ifr) < 0) { if (ioctl(sgi_sock, SIOCGIFFLAGS, &ifr) < 0) {
m_gtpu_log->error("Failed to bring up socket: %s\n", strerror(errno)); m_logger.error("Failed to bring up socket: %s", strerror(errno));
close(sgi_sock); close(sgi_sock);
close(m_sgi); close(m_sgi);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -126,7 +126,7 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
ifr.ifr_flags |= IFF_UP | IFF_RUNNING; ifr.ifr_flags |= IFF_UP | IFF_RUNNING;
if (ioctl(sgi_sock, SIOCSIFFLAGS, &ifr) < 0) { if (ioctl(sgi_sock, SIOCSIFFLAGS, &ifr) < 0) {
m_gtpu_log->error("Failed to set socket flags: %s\n", strerror(errno)); m_logger.error("Failed to set socket flags: %s", strerror(errno));
close(sgi_sock); close(sgi_sock);
close(m_sgi); close(m_sgi);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -139,8 +139,8 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
addr->sin_port = 0; addr->sin_port = 0;
if (ioctl(sgi_sock, SIOCSIFADDR, &ifr) < 0) { if (ioctl(sgi_sock, SIOCSIFADDR, &ifr) < 0) {
m_gtpu_log->error( m_logger.error(
"Failed to set TUN interface IP. Address: %s, Error: %s\n", args->sgi_if_addr.c_str(), strerror(errno)); "Failed to set TUN interface IP. Address: %s, Error: %s", args->sgi_if_addr.c_str(), strerror(errno));
close(m_sgi); close(m_sgi);
close(sgi_sock); close(sgi_sock);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -149,7 +149,7 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
ifr.ifr_netmask.sa_family = AF_INET; ifr.ifr_netmask.sa_family = AF_INET;
((struct sockaddr_in*)&ifr.ifr_netmask)->sin_addr.s_addr = inet_addr("255.255.255.0"); ((struct sockaddr_in*)&ifr.ifr_netmask)->sin_addr.s_addr = inet_addr("255.255.255.0");
if (ioctl(sgi_sock, SIOCSIFNETMASK, &ifr) < 0) { if (ioctl(sgi_sock, SIOCSIFNETMASK, &ifr) < 0) {
m_gtpu_log->error("Failed to set TUN interface Netmask. Error: %s\n", strerror(errno)); m_logger.error("Failed to set TUN interface Netmask. Error: %s", strerror(errno));
close(m_sgi); close(m_sgi);
close(sgi_sock); close(sgi_sock);
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
@ -157,7 +157,7 @@ int spgw::gtpu::init_sgi(spgw_args_t* args)
close(sgi_sock); close(sgi_sock);
m_sgi_up = true; m_sgi_up = true;
m_gtpu_log->info("Initialized SGi interface\n"); m_logger.info("Initialized SGi interface");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -166,7 +166,7 @@ int spgw::gtpu::init_s1u(spgw_args_t* args)
// Open S1-U socket // Open S1-U socket
m_s1u = socket(AF_INET, SOCK_DGRAM, 0); m_s1u = socket(AF_INET, SOCK_DGRAM, 0);
if (m_s1u == -1) { if (m_s1u == -1) {
m_gtpu_log->error("Failed to open socket: %s\n", strerror(errno)); m_logger.error("Failed to open socket: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
m_s1u_up = true; m_s1u_up = true;
@ -177,13 +177,13 @@ int spgw::gtpu::init_s1u(spgw_args_t* args)
m_s1u_addr.sin_port = htons(GTPU_RX_PORT); m_s1u_addr.sin_port = htons(GTPU_RX_PORT);
if (bind(m_s1u, (struct sockaddr*)&m_s1u_addr, sizeof(struct sockaddr_in))) { if (bind(m_s1u, (struct sockaddr*)&m_s1u_addr, sizeof(struct sockaddr_in))) {
m_gtpu_log->error("Failed to bind socket: %s\n", strerror(errno)); m_logger.error("Failed to bind socket: %s", strerror(errno));
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
m_gtpu_log->info("S1-U socket = %d\n", m_s1u); m_logger.info("S1-U socket = %d", m_s1u);
m_gtpu_log->info("S1-U IP = %s, Port = %d \n", inet_ntoa(m_s1u_addr.sin_addr), ntohs(m_s1u_addr.sin_port)); m_logger.info("S1-U IP = %s, Port = %d ", inet_ntoa(m_s1u_addr.sin_addr), ntohs(m_s1u_addr.sin_port));
m_gtpu_log->info("Initialized S1-U interface\n"); m_logger.info("Initialized S1-U interface");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -197,21 +197,21 @@ void spgw::gtpu::handle_sgi_pdu(srslte::byte_buffer_t* msg)
srslte::gtpc_f_teid_ie enb_fteid; srslte::gtpc_f_teid_ie enb_fteid;
uint32_t spgw_teid; uint32_t spgw_teid;
struct iphdr* iph = (struct iphdr*)msg->msg; struct iphdr* iph = (struct iphdr*)msg->msg;
m_gtpu_log->debug("Received SGi PDU. Bytes %d\n", msg->N_bytes); m_logger.debug("Received SGi PDU. Bytes %d", msg->N_bytes);
if (iph->version != 4) { if (iph->version != 4) {
m_gtpu_log->info("IPv6 not supported yet.\n"); m_logger.info("IPv6 not supported yet.");
return; return;
} }
if (ntohs(iph->tot_len) < 20) { if (ntohs(iph->tot_len) < 20) {
m_gtpu_log->warning("Invalid IP header length. IP length %d.\n", ntohs(iph->tot_len)); m_logger.warning("Invalid IP header length. IP length %d.", ntohs(iph->tot_len));
return; return;
} }
// Logging PDU info // Logging PDU info
m_gtpu_log->debug("SGi PDU -- IP version %d, Total length %d\n", iph->version, ntohs(iph->tot_len)); m_logger.debug("SGi PDU -- IP version %d, Total length %d", int(iph->version), ntohs(iph->tot_len));
m_gtpu_log->debug("SGi PDU -- IP src addr %s\n", srslte::gtpu_ntoa(iph->saddr).c_str()); m_logger.debug("SGi PDU -- IP src addr %s", srslte::gtpu_ntoa(iph->saddr).c_str());
m_gtpu_log->debug("SGi PDU -- IP dst addr %s\n", srslte::gtpu_ntoa(iph->daddr).c_str()); m_logger.debug("SGi PDU -- IP dst addr %s", srslte::gtpu_ntoa(iph->daddr).c_str());
// Find user and control tunnel // Find user and control tunnel
gtpu_fteid_it = m_ip_to_usr_teid.find(iph->daddr); gtpu_fteid_it = m_ip_to_usr_teid.find(iph->daddr);
@ -227,16 +227,16 @@ void spgw::gtpu::handle_sgi_pdu(srslte::byte_buffer_t* msg)
// Handle SGi packet // Handle SGi packet
if (usr_found == false && ctr_found == false) { if (usr_found == false && ctr_found == false) {
m_gtpu_log->debug("Packet for unknown UE.\n"); m_logger.debug("Packet for unknown UE.");
goto pkt_discard_out; goto pkt_discard_out;
} else if (usr_found == false && ctr_found == true) { } else if (usr_found == false && ctr_found == true) {
m_gtpu_log->debug("Packet for attached UE that is not ECM connected.\n"); m_logger.debug("Packet for attached UE that is not ECM connected.");
m_gtpu_log->debug("Triggering Donwlink Notification Requset.\n"); m_logger.debug("Triggering Donwlink Notification Requset.");
m_gtpc->send_downlink_data_notification(spgw_teid); m_gtpc->send_downlink_data_notification(spgw_teid);
m_gtpc->queue_downlink_packet(spgw_teid, msg); m_gtpc->queue_downlink_packet(spgw_teid, msg);
return; return;
} else if (usr_found == false && ctr_found == true) { } else if (usr_found == false && ctr_found == true) {
m_gtpu_log->error("User plane tunnel found without a control plane tunnel present.\n"); m_logger.error("User plane tunnel found without a control plane tunnel present.");
goto pkt_discard_out; goto pkt_discard_out;
} else { } else {
send_s1u_pdu(enb_fteid, msg); send_s1u_pdu(enb_fteid, msg);
@ -253,13 +253,13 @@ void spgw::gtpu::handle_s1u_pdu(srslte::byte_buffer_t* msg)
srslte::gtpu_header_t header; srslte::gtpu_header_t header;
srslte::gtpu_read_header(msg, &header, m_gtpu_log); srslte::gtpu_read_header(msg, &header, m_gtpu_log);
m_gtpu_log->debug("Received PDU from S1-U. Bytes=%d\n", msg->N_bytes); m_logger.debug("Received PDU from S1-U. Bytes=%d", msg->N_bytes);
m_gtpu_log->debug("TEID 0x%x. Bytes=%d\n", header.teid, msg->N_bytes); m_logger.debug("TEID 0x%x. Bytes=%d", header.teid, msg->N_bytes);
int n = write(m_sgi, msg->msg, msg->N_bytes); int n = write(m_sgi, msg->msg, msg->N_bytes);
if (n < 0) { if (n < 0) {
m_gtpu_log->error("Could not write to TUN interface.\n"); m_logger.error("Could not write to TUN interface.");
} else { } else {
m_gtpu_log->debug("Forwarded packet to TUN interface. Bytes= %d/%d\n", n, msg->N_bytes); m_logger.debug("Forwarded packet to TUN interface. Bytes= %d/%d", n, msg->N_bytes);
} }
return; return;
} }
@ -279,26 +279,26 @@ void spgw::gtpu::send_s1u_pdu(srslte::gtp_fteid_t enb_fteid, srslte::byte_buffer
header.length = msg->N_bytes; header.length = msg->N_bytes;
header.teid = enb_fteid.teid; header.teid = enb_fteid.teid;
m_gtpu_log->debug("User plane tunnel found SGi PDU. Forwarding packet to S1-U.\n"); m_logger.debug("User plane tunnel found SGi PDU. Forwarding packet to S1-U.");
m_gtpu_log->debug("eNB F-TEID -- eNB IP %s, eNB TEID 0x%x.\n", inet_ntoa(enb_addr.sin_addr), enb_fteid.teid); m_logger.debug("eNB F-TEID -- eNB IP %s, eNB TEID 0x%x.", inet_ntoa(enb_addr.sin_addr), enb_fteid.teid);
// Write header into packet // Write header into packet
int n; int n;
if (!srslte::gtpu_write_header(&header, msg, m_gtpu_log)) { if (!srslte::gtpu_write_header(&header, msg, m_gtpu_log)) {
m_gtpu_log->error("Error writing GTP-U header on PDU\n"); m_logger.error("Error writing GTP-U header on PDU");
goto out; goto out;
} }
// Send packet to destination // Send packet to destination
n = sendto(m_s1u, msg->msg, msg->N_bytes, 0, (struct sockaddr*)&enb_addr, sizeof(enb_addr)); n = sendto(m_s1u, msg->msg, msg->N_bytes, 0, (struct sockaddr*)&enb_addr, sizeof(enb_addr));
if (n < 0) { if (n < 0) {
m_gtpu_log->error("Error sending packet to eNB\n"); m_logger.error("Error sending packet to eNB");
} else if ((unsigned int)n != msg->N_bytes) { } else if ((unsigned int)n != msg->N_bytes) {
m_gtpu_log->error("Mis-match between packet bytes and sent bytes: Sent: %d/%d\n", n, msg->N_bytes); m_logger.error("Mis-match between packet bytes and sent bytes: Sent: %d/%d", n, msg->N_bytes);
} }
out: out:
m_gtpu_log->debug("Deallocating packet after sending S1-U message\n"); m_logger.debug("Deallocating packet after sending S1-U message");
m_pool->deallocate(msg); m_pool->deallocate(msg);
return; return;
} }
@ -306,7 +306,7 @@ out:
void spgw::gtpu::send_all_queued_packets(srslte::gtp_fteid_t dw_user_fteid, void spgw::gtpu::send_all_queued_packets(srslte::gtp_fteid_t dw_user_fteid,
std::queue<srslte::byte_buffer_t*>& pkt_queue) std::queue<srslte::byte_buffer_t*>& pkt_queue)
{ {
m_gtpu_log->debug("Sending all queued packets\n"); m_logger.debug("Sending all queued packets");
while (!pkt_queue.empty()) { while (!pkt_queue.empty()) {
srslte::byte_buffer_t* msg = pkt_queue.front(); srslte::byte_buffer_t* msg = pkt_queue.front();
send_s1u_pdu(dw_user_fteid, msg); send_s1u_pdu(dw_user_fteid, msg);
@ -320,11 +320,10 @@ void spgw::gtpu::send_all_queued_packets(srslte::gtp_fteid_t dw_
*/ */
bool spgw::gtpu::modify_gtpu_tunnel(in_addr_t ue_ipv4, srslte::gtpc_f_teid_ie dw_user_fteid, uint32_t up_ctrl_teid) bool spgw::gtpu::modify_gtpu_tunnel(in_addr_t ue_ipv4, srslte::gtpc_f_teid_ie dw_user_fteid, uint32_t up_ctrl_teid)
{ {
m_gtpu_log->info("Modifying GTP-U Tunnel.\n"); m_logger.info("Modifying GTP-U Tunnel.");
m_gtpu_log->info("UE IP %s\n", srslte::gtpu_ntoa(ue_ipv4).c_str()); m_logger.info("UE IP %s", srslte::gtpu_ntoa(ue_ipv4).c_str());
m_gtpu_log->info( m_logger.info("Downlink eNB addr %s, U-TEID 0x%x", srslte::gtpu_ntoa(dw_user_fteid.ipv4).c_str(), dw_user_fteid.teid);
"Downlink eNB addr %s, U-TEID 0x%x\n", srslte::gtpu_ntoa(dw_user_fteid.ipv4).c_str(), dw_user_fteid.teid); m_logger.info("Uplink C-TEID: 0x%x", up_ctrl_teid);
m_gtpu_log->info("Uplink C-TEID: 0x%x\n", up_ctrl_teid);
m_ip_to_usr_teid[ue_ipv4] = dw_user_fteid; m_ip_to_usr_teid[ue_ipv4] = dw_user_fteid;
m_ip_to_ctr_teid[ue_ipv4] = up_ctrl_teid; m_ip_to_ctr_teid[ue_ipv4] = up_ctrl_teid;
return true; return true;
@ -336,7 +335,7 @@ bool spgw::gtpu::delete_gtpu_tunnel(in_addr_t ue_ipv4)
if (m_ip_to_usr_teid.count(ue_ipv4)) { if (m_ip_to_usr_teid.count(ue_ipv4)) {
m_ip_to_usr_teid.erase(ue_ipv4); m_ip_to_usr_teid.erase(ue_ipv4);
} else { } else {
m_gtpu_log->error("Could not find GTP-U Tunnel to delete.\n"); m_logger.error("Could not find GTP-U Tunnel to delete.");
return false; return false;
} }
return true; return true;
@ -348,7 +347,7 @@ bool spgw::gtpu::delete_gtpc_tunnel(in_addr_t ue_ipv4)
if (m_ip_to_ctr_teid.count(ue_ipv4)) { if (m_ip_to_ctr_teid.count(ue_ipv4)) {
m_ip_to_ctr_teid.erase(ue_ipv4); m_ip_to_ctr_teid.erase(ue_ipv4);
} else { } else {
m_gtpu_log->error("Could not find GTP-C Tunnel info to delete.\n"); m_logger.error("Could not find GTP-C Tunnel info to delete.");
return false; return false;
} }
return true; return true;

@ -56,18 +56,11 @@ void spgw::cleanup()
pthread_mutex_unlock(&spgw_instance_mutex); pthread_mutex_unlock(&spgw_instance_mutex);
} }
int spgw::init(spgw_args_t* args, int spgw::init(spgw_args_t* args, srslte::log_ref gtpu_log, const std::map<std::string, uint64_t>& ip_to_imsi)
srslte::log_ref gtpu_log,
srslte::log_filter* gtpc_log,
srslte::log_filter* spgw_log,
const std::map<std::string, uint64_t>& ip_to_imsi)
{ {
int err; int err;
m_pool = srslte::byte_buffer_pool::get_instance(); m_pool = srslte::byte_buffer_pool::get_instance();
// Init log
m_spgw_log = spgw_log;
// Init GTP-U // Init GTP-U
if (m_gtpu->init(args, this, m_gtpc, gtpu_log) != SRSLTE_SUCCESS) { if (m_gtpu->init(args, this, m_gtpc, gtpu_log) != SRSLTE_SUCCESS) {
srslte::console("Could not initialize the SPGW's GTP-U.\n"); srslte::console("Could not initialize the SPGW's GTP-U.\n");
@ -75,12 +68,12 @@ int spgw::init(spgw_args_t* args,
} }
// Init GTP-C // Init GTP-C
if (m_gtpc->init(args, this, m_gtpu, gtpc_log, ip_to_imsi) != SRSLTE_SUCCESS) { if (m_gtpc->init(args, this, m_gtpu, ip_to_imsi) != SRSLTE_SUCCESS) {
srslte::console("Could not initialize the S1-U interface.\n"); srslte::console("Could not initialize the S1-U interface.\n");
return SRSLTE_ERROR_CANT_START; return SRSLTE_ERROR_CANT_START;
} }
m_spgw_log->info("SP-GW Initialized.\n"); m_logger.info("SP-GW Initialized.");
srslte::console("SP-GW Initialized.\n"); srslte::console("SP-GW Initialized.\n");
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -131,7 +124,7 @@ void spgw::run_thread()
int n = select(max_fd + 1, &set, NULL, NULL, NULL); int n = select(max_fd + 1, &set, NULL, NULL, NULL);
if (n == -1) { if (n == -1) {
m_spgw_log->error("Error from select\n"); m_logger.error("Error from select");
} else if (n) { } else if (n) {
if (FD_ISSET(sgi, &set)) { if (FD_ISSET(sgi, &set)) {
/* /*
@ -142,25 +135,25 @@ void spgw::run_thread()
* procedure fails (see handle_downlink_data_notification_acknowledgment and * procedure fails (see handle_downlink_data_notification_acknowledgment and
* handle_downlink_data_notification_failure) * handle_downlink_data_notification_failure)
*/ */
m_spgw_log->debug("Message received at SPGW: SGi Message\n"); m_logger.debug("Message received at SPGW: SGi Message");
sgi_msg = m_pool->allocate("spgw::run_thread::sgi_msg"); sgi_msg = m_pool->allocate("spgw::run_thread::sgi_msg");
sgi_msg->N_bytes = read(sgi, sgi_msg->msg, buf_len); sgi_msg->N_bytes = read(sgi, sgi_msg->msg, buf_len);
m_gtpu->handle_sgi_pdu(sgi_msg); m_gtpu->handle_sgi_pdu(sgi_msg);
} }
if (FD_ISSET(s1u, &set)) { if (FD_ISSET(s1u, &set)) {
m_spgw_log->debug("Message received at SPGW: S1-U Message\n"); m_logger.debug("Message received at SPGW: S1-U Message");
socklen_t addrlen = sizeof(src_addr_in); socklen_t addrlen = sizeof(src_addr_in);
s1u_msg->N_bytes = recvfrom(s1u, s1u_msg->msg, buf_len, 0, (struct sockaddr*)&src_addr_in, &addrlen); s1u_msg->N_bytes = recvfrom(s1u, s1u_msg->msg, buf_len, 0, (struct sockaddr*)&src_addr_in, &addrlen);
m_gtpu->handle_s1u_pdu(s1u_msg); m_gtpu->handle_s1u_pdu(s1u_msg);
} }
if (FD_ISSET(s11, &set)) { if (FD_ISSET(s11, &set)) {
m_spgw_log->debug("Message received at SPGW: S11 Message\n"); m_logger.debug("Message received at SPGW: S11 Message");
socklen_t addrlen = sizeof(src_addr_un); socklen_t addrlen = sizeof(src_addr_un);
s11_msg->N_bytes = recvfrom(s11, s11_msg->msg, buf_len, 0, (struct sockaddr*)&src_addr_un, &addrlen); s11_msg->N_bytes = recvfrom(s11, s11_msg->msg, buf_len, 0, (struct sockaddr*)&src_addr_un, &addrlen);
m_gtpc->handle_s11_pdu(s11_msg); m_gtpc->handle_s11_pdu(s11_msg);
} }
} else { } else {
m_spgw_log->debug("No data from select.\n"); m_logger.debug("No data from select.");
} }
} }
m_pool->deallocate(s1u_msg); m_pool->deallocate(s1u_msg);

Loading…
Cancel
Save