Commit a5178e37 authored by Reto Da Forno's avatar Reto Da Forno
Browse files

log print verbosity adjusted

parent e3151d84
......@@ -313,7 +313,7 @@ static void elwb_bootstrap(void)
{
schedule.n_slots = 0;
stats.bootstrap_cnt++;
LOG_INFO("bootstrap");
LOG_VERBOSE("bootstrap");
elwb_time_t bootstrap_timeout = ELWB_TIMER_NOW() + ELWB_CONF_BOOTSTRAP_TIMEOUT;
/* keep listening until we receive a valid schedule packet */
do {
......@@ -449,7 +449,7 @@ static elwb_time_t elwb_sync(elwb_time_t start_of_round, bool expected_first_sch
if (!expected_first_sched) {
/* missed schedule was during a contention/data round */
t_ref = last_synced;
LOG_INFO("start_of_round restored from last_synced (%llu)", last_synced);
LOG_VERBOSE("start_of_round restored from last_synced (%llu)", last_synced);
} else {
/* missed schedule is at beginning of a round */
t_ref = start_of_round;
......@@ -603,7 +603,7 @@ static void elwb_data_ack(elwb_time_t slot_start)
elwb_wait_until(slot_start + t_dack);
gloria_stop();
stats.pkt_tx_all++;
LOG_INFO("D-ACK sent (%u bytes)", packet_len);
LOG_VERBOSE("D-ACK sent (%u bytes)", packet_len);
}
memset(data_ack, 0, (ELWB_CONF_MAX_DATA_SLOTS + 7) / 8);
......@@ -680,7 +680,7 @@ static void elwb_contention(elwb_time_t slot_start, bool node_registered)
/* node not yet registered? -> include node ID in the request */
if (!node_registered) {
packet.cont.node_id = NODE_ID;
LOG_INFO("transmitting node ID");
LOG_VERBOSE("transmitting node ID");
}
ELWB_SET_PKT_HEADER(&packet);
#if ELWB_CONF_CONT_USE_HSTIMER
......@@ -802,33 +802,33 @@ int32_t elwb_calc_drift_comp(uint32_t elapsed_ticks)
static void elwb_print_stats(void)
{
if (is_host) {
LOG_INFO("%llu | T: %lus, slots: %u, rx/tx/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu, rssi: %ddBm",
network_time,
elwb_sched_get_period(),
ELWB_SCHED_N_SLOTS(&schedule),
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.rssi_avg);
LOG_VERBOSE("%llu | T: %lus, slots: %u, rx/tx/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu, rssi: %ddBm",
network_time,
elwb_sched_get_period(),
ELWB_SCHED_N_SLOTS(&schedule),
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.rssi_avg);
} else {
/* print out some stats (note: takes ~2ms to compose this string!) */
LOG_INFO("%s %llu | T: %lus, slots: %u, rx/tx/ack/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu/%lu, usync: %lu/%lu, drift: %ld, rssi: %ddBm",
elwb_syncstate_to_string[sync_state],
schedule.time,
ELWB_TICKS_TO_S(schedule.period),
ELWB_SCHED_N_SLOTS(&schedule),
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_ack,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.unsynced_cnt,
stats.bootstrap_cnt,
stats.drift,
stats.rssi_avg);
LOG_VERBOSE("%s %llu | T: %lus, slots: %u, rx/tx/ack/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu/%lu, usync: %lu/%lu, drift: %ld, rssi: %ddBm",
elwb_syncstate_to_string[sync_state],
schedule.time,
ELWB_TICKS_TO_S(schedule.period),
ELWB_SCHED_N_SLOTS(&schedule),
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_ack,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.unsynced_cnt,
stats.bootstrap_cnt,
stats.drift,
stats.rssi_avg);
}
}
......
......@@ -421,8 +421,8 @@ uint32_t elwb_sched_compute(elwb_schedule_t * const sched,
} else if (sched_state == ELWB_SCHED_STATE_DATA) {
/* a data round has just finished */
LOG_INFO("%lums round duration (%u of %u nodes requested %u slots)",
(uint32_t)ELWB_TICKS_TO_MS(t_round), req_nodes, n_nodes, req_slots);
LOG_VERBOSE("%lums round duration (%u of %u nodes requested %u slots)",
(uint32_t)ELWB_TICKS_TO_MS(t_round), req_nodes, n_nodes, req_slots);
memset(sched->slot, 0, sizeof(sched->slot)); /* clear the content */
/* reset all requests (set n_pkts to 0) */
......@@ -446,7 +446,7 @@ uint32_t elwb_sched_compute(elwb_schedule_t * const sched,
curr_node = curr_node->next;
}
}
LOG_INFO(print_buffer);
LOG_VERBOSE(print_buffer);
sched_state = ELWB_SCHED_STATE_IDLE;
/* schedule for next round will be set below */
......@@ -499,7 +499,7 @@ uint32_t elwb_sched_compute(elwb_schedule_t * const sched,
#endif /* ELWB_CONF_SCHED_CRC */
/* log the parameters of the new schedule */
LOG_INFO("schedule updated (s=%u T=%lums n=%u l=%u)", n_nodes, (uint32_t)ELWB_TICKS_TO_MS(sched->period), n_slots_assigned, compressed_size);
LOG_VERBOSE("schedule updated (s=%u T=%lums n=%u l=%u)", n_nodes, (uint32_t)ELWB_TICKS_TO_MS(sched->period), n_slots_assigned, compressed_size);
return compressed_size;
}
......
......@@ -309,7 +309,7 @@ static bool lwb_is_schedule_valid(lwb_schedule_t* schedule)
static void lwb_bootstrap(void)
{
stats.bootstrap_cnt++;
LOG_INFO("bootstrap");
LOG_VERBOSE("bootstrap");
lwb_time_t bootstrap_timeout = LWB_TIMER_NOW() + LWB_BOOTSTRAP_TIMEOUT;
/* keep listening until we receive a valid schedule packet */
do {
......@@ -565,7 +565,7 @@ static void lwb_contention(lwb_time_t slot_start)
packet.cont.node_id = LWB_NODE_ID;
packet.cont.ipi = ipi;
LWB_SET_PKT_HEADER(&packet);
LOG_INFO("transmitting node ID");
LOG_VERBOSE("transmitting node ID");
#if LWB_CONT_USE_HSTIMER
/* contention slot requires precise timing: use the high-speed timer for this wake-up! */
LWB_TIMER_HS_SET(last_synced_hs + LPTIMER_TICKS_TO_HS_TIMER(slot_start - last_synced), lwb_notify);
......@@ -672,7 +672,7 @@ static void lwb_send_rcv_sched2(lwb_time_t slot_start)
LOG_ERROR("failed to requeue packet");
}
} else {
LOG_INFO("packet reception ACK");
LOG_VERBOSE("packet reception ACK");
stats.pkt_ack++;
}
} else {
......@@ -732,33 +732,33 @@ int32_t lwb_calc_drift_comp(uint32_t elapsed_ticks)
static void lwb_print_stats(void)
{
if (is_host) {
LOG_INFO("%llu | T: %lus, slots: %u, rx/tx/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu, rssi: %ddBm",
network_time,
lwb_sched_get_period(),
schedule.n_slots,
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.rssi_avg);
LOG_VERBOSE("%llu | T: %lus, slots: %u, rx/tx/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu, rssi: %ddBm",
network_time,
lwb_sched_get_period(),
schedule.n_slots,
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.rssi_avg);
} else {
/* print out some stats (note: takes ~2ms to compose this string!) */
LOG_INFO("%s %llu | T: %lus, slots: %u, rx/tx/ack/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu/%lu, usync: %lu/%lu, drift: %ld, rssi: %ddBm",
lwb_syncstate_to_string[sync_state],
schedule.time,
LWB_TICKS_TO_S(schedule.period),
schedule.n_slots,
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_ack,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.unsynced_cnt,
stats.bootstrap_cnt,
stats.drift,
stats.rssi_avg);
LOG_VERBOSE("%s %llu | T: %lus, slots: %u, rx/tx/ack/drop/rx_all/tx_all: %lu/%lu/%lu/%lu/%lu/%lu, usync: %lu/%lu, drift: %ld, rssi: %ddBm",
lwb_syncstate_to_string[sync_state],
schedule.time,
LWB_TICKS_TO_S(schedule.period),
schedule.n_slots,
stats.pkt_rcvd,
stats.pkt_sent,
stats.pkt_ack,
stats.pkt_dropped,
stats.pkt_rx_all,
stats.pkt_tx_all,
stats.unsynced_cnt,
stats.bootstrap_cnt,
stats.drift,
stats.rssi_avg);
}
}
......
......@@ -254,7 +254,7 @@ uint32_t lwb_sched_compute(lwb_schedule_t* const sched,
#endif /* LWB_SCHED_ADD_CRC */
/* log the parameters of the new schedule */
LOG_INFO("schedule updated (s=%lu T=%lums n=%u l=%u)", n_nodes, (uint32_t)LWB_TICKS_TO_MS(sched->period), sched->n_slots, sched_len);
LOG_VERBOSE("schedule updated (s=%lu T=%lums n=%u l=%u)", n_nodes, (uint32_t)LWB_TICKS_TO_MS(sched->period), sched->n_slots, sched_len);
return sched_len;
}
......
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment