Return-Path: X-Original-To: apmail-httpd-dev-archive@www.apache.org Delivered-To: apmail-httpd-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id C07081038E for ; Mon, 18 Nov 2013 15:46:19 +0000 (UTC) Received: (qmail 1248 invoked by uid 500); 18 Nov 2013 15:46:17 -0000 Delivered-To: apmail-httpd-dev-archive@httpd.apache.org Received: (qmail 1178 invoked by uid 500); 18 Nov 2013 15:46:17 -0000 Mailing-List: contact dev-help@httpd.apache.org; run by ezmlm Precedence: bulk Reply-To: dev@httpd.apache.org list-help: list-unsubscribe: List-Post: List-Id: Delivered-To: mailing list dev@httpd.apache.org Received: (qmail 1170 invoked by uid 99); 18 Nov 2013 15:46:16 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 18 Nov 2013 15:46:16 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of trawick@gmail.com designates 209.85.217.182 as permitted sender) Received: from [209.85.217.182] (HELO mail-lb0-f182.google.com) (209.85.217.182) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 18 Nov 2013 15:46:12 +0000 Received: by mail-lb0-f182.google.com with SMTP id u14so1521711lbd.41 for ; Mon, 18 Nov 2013 07:45:50 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=v9/hyCzqiqVIt0nXcct+NTWo8oyQPCAWk1kCyGKXaMQ=; b=IPSPMrHTMiUfP34MeAgn6cwkgEcony99fakGZR3BWtZbYQxA92nioFzckfP9MEaplN CNxatOWRcLkHZX1ROivoYgm2RovR8xCVdZCYP8Y58ISk7SiU6EeXs5L/8gtxlwtBcjxG fgEQJcVAh6XujxrHlOJWdRqwTR6mQ3QxN4XJpj4mp705EvNzoF4jqwAKLxlyEaWZbWbv zbfa3epe5ix1m6EsVXhPHRBinIMJvQFAQhRVJI2GyehmMbYh+bxrxLD4rVKI4jnC5gA4 /yG4nfgKih57mrfEeEKfeSZLyrtPucaYZBLygPgl2DCy6Sh8X712wNP2bMKN9ziDNPUW CANA== MIME-Version: 1.0 X-Received: by 10.152.116.109 with SMTP id jv13mr2273836lab.30.1384789550422; Mon, 18 Nov 2013 07:45:50 -0800 (PST) Received: by 10.114.187.71 with HTTP; Mon, 18 Nov 2013 07:45:50 -0800 (PST) In-Reply-To: <20131108114108.CA84D23888FE@eris.apache.org> References: <20131108114108.CA84D23888FE@eris.apache.org> Date: Mon, 18 Nov 2013 10:45:50 -0500 Message-ID: Subject: Re: svn commit: r1539988 - /httpd/httpd/trunk/server/log.c From: Jeff Trawick To: Apache HTTP Server Development List Content-Type: multipart/alternative; boundary=001a11c3675e3de19d04eb7571df X-Virus-Checked: Checked by ClamAV on apache.org --001a11c3675e3de19d04eb7571df Content-Type: text/plain; charset=ISO-8859-1 On Fri, Nov 8, 2013 at 6:41 AM, wrote: > Author: jkaluza > Date: Fri Nov 8 11:41:08 2013 > New Revision: 1539988 > > URL: http://svn.apache.org/r1539988 > Log: > Do not lose log messages with NULL server_rec when error log provider is > used. > > - set stderr_log to NULL after it is redirected to /dev/null > - use log provider of ap_server_conf in log_error_core when no server_rec > is provided and std_err_log is NULL > I think this is resulting in a crash in my provider when ap_log_error() is called before open-logs (i.e., before my provider has had a chance to set up a destination for logging). This is the original 2.4 expectation regarding NULL server_rec IIUC: NULL is okay until logs are opened, at which point a NULL server_rec is a bug in the caller. But just pass ap_server_conf when you don't have a context-specific server_rec and core httpd will make sure it is always set when logging requires a server_rec. If at all practical, a NULL server_rec prior to setting up a configured provider shouldn't be treated differently than a NULL server_rec prior to setting a configured error log file/piped logger. My provider is getting a call on this path: #1 0x00007ffff1531a7b in elprov_error_log (info=0x7fffffffb340, handle=0x0, errstr=0x7fffffffb390 "AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1. Set the 'ServerName' directive globally to suppress this message\n", len=169) at mod_elprov.c:38 #2 0x000000000046a3f9 in log_error_core (file=0x488f00 "util.c", line=2201, module_index=0, level=65, status=0, s=0x0, c=0x0, r=0x0, pool=0x6b6138, fmt=0x489618 "AH00558: %s: Could not reliably determine the server's fully qualified domain name, using %s. Set the 'ServerName' directive globally to suppress this message", args=0x7fffffffd408) at log.c:1259 #3 0x000000000046a709 in ap_log_perror_ (file=0x488f00 "util.c", line=2201, module_index=0, level=65, status=0, p=0x6b6138, fmt=0x489618 "AH00558: %s: Could not reliably determine the server's fully qualified domain name, using %s. Set the 'ServerName' directive globally to suppress this message") at log.c:1311 #4 0x00000000004335e7 in ap_get_local_host (a=0x6b6138) at util.c:2201 #5 0x000000000042d9f9 in ap_fini_vhost_config (p=0x6b6138, main_s=0x6df320) at vhost.c:565 #6 0x000000000042cac5 in main (argc=2, argv=0x7fffffffe0e8) at main.c:758 Maybe the handle should be checked (!= NULL) to see if there is a provider AND we've passed the critical point in the open-logs hook where the provider becomes usable. The call to the provider's init function in open-logs will abort startup if NULL is returned for the handle, so handle will never be NULL if the provider is initialized. > Modified: > httpd/httpd/trunk/server/log.c > > Modified: httpd/httpd/trunk/server/log.c > URL: > http://svn.apache.org/viewvc/httpd/httpd/trunk/server/log.c?rev=1539988&r1=1539987&r2=1539988&view=diff > > ============================================================================== > --- httpd/httpd/trunk/server/log.c (original) > +++ httpd/httpd/trunk/server/log.c Fri Nov 8 11:41:08 2013 > @@ -437,9 +437,12 @@ int ap_open_logs(apr_pool_t *pconf, apr_ > #define NULL_DEVICE "/dev/null" > #endif > > - if (replace_stderr && freopen(NULL_DEVICE, "w", stderr) == NULL) { > - ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, APLOGNO(00093) > - "unable to replace stderr with %s", NULL_DEVICE); > + if (replace_stderr) { > + if (freopen(NULL_DEVICE, "w", stderr) == NULL) { > + ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, > APLOGNO(00093) > + "unable to replace stderr with %s", NULL_DEVICE); > + } > + stderr_log = NULL; > } > > for (virt = s_main->next; virt; virt = virt->next) { > @@ -1034,6 +1037,8 @@ static void log_error_core(const char *f > const request_rec *rmain = NULL; > core_server_config *sconf = NULL; > ap_errorlog_info info; > + ap_errorlog_provider *errorlog_provider = NULL; > + void *errorlog_provider_handle = NULL; > > /* do we need to log once-per-req or once-per-conn info? */ > int log_conn_info = 0, log_req_info = 0; > @@ -1060,6 +1065,10 @@ static void log_error_core(const char *f > #endif > > logf = stderr_log; > + if (!logf && ap_server_conf && ap_server_conf->errorlog_provider) > { > + errorlog_provider = ap_server_conf->errorlog_provider; > + errorlog_provider_handle = > ap_server_conf->errorlog_provider_handle; > + } > } > else { > int configured_level = r ? ap_get_request_module_loglevel(r, > module_index) : > @@ -1078,6 +1087,9 @@ static void log_error_core(const char *f > logf = s->error_log; > } > > + errorlog_provider = s->errorlog_provider; > + errorlog_provider_handle = s->errorlog_provider_handle; > + > /* the faked server_rec from mod_cgid does not have > s->module_config */ > if (s->module_config) { > sconf = ap_get_core_module_config(s->module_config); > @@ -1106,6 +1118,14 @@ static void log_error_core(const char *f > } > } > > + if (!logf && !errorlog_provider) { > + /* There is no file to send the log message to (or it is > + * redirected to /dev/null and therefore any formating done below > + * would be lost anyway) and there is no log provider available, > so > + * we just return here. */ > + return; > + } > + > info.s = s; > info.c = c; > info.pool = pool; > @@ -1191,7 +1211,7 @@ static void log_error_core(const char *f > continue; > } > > - if (logf || (s->errorlog_provider->flags & > + if (logf || (errorlog_provider->flags & > AP_ERRORLOG_PROVIDER_ADD_EOL_STR)) { > /* Truncate for the terminator (as apr_snprintf does) */ > if (len > MAX_STRING_LEN - sizeof(APR_EOL_STR)) { > @@ -1205,8 +1225,8 @@ static void log_error_core(const char *f > write_logline(errstr, len, logf, level_and_mask); > } > else { > - s->errorlog_provider->writer(&info, > s->errorlog_provider_handle, > - errstr, len); > + errorlog_provider->writer(&info, errorlog_provider_handle, > + errstr, len); > } > > if (done) { > > > -- Born in Roswell... married an alien... http://emptyhammock.com/ --001a11c3675e3de19d04eb7571df Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable
On Fri, Nov 8, 2013 at 6:41 AM, <jkaluza@apache.org= > wrote:
Author: jkaluza
Date: Fri Nov =A08 11:41:08 2013
New Revision: 1539988

URL: http://sv= n.apache.org/r1539988
Log:
Do not lose log messages with NULL server_rec when error log provider is us= ed.

- set stderr_log to NULL after it is redirected to /dev/null
- use log provider of ap_server_conf in log_error_core when no server_rec =A0 is provided and std_err_log is NULL

I think this is resulting in a crash in my provider when ap_log_error() is= called before open-logs (i.e., before my provider has had a chance to set = up a destination for logging).

This is the original 2.4 expectation regarding NULL ser= ver_rec IIUC: NULL is okay until logs are opened, at which point a NULL ser= ver_rec is a bug in the caller. =A0But just pass ap_server_conf when you do= n't have a context-specific server_rec and core httpd will make sure it= is always set when logging requires a server_rec.

If at all practical, a NULL server_rec prior to setting= up a configured provider shouldn't be treated differently than a NULL = server_rec prior to setting a configured error log file/piped logger.

My provider is getting a call on this path:
<= br>
#1 =A00x00007ffff1531a7b in elprov_error_log (info=3D0x7= fffffffb340, handle=3D0x0,=A0
=A0 =A0 errstr=3D0x7fffffffb390 &qu= ot;AH00558: httpd: Could not reliably determine the server's fully qual= ified domain name, using 127.0.1.1. Set the 'ServerName' directive = globally to suppress this message\n",=A0
=A0 =A0 len=3D169) at mod_elprov.c:38
#2 =A00x000000000046a3= f9 in log_error_core (file=3D0x488f00 "util.c", line=3D2201, modu= le_index=3D0,=A0
=A0 =A0 level=3D65, status=3D0, s=3D0x0, c=3D0x0= , r=3D0x0, pool=3D0x6b6138,=A0
=A0 =A0 fmt=3D0x489618 "AH00558: %s: Could not reliably determine= the server's fully qualified domain name, using %s. Set the 'Serve= rName' directive globally to suppress this message", args=3D0x7fff= ffffd408)
=A0 =A0 at log.c:1259
#3 =A00x000000000046a709 in ap_log_per= ror_ (file=3D0x488f00 "util.c", line=3D2201, module_index=3D0,=A0=
=A0 =A0 level=3D65, status=3D0, p=3D0x6b6138,=A0
=A0 = =A0 fmt=3D0x489618 "AH00558: %s: Could not reliably determine the serv= er's fully qualified domain name, using %s. Set the 'ServerName'= ; directive globally to suppress this message") at log.c:1311
#4 =A00x00000000004335e7 in ap_get_local_host (a=3D0x6b6138) at util.c= :2201
#5 =A00x000000000042d9f9 in ap_fini_vhost_config (p=3D0x6b6= 138, main_s=3D0x6df320) at vhost.c:565
#6 =A00x000000000042cac5 i= n main (argc=3D2, argv=3D0x7fffffffe0e8) at main.c:758

Maybe the handle should be checked (!=3D NULL) to= see if there is a provider AND we've passed the critical point in the = open-logs hook where the provider becomes usable. =A0The call to the provid= er's init function in open-logs will abort startup if NULL is returned = for the handle, so handle will never be NULL if the provider is initialized= .


Modified:
=A0 =A0 httpd/httpd/trunk/server/log.c

Modified: httpd/httpd/trunk/server/log.c
URL: http://svn.apache.org/viewvc/httpd/httpd/trunk/server/log.c?rev=3D= 1539988&r1=3D1539987&r2=3D1539988&view=3Ddiff
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D
--- httpd/httpd/trunk/server/log.c (original)
+++ httpd/httpd/trunk/server/log.c Fri Nov =A08 11:41:08 2013
@@ -437,9 +437,12 @@ int ap_open_logs(apr_pool_t *pconf, apr_
=A0#define NULL_DEVICE "/dev/null"
=A0#endif

- =A0 =A0if (replace_stderr && freopen(NULL_DEVICE, "w", = stderr) =3D=3D NULL) {
- =A0 =A0 =A0 =A0ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main, APLOGN= O(00093)
- =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 "unable to replace stderr wi= th %s", NULL_DEVICE);
+ =A0 =A0if (replace_stderr) {
+ =A0 =A0 =A0 =A0if (freopen(NULL_DEVICE, "w", stderr) =3D=3D NUL= L) {
+ =A0 =A0 =A0 =A0 =A0 =A0ap_log_error(APLOG_MARK, APLOG_CRIT, errno, s_main= , APLOGNO(00093)
+ =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0"unable to replace st= derr with %s", NULL_DEVICE);
+ =A0 =A0 =A0 =A0}
+ =A0 =A0 =A0 =A0stderr_log =3D NULL;
=A0 =A0 =A0}

=A0 =A0 =A0for (virt =3D s_main->next; virt; virt =3D virt->next) { @@ -1034,6 +1037,8 @@ static void log_error_core(const char *f
=A0 =A0 =A0const request_rec *rmain =3D NULL;
=A0 =A0 =A0core_server_config *sconf =3D NULL;
=A0 =A0 =A0ap_errorlog_info info;
+ =A0 =A0ap_errorlog_provider *errorlog_provider =3D NULL;
+ =A0 =A0void *errorlog_provider_handle =3D NULL;

=A0 =A0 =A0/* do we need to log once-per-req or once-per-conn info? */
=A0 =A0 =A0int log_conn_info =3D 0, log_req_info =3D 0;
@@ -1060,6 +1065,10 @@ static void log_error_core(const char *f
=A0#endif

=A0 =A0 =A0 =A0 =A0logf =3D stderr_log;
+ =A0 =A0 =A0 =A0if (!logf && ap_server_conf && ap_server_c= onf->errorlog_provider) {
+ =A0 =A0 =A0 =A0 =A0 =A0errorlog_provider =3D ap_server_conf->errorlog_= provider;
+ =A0 =A0 =A0 =A0 =A0 =A0errorlog_provider_handle =3D ap_server_conf->er= rorlog_provider_handle;
+ =A0 =A0 =A0 =A0}
=A0 =A0 =A0}
=A0 =A0 =A0else {
=A0 =A0 =A0 =A0 =A0int configured_level =3D r ? ap_get_request_module_logle= vel(r, module_index) =A0 =A0 =A0 =A0:
@@ -1078,6 +1087,9 @@ static void log_error_core(const char *f
=A0 =A0 =A0 =A0 =A0 =A0 =A0logf =3D s->error_log;
=A0 =A0 =A0 =A0 =A0}

+ =A0 =A0 =A0 =A0errorlog_provider =3D s->errorlog_provider;
+ =A0 =A0 =A0 =A0errorlog_provider_handle =3D s->errorlog_provider_handl= e;
+
=A0 =A0 =A0 =A0 =A0/* the faked server_rec from mod_cgid does not have s-&g= t;module_config */
=A0 =A0 =A0 =A0 =A0if (s->module_config) {
=A0 =A0 =A0 =A0 =A0 =A0 =A0sconf =3D ap_get_core_module_config(s->module= _config);
@@ -1106,6 +1118,14 @@ static void log_error_core(const char *f
=A0 =A0 =A0 =A0 =A0}
=A0 =A0 =A0}

+ =A0 =A0if (!logf && !errorlog_provider) {
+ =A0 =A0 =A0 =A0/* There is no file to send the log message to (or it is + =A0 =A0 =A0 =A0 * redirected to /dev/null and therefore any formating don= e below
+ =A0 =A0 =A0 =A0 * would be lost anyway) and there is no log provider avai= lable, so
+ =A0 =A0 =A0 =A0 * we just return here. */
+ =A0 =A0 =A0 =A0return;
+ =A0 =A0}
+
=A0 =A0 =A0info.s =A0 =A0 =A0 =A0 =A0 =A0 =3D s;
=A0 =A0 =A0info.c =A0 =A0 =A0 =A0 =A0 =A0 =3D c;
=A0 =A0 =A0info.pool =A0 =A0 =A0 =A0 =A0=3D pool;
@@ -1191,7 +1211,7 @@ static void log_error_core(const char *f
=A0 =A0 =A0 =A0 =A0 =A0 =A0continue;
=A0 =A0 =A0 =A0 =A0}

- =A0 =A0 =A0 =A0if (logf || (s->errorlog_provider->flags &
+ =A0 =A0 =A0 =A0if (logf || (errorlog_provider->flags &
=A0 =A0 =A0 =A0 =A0 =A0 =A0AP_ERRORLOG_PROVIDER_ADD_EOL_STR)) {
=A0 =A0 =A0 =A0 =A0 =A0 =A0/* Truncate for the terminator (as apr_snprintf = does) */
=A0 =A0 =A0 =A0 =A0 =A0 =A0if (len > MAX_STRING_LEN - sizeof(APR_EOL_STR= )) {
@@ -1205,8 +1225,8 @@ static void log_error_core(const char *f
=A0 =A0 =A0 =A0 =A0 =A0 =A0write_logline(errstr, len, logf, level_and_mask)= ;
=A0 =A0 =A0 =A0 =A0}
=A0 =A0 =A0 =A0 =A0else {
- =A0 =A0 =A0 =A0 =A0 =A0s->errorlog_provider->writer(&info, s-&g= t;errorlog_provider_handle,
- =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 errstr, len);
+ =A0 =A0 =A0 =A0 =A0 =A0errorlog_provider->writer(&info, errorlog_p= rovider_handle,
+ =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0errstr, len);
=A0 =A0 =A0 =A0 =A0}

=A0 =A0 =A0 =A0 =A0if (done) {





--
Born in Rosw= ell... married an alien...
http://emptyhammock.com/
--001a11c3675e3de19d04eb7571df--