wirtz
/
esp-link
mirror of https://github.com/jeelabs/esp-link.git
1
0
Fork 0
Code Issues Releases Wiki Activity

syslog: fixup

Browse Source 
- implement syslog filter
- honour timezone setting
- rework syslog format
- finish (really?) syslog documentation
pull/80/head
susisstrolch 9 years ago
parent 8791bda62d
commit 94d54c140c
2 changed files with 72 additions and 29 deletions
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Show Stats Download Patch File Download Diff File
  1. 29
      syslog/syslog.c
  2. 72
      syslog/syslog.md

29
syslog/syslog.c
Unescape View File

@ -16,7 +16,6 @@
extern void * mem_trim(void *m, size_t s); // not well documented... extern void * mem_trim(void *m, size_t s); // not well documented...
#undef SYSLOG_DBG
#ifdef SYSLOG_DBG #ifdef SYSLOG_DBG
#define DBG(format, ...) do { os_printf(format, ## __VA_ARGS__); } while(0) #define DBG(format, ...) do { os_printf(format, ## __VA_ARGS__); } while(0)
#else #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) void ICACHE_FLASH_ATTR syslog_init(char *syslog_host)
{ {
syslogState = SYSLOG_HALTED;
if (!*syslog_host) { if (!*syslog_host) {
syslogState = SYSLOG_HALTED;
return; return;
} }
if (syslog_host == NULL) { if (syslog_host == NULL) {
// disable and unregister syslog handler // disable and unregister syslog handler
syslogState = SYSLOG_HALTED;
if (syslog_espconn != NULL) { if (syslog_espconn != NULL) {
if (syslog_espconn->proto.udp) { if (syslog_espconn->proto.udp) {
// there's no counterpart to espconn_create... // there's no counterpart to espconn_create...
@ -235,6 +235,7 @@ void ICACHE_FLASH_ATTR syslog_init(char *syslog_host)
pse = next; pse = next;
} }
syslogQueue = NULL; syslogQueue = NULL;
syslogState = SYSLOG_HALTED;
return; return;
} }
@ -272,23 +273,22 @@ void ICACHE_FLASH_ATTR syslog_init(char *syslog_host)
espconn_create(syslog_espconn); // create udp espconn_create(syslog_espconn); // create udp
if (UTILS_StrToIP((const char *)host, (void*)&syslogHost.addr)) { if (UTILS_StrToIP((const char *)host, (void*)&syslogHost.addr)) {
syslogState = SYSLOG_READY;
syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG", syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG",
"syslogserver: %s:%d", host, syslogHost.port); "syslogserver: %s:%d", host, syslogHost.port);
syslogState = SYSLOG_READY;
} else { } else {
syslogState = SYSLOG_DNSWAIT;
syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG", syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG",
"resolving hostname: %s", host); "resolving hostname: %s", host);
syslogState = SYSLOG_DNSWAIT;
espconn_gethostbyname(syslog_espconn, host, &syslogHost.addr, syslog_gethostbyname_cb); espconn_gethostbyname(syslog_espconn, host, &syslogHost.addr, syslog_gethostbyname_cb);
} }
#ifdef SYSLOG_UDP_RECV #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, host, syslogHost.port, syslog_espconn->proto.udp->local_port,
syslog_udp_recv_cb, syslog_udp_sent_cb, syslogState ); syslog_udp_recv_cb, syslogState );
#else #else
DBG("syslog_init: host: %s, port: %d, lport: %d, rsentcb: %p, state: %d\n", LOG_NOTICE("syslog_init: host: %s, port: %d, lport: %d, state: %d",
host, syslogHost.port, syslog_espconn->proto.udp->local_port, host, syslogHost.port, syslog_espconn->proto.udp->local_port, syslogState );
syslog_udp_sent_cb, syslogState );
#endif #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; now = (realtime_stamp == 0) ? (se->tick / 1000000) : realtime_stamp;
tp = gmtime(&now); 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_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 // 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) syslogState == SYSLOG_HALTED)
return; return;
if (severity > flashConfig.syslog_filter)
return;
// compose the syslog message // compose the syslog message
void *arg = __builtin_apply_args(); void *arg = __builtin_apply_args();
void *res = __builtin_apply((void*)syslog_compose, arg, 128); void *res = __builtin_apply((void*)syslog_compose, arg, 128);

72
syslog/syslog.md
Unescape View File

@ -1,13 +1,40 @@
syslog syslog
====== ======
The lib implements a RFC5424 compliant syslog interface for ESP8266. The syslog The lib (tries to )implement a RFC5424 compliant syslog interface for ESP8266. syslog
message is send via UDP. 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. 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 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 and stop further logging until the queue is empty and sufficient heap space is
available again. 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: The module may be controlled by flashconfig variables:
@ -26,14 +53,14 @@ logging will be enabled again.
* **syslog_filter: 0..7** * **syslog_filter: 0..7**
**syslog_filter** is the minimum severity for sending a syslog message. The filter **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 is applied against the message queue, so any message with a severity numerical higher
than **syslog_filter** will be dropped instead of being send. than **syslog_filter** will be dropped instead of being queued/send.
* **syslog_showtick: 0|1** * **syslog_showtick: 0|1**
If **syslog_showtick** is set to **1**, syslog will insert an additional timestamp If **syslog_showtick** is set to **1**, syslog will insert an additional timestamp
(system tick) as "PROCESS" field (before the users syslog message). (system tick) as "PROCID" field (before the users real syslog message).
The value shown is in ms, (1µs resolution) since (re)boot or timer overflow. The value shown is in seconds, with 1µs resolution since (re)boot or timer overflow.
* **syslog_showdate: 0|1** * **syslog_showdate: 0|1**
@ -92,19 +119,28 @@ usage: `syslog(uint8_t facility, uint8_t severity, const char *tag, const char *
Examples 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 + If **syslog_showdate** == 1, the syslog _server_ MAY replace it's own receive timestamp with the timestamp sent by the syslog client.
Invocation: syslog()
output:
showtick=1, showdate=1 + Some syslog servers don't show the fractional seconds of the syslog timestamp
Invocation: syslog()
output:
showtick=1, showdate=1, NTP not available + 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.
Invocation: syslog()
output:
showtick=1, showdate=1, NTP available + Some servers (e.g. _Synology_) won't show the syslog message if you set **facility** to **SYSLOG_FAC_SYSLOG**.
Invocation: syslog()
output:

Write Preview
Loading…
Cancel
Save