3c99391d93
In some cases the license-identification header was missing, so I added that as well. Replaced the remaining headers that specifically identified "Versions 3.13.7 and higher". Makefiles and the build system were deliberately excluded.
519 lines
14 KiB
C
519 lines
14 KiB
C
/*************************************************************************\
|
|
* Copyright (c) 2010 Brookhaven Science Associates, as Operator of
|
|
* Brookhaven National Laboratory.
|
|
* Copyright (c) 2010 UChicago Argonne LLC, as Operator of Argonne
|
|
* National Laboratory.
|
|
* SPDX-License-Identifier: EPICS
|
|
* EPICS BASE is distributed subject to a Software License Agreement found
|
|
* in file LICENSE that is included with this distribution.
|
|
\*************************************************************************/
|
|
/*
|
|
* Author: Michael Davidsaver
|
|
* Date: 2010-09-24
|
|
*/
|
|
|
|
#include <stdio.h>
|
|
#include <stdlib.h>
|
|
#include <string.h>
|
|
|
|
#include "epicsAssert.h"
|
|
#include "epicsThread.h"
|
|
#include "epicsEvent.h"
|
|
#include "dbDefs.h"
|
|
#include "errlog.h"
|
|
#include "epicsUnitTest.h"
|
|
#include "testMain.h"
|
|
#include "iocLog.h"
|
|
#include "logClient.h"
|
|
#include "envDefs.h"
|
|
#include "osiSock.h"
|
|
#include "fdmgr.h"
|
|
|
|
#define LOGBUFSIZE 2048
|
|
|
|
static
|
|
const char longmsg[]="A0123456789abcdef"
|
|
"B0123456789abcdef"
|
|
"C0123456789abcdef"
|
|
"D0123456789abcdef"
|
|
"E0123456789abcdef"
|
|
"F0123456789abcdef"
|
|
"G0123456789abcdef"
|
|
"H0123456789abcdef"
|
|
"I0123456789abcdef"
|
|
"J0123456789abcdef"
|
|
"K0123456789abcdef"
|
|
"L0123456789abcdef"
|
|
"M0123456789abcdef"
|
|
"N0123456789abcdef"
|
|
"O0123456789abcdef"
|
|
"P0123456789abcdef"
|
|
"Q0123456789abcdef"
|
|
"R0123456789abcdef"
|
|
"S0123456789abcdef"
|
|
;
|
|
STATIC_ASSERT(NELEMENTS(longmsg)==324);
|
|
|
|
static
|
|
const char truncmsg[]="A0123456789abcdef"
|
|
"B0123456789abcdef"
|
|
"C0123456789abcdef"
|
|
"D0123456789abcdef"
|
|
"E0123456789abcdef"
|
|
"F0123456789abcdef"
|
|
"G0123456789abcdef"
|
|
"H0123456789abcdef"
|
|
"I0123456789abcdef"
|
|
"J0123456789abcdef"
|
|
"K0123456789abcdef"
|
|
"L0123456789abcdef"
|
|
"M0123456789abcdef"
|
|
"N0123456789abcdef"
|
|
"O01<<TRUNCATED>>\n"
|
|
;
|
|
STATIC_ASSERT(NELEMENTS(truncmsg)==256);
|
|
|
|
typedef struct {
|
|
unsigned int count;
|
|
const char* expect;
|
|
size_t checkLen;
|
|
epicsEventId jammer;
|
|
int jam;
|
|
epicsEventId done;
|
|
} clientPvt;
|
|
|
|
static void testLogPrefix(void);
|
|
static void acceptNewClient( void *pParam );
|
|
static void readFromClient( void *pParam );
|
|
static void testPrefixLogandCompare( const char* logmessage);
|
|
|
|
static void *pfdctx;
|
|
static SOCKET sock;
|
|
static SOCKET insock;
|
|
|
|
static const char* prefixactualmsg[]= {
|
|
"A message without prefix",
|
|
"A message with prefix",
|
|
"DONE"
|
|
};
|
|
static const char *prefixstring = "fac=LI21 ";
|
|
static const char prefixexpectedmsg[] = "A message without prefix"
|
|
"fac=LI21 A message with prefix"
|
|
"fac=LI21 DONE"
|
|
;
|
|
static char prefixmsgbuffer[1024];
|
|
|
|
|
|
static void
|
|
testEqInt_(int line, int lhs, int rhs, const char *LHS, const char *RHS)
|
|
{
|
|
testOk(lhs==rhs, "%d: %s (%d) == %s (%d)", line, LHS, lhs, RHS, rhs);
|
|
}
|
|
#define testEqInt(L, R) testEqInt_(__LINE__, L, R, #L, #R);
|
|
|
|
static
|
|
void logClient(void* raw, const char* msg)
|
|
{
|
|
clientPvt *pvt = raw;
|
|
size_t len;
|
|
char show[46];
|
|
|
|
/* Simulate thread priority on non-realtime
|
|
* OSs like Linux. This will cause the logging
|
|
* thread to sleep with the buffer lock held.
|
|
*/
|
|
if (pvt->jam > 0) {
|
|
pvt->jam = 0;
|
|
epicsEventMustWait(pvt->jammer);
|
|
} else if (pvt->jam < 0) {
|
|
pvt->jam++;
|
|
if (pvt->jam == 0)
|
|
epicsEventMustWait(pvt->jammer);
|
|
}
|
|
|
|
len = strlen(msg);
|
|
if (len > 45) {
|
|
/* Only show start and end of long messages */
|
|
strncpy(show, msg, 20);
|
|
show[20] = 0;
|
|
strcat(show + 20, " ... ");
|
|
strcat(show + 25, msg + len - 20);
|
|
}
|
|
else {
|
|
strcpy(show, msg);
|
|
}
|
|
|
|
if (pvt->checkLen)
|
|
if (!testOk(pvt->checkLen == len, "Received %d chars", (int) len)) {
|
|
testDiag("Expected %d", (int) pvt->checkLen);
|
|
if (!pvt->expect)
|
|
testDiag("Message is \"%s\"", show);
|
|
}
|
|
|
|
if (pvt->expect) {
|
|
if (!testOk(strcmp(pvt->expect, msg) == 0, "Message is \"%s\"", show)) {
|
|
len = strlen(pvt->expect);
|
|
if (len > 45) {
|
|
testDiag("Expected \"%.20s ... %s\"",
|
|
pvt->expect, pvt->expect + len - 20);
|
|
}
|
|
else {
|
|
testDiag("Expected \"%s\"", pvt->expect);
|
|
}
|
|
}
|
|
}
|
|
|
|
pvt->count++;
|
|
epicsEventSignal(pvt->done);
|
|
}
|
|
|
|
MAIN(epicsErrlogTest)
|
|
{
|
|
size_t mlen, i, N;
|
|
char msg[256];
|
|
clientPvt pvt, pvt2;
|
|
|
|
testPlan(40);
|
|
|
|
strcpy(msg, truncmsg);
|
|
|
|
errlogInit2(LOGBUFSIZE, 256);
|
|
|
|
pvt.count = 0;
|
|
pvt2.count = 0;
|
|
|
|
pvt.expect = NULL;
|
|
pvt2.expect = NULL;
|
|
|
|
pvt.checkLen = 0;
|
|
pvt2.checkLen = 0;
|
|
|
|
pvt.jam = 0;
|
|
pvt2.jam = 0;
|
|
|
|
pvt.jammer = epicsEventMustCreate(epicsEventEmpty);
|
|
pvt.done = epicsEventMustCreate(epicsEventEmpty);
|
|
pvt2.jammer = epicsEventMustCreate(epicsEventEmpty);
|
|
pvt2.done = epicsEventMustCreate(epicsEventEmpty);
|
|
|
|
testDiag("Check listener registration");
|
|
|
|
errlogAddListener(&logClient, &pvt);
|
|
|
|
pvt.expect = "Testing";
|
|
pvt.checkLen = strlen(pvt.expect);
|
|
|
|
errlogPrintfNoConsole("%s", pvt.expect);
|
|
errlogFlush();
|
|
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, 1);
|
|
|
|
errlogAddListener(&logClient, &pvt2);
|
|
|
|
pvt2.expect = pvt.expect = "Testing2";
|
|
pvt2.checkLen = pvt.checkLen = strlen(pvt.expect);
|
|
|
|
errlogPrintfNoConsole("%s", pvt.expect);
|
|
errlogFlush();
|
|
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, 2);
|
|
|
|
epicsEventMustWait(pvt2.done);
|
|
testEqInt(pvt2.count, 1);
|
|
|
|
/* Removes the first listener */
|
|
testOk(1 == errlogRemoveListeners(&logClient, &pvt),
|
|
"Removed 1 listener");
|
|
|
|
pvt2.expect = "Testing3";
|
|
pvt2.checkLen = strlen(pvt2.expect);
|
|
|
|
errlogPrintfNoConsole("%s", pvt2.expect);
|
|
errlogFlush();
|
|
|
|
testOk(epicsEventWaitWithTimeout(pvt.done, 0.5) == epicsEventWaitTimeout,
|
|
"%d: Listener 1 didn't run", __LINE__);
|
|
testOk(epicsEventTryWait(pvt2.done) == epicsEventOK,
|
|
"%d: Listener 2 ran", __LINE__);
|
|
testEqInt(pvt.count, 2);
|
|
testEqInt(pvt2.count, 2);
|
|
|
|
/* Add the second listener again, then remove both instances */
|
|
errlogAddListener(&logClient, &pvt2);
|
|
testOk(2 == errlogRemoveListeners(&logClient, &pvt2),
|
|
"Removed 2 listeners");
|
|
|
|
errlogPrintfNoConsole("Something different");
|
|
errlogFlush();
|
|
|
|
testOk(epicsEventWaitWithTimeout(pvt.done, 0.5) == epicsEventWaitTimeout,
|
|
"%d: Listener 1 didn't run", __LINE__);
|
|
testOk(epicsEventTryWait(pvt2.done) == epicsEventWaitTimeout,
|
|
"%d: Listener 2 didn't run", __LINE__);
|
|
testEqInt(pvt.count, 2);
|
|
testEqInt(pvt2.count, 2);
|
|
|
|
/* Re-add one listener */
|
|
errlogAddListener(&logClient, &pvt);
|
|
|
|
testDiag("Check truncation");
|
|
|
|
pvt.expect = truncmsg;
|
|
pvt.checkLen = 255;
|
|
|
|
errlogPrintfNoConsole("%s", longmsg);
|
|
errlogFlush();
|
|
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, 3);
|
|
|
|
pvt.expect = NULL;
|
|
|
|
testDiag("Check priority");
|
|
/* For the following tests it is important that
|
|
* the buffer should not flush until we request it
|
|
*/
|
|
pvt.jam = 1;
|
|
|
|
errlogPrintfNoConsole("%s", longmsg);
|
|
|
|
testOk(epicsEventWaitWithTimeout(pvt.done, 0.5) == epicsEventWaitTimeout,
|
|
"%d: Listener 1 didn't run", __LINE__);
|
|
testEqInt(pvt.count, 3);
|
|
|
|
epicsEventSignal(pvt.jammer);
|
|
errlogFlush();
|
|
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, 4);
|
|
|
|
testDiag("Find buffer capacity (%u theoretical)",LOGBUFSIZE);
|
|
|
|
pvt.checkLen = 0;
|
|
|
|
for (mlen = 8; mlen <= 255; mlen *= 2) {
|
|
double eff;
|
|
char save = msg[mlen - 1];
|
|
|
|
N = LOGBUFSIZE / mlen; /* # of of messages to send */
|
|
msg[mlen - 1] = '\0';
|
|
pvt.count = 0;
|
|
/* pvt.checkLen = mlen - 1; */
|
|
|
|
pvt.jam = 1;
|
|
|
|
for (i = 0; i < N; i++) {
|
|
errlogPrintfNoConsole("%s", msg);
|
|
}
|
|
|
|
epicsEventSignal(pvt.jammer);
|
|
errlogFlush();
|
|
|
|
eff = (double) (pvt.count * mlen) / LOGBUFSIZE * 100.0;
|
|
testDiag(" For %d messages of length %d got %u (%.1f%% efficient)",
|
|
(int) N, (int) mlen, pvt.count, eff);
|
|
|
|
msg[mlen - 1] = save;
|
|
N = pvt.count; /* Save final count for the test below */
|
|
|
|
/* Clear "errlog: <n> messages were discarded" status */
|
|
pvt.checkLen = 0;
|
|
errlogPrintfNoConsole(".");
|
|
errlogFlush();
|
|
}
|
|
|
|
testOk(epicsEventTryWait(pvt.done) == epicsEventOK,
|
|
"%d: Listener 1 ran", __LINE__);
|
|
|
|
testDiag("Checking buffer use after partial flush");
|
|
|
|
/* Use the numbers from the largest block size above */
|
|
mlen /= 2;
|
|
msg[mlen - 1] = '\0';
|
|
|
|
pvt.jam = 1;
|
|
pvt.count = 0;
|
|
|
|
testDiag("Filling with %d messages of size %d", (int) N, (int) mlen);
|
|
|
|
for (i = 0; i < N; i++) {
|
|
errlogPrintfNoConsole("%s", msg);
|
|
}
|
|
|
|
testOk(epicsEventWaitWithTimeout(pvt.done, 0.5) == epicsEventWaitTimeout,
|
|
"%d: Listener 1 didn't run", __LINE__);
|
|
testEqInt(pvt.count, 0);
|
|
|
|
/* Extract the first 2 messages, 2*(sizeof(msgNode) + 128) bytes */
|
|
pvt.jam = -2;
|
|
epicsEventSignal(pvt.jammer);
|
|
epicsThreadSleep(0.5);
|
|
|
|
testDiag("Drained %u messages", pvt.count);
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, 2);
|
|
|
|
/* The buffer has space for 1 more message: sizeof(msgNode) + 256 bytes */
|
|
errlogPrintfNoConsole("%s", msg); /* Use up that space */
|
|
|
|
testDiag("Overflow the buffer");
|
|
errlogPrintfNoConsole("%s", msg);
|
|
|
|
testOk(epicsEventWaitWithTimeout(pvt.done, 0.5) == epicsEventWaitTimeout,
|
|
"%d: Listener 1 didn't run", __LINE__);
|
|
testEqInt(pvt.count, 2);
|
|
|
|
epicsEventSignal(pvt.jammer); /* Empty */
|
|
errlogFlush();
|
|
|
|
testDiag("Logged %u messages", pvt.count);
|
|
epicsEventMustWait(pvt.done);
|
|
testEqInt(pvt.count, N+1);
|
|
|
|
/* Clean up */
|
|
testOk(1 == errlogRemoveListeners(&logClient, &pvt),
|
|
"Removed 1 listener");
|
|
|
|
testLogPrefix();
|
|
|
|
return testDone();
|
|
}
|
|
/*
|
|
* Tests the log prefix code
|
|
* The prefix is only applied to log messages as they go out to the socket,
|
|
* so we need to create a server listening on a port, accept connections etc.
|
|
* This code is a reduced version of the code in iocLogServer.
|
|
*/
|
|
static void testLogPrefix(void) {
|
|
struct sockaddr_in serverAddr;
|
|
int status;
|
|
struct timeval timeout;
|
|
struct sockaddr_in actualServerAddr;
|
|
osiSocklen_t actualServerAddrSize;
|
|
char portstring[16];
|
|
|
|
|
|
testDiag("Testing iocLogPrefix");
|
|
|
|
timeout.tv_sec = 5; /* in seconds */
|
|
timeout.tv_usec = 0;
|
|
|
|
memset((void*)prefixmsgbuffer, 0, sizeof prefixmsgbuffer);
|
|
|
|
/* Clear "errlog: <n> messages were discarded" status */
|
|
errlogPrintfNoConsole(".");
|
|
errlogFlush();
|
|
|
|
sock = epicsSocketCreate(AF_INET, SOCK_STREAM, 0);
|
|
if (sock == INVALID_SOCKET) {
|
|
testAbort("epicsSocketCreate failed.");
|
|
}
|
|
|
|
/* We listen on a an available port. */
|
|
memset((void *)&serverAddr, 0, sizeof serverAddr);
|
|
serverAddr.sin_family = AF_INET;
|
|
serverAddr.sin_port = htons(0);
|
|
|
|
status = bind (sock, (struct sockaddr *)&serverAddr,
|
|
sizeof (serverAddr) );
|
|
if (status < 0) {
|
|
testAbort("bind failed; all ports in use?");
|
|
}
|
|
|
|
status = listen(sock, 10);
|
|
if (status < 0) {
|
|
testAbort("listen failed!");
|
|
}
|
|
|
|
/* Determine the port that the OS chose */
|
|
actualServerAddrSize = sizeof actualServerAddr;
|
|
memset((void *)&actualServerAddr, 0, sizeof serverAddr);
|
|
status = getsockname(sock, (struct sockaddr *) &actualServerAddr,
|
|
&actualServerAddrSize);
|
|
if (status < 0) {
|
|
testAbort("Can't find port number!");
|
|
}
|
|
|
|
sprintf(portstring, "%d", ntohs(actualServerAddr.sin_port));
|
|
testDiag("Listening on port %s", portstring);
|
|
|
|
/* Set the EPICS environment variables for logging. */
|
|
epicsEnvSet ( "EPICS_IOC_LOG_INET", "localhost" );
|
|
epicsEnvSet ( "EPICS_IOC_LOG_PORT", portstring );
|
|
|
|
pfdctx = (void *) fdmgr_init();
|
|
if (status < 0) {
|
|
testAbort("fdmgr_init failed!");
|
|
}
|
|
|
|
status = fdmgr_add_callback(pfdctx, sock, fdi_read,
|
|
acceptNewClient, &serverAddr);
|
|
|
|
if (status < 0) {
|
|
testAbort("fdmgr_add_callback failed!");
|
|
}
|
|
|
|
testOk1(iocLogInit() == 0);
|
|
fdmgr_pend_event(pfdctx, &timeout);
|
|
|
|
testPrefixLogandCompare(prefixactualmsg[0]);
|
|
|
|
iocLogPrefix(prefixstring);
|
|
testPrefixLogandCompare(prefixactualmsg[1]);
|
|
testPrefixLogandCompare(prefixactualmsg[2]);
|
|
epicsSocketDestroy(sock);
|
|
}
|
|
|
|
static void testPrefixLogandCompare( const char* logmessage ) {
|
|
struct timeval timeout;
|
|
timeout.tv_sec = 5; /* in seconds */
|
|
timeout.tv_usec = 0;
|
|
|
|
errlogPrintfNoConsole("%s", logmessage);
|
|
errlogFlush();
|
|
iocLogFlush();
|
|
fdmgr_pend_event(pfdctx, &timeout);
|
|
}
|
|
|
|
static void acceptNewClient ( void *pParam )
|
|
{
|
|
osiSocklen_t addrSize;
|
|
struct sockaddr_in addr;
|
|
int status;
|
|
|
|
addrSize = sizeof ( addr );
|
|
insock = epicsSocketAccept ( sock, (struct sockaddr *)&addr, &addrSize );
|
|
testOk(insock != INVALID_SOCKET && addrSize >= sizeof (addr),
|
|
"Accepted new client");
|
|
|
|
status = fdmgr_add_callback(pfdctx, insock, fdi_read,
|
|
readFromClient, NULL);
|
|
|
|
testOk(status >= 0, "Client read configured");
|
|
}
|
|
|
|
static void readFromClient(void *pParam)
|
|
{
|
|
char recvbuf[1024];
|
|
int recvLength;
|
|
|
|
memset(recvbuf, 0, 1024);
|
|
recvLength = recv(insock, recvbuf, 1024, 0);
|
|
if (recvLength > 0) {
|
|
strcat(prefixmsgbuffer, recvbuf);
|
|
|
|
/* If we have received all of the messages. */
|
|
if (strstr(prefixmsgbuffer, "DONE") != NULL) {
|
|
size_t msglen = strlen(prefixexpectedmsg);
|
|
int prefixcmp = strncmp(prefixexpectedmsg, prefixmsgbuffer, msglen);
|
|
|
|
if (!testOk(prefixcmp == 0, "prefix matches")) {
|
|
testDiag("Expected '%s'\n", prefixexpectedmsg);
|
|
testDiag("Obtained '%s'\n", prefixmsgbuffer);
|
|
}
|
|
}
|
|
}
|
|
}
|