Re: [HACKERS] WIP: Separate log file for extension

2017-09-27 Thread Antonin Houska 
Magnus Hagander  wrote:

> > On Fri, Aug 25, 2017 at 12:12 AM, Antonin Houska  wrote:

> 
> I like this idea in general.
> 
>  Then it's supposed to change some of its attributes
> 
> >  adjust_log_stream_attr(&stream->filename, "my_extension.log");
> 
> This, however, seems to be wrong.
> 
> The logfile name does not belong in the extension, it belongs in the
> configuration file. I think the extension should set it's "stream id" or
> whatever you want to call it, and then it should be possible to control in
> postgresql.conf where that log is sent.

Doesn't the last paragraph of

https://www.postgresql.org/message-id/11412.1503912190%40localhost

address your concerns?

> Also, what if this extension is loaded on demand in a session and not via
> shared_preload_libraries? It looks like the syslogger only gets the list of
> configured streams when it starts?

Yes, the syslogger gets the list of streams only when it starts, so the
extension that wants to use this feature needs to provide the file information
via shared_preload_libraries. I consider it sufficient because various
existing logging-related GUCs also can't be changed on-the-fly.

> In short, I think the solution should be more generic, and not "just for 
> extensions".

o.k. Any idea about dividing the streams into categories? Should they for
example correspond somehow to categories of GUC variables?

> I completely missed this thread when I did my quick-wip at
> https://www.postgresql.org/message-id/flat/cabuevexztl0gorywm9s4tr_ft3fmjbraxqdxj+bqzjpvmru...@mail.gmail.com#cabuevexztl0gorywm9s4tr_ft3fmjbraxqdxj+bqzjpvmru...@mail.gmail.com
> -- some of the changes made were close enough that I got the two confused :)
> Based on the feedback of that one, have you done any performance checks?

I don't expect mere routing of messages into multiple files to bring any
overhead. I'll run some tests, just out of curiosity.

-- 
Antonin Houska
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de, http://www.cybertec.at


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-09-27 Thread Antonin Houska 
Tomas Vondra  wrote:

> On 08/28/2017 11:23 AM, Antonin Houska wrote:
> > Craig Ringer  wrote:
> > 
> >> On 25 August 2017 at 15:12, Antonin Houska  wrote:
> >>
> >> How will this play with syslog? csvlog? etc?
> > 
> > There's nothing special about csvlog: the LogStream structure has a
> > "destination" field, so if particular extension wants this kind of output, 
> > it
> > simply sets the LOG_DESTINATION_CSVLOG bit here.
> > 
> 
> I assume Craig's point was more about CSVLOG requiring log_collector=on.
> So what will happen if the PostgreSQL is started without the collector,
> and an extension attempts to use LOG_DESTINATION_CSVLOG? Or will it
> start a separate collector for each such extension?

The patch does not try to change this behavior. So there'll be no csvlog file
and only the plain (not csv-formatted) message will be written to console.

-- 
Antonin Houska
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de, http://www.cybertec.at


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-09-10 Thread Magnus Hagander 
On Fri, Aug 25, 2017 at 12:12 AM, Antonin Houska  wrote:

> Attached is a draft patch to allow extension to write log messages to a
> separate file. It introduces a concept of a "log stream". The extension's
> shared library gets its stream assigned by calling this function from
> _PG_init()


> my_stream_id = get_log_stream("my_extension", &my_log_stream);
>

I like this idea in general.



> Then it's supposed to change some of its attributes
>
> adjust_log_stream_attr(&stream->filename, "my_extension.log");
>

This, however, seems to be wrong.

The logfile name does not belong in the extension, it belongs in the
configuration file. I think the extension should set it's "stream id" or
whatever you want to call it, and then it should be possible to control in
postgresql.conf where that log is sent.

Also, what if this extension is loaded on demand in a session and not via
shared_preload_libraries? It looks like the syslogger only gets the list of
configured streams when it starts?

In short, I think the solution should be more generic, and not "just for
extensions".

I completely missed this thread when I did my quick-wip at
https://www.postgresql.org/message-id/flat/cabuevexztl0gorywm9s4tr_ft3fmjbraxqdxj+bqzjpvmru...@mail.gmail.com#cabuevexztl0gorywm9s4tr_ft3fmjbraxqdxj+bqzjpvmru...@mail.gmail.com
 -- some of the changes made were close enough that I got the two confused
:) Based on the feedback of that one, have you done any performance checks?


-- 
 Magnus Hagander
 Me: https://www.hagander.net/ 
 Work: https://www.redpill-linpro.com/

Re: [HACKERS] WIP: Separate log file for extension

2017-09-09 Thread Tomas Vondra 


On 08/28/2017 11:23 AM, Antonin Houska wrote:
> Craig Ringer  wrote:
> 
>> On 25 August 2017 at 15:12, Antonin Houska  wrote:
>>
>> How will this play with syslog? csvlog? etc?
> 
> There's nothing special about csvlog: the LogStream structure has a
> "destination" field, so if particular extension wants this kind of output, it
> simply sets the LOG_DESTINATION_CSVLOG bit here.
> 

I assume Craig's point was more about CSVLOG requiring log_collector=on.
So what will happen if the PostgreSQL is started without the collector,
and an extension attempts to use LOG_DESTINATION_CSVLOG? Or will it
start a separate collector for each such extension?

regards

-- 
Tomas Vondra  http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-08-30 Thread Antonin Houska 
Masahiko Sawada  wrote:

> On Fri, Aug 25, 2017 at 4:12 PM, Antonin Houska  wrote:
> > Attached is a draft patch to allow extension to write log messages to a
> > separate file.
> 
> Does it allow postgres core code to write log messages to multiple log
> files as well? I can imagine a use case where we want to write log
> messages to separate log files by error level or purpose (server log
> and SQL log etc).

At low level it should work as long as several log streams are reserved for
the core code. However, as every single stream needs multiple variables, I
have no idea how to configure those additional streams w/o adding many new GUC
variables to the core.

Also the discussion what should (not) be logged separate would probably be
difficult.

Specifically to log SQL statements to a separate file, I think (but not
verified) that you can write an extension that reserves a stream for itself
and also uses emit_log_hook to recognize SQL statements among the logged
messages. If the hook adjusts the syslogger_stream field of ErrorData
accordingly, the message should end up in the separate file.

-- 
Antonin Houska
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de, http://www.cybertec.at


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-08-29 Thread Masahiko Sawada 
On Fri, Aug 25, 2017 at 4:12 PM, Antonin Houska  wrote:
> Attached is a draft patch to allow extension to write log messages to a
> separate file.

Does it allow postgres core code to write log messages to multiple log
files as well? I can imagine a use case where we want to write log
messages to separate log files by error level or purpose (server log
and SQL log etc).

Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-08-28 Thread Antonin Houska 
Craig Ringer  wrote:

> On 25 August 2017 at 15:12, Antonin Houska  wrote:
> 
> How will this play with syslog? csvlog? etc?

There's nothing special about csvlog: the LogStream structure has a
"destination" field, so if particular extension wants this kind of output, it
simply sets the LOG_DESTINATION_CSVLOG bit here.

LOG_DESTINATION_SYSLOG is a problem because (AFAIK) a single process can
maintain no more than one connection to the syslog server. I don't like the
idea of closing the current connection and opening a different one whenever
the next ereport() is associated with a different stream than the previous
was.

As for LOG_DESTINATION_EVENTLOG, I haven't checked yet.

> I wonder if a level of indirection is appropriate here, where extensions (or
> postgres subsystems, even) provide a log stream label. Then the logging
> backed takes care of using that appropriately for the logging mechanism in
> use; for logging to file that'd generally be separate files. Same for
> CSVlog. Other mechanisms could be left as stubs initially.
> 
> So the outcome would be the same, just without the assumption of specific
> file name and output mechanism baked in.

The example I shown in my previous email was the simplest case I could think
of. But it does not mean that the file name has to be hard-coded in the
extension. Instead of setting the LogStream.filename field, you can pass a
pointer to this field to DefineCustomStringVariable() function, so the
specific GUC can control the value.

-- 
Antonin Houska
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de, http://www.cybertec.at


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: [HACKERS] WIP: Separate log file for extension

2017-08-27 Thread Craig Ringer 
On 25 August 2017 at 15:12, Antonin Houska  wrote:

> Attached is a draft patch to allow extension to write log messages to a
> separate file.


I like the idea a lot. I'm not so sure about the approach.

How will this play with syslog? csvlog? etc?

I wonder if a level of indirection is appropriate here, where extensions
(or postgres subsystems, even) provide a log stream label. Then the logging
backed takes care of using that appropriately for the logging mechanism in
use; for logging to file that'd generally be separate files.  Same for
CSVlog. Other mechanisms could be left as stubs initially.

So the outcome would be the same, just without the assumption of specific
file name and output mechanism baked in.

-- 
 Craig Ringer   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

[HACKERS] WIP: Separate log file for extension

2017-08-25 Thread Antonin Houska 
Attached is a draft patch to allow extension to write log messages to a
separate file. It introduces a concept of a "log stream". The extension's
shared library gets its stream assigned by calling this function from
_PG_init()

my_stream_id = get_log_stream("my_extension", &my_log_stream);

Then it's supposed to change some of its attributes

adjust_log_stream_attr(&stream->filename, "my_extension.log");

and to use the stream id in ereport() calls

ereport(LOG, (errmsg("Hello world"), errstream(my_stream_id)));

The EXEC_BACKEND mechanism makes initialization of the log streams by
postmaster child processes non-trivial. I decided to extend
save_backend_variables() and restore_backend_variables() accordingly. Maybe
someone has better idea.

pgaudit seems to be the most obvious use case for this enhancement, but it
might be useful for many other extensions.

-- 
Antonin Houska
Cybertec Schönig & Schönig GmbH
Gröhrmühlgasse 26
A-2700 Wiener Neustadt
Web: http://www.postgresql-support.de, http://www.cybertec.at

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
new file mode 100644
index 95180b2..e9b5684
*** a/src/backend/postmaster/postmaster.c
--- b/src/backend/postmaster/postmaster.c
*** typedef struct
*** 464,469 
--- 464,470 
  
  static pid_t backend_forkexec(Port *port);
  static pid_t internal_forkexec(int argc, char *argv[], Port *port);
+ static Size get_backend_params_size(void);
  
  /* Type for a socket that can be inherited to a client process */
  #ifdef WIN32
*** typedef int InheritableSocket;
*** 482,488 
--- 483,495 
   */
  typedef struct
  {
+ 	/*
+ 	 * read_backend_variables() relies on size to be the first field, followed
+ 	 * by port.
+ 	 */
+ 	Size		size;
  	Port		port;
+ 
  	InheritableSocket portsocket;
  	char		DataDir[MAXPGPATH];
  	pgsocket	ListenSocket[MAXLISTEN];
*** typedef struct
*** 528,533 
--- 535,542 
  	char		my_exec_path[MAXPGPATH];
  	char		pkglib_path[MAXPGPATH];
  	char		ExtraOptions[MAXPGPATH];
+ 	int			nlogstreams;
+ 	char		log_streams[FLEXIBLE_ARRAY_MEMBER];
  } BackendParameters;
  
  static void read_backend_variables(char *id, Port *port);
*** PostmasterMain(int argc, char *argv[])
*** 578,583 
--- 587,593 
  	bool		listen_addr_saved = false;
  	int			i;
  	char	   *output_config_variable = NULL;
+ 	LogStream  *log = &log_streams[0];
  
  	MyProcPid = PostmasterPid = getpid();
  
*** PostmasterMain(int argc, char *argv[])
*** 1273,1279 
  	 * saying so, to provide a breadcrumb trail for users who may not remember
  	 * that their logging is configured to go somewhere else.
  	 */
! 	if (!(Log_destination & LOG_DESTINATION_STDERR))
  		ereport(LOG,
  (errmsg("ending log output to stderr"),
   errhint("Future log output will go to log destination \"%s\".",
--- 1283,1289 
  	 * saying so, to provide a breadcrumb trail for users who may not remember
  	 * that their logging is configured to go somewhere else.
  	 */
! 	if (!(log->destination & LOG_DESTINATION_STDERR))
  		ereport(LOG,
  (errmsg("ending log output to stderr"),
   errhint("Future log output will go to log destination \"%s\".",
*** internal_forkexec(int argc, char *argv[]
*** 4421,4431 
  	static unsigned long tmpBackendFileNum = 0;
  	pid_t		pid;
  	char		tmpfilename[MAXPGPATH];
! 	BackendParameters param;
  	FILE	   *fp;
  
! 	if (!save_backend_variables(¶m, port))
  		return -1;/* log made by save_backend_variables */
  
  	/* Calculate name for temp file */
  	snprintf(tmpfilename, MAXPGPATH, "%s/%s.backend_var.%d.%lu",
--- 4431,4448 
  	static unsigned long tmpBackendFileNum = 0;
  	pid_t		pid;
  	char		tmpfilename[MAXPGPATH];
! 	Size		param_size;
! 	BackendParameters *param;
  	FILE	   *fp;
  
! 	param_size = get_backend_params_size();
! 	param = (BackendParameters *) palloc(param_size);
! 	if (!save_backend_variables(param, port))
! 	{
! 		pfree(param);
  		return -1;/* log made by save_backend_variables */
+ 	}
+ 	Assert(param->size == param_size);
  
  	/* Calculate name for temp file */
  	snprintf(tmpfilename, MAXPGPATH, "%s/%s.backend_var.%d.%lu",
*** internal_forkexec(int argc, char *argv[]
*** 4449,4466 
  	(errcode_for_file_access(),
  	 errmsg("could not create file \"%s\": %m",
  			tmpfilename)));
  			return -1;
  		}
  	}
  
! 	if (fwrite(¶m, sizeof(param), 1, fp) != 1)
  	{
  		ereport(LOG,
  (errcode_for_file_access(),
   errmsg("could not write to file \"%s\": %m", tmpfilename)));
  		FreeFile(fp);
  		return -1;
  	}
  
  	/* Release file */
  	if (FreeFile(fp))
--- 4466,4486 
  	(errcode_for_file_access(),
  	 errmsg("could not create file \"%s\": %m",
  			tmpfilename)));
+ 			pfree(param);
  			return -1;
  		}
  	}
  
! 	if (fwrite(param, param_size, 1, fp) != 1)
  	{
  		ereport(LOG,
  (errcode_for_file_access(),