Nov 11 01:37:39 psql02 crmd: [1756]: info: do_lrm_rsc_op: Performing key=18:27:0:39aa410e-6267-43a0-a085-55e8bbdd85ec op=failover-ip_start_0 ) Nov 11 01:37:39 psql02 lrmd: [1753]: info: rsc:failover-ip:19: start Nov 11 01:37:39 psql02 IPaddr[8315]: INFO: Using calculated nic for 10.100.53.100: eth0 Nov 11 01:37:39 psql02 lrmd: [1753]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:37:39 INFO: Using calculated nic for 10.100.53.100: eth0 Nov 11 01:37:39 psql02 IPaddr[8315]: INFO: Using calculated netmask for 10.100.53.100: 255.255.255.255 Nov 11 01:37:39 psql02 lrmd: [1753]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:37:39 INFO: Using calculated netmask for 10.100.53.100: 255.255.255.255 Nov 11 01:37:39 psql02 IPaddr[8315]: INFO: eval ifconfig eth0:0 10.100.53.100 netmask 255.255.255.255 broadcast 10.100.53.100 Nov 11 01:37:39 psql02 lrmd: [1753]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:37:39 INFO: eval ifconfig eth0:0 10.100.53.100 netmask 255.255.255.255 broadcast 10.100.53.100 Nov 11 01:37:39 psql02 crmd: [1756]: info: process_lrm_event: LRM operation failover-ip_start_0 (call=19, rc=0, cib-update=33, confirmed=true) ok Nov 11 01:37:40 psql02 crmd: [1756]: info: do_lrm_rsc_op: Performing key=15:27:0:39aa410e-6267-43a0-a085-55e8bbdd85ec op=failover-psql_start_0 ) Nov 11 01:37:40 psql02 lrmd: [1753]: info: rsc:failover-psql:20: start Nov 11 01:37:40 psql02 lrmd: [8404]: WARN: For LSB init script, no additional parameters are needed. Nov 11 01:37:40 psql02 crmd: [1756]: info: do_lrm_rsc_op: Performing key=19:27:0:39aa410e-6267-43a0-a085-55e8bbdd85ec op=failover-ip_monitor_5000 ) Nov 11 01:37:40 psql02 lrmd: [1753]: info: RA output: (failover-psql:start:stdout) Starting PostgreSQL 8.3 database server: Nov 11 01:37:40 psql02 lrmd: [1753]: info: RA output: (failover-psql:start:stdout) main Nov 11 01:37:40 psql02 crmd: [1756]: info: process_lrm_event: LRM operation failover-ip_monitor_5000 (call=21, rc=0, cib-update=34, confirmed=false) ok Nov 11 01:37:42 psql02 shutdown[8435]: shutting down for system reboot Nov 11 01:37:43 psql02 init: Switching to runlevel: 6 Nov 11 01:37:44 psql02 lrmd: [1753]: info: RA output: (failover-psql:start:stdout) . Nov 11 01:37:44 psql02 crmd: [1756]: info: process_lrm_event: LRM operation failover-psql_start_0 (call=20, rc=0, cib-update=35, confirmed=true) ok Nov 11 01:37:45 psql02 corosync[1706]: [TOTEM ] A processor failed, forming new configuration. Nov 11 01:37:46 psql02 kernel: [ 3259.650976] fuse exit Nov 11 01:37:46 psql02 logd: [8509]: debug: Stopping ha_logd with pid 1805 Nov 11 01:37:46 psql02 logd: [8509]: info: Waiting for pid=1805 to exit Nov 11 01:37:46 psql02 logd: [1805]: debug: logd_term_action: received SIGTERM Nov 11 01:37:46 psql02 logd: [1805]: debug: logd_term_action: waiting for 0 messages to be read by write process Nov 11 01:37:46 psql02 logd: [1805]: debug: logd_term_action: sending SIGTERM to write process Nov 11 01:37:46 psql02 logd: [1806]: info: logd_term_write_action: received SIGTERM Nov 11 01:37:46 psql02 logd: [1806]: debug: Writing out 0 messages then quitting Nov 11 01:37:46 psql02 logd: [1806]: info: Exiting write process Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] notice: pcmk_peer_update: Transitional membership event on ring 104: memb=1, new=0, lost=1 Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: pcmk_peer_update: memb: psql02 389374986 Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: pcmk_peer_update: lost: psql01 372597770 Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] notice: pcmk_peer_update: Stable membership event on ring 104: memb=1, new=0, lost=0 Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: pcmk_peer_update: MEMB: psql02 389374986 Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: ais_mark_unseen_peer_dead: Node psql01 was not seen in the previous transition Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: update_member: Node 372597770/psql01 is now: lost Nov 11 01:37:47 psql02 corosync[1706]: [pcmk ] info: send_member_notification: Sending membership update 104 to 2 children Nov 11 01:37:47 psql02 corosync[1706]: [TOTEM ] A processor joined or left the membership and a new membership was formed. Nov 11 01:37:47 psql02 corosync[1706]: [MAIN ] Completed service synchronization, ready to provide service. Nov 11 01:37:47 psql02 cib: [1752]: notice: ais_dispatch: Membership 104: quorum lost Nov 11 01:37:47 psql02 cib: [1752]: info: crm_update_peer: Node psql01: id=372597770 state=lost (new) addr=r(0) ip(10.100.53.150) votes=1 born=100 seen=100 proc=00000000000000000000000000013312 Nov 11 01:37:47 psql02 crmd: [1756]: notice: ais_dispatch: Membership 104: quorum lost Nov 11 01:37:47 psql02 crmd: [1756]: info: crm_update_peer: Node psql01: id=372597770 state=lost (new) addr=r(0) ip(10.100.53.150) votes=1 born=100 seen=100 proc=00000000000000000000000000013312 Nov 11 01:37:47 psql02 crmd: [1756]: WARN: check_dead_member: Our DC node (psql01) left the cluster Nov 11 01:37:47 psql02 crmd: [1756]: info: do_state_transition: State transition S_NOT_DC -> S_ELECTION [ input=I_ELECTION cause=C_FSA_INTERNAL origin=check_dead_member ] Nov 11 01:37:47 psql02 crmd: [1756]: info: update_dc: Unset DC psql01 Nov 11 01:37:47 psql02 crmd: [1756]: info: do_state_transition: State transition S_ELECTION -> S_INTEGRATION [ input=I_ELECTION_DC cause=C_FSA_INTERNAL origin=do_election_check ] Nov 11 01:37:47 psql02 crmd: [1756]: info: do_te_control: Registering TE UUID: 7ccd272a-6676-4cc3-a540-9e2262fef5b4 Nov 11 01:37:47 psql02 crmd: [1756]: WARN: cib_client_add_notify_callback: Callback already present Nov 11 01:37:47 psql02 crmd: [1756]: info: set_graph_functions: Setting custom graph functions Nov 11 01:37:47 psql02 crmd: [1756]: info: unpack_graph: Unpacked transition -1: 0 actions in 0 synapses Nov 11 01:37:47 psql02 crmd: [1756]: info: do_dc_takeover: Taking over DC status for this partition Nov 11 01:37:47 psql02 logd: [8509]: info: Pid 1805 exited Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_readwrite: We are now in R/W mode Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_master for section 'all' (origin=local/crmd/37, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_modify for section cib (origin=local/crmd/38, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/40, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 crmd: [1756]: info: join_make_offer: Making join offers based on membership 104 Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/42, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 crmd: [1756]: info: do_dc_join_offer_all: join-1: Waiting on 1 outstanding join acks Nov 11 01:37:47 psql02 crmd: [1756]: info: ais_dispatch: Membership 104: quorum still lost Nov 11 01:37:47 psql02 crmd: [1756]: info: config_query_callback: Checking for expired actions every 900000ms Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/45, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 crmd: [1756]: info: update_dc: Set DC to psql02 (3.0.1) Nov 11 01:37:47 psql02 crmd: [1756]: info: ais_dispatch: Membership 104: quorum still lost Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_modify for section crm_config (origin=local/crmd/48, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 crmd: [1756]: info: do_state_transition: State transition S_INTEGRATION -> S_FINALIZE_JOIN [ input=I_INTEGRATED cause=C_FSA_INTERNAL origin=check_join_state ] Nov 11 01:37:47 psql02 crmd: [1756]: info: do_state_transition: All 1 cluster nodes responded to the join offer. Nov 11 01:37:47 psql02 crmd: [1756]: info: do_dc_join_finalize: join-1: Syncing the CIB from psql02 to the rest of the cluster Nov 11 01:37:47 psql02 crmd: [1756]: info: te_connect_stonith: Attempting connection to fencing daemon... Nov 11 01:37:47 psql02 cib: [1752]: info: cib_process_request: Operation complete: op cib_sync for section 'all' (origin=local/crmd/49, version=0.780.15): ok (rc=0) Nov 11 01:37:47 psql02 rpc.statd[1542]: Caught signal 15, un-registering and exiting. Nov 11 01:38:53 psql02 kernel: imklog 3.18.6, log source = /proc/kmsg started. Nov 11 01:38:53 psql02 kernel: [ 0.000000] Initializing cgroup subsys cpuset Nov 11 01:38:53 psql02 kernel: [ 0.000000] Initializing cgroup subsys cpu Nov 11 01:38:53 psql02 kernel: [ 0.000000] Linux version 2.6.26-2-686 (Debian 2.6.26-19lenny1) (dannf@debian.org) (gcc version 4.1.3 20080704 (prerelease) (Debian 4.1.2-25)) #1 SMP Sat Oct 17 17:59:23 UTC 2009 Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-provided physical RAM map: Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009f800 (usable) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 00000000000ca000 - 00000000000cc000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 0000000000100000 - 000000001fef0000 (usable) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 000000001fef0000 - 000000001feff000 (ACPI data) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 000000001feff000 - 000000001ff00000 (ACPI NVS) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 000000001ff00000 - 0000000020000000 (usable) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] BIOS-e820: 00000000fffe0000 - 0000000100000000 (reserved) Nov 11 01:38:53 psql02 kernel: [ 0.000000] 0MB HIGHMEM available. Nov 11 01:38:53 psql02 kernel: [ 0.000000] 512MB LOWMEM available. Nov 11 01:38:53 psql02 kernel: [ 0.000000] found SMP MP-table at [c00f6cd0] 000f6cd0 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Entering add_active_range(0, 0, 131072) 0 entries of 256 used Nov 11 01:38:53 psql02 kernel: [ 0.000000] Zone PFN ranges: Nov 11 01:38:53 psql02 kernel: [ 0.000000] DMA 0 -> 4096 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Normal 4096 -> 131072 Nov 11 01:38:53 psql02 kernel: [ 0.000000] HighMem 131072 -> 131072 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Movable zone start PFN for each node Nov 11 01:38:53 psql02 kernel: [ 0.000000] early_node_map[1] active PFN ranges Nov 11 01:38:53 psql02 kernel: [ 0.000000] 0: 0 -> 131072 Nov 11 01:38:53 psql02 kernel: [ 0.000000] On node 0 totalpages: 131072 Nov 11 01:38:53 psql02 kernel: [ 0.000000] DMA zone: 32 pages used for memmap Nov 11 01:38:53 psql02 kernel: [ 0.000000] DMA zone: 0 pages reserved Nov 11 01:38:53 psql02 kernel: [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Normal zone: 992 pages used for memmap Nov 11 01:38:53 psql02 kernel: [ 0.000000] Normal zone: 125984 pages, LIFO batch:31 Nov 11 01:38:53 psql02 kernel: [ 0.000000] HighMem zone: 0 pages used for memmap Nov 11 01:38:53 psql02 kernel: [ 0.000000] Movable zone: 0 pages used for memmap Nov 11 01:38:53 psql02 kernel: [ 0.000000] DMI present. Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: RSDP 000F6C60, 0014 (r0 PTLTD ) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: RSDT 1FEFAB68, 0030 (r1 PTLTD RSDT 6040000 LTP 0) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: FACP 1FEFEF14, 0074 (r1 INTEL 440BX 6040000 PTL F4240) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: DSDT 1FEFAB98, 437C (r1 PTLTD Custom 6040000 MSFT 100000D) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: FACS 1FEFFFC0, 0040 Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: APIC 1FEFEF88, 0050 (r1 PTLTD APIC 6040000 LTP 0) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: BOOT 1FEFEFD8, 0028 (r1 PTLTD $SBFTBL$ 6040000 LTP 1) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: PM-Timer IO Port: 0x1008 Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: Local APIC address 0xfee00000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1]) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0]) Nov 11 01:38:53 psql02 kernel: [ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23 Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 high edge) Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: IRQ0 used by override. Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: IRQ2 used by override. Nov 11 01:38:53 psql02 kernel: [ 0.000000] ACPI: IRQ9 used by override. Nov 11 01:38:53 psql02 kernel: [ 0.000000] Enabling APIC mode: Flat. Using 1 I/O APICs Nov 11 01:38:53 psql02 kernel: [ 0.000000] Using ACPI (MADT) for SMP configuration information Nov 11 01:38:53 psql02 kernel: [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dec00000) Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000ca000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 00000000000ca000 - 00000000000cc000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 00000000000cc000 - 00000000000dc000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 00000000000dc000 - 0000000000100000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 000000001fef0000 - 000000001feff000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PM: Registered nosave memory: 000000001feff000 - 000000001ff00000 Nov 11 01:38:53 psql02 kernel: [ 0.000000] SMP: Allowing 1 CPUs, 0 hotplug CPUs Nov 11 01:38:53 psql02 kernel: [ 0.000000] PERCPU: Allocating 37960 bytes of per cpu data Nov 11 01:38:53 psql02 kernel: [ 0.000000] NR_CPUS: 8, nr_cpu_ids: 1 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 130048 Nov 11 01:38:53 psql02 kernel: [ 0.000000] Kernel command line: root=/dev/sda1 ro quiet Nov 11 01:38:53 psql02 kernel: [ 0.000000] mapped APIC to ffffb000 (fee00000) Nov 11 01:38:53 psql02 kernel: [ 0.000000] mapped IOAPIC to ffffa000 (fec00000) Nov 11 01:38:53 psql02 kernel: [ 0.000000] Enabling fast FPU save and restore... done. Nov 11 01:38:53 psql02 kernel: [ 0.000000] Enabling unmasked SIMD FPU exception support... done. Nov 11 01:38:53 psql02 kernel: [ 0.000000] Initializing CPU#0 Nov 11 01:38:53 psql02 kernel: [ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.000000] Detected 3199.006 MHz processor. Nov 11 01:38:53 psql02 kernel: [ 0.004000] Console: colour VGA+ 80x25 Nov 11 01:38:53 psql02 kernel: [ 0.004000] console [tty0] enabled Nov 11 01:38:53 psql02 kernel: [ 0.004000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.004000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.004000] Memory: 509764k/524288k available (1770k kernel code, 13820k reserved, 751k data, 244k init, 0k highmem) Nov 11 01:38:53 psql02 kernel: [ 0.004000] virtual kernel memory layout: Nov 11 01:38:53 psql02 kernel: [ 0.004000] fixmap : 0xfff4c000 - 0xfffff000 ( 716 kB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] pkmap : 0xff800000 - 0xffc00000 (4096 kB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] vmalloc : 0xe0800000 - 0xff7fe000 ( 495 MB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] lowmem : 0xc0000000 - 0xe0000000 ( 512 MB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] .init : 0xc037f000 - 0xc03bc000 ( 244 kB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] .data : 0xc02ba9c9 - 0xc0376620 ( 751 kB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] .text : 0xc0100000 - 0xc02ba9c9 (1770 kB) Nov 11 01:38:53 psql02 kernel: [ 0.004000] Checking if this processor honours the WP bit even in supervisor mode...Ok. Nov 11 01:38:53 psql02 kernel: [ 0.004000] CPA: page pool initialized 1 of 1 pages preallocated Nov 11 01:38:53 psql02 kernel: [ 0.084845] Calibrating delay using timer specific routine.. 6426.26 BogoMIPS (lpj=12852520) Nov 11 01:38:53 psql02 kernel: [ 0.084908] Security Framework initialized Nov 11 01:38:53 psql02 kernel: [ 0.084970] SELinux: Disabled at boot. Nov 11 01:38:53 psql02 kernel: [ 0.085033] Capability LSM initialized Nov 11 01:38:53 psql02 kernel: [ 0.085095] Mount-cache hash table entries: 512 Nov 11 01:38:53 psql02 kernel: [ 0.085158] Initializing cgroup subsys ns Nov 11 01:38:53 psql02 kernel: [ 0.085220] Initializing cgroup subsys cpuacct Nov 11 01:38:53 psql02 kernel: [ 0.085277] Initializing cgroup subsys devices Nov 11 01:38:53 psql02 kernel: [ 0.085340] CPU: Trace cache: 12K uops, L1 D cache: 16K Nov 11 01:38:53 psql02 kernel: [ 0.085395] CPU: L2 cache: 1024K Nov 11 01:38:53 psql02 kernel: [ 0.085457] Intel machine check architecture supported. Nov 11 01:38:53 psql02 kernel: [ 0.085520] Intel machine check reporting enabled on CPU#0. Nov 11 01:38:53 psql02 kernel: [ 0.085582] Checking 'hlt' instruction... OK. Nov 11 01:38:53 psql02 kernel: [ 0.100857] SMP alternatives: switching to UP code Nov 11 01:38:53 psql02 kernel: [ 0.124738] Freeing SMP alternatives: 16k freed Nov 11 01:38:53 psql02 kernel: [ 0.124800] ACPI: Core revision 20080321 Nov 11 01:38:53 psql02 kernel: [ 0.129173] ENABLING IO-APIC IRQs Nov 11 01:38:53 psql02 kernel: [ 0.129616] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1 Nov 11 01:38:53 psql02 kernel: [ 0.169608] CPU0: Intel(R) Xeon(TM) CPU 3.20GHz stepping 08 Nov 11 01:38:53 psql02 kernel: [ 0.172010] Brought up 1 CPUs Nov 11 01:38:53 psql02 kernel: [ 0.172010] Total of 1 processors activated (6426.26 BogoMIPS). Nov 11 01:38:53 psql02 kernel: [ 0.172010] CPU0 attaching sched-domain: Nov 11 01:38:53 psql02 kernel: [ 0.172010] domain 0: span 0 Nov 11 01:38:53 psql02 kernel: [ 0.172010] groups: 0 Nov 11 01:38:53 psql02 kernel: [ 0.183569] net_namespace: 660 bytes Nov 11 01:38:53 psql02 kernel: [ 0.183597] Booting paravirtualized kernel on bare hardware Nov 11 01:38:53 psql02 kernel: [ 0.184181] NET: Registered protocol family 16 Nov 11 01:38:53 psql02 kernel: [ 0.188807] ACPI: bus type pci registered Nov 11 01:38:53 psql02 kernel: [ 0.189084] PCI: PCI BIOS revision 2.10 entry at 0xfd9a0, last bus=1 Nov 11 01:38:53 psql02 kernel: [ 0.189111] PCI: Using configuration type 1 for base access Nov 11 01:38:53 psql02 kernel: [ 0.189138] Setting up standard PCI resources Nov 11 01:38:53 psql02 kernel: [ 0.204070] ACPI: EC: Look up EC in DSDT Nov 11 01:38:53 psql02 kernel: [ 0.252080] ACPI: Interpreter enabled Nov 11 01:38:53 psql02 kernel: [ 0.252139] ACPI: (supports S0 S1 S4 S5) Nov 11 01:38:53 psql02 kernel: [ 0.252202] ACPI: Using IOAPIC for interrupt routing Nov 11 01:38:53 psql02 kernel: [ 0.304713] ACPI: PCI Root Bridge [PCI0] (0000:00) Nov 11 01:38:53 psql02 kernel: [ 0.320085] pci 0000:00:07.3: quirk: region 1000-103f claimed by PIIX4 ACPI Nov 11 01:38:53 psql02 kernel: [ 0.320147] pci 0000:00:07.3: quirk: region 1040-104f claimed by PIIX4 SMB Nov 11 01:38:53 psql02 kernel: [ 0.332086] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT] Nov 11 01:38:53 psql02 kernel: [ 0.336092] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 11 14 15) *0, disabled. Nov 11 01:38:53 psql02 kernel: [ 0.336155] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 *9 10 11 14 15) Nov 11 01:38:53 psql02 kernel: [ 0.336217] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11 14 15) Nov 11 01:38:53 psql02 kernel: [ 0.336280] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 11 14 15) *0, disabled. Nov 11 01:38:53 psql02 kernel: [ 0.336681] Linux Plug and Play Support v0.97 (c) Adam Belay Nov 11 01:38:53 psql02 kernel: [ 0.336933] pnp: PnP ACPI init Nov 11 01:38:53 psql02 kernel: [ 0.336995] ACPI: bus type pnp registered Nov 11 01:38:53 psql02 kernel: [ 0.416297] pnp: PnP ACPI: found 12 devices Nov 11 01:38:53 psql02 kernel: [ 0.416360] ACPI: ACPI bus type pnp unregistered Nov 11 01:38:53 psql02 kernel: [ 0.416422] PnPBIOS: Disabled by ACPI PNP Nov 11 01:38:53 psql02 kernel: [ 0.417879] PCI: Using ACPI for IRQ routing Nov 11 01:38:53 psql02 kernel: [ 0.420581] system 00:01: ioport range 0x1000-0x103f has been reserved Nov 11 01:38:53 psql02 kernel: [ 0.420617] system 00:01: ioport range 0x1040-0x104f has been reserved Nov 11 01:38:53 psql02 kernel: [ 0.452380] PCI: Bridge: 0000:00:01.0 Nov 11 01:38:53 psql02 kernel: [ 0.452415] IO window: disabled. Nov 11 01:38:53 psql02 kernel: [ 0.452478] MEM window: disabled. Nov 11 01:38:53 psql02 kernel: [ 0.452540] PREFETCH window: disabled. Nov 11 01:38:53 psql02 kernel: [ 0.452603] PCI: Setting latency timer of device 0000:00:01.0 to 64 Nov 11 01:38:53 psql02 kernel: [ 0.452665] NET: Registered protocol family 2 Nov 11 01:38:53 psql02 kernel: [ 0.453082] IP route cache hash table entries: 16384 (order: 4, 65536 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.456162] TCP established hash table entries: 65536 (order: 7, 524288 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.456224] TCP bind hash table entries: 65536 (order: 7, 524288 bytes) Nov 11 01:38:53 psql02 kernel: [ 0.460161] TCP: Hash tables configured (established 65536 bind 65536) Nov 11 01:38:53 psql02 kernel: [ 0.460224] TCP reno registered Nov 11 01:38:53 psql02 kernel: [ 0.460430] NET: Registered protocol family 1 Nov 11 01:38:53 psql02 kernel: [ 0.464148] checking if image is initramfs... it is Nov 11 01:38:53 psql02 kernel: [ 0.956433] Switched to high resolution mode on CPU 0 Nov 11 01:38:53 psql02 kernel: [ 2.868091] Freeing initrd memory: 6022k freed Nov 11 01:38:53 psql02 kernel: [ 2.868739] Simple Boot Flag at 0x36 set to 0x1 Nov 11 01:38:53 psql02 kernel: [ 2.880214] audit: initializing netlink socket (disabled) Nov 11 01:38:53 psql02 kernel: [ 2.880281] type=2000 audit(1257874695.880:1): initialized Nov 11 01:38:53 psql02 kernel: [ 2.880904] Total HugeTLB memory allocated, 0 Nov 11 01:38:53 psql02 kernel: [ 2.881123] VFS: Disk quotas dquot_6.5.1 Nov 11 01:38:53 psql02 kernel: [ 2.881190] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Nov 11 01:38:53 psql02 kernel: [ 2.881257] msgmni has been set to 1007 Nov 11 01:38:53 psql02 kernel: [ 2.881601] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253) Nov 11 01:38:53 psql02 kernel: [ 2.881668] io scheduler noop registered Nov 11 01:38:53 psql02 kernel: [ 2.881733] io scheduler anticipatory registered Nov 11 01:38:53 psql02 kernel: [ 2.881762] io scheduler deadline registered Nov 11 01:38:53 psql02 kernel: [ 2.881829] io scheduler cfq registered (default) Nov 11 01:38:53 psql02 kernel: [ 2.881897] pci 0000:00:00.0: Limiting direct PCI/PCI transfers Nov 11 01:38:53 psql02 kernel: [ 2.881964] pci 0000:00:0f.0: Boot video device Nov 11 01:38:53 psql02 kernel: [ 2.883285] isapnp: Scanning for PnP cards... Nov 11 01:38:53 psql02 kernel: [ 3.247058] isapnp: No Plug & Play device found Nov 11 01:38:53 psql02 kernel: [ 3.276580] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled Nov 11 01:38:53 psql02 kernel: [ 3.280094] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A Nov 11 01:38:53 psql02 kernel: [ 3.280347] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A Nov 11 01:38:53 psql02 kernel: [ 3.281243] 00:09: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A Nov 11 01:38:53 psql02 kernel: [ 3.281610] 00:0a: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A Nov 11 01:38:53 psql02 kernel: [ 3.292324] brd: module loaded Nov 11 01:38:53 psql02 kernel: [ 3.292700] PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:MOUS] at 0x60,0x64 irq 1,12 Nov 11 01:38:53 psql02 kernel: [ 3.804008] serio: i8042 KBD port at 0x60,0x64 irq 1 Nov 11 01:38:53 psql02 kernel: [ 3.804014] serio: i8042 AUX port at 0x60,0x64 irq 12 Nov 11 01:38:53 psql02 kernel: [ 3.804014] mice: PS/2 mouse device common for all mice Nov 11 01:38:53 psql02 kernel: [ 3.822009] rtc_cmos 00:04: rtc core: registered rtc_cmos as rtc0 Nov 11 01:38:53 psql02 kernel: [ 3.822720] rtc0: alarms up to one month, y3k Nov 11 01:38:53 psql02 kernel: [ 3.825489] cpuidle: using governor ladder Nov 11 01:38:53 psql02 kernel: [ 3.825688] cpuidle: using governor menu Nov 11 01:38:53 psql02 kernel: [ 3.825916] No iBFT detected. Nov 11 01:38:53 psql02 kernel: [ 3.829172] TCP cubic registered Nov 11 01:38:53 psql02 kernel: [ 3.829215] NET: Registered protocol family 17 Nov 11 01:38:53 psql02 kernel: [ 3.830430] Using IPI No-Shortcut mode Nov 11 01:38:53 psql02 kernel: [ 3.830809] input: AT Translated Set 2 keyboard as /class/input/input0 Nov 11 01:38:53 psql02 kernel: [ 3.833322] registered taskstats version 1 Nov 11 01:38:53 psql02 kernel: [ 3.861009] rtc_cmos 00:04: setting system clock to 2009-11-10 17:38:22 UTC (1257874702) Nov 11 01:38:53 psql02 kernel: [ 3.904340] Freeing unused kernel memory: 244k freed Nov 11 01:38:53 psql02 kernel: [ 4.292707] ACPI: ACPI0007:00 is registered as cooling_device0 Nov 11 01:38:53 psql02 kernel: [ 4.296430] ACPI: Processor [CPU0] (supports 8 throttling states) Nov 11 01:38:53 psql02 kernel: [ 5.281404] Uniform Multi-Platform E-IDE driver Nov 11 01:38:53 psql02 kernel: [ 5.281490] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx Nov 11 01:38:53 psql02 kernel: [ 5.308740] PIIX4: IDE controller (0x8086:0x7111 rev 0x01) at PCI slot 0000:00:07.1 Nov 11 01:38:53 psql02 kernel: [ 5.308826] PIIX4: not 100% native mode: will probe irqs later Nov 11 01:38:53 psql02 kernel: [ 5.308912] PIIX4: IDE port disabled Nov 11 01:38:53 psql02 kernel: [ 5.308998] ide0: BM-DMA at 0x1050-0x1057 Nov 11 01:38:53 psql02 kernel: [ 5.309084] Probing IDE interface ide0... Nov 11 01:38:53 psql02 kernel: [ 5.392874] SCSI subsystem initialized Nov 11 01:38:53 psql02 kernel: [ 5.393529] pcnet32.c:v1.35 21.Apr.2008 tsbogend@alpha.franken.de Nov 11 01:38:53 psql02 kernel: [ 5.420309] Fusion MPT base driver 3.04.06 Nov 11 01:38:53 psql02 kernel: [ 5.420332] Copyright (c) 1999-2007 LSI Corporation Nov 11 01:38:53 psql02 kernel: [ 5.420960] Fusion MPT SPI Host driver 3.04.06 Nov 11 01:38:53 psql02 kernel: [ 5.480847] Floppy drive(s): fd0 is 1.44M Nov 11 01:38:53 psql02 kernel: [ 5.500050] FDC 0 is a post-1991 82077 Nov 11 01:38:53 psql02 kernel: [ 6.044156] hda: VMware Virtual IDE CDROM Drive, ATAPI CD/DVD-ROM drive Nov 11 01:38:53 psql02 kernel: [ 6.380385] hda: host max PIO4 wanted PIO255(auto-tune) selected PIO4 Nov 11 01:38:53 psql02 kernel: [ 6.380895] hda: UDMA/33 mode selected Nov 11 01:38:53 psql02 kernel: [ 6.381237] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 Nov 11 01:38:53 psql02 kernel: [ 6.385073] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 17 (level, low) -> IRQ 17 Nov 11 01:38:53 psql02 kernel: [ 6.385236] mptbase: ioc0: Initiating bringup Nov 11 01:38:53 psql02 kernel: [ 6.385639] No dock devices found. Nov 11 01:38:53 psql02 kernel: [ 6.401175] libata version 3.00 loaded. Nov 11 01:38:53 psql02 kernel: [ 6.464197] ioc0: LSI53C1030 B0: Capabilities={Initiator} Nov 11 01:38:53 psql02 kernel: [ 6.604470] scsi0 : ioc0: LSI53C1030 B0, FwRev=01032920h, Ports=1, MaxQ=128, IRQ=17 Nov 11 01:38:53 psql02 kernel: [ 6.716507] ACPI: PCI Interrupt 0000:00:11.0[A] -> GSI 18 (level, low) -> IRQ 18 Nov 11 01:38:53 psql02 kernel: [ 6.716669] pcnet32: PCnet/PCI II 79C970A at 0x1400, 00:0c:29:ea:97:39 assigned IRQ 18. Nov 11 01:38:53 psql02 kernel: [ 6.720189] eth0: registered as PCnet/PCI II 79C970A Nov 11 01:38:53 psql02 kernel: [ 6.720445] pcnet32: 1 cards_found. Nov 11 01:38:53 psql02 kernel: [ 6.732188] scsi 0:0:0:0: Direct-Access VMware Virtual disk 1.0 PQ: 0 ANSI: 2 Nov 11 01:38:53 psql02 kernel: [ 6.732351] target0:0:0: Beginning Domain Validation Nov 11 01:38:53 psql02 kernel: [ 6.733703] target0:0:0: Domain Validation skipping write tests Nov 11 01:38:53 psql02 kernel: [ 6.733743] target0:0:0: Ending Domain Validation Nov 11 01:38:53 psql02 kernel: [ 6.733906] target0:0:0: FAST-40 WIDE SCSI 80.0 MB/s ST (25 ns, offset 127) Nov 11 01:38:53 psql02 kernel: [ 6.765446] hda: ATAPI 1X CD-ROM drive, 32kB Cache Nov 11 01:38:53 psql02 rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="1748" x-info="http://www.rsyslog.com"] restart Nov 11 01:38:53 psql02 kernel: [ 6.765609] Uniform CD-ROM driver Revision: 3.20 Nov 11 01:38:53 psql02 kernel: [ 6.792513] Driver 'sd' needs updating - please use bus_type methods Nov 11 01:38:53 psql02 kernel: [ 6.792676] sd 0:0:0:0: [sda] 12582912 512-byte hardware sectors (6442 MB) Nov 11 01:38:53 psql02 kernel: [ 6.792839] sd 0:0:0:0: [sda] Test WP failed, assume Write Enabled Nov 11 01:38:53 psql02 kernel: [ 6.793002] sd 0:0:0:0: [sda] Cache data unavailable Nov 11 01:38:53 psql02 kernel: [ 6.793049] sd 0:0:0:0: [sda] Assuming drive cache: write through Nov 11 01:38:53 psql02 kernel: [ 6.793212] sd 0:0:0:0: [sda] 12582912 512-byte hardware sectors (6442 MB) Nov 11 01:38:53 psql02 kernel: [ 6.793355] sd 0:0:0:0: [sda] Test WP failed, assume Write Enabled Nov 11 01:38:53 psql02 kernel: [ 6.793420] sd 0:0:0:0: [sda] Cache data unavailable Nov 11 01:38:53 psql02 kernel: [ 6.793428] sd 0:0:0:0: [sda] Assuming drive cache: write through Nov 11 01:38:53 psql02 kernel: [ 6.793591] sda: sda1 sda2 sda3 Nov 11 01:38:53 psql02 kernel: [ 6.808190] sd 0:0:0:0: [sda] Attached SCSI disk Nov 11 01:38:53 psql02 kernel: [ 7.000122] PM: Starting manual resume from disk Nov 11 01:38:53 psql02 kernel: [ 7.024874] EXT3-fs: INFO: recovery required on readonly filesystem. Nov 11 01:38:53 psql02 kernel: [ 7.024903] EXT3-fs: write access will be enabled during recovery. Nov 11 01:38:53 psql02 kernel: [ 8.093349] kjournald starting. Commit interval 5 seconds Nov 11 01:38:53 psql02 kernel: [ 8.097525] EXT3-fs: recovery complete. Nov 11 01:38:53 psql02 kernel: [ 8.197785] EXT3-fs: mounted filesystem with ordered data mode. Nov 11 01:38:53 psql02 kernel: [ 22.312785] udevd version 125 started Nov 11 01:38:53 psql02 kernel: [ 23.731214] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 Nov 11 01:38:53 psql02 kernel: [ 23.808115] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 Nov 11 01:38:53 psql02 kernel: [ 23.836185] Linux agpgart interface v0.103 Nov 11 01:38:53 psql02 kernel: [ 23.871047] agpgart: Detected an Intel 440BX Chipset. Nov 11 01:38:53 psql02 kernel: [ 23.874806] agpgart: AGP aperture is 256M @ 0x0 Nov 11 01:38:53 psql02 kernel: [ 23.910920] piix4_smbus 0000:00:07.3: Found 0000:00:07.3 device Nov 11 01:38:53 psql02 kernel: [ 23.911234] piix4_smbus 0000:00:07.3: Host SMBus controller not enabled! Nov 11 01:38:53 psql02 kernel: [ 24.452500] input: Power Button (FF) as /class/input/input1 Nov 11 01:38:53 psql02 kernel: [ 24.482705] ACPI: Power Button (FF) [PWRF] Nov 11 01:38:53 psql02 kernel: [ 24.497236] ACPI: AC Adapter [ACAD] (on-line) Nov 11 01:38:53 psql02 kernel: [ 25.081329] input: PC Speaker as /class/input/input2 Nov 11 01:38:53 psql02 kernel: [ 25.455400] input: ImPS/2 Generic Wheel Mouse as /class/input/input3 Nov 11 01:38:53 psql02 kernel: [ 25.497120] parport_pc 00:08: reported by Plug and Play ACPI Nov 11 01:38:53 psql02 kernel: [ 25.498716] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE] Nov 11 01:38:53 psql02 kernel: [ 25.773918] Error: Driver 'pcspkr' is already registered, aborting... Nov 11 01:38:53 psql02 kernel: [ 29.692022] Adding 248996k swap on /dev/sda2. Priority:-1 extents:1 across:248996k Nov 11 01:38:53 psql02 kernel: [ 31.156094] EXT3 FS on sda1, internal journal Nov 11 01:38:53 psql02 kernel: [ 31.432939] loop: module loaded Nov 11 01:38:53 psql02 kernel: [ 32.674968] fuse init (API version 7.9) Nov 11 01:38:53 psql02 kernel: [ 33.788072] eth0: link up Nov 11 01:38:53 psql02 lrmd: [1744]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Nov 11 01:38:53 psql02 lrmd: [1744]: info: G_main_add_SignalHandler: Added signal handler for signal 10 Nov 11 01:38:53 psql02 lrmd: [1744]: info: G_main_add_SignalHandler: Added signal handler for signal 12 Nov 11 01:38:53 psql02 lrmd: [1744]: info: Started. Nov 11 01:38:54 psql02 stonithd: [1742]: info: G_main_add_SignalHandler: Added signal handler for signal 10 Nov 11 01:38:54 psql02 stonithd: [1742]: info: G_main_add_SignalHandler: Added signal handler for signal 12 Nov 11 01:38:54 psql02 stonithd: [1742]: info: Stack hogger failed 0xffffffff Nov 11 01:38:54 psql02 crmd: [1747]: info: Invoked: /usr/lib/heartbeat/crmd Nov 11 01:38:54 psql02 crmd: [1747]: info: main: CRM Hg Version: cebe2b6ff49b36b29a3bd7ada1c4701c7470febe Nov 11 01:38:54 psql02 cib: [1743]: info: Invoked: /usr/lib/heartbeat/cib Nov 11 01:38:54 psql02 cib: [1743]: info: G_main_add_TriggerHandler: Added signal manual handler Nov 11 01:38:54 psql02 cib: [1743]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Nov 11 01:38:54 psql02 attrd: [1745]: info: Invoked: /usr/lib/heartbeat/attrd Nov 11 01:38:54 psql02 attrd: [1745]: info: main: Starting up Nov 11 01:38:54 psql02 attrd: [1745]: info: crm_cluster_connect: Connecting to OpenAIS Nov 11 01:38:54 psql02 attrd: [1745]: info: init_ais_connection: Creating connection to our AIS plugin Nov 11 01:38:54 psql02 pengine: [1746]: info: Invoked: /usr/lib/heartbeat/pengine Nov 11 01:38:54 psql02 pengine: [1746]: info: main: Starting pengine Nov 11 01:38:54 psql02 crmd: [1747]: info: crmd_init: Starting crmd Nov 11 01:38:54 psql02 attrd: [1745]: info: init_ais_connection: AIS connection established Nov 11 01:38:54 psql02 cib: [1743]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.xml (digest: /var/lib/heartbeat/crm/cib.xml.sig) Nov 11 01:38:54 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Recorded connection 0x87c26f0 for attrd/1745 Nov 11 01:38:54 psql02 attrd: [1745]: info: get_ais_nodeid: Server details: id=389374986 uname=psql02 Nov 11 01:38:54 psql02 attrd: [1745]: info: crm_new_peer: Node psql02 now has id: 389374986 Nov 11 01:38:54 psql02 attrd: [1745]: info: crm_new_peer: Node 389374986 is now known as psql02 Nov 11 01:38:54 psql02 attrd: [1745]: info: main: Cluster connection active Nov 11 01:38:54 psql02 attrd: [1745]: info: main: Accepting attribute updates Nov 11 01:38:54 psql02 attrd: [1745]: info: main: Starting mainloop... Nov 11 01:38:54 psql02 crmd: [1747]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Nov 11 01:38:54 psql02 cib: [1743]: info: startCib: CIB Initialization completed successfully Nov 11 01:38:54 psql02 cib: [1743]: info: crm_cluster_connect: Connecting to OpenAIS Nov 11 01:38:54 psql02 cib: [1743]: info: init_ais_connection: Creating connection to our AIS plugin Nov 11 01:38:54 psql02 cib: [1743]: info: init_ais_connection: AIS connection established Nov 11 01:38:54 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Recorded connection 0x87c3c40 for cib/1743 Nov 11 01:38:54 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Sending membership update 108 to cib Nov 11 01:38:54 psql02 cib: [1743]: info: get_ais_nodeid: Server details: id=389374986 uname=psql02 Nov 11 01:38:54 psql02 cib: [1743]: info: crm_new_peer: Node psql02 now has id: 389374986 Nov 11 01:38:54 psql02 cib: [1743]: info: crm_new_peer: Node 389374986 is now known as psql02 Nov 11 01:38:54 psql02 cib: [1743]: info: cib_init: Starting cib mainloop Nov 11 01:38:54 psql02 cib: [1743]: info: ais_dispatch: Membership 108: quorum still lost Nov 11 01:38:54 psql02 cib: [1743]: info: crm_update_peer: Node psql02: id=389374986 state=member (new) addr=r(0) ip(10.100.53.151) (new) votes=1 (new) born=0 seen=108 proc=00000000000000000000000000013312 (new) Nov 11 01:38:54 psql02 stonithd: [1742]: info: crm_cluster_connect: Connecting to OpenAIS Nov 11 01:38:54 psql02 stonithd: [1742]: info: init_ais_connection: Creating connection to our AIS plugin Nov 11 01:38:54 psql02 cib: [1761]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-54.raw Nov 11 01:38:54 psql02 cib: [1761]: info: write_cib_contents: Wrote version 0.781.0 of the CIB to disk (digest: 378dcb51810fdfb80e50cdad468c1e8b) Nov 11 01:38:54 psql02 cib: [1761]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.IXtHDQ (digest: /var/lib/heartbeat/crm/cib.K7Xozg) Nov 11 01:38:55 psql02 stonithd: [1742]: info: init_ais_connection: AIS connection established Nov 11 01:38:55 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Recorded connection 0x87c3f10 for stonithd/1742 Nov 11 01:38:55 psql02 stonithd: [1742]: info: get_ais_nodeid: Server details: id=389374986 uname=psql02 Nov 11 01:38:55 psql02 stonithd: [1742]: info: crm_new_peer: Node psql02 now has id: 389374986 Nov 11 01:38:55 psql02 stonithd: [1742]: info: crm_new_peer: Node 389374986 is now known as psql02 Nov 11 01:38:55 psql02 stonithd: [1742]: notice: /usr/lib/heartbeat/stonithd start up successfully. Nov 11 01:38:55 psql02 stonithd: [1742]: info: G_main_add_SignalHandler: Added signal handler for signal 17 Nov 11 01:38:55 psql02 crmd: [1747]: info: do_cib_control: CIB connection established Nov 11 01:38:55 psql02 crmd: [1747]: info: crm_cluster_connect: Connecting to OpenAIS Nov 11 01:38:55 psql02 crmd: [1747]: info: init_ais_connection: Creating connection to our AIS plugin Nov 11 01:38:55 psql02 crmd: [1747]: info: init_ais_connection: AIS connection established Nov 11 01:38:55 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Recorded connection 0x87c4278 for crmd/1747 Nov 11 01:38:55 psql02 corosync[1698]: [pcmk ] info: pcmk_ipc: Sending membership update 108 to crmd Nov 11 01:38:55 psql02 crmd: [1747]: info: get_ais_nodeid: Server details: id=389374986 uname=psql02 Nov 11 01:38:55 psql02 crmd: [1747]: info: crm_new_peer: Node psql02 now has id: 389374986 Nov 11 01:38:55 psql02 crmd: [1747]: info: crm_new_peer: Node 389374986 is now known as psql02 Nov 11 01:38:55 psql02 crmd: [1747]: info: do_ha_control: Connected to the cluster Nov 11 01:38:55 psql02 crmd: [1747]: info: do_started: Delaying start, CCM (0000000000100000) not connected Nov 11 01:38:55 psql02 crmd: [1747]: info: crmd_init: Starting crmd's mainloop Nov 11 01:38:55 psql02 crmd: [1747]: info: ais_dispatch: Membership 108: quorum still lost Nov 11 01:38:55 psql02 crmd: [1747]: info: crm_update_peer: Node psql02: id=389374986 state=member (new) addr=r(0) ip(10.100.53.151) (new) votes=1 (new) born=0 seen=108 proc=00000000000000000000000000013312 (new) Nov 11 01:38:55 psql02 crmd: [1747]: info: do_started: Delaying start, Config not read (0000000000000040) Nov 11 01:38:55 psql02 crmd: [1747]: info: config_query_callback: Checking for expired actions every 900000ms Nov 11 01:38:55 psql02 crmd: [1747]: info: do_started: The local CRM is operational Nov 11 01:38:55 psql02 corosync[1698]: [pcmk ] info: update_expected_votes: Expected quorum votes 1024 -> 2 Nov 11 01:38:55 psql02 crmd: [1747]: info: do_state_transition: State transition S_STARTING -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_started ] Nov 11 01:38:55 psql02 /usr/sbin/cron[1791]: (CRON) INFO (pidfile fd = 3) Nov 11 01:38:55 psql02 /usr/sbin/cron[1792]: (CRON) STARTUP (fork ok) Nov 11 01:38:55 psql02 /usr/sbin/cron[1792]: (CRON) INFO (Running @reboot jobs) Nov 11 01:38:55 psql02 logd: [1801]: info: logd started with default configuration. Nov 11 01:38:55 psql02 logd: [1802]: info: G_main_add_SignalHandler: Added signal handler for signal 15 Nov 11 01:38:55 psql02 logd: [1801]: info: G_main_add_SignalHandler: Added signal handler for signal 15 Nov 11 01:38:56 psql02 crmd: [1747]: info: ais_dispatch: Membership 108: quorum still lost Nov 11 01:38:57 psql02 kernel: [ 43.528016] NET: Registered protocol family 10 Nov 11 01:38:57 psql02 kernel: [ 43.534287] lo: Disabled Privacy Extensions Nov 11 01:38:59 psql02 attrd: [1745]: info: cib_connect: Connected to the CIB after 1 signon attempts Nov 11 01:38:59 psql02 attrd: [1745]: info: cib_connect: Sending full refresh Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] notice: pcmk_peer_update: Transitional membership event on ring 112: memb=1, new=0, lost=0 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: pcmk_peer_update: memb: psql02 389374986 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] notice: pcmk_peer_update: Stable membership event on ring 112: memb=2, new=1, lost=0 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: Creating entry for node 372597770 born on 112 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: Node 372597770/unknown is now: member Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: pcmk_peer_update: NEW: .pending. 372597770 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: pcmk_peer_update: MEMB: .pending. 372597770 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: pcmk_peer_update: MEMB: psql02 389374986 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: send_member_notification: Sending membership update 112 to 2 children Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: 0x87bf228 Node 389374986 ((null)) born on: 112 Nov 11 01:39:06 psql02 corosync[1698]: [TOTEM ] A processor joined or left the membership and a new membership was formed. Nov 11 01:39:06 psql02 crmd: [1747]: notice: ais_dispatch: Membership 112: quorum acquired Nov 11 01:39:06 psql02 cib: [1743]: notice: ais_dispatch: Membership 112: quorum acquired Nov 11 01:39:06 psql02 crmd: [1747]: info: crm_new_peer: Node now has id: 372597770 Nov 11 01:39:06 psql02 cib: [1743]: info: crm_new_peer: Node now has id: 372597770 Nov 11 01:39:06 psql02 crmd: [1747]: info: crm_update_peer: Node (null): id=372597770 state=member (new) addr=r(0) ip(10.100.53.150) votes=0 born=0 seen=112 proc=00000000000000000000000000000000 Nov 11 01:39:06 psql02 cib: [1743]: info: crm_update_peer: Node (null): id=372597770 state=member (new) addr=r(0) ip(10.100.53.150) votes=0 born=0 seen=112 proc=00000000000000000000000000000000 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: 0x87b9958 Node 372597770 (psql01) born on: 112 Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: 0x87b9958 Node 372597770 now known as psql01 (was: (null)) Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: Node psql01 now has process list: 00000000000000000000000000013312 (78610) Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: update_member: Node psql01 now has 1 quorum votes (was 0) Nov 11 01:39:06 psql02 corosync[1698]: [pcmk ] info: send_member_notification: Sending membership update 112 to 2 children Nov 11 01:39:06 psql02 crmd: [1747]: info: ais_dispatch: Membership 112: quorum retained Nov 11 01:39:06 psql02 crmd: [1747]: info: crm_get_peer: Node 372597770 is now known as psql01 Nov 11 01:39:06 psql02 crmd: [1747]: info: crm_update_peer: Node psql01: id=372597770 state=member addr=r(0) ip(10.100.53.150) votes=1 (new) born=112 seen=112 proc=00000000000000000000000000013312 (new) Nov 11 01:39:06 psql02 cib: [1743]: info: ais_dispatch: Membership 112: quorum retained Nov 11 01:39:06 psql02 cib: [1743]: info: crm_get_peer: Node 372597770 is now known as psql01 Nov 11 01:39:06 psql02 cib: [1743]: info: crm_update_peer: Node psql01: id=372597770 state=member addr=r(0) ip(10.100.53.150) votes=1 (new) born=112 seen=112 proc=00000000000000000000000000013312 (new) Nov 11 01:39:06 psql02 corosync[1698]: [MAIN ] Completed service synchronization, ready to provide service. Nov 11 01:39:08 psql02 kernel: [ 54.837072] eth0: no IPv6 routers present Nov 11 01:39:56 psql02 crmd: [1747]: info: crm_timer_popped: Election Trigger (I_DC_TIMEOUT) just popped! Nov 11 01:39:56 psql02 crmd: [1747]: WARN: do_log: FSA: Input I_DC_TIMEOUT from crm_timer_popped() received in state S_PENDING Nov 11 01:39:56 psql02 crmd: [1747]: info: do_state_transition: State transition S_PENDING -> S_ELECTION [ input=I_DC_TIMEOUT cause=C_TIMER_POPPED origin=crm_timer_popped ] Nov 11 01:39:56 psql02 crmd: [1747]: info: do_state_transition: State transition S_ELECTION -> S_PENDING [ input=I_PENDING cause=C_FSA_INTERNAL origin=do_election_count_vote ] Nov 11 01:39:56 psql02 crmd: [1747]: info: do_dc_release: DC role released Nov 11 01:39:56 psql02 crmd: [1747]: info: do_te_control: Transitioner is now inactive Nov 11 01:39:56 psql02 crmd: [1747]: info: update_dc: Set DC to psql01 (3.0.1) Nov 11 01:39:57 psql02 cib: [1743]: info: cib_process_request: Operation complete: op cib_sync for section 'all' (origin=psql01/crmd/18, version=0.781.0): ok (rc=0) Nov 11 01:39:57 psql02 crmd: [1747]: info: update_attrd: Connecting to attrd... Nov 11 01:39:57 psql02 attrd: [1745]: info: find_hash_entry: Creating hash entry for terminate Nov 11 01:39:57 psql02 attrd: [1745]: info: find_hash_entry: Creating hash entry for shutdown Nov 11 01:39:57 psql02 crmd: [1747]: info: do_state_transition: State transition S_PENDING -> S_NOT_DC [ input=I_NOT_DC cause=C_HA_MESSAGE origin=do_cl_join_finalize_respond ] Nov 11 01:39:57 psql02 attrd: [1745]: info: attrd_local_callback: Sending full refresh (origin=crmd) Nov 11 01:39:57 psql02 attrd: [1745]: info: attrd_trigger_update: Sending flush op to all hosts for: terminate () Nov 11 01:39:57 psql02 attrd: [1745]: info: attrd_trigger_update: Sending flush op to all hosts for: shutdown () Nov 11 01:39:57 psql02 crmd: [1747]: info: erase_xpath_callback: Deletion of "//node_state[@uname='psql02']/transient_attributes": ok (rc=0) Nov 11 01:39:57 psql02 crmd: [1747]: info: erase_xpath_callback: Deletion of "//node_state[@uname='psql02']/lrm": ok (rc=0) Nov 11 01:39:58 psql02 attrd: [1745]: info: crm_new_peer: Node psql01 now has id: 372597770 Nov 11 01:39:58 psql02 attrd: [1745]: info: crm_new_peer: Node 372597770 is now known as psql01 Nov 11 01:39:58 psql02 cib: [2130]: info: write_cib_contents: Archived previous version as /var/lib/heartbeat/crm/cib-55.raw Nov 11 01:39:58 psql02 lrmd: [1744]: notice: lrmd_rsc_new(): No lrm_rprovider field in message Nov 11 01:39:58 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=8:1:7:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=st-ssh:1_monitor_0 ) Nov 11 01:39:58 psql02 lrmd: [1744]: info: rsc:st-ssh:1:2: monitor Nov 11 01:39:58 psql02 crmd: [1747]: info: process_lrm_event: LRM operation st-ssh:1_monitor_0 (call=2, rc=7, cib-update=10, confirmed=true) not running Nov 11 01:39:58 psql02 cib: [2130]: info: write_cib_contents: Wrote version 0.782.0 of the CIB to disk (digest: 78e342ca4186386064997dcbf87356c3) Nov 11 01:39:58 psql02 cib: [2130]: info: retrieveCib: Reading cluster configuration from: /var/lib/heartbeat/crm/cib.v1CFuq (digest: /var/lib/heartbeat/crm/cib.Oeilhq) Nov 11 01:39:58 psql02 lrmd: [1744]: notice: lrmd_rsc_new(): No lrm_rprovider field in message Nov 11 01:39:58 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=9:1:7:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-psql_monitor_0 ) Nov 11 01:39:58 psql02 lrmd: [1744]: info: rsc:failover-psql:3: monitor Nov 11 01:40:00 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=10:1:7:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-ip_monitor_0 ) Nov 11 01:40:00 psql02 lrmd: [1744]: info: rsc:failover-ip:4: monitor Nov 11 01:40:00 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-psql_monitor_0 (call=3, rc=7, cib-update=11, confirmed=true) not running Nov 11 01:40:00 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-ip_monitor_0 (call=4, rc=7, cib-update=12, confirmed=true) not running Nov 11 01:40:01 psql02 attrd: [1745]: info: find_hash_entry: Creating hash entry for probe_complete Nov 11 01:40:01 psql02 attrd: [1745]: info: attrd_trigger_update: Sending flush op to all hosts for: probe_complete (true) Nov 11 01:40:01 psql02 attrd: [1745]: info: attrd_perform_update: Sent update 10: probe_complete=true Nov 11 01:40:03 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=6:3:0:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=st-ssh:1_start_0 ) Nov 11 01:40:03 psql02 lrmd: [1744]: info: rsc:st-ssh:1:5: start Nov 11 01:40:03 psql02 lrmd: [2145]: info: Try to start STONITH resource : Device=external/ssh Nov 11 01:40:03 psql02 lrmd: [1744]: debug: stonithRA plugin: provider attribute is not needed and will be ignored. Nov 11 01:40:03 psql02 crmd: [1747]: info: process_lrm_event: LRM operation st-ssh:1_start_0 (call=5, rc=0, cib-update=13, confirmed=true) ok Nov 11 01:40:03 psql02 stonithd: [1742]: info: st-ssh:1 stonith resource started Nov 11 01:42:22 psql02 attrd: [1745]: info: find_hash_entry: Creating hash entry for fail-count-failover-psql Nov 11 01:42:22 psql02 attrd: [1745]: info: find_hash_entry: Creating hash entry for last-failure-failover-psql Nov 11 01:42:22 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=19:6:0:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-ip_start_0 ) Nov 11 01:42:22 psql02 lrmd: [1744]: info: rsc:failover-ip:6: start Nov 11 01:42:22 psql02 IPaddr[2179]: INFO: Using calculated nic for 10.100.53.100: eth0 Nov 11 01:42:22 psql02 lrmd: [1744]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:42:22 INFO: Using calculated nic for 10.100.53.100: eth0 Nov 11 01:42:22 psql02 IPaddr[2179]: INFO: Using calculated netmask for 10.100.53.100: 255.255.255.255 Nov 11 01:42:22 psql02 lrmd: [1744]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:42:22 INFO: Using calculated netmask for 10.100.53.100: 255.255.255.255 Nov 11 01:42:23 psql02 IPaddr[2179]: INFO: eval ifconfig eth0:0 10.100.53.100 netmask 255.255.255.255 broadcast 10.100.53.100 Nov 11 01:42:23 psql02 lrmd: [1744]: info: RA output: (failover-ip:start:stderr) 2009/11/11_01:42:22 INFO: eval ifconfig eth0:0 10.100.53.100 netmask 255.255.255.255 broadcast 10.100.53.100 Nov 11 01:42:23 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-ip_start_0 (call=6, rc=0, cib-update=14, confirmed=true) ok Nov 11 01:42:23 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=16:6:0:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-psql_start_0 ) Nov 11 01:42:23 psql02 lrmd: [1744]: info: rsc:failover-psql:7: start Nov 11 01:42:23 psql02 lrmd: [2268]: WARN: For LSB init script, no additional parameters are needed. Nov 11 01:42:23 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=20:6:0:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-ip_monitor_5000 ) Nov 11 01:42:23 psql02 lrmd: [1744]: info: RA output: (failover-psql:start:stdout) Starting PostgreSQL 8.3 database server: Nov 11 01:42:23 psql02 lrmd: [1744]: info: RA output: (failover-psql:start:stdout) main Nov 11 01:42:23 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-ip_monitor_5000 (call=8, rc=0, cib-update=15, confirmed=false) ok Nov 11 01:42:30 psql02 lrmd: [1744]: info: RA output: (failover-psql:start:stdout) . Nov 11 01:42:30 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-psql_start_0 (call=7, rc=0, cib-update=16, confirmed=true) ok Nov 11 01:42:31 psql02 crmd: [1747]: info: do_lrm_rsc_op: Performing key=17:6:0:b3f6f6c3-0d0f-42a7-b357-36c601930ddf op=failover-psql_monitor_30000 ) Nov 11 01:42:31 psql02 crmd: [1747]: info: process_lrm_event: LRM operation failover-psql_monitor_30000 (call=9, rc=0, cib-update=17, confirmed=false) ok Nov 11 01:43:33 psql02 pengine: [2456]: info: crm_log_init: Changed active directory to /var/lib/heartbeat/cores/root Nov 11 01:43:33 psql02 pengine: [2456]: info: Invoked: /usr/lib/heartbeat/pengine metadata Nov 11 01:43:33 psql02 crm_shadow: [2458]: info: Invoked: crm_shadow Nov 11 01:43:33 psql02 crm_shadow: [2460]: info: Invoked: crm_shadow Nov 11 01:43:33 psql02 crm_shadow: [2462]: info: Invoked: crm_shadow Nov 11 01:43:33 psql02 cibadmin: [2463]: info: Invoked: cibadmin -Ql Nov 11 01:48:54 psql02 cib: [1743]: info: cib_stats: Processed 64 operations (468.00us average, 0% utilization) in the last 10min