hcq/MaxScale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

LOGIF and skygw_write_log removed from server/core/*.c

Browse Source 
LOGIF and skygw_write_log removed from server/core/*.c and
replaced with calls to MXS_(ERROR|WARNING|NOTICE|INFO|DEBUG).
This is a mechanism change, no updating of the actual message
has been performed.

Currently this causes a very small performance hit, since the
check whether the priority is enabled or not is performed in
the function that is called and not before the function is called.
Once all LOGIFs and skygw_write_logs have been replaced, the
behaviour will be altered back to what it was.
This commit is contained in:
Johan Wikman
2015-11-15 19:37:15 +02:00
parent 1f15843d61
commit 44df53d846
19 changed files with 1367 additions and 1992 deletions
Download Patch File Download Diff File Expand all files Collapse all files

257
server/core/poll.c
View File

@ -284,25 +284,21 @@ poll_add_dcb(DCB *dcb)
|| DCB_STATE_ZOMBIE == dcb->state
|| DCB_STATE_UNDEFINED == dcb->state)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_add_dcb] Error : existing state of dcb %p "
"is %s, but this should be impossible, crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state))));
MXS_ERROR("%lu [poll_add_dcb] Error : existing state of dcb %p "
"is %s, but this should be impossible, crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state));
raise(SIGABRT);
}
if (DCB_STATE_POLLING == dcb->state
|| DCB_STATE_LISTENING == dcb->state)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_add_dcb] Error : existing state of dcb %p "
"is %s, but this is probably an error, not crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state))));
MXS_ERROR("%lu [poll_add_dcb] Error : existing state of dcb %p "
"is %s, but this is probably an error, not crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state));
}
dcb->state = new_state;
spinlock_release(&dcb->dcb_initlock);
@ -318,12 +314,10 @@ poll_add_dcb(DCB *dcb)
}
if (0 == rc)
{
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_add_dcb] Added dcb %p in state %s to poll set.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state))));
MXS_DEBUG("%lu [poll_add_dcb] Added dcb %p in state %s to poll set.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state));
}
else dcb->state = old_state;
return rc;
@ -354,13 +348,11 @@ poll_remove_dcb(DCB *dcb)
if (DCB_STATE_POLLING != dcb->state
&& DCB_STATE_LISTENING != dcb->state)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_remove_dcb] Error : existing state of dcb %p "
"is %s, but this is probably an error, not crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state))));
MXS_ERROR("%lu [poll_remove_dcb] Error : existing state of dcb %p "
"is %s, but this is probably an error, not crashing.",
pthread_self(),
dcb,
STRDCBSTATE(dcb->state));
}
/*<
* Set state to NOPOLLING and remove dcb from poll set.
@ -409,25 +401,21 @@ poll_resolve_error(DCB *dcb, int errornum, bool adding)
{
if (EEXIST == errornum)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_resolve_error] Error : epoll_ctl could not add, "
"already exists for DCB %p.",
pthread_self(),
dcb)));
MXS_ERROR("%lu [poll_resolve_error] Error : epoll_ctl could not add, "
"already exists for DCB %p.",
pthread_self(),
dcb);
// Assume another thread added and no serious harm done
return 0;
}
if (ENOSPC == errornum)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_resolve_error] The limit imposed by "
"/proc/sys/fs/epoll/max_user_watches was "
"encountered while trying to register (EPOLL_CTL_ADD) a new "
"file descriptor on an epoll instance for dcb %p.",
pthread_self(),
dcb)));
MXS_ERROR("%lu [poll_resolve_error] The limit imposed by "
"/proc/sys/fs/epoll/max_user_watches was "
"encountered while trying to register (EPOLL_CTL_ADD) a new "
"file descriptor on an epoll instance for dcb %p.",
pthread_self(),
dcb);
/* Failure - assume handled by callers */
return -1;
}
@ -437,12 +425,10 @@ poll_resolve_error(DCB *dcb, int errornum, bool adding)
/* Must be removing */
if (ENOENT == errornum)
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [poll_resolve_error] Error : epoll_ctl could not remove, "
"not found, for dcb %p.",
pthread_self(),
dcb)));
MXS_ERROR("%lu [poll_resolve_error] Error : epoll_ctl could not remove, "
"not found, for dcb %p.",
pthread_self(),
dcb);
// Assume another thread removed and no serious harm done
return 0;
}
@ -557,13 +543,11 @@ int poll_spins = 0;
atomic_add(&n_waiting, -1);
int eno = errno;
errno = 0;
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] epoll_wait returned "
"%d, errno %d",
pthread_self(),
nfds,
eno)));
MXS_DEBUG("%lu [poll_waitevents] epoll_wait returned "
"%d, errno %d",
pthread_self(),
nfds,
eno);
atomic_add(&n_waiting, -1);
}
/*
@ -604,11 +588,9 @@ int poll_spins = 0;
if (poll_spins <= number_poll_spins + 1)
atomic_add(&pollStats.n_nbpollev, 1);
poll_spins = 0;
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] epoll_wait found %d fds",
pthread_self(),
nfds)));
MXS_DEBUG("%lu [poll_waitevents] epoll_wait found %d fds",
pthread_self(),
nfds);
atomic_add(&pollStats.n_pollev, 1);
if (thread_data)
{
@ -757,8 +739,8 @@ poll_set_maxwait(unsigned int maxwait)
* Including session id to log entries depends on this function. Assumption is
* that when maxscale thread starts processing of an event it processes one
* and only one session until it returns from this function. Session id is
* read to thread's local storage in macro LOGIF_MAYBE(...) and reset back
* to zero just before returning in LOGIF(...) macro.
* read to thread's local storage if LOG_MAY_BE_ENABLED(LOGFILE_TRACE) returns true
* reset back to zero just before returning in LOG_IS_ENABLED(LOGFILE_TRACE) returns true.
* Thread local storage (tls_log_info_t) follows thread and is accessed every
* time log is written to particular log.
*
@ -842,15 +824,13 @@ unsigned long qtime;
#if defined(FAKE_CODE)
if (dcb_fake_write_ev[dcb->fd] != 0) {
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"Added fake events %d to ev %d.",
pthread_self(),
dcb_fake_write_ev[dcb->fd],
ev)));
ev |= dcb_fake_write_ev[dcb->fd];
dcb_fake_write_ev[dcb->fd] = 0;
MXS_DEBUG("%lu [poll_waitevents] "
"Added fake events %d to ev %d.",
pthread_self(),
dcb_fake_write_ev[dcb->fd],
ev);
ev |= dcb_fake_write_ev[dcb->fd];
dcb_fake_write_ev[dcb->fd] = 0;
}
#endif /* FAKE_CODE */
ss_debug(spinlock_acquire(&dcb->dcb_initlock);)
@ -861,16 +841,14 @@ unsigned long qtime;
{
return 0;
}
ss_debug(spinlock_release(&dcb->dcb_initlock);)
ss_debug(spinlock_release(&dcb->dcb_initlock));
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] event %d dcb %p "
"role %s",
pthread_self(),
ev,
dcb,
STRDCBROLE(dcb->dcb_role))));
MXS_DEBUG("%lu [poll_waitevents] event %d dcb %p "
"role %s",
pthread_self(),
ev,
dcb,
STRDCBROLE(dcb->dcb_role));
if (ev & EPOLLOUT)
{
@ -893,28 +871,24 @@ unsigned long qtime;
}
} else {
char errbuf[STRERROR_BUFLEN];
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"EPOLLOUT due %d, %s. "
"dcb %p, fd %i",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)),
dcb,
dcb->fd)));
MXS_DEBUG("%lu [poll_waitevents] "
"EPOLLOUT due %d, %s. "
"dcb %p, fd %i",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)),
dcb,
dcb->fd);
}
}
if (ev & EPOLLIN)
{
if (dcb->state == DCB_STATE_LISTENING)
{
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"Accept in fd %d",
pthread_self(),
dcb->fd)));
MXS_DEBUG("%lu [poll_waitevents] "
"Accept in fd %d",
pthread_self(),
dcb->fd);
atomic_add(
&pollStats.n_accept, 1);
if (LOG_MAY_BE_ENABLED(LOGFILE_TRACE))
@ -931,13 +905,11 @@ unsigned long qtime;
}
else
{
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"Read in dcb %p fd %d",
pthread_self(),
dcb,
dcb->fd)));
MXS_DEBUG("%lu [poll_waitevents] "
"Read in dcb %p fd %d",
pthread_self(),
dcb,
dcb->fd);
atomic_add(&pollStats.n_read, 1);
/** Read session id to thread's local storage */
if (LOG_MAY_BE_ENABLED(LOGFILE_TRACE))
@ -960,26 +932,22 @@ unsigned long qtime;
if (eno == 0) {
eno = dcb_fake_write_errno[dcb->fd];
char errbuf[STRERROR_BUFLEN];
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"Added fake errno %d. "
"%s",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)))));
MXS_DEBUG("%lu [poll_waitevents] "
"Added fake errno %d. "
"%s",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)));
}
dcb_fake_write_errno[dcb->fd] = 0;
#endif /* FAKE_CODE */
if (eno != 0) {
char errbuf[STRERROR_BUFLEN];
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"EPOLLERR due %d, %s.",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)))));
MXS_DEBUG("%lu [poll_waitevents] "
"EPOLLERR due %d, %s.",
pthread_self(),
eno,
strerror_r(eno, errbuf, sizeof(errbuf)));
}
atomic_add(&pollStats.n_error, 1);
/** Read session id to thread's local storage */
@ -1000,16 +968,14 @@ unsigned long qtime;
int eno = 0;
eno = gw_getsockerrno(dcb->fd);
char errbuf[STRERROR_BUFLEN];
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"EPOLLHUP on dcb %p, fd %d. "
"Errno %d, %s.",
pthread_self(),
dcb,
dcb->fd,
eno,
strerror_r(eno, errbuf, sizeof(errbuf)))));
MXS_DEBUG("%lu [poll_waitevents] "
"EPOLLHUP on dcb %p, fd %d. "
"Errno %d, %s.",
pthread_self(),
dcb,
dcb->fd,
eno,
strerror_r(eno, errbuf, sizeof(errbuf)));
atomic_add(&pollStats.n_hup, 1);
spinlock_acquire(&dcb->dcb_initlock);
if ((dcb->flags & DCBF_HUNG) == 0)
@ -1038,16 +1004,14 @@ unsigned long qtime;
int eno = 0;
eno = gw_getsockerrno(dcb->fd);
char errbuf[STRERROR_BUFLEN];
LOGIF(LD, (skygw_log_write(
LOGFILE_DEBUG,
"%lu [poll_waitevents] "
"EPOLLRDHUP on dcb %p, fd %d. "
"Errno %d, %s.",
pthread_self(),
dcb,
dcb->fd,
eno,
strerror_r(eno, errbuf, sizeof(errbuf)))));
MXS_DEBUG("%lu [poll_waitevents] "
"EPOLLRDHUP on dcb %p, fd %d. "
"Errno %d, %s.",
pthread_self(),
dcb,
dcb->fd,
eno,
strerror_r(eno, errbuf, sizeof(errbuf)));
atomic_add(&pollStats.n_hup, 1);
spinlock_acquire(&dcb->dcb_initlock);
if ((dcb->flags & DCBF_HUNG) == 0)
@ -1126,7 +1090,10 @@ unsigned long qtime;
}
dcb->evq.processing = 0;
/** Reset session id from thread's local storage */
LOGIF(LT, tls_log_info.li_sesid = 0);
if (LOG_IS_ENABLED(LOGFILE_TRACE))
{
tls_log_info.li_sesid = 0;
}
spinlock_release(&pollqlock);
return 1;
@ -1150,14 +1117,12 @@ poll_dcb_session_check(DCB *dcb, const char *function)
}
else
{
LOGIF(LE, (skygw_log_write_flush(
LOGFILE_ERROR,
"%lu [%s] The dcb %p that was about to be processed by %s does not "
"have a non-null session pointer ",
pthread_self(),
__func__,
dcb,
function)));
MXS_ERROR("%lu [%s] The dcb %p that was about to be processed by %s does not "
"have a non-null session pointer ",
pthread_self(),
__func__,
dcb,
function);
return false;
}
}