After the timer expiration, just after the poll(), we can read fron the timer file descriptor a 64bit value that represents the number of expirations that have occured. This value is useful for debug. In addition, when we use a periodic timer the timer will be locked until the read of this value. --- e2e_tc.c | 4 ++++ p2p_tc.c | 4 ++++ port.c | 25 +++++++++++++++++++++++++ port.h | 10 ++++++++++ 4 files changed, 43 insertions(+)
diff --git a/e2e_tc.c b/e2e_tc.c index 2f8e821..43c69e9 100644 --- a/e2e_tc.c +++ b/e2e_tc.c @@ -85,6 +85,7 @@ enum fsm_event e2e_event(struct port *p, int fd_index) case FD_SYNC_RX_TIMER: pr_debug("%s: %s timeout", p->log_name, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); + timerfd_flush(p, fd, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); if (p->best) { fc_clear(p->best); } @@ -93,6 +94,7 @@ enum fsm_event e2e_event(struct port *p, int fd_index) case FD_DELAY_TIMER: pr_debug("%s: delay timeout", p->log_name); + timerfd_flush(p, fd, "delay"); port_set_delay_tmo(p); delay_req_prune(p); tc_prune(p); @@ -112,6 +114,7 @@ enum fsm_event e2e_event(struct port *p, int fd_index) case FD_QUALIFICATION_TIMER: pr_debug("%s: qualification timeout", p->log_name); + timerfd_flush(p, fd, "qualification"); return EV_QUALIFICATION_TIMEOUT_EXPIRES; case FD_MANNO_TIMER: @@ -119,6 +122,7 @@ enum fsm_event e2e_event(struct port *p, int fd_index) case FD_UNICAST_REQ_TIMER: case FD_UNICAST_SRV_TIMER: pr_err("unexpected timer expiration"); + timerfd_flush(p, fd, "unexpected"); return EV_NONE; case FD_RTNL: diff --git a/p2p_tc.c b/p2p_tc.c index 75cb3b9..55a4b1c 100644 --- a/p2p_tc.c +++ b/p2p_tc.c @@ -101,6 +101,7 @@ enum fsm_event p2p_event(struct port *p, int fd_index) case FD_SYNC_RX_TIMER: pr_debug("%s: %s timeout", p->log_name, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); + timerfd_flush(p, fd, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); if (p->best) { fc_clear(p->best); } @@ -109,12 +110,14 @@ enum fsm_event p2p_event(struct port *p, int fd_index) case FD_DELAY_TIMER: pr_debug("%s: delay timeout", p->log_name); + timerfd_flush(p, fd, "delay"); port_set_delay_tmo(p); tc_prune(p); return p2p_delay_request(p) ? EV_FAULT_DETECTED : EV_NONE; case FD_QUALIFICATION_TIMER: pr_debug("%s: qualification timeout", p->log_name); + timerfd_flush(p, fd, "qualification"); return EV_QUALIFICATION_TIMEOUT_EXPIRES; case FD_MANNO_TIMER: @@ -122,6 +125,7 @@ enum fsm_event p2p_event(struct port *p, int fd_index) case FD_UNICAST_REQ_TIMER: case FD_UNICAST_SRV_TIMER: pr_err("unexpected timer expiration"); + timerfd_flush(p, fd, "unexpected"); return EV_NONE; case FD_RTNL: diff --git a/port.c b/port.c index 3453716..e38f244 100644 --- a/port.c +++ b/port.c @@ -2853,6 +2853,7 @@ static enum fsm_event bc_event(struct port *p, int fd_index) case FD_SYNC_RX_TIMER: pr_debug("%s: %s timeout", p->log_name, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); + timerfd_flush(p, fd, fd_index == FD_SYNC_RX_TIMER ? "rx sync" : "announce"); if (p->best) { fc_clear(p->best); } @@ -2891,6 +2892,7 @@ static enum fsm_event bc_event(struct port *p, int fd_index) case FD_DELAY_TIMER: pr_debug("%s: delay timeout", p->log_name); + timerfd_flush(p, fd, "delay"); port_set_delay_tmo(p); delay_req_prune(p); p->service_stats.delay_timeout++; @@ -2910,11 +2912,13 @@ static enum fsm_event bc_event(struct port *p, int fd_index) case FD_QUALIFICATION_TIMER: pr_debug("%s: qualification timeout", p->log_name); + timerfd_flush(p, fd, "qualification"); p->service_stats.qualification_timeout++; return EV_QUALIFICATION_TIMEOUT_EXPIRES; case FD_MANNO_TIMER: pr_debug("%s: master tx announce timeout", p->log_name); + timerfd_flush(p, fd, "master announce"); port_set_manno_tmo(p); p->service_stats.master_announce_timeout++; clock_update_leap_status(p->clock); @@ -2923,6 +2927,7 @@ static enum fsm_event bc_event(struct port *p, int fd_index) case FD_SYNC_TX_TIMER: pr_debug("%s: master sync timeout", p->log_name); + timerfd_flush(p, fd, "master sync timeout"); port_set_sync_tx_tmo(p); p->service_stats.master_sync_timeout++; return port_tx_sync(p, NULL, p->seqnum.sync++) ? @@ -2930,11 +2935,13 @@ static enum fsm_event bc_event(struct port *p, int fd_index) case FD_UNICAST_SRV_TIMER: pr_debug("%s: unicast service timeout", p->log_name); + timerfd_flush(p, fd, "unicast service"); p->service_stats.unicast_service_timeout++; return unicast_service_timer(p) ? EV_FAULT_DETECTED : EV_NONE; case FD_UNICAST_REQ_TIMER: pr_debug("%s: unicast request timeout", p->log_name); + timerfd_flush(p, fd, "unicast request"); p->service_stats.unicast_request_timeout++; return unicast_client_timer(p) ? EV_FAULT_DETECTED : EV_NONE; @@ -3550,3 +3557,21 @@ void port_update_unicast_state(struct port *p) p->unicast_state_dirty = false; } } + +uint64_t timerfd_flush(struct port *p, int fd, char *fd_name) +{ + uint64_t val = 0; + ssize_t res = read(fd, &val, sizeof(val)); + + if (res < 0) { + pr_err("port %hu: Error on read %s timer (%"PRId64 ", %m)", portnum(p), fd_name, res); + val = 0; + } else if (res != sizeof(val)) { + pr_err("port %hu: Error on read %s timer (%"PRId64 ")", portnum(p), fd_name, res); + val = 0; + } else if (val != 1) { + pr_warning("port %hu: Missing %"PRIu64" ticks on %s timer" , portnum(p), val, fd_name); + } + + return val; +} diff --git a/port.h b/port.h index 57c8c2f..0b5b5b0 100644 --- a/port.h +++ b/port.h @@ -364,4 +364,14 @@ void tc_cleanup(void); */ void port_update_unicast_state(struct port *p); +/** + * Flush the timer fd reading the number of elapsed tick. + * + * @param p A port instance. + * @param fd A file descriptor previously opened with timerfd_create(2). + * @param fd_name A symbolic name for error logging + * @return Number of elapsed ticks + */ +uint64_t timerfd_flush(struct port *p, int fd, char *fd_name); + #endif -- 2.40.0 _______________________________________________ Linuxptp-devel mailing list Linuxptp-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/linuxptp-devel