[DRBD-user] block drbd1: al_complete_io() fresh install, step by step, still broken

adamn at eyemedia.com.au adamn at eyemedia.com.au
Mon Jul 19 12:47:09 CEST 2010

Note: "permalinks" may not be as permanent as we would like,
direct links of old sources may well be a few messages off.


Ok this is a cross list post (DRBD and SCST) as I don't know if this is an 
issue BETWEEN DRBD and SCST

I believe I'm doing this as "plain" as I can but STILL have issues, clean 
rebuild etc.
This is a LONG email but I feel it's the only way I'm going to get 
anywhere with trying to solve the issue I'm having.
I really need one of "the powers that be" tell me what step I'm either 
missing or what i'm screwing up.
I have a very simple setup in a lab environment for now (no use 
implementing this in production unless I can get it working in the lab)
I'm using VMware workstation.
I have a single VM setup.
1024Mb RAM
1 cpu, 4 cores (Core i5 is the lab machine)
6 nic's (4 for MPIO), 1 for dedicated drbd replication, 1 for "management 
acces" + heartbeat
serial connection for heartbeat.
VMdisks are IDE, NOT lsi scsi (keeping it simple in the lab)
Basically I want to build a simple iSCSI SAN (x2) for redundancy
scst
iscsi-scst
drbd
heartbeat
lvm2

storage00 Ubuntu 10.40 LTS 64bit

Followed the bouncing ball for the installation.
Manually configured partitions

/ 20GB
swap 512MB
unmounted 1GB partition (/devdrbd0 once configured)
unmounted 40GB partition (/dev/drbd1 once configured)

Installation completes with no issues.

Now I'm doing a blow by blow for this as I need someone to tell me what 
I'm doing wrong.

-> Login as user
root at storage00:sudo su
root at storage00:passwd root
root at storage00:exit
root at storage00:exit

-> Login as root
root at storage00:apt-get update
root at storage00:apt-get install ssh openssh-server ntp ntpdate
root at storage00:exit

-> SSH from now on
-> Setup some basic stuff
root at storage00:/# cat /etc/hosts
127.0.0.1       localhost
192.168.1.10    storage00
192.168.1.11    storage01

# The following lines are desirable for IPv6 capable hosts
::1     localhost ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters

root at storage00:/# cat /etc/network/interfaces
# This file describes the network interfaces available on your system
# and how to activate them. For more information, see interfaces(5).

# The loopback network interface
auto lo
iface lo inet loopback

auto eth0
iface eth0 inet static
        address 10.1.5.10
        netmask 255.255.255.0

auto eth1
iface eth1 inet static
        address 10.1.5.11
        netmask 255.255.255.0

auto eth2
iface eth2 inet static
        address 10.1.5.12
        netmask 255.255.255.0

auto eth3
iface eth3 inet static
        address 10.1.5.13
        netmask 255.255.255.0

# The primary network interface
auto eth4
iface eth4 inet static
        address 10.0.10.71
        netmask 255.255.255.0
        network 10.0.10.0
        broadcast 10.0.10.255
        gateway 10.0.10.1
        # dns-* options are implemented by the resolvconf package, if 
installed
        dns-nameservers 10.0.10.10
        dns-search eyemedia.net.au

auto eth5
iface eth5 inet static
        address 192.168.1.10
        netmask 255.255.255.0

-> SCST
root at storage00:apt-get install subversion
root at storage00:cd ~
root at storage00:svn co https://scst.svn.sourceforge.net/svnroot/scst/trunk 
scst

-> DRBD is built into 2.6.33 now so latest stable 2.6.33.6
root at storage00:cd /usr/src/
root at storage00:wget 
http://www.kernel.org/pub/linux/kernel/v2.6/linux-2.6.33.6.tar.bz2
root at storage00:tar vxjf linux-2.6.33.6.tar.bz2
root at storage00:ln -s linux-2.6.33.6 linux
root at storage00:cd linux
root at storage00:apt-get install build-essential libncurses5-dev 
kernel-package
root at storage00:/usr/src/linux# patch -p1 < 
~/scst/iscsi-scst/kernel/patches/put_page_callback-2.6.33.patch
patching file include/linux/mm_types.h
patching file include/linux/net.h
patching file net/core/dev.c
Hunk #1 succeeded at 2654 (offset 2 lines).
patching file net/core/skbuff.c
patching file net/ipv4/ip_output.c
patching file net/ipv4/Makefile
patching file net/ipv4/tcp.c
patching file net/ipv4/tcp_output.c
patching file net/ipv4/tcp_zero_copy.c
patching file net/ipv6/ip6_output.c
patching file net/Kconfig
root at storage00:/usr/src/linux# patch -p1 < 
~/scst/scst/kernel/scst_exec_req_fifo-2.6.33.patch
patching file block/blk-map.c
patching file include/linux/blkdev.h
patching file include/linux/scatterlist.h
patching file lib/scatterlist.c
root at storage00:cp /boot/config-2.6.32-21-server .config
root at storage00:export CONCURRENCY_LEVEL=5
root at storage00:make mrproper
root at storage00:make oldconfig

Kernel compression mode
> 1. Gzip (KERNEL_GZIP)
  2. Bzip2 (KERNEL_BZIP2)
  3. LZMA (KERNEL_LZMA)
  4. LZO (KERNEL_LZO) (NEW)

-> answered 1

TCP/IP networking (INET) [Y/n/?] y
  TCP/IP zero-copy transfer completion notification 
(TCP_ZERO_COPY_TRANSFER_COMPLETION_NOTIFICATION) [N/y/?] (NEW)
 
-> answered y

DRBD Distributed Replicated Block Device support (BLK_DEV_DRBD) [N/m/y/?] 
(NEW)

-> answered m

DRBD fault injection (DRBD_FAULT_INJECTION) [N/y/?] (NEW)

-> answered n
-> took defaults for all other .config (NEW) options which where all no
-> will run make localmodconfig on the production machine but didn't here
root at storage00:make menuconfig

in "Kernel hacking" -> "Kernel debugging"
        disable "Compile the kernel with debug info"
in "Enable the block layer" -> "IO Schedulers"
        enable "CFQ I/O scheduler"
        set "Default I/O scheduler" to "CFQ"

root at storage00:fakeroot make-kpkg --initrd --append-to-version=-scst 
--revision=1.0 kernel_image kernel_headers

-> Got coffee, stared at the screen, got more coffee...

root at storage00:mkdir /etc/kernel/
root at storage00:mkdir /etc/kernel/postinst.d
root at storage00:mkdir /etc/kernel/postrm.d
root at storage00:cp 
/usr/share/doc/kernel-package/examples/etc/kernel/postinst.d/initramfs 
/etc/kernel/postinst.d/initramfs
root at storage00:cp 
/usr/share/doc/kernel-package/examples/etc/kernel/postrm.d/initramfs 
/etc/kernel/postrm.d/initramfs
root at storage00:dpkg -i linux-headers-2.6.33.6-scst_1.0_amd64.deb
root at storage00:/usr/src# dpkg -i linux-image-2.6.33.6-scst_1.0_amd64.deb
Selecting previously deselected package linux-image-2.6.33.6-scst.
(Reading database ... 59444 files and directories currently installed.)
Unpacking linux-image-2.6.33.6-scst (from 
linux-image-2.6.33.6-scst_1.0_amd64.deb) ...
Done.
Setting up linux-image-2.6.33.6-scst (1.0) ...
Running depmod.
Examining /etc/kernel/postinst.d.
run-parts: executing /etc/kernel/postinst.d/initramfs 2.6.33.6-scst 
/boot/vmlinuz-2.6.33.6-scst
Running postinst hook script update-grub.
Generating grub.cfg ...
Found linux image: /boot/vmlinuz-2.6.33.6-scst
Found initrd image: /boot/initrd.img-2.6.33.6-scst
Found linux image: /boot/vmlinuz-2.6.32-21-server
Found initrd image: /boot/initrd.img-2.6.32-21-server
Found memtest86+ image: /boot/memtest86+.bin
done
root at storage00:reboot

-> Reboot perfectly no issues to note.
-> Setup DRBD.
root at storage00:apt-get install flex
root at storage00:cd ~
root at storage00:wget http://oss.linbit.com/drbd/8.3/drbd-8.3.7.tar.gz
root at storage00:tar zxvf drbd-8.3.7.tar.gz
root at storage00:cd drbd-8.3.7
root at storage00:./configure --with-utils --with-km=no --with-pacemaker=no 
--prefix=/usr --localstatedir=/var --sysconfdir=/etc
root at storage00:export CONCURRENCY_LEVEL=5
root at storage00:make clean
root at storage00:make KDIR=/usr/src/linux
root at storage00:make install
root at storage00:cp /etc/drbd.conf drbd.conf.orig
root at storage00:/etc# fdisk -l
Disk /dev/sda: 21.5 GB, 21474836480 bytes
255 heads, 63 sectors/track, 2610 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0x000dfa04

   Device Boot      Start         End      Blocks   Id  System
/dev/sda1   *           1        2432    19530752   83  Linux
/dev/sda2            2432        2494      498689    5  Extended
/dev/sda3            2494        2611      939008   83  Linux
/dev/sda5            2432        2494      498688   82  Linux swap / 
Solaris

Disk /dev/sdb: 42.9 GB, 42949672960 bytes
255 heads, 63 sectors/track, 5221 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0x0005e4f9

   Device Boot      Start         End      Blocks   Id  System
/dev/sdb1               1        5222    41940992   8e  Linux LVM

-> update /etc/drbd.conf

root at storage00:/etc# cat drbd.conf
global {
        usage-count no;
}

common {
        syncer { rate 110M; }
}
resource meta {
        protocol C;
        handlers {
         pri-on-incon-degr "echo O > /proc/sysrq-trigger ; halt -f";
         pri-lost-after-sb "echo O > /proc/sysrq-trigger ; halt -f";
         local-io-error "echo O > /proc/sysrq-trigger ; halt -f";
        }

        startup {
         # wfc-timeout 0;
         degr-wfc-timeout 120; # 2 minutes.
        }
        disk {
         on-io-error detach;
        }

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

        syncer {
         # rate 110M;
         # after "r2";
         al-extents 257;
        }

        on storage00 {
         device /dev/drbd0;
         disk /dev/sda3;
         address 192.168.1.10:7788;
         meta-disk internal;
        }

        on storage01 {
         device /dev/drbd0;
         disk /dev/sda3;
         address 192.168.1.11:7788;
         meta-disk internal;
        }
}

resource data {
        protocol C;
        startup {
         wfc-timeout 0; ## Infinite!
         degr-wfc-timeout 120; ## 2 minutes.
        }

        disk {
         on-io-error detach;
        }

        net {
         # timeout 60;
         # connect-int 10;
         # ping-int 10;
         # max-buffers 2048;
         # max-epoch-size 2048;
        }

        syncer {
         after "meta";
        }

        on storage00 {
         device /dev/drbd1;
         disk /dev/sdb1;
         address 192.168.1.10:7789;
         meta-disk internal;
        }
        on storage01 {
         device /dev/drbd1;
         disk /dev/sdb1;
         address 192.168.1.11:7789;
         meta-disk internal;
        }


root at storage00:/etc# drbdadm create-md meta
Writing meta data...
initializing activity log
NOT initialized bitmap
New drbd meta data block successfully created.
root at storage00:/etc# drbdadm create-md data
Writing meta data...
initializing activity log
NOT initialized bitmap
New drbd meta data block successfully created.
root at storage00:/etc/init.d/drbd start
root at storage00:drbdsetup /dev/drbd0 primary -o
root at storage00:drbdsetup /dev/drbd1 primary -o
root at storage00:/etc# /etc/init.d/drbd status
drbd driver loaded OK; device status:
version: 8.3.7 (api:88/proto:86-91)
srcversion: EE47D8BF18AC166BE219757
m:res   cs            ro               ds                 p  mounted 
fstype
0:meta  WFConnection  Primary/Unknown  UpToDate/DUnknown  C
1:data  WFConnection  Primary/Unknown  UpToDate/DUnknown  C

-> So far all looks good.
root at storage00:apt-get install lvm2
root at storage00:reboot
root at storage00:/etc/init.d/drbd start
root at storage00:~# drbdsetup /dev/drbd0 primary -o
root at storage00:~# drbdsetup /dev/drbd1 primary -o
root at storage00:~# /etc/init.d/drbd status
drbd driver loaded OK; device status:
version: 8.3.7 (api:88/proto:86-91)
srcversion: EE47D8BF18AC166BE219757
m:res   cs            ro               ds                 p  mounted 
fstype
0:meta  WFConnection  Primary/Unknown  UpToDate/DUnknown  C
1:data  WFConnection  Primary/Unknown  UpToDate/DUnknown  C
root at storage00:~#

-> update filter to filter = [ "r|/dev/sdb1|" ]
root at storage00:~# vim /etc/lvm/lvm.conf
root at storage00:~# vgscan
  Reading all physical volumes.  This may take a while...
root at storage00:~# pvcreate /dev/drbd1
  Physical volume "/dev/drbd1" successfully created
root at storage00:~# vgcreate esx-vol /dev/drbd1
  Volume group "esx-vol" successfully created
root at storage00:~# lvcreate -n test --size 20g esx-vol
  Logical volume "test" created
root at storage00:~#

->Setup SCST
root at storage00:cd ~/scst/
root at storage00:make scst scst_install iscsi iscsi_install scstadm 
scstadm_install
-> the only errors I get are
make[1]: /usr/lib/lsb/install_initd: Command not found
make[1]: [install] Error 127 (ignored)
/usr/lib/lsb/install_initd qla2x00t
make[1]: /usr/lib/lsb/install_initd: Command not found
make[1]: [install] Error 127 (ignored)
make[1]: Leaving directory `/root/scst/scstadmin'

-> Remove the scst_disk module from the startup file
root at storage00:vim /etc/init.d/scst
-> change the line SCST_MODULES="scst scst-disk scst_vdisk" to 
SCST_MODULES="scst scst_vdisk"
root at storage00:cd ~/scst/iscsi-scst
root at storage00:cp etc/initiators.* /etc
root at storage00:cp etc/iscsi-scstd.conf /etc
root at storage00:vim /etc/iscsi-scstd.conf
-> add Target iqn.2010-01.com.test:sn.00
root at storage00:touch /etc/scst.conf
root at storage00:/etc/init.d/scst start

[ 3319.098243] [3129]: scst_suspend_activity:673:suspend_count 0
[ 3319.098249] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098252] [3129]: scst_suspend_activity:718:Waiting for 0 active 
commands finally to complete
[ 3319.098269] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098314] [3129]: __scst_resume_activity:749:suspend_count 0 left
[ 3319.098317] [3129]: scst: scst_register_device:887:Attached to scsi0, 
channel 0, id 0, lun 0, type 0
[ 3319.098401] [3129]: scst_suspend_activity:673:suspend_count 0
[ 3319.098404] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098406] [3129]: scst_suspend_activity:718:Waiting for 0 active 
commands finally to complete
[ 3319.098408] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098413] [3129]: __scst_resume_activity:749:suspend_count 0 left
[ 3319.098415] [3129]: scst: scst_register_device:887:Attached to scsi0, 
channel 0, id 1, lun 0, type 0
[ 3319.098422] [3129]: scst_suspend_activity:673:suspend_count 0
[ 3319.098424] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098426] [3129]: scst_suspend_activity:718:Waiting for 0 active 
commands finally to complete
[ 3319.098428] [3129]: scst_susp_wait:639:wait_event() returned 0
[ 3319.098431] [3129]: __scst_resume_activity:749:suspend_count 0 left
[ 3319.098434] [3129]: scst: scst_register_device:887:Attached to scsi1, 
channel 0, id 0, lun 0, type 5
[ 3319.102968] [3131]: scst: scst_cmd_thread:4269:Processing thread 
scsi_tgt0 (PID 3131) started
[ 3319.104476] [3136]: scst: scst_cmd_thread:4269:Processing thread 
scsi_tgt1 (PID 3136) started
[ 3319.104642] [3137]: scst: scst_cmd_thread:4269:Processing thread 
scsi_tgt2 (PID 3137) started
[ 3319.104712] [3138]: scst: scst_cmd_thread:4269:Processing thread 
scsi_tgt3 (PID 3138) started
[ 3319.104878] [3139]: scst: scst_init_thread:4011:Init thread started, 
PID 3139
[ 3319.105085] [3140]: scst: scst_tm_thread:5789:Task management thread 
started, PID 3140
[ 3319.105204] [3129]: scst: init_scst:2255:SCST version 2.0.0-rc2-procfs 
loaded successfully (max mem for commands 249MB, per device 99MB)
[ 3319.105209] [3129]: scst: scst_print_config:2037:Enabled features: 
EXTRACHECKS, DEBUG
[ 3319.105666] [3141]: scst: scst_global_mgmt_thread:6527:Management 
thread started, PID 3141
[ 3319.110209] [3142]: scst: 
__scst_register_virtual_dev_driver:1427:Virtual device handler 
vdisk_fileio for type 0 registered successfully
[ 3319.110215] [3142]: scst: 
__scst_register_virtual_dev_driver:1427:Virtual device handler 
vdisk_blockio for type 0 registered successfully
[ 3319.110219] [3142]: scst: 
__scst_register_virtual_dev_driver:1427:Virtual device handler 
vdisk_nullio for type 0 registered successfully
[ 3319.110224] [3142]: scst: 
__scst_register_virtual_dev_driver:1427:Virtual device handler vcdrom for 
type 5 registered successfully

root at storage00:scstadmin -ClearConfig /etc/scst.conf
root at storage00:scstadmin -adddev sn.00 -path /dev/esx-vol/test -handler 
vdisk -options BLOCKIO

NOTE: it is BLOCKIO (I'm not sure if this has anything to do with it)

root at storage00:scstadmin -addgroup Default_iqn.2010-01.com.test:sn.00
root at storage00:scstadmin -assigndev sn.00 -group 
Default_iqn.2010-01.com.test:sn.00 -lun 0
root at storage00:scstadmin -WriteConfig /etc/scst.conf
root at storage00:vim /etc/initiators.allow
-> ALL ALL (this is just a test lab)

root at storage00:/etc/init.d/scst stop
root at storage00:/etc/init.d/scst start
root at storage00:/etc/init.d/iscsi-scst start

-> So everything seems ok.

root at storage00:~/scst/iscsi-scst# lvdisplay
  --- Logical volume ---
  LV Name                /dev/esx-vol/test
  VG Name                esx-vol
  LV UUID                Lpcu0q-LDrJ-XmHG-OjSp-NNXs-72BQ-A1TbUc
  LV Write Access        read/write
  LV Status              available
  # open                 0
  LV Size                20.00 GiB
  Current LE             5120
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           251:0

root at storage00:~/scst/iscsi-scst# /etc/init.d/drbd status
drbd driver loaded OK; device status:
version: 8.3.7 (api:88/proto:86-91)
srcversion: EE47D8BF18AC166BE219757
m:res   cs            ro               ds                 p  mounted 
fstype
0:meta  WFConnection  Primary/Unknown  UpToDate/DUnknown  C
1:data  WFConnection  Primary/Unknown  UpToDate/DUnknown  C

-> Now the clincher...
-> Simply connect to the box via iscsi (in this case a Windows VISTA x64) 
initiator Windows see's the machine, everything is working fine.
-> I can see the target isqn.2010-01.com.test:sn.00
-> I can Log on to it fine.

[ 3737.669348] [3196]: scst: scst_init_session:6265:Using security group 
"Default_iqn.2010-01.com.test:sn.00" for initiator 
"iqn.1991-05.com.microsoft:ad-desktop"
[ 3737.669492] [3196]: scst_alloc_add_tgt_dev:3203:Device sn.00 on SCST 
lun=0
[ 3737.669503] [3196]: scst_alloc_set_UA:6263:Adding new UA to tgt_dev 
ffff88003d95c000
[ 3737.669867] [3243]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_0 (PID 3243) started
[ 3737.669873] [3243]: scst_cmd_thread:4290:Alloced new IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.670132] [3244]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_1 (PID 3244) started
[ 3737.670136] [3244]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.670375] [3245]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_2 (PID 3245) started
[ 3737.670379] [3245]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.670618] [3246]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_3 (PID 3246) started
[ 3737.670795] [3246]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.670990] [3247]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_4 (PID 3247) started
[ 3737.670994] [3247]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.671279] [3248]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_5 (PID 3248) started
[ 3737.671283] [3248]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.671377] [3249]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_6 (PID 3249) started
[ 3737.671381] [3249]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.671611] [3196]: iscsi_session_alloc:96:Session ffff88003dc9c000 
created: target ffff88003d6bca00, tid 1, sid 0x1000037010040
[ 3737.671623] [3250]: scst: scst_cmd_thread:4269:Processing thread 
sn.000_7 (PID 3250) started
[ 3737.671626] [3196]: iscsi-scst: log_params:91:Negotiated parameters: 
InitialR2T No, ImmediateData Yes, MaxConnections 1, 
MaxRecvDataSegmentLength 1048576, MaxXmitDataSegmentLength 65536,
[ 3737.671632] [3250]: scst_cmd_thread:4309:Linked IO context 
ffff88003d341678 (p_cmd_threads ffff88003d95c0f0)
[ 3737.671637] [3196]: iscsi-scst: log_params:95:    MaxBurstLength 
262144, FirstBurstLength 65536, DefaultTime2Wait 0, DefaultTime2Retain 0,
[ 3737.671640] [3196]: iscsi-scst: log_params:101:    MaxOutstandingR2T 
16, DataPDUInOrder Yes, DataSequenceInOrder Yes, ErrorRecoveryLevel 0,
[ 3737.671644] [3196]: iscsi-scst: log_params:108:    HeaderDigest None, 
DataDigest None, OFMarker No, IFMarker No, OFMarkInt 2048, IFMarkInt 2048
[ 3737.671649] [3196]: iscsi-scst: iscsi_tgt_params_set:228:Target 
parameters set for session 1000037010040: QueuedCommands 32, Response 
timeout 30, Nop-In interval 30
[ 3737.671770] [3196]: iscsi_conn_alloc:727:Creating connection 
ffff88003cf6ec00 for sid 0x1000037010040, cid 1
[ 3737.671978] [3196]: conn_activate:590:Enabling conn ffff88003cf6ec00
[ 3737.675994] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
16777216), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.675999] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.676062] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
16777216): unblocking dev ffff88003d95b200
[ 3737.676066] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.677763] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
33554432), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.677768] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.677825] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
33554432): unblocking dev ffff88003d95b200
[ 3737.677828] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.679112] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
50331648), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.679116] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.679123] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
50331648): unblocking dev ffff88003d95b200
[ 3737.679132] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.680491] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
67108864), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.680496] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.680504] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
67108864): unblocking dev ffff88003d95b200
[ 3737.680507] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.682371] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
83886080), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.682516] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.682523] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
83886080): unblocking dev ffff88003d95b200
[ 3737.682526] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.694780] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b2000 (tag 
100663296), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.694790] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.694796] [3250]: scst_set_pending_UA:6119:Setting pending UA cmd 
ffff88003c4b2000
[ 3737.694807] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b2000 (tag 
100663296): unblocking dev ffff88003d95b200
[ 3737.694816] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200
[ 3737.696207] [0]: scst_inc_on_dev_cmd:6688:cmd ffff88003c4b21f8 (tag 
117440512), blocking further cmds due to possible double reset UA (dev 
ffff88003d95b200)
[ 3737.696212] [0]: __scst_block_dev:6583:Device BLOCK(new 1), dev 
ffff88003d95b200
[ 3737.696223] [3250]: scst_check_sense:2973:Clearing dbl_ua_possible flag 
(dev ffff88003d95b200, cmd ffff88003c4b21f8)
[ 3737.696229] [3250]: scst_dec_on_dev_cmd:619:cmd ffff88003c4b21f8 (tag 
117440512): unblocking dev ffff88003d95b200
[ 3737.696234] [0]: scst_unblock_dev:6626:Device UNBLOCK(new 0), dev 
ffff88003d95b200

-> again all working fine, now I open up Disk Manager on windows to 
"format the partition" prompted to initialise the disk.
-> Format the disk and I get pages and pages of
[ 1129.879296] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.879527] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.879657] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.879786] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.946005] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.946148] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.946276] block drbd1: al_complete_io() called on inactive extent 78
[ 1129.946403] block drbd1: al_complete_io() called on inactive extent 78
[ 1130.016112] block drbd1: al_complete_io() called on inactive extent 78

The console keeps incrementing the last number and of course the machine 
just grinds and grinds..
scrolling on the console window (but nothing in any logs, nothing in 
messages/syslog/debug etc) only outputs to dmesg

I'm at a loss, this is a brand new clean build. As per above, what step 
have a missed? or what else should I have done? 
Where do I go from here?

Regards
Adam
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.linbit.com/pipermail/drbd-user/attachments/20100719/70e95b57/attachment.htm>


More information about the drbd-user mailing list