server/common/logger.C

/*
 * This file is part of Deliantra, the Roguelike Realtime MMORPG.
 *
 * Copyright (©) 2017,2018 Marc Alexander Lehmann / the Deliantra team
 * Copyright (©) 2005,2006,2007,2008,2009,2010,2011,2012,2013,2014,2015,2016 Marc Alexander Lehmann / Robin Redeker / the Deliantra team
 *
 * Deliantra is free software: you can redistribute it and/or modify it under
 * the terms of the Affero GNU General Public License as published by the
 * Free Software Foundation, either version 3 of the License, or (at your
 * option) any later version.
 *
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
 * GNU General Public License for more details.
 *
 * You should have received a copy of the Affero GNU General Public License
 * and the GNU General Public License along with this program. If not, see
 * <http://www.gnu.org/licenses/>.
 *
 * The authors can be reached via e-mail to <support@deliantra.net>
 */

#include <cstdarg>
#include <cstring>

#include <vector>

#include <sys/uio.h>
#include <pthread.h>

#include "global.h"
#include "dynbuf.h"
#include "util.h"

struct logline
{
  struct timeval tv;
  char *buf; // includes PREFIX_LEN garbage bytes
  int len;
  int flags;
};

typedef std::vector<logline, slice_allocator<logline> > logvector;

static SMUTEX(mutex);
static SMUTEX(fdlock);
static SCOND(cond);
static int logfd = STDERR_FILENO;
static int logsync = 1;
static logvector queue;

int log_setfd (int fd)
{
  SMUTEX_LOCK (fdlock);
  int old = logfd;
  logfd = fd < 0 ? STDERR_FILENO : fd;
  SMUTEX_UNLOCK (fdlock);

  return old;
}

#define PREFIX_LEN sizeof ("0000-00-00 00:00:00.0000 L+") - 1

static void
log_sync (logline &line)
{
  static const char levelchar [16+1] = "EWIDt???????????";
  struct tm lt;
  char pfx [PREFIX_LEN];

  localtime_r (&line.tv.tv_sec, &lt);

  sprintf (pfx, "%04d-%02d-%02d %02d:%02d:%02d.%04d %c",
    lt.tm_year + 1900,
    lt.tm_mon + 1,
    lt.tm_mday,
    lt.tm_hour,
    lt.tm_min,
    lt.tm_sec,
    (int)(line.tv.tv_usec / 100),
    levelchar [line.flags & 15]
  );

  pfx [PREFIX_LEN - 1] = line.flags & logSync ? '=' : ' ';

  struct iovec iov [2];

  iov [0].iov_base = pfx;
  iov [0].iov_len = PREFIX_LEN;

  char *buf = line.buf;

  if (logsync != 2)
    SMUTEX_LOCK (fdlock);

  while (char *end = strchr (buf, '\n'))
    {
      iov [1].iov_base = buf;
      iov [1].iov_len = end - buf + 1;

      writev (STDERR_FILENO, iov, 2);
      if (logfd != STDERR_FILENO)
        writev (logfd, iov, 2);

      buf = end + 1;

      if (buf == line.buf + line.len)
        break;

      pfx [PREFIX_LEN - 1] = '+';
    }

  if (logsync != 2)
    SMUTEX_UNLOCK (fdlock);

  sfree (line.buf, line.len);
}

static void *
logthread_proc (void *arg)
{
  int idx = 0;

  for (;;)
    {
      logline line;

      SMUTEX_LOCK (mutex);

      while (queue.empty ())
        SCOND_WAIT (cond, mutex);

      line = queue [idx++];

      // this algorithm could result in an ever-increasing vector
      // size if we log faster than we can write, but if that happens
      // we have bigger problems.
      if (idx == queue.size ())
        {
          if (idx < 32)
            queue.clear ();
          else
            logvector ().swap (queue); // free memory, hopefully

          idx = 0;
        }

      SMUTEX_UNLOCK (mutex);

      log_sync (line);
    }
}

void
log_cleanup ()
{
  logsync = 1;
  SMUTEX_UNLOCK (fdlock);

  for (;;)
    {
      int done;

      SMUTEX_LOCK (mutex);
      done = queue.empty ();
      SMUTEX_UNLOCK (mutex);

      if (done)
        break;

      usleep (10000);
      SMUTEX_LOCK (fdlock);
      SMUTEX_UNLOCK (fdlock);
    }
}

static void
af_child ()
{
  logsync = 2;
}

static struct logthread : thread
{
  logthread ()
  {
    pthread_atfork (0, 0, af_child);
    start (logthread_proc);
    logsync = 0;
  }
} logthread;

void
LOG (int flags, const_utf8_string format, ...)
{
  int level = flags & 15;

  if (level > settings.debug)
    return;

  logline line;
  gettimeofday (&line.tv, 0);

  static dynbuf_text buf;

  va_list ap;
  va_start (ap, format);
  buf.vprintf (format, ap);
  va_end (ap);

  buf << '\n';

  line.buf = buf.linearise ();
  line.len = buf.size ();

  if (line.buf [line.len - 2] == '\n')
    --line.len;

  line.buf = salloc<char> (line.len, line.buf);

  buf.clear ();

  if (logsync)
    flags |= logSync;

  if (flags & logBacktrace)
    {
      line.buf [line.len - 1] = 0;
      log_backtrace (line.buf);
      line.buf [line.len - 1] = '\n';
    }

  line.flags = flags;

  if (line.flags & logSync)
    log_sync (line);
  else
    {
      SMUTEX_LOCK (mutex);
      queue.push_back (line);
      SMUTEX_UNLOCK (mutex);
      SCOND_SIGNAL (cond);
    }
}

static int suspended;

void
log_suspend ()
{
  if (!suspended++)
    {
      LOG (llevDebug, "logging suspended.");
      SMUTEX_LOCK (fdlock);
    }
}

void
log_resume ()
{
  if (!--suspended)
    {
      SMUTEX_UNLOCK (fdlock);
      LOG (llevDebug, "logging resumed.");
    }
}

Revision:	1.31
Committed:	Sat Nov 17 23:40:00 2018 UTC (5 years, 5 months ago) by root
Content type:	text/plain
Branch:	MAIN
CVS Tags:	HEAD
Changes since 1.30:	+1 -0 lines
Log Message:	copyright update 2018
#	Content
1	/*
2	* This file is part of Deliantra, the Roguelike Realtime MMORPG.
3	*
4	* Copyright (©) 2017,2018 Marc Alexander Lehmann / the Deliantra team
5	* Copyright (©) 2005,2006,2007,2008,2009,2010,2011,2012,2013,2014,2015,2016 Marc Alexander Lehmann / Robin Redeker / the Deliantra team
6	*
7	* Deliantra is free software: you can redistribute it and/or modify it under
8	* the terms of the Affero GNU General Public License as published by the
9	* Free Software Foundation, either version 3 of the License, or (at your
10	* option) any later version.
11	*
12	* This program is distributed in the hope that it will be useful,
13	* but WITHOUT ANY WARRANTY; without even the implied warranty of
14	* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
15	* GNU General Public License for more details.
16	*
17	* You should have received a copy of the Affero GNU General Public License
18	* and the GNU General Public License along with this program. If not, see
19	* <http://www.gnu.org/licenses/>.
20	*
21	* The authors can be reached via e-mail to <support@deliantra.net>
22	*/
23
24	#include <cstdarg>
25	#include <cstring>
26
27	#include <vector>
28
29	#include <sys/uio.h>
30	#include <pthread.h>
31
32	#include "global.h"
33	#include "dynbuf.h"
34	#include "util.h"
35
36	struct logline
37	{
38	struct timeval tv;
39	char *buf; // includes PREFIX_LEN garbage bytes
40	int len;
41	int flags;
42	};
43
44	typedef std::vector<logline, slice_allocator<logline> > logvector;
45
46	static SMUTEX(mutex);
47	static SMUTEX(fdlock);
48	static SCOND(cond);
49	static int logfd = STDERR_FILENO;
50	static int logsync = 1;
51	static logvector queue;
52
53	int log_setfd (int fd)
54	{
55	SMUTEX_LOCK (fdlock);
56	int old = logfd;
57	logfd = fd < 0 ? STDERR_FILENO : fd;
58	SMUTEX_UNLOCK (fdlock);
59
60	return old;
61	}
62
63	#define PREFIX_LEN sizeof ("0000-00-00 00:00:00.0000 L+") - 1
64
65	static void
66	log_sync (logline &line)
67	{
68	static const char levelchar [16+1] = "EWIDt???????????";
69	struct tm lt;
70	char pfx [PREFIX_LEN];
71
72	localtime_r (&line.tv.tv_sec, &lt);
73
74	sprintf (pfx, "%04d-%02d-%02d %02d:%02d:%02d.%04d %c",
75	lt.tm_year + 1900,
76	lt.tm_mon + 1,
77	lt.tm_mday,
78	lt.tm_hour,
79	lt.tm_min,
80	lt.tm_sec,
81	(int)(line.tv.tv_usec / 100),
82	levelchar [line.flags & 15]
83	);
84
85	pfx [PREFIX_LEN - 1] = line.flags & logSync ? '=' : ' ';
86
87	struct iovec iov [2];
88
89	iov [0].iov_base = pfx;
90	iov [0].iov_len = PREFIX_LEN;
91
92	char *buf = line.buf;
93
94	if (logsync != 2)
95	SMUTEX_LOCK (fdlock);
96
97	while (char *end = strchr (buf, '\n'))
98	{
99	iov [1].iov_base = buf;
100	iov [1].iov_len = end - buf + 1;
101
102	writev (STDERR_FILENO, iov, 2);
103	if (logfd != STDERR_FILENO)
104	writev (logfd, iov, 2);
105
106	buf = end + 1;
107
108	if (buf == line.buf + line.len)
109	break;
110
111	pfx [PREFIX_LEN - 1] = '+';
112	}
113
114	if (logsync != 2)
115	SMUTEX_UNLOCK (fdlock);
116
117	sfree (line.buf, line.len);
118	}
119
120	static void *
121	logthread_proc (void *arg)
122	{
123	int idx = 0;
124
125	for (;;)
126	{
127	logline line;
128
129	SMUTEX_LOCK (mutex);
130
131	while (queue.empty ())
132	SCOND_WAIT (cond, mutex);
133
134	line = queue [idx++];
135
136	// this algorithm could result in an ever-increasing vector
137	// size if we log faster than we can write, but if that happens
138	// we have bigger problems.
139	if (idx == queue.size ())
140	{
141	if (idx < 32)
142	queue.clear ();
143	else
144	logvector ().swap (queue); // free memory, hopefully
145
146	idx = 0;
147	}
148
149	SMUTEX_UNLOCK (mutex);
150
151	log_sync (line);
152	}
153	}
154
155	void
156	log_cleanup ()
157	{
158	logsync = 1;
159	SMUTEX_UNLOCK (fdlock);
160
161	for (;;)
162	{
163	int done;
164
165	SMUTEX_LOCK (mutex);
166	done = queue.empty ();
167	SMUTEX_UNLOCK (mutex);
168
169	if (done)
170	break;
171
172	usleep (10000);
173	SMUTEX_LOCK (fdlock);
174	SMUTEX_UNLOCK (fdlock);
175	}
176	}
177
178	static void
179	af_child ()
180	{
181	logsync = 2;
182	}
183
184	static struct logthread : thread
185	{
186	logthread ()
187	{
188	pthread_atfork (0, 0, af_child);
189	start (logthread_proc);
190	logsync = 0;
191	}
192	} logthread;
193
194	void
195	LOG (int flags, const_utf8_string format, ...)
196	{
197	int level = flags & 15;
198
199	if (level > settings.debug)
200	return;
201
202	logline line;
203	gettimeofday (&line.tv, 0);
204
205	static dynbuf_text buf;
206
207	va_list ap;
208	va_start (ap, format);
209	buf.vprintf (format, ap);
210	va_end (ap);
211
212	buf << '\n';
213
214	line.buf = buf.linearise ();
215	line.len = buf.size ();
216
217	if (line.buf [line.len - 2] == '\n')
218	--line.len;
219
220	line.buf = salloc<char> (line.len, line.buf);
221
222	buf.clear ();
223
224	if (logsync)
225	flags \|= logSync;
226
227	if (flags & logBacktrace)
228	{
229	line.buf [line.len - 1] = 0;
230	log_backtrace (line.buf);
231	line.buf [line.len - 1] = '\n';
232	}
233
234	line.flags = flags;
235
236	if (line.flags & logSync)
237	log_sync (line);
238	else
239	{
240	SMUTEX_LOCK (mutex);
241	queue.push_back (line);
242	SMUTEX_UNLOCK (mutex);
243	SCOND_SIGNAL (cond);
244	}
245	}
246
247	static int suspended;
248
249	void
250	log_suspend ()
251	{
252	if (!suspended++)
253	{
254	LOG (llevDebug, "logging suspended.");
255	SMUTEX_LOCK (fdlock);
256	}
257	}
258
259	void
260	log_resume ()
261	{
262	if (!--suspended)
263	{
264	SMUTEX_UNLOCK (fdlock);
265	LOG (llevDebug, "logging resumed.");
266	}
267	}
268