[DRBD-user] Problem with resize of big volumes or new node add for one big volume (1Tb or more)
Baji Zsolt
bajizs at cnt.rs
Fri Jan 12 12:39:53 CET 2018
When we add new node for one big over drbdmanage, this is lot of time
unsuccessful. I have find in logs, that the lvm volume creation was
successful, and the drbd volume creation was successful too, but after
it the drbdmanage try to remove newly created lvm volume for unknown
reason. if I check drbdadm status I see that drbd sync started, but when
list assignments over drbdmanage I see two assignment for some volume in
some server with errors. I can not understand why want drbdmanage to
delete some of successfully created assignments. Logs in attachment:
Jan 12 02:00:26 hp02 dbus-drbdmanaged-service[6158]: Failed to find
logical volume "data/backup_00"
Jan 12 02:00:26 hp02 dbus-drbdmanaged-service[6158]: Rounding up size
to full physical extent 1.17 TiB
Jan 12 02:00:26 hp02 dbus-drbdmanaged-service[6158]: Logical volume
"backup_00" created.
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -vvv -c
/var/lib/drbdmanage/drbdmanage_backup.res --max-peers 7 -- --force
create-md backup/0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdmeta --force --node-id 1 104 v09
/dev/data/backup_00 internal set-gi AEDAE85F6CCE619C:
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdmeta': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:27 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -vvv adjust -c
/var/lib/drbdmanage/drbdmanage_backup.res backup
Jan 12 02:00:27 hp02 kernel: drbd backup: Starting worker thread (from
drbdsetup [12135])
Jan 12 02:00:27 hp02 kernel: drbd backup hp01: Starting sender thread
(from drbdsetup [12142])
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104: disk( Diskless ->
Attaching )
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104: Maximum number of
peer devices = 7
Jan 12 02:00:27 hp02 kernel: drbd backup: Method to ensure write
ordering: flush
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104 hp01: node_id: 0 idx:
0 bm-uuid: 0x0 flags: 0x0 max_size: 0 (DUnknown)
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104: my node_id: 1
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104 hp01: node_id: 0 idx:
0 bm-uuid: 0x0 flags: 0x0 max_size: 0 (DUnknown)
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104: my node_id: 1
Jan 12 02:00:27 hp02 kernel: drbd backup/0 drbd104: drbd_bm_resize
called with capacity == 2516582400
Jan 12 02:00:28 hp02 kernel: drbd backup/0 drbd104: resync bitmap:
bits=314572800 words=34406400 pages=67200
Jan 12 02:00:31 hp02 kernel: drbd backup/0 drbd104: recounting of set
bits took additional 268ms
Jan 12 02:00:31 hp02 kernel: drbd backup/0 drbd104: disk( Attaching ->
Inconsistent )
Jan 12 02:00:31 hp02 kernel: drbd backup/0 drbd104: attached to current
UUID: AEDAE85F6CCE619C
Jan 12 02:00:31 hp02 kernel: drbd backup hp01: conn( StandAlone ->
Unconnected )
Jan 12 02:00:31 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:31 hp02 kernel: drbd backup hp01: Starting receiver thread
(from drbd_w_backup [12136])
Jan 12 02:00:31 hp02 kernel: drbd backup hp01: conn( Unconnected ->
Connecting )
Jan 12 02:00:31 hp02 drbdmanaged[6158]: WARNING ThinLV: Volume
'backup_00' exists already, attempting to remove it.
Jan 12 02:00:31 hp02 drbdmanaged[6158]: WARNING ThinLV: Attempt 1 of
2: Removal of volume 'backup_00' failed.
Jan 12 02:00:31 hp02 dbus-drbdmanaged-service[6158]: Logical volume
data/backup_00 is used by another device.
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Handshake to peer 0
successful: Agreed network protocol version 112
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Feature flags enabled on
protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME.
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Peer authenticated using
20 bytes HMAC
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Starting ack_recv thread
(from drbd_r_backup [12159])
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Preparing remote state
change 1322273498 (primary_nodes=0, weak_nodes=0)
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: Committing remote state
change 1322273498
Jan 12 02:00:32 hp02 kernel: drbd backup hp01: conn( Connecting ->
Connected ) peer( Unknown -> Primary )
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104: current_size: 2516582400
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: c_size:
2516582400 u_size: 2516582400 d_size: 2518428088 max_size: 2518428088
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: la_size: 0
my_usize: 2516582400 my_max_size: 2518428088
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: node_id: 0 idx:
0 bm-uuid: 0x0 flags: 0x0 max_size: 2518428088 (DUnknown)
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104: my node_id: 1
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: calling
drbd_determine_dev_size()
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: node_id: 0 idx:
0 bm-uuid: 0x0 flags: 0x0 max_size: 2518428088 (DUnknown)
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104: my node_id: 1
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01:
drbd_sync_handshake:
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: self
AEDAE85F6CCE619C:0000000000000000:0000000000000000:0000000000000000
bits:0 flags:24
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: peer
5B777F53B6966F90:AEDAE85F6CCE619C:0000000000000000:0000000000000000
bits:314554800 flags:20
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01:
uuid_compare()=-2 by rule 50
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: pdsk( DUnknown
-> UpToDate ) repl( Off -> WFBitMapT )
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104: size = 1200 GB
(1258291200 KB)
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: receive bitmap
stats [Bytes(packets)]: plain 0(0), RLE 26(1), total 26; compression: 100.0%
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: send bitmap
stats [Bytes(packets)]: plain 0(0), RLE 26(1), total 26; compression: 100.0%
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: helper command:
/sbin/drbdadm before-resync-target
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: helper command:
/sbin/drbdadm before-resync-target exit code 0 (0x0)
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: repl( WFBitMapT
-> SyncTarget )
Jan 12 02:00:32 hp02 kernel: drbd backup/0 drbd104 hp01: Began resync as
SyncTarget (will sync 1258219200 KB [314554800 bits set]).
Jan 12 02:00:32 hp02 drbdmanaged[6158]: WARNING ThinLV: Attempt 2 of
2: Removal of volume 'backup_00' failed.
Jan 12 02:00:32 hp02 dbus-drbdmanaged-service[6158]: Logical volume
data/backup_00 is used by another device.
Jan 12 02:00:32 hp02 drbdmanaged[6158]: ERROR ThinLV: Removal of an
existing volume 'backup_00' failed. Unable to clean up and recreate the
volume, using existing volume.
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:32 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -vvv -c
/var/lib/drbdmanage/drbdmanage_backup.res --max-peers 7 -- --force
create-md backup/0
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR DrbdAdm: External
command 'drbdadm': Exit code 20
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stdout:
drbdmeta 104 v09 /dev/data/backup_00 internal create-md 7 --force
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
open(/dev/data/backup_00) failed: Device or resource busy
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Exclusive open failed. Do it anyways?
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr: ***
confirmation forced via --force option ***
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr: #
Output might be stale, since minor 104 is attached
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Device '104' is configured!
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Command 'drbdmeta 104 v09 /dev/data/backup_00 internal create-md 7
--force' terminated with exit code 20
Jan 12 02:00:33 hp02 drbdmanaged[6158]: ERROR DrbdManager: Failed
to create meta data for resource 'backup' volume 0
Jan 12 02:00:33 hp02 drbdmanaged[6158]: WARNING ThinLV: Volume
'backup_00' exists already, attempting to remove it.
Jan 12 02:00:33 hp02 drbdmanaged[6158]: WARNING ThinLV: Attempt 1 of
2: Removal of volume 'backup_00' failed.
Jan 12 02:00:33 hp02 dbus-drbdmanaged-service[6158]: Logical volume
data/backup_00 is used by another device.
Jan 12 02:00:34 hp02 drbdmanaged[6158]: WARNING ThinLV: Attempt 2 of
2: Removal of volume 'backup_00' failed.
Jan 12 02:00:34 hp02 dbus-drbdmanaged-service[6158]: Logical volume
data/backup_00 is used by another device.
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR ThinLV: Removal of an
existing volume 'backup_00' failed. Unable to clean up and recreate the
volume, using existing volume.
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm --config-to-test
/var/lib/drbdmanage/drbdmanage_backup.res.tmp --config-to-exclude
/var/lib/drbdmanage/drbdmanage_backup.res sh-nop
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -c
/var/lib/drbdmanage/drbdmanage_backup.res.tmp -d up backup
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: External
command 'drbdadm': Exit code 0
Jan 12 02:00:34 hp02 drbdmanaged[6158]: INFO DrbdAdm: Running
external command: drbdadm -vvv -c
/var/lib/drbdmanage/drbdmanage_backup.res --max-peers 7 -- --force
create-md backup/0
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR DrbdAdm: External
command 'drbdadm': Exit code 20
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stdout:
drbdmeta 104 v09 /dev/data/backup_00 internal create-md 7 --force
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
open(/dev/data/backup_00) failed: Device or resource busy
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Exclusive open failed. Do it anyways?
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr: ***
confirmation forced via --force option ***
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr: #
Output might be stale, since minor 104 is attached
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Device '104' is configured!
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR drbdadm/stderr:
Command 'drbdmeta 104 v09 /dev/data/backup_00 internal create-md 7
--force' terminated with exit code 20
Jan 12 02:00:34 hp02 drbdmanaged[6158]: ERROR DrbdManager: Failed
to create meta data for resource 'backup' volume 0
More information about the drbd-user
mailing list