r18180 MediaWiki - Code Review archive

Repository:MediaWiki
Revision:< r18179‎ | r18180 | r18181 >
Date:12:11, 5 December 2006
Author:river
Status:old
Tags:
Comment:
should have a simple way to rate-limit log messages
Modified paths:
  • /trunk/loreley/src/include/log.h (modified) (history)
  • /trunk/loreley/src/loreley/backend.cc (modified) (history)
  • /trunk/loreley/src/loreley/log.cc (modified) (history)
  • /trunk/loreley/src/loreley/net.cc (modified) (history)

Diff [purge]

Index: trunk/loreley/src/include/log.h
——@@ -39,16 +39,18 @@
4040 bool open(void);
4141 void close(void);
4242
43 - void debug (format const &f) { _log(ll_debug, str(f)); }
44 - void notice(format const &f) { _log(ll_notice, str(f));}
45 - void warn (format const &f) { _log(ll_warn, str(f)); }
46 - void error (format const &f) { _log(ll_error, str(f)); }
 43+ void debug (format const &f) { log(ll_debug, str(f)); }
 44+ void notice(format const &f) { log(ll_notice, str(f));}
 45+ void warn (format const &f) { log(ll_warn, str(f)); }
 46+ void error (format const &f) { log(ll_error, str(f)); }
4747
48 - void debug (string const &s) { _log(ll_debug, s); }
49 - void notice(string const &s) { _log(ll_notice, s); }
50 - void warn (string const &s) { _log(ll_warn, s); }
51 - void error (string const &s) { _log(ll_error, s); }
 48+ void debug (string const &s) { log(ll_debug, s); }
 49+ void notice(string const &s) { log(ll_notice, s); }
 50+ void warn (string const &s) { log(ll_warn, s); }
 51+ void error (string const &s) { log(ll_error, s); }
5252
 53+ void log(log_level l, string const &);
 54+
5355 private:
5456 bool _syslog;
5557 int _facility;
——@@ -58,12 +60,109 @@
5961 ofstream *_fp;
6062 lockable _lock;
6163
62 - void _log(log_level l, string const &);
6364 void _log_unlocked(log_level l, string const &);
6465 };
6566
6667 extern logger wlog;
6768
 69+/**
 70+ * A class to easily rate-limit certain log messages, so the error log isn't
 71+ * spammed too much.
 72+ *
 73+ * Example usage:
 74+ *
 75+ *\code
 76+ * rate_limited_logger rlog(5, ll_error, "%d + %d = %d")
 77+ * rlog.log(1, 1, 2);
 78+ * rlog.log(2, 2, 4);
 79+ * sleep(5);
 80+ * rlog.log(3, 3, 6);
 81+ * \code
 82+ *
 83+ * Only the first and third messages will be logged.
 84+ */
 85+struct rate_limited_logger {
 86+ /**
 87+ * Construct a new limited logger.
 88+ * \param nsecs Minimum number of seconds between logging instances of
 89+ * this message.
 90+ * \param lev Log level of this message.
 91+ * \param msg Format-string should this message.
 92+ */
 93+ rate_limited_logger(int nsecs, log_level lev, string const &msg)
 94+ : _nsecs(nsecs)
 95+ , _lev(lev)
 96+ , _format(msg)
 97+ , _last(0)
 98+ {}
 99+
 100+ /**
 101+ * Log a message with no arguments. Note that the msg is still a
 102+ * format string and needs appropriate escaping.
 103+ */
 104+ void log(void) {
 105+ if (!again())
 106+ return;
 107+
 108+ wlog.log(_lev, str(_format));
 109+ }
 110+
 111+ /**
 112+ * Log a message with one argument.
 113+ */
 114+ template<typename arg1_type>
 115+ void log(arg1_type const &arg1) {
 116+ if (!again())
 117+ return;
 118+
 119+ format f(_format);
 120+ f % arg1;
 121+ wlog.log(_lev, str(f));
 122+ }
 123+
 124+ /**
 125+ * Log a message with two arguments.
 126+ */
 127+ template<typename arg1_type, typename arg2_type>
 128+ void log(arg1_type const &arg1, arg2_type const &arg2) {
 129+ if (!again())
 130+ return;
 131+
 132+ format f(_format);
 133+ f % arg1 % arg2;
 134+ wlog.log(_lev, str(f));
 135+ }
 136+
 137+ /**
 138+ * Log a message with three arguments.
 139+ */
 140+ template<typename arg1_type, typename arg2_type, typename arg3_type>
 141+ void log(arg1_type const &arg1, arg2_type const &arg2,
 142+ arg3_type const &arg3) {
 143+ if (!again())
 144+ return;
 145+
 146+ format f(_format);
 147+ f % arg1 % arg2 % arg3;
 148+ wlog.log(_lev, str(f));
 149+ }
 150+
 151+private:
 152+ bool again(void) {
 153+ time_t now = time(0);
 154+ if (_last + _nsecs < now) {
 155+ _last = now;
 156+ return true;
 157+ }
 158+ return false;
 159+ }
 160+
 161+ int _nsecs;
 162+ log_level _lev;
 163+ format _format;
 164+ int _last;
 165+};
 166+
68167 #ifndef LORELEY_DEBUG
69168 # define WDEBUG(x) ((void)0)
70169 #else
Index: trunk/loreley/src/loreley/log.cc
——@@ -68,7 +68,7 @@
6969 }
7070
7171 void
72 -logger::_log(log_level sev, string const &e)
 72+logger::log(log_level sev, string const &e)
7373 {
7474 HOLDING(_lock);
7575 _log_unlocked(sev, e);
Index: trunk/loreley/src/loreley/net.cc
——@@ -262,15 +262,13 @@
263263 ioloop_t::_accept(wsocket *s, int)
264264 {
265265 wsocket *newe;
266 -static atomic<time_t> last_nfile = 0;
267 - time_t now = time(NULL);
 266+static rate_limited_logger enfile_log(60, ll_warn, "accept error: %s");
268267
269268 if ((newe = s->accept("HTTP client", prio_norm)) == NULL) {
270 - if ((errno != ENFILE && errno != EMFILE) || (now - last_nfile) > 60) {
271 - if (errno == ENFILE || errno == EMFILE)
272 - last_nfile = now;
 269+ if (errno == ENFILE || errno == EMFILE)
 270+ enfile_log.log(strerror(errno));
 271+ else
273272 wlog.warn(format("accept error: %s") % strerror(errno));
274 - }
275273 s->readback(bind(&ioloop_t::_accept, this, _1, _2), -1);
276274 return;
277275 }
Index: trunk/loreley/src/loreley/backend.cc
——@@ -96,8 +96,6 @@
9797 {
9898 struct backend_cb_data *cbd;
9999 wsocket *s = NULL;
100 -static time_t last_nfile;
101 - time_t now = time(NULL);
102100
103101 /*
104102 * If we're delegating (for failover), pass this request off.
——@@ -129,11 +127,13 @@
130128 "backend connection", prio_backend);
131129 s->nonblocking(true);
132130 } catch (socket_error &e) {
133 - if (e.err() != ENFILE || now - last_nfile > 60)
 131+ static rate_limited_logger enfile_msg(5, ll_warn,
 132+ "opening backend socket: %s");
 133+ if (e.err() == ENFILE || e.err() == EMFILE)
 134+ enfile_msg.log(e.what());
 135+ else
134136 wlog.warn(format("opening backend socket: %s")
135137 % e.what());
136 - if (e.err() == ENFILE)
137 - last_nfile = now;
138138 delete cbd;
139139 delete s;
140140 return -1;