laforge has uploaded this change for review. ( https://gerrit.osmocom.org/c/osmo-e1d/+/27989 ) Change subject: octoi: Send ECHO_REQ every 10s and update the related stat_item ...................................................................... octoi: Send ECHO_REQ every 10s and update the related stat_item As soon as an OCTOI connection gets into ACTIVE state, send a ECHO_REQ every 10s and compute the RTT at the time of receiving the response. Contrary to the initial idea, the stat item contains the RTT (round trip time) measured in micro-seconds. Changing this is not a problem as so far the RTT was always reported as '0', and 0ms == 0us. Change-Id: Id331319bff1cf6896fee37acc45846a2491ca92d --- M src/octoi/e1oip.c M src/octoi/octoi_clnt_fsm.c M src/octoi/octoi_fsm.c M src/octoi/octoi_fsm.h M src/octoi/octoi_srv_fsm.c 5 files changed, 82 insertions(+), 5 deletions(-) git pull ssh://gerrit.osmocom.org:29418/osmo-e1d refs/changes/89/27989/1 diff --git a/src/octoi/e1oip.c b/src/octoi/e1oip.c index a50626f..a369034 100644 --- a/src/octoi/e1oip.c +++ b/src/octoi/e1oip.c @@ -66,7 +66,7 @@ }; static const struct osmo_stat_item_desc iline_stat_description[] = { - [LINE_STAT_E1oIP_RTT] = { "e1oip:rtt", "Round Trip Time (in ms)" }, + [LINE_STAT_E1oIP_RTT] = { "e1oip:rtt", "Round Trip Time (in us)" }, [LINE_STAT_E1oIP_E1O_FIFO] = { "e1oip:e1o_fifo_level", "E1 originated FIFO level" }, [LINE_STAT_E1oIP_E1T_FIFO] = { "e1oip:e1t_fifo_level", "E1 terminated FIFO level" }, [LINE_STAT_E1oIP_E1O_TS] = { "e1oip:e1o_ts_active", "E1 timeslots active in E1->IP direction" }, diff --git a/src/octoi/octoi_clnt_fsm.c b/src/octoi/octoi_clnt_fsm.c index 441f904..c4117d2 100644 --- a/src/octoi/octoi_clnt_fsm.c +++ b/src/octoi/octoi_clnt_fsm.c @@ -46,6 +46,12 @@ struct osmo_timer_list rx_alive_timer; struct octoi_account *acc; + struct { + struct osmo_timer_list timer; + struct timespec last_tx_ts; + uint16_t last_tx_seq; + } echo_req; + /* fields below are all filled in once received from the remote server side */ struct { char *server_id; @@ -122,6 +128,7 @@ st->peer->tdm_permitted = true; osmo_timer_schedule(&st->rx_alive_timer, 3, 0); + osmo_timer_schedule(&st->echo_req.timer, 10, 0); } static void clnt_st_accepted(struct osmo_fsm_inst *fi, uint32_t event, void *data) @@ -143,6 +150,7 @@ { struct clnt_state *st = fi->priv; + osmo_timer_del(&st->echo_req.timer); osmo_timer_del(&st->rx_alive_timer); st->peer->tdm_permitted = false; } @@ -210,16 +218,27 @@ { struct clnt_state *st = fi->priv; struct msgb *msg = data; - struct e1oip_echo *echo_req; + struct e1oip_echo *echo_req, *echo_resp; struct e1oip_error_ind *err_ind; + int32_t rtt_us; switch (event) { case OCTOI_EV_RX_ECHO_REQ: echo_req = msgb_l2(msg); + LOGPFSML(fi, LOGL_DEBUG, "Rx OCTOI ECHO_REQ (seq=%u)\n", ntohs(echo_req->seq_nr)); octoi_tx_echo_resp(st->peer, ntohs(echo_req->seq_nr), echo_req->data, msgb_l2len(msg)); break; case OCTOI_EV_RX_ECHO_RESP: - /* FIXME: update state, peer has responded! */ + echo_resp = msgb_l2(msg); + if (ntohs(echo_resp->seq_nr) != st->echo_req.last_tx_seq) { + LOGPFSML(fi, LOGL_NOTICE, "Rx OCTOI ECHO RESP (seq=%u) doesn't match our last " + "request (seq=%u)\n", ntohs(echo_resp->seq_nr), st->echo_req.last_tx_seq); + break; + } + rtt_us = ts_us_ago(&st->echo_req.last_tx_ts); + iline_stat_set(st->peer->iline, LINE_STAT_E1oIP_RTT, rtt_us); + LOGPFSML(fi, LOGL_INFO, "Rx OCTOI ECHO_RESP (seq=%u, rtt=%d)\n", + ntohs(echo_resp->seq_nr), rtt_us); break; case OCTOI_EV_RX_ERROR_IND: err_ind = msgb_l2(msg); @@ -301,6 +320,17 @@ osmo_fsm_inst_state_chg(fi, CLNT_ST_WAIT_RECONNECT, 10, 0); } +static void clnt_echo_req_timer_cb(void *data) +{ + struct osmo_fsm_inst *fi = data; + struct clnt_state *st = fi->priv; + + /* trigger sending of an OCTOI ECHO REQ */ + clock_gettime(CLOCK_MONOTONIC, &st->echo_req.last_tx_ts); + octoi_tx_echo_req(st->peer, ++st->echo_req.last_tx_seq, NULL, 0); + LOGPFSML(fi, LOGL_DEBUG, "Tx OCTOI ECHO_REQ (seq=%u)\n", st->echo_req.last_tx_seq); + osmo_timer_schedule(&st->echo_req.timer, 10, 0); +} /* call-back function for every received OCTOI socket message for given peer */ int octoi_clnt_fsm_rx_cb(struct octoi_peer *peer, struct msgb *msg) @@ -345,6 +375,7 @@ st->service = E1OIP_SERVICE_E1_FRAMED; st->capability_flags = 0; osmo_timer_setup(&st->rx_alive_timer, clnt_rx_alive_timer_cb, fi); + osmo_timer_setup(&st->echo_req.timer, clnt_echo_req_timer_cb, fi); fi->priv = st; peer->priv = fi; diff --git a/src/octoi/octoi_fsm.c b/src/octoi/octoi_fsm.c index 37d0259..39790fa 100644 --- a/src/octoi/octoi_fsm.c +++ b/src/octoi/octoi_fsm.c @@ -28,6 +28,19 @@ #include "octoi_fsm.h" #include "e1oip.h" +/* how many microseconds ago was 'old_ts'? */ +int32_t ts_us_ago(const struct timespec *old_ts) +{ + struct timespec ts_now, ts_diff; + + clock_gettime(CLOCK_MONOTONIC, &ts_now); + timespecsub(&ts_now, old_ts, &ts_diff); + + if (ts_diff.tv_sec > INT32_MAX / 1000000) + return INT32_MAX; + + return ts_diff.tv_sec * 1000000 + ts_diff.tv_nsec / 1000; +} const struct value_string octoi_fsm_event_names[] = { { OCTOI_EV_RX_TDM_DATA, "RX_TDM_DATA" }, diff --git a/src/octoi/octoi_fsm.h b/src/octoi/octoi_fsm.h index b605c3a..e54afe1 100644 --- a/src/octoi/octoi_fsm.h +++ b/src/octoi/octoi_fsm.h @@ -29,3 +29,5 @@ /* call-back function for every received OCTOI socket message for given peer */ int octoi_srv_fsm_rx_cb(struct octoi_peer *peer, struct msgb *msg); int octoi_clnt_fsm_rx_cb(struct octoi_peer *peer, struct msgb *msg); + +int32_t ts_us_ago(const struct timespec *old_ts); diff --git a/src/octoi/octoi_srv_fsm.c b/src/octoi/octoi_srv_fsm.c index 53b79e7..cc6c1ce 100644 --- a/src/octoi/octoi_srv_fsm.c +++ b/src/octoi/octoi_srv_fsm.c @@ -55,6 +55,11 @@ struct octoi_account *acc; void *app_priv; /* application private data */ const char *rej_str; + struct { + struct osmo_timer_list timer; + struct timespec last_tx_ts; + uint16_t last_tx_seq; + } echo_req; }; static void srv_st_init(struct osmo_fsm_inst *fi, uint32_t event, void *data) @@ -175,6 +180,7 @@ st->peer->tdm_permitted = true; osmo_timer_schedule(&st->rx_alive_timer, 3, 0); + osmo_timer_schedule(&st->echo_req.timer, 10, 0); } static void srv_st_accepted(struct osmo_fsm_inst *fi, uint32_t event, void *data) @@ -200,6 +206,7 @@ { struct srv_state *st = fi->priv; + osmo_timer_del(&st->echo_req.timer); osmo_timer_del(&st->rx_alive_timer); st->peer->tdm_permitted = false; } @@ -277,16 +284,27 @@ { struct srv_state *st = fi->priv; struct msgb *msg = data; - struct e1oip_echo *echo_req; + struct e1oip_echo *echo_req, *echo_resp; struct e1oip_error_ind *err_ind; + int32_t rtt_us; switch (event) { case OCTOI_EV_RX_ECHO_REQ: echo_req = msgb_l2(msg); + LOGPFSML(fi, LOGL_DEBUG, "Rx OCTOI ECHO_REQ (seq=%u)\n", ntohs(echo_req->seq_nr)); octoi_tx_echo_resp(st->peer, ntohs(echo_req->seq_nr), echo_req->data, msgb_l2len(msg)); break; case OCTOI_EV_RX_ECHO_RESP: - /* TODO: update state, peer has responded! */ + echo_resp = msgb_l2(msg); + if (ntohs(echo_resp->seq_nr) != st->echo_req.last_tx_seq) { + LOGPFSML(fi, LOGL_NOTICE, "Rx OCTOI ECHO RESP (seq=%u) doesn't match our last " + "request (seq=%u)\n", ntohs(echo_resp->seq_nr), st->echo_req.last_tx_seq); + break; + } + rtt_us = ts_us_ago(&st->echo_req.last_tx_ts); + iline_stat_set(st->peer->iline, LINE_STAT_E1oIP_RTT, rtt_us); + LOGPFSML(fi, LOGL_INFO, "Rx OCTOI ECHO_RESP (seq=%u, rtt=%d)\n", + ntohs(echo_resp->seq_nr), rtt_us); break; case OCTOI_EV_RX_ERROR_IND: err_ind = msgb_l2(msg); @@ -377,6 +395,18 @@ osmo_fsm_inst_term(fi, OSMO_FSM_TERM_ERROR, NULL); } +static void srv_echo_req_timer_cb(void *data) +{ + struct osmo_fsm_inst *fi = data; + struct srv_state *st = fi->priv; + + /* trigger sending of an OCTOI ECHO REQ */ + clock_gettime(CLOCK_MONOTONIC, &st->echo_req.last_tx_ts); + octoi_tx_echo_req(st->peer, ++st->echo_req.last_tx_seq, NULL, 0); + LOGPFSML(fi, LOGL_DEBUG, "Tx OCTOI ECHO_REQ (seq=%u)\n", st->echo_req.last_tx_seq); + osmo_timer_schedule(&st->echo_req.timer, 10, 0); +} + /* call-back function for every received OCTOI socket message for given peer */ int octoi_srv_fsm_rx_cb(struct octoi_peer *peer, struct msgb *msg) { @@ -393,6 +423,7 @@ OSMO_ASSERT(st); st->peer = peer; osmo_timer_setup(&st->rx_alive_timer, srv_rx_alive_timer_cb, fi); + osmo_timer_setup(&st->echo_req.timer, srv_echo_req_timer_cb, fi); fi->priv = st; peer->priv = fi; -- To view, visit https://gerrit.osmocom.org/c/osmo-e1d/+/27989 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-e1d Gerrit-Branch: master Gerrit-Change-Id: Id331319bff1cf6896fee37acc45846a2491ca92d Gerrit-Change-Number: 27989 Gerrit-PatchSet: 1 Gerrit-Owner: laforge <laforge(a)osmocom.org> Gerrit-MessageType: newchange