From c46c8ac083b851d35137ae455eef0c8622dc07c7 Mon Sep 17 00:00:00 2001
From: Christopher Powell
Date: Tue, 2 Apr 2002 20:19:30 +0000
Subject: This is a "pre" snapshot of 1.15. Numerous changes emphasizing how
SQL errors are reported and handled. Any missed queries during SQL downtime
are written out to a textfile.
---
CHANGELOG | 17 ++++-
INSTALL | 4 +-
mod_log_sql.c | 195 +++++++++++++++++++++++++++++++++++++++++-----------------
3 files changed, 155 insertions(+), 61 deletions(-)
diff --git a/CHANGELOG b/CHANGELOG
index b0da0a2..34aed54 100644
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -1,14 +1,27 @@
-$Id: CHANGELOG,v 1.6 2002/02/24 20:17:16 helios Exp $
+$Id: CHANGELOG,v 1.7 2002/04/02 20:19:30 helios Exp $
TODO:
* Full commenting of the code.
* Rethink documentation flow and rewrite?
-* Message queueing during server downtime?
+* Config directives for proxy clients
+* Port connection portion to other DBMS? Genericize the module?
CHANGES:
+1.15:
+* Vastly improved error reporting is a lot clearer about lost db
+ connections, etc. Some unreachable code has been corrected.
+* The way that query-retries and openlink-retries are handled has
+ been tweaked and improved.
+* Missed database entries are now preserved for later inclusion. This
+ file is not held open but is closed after each use, so it's safe
+ to delete while Apache is running.
+* Now each child instantiates its MySQL link upon birth rather than
+ waiting for its first request.
+
+
1.14:
* Improved the apxs instructions based on user feedback, including the
mysql.sock define issue.
diff --git a/INSTALL b/INSTALL
index 0391e88..3226e89 100644
--- a/INSTALL
+++ b/INSTALL
@@ -1,4 +1,4 @@
-$Id: INSTALL,v 1.5 2002/02/24 20:17:16 helios Exp $
+$Id: INSTALL,v 1.6 2002/04/02 20:19:30 helios Exp $
Requirements
@@ -126,7 +126,7 @@ Installation (as a static module compiled into httpd)
6a) Edit Configuration.apaci as follows...
* Append the following string to the EXTRA_LIBS= line. (/usr/lib/mysql is where your libmysqlclient.a file lives):
- -L/usr/lib/mysql -lmysqlclient -lm
+ -L/usr/lib/mysql -lmysqlclient -lm -lz
* Add this line at the end of the file:
Module mysql_log_module mod_log_mysql.o
diff --git a/mod_log_sql.c b/mod_log_sql.c
index 6780b74..61c1ed9 100644
--- a/mod_log_sql.c
+++ b/mod_log_sql.c
@@ -1,10 +1,13 @@
-/* $Id: mod_log_sql.c,v 1.5 2002/01/15 18:40:14 helios Exp $ */
+/* $Id: mod_log_sql.c,v 1.6 2002/04/02 20:19:30 helios Exp $ */
/* DEFINES */
#define MYSQL_ERROR(mysql) ((mysql)?(mysql_error(mysql)):"MySQL server has gone away")
#define ERRLEVEL APLOG_ERR|APLOG_NOERRNO
+#define WARNINGLEVEL APLOG_WARNING|APLOG_NOERRNO
+#define NOTICELEVEL APLOG_NOTICE|APLOG_NOERRNO
#define DEBUGLEVEL APLOG_INFO|APLOG_NOERRNO
+#define PRESERVEFILE "/tmp/mysql-preserve"
/* (MYSQLSOCKET, DEBUG and WANT_SSL_LOGGING are defined in the Makefile DEFS line.) */
@@ -463,15 +466,35 @@ const char *mysql_escape_log(const char *str, pool *p)
}
}
-void open_logdb_link()
+int open_logdb_link()
{
- if (mysql_log != NULL) { /* virtual database link shared with main server */
- return;
+ if (mysql_log != NULL) {
+ return 2;
}
- if (db_name) { /* open an SQL link */
+
+ if (db_name) {
mysql_init(&sql_server);
mysql_log = mysql_real_connect(&sql_server, db_host, db_user, db_pwd, db_name, 0, MYSQLSOCKET, 0);
+
+ if (mysql_log != NULL) {
+ return 1;
+ } else {
+ return 0;
+ }
}
+ return 0;
+}
+
+void preserve_entry(request_rec *r, const char *query)
+{
+ FILE *fp;
+
+ fp = fopen(PRESERVEFILE, "a");
+ if (fp == NULL)
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: attempted append of local offline file but failed.");
+ else
+ fprintf(fp,"%s\n", query);
+ fclose(fp);
}
int safe_mysql_query(request_rec *r, const char *query)
@@ -481,57 +504,61 @@ int safe_mysql_query(request_rec *r, const char *query)
int ret;
char *str;
void (*handler) (int);
+
/* A failed mysql_query() may send a SIGPIPE, so we ignore that signal momentarily. */
handler = signal(SIGPIPE, SIG_IGN);
- /* If there's no DB link, or if we run the query and it gacks, try to be graceful */
- if ( !mysql_log ||
- (
- (retval = mysql_query(mysql_log, query)) &&
- (mysql_errno(mysql_log) != 0)
- )
- )
-
- { /* We need to restart the server link */
- mysql_log = NULL;
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: connection lost, attempting reconnect");
+ /* First attempt for the query */
+ retval = mysql_query(mysql_log, query);
+
+ /* If we ran the query and it returned an error, try to be graceful.
+ * We only reach this point if the module thinks it has a valid connection to the
+ * database (i.e. mysql_log is non-null). But that connection could go sour
+ * at any time, hence the check. */
+ if ( retval != 0 )
+ {
+ /* Something went wrong, so start by trying to restart the db link. */
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: attempting reconnect because API said: %s", MYSQL_ERROR(mysql_log));
+ mysql_log = NULL;
open_logdb_link();
if (mysql_log == NULL) { /* still unable to link */
signal(SIGPIPE, handler);
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: reconnect failed");
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: httpd child reconnect failed, unable to reach database. SQL logging stopped until an httpd child regains a db connection.");
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: log entries are being preserved in %s",PRESERVEFILE);
return retval;
- }
+ } else {
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: reconnect successful.");
+ }
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: reconnect successful");
- retval = mysql_query(mysql_log, query);
+ /* Attempt a single re-try... First sleep for a tiny amount of time. */
+ delay.tv_sec = 0;
+ delay.tv_nsec = 500000000; /* max is 999999999 (nine nines) */
+ ret = nanosleep(&delay, &remainder);
+ if (ret && errno != EINTR)
+ perror("nanosleep");
+
+ /* Now make our second attempt */
+ retval = mysql_query(mysql_log,query);
+
+ /* If this one also failed, log that and append to our local offline file */
+ if ( retval != 0 )
+ {
+ str = pstrcat(r->pool, "MySQL delayed insert attempt failed, API said: ", MYSQL_ERROR(mysql_log), NULL);
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,str);
+
+ preserve_entry(r, query);
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: entry preserved in %s",PRESERVEFILE);
+ } else {
+ ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: insert successful after a delayed retry.");
+ }
}
/* Restore SIGPIPE to its original handler function */
signal(SIGPIPE, handler);
-
- if (retval) {
- /* Attempt a single re-try... First sleep for a tiny amount of time. */
- delay.tv_sec = 0;
- delay.tv_nsec = 500000000; /* max is 999999999 (nine nines) */
- ret = nanosleep(&delay, &remainder);
- if (ret && errno != EINTR)
- perror("nanosleep");
-
- /* Now re-attempt */
- retval = mysql_query(mysql_log,query);
-
- if (retval) {
- str = pstrcat(r->pool, "MySQL insert failed: ", query, NULL);
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,str);
- str = pstrcat(r->pool, "MySQL failure reason: ", MYSQL_ERROR(mysql_log), NULL);
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,str);
- } else {
- ap_log_error(APLOG_MARK,ERRLEVEL,r->server,"MySQL: insert successful after a delayed retry.");
- }
- }
+
return retval;
}
@@ -657,7 +684,7 @@ void *log_mysql_make_state(pool *p, server_rec *s)
/* Setup of the available httpd.conf configuration commands.
- * command, function called, NULL, where available, how many arguments, verbose description
+ * Structure: command, function called, NULL, where available, how many arguments, verbose description
*/
command_rec log_mysql_cmds[] = {
{"MySQLRefererLogTable", set_referer_log_mysql_table, NULL, RSRC_CONF, TAKE1,
@@ -708,7 +735,8 @@ int log_mysql_transaction(request_rec *orig)
request_rec *r;
int retvalue = DECLINED;
int referer_needed, agent_needed, transfer_needed;
-
+
+
/* Are there configuration directives for these SQL logs? For each found
* config directive that is found, mark that type as 'needed'.
*/
@@ -719,13 +747,7 @@ int log_mysql_transaction(request_rec *orig)
if (!referer_needed && !agent_needed && !transfer_needed) {
return OK;
}
-
- if (mysql_log == NULL) { /* mysql link not up, hopefully we can do something about it */
- open_logdb_link();
- if (mysql_log == NULL) {
- return OK;
- }
- }
+
for (r = orig; r->next; r = r->next) {
continue;
@@ -750,7 +772,20 @@ int log_mysql_transaction(request_rec *orig)
}
}
str = pstrcat(orig->pool, "insert into ", cls->referer_table_name, " (referer,url,time_stamp) values ('", mysql_escape_log(referer, orig->pool), "','", mysql_escape_log(r->uri, orig->pool), "',unix_timestamp(now()) )", NULL);
- safe_mysql_query(orig, str);
+
+ if (mysql_log == NULL) { /* child's mysql link not up, re-establish it */
+ open_logdb_link();
+ if (mysql_log == NULL) {
+ preserve_entry(r, str);
+ return OK;
+ } else {
+ ap_log_error(APLOG_MARK,NOTICELEVEL,orig->server,"MySQL: httpd child established database connection");
+ safe_mysql_query(orig, str);
+ }
+ } else {
+ safe_mysql_query(orig, str);
+ }
+
}
}
@@ -763,7 +798,19 @@ int log_mysql_transaction(request_rec *orig)
if (agent != NULL) {
str = pstrcat(orig->pool, "insert into ", cls->agent_table_name, "(agent,time_stamp) values ('", mysql_escape_log(agent, orig->pool), "',unix_timestamp(now()) )", NULL);
- safe_mysql_query(orig, str);
+
+ if (mysql_log == NULL) { /* child's mysql link not up, re-establish it */
+ open_logdb_link();
+ if (mysql_log == NULL) {
+ preserve_entry(r, str);
+ return OK;
+ } else {
+ ap_log_error(APLOG_MARK,NOTICELEVEL,orig->server,"MySQL: httpd child established database connection");
+ safe_mysql_query(orig, str);
+ }
+ } else {
+ safe_mysql_query(orig, str);
+ }
}
}
@@ -771,7 +818,7 @@ int log_mysql_transaction(request_rec *orig)
if (transfer_needed) {
const char *thehost;
- char *fields = "", *values = "", *query;
+ char *fields = "", *values = "";
const char *formatted_item;
int i, j, length;
@@ -840,8 +887,29 @@ int log_mysql_transaction(request_rec *orig)
}
/* Set up the actual INSERT statement and execute it. */
- query = pstrcat(orig->pool, "insert into ", cls->transfer_table_name, " (", fields, ") values (", values, ")", NULL);
- safe_mysql_query(orig, query);
+ str = pstrcat(orig->pool, "insert into ", cls->transfer_table_name, " (", fields, ") values (", values, ")", NULL);
+
+
+ /* How's our mysql link integrity? */
+ if (mysql_log == NULL) {
+
+ /* Try to regain the link */
+ open_logdb_link();
+
+ if (mysql_log == NULL) {
+ /* Unable to re-establish a DB link, so assume that it's really
+ * gone and send the entry to the preserve file instead. */
+ preserve_entry(r, str);
+ return OK;
+ } else {
+ /* Whew, we got the DB link back */
+ ap_log_error(APLOG_MARK,NOTICELEVEL,orig->server,"MySQL: httpd child established database connection");
+ safe_mysql_query(orig, str);
+ }
+ } else {
+ /* Everything was fine */
+ safe_mysql_query(orig, str);
+ }
}
return retvalue;
@@ -851,7 +919,20 @@ int log_mysql_transaction(request_rec *orig)
/* Called on the exit of an httpd child process */
static void log_mysql_child_exit(server_rec *s, pool *p)
{
- mysql_close(mysql_log);
+ mysql_close(mysql_log);
+}
+
+/* Called on the init of an httpd child process */
+static void log_mysql_child_init(server_rec *s, pool *p)
+{
+ int retval;
+
+ retval = open_logdb_link();
+ #ifdef DEBUG
+ if (retval > 0) {
+ ap_log_error(APLOG_MARK,DEBUGLEVEL,s,"MySQL: open_logdb_link successful");
+ }
+ #endif
}
@@ -874,7 +955,7 @@ module mysql_log_module = {
log_mysql_transaction, /* logger */
NULL, /* header parser */
#if MODULE_MAGIC_NUMBER >= 19970728 /* 1.3-dev or later support these additionals... */
- NULL, /* child_init */
+ log_mysql_child_init, /* child_init */
log_mysql_child_exit, /* process exit/cleanup */
NULL /* [#0] post read-request */
#endif
--
cgit