diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index 81b98804..77b37312 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -26,3 +26,5 @@ jobs: run: make CI=1 MACHINE="KP_9000_6XHML_X2" - name: Make project (8x1/RTL8373) run: make CI=1 MACHINE="KP_9000_9XHML_X_V3_1" + - name: Make project with the health instrumentation + run: make clean && make CI=1 MACHINE="KP_9000_6XHML_X2" HEALTH=1 diff --git a/Makefile b/Makefile index 0b5628be..2189b27b 100644 --- a/Makefile +++ b/Makefile @@ -19,6 +19,10 @@ ifeq ($(MACHINE),) else CC_FLAGS += -DMACHINE_$(MACHINE) endif +# Health instrumentation and the "health" console command: HEALTH=1 gmake ... +ifneq ($(HEALTH),) + CC_FLAGS += -DHEALTH +endif ifeq ($(CI),1) CC_FLAGS += --Werror diff --git a/cmd_parser.c b/cmd_parser.c index 24e7d2e1..5b4e1f34 100644 --- a/cmd_parser.c +++ b/cmd_parser.c @@ -5,6 +5,8 @@ // #define DEBUG // #define REGDBG 1 +#include <8051.h> +#include "cmd_parser.h" #include "rtl837x_common.h" #include "rtl837x_port.h" #include "rtl837x_flash.h" @@ -1850,6 +1852,10 @@ void cmd_parser(void) __banked } } else if (cmd_compare(0, "stp")) { stp_parse(); +#ifdef HEALTH + } else if (cmd_compare(0, "health")) { + health_show(); +#endif } else if (cmd_compare(0, "pvid")) { if (cmd_words_len == 3 && cmd_parse_port_separator(cmd_words_b[1]) != 0 && atoi_short(cmd_words_b[2]) && atoi_results_short && atoi_results_short <= 4094) @@ -2054,3 +2060,161 @@ void execute_commands(__xdata uint8_t *p) __banked { p++; }; } + +#ifdef HEALTH +/* + * Health instrumentation. The counters live in xdata and are fed from the + * main loop through the banked entry points below; the "health" command + * prints everything in one go. All figures are raw hex, diffing two dumps + * gives the rates. Phase times are in system ticks (SYS_TICK_HZ = 200, + * 5 ms each); a phase counts as slow when it spans 2 or more ticks. + */ +extern __xdata uint16_t len_left; /* httpd: bytes still to send of the current file */ +extern __xdata uint8_t entry; /* httpd: index of the file being sent */ + +static __xdata uint32_t health_loops; +__xdata uint16_t health_rx_frames; + +static __xdata uint16_t ph_last_t; +static __xdata uint8_t ph_max[HEALTH_PHASES]; +static __xdata uint16_t ph_slow[HEALTH_PHASES]; + +/* The ISR increments ticks between the two byte reads of a 16-bit load, so + * read until two loads agree. */ +static uint16_t ticks_lo(void) +{ + uint16_t a, b; + a = (uint16_t)ticks; + do { + b = a; + a = (uint16_t)ticks; + } while (a != b); + return a; +} + + +void health_loop_start(void) __banked +{ + health_loops++; + ph_last_t = ticks_lo(); +} + + +void health_phase(uint8_t id) __banked +{ + __xdata uint16_t now = ticks_lo(); + __xdata uint16_t d = now - ph_last_t; + ph_last_t = now; + if (d > 0xff) + d = 0xff; + if ((uint8_t)d > ph_max[id]) + ph_max[id] = d; + if (d >= 2) + ph_slow[id]++; +} + + +/* Fill the stack area above the current frame with a pattern; the dump scans + * for how much of it survived. The 8051 stack grows upward, so everything + * above SP is free at this point. Interrupts are held off so an ISR does not + * push into the area mid-paint. */ +void health_stack_paint(void) __banked +{ + __xdata uint8_t from = SP + 4; + __xdata uint8_t ea = EA; + EA = 0; + for (uint8_t i = 0xff; i >= from; i--) + *(__idata uint8_t *)i = 0xa5; + EA = ea; +} + + +static void ph_line(__code const char *name, uint8_t id) +{ + print_string(name); + print_string(" max "); + print_byte(ph_max[id]); + print_string(" slow "); + print_short(ph_slow[id]); + write_char('\n'); +} + + +void health_show(void) __banked +{ + __xdata uint8_t i; + + print_string("up "); + reg_read_m(RTL837X_REG_SEC_COUNTER); + print_byte(sfr_data[0]); print_byte(sfr_data[1]); + print_byte(sfr_data[2]); print_byte(sfr_data[3]); + print_string(" ticks "); + print_long(ticks); + print_string(" loops "); + print_long(health_loops); + print_string(" rx "); + print_short(health_rx_frames); + write_char('\n'); + + /* Phase timing: max duration seen (ticks of 5 ms) and slow-pass count */ + ph_line("link", HEALTH_PH_LINK); + ph_line("sfp ", HEALTH_PH_SFP); + ph_line("rx ", HEALTH_PH_RX); + ph_line("tx ", HEALTH_PH_TX); + ph_line("stp ", HEALTH_PH_STP); + ph_line("cmd ", HEALTH_PH_CMD); + + /* Stack: current depth plus how much of the painted area is untouched */ + print_string("sp "); + print_byte(SP); + print_string(" untouched "); + i = 0; + while (*(__idata uint8_t *)(0xff - i) == 0xa5 && i < 0x86) + i++; + print_byte(i); + write_char('\n'); + + /* The TCP connection slot. One on this configuration; a build with more + * has to say which slot each line is, so make that a visible decision. */ +#if UIP_CONNS != 1 +#error "health: the tcp dump prints a single slot, extend it for UIP_CONNS > 1" +#endif + i = 0; + { + print_string("tcp "); + print_string("st "); + print_byte(uip_conns[i].tcpstateflags); + print_string(" tmr "); + print_byte(uip_conns[i].timer); + print_string(" rtx "); + print_byte(uip_conns[i].nrtx); + print_string(" rto "); + print_byte(uip_conns[i].rto); + print_string(" len "); + print_short(uip_conns[i].len); + print_string(" mss "); + print_short(uip_conns[i].mss); + write_char('\n'); + print_string(" lport "); + print_short(HTONS(uip_conns[i].lport)); + print_string(" rport "); + print_short(HTONS(uip_conns[i].rport)); + print_string(" rip "); + print_short(HTONS(uip_conns[i].ripaddr[0])); + write_char(' '); + print_short(HTONS(uip_conns[i].ripaddr[1])); + write_char('\n'); + } + + /* httpd transfer state and the protocol flags */ + print_string("httpd left "); + print_short(len_left); + print_string(" entry "); + print_byte(entry); + print_string(" stp "); + print_byte(stp_enabled); + print_string(" mvlan "); + print_short(management_vlan); + write_char('\n'); +} +#endif diff --git a/cmd_parser.h b/cmd_parser.h index 7564b458..29d08c36 100644 --- a/cmd_parser.h +++ b/cmd_parser.h @@ -9,6 +9,32 @@ extern __xdata uint8_t cmd_buffer[CMD_BUF_SIZE]; extern __xdata uint8_t cmd_available; extern __xdata uint8_t err_status; +/* Health instrumentation, built with HEALTH=1. Without it the hooks below + * compile to nothing and the "health" command does not exist. */ +#ifdef HEALTH +/* Phase ids, in main-loop order */ +#define HEALTH_PH_LINK 0 +#define HEALTH_PH_SFP 1 +#define HEALTH_PH_RX 2 +#define HEALTH_PH_TX 3 +#define HEALTH_PH_STP 4 +#define HEALTH_PH_CMD 5 +#define HEALTH_PHASES 6 + +extern __xdata uint16_t health_rx_frames; +#define health_rx_frame() health_rx_frames++ + +void health_loop_start(void) __banked; /* once per idle() pass, resets the phase baseline */ +void health_phase(uint8_t id) __banked; /* after each phase; accounts ticks since last checkpoint */ +void health_stack_paint(void) __banked; /* paint the unused stack area once at boot */ +void health_show(void) __banked; /* "health" CLI dump */ +#else +#define health_rx_frame() +#define health_loop_start() +#define health_phase(id) +#define health_stack_paint() +#endif + void cmd_tokenize(void) __banked; void cmd_parser(void) __banked; void execute_config(void) __banked; diff --git a/doc/health.md b/doc/health.md new file mode 100644 index 00000000..736d52b7 --- /dev/null +++ b/doc/health.md @@ -0,0 +1,79 @@ +# The health command + +`health` prints a one-page snapshot of the firmware's vital signs on the +serial console. It exists for the situations where the switch misbehaves and +every probe from the network measures the network instead of the device: the +dump is taken from inside, costs one command, and works while HTTP does not. + +``` +> health +up 0000001f ticks 0x00001f4c loops 0x000016da rx 0x024e +link max 01 slow 0x0000 +sfp max 74 slow 0x0001 +rx max 00 slow 0x0000 +tx max 00 slow 0x0000 +stp max 04 slow 0x0001 +cmd max 02 slow 0x0001 +sp 80 untouched 62 +tcp st 00 tmr 00 rtx 00 rto 00 len 0x0000 mss 0x05b4 + lport 0x0000 rport 0x0000 rip 0x0000 0x0000 +httpd left 0x0000 entry 00 stp 01 mvlan 0x0002 +``` + +The instrumentation is not part of a default build. It costs about 1.1 kB +of bank 2, a few bytes of xdata and seven banked calls per main-loop pass, +which is nothing a user needs unless they are chasing a problem, so it is +switched on at build time: + +``` +make MACHINE=SWTGW218AS HEALTH=1 +``` + +Without it the hooks compile to nothing and `health` is not a command. + +All figures are raw hex. The counters are cumulative: take two dumps a known +time apart and the differences give the rates. + +## The first line + +`up` is the seconds counter, `ticks` the system tick (200 per second), +`loops` the number of main-loop passes and `rx` the frames handle_rx has +taken off the NIC. A healthy loop completes one pass per tick, so the +difference in `loops` tracks the difference in `ticks`; a loop that falls +behind is being held up by one of the phases below. The `rx` rate separates +a flooded CPU port from a stalled loop, which look identical from outside. + +## Phases + +Each line is one section of the main loop: the link poll, SFP handling, +frame reception, TCP transmission, the STP timers and the command dispatch. +`max` is the worst time that section has taken, in ticks of 5 ms; `slow` +counts the passes that took two ticks or more. A misbehaving subsystem +names itself here, which is the difference between knowing that the loop is +slow and knowing why. + +A dump of its own output takes the console some milliseconds, so running +`health` repeatedly increments the `cmd` counters by itself. That is the +instrument observing itself, not a fault. + +## Stack + +At boot the free stack area is painted with a pattern. `sp` is the live +stack pointer; `untouched` counts the painted bytes still intact at the top, +which is the closest thing to a high-water mark this hardware offers. A +shrinking `untouched` across dumps means something is reaching deeper than +anything before it. + +## The TCP slot + +The connection table is printed whole, one slot per pair of lines: TCP +state (3 is ESTABLISHED, 0 closed), retransmission timer and counter, bytes +in flight, negotiated MSS, then the ports and the peer address. With a +single slot serving the entire web interface, one glance answers the +question every management outage starts with: who is holding it. A slot +showing state 3 with nothing in flight and a peer that no longer answers is +a connection whose owner went away. + +`httpd left` and `entry` describe the file transfer the web server believes +it is in the middle of, and the trailing flags show whether STP is running +and which VLAN carries management. diff --git a/rtlplayground.c b/rtlplayground.c index 25af2482..80f599cb 100644 --- a/rtlplayground.c +++ b/rtlplayground.c @@ -1015,6 +1015,7 @@ void handle_rx(void) REG_SET(RTL837X_REG_NIC_RXCMD, 1); return; } + health_rx_frame(); #ifdef RXTXDBG print_string("\n<< "); @@ -1176,6 +1177,7 @@ void idle(void) reg_read(RTL837X_REG_NIC_RX_BUFF_DATA); if (!SFR_DATA_U16) PCON |= 1; + health_loop_start(); if (sec_counter >= SYS_TICK_HZ) { sec_counter -= SYS_TICK_HZ; reg_read_m(RTL837X_REG_SEC_COUNTER); @@ -1251,13 +1253,18 @@ void idle(void) } } + health_phase(HEALTH_PH_LINK); + // Check for changes with SFP modules handle_sfp(); + health_phase(HEALTH_PH_SFP); // Check new Packets RX handle_rx(); + health_phase(HEALTH_PH_RX); // Check UIP for packets to transmit handle_tx(); + health_phase(HEALTH_PH_TX); // If STP protocol enabled, decrease STP timers to trigger actions if (stp_enabled) { if (!stp_clock) { @@ -1267,6 +1274,7 @@ void idle(void) stp_clock--; } } + health_phase(HEALTH_PH_STP); // Check whether a command is waiting in the cmd_buffer and execute if (cmd_available) { cmd_available = 0; @@ -1275,6 +1283,7 @@ void idle(void) cmd_parser(); print_cmd_prompt(); } + health_phase(HEALTH_PH_CMD); } @@ -1769,6 +1778,7 @@ void main(void) cmd_editor_init(); + health_stack_paint(); while (1) { cmd_edit(); idle(); // Enter Idle mode until interrupt occurs