Re: [BUGS] Completely broken replica after PANIC: WAL contains references to invalid pages

2013-03-29 Thread Sergey Konoplev
On Fri, Mar 29, 2013 at 2:38 PM, Andres Freund  wrote:
> I have to admit, I find it a bit confusing that so many people report a
> bug and then immediately destroy all evidence of the bug. Just seems to
> a happen a bit too frequently.

You see, businesses usually need it up ASAP again. Sorry, I must have
note down the output of pg_controldata straight after it got broken, I
just have not came up to it.

> Thats not a pg_controldata output from the broken replica though, or is
> it? I guess its from a new standby?

That was the output from the standby that was rsync-ed on top of the
broken one. I thought you might find something useful in it.

Can I test your guess some other way? And what was the guess?

--
Kind regards,
Sergey Konoplev
Database and Software Consultant

Profile: http://www.linkedin.com/in/grayhemp
Phone: USA +1 (415) 867-9984, Russia +7 (901) 903-0499, +7 (988) 888-1979
Skype: gray-hemp
Jabber: gray...@gmail.com


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


Re: [BUGS] Completely broken replica after PANIC: WAL contains references to invalid pages

2013-03-29 Thread Andres Freund
On 2013-03-29 14:19:59 -0700, Sergey Konoplev wrote:
> On Fri, Mar 29, 2013 at 1:52 PM, anara...@anarazel.de
>  wrote:
> > I think I See whats going on. Do you still have the datadir available? If 
> > so, could you send the pg_controldata output?
> 
> I have already rebuilt the replica, however below is the output if it is 
> useful:

I have to admit, I find it a bit confusing that so many people report a
bug and then immediately destroy all evidence of the bug. Just seems to
a happen a bit too frequently.

> pg_control version number:922
> Catalog version number:   201204301
> Database system identifier:   5858109675396804534
> Database cluster state:   in archive recovery
> pg_control last modified: Сбт 30 Мар 2013 00:21:11
> Latest checkpoint location:   258B/BDBBE748
> Prior checkpoint location:258B/86DABCB8
> Latest checkpoint's REDO location:258B/8B78BED0
> Latest checkpoint's TimeLineID:   2
> Latest checkpoint's full_page_writes: on
> Latest checkpoint's NextXID:  0/423386899
> Latest checkpoint's NextOID:  2758636912
> Latest checkpoint's NextMultiXactId:  103920
> Latest checkpoint's NextMultiOffset:  431309
> Latest checkpoint's oldestXID:225634745
> Latest checkpoint's oldestXID's DB:   16436
> Latest checkpoint's oldestActiveXID:  421766298
> Time of latest checkpoint:Птн 29 Мар 2013 22:33:01

Thats not a pg_controldata output from the broken replica though, or is
it? I guess its from a new standby?

Andres
Greetings,

Andres Freund

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


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


Re: [BUGS] Completely broken replica after PANIC: WAL contains references to invalid pages

2013-03-29 Thread Sergey Konoplev
On Fri, Mar 29, 2013 at 1:52 PM, anara...@anarazel.de
 wrote:
> I think I See whats going on. Do you still have the datadir available? If so, 
> could you send the pg_controldata output?

I have already rebuilt the replica, however below is the output if it is useful:

pg_control version number:922
Catalog version number:   201204301
Database system identifier:   5858109675396804534
Database cluster state:   in archive recovery
pg_control last modified: Сбт 30 Мар 2013 00:21:11
Latest checkpoint location:   258B/BDBBE748
Prior checkpoint location:258B/86DABCB8
Latest checkpoint's REDO location:258B/8B78BED0
Latest checkpoint's TimeLineID:   2
Latest checkpoint's full_page_writes: on
Latest checkpoint's NextXID:  0/423386899
Latest checkpoint's NextOID:  2758636912
Latest checkpoint's NextMultiXactId:  103920
Latest checkpoint's NextMultiOffset:  431309
Latest checkpoint's oldestXID:225634745
Latest checkpoint's oldestXID's DB:   16436
Latest checkpoint's oldestActiveXID:  421766298
Time of latest checkpoint:Птн 29 Мар 2013 22:33:01
Minimum recovery ending location: 258C/14AA5FA0
Backup start location:0/0
Backup end location:  0/0
End-of-backup record required:no
Current wal_level setting:hot_standby
Current max_connections setting:  550
Current max_prepared_xacts setting:   0
Current max_locks_per_xact setting:   64
Maximum data alignment:   8
Database block size:  8192
Blocks per segment of large relation: 131072
WAL block size:   8192
Bytes per WAL segment:16777216
Maximum length of identifiers:64
Maximum columns in an index:  32
Maximum size of a TOAST chunk:1996
Date/time type storage:   64-bit integers
Float4 argument passing:  by value
Float8 argument passing:  by value

>
>
> Andres
>
>>Hardware:
>>
>>IBM System x3650 M4, 148GB RAM, NAS
>>
>>Software:
>>
>>PostgreSQL 9.2.3, yum.postgresql.org
>>CentOS 6.3, kernel 2.6.32-279.22.1.el6.x86_64
>>
>>Configuration:
>>
>>listen_addresses = '*'
>>max_connections = 550
>>shared_buffers = 35GB
>>work_mem = 256MB
>>maintenance_work_mem = 1GB
>>bgwriter_delay = 10ms
>>bgwriter_lru_multiplier = 10.0
>>effective_io_concurrency = 32
>>wal_level = hot_standby
>>synchronous_commit = off
>>checkpoint_segments = 1024
>>checkpoint_timeout = 1h
>>checkpoint_completion_target = 0.9
>>checkpoint_warning = 5min
>>max_wal_senders = 3
>>wal_keep_segments = 2048
>>hot_standby = on
>>max_standby_streaming_delay = 5min
>>hot_standby_feedback = on
>>effective_cache_size = 133GB
>>log_directory = '/var/log/pgsql'
>>log_filename = 'postgresql-%Y-%m-%d.log'
>>log_checkpoints = on
>>log_line_prefix = '%t %p %u@%d from %h [vxid:%v txid:%x] [%i] '
>>log_lock_waits = on
>>log_statement = 'ddl'
>>log_timezone = 'W-SU'
>>track_activity_query_size = 4096
>>autovacuum_max_workers = 5
>>autovacuum_naptime = 5s
>>autovacuum_vacuum_scale_factor = 0.05
>>autovacuum_analyze_scale_factor = 0.05
>>autovacuum_vacuum_cost_delay = 5ms
>>datestyle = 'iso, dmy'
>>timezone = 'W-SU'
>>lc_messages = 'en_US.UTF-8'
>>lc_monetary = 'ru_RU.UTF-8'
>>lc_numeric = 'ru_RU.UTF-8'
>>lc_time = 'ru_RU.UTF-8'
>>default_text_search_config = 'pg_catalog.russian'
>>
>>System:
>>
>># Controls the maximum shared segment size, in bytes
>>kernel.shmmax = 53287555072
>>
>># Controls the maximum number of shared memory segments, in pages
>>kernel.shmall = 13009657
>>
>># Maximum number of file-handles
>>fs.file-max = 65535
>>
>># pdflush tuning to prevent lag spikes
>>vm.dirty_ratio = 10
>>vm.dirty_background_ratio = 1
>>vm.dirty_expire_centisecs = 499
>>
>># Prevent the scheduler breakdown
>>kernel.sched_migration_cost = 500
>>
>># Turned off to provide more CPU to PostgreSQL
>>kernel.sched_autogroup_enabled = 0
>>
>># Setup hugepages
>>vm.hugetlb_shm_group = 26
>>vm.hugepages_treat_as_movable = 0
>>vm.nr_overcommit_hugepages = 512
>>
>># The Huge Page Size is 2048kB, so for 35GB shared buffers the number
>>is 17920
>>vm.nr_hugepages = 17920
>>
>># Turn off the NUMA local pages reclaim as it leads to wrong caching
>>strategy for databases
>>vm.zone_reclaim_mode = 0
>>
>>Environment:
>>
>>HUGETLB_SHM=yes
>>LD_PRELOAD='/usr/lib64/libhugetlbfs.so'
>>export HUGETLB_SHM LD_PRELOAD
>>
>>When it is stopped:
>>
>>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] LOG:
>>restartpoint complete: wrote 1685004 buffers (36.7%); 0 transaction
>>log file(s) added, 0 removed, 555 recycled; write=3237.402 s,
>>sync=0.071 s, total=3237.507 s; sync files=2673, longest=0.008 s,
>>average=0.000 s
>>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] LOG:  recovery
>>restart point at 2538/6E154AC0
>>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] DETAIL:  last
>>completed transaction was at log time 2013-03-26 11:50:31.613948+04
>

Re: [BUGS] Completely broken replica after PANIC: WAL contains references to invalid pages

2013-03-29 Thread anara...@anarazel.de
Hi

Sergey Konoplev  schrieb:

>Hi all,
>
>A couple of days ago I found the replica stopped after the PANIC
>message:
>
>PANIC:  WAL contains references to invalid pages
>
>When I tried to restart it I got this FATAL:
>
>FATAL:  could not access status of transaction 280557568
>
>Below is the description of the server and information from PostgreSQL
>and system logs. After googling the problem I have found nothing like
>this.
>
>Any thoughts of what it could be and how to prevent it in the future?

I think I See whats going on. Do you still have the datadir available? If so, 
could you send the pg_controldata output?


Andres

>Hardware:
>
>IBM System x3650 M4, 148GB RAM, NAS
>
>Software:
>
>PostgreSQL 9.2.3, yum.postgresql.org
>CentOS 6.3, kernel 2.6.32-279.22.1.el6.x86_64
>
>Configuration:
>
>listen_addresses = '*'
>max_connections = 550
>shared_buffers = 35GB
>work_mem = 256MB
>maintenance_work_mem = 1GB
>bgwriter_delay = 10ms
>bgwriter_lru_multiplier = 10.0
>effective_io_concurrency = 32
>wal_level = hot_standby
>synchronous_commit = off
>checkpoint_segments = 1024
>checkpoint_timeout = 1h
>checkpoint_completion_target = 0.9
>checkpoint_warning = 5min
>max_wal_senders = 3
>wal_keep_segments = 2048
>hot_standby = on
>max_standby_streaming_delay = 5min
>hot_standby_feedback = on
>effective_cache_size = 133GB
>log_directory = '/var/log/pgsql'
>log_filename = 'postgresql-%Y-%m-%d.log'
>log_checkpoints = on
>log_line_prefix = '%t %p %u@%d from %h [vxid:%v txid:%x] [%i] '
>log_lock_waits = on
>log_statement = 'ddl'
>log_timezone = 'W-SU'
>track_activity_query_size = 4096
>autovacuum_max_workers = 5
>autovacuum_naptime = 5s
>autovacuum_vacuum_scale_factor = 0.05
>autovacuum_analyze_scale_factor = 0.05
>autovacuum_vacuum_cost_delay = 5ms
>datestyle = 'iso, dmy'
>timezone = 'W-SU'
>lc_messages = 'en_US.UTF-8'
>lc_monetary = 'ru_RU.UTF-8'
>lc_numeric = 'ru_RU.UTF-8'
>lc_time = 'ru_RU.UTF-8'
>default_text_search_config = 'pg_catalog.russian'
>
>System:
>
># Controls the maximum shared segment size, in bytes
>kernel.shmmax = 53287555072
>
># Controls the maximum number of shared memory segments, in pages
>kernel.shmall = 13009657
>
># Maximum number of file-handles
>fs.file-max = 65535
>
># pdflush tuning to prevent lag spikes
>vm.dirty_ratio = 10
>vm.dirty_background_ratio = 1
>vm.dirty_expire_centisecs = 499
>
># Prevent the scheduler breakdown
>kernel.sched_migration_cost = 500
>
># Turned off to provide more CPU to PostgreSQL
>kernel.sched_autogroup_enabled = 0
>
># Setup hugepages
>vm.hugetlb_shm_group = 26
>vm.hugepages_treat_as_movable = 0
>vm.nr_overcommit_hugepages = 512
>
># The Huge Page Size is 2048kB, so for 35GB shared buffers the number
>is 17920
>vm.nr_hugepages = 17920
>
># Turn off the NUMA local pages reclaim as it leads to wrong caching
>strategy for databases
>vm.zone_reclaim_mode = 0
>
>Environment:
>
>HUGETLB_SHM=yes
>LD_PRELOAD='/usr/lib64/libhugetlbfs.so'
>export HUGETLB_SHM LD_PRELOAD
>
>When it is stopped:
>
>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] LOG:
>restartpoint complete: wrote 1685004 buffers (36.7%); 0 transaction
>log file(s) added, 0 removed, 555 recycled; write=3237.402 s,
>sync=0.071 s, total=3237.507 s; sync files=2673, longest=0.008 s,
>average=0.000 s
>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] LOG:  recovery
>restart point at 2538/6E154AC0
>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] DETAIL:  last
>completed transaction was at log time 2013-03-26 11:50:31.613948+04
>2013-03-26 11:50:32 MSK 3775 @ from  [vxid: txid:0] [] LOG:
>restartpoint starting: xlog
>2013-03-26 11:51:16 MSK 3773 @ from  [vxid:1/0 txid:0] [] WARNING:
>page 451 of relation base/16436/2686702648 is uninitialized
>2013-03-26 11:51:16 MSK 3773 @ from  [vxid:1/0 txid:0] [] CONTEXT:
>xlog redo vacuum: rel 1663/16436/2686702648; blk 2485,
>lastBlockVacuumed 0
>2013-03-26 11:51:16 MSK 3773 @ from  [vxid:1/0 txid:0] [] PANIC:  WAL
>contains references to invalid pages
>2013-03-26 11:51:16 MSK 3773 @ from  [vxid:1/0 txid:0] [] CONTEXT:
>xlog redo vacuum: rel 1663/16436/2686702648; blk 2485,
>lastBlockVacuumed 0
>2013-03-26 11:51:16 MSK 3770 @ from  [vxid: txid:0] [] LOG:  startup
>process (PID 3773) was terminated by signal 6: Aborted
>2013-03-26 11:51:16 MSK 3770 @ from  [vxid: txid:0] [] LOG:
>terminating any other active server processes
>
>From /var/log/messages:
>
>Mar 26 10:50:52 tms2 kernel: : postmaster: page allocation failure.
>order:8, mode:0xd0
>Mar 26 10:50:52 tms2 kernel: : Pid: 3774, comm: postmaster Not tainted
>2.6.32-279.22.1.el6.x86_64 #1
>Mar 26 10:50:52 tms2 kernel: : Call Trace:
>Mar 26 10:50:52 tms2 kernel: : [] ?
>__alloc_pages_nodemask+0x77f/0x940
>Mar 26 10:50:52 tms2 kernel: : [] ?
>kmem_getpages+0x62/0x170
>Mar 26 10:50:52 tms2 kernel: : [] ?
>fallback_alloc+0x1ba/0x270
>Mar 26 10:50:52 tms2 kernel: : [] ?
>cache_grow+0x2cf/0x320
>Mar 26 10:50:52 tms2 kernel: : [] ?
>cache_alloc_node+0x99/0x160
>Mar 26 10:50:52 tms2 kernel: : [] ?
>dma_pin_

Re: [BUGS] Issue with range types and casts?

2013-03-29 Thread Jeff Davis
On Fri, 2013-03-08 at 15:27 -0800, Josh Berkus wrote:
> create table tenmin as select * from sampledata where collect_ts <@
> '[2013-01-01 00:00:00,2013-01-01 00:10:00)';
> ERROR:  could not find range type for data type timestamp with time zone
> Time: 0.189 ms
> 
> This seems like it ought to be fixable.  Postgres has figured out that
> it needs to find the range type for timestamptz.  Why can't it?

The reason it's doing that is because there could be multiple range
types based on one element type. The workaround (which you are probably
already using) is to cast the second argument to a tstzrange.

We could try to be smarter about it, but the problem with relying on
that intelligence is that, when it doesn't work, your queries break. For
instance, someone else could add a new datatype "tstzrange2"[1], and
that would introduce ambiguity, and you'd get an error then (probably
breaking many existing queries baked into your application). Different
people have different opinions on how smart the type system should try
to be, and reasonable people may differ; I'm just saying what it does
currently.

That being said, perhaps the error message should be improved? I'm not
sure what it should say exactly, though.

Regards,
Jeff Davis

[1] To make it more plausible, tstzrange2 might have a canonicalization
function that turns it into a discrete range (kind of like date but at a
resolution smaller than a day).



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