Heartbeat, DRBD, PostgreSQL: Fehler und Serverneustart

[Judge]

Hallo zusammen,

ich habe die Suchfunktion dieses Forums bereits bemüht. Dabei bin ich auf einen alten Thread von 2007 gestoßen, bei dem offenbar dieselben Probleme aufgetreten sind, der jedoch nicht beantwortet wurde: Problem mit Heartbeat.
Da das gleiche Problem auch 7 Jahre später noch in Debian vorhanden zu sein scheint, würde ich das Thema gerne noch einmal mit meinem aktuellen Problem aufgreifen, da mein Server auch jedes Mal hart resettet wird, wenn Heartbeat beendet wird (STONITH ist nicht konfiguriert).

Ich habe zwei Nodes:

• prod-cl3
• prod-cl4

Ich habe in der Datei /etc/ha.d/haresources (welche natürlich auf beiden Nodes identisch ist) nur eine einzige Zeile/Resource Group definiert:

Code: Alles auswählen

prod-cl3  drbddisk::var_lib_postgres Filesystem::/dev/drbd0::/var/lib/postgresql::ext4 192.168.20.18/24/eth0

Heartbeat funktioniert auf beiden Nodes genau wie es soll: Die Ressourcen werden beim starten von links nach rechts abgearbeitet und alles ist gut; die Ressourcen werden von Node prod-cl3 zugewiesen.
Beendet man den Heartbeat auf prod-cl3, holt prod-cl4 sich diese.
Startet man den Heartbeat auf prod-cl3 wieder, gehen die Ressourcen zurück an diesen ("auto_failback on" in ha.cf ist gesetzt).

Erweitere ich diese Resource Group jedoch um den Eintrag "postgresql", gibt es Probleme, die ich im folgendem gerne erklären werde:

Code: Alles auswählen

prod-cl3  drbddisk::var_lib_postgres Filesystem::/dev/drbd0::/var/lib/postgresql::ext4 192.168.20.18/24/eth0 postgresql

Da es die Datei /etc/ha.d/resource.d/postgresql nicht gibt, sollte heartbeat wissen, das es um /etc/init.d/postgresql geht und diese verwenden.

1. Startet man heartbeat, wird postgresql zwar in der Liste der Ressourcen die in's ha-debug - Log geschrieben werden aufgelistet (Acquiring resource group), es wird jedoch scheinbar nicht gestartet, da postgresql im weiteren Verlauf des Logs nicht mehr auftaucht:

   Code: Alles auswählen

   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: WARN: Core dumps could be lost if multiple dumps occur.
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: WARN: Consider setting non-default value in /proc/sys/kernel/core_pattern (or equivalent) for maximum supportability
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: WARN: Consider setting /proc/sys/kernel/core_uses_pid (or equivalent) to 1 for maximum supportability
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: info: Pacemaker support: false
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: WARN: Logging daemon is disabled --enabling logging daemon is recommended
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: info: **************************
   Jul 30 13:51:11 prod-cl3 heartbeat: [20846]: info: Configuration validated. Starting heartbeat 3.0.5
   Jul 30 13:51:11 prod-cl3 heartbeat: [20847]: info: heartbeat: version 3.0.5
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: Heartbeat generation: 1406638883
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: glib: ucast: write socket priority set to IPTOS_LOWDELAY on eth1
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: glib: ucast: bound send socket to device: eth1
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: glib: ucast: bound receive socket to device: eth1
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: glib: ucast: started on port 694 interface eth1 to 10.250.250.17
   Jul 30 13:51:12 prod-cl3 heartbeat: [20847]: info: Local status now set to: 'up'
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: WARN: node prod-cl4: is dead
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: info: Comm_now_up(): updating status to active
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: info: Local status now set to: 'active'
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: WARN: No STONITH device configured.
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: WARN: Shared disks are not protected.
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: info: Resources being acquired from prod-cl4.
   Jul 30 13:52:43 prod-cl3 heartbeat: [20876]: debug: notify_world: setting SIGCHLD Handler to SIG_DFL
   harc[20876]:    2014/07/30_13:52:43 info: Running /etc/ha.d//rc.d/status status
   Jul 30 13:52:43 prod-cl3 heartbeat: [20877]: info: Local Resource acquisition completed.
   mach_down[20910]:       2014/07/30_13:52:43 info: /usr/share/heartbeat/mach_down: nice_failback: foreign resources acquired
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: debug: StartNextRemoteRscReq(): child count 2
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: info: mach_down takeover complete.
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: info: Initial resource acquisition complete (mach_down)
   Jul 30 13:52:43 prod-cl3 heartbeat: [20847]: debug: StartNextRemoteRscReq(): child count 1
   mach_down[20910]:       2014/07/30_13:52:43 info: mach_down takeover complete for node prod-cl4.
   Jul 30 13:52:43 prod-cl3 heartbeat: [20968]: debug: notify_world: setting SIGCHLD Handler to SIG_DFL
   harc[20968]:    2014/07/30_13:52:43 info: Running /etc/ha.d//rc.d/ip-request-resp ip-request-resp
   ip-request-resp[20968]: 2014/07/30_13:52:43 received ip-request-resp drbddisk::var_lib_postgres OK yes
   ResourceManager[20989]: 2014/07/30_13:52:43 info: Acquiring resource group: prod-cl3 drbddisk::var_lib_postgres Filesystem::/dev/drbd0::/var/lib/postgresql::ext4 192.168.20.18/24/eth0 postgresql
   ResourceManager[20989]: 2014/07/30_13:52:43 info: Running /etc/ha.d/resource.d/drbddisk var_lib_postgres start
   Filesystem[21057]:      2014/07/30_13:52:43 INFO:  Resource is stopped
   ResourceManager[20989]: 2014/07/30_13:52:43 info: Running /etc/ha.d/resource.d/Filesystem /dev/drbd0 /var/lib/postgresql ext4 start
   Filesystem[21131]:      2014/07/30_13:52:43 INFO: Running start for /dev/drbd0 on /var/lib/postgresql
   FATAL: Module scsi_hostadapter not found.
   Filesystem[21125]:      2014/07/30_13:52:43 INFO:  Success
   INFO:  Success
   IPaddr[21200]:  2014/07/30_13:52:43 INFO:  Resource is stopped
   ResourceManager[20989]: 2014/07/30_13:52:43 info: Running /etc/ha.d/resource.d/IPaddr 192.168.20.18/24/eth0 start
   IPaddr[21282]:  2014/07/30_13:52:43 INFO: Using calculated netmask for 192.168.20.18: 255.255.255.0
   IPaddr[21282]:  2014/07/30_13:52:43 INFO: eval ifconfig eth0:0 192.168.20.18 netmask 255.255.255.0 broadcast 192.168.20.255
   IPaddr[21258]:  2014/07/30_13:52:43 INFO:  Success
   INFO:  Success
   Jul 30 13:52:53 prod-cl3 heartbeat: [20847]: info: Local Resource acquisition completed. (none)
   Jul 30 13:52:53 prod-cl3 heartbeat: [20847]: info: local resource transition completed.

   PostgreSQL läuft anschließend auch nicht; es lässt sich jedoch problemlos manuell (/etc/init.d/postgresql start) starten.
2. Beendet man auf der inaktiven Node (prod-cl4) heartbeat, wird folgendes in's Log geschrieben:

   Code: Alles auswählen

   Jul 30 13:57:49 prod-cl4 heartbeat: [3340]: info: Heartbeat shutdown in progress. (3340)
   Jul 30 13:57:49 prod-cl4 heartbeat: [3410]: info: Giving up all HA resources.
   ResourceManager[3424]:  2014/07/30_13:57:49 info: Releasing resource group: prod-cl3 drbddisk::var_lib_postgres Filesystem::/dev/drbd0::/var/lib/postgresql::ext4 192.168.20.18/24/eth0 postgresql
   ResourceManager[3424]:  2014/07/30_13:57:49 info: Running /etc/init.d/postgresql  stop
   Stopping PostgreSQL 9.1 database server: mainError: /var/lib/postgresql/9.1/main is not accessible or does not exist ... failed!
    failed!
   ResourceManager[3424]:  2014/07/30_13:57:50 ERROR: Return code 1 from /etc/init.d/postgresql
   ResourceManager[3424]:  2014/07/30_13:57:51 info: Retrying failed stop operation [postgresql]
   ResourceManager[3424]:  2014/07/30_13:5
   

   Was ich hier nicht verstehe: Warum wird diese Resource Group überhaupt "beendet"; sie wurde auf dieser Node doch garnicht zugewiesen, da sie auf prod-cl3 aktiv ist!? Das "/etc/init.d/postgresql stop" fehlschlägt ist mir in Folge dessen auch klar: Das Dateisystem /var/lib/postgresql ist auf dieser Node ja garnicht gemounted.
3. Wie man in der letzten Zeile der Logdatei sehen kann, wird dadurch irgendwie ein Hard Reset des Servers durchgeführt; STONITH ist jedoch nicht konfiguriert. Wer oder was schießt den Server da derartig ab?

Das ganze ist nicht wirklich exotisch konfiguriert; im folgendem findet Ihr die Konfigurationsdateien. In dieser Form und Kombination (Heartbeat + DRBD + PostgreSQL) scheint Debian mir daher nicht HA-Fähig zu sein, oder mache ich etwas falsch?

/etc/ha.d/ha.cf :

Code: Alles auswählen

debugfile /var/log/ha-debug
logfile /var/log/ha-log
logfacility     local0
keepalive 2
deadtime 30
warntime 10
initdead 90
udpport 694
ucast eth1 10.250.250.16
auto_failback on
node   prod-cl3
node   prod-cl4

/etc/ha.d/haresources :

Code: Alles auswählen

prod-cl3  drbddisk::var_lib_postgres Filesystem::/dev/drbd0::/var/lib/postgresql::ext4 192.168.20.18/24/eth0 postgresql

/etc/drbd.conf :

Code: Alles auswählen

# You can find an example in  /usr/share/doc/drbd.../drbd.conf.example

include "drbd.d/global_common.conf";
include "drbd.d/*.res";

/etc/drbd.d/global_common.conf :

Code: Alles auswählen

global {
        usage-count yes;
}

common {
        protocol C;

        startup {
                wfc-timeout  15;
                degr-wfc-timeout 120;
        }

        disk {
                on-io-error     detach;
        }

        net {
                after-sb-0pri disconnect;
                after-sb-1pri disconnect;
                after-sb-2pri disconnect;
                rr-conflict disconnect;
        }

        syncer {
                rate 96256;
        }
}

/etc/drbd.d/prod-cl.res :

Code: Alles auswählen

resource var_lib_postgres {
        protocol C;
        on prod-cl3 {
                device  /dev/drbd0;
                disk    /dev/prod-cl3_data/var_lib_postgres;
                address 10.250.250.16:7789;
                meta-disk       internal;
        }
        on prod-cl4 {
                device  /dev/drbd0;
                disk    /dev/prod-cl4_data/var_lib_postgres;
                address 10.250.250.17:7789;
                meta-disk       internal;
        }
}

[Judge]

PS: Andere Dienste (ich habe testweise statt "postgresql" mal "cron" genommen) scheinen problemlos zu funktionieren.

Das Problem wurde hier im Forum scheinbar 2007 das erste Mal erwähnt und seinerzeit nicht gelöst. Der "aufgerufen" Zähler dieses Threads liegt seit seiner gestrigen Erstellung bereits bei weit über 100. Da niemand dazu etwas zu wissen scheint, handelt es sich dabei um einen Bug, den man reporten sollte?

[Colttt]

Kannst du es mal bitte mit einem anderen einfachen Dienst machen? Ala Apache oder so.. Aber Apache sollte dann sein /var/www auch auf dem DRBD Volumen haben.. Wenn es dann klappt poste mal bitte das log..
In der Log steht auch einmal ein FATAL drin, ich glaube da läuft was schief oder? Und dadurch wird der Rest auch nicht gestartet.. Ich sehe auch nirgends das PostgreSQL gestartet wird?

Wie sieht denn die Log aus vom Node2 wenn er alles über nimmt?

[Judge]

Hi Colttt,

Danke für Deine Mühe, aber irgendwie hast Du nur Dinge abgefragt, die ich bereits in den beiden ersten Beiträgen beantwortet oder als das eigentlich Problem genauso beschrieben habe.

Code: Alles auswählen

FATAL: Module scsi_hostadapter not found.

... steht IMMER so in einem HA log; hab's noch nie anders gesehen. Allerdings führt es keineswegs dazu das der Rest nicht gestartet wird.

[Colttt]

soo fehler gefunden..

heartbeet guckt anscheinend auf das wort "running".. da es auch kommt obwohl postgres aus ist, denkt heartbeat das psql schon läuft..
du müsstest also die ausgabe vom init-script ändern

[Judge]

Hi Colttt,

yo, hab ich just gestern abend auch gefunden:
http://www.linux-ha.org/wiki/Heartbeat_ ... _operation :

For the status operation, we ignore the return code.
This sounds quite odd, but it's a historical hangover for compatibility with earlier versions of Linux distributions where the init scripts didn't reliably give proper status exit codes, but they did print OK or running reliably.
Heartbeat calls the status operation in many places. We do it before starting any resource, and also (IIRC) when releasing resources.
After repeated stop failures, we will do a status on the resource. If the status reports that the resource is still running, then we will reboot the machine to make sure things are really stopped. Note that this behaviour is only with haresources based clusters.

Ziemlich bescheuert ...

Allerdings habe ich nun ein eigenes Script geschrieben, welches ...

• Nur status, start und stop unterstützt
• Keine Statuscodes verwendet
• Nur "running" für status und start ausgibt
• nichts ausgibt, wenn PostgreSQL nicht läuft

Trotzdem will Heartbeat nicht mit PostgreSQL zusammenarbeiten ...

Ich komme am WE nicht dran; ich werde Montag aber das Script mal posten.

[Cae]

• nichts ausgibt, wenn PostgreSQL nicht läuft

Wenn die da schon so deppertes Parsing machen, wuerde ich fuer diesen Fall "stopped" ausgeben, aber nicht nichts. Mit Rueckgabewerten haette man das Problem nie gehabt, aber hey, die gibt's ja erst seit so ungefaehr 40 Jahren... [1]

Gruss Cae

[1] im K&R ist's als return in main() drin, das war 1978

[Colttt]

Stoppen mal bitte postgres und dann mach mal da bitte ein /etc/init.d/postgresql status steht da immer noch was von running? Wenn nein was steht da genau?