Skip to content

fix fpm log prefix message with wrong stdout/stderr notation #4476

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 1 commit into from

Conversation

sadapon2008
Copy link
Contributor

@sadapon2008 sadapon2008 commented Jul 25, 2019

This pr fixes https://bugs.php.net/bug.php?id=78334
The following code outputs messages to either stdout or stderr.

<?php
file_put_contents('php://stdout', "msg 1 - ");
usleep(1);
file_put_contents('php://stderr', "msg 2 - ");
usleep(1);
file_put_contents('php://stderr', "msg 3");

Expected results:

LOG LINE: [25-Jul-2019 23:34:52] WARNING: [pool unconfined] child 87539 said into stdout: "msg 1 - "
LOG LINE: [25-Jul-2019 23:34:52] WARNING: [pool unconfined] child 87539 said into stderr: "msg 2 - msg 3"

Actual results:

LOG LINE: [25-Jul-2019 23:34:52] WARNING: [pool unconfined] child 87539 said into stdout: "msg 1 - msg 2 - msg 3"

This is caused by the reuse of log stream introduced by #3471

@cmb69
Copy link
Member

cmb69 commented Jul 26, 2019

@bukka, could you please review?

zlog_stream_finish(log_stream);
}
// free stream's msg_prefix for reset
if (log_stream->msg_prefix) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This would be better to handle inside zlog_stream_set_msg_prefix as it won't be necessary to do another allocation ("stdout" and "stderr" have the same length). However to make it generic there should be a check added. Basically something like:

zlog_bool zlog_stream_set_msg_prefix(struct zlog_stream *stream, const char *fmt, ...) /* {{{ */
{
	char buf[MAX_WRAPPING_PREFIX_LENGTH];
	size_t len;
	va_list args;

	if (!stream->decorate) {
		return ZLOG_TRUE;
	}

	va_start(args, fmt);
	len = vsnprintf(buf, MAX_WRAPPING_PREFIX_LENGTH - 1, fmt, args);
	va_end(args);

	if (stream->msg_prefix_len < len) {
		stream->msg_prefix = stream->msg_prefix_len ? realloc(stream->msg_prefix, len + 1) : malloc(len + 1);
		if (stream->msg_prefix == NULL) {
			return ZLOG_FALSE;
		}
	}
	memcpy(stream->msg_prefix, buf, len);
	stream->msg_prefix[len] = 0;
	stream->msg_prefix_len = len;

	return len;
}

@@ -144,12 +144,24 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
zlog_stream_init_ex(log_stream, ZLOG_WARNING, STDERR_FILENO);
zlog_stream_set_decorating(log_stream, child->wp->config->decorate_workers_output);
zlog_stream_set_wrapping(log_stream, ZLOG_TRUE);
zlog_stream_set_msg_prefix(log_stream, "[pool %s] child %d said into %s: ",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be kept and then just added behind the stdout condition (line 152: https://github.com/php/php-src/pull/4476/files#diff-57f24d1c50be851c62c450ad57b13675R152 )

}
// reset stream's msg_prefix
zlog_stream_set_msg_prefix(log_stream, "[pool %s] child %d said into %s: ",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be deleted

zlog_stream_set_msg_prefix(log_stream, "[pool %s] child %d said into %s: ",
child->wp->config->name, (int) child->pid, is_stdout ? "stdout" : "stderr");
// store fd type (stdout/stderr)
log_stream->is_stdout = (unsigned int)is_stdout;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It changes only if they are different. It should be also wrapped in inline function as other flags.

@sadapon2008
Copy link
Contributor Author

@bukka Thank you for your review.
I refactored code.
Please review again.

@bukka
Copy link
Member

bukka commented Aug 18, 2019

@sadapon2008 Sorry for the late review. The code looks good now. If you could squash it and push force it, that would be great! I will test it hopefully next weekend and if all good, I will merge it! Thanks!

@sadapon2008 sadapon2008 force-pushed the fpm-log-prefix-message branch from cbc2ee4 to 33074ba Compare August 21, 2019 12:27
@sadapon2008
Copy link
Contributor Author

@bukka Thank you for your reply.
I have squashed and pushed force.
Please check again.

@bukka
Copy link
Member

bukka commented Aug 26, 2019

Merged as ffcf57f

@bukka bukka closed this Aug 26, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants