Mailing List Archive

Online verification skipped verify, too busy
Hello,

I have this setup with two replica, primary on lvm (datacenter ssd)
and secondary on zfs (datacenter ssd)

All works well but I want to verify it.

So I found some OOS and some skipped, I suspect that the OSS
was a false positive due to the high activity at the time... any idea?
Anyway I did a drbdadm disconnect and connect

The question is why some sectors was skipped and what shoud I do?

Below the logs, thanks for your attention!

Denis


version: 9.0.22-2 (api:2/proto:86-116)
GIT-hash: 719792f2cc1360c65c848ffdb66090959e27fde5 build by root@node2,
2020-04-24 14:04:55
Transports (api:16): tcp (9.0.22-2)


[Sun Jun 28 16:22:31 2020] drbd stor-node2 node2: Preparing remote state
change 2866147247
[Sun Jun 28 16:22:31 2020] drbd stor-node2 node2: Committing remote
state change 2866147247 (primary_nodes=1)
[Sun Jun 28 16:22:31 2020] drbd stor-node2/0 drbd1222 node2: repl(
Established -> VerifyT )
[Sun Jun 28 16:22:31 2020] drbd stor-node2/0 drbd1222: Online Verify
start sector: 0
[Sun Jun 28 17:17:39 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=47073208, size=25712 (sectors)
[Sun Jun 28 17:24:29 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=132786072, size=8 (sectors)
[Sun Jun 28 17:31:02 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=113871928, size=17848 (sectors)
[Sun Jun 28 17:33:15 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=154119224, size=23024 (sectors)
[Sun Jun 28 17:41:25 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=160350504, size=19600 (sectors)
[Sun Jun 28 17:41:27 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=183804632, size=24264 (sectors)
[Sun Jun 28 17:56:02 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=183893160, size=21120 (sectors)
[Sun Jun 28 17:56:03 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=227313536, size=17944 (sectors)
[Sun Jun 28 18:08:39 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=227364904, size=35936 (sectors)
[Sun Jun 28 18:08:44 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=259563408, size=6720 (sectors)
[Sun Jun 28 19:33:34 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=259758128, size=18488 (sectors)
[Sun Jun 28 19:34:15 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=502827808, size=6912 (sectors)
[Sun Jun 28 20:03:40 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=504813152, size=21168 (sectors)
[Sun Jun 28 20:34:25 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=664642232, size=8 (sectors)
[Sun Jun 28 20:34:37 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=664979448, size=8 (sectors)
[Sun Jun 28 20:34:42 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665139496, size=8 (sectors)
[Sun Jun 28 20:34:42 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665139664, size=8 (sectors)
[Sun Jun 28 20:34:42 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665139752, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665258560, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665258584, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665258904, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665258944, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665259248, size=8 (sectors)
[Sun Jun 28 20:34:49 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665259336, size=8 (sectors)
[Sun Jun 28 20:34:50 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665287312, size=8 (sectors)
[Sun Jun 28 20:34:50 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665287592, size=8 (sectors)
[Sun Jun 28 20:34:53 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=665322400, size=8 (sectors)
[Sun Jun 28 20:41:49 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=584780824, size=35536 (sectors)
[Sun Jun 28 20:48:35 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=685446824, size=23176 (sectors)
[Sun Jun 28 20:53:10 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=707061680, size=19912 (sectors)
[Sun Jun 28 22:08:11 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=718457776, size=21208 (sectors)
[Sun Jun 28 22:21:43 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=973231480, size=8 (sectors)
[Sun Jun 28 22:22:12 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=974514408, size=8 (sectors)
[Sun Jun 28 22:22:15 2020] drbd stor-node2/0 drbd1222 node2: Out of
sync: start=974654160, size=8 (sectors)
[Sun Jun 28 22:39:05 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=936978880, size=17888 (sectors)
[Sun Jun 28 22:45:56 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=1028544008, size=20664 (sectors)
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: Skipped
verify, too busy: start=1049394256, size=19880 (sectors)
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: Online
verify done but 49625 4k blocks skipped (total 34281 sec; paused 0 sec;
24468 K/sec)
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: Online
verify found 17 4k blocks out of sync!
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: repl(
VerifyT -> Established )
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm out-of-sync
[Mon Jun 29 01:53:54 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm out-of-sync exit code 0



[Mon Jun 29 09:24:39 2020] drbd stor-node2: Preparing cluster-wide state
change 3568948431 (1->0 496/16)
[Mon Jun 29 09:24:39 2020] drbd stor-node2: State change 3568948431:
primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFE
[Mon Jun 29 09:24:39 2020] drbd stor-node2 node2: Cluster is now split
[Mon Jun 29 09:24:39 2020] drbd stor-node2: Committing cluster-wide
state change 3568948431 (0ms)
[Mon Jun 29 09:24:39 2020] drbd stor-node2 node2: conn( Connected ->
Disconnecting ) peer( Primary -> Unknown )
[Mon Jun 29 09:24:39 2020] drbd stor-node2/0 drbd1222: disk( UpToDate ->
Outdated )
[Mon Jun 29 09:24:39 2020] drbd stor-node2/0 drbd1222 node2: pdsk(
UpToDate -> DUnknown ) repl( Established -> Off )
[Mon Jun 29 09:24:39 2020] drbd stor-node2 node2: ack_receiver terminated
[Mon Jun 29 09:24:39 2020] drbd stor-node2 node2: Terminating ack_recv
thread
[Mon Jun 29 09:24:40 2020] drbd stor-node2 node2: Aborting remote state
change 0 commit not possible
[Mon Jun 29 09:24:40 2020] drbd stor-node2 node2: Restarting sender thread
[Mon Jun 29 09:24:40 2020] drbd stor-node2 node2: Connection closed
[Mon Jun 29 09:24:40 2020] drbd stor-node2 node2: conn( Disconnecting ->
StandAlone )
[Mon Jun 29 09:24:40 2020] drbd stor-node2 node2: Terminating receiver
thread
[Mon Jun 29 09:24:48 2020] drbd stor-node2 node2: conn( StandAlone ->
Unconnected )
[Mon Jun 29 09:24:48 2020] drbd stor-node2 node2: Starting receiver
thread (from drbd_w_stor-pve [11351])
[Mon Jun 29 09:24:48 2020] drbd stor-node2 node2: conn( Unconnected ->
Connecting )
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Handshake to peer 0
successful: Agreed network protocol version 116
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Feature flags enabled
on protocol level: 0xf TRIM THIN_RESYNC WRITE_SAME WRITE_ZEROES.
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Peer authenticated
using 20 bytes HMAC
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Starting ack_recv
thread (from drbd_r_stor-pve [9095])
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Preparing remote state
change 1327599887
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: Committing remote
state change 1327599887 (primary_nodes=1)
[Mon Jun 29 09:24:49 2020] drbd stor-node2 node2: conn( Connecting ->
Connected ) peer( Unknown -> Primary )
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2:
drbd_sync_handshake:
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: self
A46181A69F5B2C5E:0000000000000000:646F7C83E8FFC96A:59AF1EFB1F88F6C6
bits:17 flags:120
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: peer
CBB75ACDAB4ED177:A46181A69F5B2C5F:508441C732E4D840:73F4F74963135314
bits:4529 flags:120
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2:
uuid_compare()=target-use-bitmap by rule 50
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: pdsk(
DUnknown -> UpToDate ) repl( Off -> WFBitMapT )
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: receive
bitmap stats [Bytes(packets)]: plain 0(0), RLE 1590(1), total 1590;
compression: 100.0%
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: send bitmap
stats [Bytes(packets)]: plain 0(0), RLE 1590(1), total 1590;
compression: 100.0%
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm before-resync-target
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm before-resync-target exit code 0
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222: disk( Outdated ->
Inconsistent )
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: repl(
WFBitMapT -> SyncTarget )
[Mon Jun 29 09:24:49 2020] drbd stor-node2/0 drbd1222 node2: Began
resync as SyncTarget (will sync 18120 KB [4530 bits set]).
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222 node2: Resync done
(total 8 sec; paused 0 sec; 2308 K/sec)
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222 node2: updated
UUIDs CBB75ACDAB4ED176:0000000000000000:646F7C83E8FFC96A:59AF1EFB1F88F6C6
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222: disk(
Inconsistent -> UpToDate )
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222 node2: repl(
SyncTarget -> Established )
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm after-resync-target
[Mon Jun 29 09:24:58 2020] drbd stor-node2/0 drbd1222 node2: helper
command: /sbin/drbdadm after-resync-target exit code 0


_______________________________________________
Star us on GITHUB: https://github.com/LINBIT
drbd-user mailing list
drbd-user@lists.linbit.com
https://lists.linbit.com/mailman/listinfo/drbd-user