Changed log methods to take string literal vs string object

to allow for format checking and save on object copy.
Fixed log format specifier warnings.

CMakeLists.txt

@@ -226,7 +226,7 @@ macro(ADD_CXX_COMPILER_FLAG_IF_AVAILABLE flag have)
 endmacro(ADD_CXX_COMPILER_FLAG_IF_AVAILABLE)
 
 if(CMAKE_CXX_COMPILER_ID MATCHES "GNU" OR CMAKE_CXX_COMPILER_ID MATCHES "Clang")
-  set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -march=${GCC_ARCH} -Wall -Wno-comment -Wno-reorder -Wno-unused-but-set-variable -Wno-unused-variable -std=c++03")
+  set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -march=${GCC_ARCH} -Wall -Wno-comment -Wno-reorder -Wno-unused-but-set-variable -Wno-unused-variable -Wformat -std=c++03")
 
   find_package(SSE)
   if (HAVE_AVX2)

lib/include/srslte/common/log.h

@@ -122,11 +122,11 @@ class log
   }
 
   // Pure virtual methods for logging
-  virtual void console(std::string message, ...) = 0;
-  virtual void error(std::string message, ...)   = 0;
-  virtual void warning(std::string message, ...) = 0;
-  virtual void info(std::string message, ...)    = 0;
-  virtual void debug(std::string message, ...)   = 0;
+  virtual void console(const char * message, ...) __attribute__ ((format (printf, 2, 3))) = 0;
+  virtual void error(const char * message, ...)   __attribute__ ((format (printf, 2, 3))) = 0;
+  virtual void warning(const char * message, ...) __attribute__ ((format (printf, 2, 3))) = 0;
+  virtual void info(const char * message, ...)    __attribute__ ((format (printf, 2, 3))) = 0;
+  virtual void debug(const char * message, ...)   __attribute__ ((format (printf, 2, 3))) = 0;
 
   // Same with hex dump
   virtual void error_hex(uint8_t *hex, int size, std::string message, ...){error("error_hex not implemented.\n");}

lib/include/srslte/common/log_filter.h

@@ -57,11 +57,11 @@ class log_filter : public srslte::log
 
   void init(std::string layer, logger *logger_, bool tti=false);
 
-  void console(std::string message, ...);
-  void error(std::string message, ...);
-  void warning(std::string message, ...);
-  void info(std::string message, ...);
-  void debug(std::string message, ...);
+  void console(const char * message, ...);
+  void error(const char * message, ...);
+  void warning(const char * message, ...);
+  void info(const char * message, ...);
+  void debug(const char * message, ...);
 
   void error_hex(uint8_t *hex, int size, std::string message, ...);
   void warning_hex(uint8_t *hex, int size, std::string message, ...);

lib/src/common/log_filter.cc

@@ -135,55 +135,55 @@ void log_filter::all_log(srslte::LOG_LEVEL_ENUM level,
   }
 }
 
-void log_filter::console(std::string message, ...) {
+void log_filter::console(const char * message, ...) {
   char     *args_msg;
   va_list   args;
   va_start(args, message);
-  if(vasprintf(&args_msg, message.c_str(), args) > 0)
+  if(vasprintf(&args_msg, message, args) > 0)
     printf("%s",args_msg); // Print directly to stdout
   va_end(args);
   free(args_msg);
 }
 
-void log_filter::error(std::string message, ...) {
+void log_filter::error(const char * message, ...) {
   if (level >= LOG_LEVEL_ERROR) {
     char     *args_msg;
     va_list   args;
     va_start(args, message);
-    if(vasprintf(&args_msg, message.c_str(), args) > 0)
+    if(vasprintf(&args_msg, message, args) > 0)
       all_log(LOG_LEVEL_ERROR, tti, args_msg);
     va_end(args);
     free(args_msg);
   }
 }
-void log_filter::warning(std::string message, ...) {
+void log_filter::warning(const char * message, ...) {
   if (level >= LOG_LEVEL_WARNING) {
     char     *args_msg;
     va_list   args;
     va_start(args, message);
-    if(vasprintf(&args_msg, message.c_str(), args) > 0)
+    if(vasprintf(&args_msg, message, args) > 0)
       all_log(LOG_LEVEL_WARNING, tti, args_msg);
     va_end(args);
     free(args_msg);
   }
 }
-void log_filter::info(std::string message, ...) {
+void log_filter::info(const char * message, ...) {
   if (level >= LOG_LEVEL_INFO) {
     char     *args_msg;
     va_list   args;
     va_start(args, message);
-    if(vasprintf(&args_msg, message.c_str(), args) > 0)
+    if(vasprintf(&args_msg, message, args) > 0)
       all_log(LOG_LEVEL_INFO, tti, args_msg);
     va_end(args);
     free(args_msg);
   }
 }
-void log_filter::debug(std::string message, ...) {
+void log_filter::debug(const char * message, ...) {
   if (level >= LOG_LEVEL_DEBUG) {
     char     *args_msg;
     va_list   args;
     va_start(args, message);
-    if(vasprintf(&args_msg, message.c_str(), args) > 0)
+    if(vasprintf(&args_msg, message, args) > 0)
       all_log(LOG_LEVEL_DEBUG, tti, args_msg);
     va_end(args);
     free(args_msg);

lib/src/upper/rlc_am.cc

@@ -342,7 +342,7 @@ int rlc_am::read_pdu(uint8_t *payload, uint32_t nof_bytes)
   pthread_mutex_lock(&mutex);
 
   log->debug("MAC opportunity - %d bytes\n", nof_bytes);
-  log->debug("tx_window size - %d PDUs\n", tx_window.size());
+  log->debug("tx_window size - %zu PDUs\n", tx_window.size());
 
   // Tx STATUS if requested
   if(do_status && !status_prohibited()) {
@@ -698,7 +698,7 @@ int rlc_am::build_segment(uint8_t *payload, uint32_t nof_bytes, rlc_amd_retx_t r
   if(pdu_len > (int)nof_bytes) {
     log->error("%s Retx PDU segment length error. Available: %d, Used: %d\n",
                rrc->get_rb_name(lcid).c_str(), nof_bytes, pdu_len);
-    log->debug("%s Retx PDU segment length error. Header len: %d, Payload len: %d, N_li: %d\n",
+    log->debug("%s Retx PDU segment length error. Header len: %ld, Payload len: %d, N_li: %d\n",
                rrc->get_rb_name(lcid).c_str(), (ptr-payload), len, new_header.N_li);
   }
   return pdu_len;

srsenb/src/enb.cc

@@ -297,7 +297,7 @@ void enb::handle_rf_msg(srslte_rf_error_t error)
     str.erase(std::remove(str.begin(), str.end(), '\n'), str.end());
     str.erase(std::remove(str.begin(), str.end(), '\r'), str.end());
     str.push_back('\n');
-    rf_log.info(str);
+    rf_log.info(str.c_str());
   }
 }
 

srsenb/src/phy/phch_worker.cc

@@ -227,7 +227,7 @@ void phch_worker::set_conf_dedicated_ack(uint16_t rnti, bool ack){
   if (ue_db.count(rnti)) {
     ue_db[rnti].dedicated_ack = ack;
   } else {
-    Error("Setting dedicated ack: rnti=0x%x does not exist\n");
+    Error("Setting dedicated ack: rnti=0x%x does not exist\n", rnti);
   }
   pthread_mutex_unlock(&mutex);
 }
@@ -309,7 +309,7 @@ void phch_worker::set_config_dedicated(uint16_t rnti,
       ue_db[rnti].dedicated.pdsch_cnfg_ded = dedicated->pdsch_cnfg_ded;
     }
   } else {
-    Error("Setting config dedicated: rnti=0x%x does not exist\n");
+    Error("Setting config dedicated: rnti=0x%x does not exist\n", rnti);
   }
   pthread_mutex_unlock(&mutex);
 }

srsenb/src/phy/txrx.cc

@@ -125,7 +125,7 @@ void txrx::run_thread()
       srslte_timestamp_copy(&tx_time, &rx_time);
       srslte_timestamp_add(&tx_time, 0, HARQ_DELAY_MS*1e-3);
 
-      Debug("Settting TTI=%d, tx_mutex=%d, tx_time=%d:%f to worker %d\n", 
+      Debug("Settting TTI=%d, tx_mutex=%d, tx_time=%ld:%f to worker %d\n", 
             tti, tx_mutex_cnt, 
             tx_time.full_secs, tx_time.frac_secs,
             worker->get_id());

srsenb/src/upper/rrc.cc

@@ -225,7 +225,7 @@ void rrc::add_user(uint16_t rnti)
     pdcp->add_user(rnti);    
     rrc_log->info("Added new user rnti=0x%x\n", rnti);
   } else {
-    rrc_log->error("Adding user rnti=0x%x (already exists)\n");
+    rrc_log->error("Adding user rnti=0x%x (already exists)\n", rnti);
   }
   pthread_mutex_unlock(&user_mutex);
 }
@@ -584,7 +584,7 @@ void rrc::parse_ul_ccch(uint16_t rnti, byte_buffer_t *pdu)
         if (users[rnti].is_idle()) {
           old_rnti = ul_ccch_msg.msg.rrc_con_reest_req.ue_id.c_rnti;
           if (users.count(old_rnti)) {
-            rrc_log->error("Not supported: ConnectionReestablishment. Sending Connection Reject\n", old_rnti);
+            rrc_log->error("Not supported: ConnectionReestablishment for rnti=0x%x. Sending Connection Reject\n", old_rnti);
             users[rnti].send_connection_reest_rej();
             rem_user_thread(old_rnti);
           } else {
@@ -649,7 +649,7 @@ void rrc::run_thread()
           pthread_mutex_lock(&user_mutex);
           break;
         default:
-          rrc_log->error("Rx PDU with invalid bearer id: %s", p.lcid);
+          rrc_log->error("Rx PDU with invalid bearer id: %d", p.lcid);
           break;
       }
     } else {
@@ -799,7 +799,7 @@ bool rrc::ue::is_timeout()
     int64_t deadline = deadline_s*1e6  + deadline_us;
     int64_t elapsed  = t[0].tv_sec*1e6 + t[0].tv_usec;
     if (elapsed > deadline && elapsed > 0) {
-      parent->rrc_log->warning("User rnti=0x%x expired %s deadline: %d:%d>%d:%d us\n", 
+      parent->rrc_log->warning("User rnti=0x%x expired %s deadline: %ld:%ld>%d:%d us\n", 
                                 rnti, deadline_str, 
                                 t[0].tv_sec, t[0].tv_usec, 
                                deadline_s, deadline_us);

srsepc/src/mme/s1ap_nas_transport.cc

@@ -1128,13 +1128,13 @@ s1ap_nas_transport::handle_esm_information_response(srslte::byte_buffer_t *nas_m
   m_s1ap_log->info("ESM Info: EPS bearer id %d\n",esm_info_resp.eps_bearer_id);
   if(esm_info_resp.apn_present)
   {
-    m_s1ap_log->info("ESM Info: APN %s\n",esm_info_resp.eps_bearer_id);
-    m_s1ap_log->console("ESM Info: APN %s\n",esm_info_resp.eps_bearer_id);
+    m_s1ap_log->info("ESM Info: APN %d\n",esm_info_resp.eps_bearer_id);
+    m_s1ap_log->console("ESM Info: APN %d\n",esm_info_resp.eps_bearer_id);
   }
   if(esm_info_resp.protocol_cnfg_opts_present)
   {
-    m_s1ap_log->info("ESM Info: %d Protocol Configuration Options %s\n",esm_info_resp.protocol_cnfg_opts.N_opts);
-    m_s1ap_log->console("ESM Info: %d Protocol Configuration Options %s\n",esm_info_resp.protocol_cnfg_opts.N_opts);
+    m_s1ap_log->info("ESM Info: %d Protocol Configuration Options\n",esm_info_resp.protocol_cnfg_opts.N_opts);
+    m_s1ap_log->console("ESM Info: %d Protocol Configuration Options\n",esm_info_resp.protocol_cnfg_opts.N_opts);
   }
 
   //FIXME The packging of GTP-C messages is not ready.

srsue/src/mac/proc_phr.cc

@@ -91,7 +91,7 @@ void phr_proc::timer_expired(uint32_t timer_id) {
   } else if (timer_id == timer_prohibit_id) {
     int pathloss_db = liblte_rrc_dl_pathloss_change_num[mac_cfg->main.phr_cnfg.dl_pathloss_change];
     if (pathloss_changed()) {
-      Info("PHR:   Triggered by pathloss difference. cur_pathloss_db=%f (timer expired)\n", last_pathloss_db);
+      Info("PHR:   Triggered by pathloss difference. cur_pathloss_db=%d (timer expired)\n", last_pathloss_db);
       phr_is_triggered = true;
     }
   } else {
@@ -132,7 +132,7 @@ void phr_proc::step(uint32_t tti)
   }  
   if (pathloss_changed() && timers_db->get(timer_prohibit_id)->is_expired())
   {
-    Info("PHR:   Triggered by pathloss difference. cur_pathloss_db=%f\n", last_pathloss_db);
+    Info("PHR:   Triggered by pathloss difference. cur_pathloss_db=%d\n", last_pathloss_db);
     phr_is_triggered = true;        
   }
 }

srsue/src/phy/phch_recv.cc

@@ -275,7 +275,7 @@ void phch_recv::cell_search_inc()
       phy_state = IDLE;
       rrc->earfcn_end();
     } else {
-      Info("SYNC:  Cell Search idx %d/%d\n", cur_earfcn_index, earfcn.size());
+      Info("SYNC:  Cell Search idx %d/%zu\n", cur_earfcn_index, earfcn.size());
       if (current_earfcn != earfcn[cur_earfcn_index]) {
         current_earfcn = earfcn[cur_earfcn_index];
         set_frequency();
@@ -297,7 +297,7 @@ void phch_recv::cell_search_start() {
     Warning("SYNC:  Can't start cell search procedure while camping on cell\n");
   } else {
     if (earfcn.size() > 0) {
-      Info("SYNC:  Starting Cell Search procedure in %d EARFCNs...\n", earfcn.size());
+      Info("SYNC:  Starting Cell Search procedure in %zu EARFCNs...\n", earfcn.size());
       cell_search_next(true);
     } else {
       Info("SYNC:  Empty EARFCN list. Stopping cell search...\n");
@@ -1502,7 +1502,7 @@ void phch_recv::intra_measure::rem_cell(int pci) {
     if (active_pci.size() == 0) {
       receive_enabled = false;
     }
-    Info("INTRA: Stopping intra-frequency measurement for pci=%d. Number of cells: %d\n", pci, active_pci.size());
+    Info("INTRA: Stopping intra-frequency measurement for pci=%d. Number of cells: %zu\n", pci, active_pci.size());
   } else {
     Warning("INTRA: Requested to stop non-existing intra-frequency measurement for PCI=%d\n", pci);
   }

srsue/src/phy/prach.cc

@@ -201,7 +201,7 @@ void prach::send(srslte::radio *radio_handler, float cfo, float pathloss, srslte
     float scale = sqrtf(pow(10,tx_power/10)/digital_power);
 
     srslte_vec_sc_prod_cfc(signal_buffer, scale, signal_buffer, len);
-    log_h->console("PRACH: Pathloss=%.2f dB, Target power %.2f dBm, TX_power %.2f dBm, TX_gain %.1f dB\n",
+    log_h->console("PRACH: Pathloss=%.2f dB, Target power %.2f dBm, TX_power %.2f dBm, TX_gain %.1f dB, scale %.2f\n",
           pathloss, target_power_dbm, tx_power, radio_handler->get_tx_gain(), scale);
 
   } else {

srsue/src/ue_base.cc

@@ -104,7 +104,7 @@ void ue_base::handle_rf_msg(srslte_rf_error_t error)
     str.erase(std::remove(str.begin(), str.end(), '\n'), str.end());
     str.erase(std::remove(str.begin(), str.end(), '\r'), str.end());
     str.push_back('\n');
-    rf_log.info(str);
+    rf_log.info(str.c_str());
   }
 }
 

srsue/src/upper/nas.cc

@@ -682,7 +682,7 @@ void nas::parse_identity_request(uint32_t lcid, byte_buffer_t *pdu) {
     usim->get_imei_vec(id_resp.mobile_id.imei, 15);
     break;
   default:
-    nas_log->error("Unhandled ID type: %d\n");
+    nas_log->error("Unhandled ID type: %d\n", id_req.id_type);
     pool->deallocate(pdu);
     return;
   }

srsue/src/upper/rrc.cc

@@ -1680,7 +1680,7 @@ void rrc::write_pdu(uint32_t lcid, byte_buffer_t *pdu) {
       parse_dl_dcch(lcid, pdu);
       break;
     default:
-      rrc_log->error("RX PDU with invalid bearer id: %s", lcid);
+      rrc_log->error("RX PDU with invalid bearer id: %d", lcid);
       break;
   }
 }
@@ -2891,8 +2891,8 @@ void rrc::rrc_meas::parse_meas_config(LIBLTE_RRC_MEAS_CONFIG_STRUCT *cfg)
 
           log_h->info("MEAS: Added measObjectId=%d, earfcn=%d, q_offset=%f, pci=%d, offset_cell=%f\n",
                       cfg->meas_obj_to_add_mod_list.meas_obj_list[i].meas_obj_id, dst_obj->earfcn, dst_obj->q_offset,
-                      dst_obj->cells[src_obj->cells_to_add_mod_list[j].cell_idx].q_offset,
-                      dst_obj->cells[src_obj->cells_to_add_mod_list[j].cell_idx].pci);
+                      dst_obj->cells[src_obj->cells_to_add_mod_list[j].cell_idx].pci,
+                      dst_obj->cells[src_obj->cells_to_add_mod_list[j].cell_idx].q_offset);
 
         }
 

srsue/src/upper/usim.cc

@@ -49,8 +49,8 @@ void usim::init(usim_args_t *args, srslte::log *usim_log_)
   if(32 == args->op.length()) {
     str_to_hex(args->op, op);
   } else {
-    usim_log->error("Invalid length for OP: %d should be %d", args->op.length(), 32);
-    usim_log->console("Invalid length for OP: %d should be %d", args->op.length(), 32);
+    usim_log->error("Invalid length for OP: %zu should be %d", args->op.length(), 32);
+    usim_log->console("Invalid length for OP: %zu should be %d", args->op.length(), 32);
   }
 
   if(15 == args->imsi.length()) {
@@ -61,8 +61,8 @@ void usim::init(usim_args_t *args, srslte::log *usim_log_)
       imsi += imsi_c[i] - '0';
     }
   } else {
-    usim_log->error("Invalid length for ISMI: %d should be %d", args->imsi.length(), 15);
-    usim_log->console("Invalid length for IMSI: %d should be %d", args->imsi.length(), 15);
+    usim_log->error("Invalid length for ISMI: %zu should be %d", args->imsi.length(), 15);
+    usim_log->console("Invalid length for IMSI: %zu should be %d", args->imsi.length(), 15);
   }
 
   if(15 == args->imei.length()) {
@@ -73,15 +73,15 @@ void usim::init(usim_args_t *args, srslte::log *usim_log_)
       imei += imei_c[i] - '0';
     }
   } else {
-    usim_log->error("Invalid length for IMEI: %d should be %d", args->imei.length(), 15);
-    usim_log->console("Invalid length for IMEI: %d should be %d", args->imei.length(), 15);
+    usim_log->error("Invalid length for IMEI: %zu should be %d", args->imei.length(), 15);
+    usim_log->console("Invalid length for IMEI: %zu should be %d", args->imei.length(), 15);
   }
 
   if(32 == args->k.length()) {
     str_to_hex(args->k, k);
   } else {
-    usim_log->error("Invalid length for K: %d should be %d", args->k.length(), 32);
-    usim_log->console("Invalid length for K: %d should be %d", args->k.length(), 32);
+    usim_log->error("Invalid length for K: %zu should be %d", args->k.length(), 32);
+    usim_log->console("Invalid length for K: %zu should be %d", args->k.length(), 32);
   }
 
   auth_algo = auth_algo_milenage;