Hi, I have been working with a 4 node cluster and have noticed some FIXME messages in the logs. Maybe the same as https://lists.linbit.com/pipermail/drbd-user/2019-June/025078.html
drbd90 kernel module version:9.0.22-2(later updated to 9.0.25-1) drbd90-utils:9.12.2-1 kernel:3.10.0-1127.18.2.el7.x86_64 pacemaker:1.1.21-4 corosync-2.4.5-4 system is centos:7.6 host is VMware ESXi FIXME messages seem to happen during initial sync/resync. Example from system log: Sep 21 17:02:17 cdc0 kernel: drbd r0 dh-cdc0-n3: Handshake to peer 3 successful: Agreed network protocol version 116 Sep 21 17:02:17 cdc0 kernel: drbd r0 dh-cdc0-n3: Feature flags enabled on protocol level: 0xf TRIM THIN_RESYNC WRITE_SAME WRITE_ZEROES. Sep 21 17:02:17 cdc0 kernel: drbd r0 dh-cdc0-n3: Starting ack_recv thread (from drbd_r_r0 [16881]) Sep 21 17:02:18 cdc0 kernel: drbd r0: Preparing cluster-wide state change 1184555410 (1->3 499/145) Sep 21 17:02:18 cdc0 kernel: drbd r0: State change 1184555410: primary_nodes=2, weak_nodes=FFFFFFFFFFFFFFF1 Sep 21 17:02:18 cdc0 kernel: drbd r0: Committing cluster-wide state change 1184555410 (1365ms) Sep 21 17:02:18 cdc0 kernel: drbd r0 dh-cdc0-n3: conn( Connecting -> Connected ) peer( Unknown -> Secondary ) Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: WRITE_SAME disabled by config Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: drbd_sync_handshake: Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: self 52067E32B742047A:FCB41408CC57E195:0000000000000000:0000000000000000 bits:994 flags:20 Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: peer 0000000000000004:0000000000000000:0000000000000000:0000000000000000 bits:0 flags:24 Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: uuid_compare()=source-set-bitmap by rule 30 Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: Writing the whole bitmap, full sync required after drbd_sync_handshake. Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[18134] op clear, bitmap locked for 'set_n_write from sync_handshake' by drbd_r_r0[16881] Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: pdsk( DUnknown -> Inconsistent ) repl( Off -> WFBitMapS ) Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: send bitmap stats [Bytes(packets)]: plain 0(0), RLE 21(1), total 21; compression: 100.0% Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: receive bitmap stats [Bytes(packets)]: plain 0(0), RLE 21(1), total 21; compression: 100.0% Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: helper command: /sbin/drbdadm before-resync-source Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: helper command: /sbin/drbdadm before-resync-source exit code 0 Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: repl( WFBitMapS -> SyncSource ) Sep 21 17:02:18 cdc0 kernel: drbd r0/0 drbd0 dh-cdc0-n3: Began resync as SyncSource (will sync 5144576 KB [1286144 bits set]). Sep 21 17:02:19 cdc0 kernel: drbd r0 dh-cdc0-n2: Preparing remote state change 3124969320 Sep 21 17:02:19 cdc0 kernel: drbd r0 dh-cdc0-n2: Committing remote state change 3124969320 (primary_nodes=2) I uninstalled the 9.0.22 kernel module rpm and compiled and installed the 9.0.25-1 version on all 4 nodes and resynced the partition(using 'drbdadm invalidate all' on the 3 secondary nodes) but I still see the FIXME messages: Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0 dh-cdc0-n3: Preparing remote state change 3729689878 Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0 dh-cdc0-n3: Committing remote state change 3729689878 (primary_nodes=2) Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: pdsk( UpToDate -> Consistent ) repl( Established -> StartingSyncS ) Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: pdsk( Consistent -> Outdated ) Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[27396] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: helper command: /sbin/drbdadm before-resync-source Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: helper command: /sbin/drbdadm before-resync-source exit code 0 Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: pdsk( Outdated -> Inconsistent ) repl( StartingSyncS -> SyncSource ) Oct 6 12:02:19 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n3: Began resync as SyncSource (will sync 5144576 KB [1286144 bits set]). Oct 6 12:02:21 dh-cdc0-n1 kernel: drbd r0/0 drbd0: new current UUID: 76D23070780C9DB1 weak: FFFFFFFFFFFFFFE1 Oct 6 12:02:23 dh-cdc0-n1 crmd[24427]: notice: State transition S_IDLE -> S_POLICY_ENGINE Oct 6 12:02:23 dh-cdc0-n1 pengine[24426]: notice: Calculated transition 3, saving inputs in /var/lib/pacemaker/pengine/pe-input-53.bz2 Oct 6 12:02:23 dh-cdc0-n1 crmd[24427]: notice: Transition 3 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-53.bz2): Complete Oct 6 12:02:23 dh-cdc0-n1 crmd[24427]: notice: State transition S_TRANSITION_ENGINE -> S_IDLE Oct 6 12:02:24 dh-cdc0-n1 crmd[24427]: notice: State transition S_IDLE -> S_POLICY_ENGINE Oct 6 12:02:24 dh-cdc0-n1 pengine[24426]: notice: Calculated transition 4, saving inputs in /var/lib/pacemaker/pengine/pe-input-54.bz2 Oct 6 12:02:24 dh-cdc0-n1 crmd[24427]: notice: Transition 4 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-54.bz2): Complete Oct 6 12:02:24 dh-cdc0-n1 crmd[24427]: notice: State transition S_TRANSITION_ENGINE -> S_IDLE Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0 dh-cdc0-n4: Preparing remote state change 1158604591 Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0 dh-cdc0-n4: Committing remote state change 1158604591 (primary_nodes=2) Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: pdsk( UpToDate -> Consistent ) repl( Established -> StartingSyncS ) Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: pdsk( Consistent -> Outdated ) Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0: FIXME drbd_a_r0[28404] op clear, bitmap locked for 'set_n_write from StartingSync' by drbd_w_r0[24628] Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0: bitmap page idx 11 changed during IO! Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: helper command: /sbin/drbdadm before-resync-source Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: pdsk( Outdated -> Inconsistent ) Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: helper command: /sbin/drbdadm before-resync-source exit code 0 Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: repl( StartingSyncS -> SyncSource ) Oct 6 12:02:30 dh-cdc0-n1 kernel: drbd r0/0 drbd0 dh-cdc0-n4: Began resync as SyncSource (will sync 5144576 KB [1286144 bits set]). Oct 6 12:02:36 dh-cdc0-n1 crmd[24427]: notice: Current ping state: S_IDLE Oct 6 12:02:40 dh-cdc0-n1 crmd[24427]: notice: State transition S_IDLE -> S_POLICY_ENGINE Oct 6 12:02:40 dh-cdc0-n1 pengine[24426]: notice: Calculated transition 5, saving inputs in /var/lib/pacemaker/pengine/pe-input-55.bz2 Oct 6 12:02:40 dh-cdc0-n1 crmd[24427]: notice: Transition 5 (Complete=0, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pacemaker/pengine/pe-input-55.bz2): Complete Oct 6 12:02:40 dh-cdc0-n1 crmd[24427]: notice: State transition S_TRANSITION_ENGINE -> S_IDLE Oct 6 12:02:41 dh-cdc0-n1 kernel: drbd r0/0 drbd0: new current UUID: 6BB40F1CCF845C01 weak: FFFFFFFFFFFFFFE1 Are these messages a problem or just noise? Regards, Jeremy
_______________________________________________ Star us on GITHUB: https://github.com/LINBIT drbd-user mailing list [email protected] https://lists.linbit.com/mailman/listinfo/drbd-user
