diff --git a/syslog/syslog.c b/syslog/syslog.c index 9cdc6d9..a9fbb2a 100644 --- a/syslog/syslog.c +++ b/syslog/syslog.c @@ -16,7 +16,6 @@ extern void * mem_trim(void *m, size_t s); // not well documented... -#undef SYSLOG_DBG #ifdef SYSLOG_DBG #define DBG(format, ...) do { os_printf(format, ## __VA_ARGS__); } while(0) #else @@ -210,14 +209,15 @@ static void ICACHE_FLASH_ATTR syslog_gethostbyname_cb(const char *name, ip_addr_ *******************************************************************************/ void ICACHE_FLASH_ATTR syslog_init(char *syslog_host) { - syslogState = SYSLOG_HALTED; if (!*syslog_host) { + syslogState = SYSLOG_HALTED; return; } if (syslog_host == NULL) { // disable and unregister syslog handler + syslogState = SYSLOG_HALTED; if (syslog_espconn != NULL) { if (syslog_espconn->proto.udp) { // there's no counterpart to espconn_create... @@ -235,6 +235,7 @@ void ICACHE_FLASH_ATTR syslog_init(char *syslog_host) pse = next; } syslogQueue = NULL; + syslogState = SYSLOG_HALTED; return; } @@ -272,23 +273,22 @@ void ICACHE_FLASH_ATTR syslog_init(char *syslog_host) espconn_create(syslog_espconn); // create udp if (UTILS_StrToIP((const char *)host, (void*)&syslogHost.addr)) { + syslogState = SYSLOG_READY; syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG", "syslogserver: %s:%d", host, syslogHost.port); - syslogState = SYSLOG_READY; } else { + syslogState = SYSLOG_DNSWAIT; syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG", "resolving hostname: %s", host); - syslogState = SYSLOG_DNSWAIT; espconn_gethostbyname(syslog_espconn, host, &syslogHost.addr, syslog_gethostbyname_cb); } #ifdef SYSLOG_UDP_RECV - DBG("syslog_init: host: %s, port: %d, lport: %d, recvcb: %p, sentcb: %p, state: %d\n", + LOG_NOTICE("syslog_init: host: %s, port: %d, lport: %d, recvcb: %p, sstate: %d", host, syslogHost.port, syslog_espconn->proto.udp->local_port, - syslog_udp_recv_cb, syslog_udp_sent_cb, syslogState ); + syslog_udp_recv_cb, syslogState ); #else - DBG("syslog_init: host: %s, port: %d, lport: %d, rsentcb: %p, state: %d\n", - host, syslogHost.port, syslog_espconn->proto.udp->local_port, - syslog_udp_sent_cb, syslogState ); + LOG_NOTICE("syslog_init: host: %s, port: %d, lport: %d, state: %d", + host, syslogHost.port, syslog_espconn->proto.udp->local_port, syslogState ); #endif } @@ -357,9 +357,13 @@ syslog_compose(uint8_t facility, uint8_t severity, const char *tag, const char * now = (realtime_stamp == 0) ? (se->tick / 1000000) : realtime_stamp; tp = gmtime(&now); - p += os_sprintf(p, "%4d-%02d-%02dT%02d:%02d:%02dZ ", + p += os_sprintf(p, "%4d-%02d-%02dT%02d:%02d:%02d", tp->tm_year + 1900, tp->tm_mon + 1, tp->tm_mday, - tp->tm_hour, tp->tm_min, tp->tm_sec); + tp->tm_hour, tp->tm_min, tp->tm_sec); + if (realtime_stamp == 0) + p += os_sprintf(p, ".%06luZ ", se->tick % 1000000); + else + p += os_sprintf(p, "%+03d:00 ", flashConfig.timezone_offset); } // add HOSTNAME APP-NAME PROCID MSGID @@ -457,6 +461,9 @@ void ICACHE_FLASH_ATTR syslog(uint8_t facility, uint8_t severity, const char *ta syslogState == SYSLOG_HALTED) return; + if (severity > flashConfig.syslog_filter) + return; + // compose the syslog message void *arg = __builtin_apply_args(); void *res = __builtin_apply((void*)syslog_compose, arg, 128); diff --git a/syslog/syslog.md b/syslog/syslog.md index d7e08ac..d60cbf5 100644 --- a/syslog/syslog.md +++ b/syslog/syslog.md @@ -1,13 +1,40 @@ syslog ====== -The lib implements a RFC5424 compliant syslog interface for ESP8266. The syslog -message is send via UDP. +The lib (tries to )implement a RFC5424 compliant syslog interface for ESP8266. syslog +messages are send via UDP. Messages are send in the following format: + +``` +PRI VERSION SP TIMESTAMP SP HOSTNAME SP APP-NAME SP PROCID SP MSGID SP MSG + PRI: msg priority: facility * 8 + severity + TIMESTAMP: dash (no timestamp) or ISO8601 (2015-12-14T17:26:32Z) + HOSTNAME: flashConfig.hostname + APP-NAME: tag - (e.g. MQTT, mySQL, REST, ...) + PROCID: dash or ESP system tick (µseconds since reboot) + MSGID: counter - # syslog messages since reboot + MSG: the syslog message +``` + +The meaning of TIMESTAMP, HOSTNAME, PROCID and MSGID is hardcoded, all others are parameters for the syslog function. syslog messages are queued on heap until the Wifi stack is fully initialized. If the remaining heap size reaches a given limit, syslog will add a final obituary and stop further logging until the queue is empty and sufficient heap space is available again. +Example: + +``` +Jan 1 00:00:00 192.168.254.82 esp_link 0.126850 1 Reset cause: 4=restart +Jan 1 00:00:00 192.168.254.82 esp_link 0.133970 2 exccause=0 epc1=0x0 epc2=0x0 epc3=0x0 excvaddr=0x0 depc=0x0 +Jan 1 00:00:00 192.168.254.82 esp_link 0.151069 3 Flash map 4MB:512/512, manuf 0xC8 chip 0x4016 +Jan 1 00:00:00 192.168.254.82 esp_link 0.166935 4 ** esp-link ready +Jan 1 00:00:00 192.168.254.82 esp_link 0.185586 5 initializing MQTT +Jan 1 00:00:00 192.168.254.82 esp_link 0.200681 6 initializing user application +Jan 1 00:00:00 192.168.254.82 esp_link 0.215169 7 waiting for work to do... +Jan 1 00:00:03 192.168.254.82 SYSLOG 3.325626 8 syslogserver: 192.168.254.216:514 +Jan 1 00:00:03 192.168.254.82 esp_link 3.336756 9 syslog_init: host: 192.168.254.216, port: 514, lport: 24377, state: 4 +Dec 15 11:49:14 192.168.254.82 esp-link 18.037949 10 Accept port 23, conn=3fff5f68, pool slot 0 +``` The module may be controlled by flashconfig variables: @@ -26,14 +53,14 @@ logging will be enabled again. * **syslog_filter: 0..7** **syslog_filter** is the minimum severity for sending a syslog message. The filter -is applied against the message queue, so any message with a severity numerical lower -than **syslog_filter** will be dropped instead of being send. +is applied against the message queue, so any message with a severity numerical higher +than **syslog_filter** will be dropped instead of being queued/send. * **syslog_showtick: 0|1** If **syslog_showtick** is set to **1**, syslog will insert an additional timestamp -(system tick) as "PROCESS" field (before the users syslog message). -The value shown is in ms, (1µs resolution) since (re)boot or timer overflow. +(system tick) as "PROCID" field (before the users real syslog message). +The value shown is in seconds, with 1µs resolution since (re)boot or timer overflow. * **syslog_showdate: 0|1** @@ -92,19 +119,28 @@ usage: `syslog(uint8_t facility, uint8_t severity, const char *tag, const char * Examples ======== + hostname="ems-link02", showtick=0, showdate=0 + Syslog message: USER.NOTICE: - ems-link02 esp_link - 20 syslog_init: host: 192.168.254.216, port: 514, lport: 28271, rsentcb: 40211e08, state: 4\n + + hostname="ems-link02", showtick=1, showdate=0 + Syslog message: USER.NOTICE: - ems-link02 esp_link 3.325677 8 syslog_init: host: 192.168.254.216, port: 514, lport: 19368, rsentcb: 40211e08, state: 4\n + + hostname="ems-link02", showtick=1, showdate=1, NTP not available + Syslog message: USER.NOTICE: 1970-01-01T00:00:03.325668Z ems-link02 esp_link 3.325668 8 syslog_init: host: 192.168.254.216, port: 514, lport: 36802, rsentcb: 40211e08, state: 4\n + + hostname="ems-link02", showtick=1, showdate=1, NTP available + Syslog message: USER.NOTICE: 2015-12-15T11:15:29+00:00 ems-link02 esp_link 182.036860 13 syslog_init: host: 192.168.254.216, port: 514, lport: 43626, rsentcb: 40291db8, state: 4\n + +Notes +===== ++ The ESP8266 (NON-OS) needs a delay of **at least 2ms** between consecutive UDP packages. So the syslog throughput is restricted to approx. 500EPS. + ++ If a syslog message doesn't have the timestamp set ( **syslog_showdate** == 0), the syslog _server_ will insert _it's own receive timestamp_ into the log message. - showtick=0, showdate=0 - Invocation: syslog() -output: ++ If **syslog_showdate** == 1, the syslog _server_ MAY replace it's own receive timestamp with the timestamp sent by the syslog client. - showtick=1, showdate=1 - Invocation: syslog() -output: ++ Some syslog servers don't show the fractional seconds of the syslog timestamp - showtick=1, showdate=1, NTP not available - Invocation: syslog() -output: ++ Setting **syslog_showdate** will send timestamps from 1970 (because of using the internal ticker) until the **SNTP-client** got a valid NTP datagram. Some syslog servers (for example _Synology_) will roll over their database if they get such "old" syslog messages. In fact, you won't see those messages in your current syslog. - showtick=1, showdate=1, NTP available - Invocation: syslog() -output: ++ Some servers (e.g. _Synology_) won't show the syslog message if you set **facility** to **SYSLOG_FAC_SYSLOG**.