Re: [Patch] Reliable error logs for trunk
pl = apr_palloc(p, sizeof (*pl)); pl->p = p; +pl->program = (program == NULL) ? NULL : apr_pstrdup(p, program); +pl->pid = NULL; Why is this needed now? Or was this just missed previously and is not really related to the reliable pipe usage of the error log? This was borked. Those fields do not exist in the struct when AP_HAVE_RELIABLE_PIPED_LOGS is not defined. I removed it.
Re: [Patch] Reliable error logs for trunk
On 01/18/2009 04:48 PM, Rainer Jung wrote: > On 18.01.2009 16:37, Ruediger Pluem wrote: >> >>> >>> Step 6: >>> --- >>> >>> open_error_log() calls >>> apr_file_close(s_main->error_log) >> >> The call to apr_file_close happens in ap_open_logs not in open_error_log >> and ap_open_logs is IMHO not called by piped_log_maintenance. > > Yes, sorry, it is ap_open_logs. > > But nevertheless: > > During startup or after restart we go through ap_open_logs() and thus > after startup or restart, the write side of the original pl is closed > and the pipe is written to via the duped FD in stderr. Ahh. Now I got it. So your approach seems fine. Really very confusing :-). > > More precisely ap_open_logs() calls open_error_log(), which returns > ap_piped_log_write_fd(pl) in s->error_log, and after return > ap_open_logs() calls apr_file_close(s_main->error_log) is s==s_main. > > When killing the logger, piped_log_maintenance() gets called. It can now > not simply use pl, because the write side has been closed before in > ap_open_logs(). > > I tried to keep the startup behaviour during restart, so I dup stderr to > the write side in the maintenance function, spawn and close the write > side again. > >>> FD10 gets closed, we only have FD2 and FD9 remaining, >>> ap_piped_log_write_fd(pl) is gone now! >>> >>> So if we want to keep this behaviour, we need to recreate the write side >>> of the pipe from stderr in maintenance before spawning again (in the >>> main error logger case), and close it after spawning. >>> >>> I tried using FD2 directly as the write side without duping it, but that >>> doesn't work. >> >> Hm. F10 should still be open and untouched. > > Just to make sure we are talking about the same. This gets only closed > for the main error logger. For all other error loggers and the access > loggers, there's no such complication. Yes, this clearly was only valid for the main error log. Regards Rüdiger
Re: [Patch] Reliable error logs for trunk
Oups, need to clarify. On 18.01.2009 16:48, Rainer Jung wrote: During startup or after restart we go through ap_open_logs() and thus restart -> restart of httpd after startup or restart, the write side of the original pl is closed and the pipe is written to via the duped FD in stderr. More precisely ap_open_logs() calls open_error_log(), which returns ap_piped_log_write_fd(pl) in s->error_log, and after return ap_open_logs() calls apr_file_close(s_main->error_log) is s==s_main. is -> if When killing the logger, piped_log_maintenance() gets called. It can now not simply use pl, because the write side has been closed before in ap_open_logs(). I tried to keep the startup behaviour during restart, so I dup stderr to restart -> restart of a killed logger the write side in the maintenance function, spawn and close the write side again.
Re: [Patch] Reliable error logs for trunk
On 18.01.2009 16:37, Ruediger Pluem wrote:
On 01/18/2009 03:52 PM, Rainer Jung wrote:
Hi Rüdiger,
first thanks for reviewing.
On 17.01.2009 18:02, Ruediger Pluem wrote:
On 01/16/2009 12:21 AM, Rainer Jung wrote:
This difference goes back to pre 1.3 httpd.
The patch at
http://people.apache.org/~rjung/patches/reliable_error_log.patch
Just some quick comments below
Index: server/log.c
===
--- server/log.c(revision 734457)
+++ server/log.c(working copy)
@@ -953,13 +992,26 @@
ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
"piped log program '%s' failed unexpectedly",
pl->program);
-if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) {
+
+/* If special_stderr is non-zero, we need to get the write
+ * end of the pipe back from stderr before spawning. */
+if ((plw->special_stderr&& (stats =
apr_file_dup(&ap_piped_log_write_fd(pl),
+
stderr_log, pl->p))
+!= APR_SUCCESS) ||
+ ((stats = piped_log_spawn(plw)) != APR_SUCCESS) ||
+/* If special_stderr is non-zero, we need to close the write
+ * end of the pipe after spawning, because we write to it
via
+ * stderr. */
+ (plw->special_stderr&& (stats =
apr_file_close(ap_piped_log_write_fd(pl)))
+!= APR_SUCCESS)) {
I know that this is always a difficult and confusing part, so maybe it
just confused me again,
but why do we need to do the above?
ap_piped_log_write_fd(pl) should have the correct fd already because
in ap_open_logs we just
duplicate the write side of the pipe to stderr and in all other cases
(not main server error log)
ap_piped_log_write_fd is just fine anyways.
It *is* confusing.
Step 1:
---
open_error_log() calls
piped_log_open() calls
apr_file_pipe_create_ex()
We get 2 FDs, say FD9 (read) and FD10 (write).
Step 2:
---
piped_log_open() calls
piped_log_spawn() calls
apr_procattr_child_in_set()
We have 2 additional FDs, say FD11 and FD12, FD11 pointing to the same
end of the pipe as FD9 and FD12 as FD10.
Step 3:
---
piped_log_spawn() calls
apr_proc_create()
This closes FD11.
Step 4:
---
piped_log_spawn() calls
apr_file_close(procnew->in)
This closes FD12.
Now we have a separate process and the parent only has 2 additional FDs,
which can be used to communicate to the external process and to recreate
it.
The next steps do only happen for the main error logger:
Step 5:
---
open_error_log() calls
apr_file_dup2(stderr_log, s_main->error_log, stderr_p)
s_main->error_log contains FD10, so the call lets FD2 (stderr_log) point
to the same pipe as FD10. FD9 and FD10 remain unchanged.
Step 6:
---
open_error_log() calls
apr_file_close(s_main->error_log)
The call to apr_file_close happens in ap_open_logs not in open_error_log
and ap_open_logs is IMHO not called by piped_log_maintenance.
Yes, sorry, it is ap_open_logs.
But nevertheless:
During startup or after restart we go through ap_open_logs() and thus
after startup or restart, the write side of the original pl is closed
and the pipe is written to via the duped FD in stderr.
More precisely ap_open_logs() calls open_error_log(), which returns
ap_piped_log_write_fd(pl) in s->error_log, and after return
ap_open_logs() calls apr_file_close(s_main->error_log) is s==s_main.
When killing the logger, piped_log_maintenance() gets called. It can now
not simply use pl, because the write side has been closed before in
ap_open_logs().
I tried to keep the startup behaviour during restart, so I dup stderr to
the write side in the maintenance function, spawn and close the write
side again.
FD10 gets closed, we only have FD2 and FD9 remaining,
ap_piped_log_write_fd(pl) is gone now!
So if we want to keep this behaviour, we need to recreate the write side
of the pipe from stderr in maintenance before spawning again (in the
main error logger case), and close it after spawning.
I tried using FD2 directly as the write side without duping it, but that
doesn't work.
Hm. F10 should still be open and untouched.
Just to make sure we are talking about the same. This gets only closed
for the main error logger. For all other error loggers and the access
loggers, there's no such complication.
Regards,
Rainer
Re: [Patch] Reliable error logs for trunk
On 01/18/2009 03:52 PM, Rainer Jung wrote:
> Hi Rüdiger,
>
> first thanks for reviewing.
>
> On 17.01.2009 18:02, Ruediger Pluem wrote:
>>
>> On 01/16/2009 12:21 AM, Rainer Jung wrote:
>>
>>> This difference goes back to pre 1.3 httpd.
>>>
>>> The patch at
>>>
>>> http://people.apache.org/~rjung/patches/reliable_error_log.patch
>>
>> Just some quick comments below
>>
>> Index: server/log.c
>> ===
>> --- server/log.c(revision 734457)
>> +++ server/log.c(working copy)
>> @@ -953,13 +992,26 @@
>> ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
>>"piped log program '%s' failed unexpectedly",
>>pl->program);
>> -if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) {
>> +
>> +/* If special_stderr is non-zero, we need to get the write
>> + * end of the pipe back from stderr before spawning. */
>> +if ((plw->special_stderr&& (stats =
>> apr_file_dup(&ap_piped_log_write_fd(pl),
>> +
>> stderr_log, pl->p))
>> +!= APR_SUCCESS) ||
>> + ((stats = piped_log_spawn(plw)) != APR_SUCCESS) ||
>> +/* If special_stderr is non-zero, we need to close the write
>> + * end of the pipe after spawning, because we write to it
>> via
>> + * stderr. */
>> + (plw->special_stderr&& (stats =
>> apr_file_close(ap_piped_log_write_fd(pl)))
>> +!= APR_SUCCESS)) {
>>
>> I know that this is always a difficult and confusing part, so maybe it
>> just confused me again,
>> but why do we need to do the above?
>> ap_piped_log_write_fd(pl) should have the correct fd already because
>> in ap_open_logs we just
>> duplicate the write side of the pipe to stderr and in all other cases
>> (not main server error log)
>> ap_piped_log_write_fd is just fine anyways.
>
> It *is* confusing.
>
> Step 1:
> ---
>
> open_error_log() calls
>piped_log_open() calls
> apr_file_pipe_create_ex()
>
> We get 2 FDs, say FD9 (read) and FD10 (write).
>
> Step 2:
> ---
>
>piped_log_open() calls
> piped_log_spawn() calls
> apr_procattr_child_in_set()
>
>
> We have 2 additional FDs, say FD11 and FD12, FD11 pointing to the same
> end of the pipe as FD9 and FD12 as FD10.
>
> Step 3:
> ---
>
> piped_log_spawn() calls
> apr_proc_create()
>
> This closes FD11.
>
> Step 4:
> ---
>
> piped_log_spawn() calls
> apr_file_close(procnew->in)
>
> This closes FD12.
>
> Now we have a separate process and the parent only has 2 additional FDs,
> which can be used to communicate to the external process and to recreate
> it.
>
> The next steps do only happen for the main error logger:
>
> Step 5:
> ---
>
> open_error_log() calls
>apr_file_dup2(stderr_log, s_main->error_log, stderr_p)
>
> s_main->error_log contains FD10, so the call lets FD2 (stderr_log) point
> to the same pipe as FD10. FD9 and FD10 remain unchanged.
>
> Step 6:
> ---
>
> open_error_log() calls
>apr_file_close(s_main->error_log)
The call to apr_file_close happens in ap_open_logs not in open_error_log
and ap_open_logs is IMHO not called by piped_log_maintenance.
>
> FD10 gets closed, we only have FD2 and FD9 remaining,
> ap_piped_log_write_fd(pl) is gone now!
>
> So if we want to keep this behaviour, we need to recreate the write side
> of the pipe from stderr in maintenance before spawning again (in the
> main error logger case), and close it after spawning.
>
> I tried using FD2 directly as the write side without duping it, but that
> doesn't work.
Hm. F10 should still be open and untouched.
Regards
Rüdiger
Re: [Patch] Reliable error logs for trunk
Hi Rüdiger,
first thanks for reviewing.
On 17.01.2009 18:02, Ruediger Pluem wrote:
On 01/16/2009 12:21 AM, Rainer Jung wrote:
This difference goes back to pre 1.3 httpd.
The patch at
http://people.apache.org/~rjung/patches/reliable_error_log.patch
Just some quick comments below
Index: server/log.c
===
--- server/log.c(revision 734457)
+++ server/log.c(working copy)
@@ -319,20 +333,28 @@
int rc;
if (*s->error_fname == '|') {
-apr_file_t *dummy = NULL;
+piped_log *pl;
+fname = ap_server_root_relative(p, s->error_fname + 1);
+if (!fname) {
+ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL,
+ "%s: Invalid error log path '%s'.",
+ ap_server_argv0, s->error_fname);
+return NULL;
+}
+
/* Spawn a new child logger. If this is the main server_rec,
* the new child must use a dummy stderr since the current
* stderr might be a pipe to the old logger. Otherwise, the
* child inherits the parents stderr. */
-rc = log_child(p, s->error_fname + 1,&dummy, is_main);
-if (rc != APR_SUCCESS) {
-ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL,
- "Couldn't start ErrorLog process");
+pl = piped_log_open(p, fname, is_main);
+if (pl == NULL) {
+ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
+ "%s: Couldn't start ErrorLog process '%s'.",
+ ap_server_argv0, fname);
return DONE;
Why not keeping the old way if
#ifndef AP_HAVE_RELIABLE_PIPED_LOGS?
I still need to investigate, what actually happens in the non-reliable
case. But yes, for lowest risk, we could keep calling log_child() in
that case, until we understand it better. On the long term I have a
preference to keep access and error logging in both cases consistent.
}
-
-s->error_log = dummy;
+s->error_log = ap_piped_log_write_fd(pl);
}
#ifdef HAVE_SYSLOG
@@ -953,13 +992,26 @@
ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
"piped log program '%s' failed unexpectedly",
pl->program);
-if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) {
+
+/* If special_stderr is non-zero, we need to get the write
+ * end of the pipe back from stderr before spawning. */
+if ((plw->special_stderr&& (stats =
apr_file_dup(&ap_piped_log_write_fd(pl),
+ stderr_log,
pl->p))
+!= APR_SUCCESS) ||
+ ((stats = piped_log_spawn(plw)) != APR_SUCCESS) ||
+/* If special_stderr is non-zero, we need to close the write
+ * end of the pipe after spawning, because we write to it via
+ * stderr. */
+ (plw->special_stderr&& (stats =
apr_file_close(ap_piped_log_write_fd(pl)))
+!= APR_SUCCESS)) {
I know that this is always a difficult and confusing part, so maybe it just
confused me again,
but why do we need to do the above?
ap_piped_log_write_fd(pl) should have the correct fd already because in
ap_open_logs we just
duplicate the write side of the pipe to stderr and in all other cases (not main
server error log)
ap_piped_log_write_fd is just fine anyways.
It *is* confusing.
Step 1:
---
open_error_log() calls
piped_log_open() calls
apr_file_pipe_create_ex()
We get 2 FDs, say FD9 (read) and FD10 (write).
Step 2:
---
piped_log_open() calls
piped_log_spawn() calls
apr_procattr_child_in_set()
We have 2 additional FDs, say FD11 and FD12, FD11 pointing to the same
end of the pipe as FD9 and FD12 as FD10.
Step 3:
---
piped_log_spawn() calls
apr_proc_create()
This closes FD11.
Step 4:
---
piped_log_spawn() calls
apr_file_close(procnew->in)
This closes FD12.
Now we have a separate process and the parent only has 2 additional FDs,
which can be used to communicate to the external process and to recreate it.
The next steps do only happen for the main error logger:
Step 5:
---
open_error_log() calls
apr_file_dup2(stderr_log, s_main->error_log, stderr_p)
s_main->error_log contains FD10, so the call lets FD2 (stderr_log) point
to the same pipe as FD10. FD9 and FD10 remain unchanged.
Step 6:
---
open_error_log() calls
apr_file_close(s_main->error_log)
FD10 gets closed, we only have FD2 and FD9 remaining,
ap_piped_log_write_fd(pl) is gone now!
So if we want to keep this behaviour, we need to recreate the write side
of the pipe from stderr in maintenance before spawning again (in the
main error logger case), and close it after spawning.
I tried using FD2 directly as the write side without du
Re: [Patch] Reliable error logs for trunk
On 01/16/2009 12:21 AM, Rainer Jung wrote:
>
> This difference goes back to pre 1.3 httpd.
>
> The patch at
>
> http://people.apache.org/~rjung/patches/reliable_error_log.patch
Just some quick comments below
Index: server/log.c
===
--- server/log.c(revision 734457)
+++ server/log.c(working copy)
@@ -319,20 +333,28 @@
int rc;
if (*s->error_fname == '|') {
-apr_file_t *dummy = NULL;
+piped_log *pl;
+fname = ap_server_root_relative(p, s->error_fname + 1);
+if (!fname) {
+ap_log_error(APLOG_MARK, APLOG_STARTUP, APR_EBADPATH, NULL,
+ "%s: Invalid error log path '%s'.",
+ ap_server_argv0, s->error_fname);
+return NULL;
+}
+
/* Spawn a new child logger. If this is the main server_rec,
* the new child must use a dummy stderr since the current
* stderr might be a pipe to the old logger. Otherwise, the
* child inherits the parents stderr. */
-rc = log_child(p, s->error_fname + 1, &dummy, is_main);
-if (rc != APR_SUCCESS) {
-ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL,
- "Couldn't start ErrorLog process");
+pl = piped_log_open(p, fname, is_main);
+if (pl == NULL) {
+ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
+ "%s: Couldn't start ErrorLog process '%s'.",
+ ap_server_argv0, fname);
return DONE;
Why not keeping the old way if
#ifndef AP_HAVE_RELIABLE_PIPED_LOGS?
}
-
-s->error_log = dummy;
+s->error_log = ap_piped_log_write_fd(pl);
}
#ifdef HAVE_SYSLOG
@@ -953,13 +992,26 @@
ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
"piped log program '%s' failed unexpectedly",
pl->program);
-if ((stats = piped_log_spawn(pl)) != APR_SUCCESS) {
+
+/* If special_stderr is non-zero, we need to get the write
+ * end of the pipe back from stderr before spawning. */
+if ((plw->special_stderr && (stats =
apr_file_dup(&ap_piped_log_write_fd(pl),
+ stderr_log,
pl->p))
+!= APR_SUCCESS) ||
+ ((stats = piped_log_spawn(plw)) != APR_SUCCESS) ||
+/* If special_stderr is non-zero, we need to close the write
+ * end of the pipe after spawning, because we write to it via
+ * stderr. */
+ (plw->special_stderr && (stats =
apr_file_close(ap_piped_log_write_fd(pl)))
+!= APR_SUCCESS)) {
I know that this is always a difficult and confusing part, so maybe it just
confused me again,
but why do we need to do the above?
ap_piped_log_write_fd(pl) should have the correct fd already because in
ap_open_logs we just
duplicate the write side of the pipe to stderr and in all other cases (not main
server error log)
ap_piped_log_write_fd is just fine anyways.
+
+char buf[120];
+
/* what can we do? This could be the error log we're having
* problems opening up... */
-char buf[120];
ap_log_error(APLOG_MARK, APLOG_STARTUP, 0, NULL,
"piped_log_maintenance: unable to respawn '%s':
%s",
- pl->program, apr_strerror(stats, buf,
sizeof(buf)));
+ pl->program, apr_strerror(stats, buf, sizeof(buf)));
}
}
break;
@@ -1037,21 +1094,25 @@
return APR_SUCCESS;
}
-AP_DECLARE(piped_log *) ap_open_piped_log(apr_pool_t *p, const char *program)
+static piped_log* piped_log_open(apr_pool_t *p, const char *program,
+ int special_stderr)
{
piped_log *pl;
apr_file_t *dummy = NULL;
int rc;
-rc = log_child(p, program, &dummy, 0);
+rc = log_child(p, program, &dummy, special_stderr);
if (rc != APR_SUCCESS) {
ap_log_error(APLOG_MARK, APLOG_STARTUP, rc, NULL,
- "Couldn't start piped log process");
+ "Couldn't start piped log process for %s",
+ program == NULL ? "'NULL'" : "'" program "'");
return NULL;
}
pl = apr_palloc(p, sizeof (*pl));
pl->p = p;
+pl->program = (program == NULL) ? NULL : apr_pstrdup(p, program);
+pl->pid = NULL;
Why is this needed now? Or was this just missed previously and is not really
related to the reliable pipe usage of the error log?
ap_piped_log_read_fd(pl) = NULL;
ap_piped_log_write_fd(pl) = dummy;
apr_pool_cleanup_register(p, pl, piped_log_cleanup, piped_log_cleanup);
>
> should fix this. I tested it with access and error logs, with the main
> server and virtual hosts and with rest
