/******************************************************************************
* FunctionName : syslog_compose
* Description : compose a syslog_entry_t from va_args
* Parameters : va_args
* Returns : the malloced syslog_entry_t
******************************************************************************/
LOCAL syslog_entry_t ICACHE_FLASH_ATTR *
syslog_compose(uint8_t facility, uint8_t severity, const char *tag, const char *fmt, ...)
{
union {
uint8_t buf[sizeof (syslog_entry_t) + 1024];
syslog_entry_t se;
} sl;
DBG("[%dµs] %s id=%lu\n", WDEV_NOW(), __FUNCTION__, syslog_msgid);
syslog_entry_t *se = os_zalloc(sizeof (syslog_entry_t) + 1024); // allow up to 1k datagram
if (se == NULL) return NULL;
char *p = se->datagram;
se->tick = WDEV_NOW(); // 0 ... 4294.967295s
se->msgid = syslog_msgid;
// The Priority value is calculated by first multiplying the Facility
// number by 8 and then adding the numerical value of the Severity.
p += os_sprintf(p, "<%d> ", facility * 8 + severity);
// strftime doesn't work as expected - or adds 8k overhead.
// so let's do poor man conversion - format is fixed anyway
if (flashConfig.syslog_showdate == 0)
p += os_sprintf(p, "- ");
else {
time_t now = NULL;
struct tm *tp = NULL;
// create timestamp: FULL-DATE "T" PARTIAL-TIME "Z": 'YYYY-mm-ddTHH:MM:SSZ '
// as long as realtime_stamp is 0 we use tick div 10⁶ as date
now = (realtime_stamp == 0) ? (sl.se.tick / 1000000) : realtime_stamp;
tp = gmtime(&now);
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);
if (realtime_stamp == 0)
p += os_sprintf(p, ".%06luZ ", sl.se.tick % 1000000);
else
p += os_sprintf(p, "%+03d:00 ", flashConfig.timezone_offset);
}
// add HOSTNAME APP-NAME PROCID MSGID
if (flashConfig.syslog_showtick)
p += os_sprintf(p, "%s %s %lu.%06lu %lu ", flashConfig.hostname, tag, sl.se.tick / 1000000, sl.se.tick % 1000000, syslog_msgid++);
else
p += os_sprintf(p, "%s %s - %lu ", flashConfig.hostname, tag, syslog_msgid++);
// append syslog message
va_list arglist;
va_start(arglist, fmt);
p += ets_vsprintf(p, fmt, arglist );
va_end(arglist);
sl.se.datagram_len = 1 + p - sl.se.datagram;
syslog_entry_t *se = os_zalloc(sizeof (syslog_entry_t) + sl.se.datagram_len);
os_memcpy(se, &sl.se, sizeof (syslog_entry_t) + sl.se.datagram_len);
return se;
}
void hw_test_timer_cb(void)
{
static uint16 j = 0;
j++;
if ((WDEV_NOW() - tick_now2) >= 1000000) {
static uint32 idx = 1;
tick_now2 = WDEV_NOW();
os_printf("b%u:%d\n", idx++, j);
j = 0;
}
//hw_timer_arm(50);
}
/*****************************************************************************
* FunctionName : syslog
* Description : compose and queue a new syslog message
* Parameters : facility
* severity
* tag
* message
* ...
*
* SYSLOG-MSG = HEADER SP STRUCTURED-DATA [SP MSG]
HEADER = PRI VERSION SP TIMESTAMP SP HOSTNAME
SP APP-NAME SP PROCID SP MSGID
PRI = "<" PRIVAL ">"
PRIVAL = 1*3DIGIT ; range 0 .. 191
VERSION = NONZERO-DIGIT 0*2DIGIT
HOSTNAME = NILVALUE / 1*255PRINTUSASCII
APP-NAME = NILVALUE / 1*48PRINTUSASCII
PROCID = NILVALUE / 1*128PRINTUSASCII
MSGID = NILVALUE / 1*32PRINTUSASCII
TIMESTAMP = NILVALUE / FULL-DATE "T" FULL-TIME
FULL-DATE = DATE-FULLYEAR "-" DATE-MONTH "-" DATE-MDAY
DATE-FULLYEAR = 4DIGIT
DATE-MONTH = 2DIGIT ; 01-12
DATE-MDAY = 2DIGIT ; 01-28, 01-29, 01-30, 01-31 based on
; month/year
FULL-TIME = PARTIAL-TIME TIME-OFFSET
PARTIAL-TIME = TIME-HOUR ":" TIME-MINUTE ":" TIME-SECOND
[TIME-SECFRAC]
TIME-HOUR = 2DIGIT ; 00-23
TIME-MINUTE = 2DIGIT ; 00-59
TIME-SECOND = 2DIGIT ; 00-59
TIME-SECFRAC = "." 1*6DIGIT
TIME-OFFSET = "Z" / TIME-NUMOFFSET
TIME-NUMOFFSET = ("+" / "-") TIME-HOUR ":" TIME-MINUTE
STRUCTURED-DATA = NILVALUE / 1*SD-ELEMENT
SD-ELEMENT = "[" SD-ID *(SP SD-PARAM) "]"
SD-PARAM = PARAM-NAME "=" %d34 PARAM-VALUE %d34
SD-ID = SD-NAME
PARAM-NAME = SD-NAME
PARAM-VALUE = UTF-8-STRING ; characters '"', '\' and
; ']' MUST be escaped.
SD-NAME = 1*32PRINTUSASCII
; except '=', SP, ']', %d34 (")
MSG = MSG-ANY / MSG-UTF8
MSG-ANY = *OCTET ; not starting with BOM
MSG-UTF8 = BOM UTF-8-STRING
BOM = %xEF.BB.BF
UTF-8-STRING = *OCTET ; UTF-8 string as specified
; in RFC 3629
OCTET = %d00-255
SP = %d32
PRINTUSASCII = %d33-126
NONZERO-DIGIT = %d49-57
DIGIT = %d48 / NONZERO-DIGIT
NILVALUE = "-"
*
* TIMESTAMP: realtime_clock == 0 ? timertick / 10⁶ : realtime_clock
* HOSTNAME hostname
* APPNAME: ems-esp-link
* PROCID: timertick
* MSGID: NILVALUE
*
* Returns : none
*******************************************************************************/
void ICACHE_FLASH_ATTR syslog(uint8_t facility, uint8_t severity, const char *tag, const char *fmt, ...)
{
DBG("[%dµs] %s status: %s\n", WDEV_NOW(), __FUNCTION__, syslog_get_status());
if (syslogState == SYSLOG_ERROR ||
syslogState == SYSLOG_HALTED ||
flashConfig.syslog_host[0] == '\0')
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);
if (res == NULL) return; // compose failed, probably due to malloc failure
syslog_entry_t *se = *(syslog_entry_t **)res;
// and append it to the message queue
syslog_add_entry(se);
if (syslogState == SYSLOG_NONE)
syslog_set_status(SYSLOG_WAIT);
if (! syslog_timer_armed)
syslog_chk_status();
}
/******************************************************************************
* FunctionName : syslog_add_entry
* Description : add a syslog_entry_t to the syslogQueue
* Parameters : entry: the syslog_entry_t
* Returns : none
******************************************************************************/
static void ICACHE_FLASH_ATTR
syslog_add_entry(syslog_entry_t *entry)
{
syslog_entry_t *pse = syslogQueue;
DBG("[%dµs] %s id=%lu\n", WDEV_NOW(), __FUNCTION__, entry->msgid);
// append msg to syslog_queue
if (pse == NULL)
syslogQueue = entry;
else {
while (pse->next != NULL)
pse = pse->next;
pse->next = entry; // append msg to syslog queue
}
// Debug: show queue addr, current msgid, avail. heap and syslog datagram
// DBG("%p %lu %d %s\n", entry, entry->msgid, system_get_free_heap_size(), entry->datagram);
// ensure we have sufficient heap for the rest of the system
if (system_get_free_heap_size() < syslogHost.min_heap_size) {
if (syslogState != SYSLOG_HALTED) {
// os_printf("syslog_add_entry: Warning: queue filled up (%d), halted\n", system_get_free_heap_size());
entry->next = syslog_compose(SYSLOG_FAC_USER, SYSLOG_PRIO_CRIT, "SYSLOG", "queue filled up (%d), halted", system_get_free_heap_size());
os_printf("%s\n", entry->next->datagram);
if (syslogState == SYSLOG_READY)
syslog_send_udp();
syslog_set_status(SYSLOG_HALTED);
}
}
}
static void ICACHE_FLASH_ATTR syslog_gethostbyname_cb(const char *name, ip_addr_t *ipaddr, void *arg)
{
DBG("[%uµs] %s\n", WDEV_NOW(), __FUNCTION__);
struct espconn *pespconn = (struct espconn *)arg;
// espconn not longer required
os_free(pespconn->proto.udp);
os_free(pespconn);
if (ipaddr != NULL) {
syslog(SYSLOG_FAC_USER, SYSLOG_PRIO_NOTICE, "SYSLOG",
"resolved hostname: %s: " IPSTR, name, IP2STR(ipaddr));
syslogHost.addr.addr = ipaddr->addr;
syslog_set_status(SYSLOG_READY);
} else {
syslog_set_status(SYSLOG_ERROR);
DBG("syslog_gethostbyname_cb: status=%s\n", syslog_get_status());
}
DBG("[%uµs] ex syslog_gethostbyname_cb()\n", WDEV_NOW());
}
static void ICACHE_FLASH_ATTR
syslog_udp_send_event(os_event_t *events) {
DBG("[%uµs] %s: id=%lu\n", WDEV_NOW(), __FUNCTION__, syslogQueue ? syslogQueue->msgid : 0);
if (syslogQueue == NULL)
syslog_set_status(SYSLOG_READY);
else {
int res = 0;
syslog_espconn->proto.udp->remote_port = syslogHost.port; // ESP8266 udp remote port
os_memcpy(syslog_espconn->proto.udp->remote_ip, &syslogHost.addr.addr, 4); // ESP8266 udp remote IP
res = espconn_send(syslog_espconn, (uint8_t *)syslogQueue->datagram, syslogQueue->datagram_len);
if (res != 0) {
os_printf("syslog_udp_send: error %d\n", res);
}
}
}
/******************************************************************************
* FunctionName : syslog_sent_cb
* Description : udp sent successfully
* fetch next syslog package, free old message
* Parameters : arg -- Additional argument to pass to the callback function
* Returns : none
******************************************************************************/
static void ICACHE_FLASH_ATTR syslog_udp_sent_cb(void *arg)
{
struct espconn *pespconn = arg;
(void) pespconn;
DBG("[%uµs] %s: id=%lu\n", WDEV_NOW(), __FUNCTION__, syslogQueue ? syslogQueue->msgid : 0);
// datagram is delivered - free and advance queue
syslog_entry_t *pse = syslogQueue;
syslogQueue = syslogQueue -> next;
os_free(pse);
if (syslogQueue == NULL)
syslog_set_status(SYSLOG_READY);
else {
// UDP seems timecritical - we must ensure a minimum delay after each package...
syslog_set_status(SYSLOG_SENDING);
if (! syslog_timer_armed)
syslog_chk_status();
}
}
static void ICACHE_FLASH_ATTR syslog_set_status(enum syslog_state state) {
syslogState = state;
DBG("[%dµs] %s: %s (%d)\n", WDEV_NOW(), __FUNCTION__, syslog_get_status(), state);
}
/******************************************************************************
* FunctionName : initSyslog
* Description : Initialize the syslog library
* Parameters : syslog_host -- the syslog host (host:port)
* host: IP-Addr | hostname
* Returns : none
*******************************************************************************/
void ICACHE_FLASH_ATTR syslog_init(char *syslog_host)
{
DBG("[%uµs] %s\n", WDEV_NOW(), __FUNCTION__);
if (!*syslog_host) {
syslog_set_status(SYSLOG_HALTED);
return;
}
if (syslog_host == NULL) {
// disable and unregister syslog handler
syslog_set_status(SYSLOG_HALTED);
if (syslog_espconn != NULL) {
if (syslog_espconn->proto.udp) {
// there's no counterpart to espconn_create...
os_free(syslog_espconn->proto.udp);
}
os_free(syslog_espconn);
}
syslog_espconn = NULL;
// clean up syslog queue
syslog_entry_t *pse = syslogQueue;
while (pse != NULL) {
syslog_entry_t *next = pse->next;
os_free(pse);
pse = next;
}
syslogQueue = NULL;
return;
}
char host[32], *port = &host[0];
os_strncpy(host, syslog_host, 32);
while (*port && *port != ':') // find port delimiter
port++;
if (*port) {
*port++ = '\0';
syslogHost.port = atoi(port);
}
if (syslogHost.port == 0)
syslogHost.port = 514;
// allocate structures, init syslog_handler
if (syslog_espconn == NULL)
syslog_espconn = (espconn *)os_zalloc(sizeof(espconn));
if (syslog_espconn->proto.udp == NULL)
syslog_espconn->proto.udp = (esp_udp *)os_zalloc(sizeof(esp_udp));
syslog_espconn->type = ESPCONN_UDP;
syslog_espconn->proto.udp->local_port = espconn_port(); // set a available port
#ifdef SYSLOG_UDP_RECV
espconn_regist_recvcb(syslog_espconn, syslog_udp_recv_cb); // register a udp packet receiving callback
#endif
espconn_regist_sentcb(syslog_espconn, syslog_udp_sent_cb); // register a udp packet sent callback
syslog_task = register_usr_task(syslog_udp_send_event);
syslogHost.min_heap_size = flashConfig.syslog_minheap;
// the wifi_set_broadcast_if must be handled global in connection handler...
// wifi_set_broadcast_if(STATIONAP_MODE); // send UDP broadcast from both station and soft-AP interface
espconn_create(syslog_espconn); // create udp
if (UTILS_StrToIP((const char *)host, (void*)&syslogHost.addr)) {
syslog_set_status(SYSLOG_READY);
} else {
// we use our own espconn structure to avoid side effects...
if (syslog_dnsconn == NULL)
syslog_dnsconn = (espconn *)os_zalloc(sizeof(espconn));
if (syslog_dnsconn->proto.udp == NULL)
syslog_dnsconn->proto.udp = (esp_udp *)os_zalloc(sizeof(esp_udp));
syslog_set_status(SYSLOG_DNSWAIT);
espconn_gethostbyname(syslog_dnsconn, host, &syslogHost.addr, syslog_gethostbyname_cb);
}
}
/******************************************************************************
* FunctionName : syslog_chk_status
* Description : check whether get ip addr or not
* Parameters : none
* Returns : none
*******************************************************************************/
static void ICACHE_FLASH_ATTR syslog_chk_status(void)
{
struct ip_info ipconfig;
DBG("[%uµs] %s: id=%lu ", WDEV_NOW(), __FUNCTION__, syslogQueue ? syslogQueue->msgid : 0);
//disarm timer first
syslog_timer_armed = false;
//try to get ip info of ESP8266 station
wifi_get_ip_info(STATION_IF, &ipconfig);
int wifi_status = wifi_station_get_connect_status();
if (wifi_status == STATION_GOT_IP && ipconfig.ip.addr != 0)
{
// it seems we have to add an additional delay after the Wifi is up and running.
// so we simply add an intermediate state with 25ms delay
switch (syslogState)
{
case SYSLOG_WAIT:
DBG("%s: Wifi connected\n", syslog_get_status());
syslog_set_status(SYSLOG_INIT);
syslog_timer_arm(100);
break;
case SYSLOG_INIT:
DBG("%s: init syslog\n", syslog_get_status());
syslog_set_status(SYSLOG_INITDONE);
syslog_init(flashConfig.syslog_host);
syslog_timer_arm(10);
break;
case SYSLOG_DNSWAIT:
DBG("%s: wait for DNS resolver\n", syslog_get_status());
syslog_timer_arm(100);
break;
case SYSLOG_READY:
DBG("%s: enforce sending\n", syslog_get_status());
syslog_send_udp();
break;
case SYSLOG_SENDING:
DBG("%s: delay\n", syslog_get_status());
syslog_set_status(SYSLOG_SEND);
syslog_timer_arm(2);
break;
case SYSLOG_SEND:
DBG("%s: start sending\n", syslog_get_status());
syslog_send_udp();
break;
default:
DBG("%s: %d\n", syslog_get_status(), syslogState);
break;
}
} else {
if ((wifi_status == STATION_WRONG_PASSWORD ||
wifi_status == STATION_NO_AP_FOUND ||
wifi_status == STATION_CONNECT_FAIL)) {
syslog_set_status(SYSLOG_ERROR);
os_printf("*** connect failure %d!!!\n", wifi_status);
} else {
DBG("re-arming timer...\n");
syslog_timer_arm(WIFI_CHK_INTERVAL);
}
}
}
