Re: BUG #7814: Rotation of the log is not carried out.

tsunezumi(at)efficlabo(dot)com wrote:

> Rotation of the log is not carried out.
>
> "log_rotation_size" is not effective.

We need more details.

http://wiki.postgresql.org/wiki/Guide_to_reporting_problems

-Kevin

I installed ordinarily.
I did not correct postgresql.conf.

Installation Directory
C:\PostgreSQL\9.2

Data Directory
C:\PostgreSQL\9.2\data

locale
C

I do not have this problem on PostgreSQL 9.1.7.

On Thu, 17 Jan 2013 16:57:53 -0500
"Kevin Grittner" <kgrittn(at)mail(dot)com> wrote:

> tsunezumi(at)efficlabo(dot)com wrote:
>
> > Rotation of the log is not carried out.
> >
> > "log_rotation_size" is not effective.
>
> We need more details.
>
> http://wiki.postgresql.org/wiki/Guide_to_reporting_problems
>
> -Kevin

On Fri, Jan 18, 2013 at 3:26 AM, Tsunezumi <tsunezumi(at)efficlabo(dot)com> wrote:
>
> I installed ordinarily.
> I did not correct postgresql.conf.
>
> Installation Directory
> C:\PostgreSQL\9.2
>
> Data Directory
> C:\PostgreSQL\9.2\data
>
> locale
> C

Please post the results of the following query:

SELECT 'version'::text AS "name",
version() AS "current_setting"
UNION ALL
SELECT name,
current_setting(name)
FROM pg_settings
WHERE NOT source='default'AND NOT name IN
('config_file','data_directory','hba_file','ident_file','log_timezone','DateStyle','lc_messages','lc_monetary','lc_numeric','lc_time','timezone_abbreviations','default_text_search_config','application_name','transaction_deferrable','transaction_isolation','transaction_read_only');

I corrected "postgresql.conf", in order to improve the phenomenon.
A result is the same.
It was same phenomenon on Windows8 professional 64bit.

"name","current_setting"
"version","PostgreSQL 9.2.2, compiled by Visual C++ build 1600, 64-bit"
"bytea_output","hex"
"client_encoding","SJIS"
"lc_collate","C"
"lc_ctype","C"
"listen_addresses","*"
"log_destination","stderr"
"log_line_prefix","%t %h %a"
"log_rotation_size","1MB"
"log_statement","all"
"logging_collector","on"
"max_connections","100"
"max_stack_depth","2MB"
"port","5433"
"server_encoding","UTF8"
"shared_buffers","32MB"
"TimeZone","Asia/Tokyo"
"wal_buffers","1MB"

On Fri, 18 Jan 2013 07:35:43 -0800
bricklen <bricklen(at)gmail(dot)com> wrote:

> On Fri, Jan 18, 2013 at 3:26 AM, Tsunezumi <tsunezumi(at)efficlabo(dot)com> wrote:
> >
> > I installed ordinarily.
> > I did not correct postgresql.conf.
> >
> > Installation Directory
> > C:\PostgreSQL\9.2
> >
> > Data Directory
> > C:\PostgreSQL\9.2\data
> >
> > locale
> > C
>
> Please post the results of the following query:
>
> SELECT 'version'::text AS "name",
> version() AS "current_setting"
> UNION ALL
> SELECT name,
> current_setting(name)
> FROM pg_settings
> WHERE NOT source='default'AND NOT name IN
> ('config_file','data_directory','hba_file','ident_file','log_timezone','DateStyle','lc_messages','lc_monetary','lc_numeric','lc_time','timezone_abbreviations','default_text_search_config','application_name','transaction_deferrable','transaction_isolation','transaction_read_only');

On Fri, Jan 18, 2013 at 07:35:43AM -0800, bricklen wrote:
> Please post the results of the following query:
>
> SELECT 'version'::text AS "name",
> version() AS "current_setting"
> UNION ALL
> SELECT name,
> current_setting(name)
> FROM pg_settings
> WHERE NOT source='default'AND NOT name IN
> ('config_file','data_directory','hba_file','ident_file','log_timezone','DateStyle','lc_messages','lc_monetary','lc_numeric','lc_time','timezone_abbreviations','default_text_search_config','application_name','transaction_deferrable','transaction_isolation','transaction_read_only');

Above is a very creative query that was posted to the bugs list by
bricklen. It reports all non-default server settings, plus version().
Here is a realigned version:

SELECT 'version'::text AS name, version() AS current_setting
UNION ALL
SELECT name, current_setting(name)
FROM pg_settings
WHERE source != 'default' AND
name NOT IN
(
'config_file','data_directory','hba_file','ident_file','log_timezone',
'DateStyle','lc_messages','lc_monetary','lc_numeric','lc_time',
'timezone_abbreviations','default_text_search_config','application_name',
'transaction_deferrable','transaction_isolation','transaction_read_only'
);

and the output from my server with an unmodified postgresql.conf:

name | current_setting
-----------------+-------------------------------------------------------------------------------------------------
version | PostgreSQL 9.3devel on x86_64-unknown-linux-gnu, compiled by gcc (Debian 4.4.5-8) 4.4.5, 64-bit
client_encoding | UTF8
lc_collate | en_US.UTF-8
lc_ctype | en_US.UTF-8
max_connections | 100
max_stack_depth | 2MB
server_encoding | UTF8
shared_buffers | 128MB
TimeZone | US/Eastern
wal_buffers | 4MB
(10 rows)

I am wondering if we should make this query more widely used, perhaps by
putting it in our docs about reporting bugs, or on our website.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

Bruce Momjian <bruce(at)momjian(dot)us> writes:
> I am wondering if we should make this query more widely used, perhaps by
> putting it in our docs about reporting bugs, or on our website.

I find the manual exclusion list to be poor style, and not at all
future-proof. Maybe we could use

select name, setting, source from pg_settings
where source not in ('default', 'override');

This would print a few not-all-that-interesting settings made by initdb,
but not having to adjust the exclusion list for different versions is
easily worth that. I think the source column is potentially useful when
we're casting this type of fishing net, too.

regards, tom lane

On Friday, January 18, 2013, Tsunezumi wrote:

>
> I installed ordinarily.
>

Could you be more specific? I do not know what is ordinary for you.

I ordinarily install from source (although not on Windows). Other people
ordinarily do it differently.

> I do not have this problem on PostgreSQL 9.1.7.
>

Could you show a directory listing of the pg_log directory under both 9.1.7
and 9.2.2, so that we can see what you are seeing that leads to the
conclusion that rotation is not occurring?

Cheers,

Jeff

Thank you.

I send the picture of a screen.

On Sat, 19 Jan 2013 14:21:29 -0800
Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:

> On Friday, January 18, 2013, Tsunezumi wrote:
>
> >
> > I installed ordinarily.
> >
>
> Could you be more specific? I do not know what is ordinary for you.
>
> I ordinarily install from source (although not on Windows). Other people
> ordinarily do it differently.
>
>
> > I do not have this problem on PostgreSQL 9.1.7.
> >
>
> Could you show a directory listing of the pg_log directory under both 9.1.7
> and 9.2.2, so that we can see what you are seeing that leads to the
> conclusion that rotation is not occurring?
>
> Cheers,
>
> Jeff

On Tue, Jan 22, 2013 at 4:42 AM, Tsunezumi <tsunezumi(at)efficlabo(dot)com> wrote:
> Thank you.
>
> I send the picture of a screen.
>

Thanks.

For what it is worth, I can reproduce this on Windows 7, using the
9.2.2 and 9.1.7 windows 64 installers from EDB (i.e.
http://www.enterprisedb.com/postgresql-922-installers-win64?ls=Crossover&type=Crossover),
with completely default installation (EDB changes the default to be
logging_collector=on), and using the below to blow up the log files
with error messages:

perl -le 'print "FOO$_;" foreach 1..1e7' | psql

9.1.7 rotates the log files in $DATA/pg_log, while 9.2.2 does not
rotate based on size.

PostgreSQL 9.1.7, compiled by Visual C++ build 1500, 64-bit
PostgreSQL 9.2.2, compiled by Visual C++ build 1600, 64-bit

I do not see the problem under 9.2.2 on Linux, it rotates as expected
(after turning logging_collector on)

PostgreSQL 9.2.2 on x86_64-unknown-linux-gnu, compiled by gcc (GCC)
4.4.6 20120305 (Red Hat 4.4.6-4), 64-bit

Cheers,

Jeff

Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> For what it is worth, I can reproduce this on Windows 7, using the
> 9.2.2 and 9.1.7 windows 64 installers from EDB (i.e.
> http://www.enterprisedb.com/postgresql-922-installers-win64?ls=Crossover&type=Crossover),
> with completely default installation (EDB changes the default to be
> logging_collector=on), and using the below to blow up the log files
> with error messages:

> perl -le 'print "FOO$_;" foreach 1..1e7' | psql

> 9.1.7 rotates the log files in $DATA/pg_log, while 9.2.2 does not
> rotate based on size.

[ scratches head for awhile... ] Hm, what you are testing is the
default rotation parameters, right? log_rotation_age = 1 day,
log_rotation_size = 10MB? So you didn't wait to see what would happen
at a rotation-age boundary. If so, does "pg_ctl reload" kick it into
rotating once the file is too big? (Or you could reduce
log_rotation_age to a small value, but that would make it hard to
tell which condition triggered rotation.)

Here's what I think is probably happening: on Windows, the syslogger
process actually contains two threads, one of which handles data
transfer while the other worries about things like log rotation.
In prior versions, the control thread woke up once a second, so it
would notice within one second if the data transfer thread had filled
the current file to more than log_rotation_size. In 9.2, we got rid
of those "unnecessary" wakeups, which means log rotation won't occur
until there's some other event that kicks the control thread into
activity.

There's no bug on non-Windows because we don't use two threads on other
platforms; data transfer is done by the main thread so it's already
awake upon any write to the log file, and it won't miss the rotation
condition. (Size-based rotations were therefore always more precise on
non-Windows machines...)

So what we need on Windows is for the data transfer thread to notice
when "Log_RotationSize > 0 && ftell(syslogFile) >= Log_RotationSize",
and then either signal the control thread to wake up, or do the
rotation itself. Probably the former is less risk.

I'm not coding this fix though, since I'm not in a position to test it.

regards, tom lane

On Tuesday, January 22, 2013, Tom Lane wrote:

> Jeff Janes <jeff(dot)janes(at)gmail(dot)com <javascript:;>> writes:
> > For what it is worth, I can reproduce this on Windows 7, using the
> > 9.2.2 and 9.1.7 windows 64 installers from EDB (i.e.
> >
> http://www.enterprisedb.com/postgresql-922-installers-win64?ls=Crossover&type=Crossover
> ),
> > with completely default installation (EDB changes the default to be
> > logging_collector=on), and using the below to blow up the log files
> > with error messages:
>
> > perl -le 'print "FOO$_;" foreach 1..1e7' | psql
>
> > 9.1.7 rotates the log files in $DATA/pg_log, while 9.2.2 does not
> > rotate based on size.
>
> [ scratches head for awhile... ] Hm, what you are testing is the
> default rotation parameters, right? log_rotation_age = 1 day,
> log_rotation_size = 10MB? So you didn't wait to see what would happen
> at a rotation-age boundary.

Correct, I did not wait. But from the original reporter's screenshot, it
seemed to be rotating correctly based on time, just not on size.

> If so, does "pg_ctl reload" kick it into
> rotating once the file is too big?

Yes, triggering a reload (through pgAdmin) does cause it to kick over to a
new log file.

...

>
> So what we need on Windows is for the data transfer thread to notice
> when "Log_RotationSize > 0 && ftell(syslogFile) >= Log_RotationSize",
> and then either signal the control thread to wake up, or do the
> rotation itself. Probably the former is less risk.
>
> I'm not coding this fix though, since I'm not in a position to test it.
>

If I can follow though on Andrew Dunstan's instructions to get mingw up and
running, I'll take it for a spin.

Cheers,

Jeff

On Tue, Jan 22, 2013 at 9:29 PM, Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:
> On Tuesday, January 22, 2013, Tom Lane wrote:
>>
>>
>> So what we need on Windows is for the data transfer thread to notice
>> when "Log_RotationSize > 0 && ftell(syslogFile) >= Log_RotationSize",
>> and then either signal the control thread to wake up, or do the
>> rotation itself. Probably the former is less risk.
>>
>> I'm not coding this fix though, since I'm not in a position to test it.
>
>
> If I can follow though on Andrew Dunstan's instructions to get mingw up
and
> running, I'll take it for a spin.

The attached patch fixes the problem, tested under mingw.

I've included an elog "JJ logger woke up" in the patch to verify that the
wake up is not happening more often than it should. Obviously this line
should not be included in the actual commit--but I thought a tester would
like to see how I verified this.

This is my first effort in both Windows and in the Latch code, so committer
beware.

It should be applied to 9_2 and to head.

I've not added it to the commit-fest as it is a bug fix.

Cheers,

Jeff

Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> On Tue, Jan 22, 2013 at 9:29 PM, Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:
>> On Tuesday, January 22, 2013, Tom Lane wrote:
>>> So what we need on Windows is for the data transfer thread to notice
>>> when "Log_RotationSize > 0 && ftell(syslogFile) >= Log_RotationSize",
>>> and then either signal the control thread to wake up, or do the
>>> rotation itself. Probably the former is less risk.

> The attached patch fixes the problem, tested under mingw.
> This is my first effort in both Windows and in the Latch code, so committer
> beware.

Looks good, except I moved the test out of the if-block. The ereport in
the other if branch could also fill the file, in principle, and in any
case it hardly seems like we need to optimize any of the non-success
cases.

> It should be applied to 9_2 and to head.

Done. Thanks for doing this!

regards, tom lane