Highly Available NFS-server using DRBD, Heartbeat and User Mode Linux

Updated on May 10 / 2005

I replicated this setup in the production environment and it worked well, except for a "NFS stale filehandle" issue I solved. More information in this this wiki. I was clueless enough to think that you only needed to share the /var/lib/nfs directory using drbd, but you MUST put the shared directories on the drbd filesystem because exported inode numbers must be the same in both the main and backup server. Lession learned :)

Please use the discussion page of the wiki if you have any suggestions.

March 2005 / by Nelson Castillo. Version 0.3

This is an informal report of a scenario involving a Highly Available NFS-server (2 servers) and a test client. Both servers and the client are User Mode Linux processes. The root filesystem is Debian Sarge and it was built using debootstrap.

Theory : DRBD is cheap, nice and it seems it works well.

Host: Linux 2.6.10 with SKAS patch v7
Servers and Client: Linux 2.6.10 with DRBD patch

server1 is the main NFS server.
server2 is the backup NFS server.
client1 is a client that uses the NFS service privided by the active server.

Both servers run heartbeat.

General information

server1:~# cat /etc/debian_version
3.1

server1:~# uname -a
Linux server1 2.6.10 #7 Thu Feb 17 17:08:42 COT 2005 i686 GNU/Linux

server1:~# cat /proc/cpuinfo
processor       : 0
vendor_id       : User Mode Linux
model name      : UML
mode            : skas
host            : Linux mdk 2.6.10-skas3-v7 #1 SMP Fri Feb 18 15:45:32 COT 2005 i686
bogomips        : 1084.62


n@uml-host:~/uml$ cat ./run-uml-1.sh
nice ./linux ubd0=root_fs-1 con=fd:0,fd:1 eth0=daemon ubd1=uml-shared-partition-1
reset
echo ran uml linux 1

n@uml-host:~/uml$ cat run-uml-2.sh
nice ./linux ubd0=root_fs-2 con=fd:0,fd:1 eth0=daemon ubd1=uml-shared-partition-2
reset
echo ran uml linux 2

n@uml-host:~/uml$ cat run-uml-3.sh
nice ./linux ubd0=root_fs-client con=fd:0,fd:1 eth0=daemon
reset
echo ran uml linux 3

Files shared-partition-1 and uml-shared-partition-2 have the same size and they are used thru drbd. To create a filesysetm on them I used "mkfs.ext3 /dev/drbd/0". drbd uses 128MB to hold the metadata, so for the uml-shared-partition-1 file that is 500MB I get an ext3 filesystem that provides 361MB of free space.

We want the UMLs to have Internet access, so we run as root:

tunctl -t uml0 -u $UMLUSER
ifconfig uml0 192.168.0.1 netmask 255.255.255.0
echo 1 > /proc/sys/net/ipv4/ip_forward
iptables -t nat -A POSTROUTING -s 192.168.0.0/255.255.255.0 -o eth0 -j SNAT --to-source $MY_EXTERNAL_IP
chmod 666 /dev/net/tun # DOS ATTACK! Use a group on a shared machine.

And as a normal user ($UMLUSER):

uml_switch -tap uml0

DRBD Configuration

It's the same for server1 and server2

server1:~# cat /etc/drbd.conf

resource drbd0 {

  # TODO: Setup transfer rate.
  # TODO: Use incon-degr-cmd option.
  # TODO: Use on-io-error option.

  protocol C; # Slowest and safest protocol

  on server1 {
    device /dev/drbd/0;
    disk /dev/ubd/1;
    meta-disk internal;
    address 192.168.0.2:7788;
  }

  on server2 {
    device /dev/drbd/0;
    disk /dev/ubd/1;
    meta-disk internal;
    address 192.168.0.3:7788;
  }
  
  # Todo : Should we configure disk-size?
}

NFS Configuration

server1:~# cat /etc/exports

/mnt/disk/export/ 192.168.0.0/255.255.255.0(rw,no_root_squash,no_all_squash,sync)

server2:~# cat /etc/exports

/mnt/disk/export/ 192.168.0.0/255.255.255.0(rw,no_root_squash,no_all_squash,sync)


server1:~# ls -lha /var/lib | grep nfs
lrwxrwxrwx   1 root root   21 Feb 24 17:15 nfs -> /mnt/disk/var/lib/nfs


server2:~# ls -lha /var/lib | grep nfs
lrwxrwxrwx   1 root root   21 Feb 24 17:18 nfs -> /mnt/disk/var/lib/nfs

Heartbeat Configuration

It's the same for server1 and server2

server1:~# cat /etc/heartbeat/ha.cf

logfacility     local0
keepalive 2
#deadtime 30 # USE THIS!!!
deadtime 10
bcast   eth0
node server1 server2

server1:~# cat /etc/heartbeat/haresources

server1  IPaddr::192.168.0.10/24/eth0 drbddisk::drbd0 Filesystem::/dev/drbd/0::/mnt/disk::ext3 nfs-kernel-server

Services are started left to right and stopped right to left.

When Server 1 is UP and running

server1

Note : eth0:0 and nfsd are started by heartbeat.

server1:~#  ps axu

USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
root         1  0.0  1.8  1496  512 ?        S    16:53   0:00 init [2]
root         2  0.0  0.0     0    0 ?        RN   16:53   0:00 [ksoftirqd/0]
root         3  0.0  0.0     0    0 ?        S<   16:53   0:00 [events/0]
root         4  0.0  0.0     0    0 ?        S<   16:53   0:00 [khelper]
root         5  0.0  0.0     0    0 ?        S<   16:53   0:00 [kblockd/0]
root         6  0.0  0.0     0    0 ?        S    16:53   0:00 [pdflush]
root         7  0.0  0.0     0    0 ?        S    16:53   0:00 [pdflush]
root         9  0.0  0.0     0    0 ?        S<   16:53   0:00 [aio/0]
root         8  0.0  0.0     0    0 ?        S    16:53   0:00 [kswapd0]
root        10  0.0  0.0     0    0 ?        S<   16:53   0:00 [kcryptd/0]
root        11  0.0  0.0     0    0 ?        S<   16:53   0:00 [kmirrord/0]
root        12  0.0  0.0     0    0 ?        S    16:53   0:00 [kjournald]
root        26  0.0  7.0  2924 1948 ?        Ss   16:53   0:00 /sbin/devfsd /dev
daemon     193  0.0  1.6  1608  448 ?        Ss   16:53   0:00 /sbin/portmap
root       244  0.0  2.8  2252  804 ?        Ss   16:53   0:00 /sbin/syslogd
root       247  0.0  1.6  1500  464 ?        Ss   16:53   0:00 /sbin/klogd
root       253  0.0  5.6  3256 1576 ?        Ss   16:53   0:00 /usr/sbin/dhcpd3 -q
root       263  0.0  2.5  2232  704 ?        Ss   16:53   0:00 /usr/sbin/inetd
lp         267  0.0  3.1  2456  888 ?        Ss   16:53   0:00 /usr/sbin/lpd -s
root       276  0.0  5.3  3388 1488 ?        Ss   16:53   0:00 /usr/sbin/sshd
root       287  0.0  0.0     0    0 ?        S    16:53   0:00 [drbd0_worker]
root       300  0.0  0.0     0    0 ?        S    16:53   0:00 [drbd0_receiver]
root       306  0.0  0.0     0    0 ?        S    16:53   0:00 [drbd0_asender]
root       354  0.0 18.2  5116 5084 ?        SLs  16:53   0:02 heartbeat: heartbeat: master control process
root       359  0.0  2.6  1752  724 ?        Ss   16:53   0:00 /usr/sbin/cron
n          365  0.0  5.0  2568 1416 tty0     Ss   16:53   0:00 -bash
nobody     367  0.0 11.5  3212 3212 ?        SL   16:53   0:00 heartbeat: heartbeat: FIFO reader
nobody     368  0.0 11.5  3208 3208 ?        SL   16:53   0:00 heartbeat: heartbeat: write: bcast eth0
nobody     369  0.0 11.5  3208 3208 ?        SL   16:53   0:00 heartbeat: heartbeat: read: bcast eth0
root       620  0.0  0.0     0    0 ?        S    16:53   0:00 [kjournald]
root       649  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       650  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       651  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       652  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       653  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       654  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       655  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       656  0.0  0.0     0    0 ?        S    16:53   0:00 [nfsd]
root       659  0.0  0.0     0    0 ?        S    16:53   0:00 [lockd]
root       660  0.0  0.0     0    0 ?        S    16:53   0:00 [rpciod]
root       662  0.0  3.2  2416  896 ?        Ss   16:53   0:00 /usr/sbin/rpc.mountd

server1:~# ifconfig

eth0      Link encap:Ethernet  HWaddr FE:FD:C0:A8:00:02
          inet addr:192.168.0.2  Bcast:192.168.0.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:16442 errors:0 dropped:0 overruns:0 frame:0
          TX packets:16502 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:1921677 (1.8 MiB)  TX bytes:4169034 (3.9 MiB)
          Interrupt:5

eth0:0    Link encap:Ethernet  HWaddr FE:FD:C0:A8:00:02
          inet addr:192.168.0.10  Bcast:192.168.0.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          Interrupt:5

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:53 errors:0 dropped:0 overruns:0 frame:0
          TX packets:53 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:3696 (3.6 KiB)  TX bytes:3696 (3.6 KiB)

server1:~# cat /proc/drbd

version: 0.7.10 (api:77/proto:74)
SVN Revision: 1743 build by n@mdk, 2005-02-16 12:49:23
 0: cs:Connected st:Primary/Secondary ld:Consistent
    ns:2175 nr:84 dw:2259 dr:25 al:0 bm:2 lo:0 pe:0 ua:0 ap:0
 1: cs:Unconfigured
 2: cs:Unconfigured
 3: cs:Unconfigured
 4: cs:Unconfigured
 5: cs:Unconfigured
 6: cs:Unconfigured
 7: cs:Unconfigured

server1:~# mount

/dev/ubd/disc0/disc on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
tmpfs on /dev/shm type tmpfs (rw)
/dev/drbd/0 on /mnt/disk type ext3 (rw)

server1:~# ls /mnt/disk/var/lib/
nfs

server2

server2:~# ps axu

USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
root         1  0.0  1.4  1496  408 ?        S    Feb24   0:00 init [2]
root         2  0.0  0.0     0    0 ?        RN   Feb24   0:00 [ksoftirqd/0]
root         3  0.0  0.0     0    0 ?        S<   Feb24   0:00 [events/0]
root         4  0.0  0.0     0    0 ?        S<   Feb24   0:00 [khelper]
root         5  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kblockd/0]
root         6  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         7  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         9  0.0  0.0     0    0 ?        S<   Feb24   0:00 [aio/0]
root         8  0.0  0.0     0    0 ?        S    Feb24   0:00 [kswapd0]
root        10  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kcryptd/0]
root        11  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kmirrord/0]
root        12  0.0  0.0     0    0 ?        S    Feb24   0:00 [kjournald]
root        26  0.0  6.0  2924 1688 ?        Ss   Feb24   0:00 /sbin/devfsd /dev
daemon     192  0.0  1.3  1608  372 ?        Ss   Feb24   0:00 /sbin/portmap
root       243  0.0  2.4  2252  688 ?        Ss   Feb24   0:00 /sbin/syslogd
root       246  0.0  1.5  1500  420 ?        Ss   Feb24   0:00 /sbin/klogd
Debian-    279  0.0  2.2  4228  620 ?        Ss   Feb24   0:00 /usr/sbin/exim4 -bd -q30m
root       285  0.0  1.3  2232  388 ?        Ss   Feb24   0:00 /usr/sbin/inetd
root       301  0.0  1.5  2372  428 ?        Ss   Feb24   0:00 /sbin/rpc.statd
root       321  0.0  0.0     0    0 ?        S    Feb24   0:00 [drbd0_receiver]
daemon     333  0.0  1.5  1676  428 ?        Ss   Feb24   0:00 /usr/sbin/atd
root       336  0.0  1.8  1752  516 ?        Ss   Feb24   0:00 /usr/sbin/cron
n          342  0.0  4.2  2568 1176 tty0     Ss   Feb24   0:00 -bash
root       437  0.0  5.3  2608 1496 tty0     S    Feb24   0:00 -su
root       524  0.0  5.3  3388 1492 ?        Ss   Feb24   0:00 /usr/sbin/sshd
lp        3623  0.0  3.1  2456  888 ?        Ss   Feb27   0:00 /usr/sbin/lpd -s
root      4727  0.0 18.2  5100 5072 ?        SLs  15:17   0:03 heartbeat: heartbeat: master control process
nobody    4729  0.0 11.5  3216 3216 ?        SL   15:17   0:00 heartbeat: heartbeat: FIFO reader
nobody    4730  0.0 11.5  3212 3212 ?        SL   15:17   0:00 heartbeat: heartbeat: write: bcast eth0
nobody    4731  0.0 11.5  3212 3212 ?        SL   15:17   0:00 heartbeat: heartbeat: read: bcast eth0
root      4751  0.0  0.0     0    0 ?        S    16:41   0:00 [drbd0_worker]
root      5156  0.0  0.0     0    0 ?        S    16:53   0:00 [drbd0_asender]



server2:~# ifconfig

eth0      Link encap:Ethernet  HWaddr FE:FD:C0:A8:00:03
          inet addr:192.168.0.3  Bcast:192.168.0.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:710389 errors:0 dropped:0 overruns:0 frame:0
          TX packets:711844 errors:0 dropped:45 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:315720265 (301.0 MiB)  TX bytes:114048100 (108.7 MiB)
          Interrupt:5

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:10119 errors:0 dropped:0 overruns:0 frame:0
          TX packets:10119 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:886082 (865.3 KiB)  TX bytes:886082 (865.3 KiB)

server2:~# cat /proc/drbd

version: 0.7.10 (api:77/proto:74)
SVN Revision: 1743 build by n@mdk, 2005-02-16 12:49:23
 0: cs:Connected st:Secondary/Primary ld:Consistent
    ns:9949 nr:213581 dw:385514 dr:9797 al:7 bm:72 lo:0 pe:0 ua:0 ap:0
 1: cs:Unconfigured
 2: cs:Unconfigured
 3: cs:Unconfigured
 4: cs:Unconfigured
 5: cs:Unconfigured
 6: cs:Unconfigured
 7: cs:Unconfigured

server2:~# mount

/dev/ubd/disc0/disc on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
tmpfs on /dev/shm type tmpfs (rw)

server2:~#  ls /mnt/disk/var/lib/

ls: /mnt/disk/var/lib/: No such file or directory

client1 : mounts an NFS share using the server address 192.168.0.10

client1:~# ps axu

USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
root         1  0.0  1.8  1496  512 ?        S    Feb24   0:00 init [2]
root         2  0.0  0.0     0    0 ?        RN   Feb24   0:00 [ksoftirqd/0]
root         3  0.0  0.0     0    0 ?        S<   Feb24   0:00 [events/0]
root         4  0.0  0.0     0    0 ?        S<   Feb24   0:00 [khelper]
root         5  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kblockd/0]
root         6  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         7  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         9  0.0  0.0     0    0 ?        S<   Feb24   0:00 [aio/0]
root         8  0.0  0.0     0    0 ?        S    Feb24   0:00 [kswapd0]
root        10  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kcryptd/0]
root        11  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kmirrord/0]
root        12  0.0  0.0     0    0 ?        S    Feb24   0:00 [kjournald]
root        26  0.0  7.0  2924 1948 ?        Ss   Feb24   0:00 /sbin/devfsd /dev
daemon     192  0.0  1.6  1608  448 ?        Ss   Feb24   0:00 /sbin/portmap
root       243  0.0  2.8  2252  804 ?        Ss   Feb24   0:00 /sbin/syslogd
root       246  0.0  1.6  1500  464 ?        Ss   Feb24   0:00 /sbin/klogd
root       256  0.0  2.5  2232  704 ?        Ss   Feb24   0:00 /usr/sbin/inetd
root       268  0.0  5.3  3388 1488 ?        Ss   Feb24   0:00 /usr/sbin/sshd
root       272  0.0  3.3  2372  928 ?        Ss   Feb24   0:00 /sbin/rpc.statd
root       276  0.0  2.6  1752  724 ?        Ss   Feb24   0:00 /usr/sbin/cron
n          282  0.0  5.0  2568 1416 tty0     Ss   Feb24   0:00 -bash
root       285  0.0  5.3  2588 1488 tty0     S    Feb24   0:00 -su
root       300  0.0  0.0     0    0 ?        S    Feb24   0:00 [rpciod]
root       301  0.0  0.0     0    0 ?        S    Feb24   0:00 [lockd]
lp       21794  0.0  3.1  2456  888 ?        Ss   Feb27   0:00 /usr/sbin/lpd -s

client1:~# ifconfig

eth0      Link encap:Ethernet  HWaddr FE:FD:C0:A8:00:04
          inet addr:192.168.0.4  Bcast:192.168.0.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:587766 errors:0 dropped:0 overruns:0 frame:0
          TX packets:291176 errors:0 dropped:17702 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:98787971 (94.2 MiB)  TX bytes:100332491 (95.6 MiB)
          Interrupt:5

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:26 errors:0 dropped:0 overruns:0 frame:0
          TX packets:26 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:1820 (1.7 KiB)  TX bytes:1820 (1.7 KiB)


client1:~# mount

/dev/ubd/disc0/disc on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
tmpfs on /dev/shm type tmpfs (rw)
192.168.0.10:/mnt/disk/export on /mnt type nfs (rw,addr=192.168.0.10)

client1:/mnt# cd /mnt/

client1:/mnt# cat write.sh

while true
do
  echo     ---\> trying touch x : `date`
  touch x
  echo     \<----- done touch x : `date`
  echo
  sleep 2

done

client1:/mnt# ./write.sh
---> trying touch x : Mon Feb 28 19:11:38 COT 2005
<----- done touch x : Mon Feb 28 19:11:39 COT 2005

---> trying touch x : Mon Feb 28 19:11:41 COT 2005
<----- done touch x : Mon Feb 28 19:11:41 COT 2005

---> trying touch x : Mon Feb 28 19:11:43 COT 2005
<----- done touch x : Mon Feb 28 19:11:43 COT 2005

We're using a simple "touch" for testing. If I try to use "dd if=/dev/zero of=x bs=1M count=10" the NFS server gets flooded with a lot of packages that it cannot handle. I think they are dropped by the uml_switch, at leas they are with the Kraxel's uml_switch implementation. I think it wouldn't happen using real boxes. I am also using the slowest DRBD protocol: C. I read that with dd you only get 2% of the host's performance (Check Virtual Labs with User Mode Linux).

When Server 1 goes down

Let's turn off the main server

server1:~# date ; halt

Mon Feb 28 19:25:23 COT 2005
Broadcast message from root (vc/0) (Mon Feb 28 19:25:23 2005):
The system is going down for system halt NOW!
INIT: Switching to runlevel: 0
INIT: Sending processes the TERM signal
server1:~# 
INIT: Sending processes the KILL signal
Stopping High-Availability services: 
drbd0: Primary/Secondary --> Secondary/Secondary
Done.

Stopping all DRBD resourcesdrbd0: drbdsetup [840]: cstate Connected --> Unconnected
drbd0: drbd0_receiver [300]: cstate Unconnected --> BrokenPipe
drbd0: short read expecting header on sock: r=-512
drbd0: worker terminated
drbd0: asender terminated
drbd0: drbd0_receiver [300]: cstate BrokenPipe --> StandAlone
drbd0: Connection lost.
drbd0: receiver terminated
drbd0: drbdsetup [840]: cstate StandAlone --> StandAlone
drbd0: drbdsetup [840]: cstate StandAlone --> Unconfigured
drbd0: worker terminated

(... more messages)

server2 takes over

server2 syslog:

Feb 28 19:25:33 server2 kernel: drbd0: Secondary/Primary --> Secondary/Secondary
Feb 28 19:25:34 server2 heartbeat[4727]: info: Received shutdown notice from 'server1'.
Feb 28 19:25:34 server2 heartbeat[4727]: info: Resources being acquired from server1.
Feb 28 19:25:34 server2 heartbeat[6526]: debug: notify_world: setting SIGCHLD Handler to SIG_DFL
Feb 28 19:25:34 server2 heartbeat: info: Running /etc/ha.d/rc.d/status status
Feb 28 19:25:35 server2 heartbeat[6527]: info: No local resources [/usr/lib/heartbeat/ResourceManager listkeys server2] to acquire.
Feb 28 19:25:35 server2 heartbeat[4727]: debug: StartNextRemoteRscReq(): child count 1
Feb 28 19:25:35 server2 heartbeat: info: Taking over resource group IPaddr::192.168.0.10/24/eth0
Feb 28 19:25:35 server2 heartbeat: info: Acquiring resource group: server1 IPaddr::192.168.0.10/24/eth0 drbddisk::drbd0 Filesystem::/dev/drbd/0::/mnt/disk::ext3 nfs-kernel-server

So, heartbeat will configure the IP 192.168.0.10 in eth0:0, then enable the DRBD device /dev/drbd/0 (it can only be enabled in one of the two servers), then it will mount the partition /dev/drbd/0 at /mnt/disk as an ext3 filesystem and then it will start the NFS kernel server.

DRBD notices that it's partnet died:

Feb 28 19:25:36 server2 kernel: drbd0: sock was shut down by peer
Feb 28 19:25:36 server2 kernel: drbd0: drbd0_receiver [321]: cstate Connected --> BrokenPipe
Feb 28 19:25:36 server2 kernel: drbd0: short read expecting header on sock: r=0
Feb 28 19:25:36 server2 kernel: drbd0: meta connection shut down by peer.
Feb 28 19:25:36 server2 kernel: drbd0: asender terminated
Feb 28 19:25:36 server2 kernel: drbd0: worker terminated
Feb 28 19:25:36 server2 kernel: drbd0: drbd0_receiver [321]: cstate BrokenPipe --> Unconnected
Feb 28 19:25:36 server2 kernel: drbd0: Connection lost.
Feb 28 19:25:36 server2 kernel: drbd0: drbd0_receiver [321]: cstate Unconnected --> WFConnection

The ip address is configured and the gratuitous arp is sent to update the ARP tables of other hosts in the network.

Feb 28 19:25:36 server2 heartbeat: info: Running /etc/ha.d/resource.d/IPaddr 192.168.0.10/24/eth0 start
Feb 28 19:25:36 server2 heartbeat: debug: Starting /etc/ha.d/resource.d/IPaddr 192.168.0.10/24/eth0 start
Feb 28 19:25:37 server2 heartbeat: info: /sbin/ifconfig eth0:0 192.168.0.10 netmask 255.255.255.0^Ibroadcast 192.168.0.255
Feb 28 19:25:38 server2 heartbeat: info: Sending Gratuitous Arp for 192.168.0.10 on eth0:0 [eth0]
Feb 28 19:25:38 server2 heartbeat: /usr/lib/heartbeat/send_arp -i 1010 -r 5 -p /var/lib/heartbeat/rsctmp/send_arp/send_arp-192.168.0.10 eth0 192.168.0.10 auto 192.168.0.10 ffffffffffff
Feb 28 19:25:38 server2 heartbeat: debug: /etc/ha.d/resource.d/IPaddr 192.168.0.10/24/eth0 start done. RC=0

Now /dev/drbd/0 is enabled.

Feb 28 19:25:39 server2 heartbeat: info: Running /etc/ha.d/resource.d/drbddisk drbd0 start
Feb 28 19:25:39 server2 heartbeat: debug: Starting /etc/ha.d/resource.d/drbddisk drbd0 start
Feb 28 19:25:39 server2 kernel: drbd0: Secondary/Unknown --> Primary/Unknown
Feb 28 19:25:39 server2 heartbeat: debug: /etc/ha.d/resource.d/drbddisk drbd0 start done. RC=0
Feb 28 19:25:40 server2 heartbeat: info: Running /etc/ha.d/resource.d/Filesystem /dev/drbd/0 /mnt/disk ext3 start

Now /dev/drbd/0 is mounted... We don't have to fsck the ext3 filesystem.

Feb 28 19:25:40 server2 heartbeat: debug: Starting /etc/ha.d/resource.d/Filesystem /dev/drbd/0 /mnt/disk ext3 start
Feb 28 19:25:40 server2 kernel: kjournald starting.  Commit interval 5 seconds
Feb 28 19:25:40 server2 kernel: EXT3 FS on drbd0, internal journal
Feb 28 19:25:40 server2 kernel: EXT3-fs: mounted filesystem with ordered data mode.
Feb 28 19:25:40 server2 heartbeat: debug: /etc/ha.d/resource.d/Filesystem /dev/drbd/0 /mnt/disk ext3 start done. RC=0
Feb 28 19:25:41 server2 heartbeat: info: Running /etc/init.d/nfs-kernel-server  start
Feb 28 19:25:41 server2 heartbeat: debug: Starting /etc/init.d/nfs-kernel-server  start
Feb 28 19:25:41 server2 heartbeat: debug: /etc/init.d/nfs-kernel-server  start done. RC=0
Feb 28 19:25:41 server2 heartbeat: info: mach_down takeover complete for node server1.
Feb 28 19:25:45 server2 heartbeat[4727]: WARN: node server1: is dead
Feb 28 19:25:45 server2 heartbeat[4727]: info: Dead node server1 gave up resources.
Feb 28 19:25:45 server2 heartbeat[4727]: info: Resources being acquired from server1.
Feb 28 19:25:45 server2 heartbeat[4727]: info: Link server1:eth0 dead.
Feb 28 19:25:45 server2 heartbeat[6798]: debug: notify_world: setting SIGCHLD Handler to SIG_DFL
Feb 28 19:25:45 server2 heartbeat: info: Running /etc/ha.d/rc.d/status status
Feb 28 19:25:46 server2 heartbeat[6799]: info: No local resources [/usr/lib/heartbeat/ResourceManager listkeys server2] to acquire.
Feb 28 19:25:46 server2 heartbeat[4727]: debug: StartNextRemoteRscReq(): child count 1
Feb 28 19:25:46 server2 heartbeat: info: Taking over resource group IPaddr::192.168.0.10/24/eth0
Feb 28 19:25:46 server2 heartbeat: info: Acquiring resource group: server1 IPaddr::192.168.0.10/24/eth0 drbddisk::drbd0 Filesystem::/dev/drbd/0::/mnt/disk::ext3 nfs-kernel-server
Feb 28 19:25:48 server2 heartbeat: info: Running /etc/init.d/nfs-kernel-server  start
Feb 28 19:25:48 server2 heartbeat: debug: Starting /etc/init.d/nfs-kernel-server  start
Feb 28 19:25:48 server2 heartbeat: debug: /etc/init.d/nfs-kernel-server  start done. RC=1
Feb 28 19:25:48 server2 heartbeat: ERROR: Return code 1 from /etc/init.d/nfs-kernel-server
Feb 28 19:25:49 server2 heartbeat: info: mach_down takeover complete for node server1.

The last step is to start the NFS server. I don't know why it's returning 1. I will check it out later. It just works...

server2:~# ps axu
USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
root         1  0.0  1.4  1496  408 ?        S    Feb24   0:00 init [2]
root         2  0.0  0.0     0    0 ?        RN   Feb24   0:00 [ksoftirqd/0]
root         3  0.0  0.0     0    0 ?        S<   Feb24   0:00 [events/0]
root         4  0.0  0.0     0    0 ?        S<   Feb24   0:00 [khelper]
root         5  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kblockd/0]
root         6  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         7  0.0  0.0     0    0 ?        S    Feb24   0:00 [pdflush]
root         9  0.0  0.0     0    0 ?        S<   Feb24   0:00 [aio/0]
root         8  0.0  0.0     0    0 ?        S    Feb24   0:00 [kswapd0]
root        10  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kcryptd/0]
root        11  0.0  0.0     0    0 ?        S<   Feb24   0:00 [kmirrord/0]
root        12  0.0  0.0     0    0 ?        S    Feb24   0:00 [kjournald]
root        26  0.0  6.0  2924 1688 ?        Ss   Feb24   0:00 /sbin/devfsd /dev
daemon     192  0.0  1.3  1608  372 ?        Ss   Feb24   0:00 /sbin/portmap
root       243  0.0  2.4  2252  688 ?        Ss   Feb24   0:00 /sbin/syslogd
root       246  0.0  1.5  1500  420 ?        Ss   Feb24   0:00 /sbin/klogd
Debian-    279  0.0  2.2  4228  620 ?        Ss   Feb24   0:00 /usr/sbin/exim4 -bd -q30m
root       285  0.0  1.3  2232  388 ?        Ss   Feb24   0:00 /usr/sbin/inetd
root       301  0.0  1.5  2372  428 ?        Ss   Feb24   0:00 /sbin/rpc.statd
root       321  0.0  0.0     0    0 ?        S    Feb24   0:00 [drbd0_receiver]
daemon     333  0.0  1.5  1676  428 ?        Ss   Feb24   0:00 /usr/sbin/atd
root       336  0.0  1.8  1752  516 ?        Ss   Feb24   0:00 /usr/sbin/cron
n          342  0.0  4.2  2568 1176 tty0     Ss   Feb24   0:00 -bash
root       437  0.0  5.4  2608 1504 tty0     S    Feb24   0:00 -su
root       524  0.0  5.3  3388 1492 ?        Ss   Feb24   0:00 /usr/sbin/sshd
lp        3623  0.0  3.1  2456  888 ?        Ss   Feb27   0:00 /usr/sbin/lpd -s
root      4727  0.0 18.2  5100 5072 ?        SLs  15:17   0:06 heartbeat: heartbeat: master control process
nobody    4729  0.0 11.5  3216 3216 ?        SL   15:17   0:00 heartbeat: heartbeat: FIFO reader
nobody    4730  0.0 11.5  3212 3212 ?        SL   15:17   0:00 heartbeat: heartbeat: write: bcast eth0
nobody    4731  0.0 11.5  3212 3212 ?        SL   15:17   0:00 heartbeat: heartbeat: read: bcast eth0
root      5641  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5642  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5643  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5644  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5645  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5646  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5647  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5648  0.0  0.0     0    0 ?        S    19:15   0:00 [nfsd]
root      5649  0.0  0.0     0    0 ?        S    19:15   0:00 [lockd]
root      5650  0.0  0.0     0    0 ?        S    19:15   0:00 [rpciod]
root      6581  0.0  0.0     0    0 ?        S    19:25   0:00 [drbd0_worker]
root      6759  0.0  0.0     0    0 ?        S    19:25   0:00 [kjournald]
root      6791  0.0  3.2  2416  896 ?        Ss   19:25   0:00 /usr/sbin/rpc.mountd

As you can see, nfsd is up and running and the client is happy.

Client experiences some downtime (about 13 seconds)

The main server is declared dead after 10 seconds (see "deadtime 10" in the heartbeat configuration). A small deadtime is considered dangerous because if both servers are active at the same time we can go to hell... Usually redundant links are used to be sure that the other host is down.... and just to be sure, you can shoot the other node in the head.

client1:/mnt# ./write.sh

---> trying touch x : Mon Feb 28 19:25:30 COT 2005
<----- done touch x : Mon Feb 28 19:25:30 COT 2005

---> trying touch x : Mon Feb 28 19:25:32 COT 2005
touch: cannot touch `x': Stale NFS file handle
<----- done touch x : Mon Feb 28 19:25:32 COT 2005

---> trying touch x : Mon Feb 28 19:25:34 COT 2005
touch: cannot touch `x': Stale NFS file handle
<----- done touch x : Mon Feb 28 19:25:35 COT 2005

---> trying touch x : Mon Feb 28 19:25:37 COT 2005
touch: cannot touch `x': Stale NFS file handle
<----- done touch x : Mon Feb 28 19:25:39 COT 2005

---> trying touch x : Mon Feb 28 19:25:41 COT 2005
touch: cannot touch `x': Stale NFS file handle
<----- done touch x : Mon Feb 28 19:25:41 COT 2005

---> trying touch x : Mon Feb 28 19:25:43 COT 2005
<----- done touch x : Mon Feb 28 19:25:43 COT 2005

Well, I don't know if this temporal stale filehandle is a debian-specific issue. Somehow, the init scripts for nfs (nfs-kernel-server) don't kill the nfsd processes. I don't know how correct it is, but I read a solution that provided me an smoother transition without those messages. The idea is to send a "kill -9" 5 seconds after the "kill -2" signal. With the following patch we create a modified script for debian. You can get it here.

--- /etc/init.d/nfs-kernel-server       2003-08-03 20:38:55.000000000 -0500
+++ nfs-kernel-server   2005-05-10 20:16:19.437175064 -0500
@@ -80,6 +80,17 @@

       printf "Unexporting directories for $DESC..."
       $PREFIX/sbin/exportfs -au
+
+
+  # We start here
+
+  sleep 5
+
+  start-stop-daemon --stop --oknodo --quiet \
+      --name nfsd --user 0 --signal 9
+
+  # We end here
+

References

User Mode Linux HOWTO
DRBD HOWTO (a little outdated)
Article Data Redundancy By DRBD (a little outdated)
High-availability middleware on Linux, Part 1: Heartbeat and Apache Web server
Linux HA Wiki
Kraxel's uml_switch implementation. It seems to be better than the one that comes with the package uml-utilities. Coded by a SUSE developer.
NFS FAQ : Check it for the Stale Filehandle issue.
Virtual Labs with User Mode Linux (slides in PDF format)

Hosted by www.Geocities.ws