<div dir="ltr">Hi,<div><br></div>Similar cases occurred twice on the sync replication mode.<div><br><div><span style="font-size:14px"><br></span></div><div><span style="font-size:14px">1. Env</span></div><div><span style="font-size:14px"><br></span></div>Ver: 9.0.1-1, CentOS 7</div><div><br>Conf: C mode, 2 nodes</div><div><br>Test step:</div><div><br>1) node1: primary<br>2) node2: status ok<br>3) node1: mount /dev/drbd1 /mnt<br>4) node1: cp 1Gfile /mnt/1Gfile<br>5) node1: disconnect by disable network icon on vmware, during copy<br>6) node2: "Connecting" status<br>7) node1: VM freezed<br><br><br><br><div>2. First test log => result was "vm hang" ---------------------------------------------------</div><div><br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0: State change 2572574344: primary_nodes=0, weak_nodes=0<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0: Committing cluster-wide state change 2572574344 (1ms)<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0 drbd9-02: conn( Connecting -> Connected ) peer( Unknown -> Secondary )<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1: peer does not support WRITE_SAME<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (250294391A486048) for nodes 2 3<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: drbd_sync_handshake:<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: self 91370AC369EB7EBC:0000000000000000:250294391A486048:64E351232E3278AC bits:0 flags:0<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: peer 91370AC369EB7EBC:0000000000000000:250294391A486048:0000000000000000 bits:0 flags:120<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: uuid_compare()=0 by rule 38<br>Feb 24 09:50:12 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( DUnknown -> UpToDate ) repl( Off -> Established )<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0: Preparing cluster-wide state change 3751236876 (0->-1 3/1)<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0: State change 3751236876: primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFC<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0: Committing cluster-wide state change 3751236876 (0ms)<br><br>1) primary<br><br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0: role( Secondary -> Primary )<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (250294391A486048) for nodes 2 3<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 09:50:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br>Feb 24 09:50:21 drbd9-01 kernel: loop: module loaded<br><br>2) mount<br><br>Feb 24 09:50:29 drbd9-01 kernel: EXT4-fs (drbd1): mounting ext3 file system using the ext4 subsystem<br>Feb 24 09:50:30 drbd9-01 kernel: EXT4-fs (drbd1): mounted filesystem with ordered data mode. Opts: (null)<br><br>3) copying<br><br>4) Disable Vmware network icon<br><br>Feb 24 09:50:47 drbd9-01 chronyd[894]: Selected source 211.233.84.186<br>Feb 24 09:50:48 drbd9-01 kernel: vmxnet3 0000:04:00.0 eth1: NIC Link is Down<br><br>5) drbd detects network down<br><br>Feb 24 09:50:59 drbd9-01 kernel: drbd r0 drbd9-02: PingAck did not arrive in time.<br>Feb 24 09:50:59 drbd9-01 kernel: drbd r0 drbd9-02: conn( Connected -> NetworkFailure ) peer( Secondary -> Unknown )<br>Feb 24 09:50:59 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( UpToDate -> DUnknown ) repl( Established -> Off )<br>Feb 24 09:50:59 drbd9-01 kernel: drbd r0 drbd9-02: ack_receiver terminated<br>Feb 24 09:50:59 drbd9-01 kernel: drbd r0 drbd9-02: Terminating ack_recv thread<br><br>Feb 24 09:51:04 drbd9-01 kernel: drbd r0/0 drbd1: new current UUID: 4FBB71EFAFB55C63 weak: FFFFFFFFFFFFFFFE<br>Feb 24 09:51:06 drbd9-01 gnome-session: ** (gnome-system-monitor:2888): WARNING **: SELinux was found but is not enabled.<br><br>5) Vm freezed!!!!<br><br>6) Reset<br><br>Feb 24 09:58:46 drbd9-01 rsyslogd: [origin software="rsyslogd" swVersion="7.4.7" x-pid="901" x-info="<a href="http://www.rsyslog.com">http://www.rsyslog.com</a>"] start<br>Feb 24 09:58:43 drbd9-01 journal: Runtime journal is using 6.1M (max 48.9M, leaving 73.4M of free 483.6M, current limit 48.9M).<br>Feb 24 09:58:43 drbd9-01 kernel: Initializing cgroup subsys cpuset<br>Feb 24 09:58:43 drbd9-01 kernel: Initializing cgroup subsys cpu<br>Feb 24 09:58:43 drbd9-01 kernel: Initializing cgroup subsys cpuacct<br>Feb 24 09:58:43 drbd9-01 kernel: Linux version 3.10.0-229.7.2.el7.x86_64 (<a href="mailto:builder@kbuilder.dev.centos.org">builder@kbuilder.dev.centos.org</a>) (gcc version 4.8.3 20140911 (Red Hat 4.8.3-9) (GCC) ) #1 SMP Tue Jun 23 22:06:11 UTC 2015<br><br><br><br><br><br>3. Second test log => result was "vm hang"---------------------------------------------------<br><br>Feb 24 10:14:16 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: helper command: /sbin/drbdadm before-resync-source exit code 0 (0x0)<br>Feb 24 10:14:16 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource )<br>Feb 24 10:14:16 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: Began resync as SyncSource (will sync 520192 KB [130048 bits set]).<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: updated UUIDs 4FBB71EFAFB55C62:0000000000000000:91370AC369EB7EBC:250294391A486048<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (91370AC369EB7EBC) for nodes 2 3<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: Resync done (total 36 sec; paused 0 sec; 14448 K/sec)<br>Feb 24 10:14:53 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( Inconsistent -> UpToDate ) repl( SyncSource -> Established )<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0: Preparing cluster-wide state change 1752829256 (0->-1 3/1)<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0: State change 1752829256: primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFC<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0: Committing cluster-wide state change 1752829256 (1ms)<br><br>1) primary<br><br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0: role( Secondary -> Primary )<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (91370AC369EB7EBC) for nodes 2 3<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 10:15:08 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br><br>2) mountFeb 24 10:15:15 drbd9-01 kernel: EXT4-fs (drbd1): mounting ext3 file system using the ext4 subsystem<br>Feb 24 10:15:15 drbd9-01 kernel: EXT4-fs (drbd1): recovery complete<br>Feb 24 10:15:15 drbd9-01 kernel: EXT4-fs (drbd1): mounted filesystem with ordered data mode. Opts: (null)<br><br>3) Disconnect during copy<br><br>Feb 24 10:15:36 drbd9-01 kernel: vmxnet3 0000:04:00.0 eth1: NIC Link is Down<br>Feb 24 10:15:46 drbd9-01 kernel: drbd r0 drbd9-02: PingAck did not arrive in time.<br>Feb 24 10:15:46 drbd9-01 kernel: drbd r0 drbd9-02: conn( Connected -> NetworkFailure ) peer( Secondary -> Unknown )<br>Feb 24 10:15:46 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( UpToDate -> DUnknown ) repl( Established -> Off )<br>Feb 24 10:15:46 drbd9-01 kernel: drbd r0 drbd9-02: ack_receiver terminated<br>Feb 24 10:15:46 drbd9-01 kernel: drbd r0 drbd9-02: Terminating ack_recv thread<br>Feb 24 10:15:47 drbd9-01 kernel: drbd r0/0 drbd1: new current UUID: 12FA4E882B5DB5FD weak: FFFFFFFFFFFFFFFE<br><br>4) Vm freezed!!!<br><br>5) Reset<br><br>Feb 24 10:18:42 drbd9-01 rsyslogd: [origin software="rsyslogd" swVersion="7.4.7" x-pid="897" x-info="<a href="http://www.rsyslog.com">http://www.rsyslog.com</a>"] start<br>Feb 24 10:18:39 drbd9-01 journal: Runtime journal is using 6.1M (max 48.9M, leaving 73.4M of free 483.6M, current limit 48.9M).<br>Feb 24 10:18:39 drbd9-01 kernel: Initializing cgroup subsys cpuset<br>Feb 24 10:18:39 drbd9-01 kernel: Initializing cgroup subsys cpu<br>Feb 24 10:18:39 drbd9-01 kernel: Initializing cgroup subsys cpuacct<br>Feb 24 10:18:39 drbd9-01 kernel: Linux version 3.10.0-229.7.2.el7.x86_64 (<a href="mailto:builder@kbuilder.dev.centos.org">builder@kbuilder.dev.centos.org</a>) (gcc version 4.8.3 20140911 (Red Hat 4.8.3-9) (GCC) ) #1 SMP Tue Jun 23 22:06:11 UTC 2015<br><br><br><br><br><br>4. Third test log => result was "Normal" !!!!----------------------------------------------------<br><br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0: Preparing cluster-wide state change 4126890108 (0->-1 3/1)<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0: State change 4126890108: primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFC<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0: Committing cluster-wide state change 4126890108 (0ms)<br><br>1) Primary<br><br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0: role( Secondary -> Primary )<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (4FBB71EFAFB55C62) for nodes 2 3<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 10:25:51 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br><br>2) mount<br><br>Feb 24 10:26:09 drbd9-01 kernel: EXT4-fs (drbd1): mounting ext3 file system using the ext4 subsystem<br>Feb 24 10:26:09 drbd9-01 kernel: EXT4-fs (drbd1): recovery complete<br>Feb 24 10:26:09 drbd9-01 kernel: EXT4-fs (drbd1): mounted filesystem with ordered data mode. Opts: (null)<br><br>3) Disconnect during copy<br><br>Feb 24 10:26:33 drbd9-01 kernel: vmxnet3 0000:04:00.0 eth1: NIC Link is Down<br>Feb 24 10:26:43 drbd9-01 kernel: drbd r0 drbd9-02: PingAck did not arrive in time.<br>Feb 24 10:26:43 drbd9-01 kernel: drbd r0 drbd9-02: conn( Connected -> NetworkFailure ) peer( Secondary -> Unknown )<br>Feb 24 10:26:43 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( UpToDate -> DUnknown ) repl( Established -> Off )<br>Feb 24 10:26:43 drbd9-01 kernel: drbd r0 drbd9-02: ack_receiver terminated<br>Feb 24 10:26:43 drbd9-01 kernel: drbd r0 drbd9-02: Terminating ack_recv thread<br>Feb 24 10:26:57 drbd9-01 kernel: drbd r0/0 drbd1: new current UUID: C4E750298906134D weak: FFFFFFFFFFFFFFFE<br><br>4) It's normal case. No Vm freeze!!<br><br>Feb 24 10:26:57 drbd9-01 kernel: drbd r0 drbd9-02: Connection closed<br>Feb 24 10:26:57 drbd9-01 kernel: drbd r0 drbd9-02: conn( NetworkFailure -> Unconnected )<br>Feb 24 10:26:57 drbd9-01 kernel: drbd r0 drbd9-02: Restarting receiver thread<br>Feb 24 10:26:57 drbd9-01 kernel: drbd r0 drbd9-02: conn( Unconnected -> Connecting )<br>Feb 24 10:30:02 drbd9-01 systemd: Starting Session 3 of user root.<br>Feb 24 10:30:02 drbd9-01 systemd: Started Session 3 of user root.<br><br>5) Connct by enabling VM network icon<br><br>Feb 24 10:31:12 drbd9-01 kernel: vmxnet3 0000:04:00.0 eth1: NIC Link is Up 10000 Mbps<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0 drbd9-02: Handshake successful: Agreed network protocol version 111<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0 drbd9-02: Feature flags enabled on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME.<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0 drbd9-02: Starting ack_recv thread (from drbd_r_r0 [2835])<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0: Preparing cluster-wide state change 478233498 (0->1 499/145)<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0: State change 478233498: primary_nodes=1, weak_nodes=FFFFFFFFFFFFFFFC<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0: Committing cluster-wide state change 478233498 (1ms)<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0 drbd9-02: conn( Connecting -> Connected ) peer( Unknown -> Secondary )<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1: peer does not support WRITE_SAME<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: unexpected<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: In UUIDs from node 1 found equal UUID (4FBB71EFAFB55C62) for nodes 2 3<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=2<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: I have 64E351232E3278AC for node_id=3<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: drbd_sync_handshake:<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: self C4E750298906134D:12FA4E882B5DB5FC:4FBB71EFAFB55C62:91370AC369EB7EBC bits:204521 flags:0<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: peer 12FA4E882B5DB5FC:0000000000000000:4FBB71EFAFB55C62:0000000000000000 bits:0 flags:100<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: uuid_compare()=2 by rule 70<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( DUnknown -> Consistent ) repl( Off -> WFBitMapS )<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: send bitmap stats [Bytes(packets)]: plain 0(0), RLE 124(1), total 124; compression: 100.0%<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( Consistent -> Outdated )<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: receive bitmap stats [Bytes(packets)]: plain 0(0), RLE 124(1), total 124; compression: 100.0%<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: helper command: /sbin/drbdadm before-resync-source<br>Feb 24 10:31:13 drbd9-01 drbdadm[3274]: Don't know which config file belongs to resource r0, trying default ones...<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: helper command: /sbin/drbdadm before-resync-source exit code 0 (0x0)<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource )<br>Feb 24 10:31:13 drbd9-01 kernel: drbd r0/0 drbd1 drbd9-02: Began resync as SyncSource (will sync 818084 KB [204521 bits set]).<div><div class="gmail_extra"><br></div><div class="gmail_extra"><br></div><div class="gmail_extra"><div class="gmail_quote">2016-02-12 16:02 GMT+09:00 김재헌 <span dir="ltr"><<a href="mailto:jhkim@mantech.co.kr" target="_blank">jhkim@mantech.co.kr</a>></span>:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr"><div style="font-size:14px">Hi,</div><div style="font-size:14px"><br></div><div style="font-size:14px">This problem is reproduced on your latest 9.0.1-1 version also.</div><div style="font-size:14px"><br></div><div style="font-size:14px">1. Test version</div><div style="font-size:14px"> - CentOS-7 Linux 3.10.0-229.7.2.el7.x86_64</div><div style="font-size:14px">- [root@drbd9-02 etc]# cat /proc/drbd<br></div><div style="font-size:14px"><div> version: 9.0.1-1 (api:2/proto:86-111)</div><div> GIT-hash: f57acfc22d29a95697e683fb6bbacd9a1ad4348e build by root@drbd9-02, 2016-02-09 09:46:20</div><div> Transports (api:14): tcp (1.0.0)</div><br><br>2. Test scenario</div><div style="font-size:14px"> 1) setup primary-seconary<br> 2) set Async replication mode(sndbuf=1M, congestion-fill=256KB)</div><div style="font-size:14px"> 3) copy big file(4GB)</div><div style="font-size:14px"> 4) disconnect by disable vmware's network icon while copying</div><div style="font-size:14px"> 5) Result:</div><div style="font-size:14px"> - VM hang sometimes!!!!</div><div style="font-size:14px"><br><br>3. Log (/var/log/messages) analysys:</div><div style="font-size:14px">1) promote to primary</div><div style="font-size:14px"></div></div></blockquote><div><br></div><div> </div><div><span style="font-size:14px">[snip]</span><br></div><div><span style="font-size:14px"><br></span></div><div><span style="font-size:14px"><br></span></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr"><div style="font-size:14px"><br></div><div style="font-size:14px">4. Question</div><div style="font-size:14px"><div> - Please see above 10), 11) points, I think It's deadlock.<br></div><div> - the worker and receiver threads may be deadlocked by race condition for data socket.</div><div><br></div><div>Thanks</div></div><div><br></div><div><div dir="ltr"><div><div dir="ltr"><p style="margin:0cm 0cm 0.0001pt;line-height:21px"><span lang="EN-US" style="font-size:8pt;line-height:16px;font-family:'\00b9d1\00c740 \00ace0\00b515';color:rgb(127,127,127)"><br></span></p></div></div></div></div>
</div>
</blockquote></div><br><br><br><br>Please carefully compare the first and second hang logs with the third normal log.<br><br>Thanks.</div><div class="gmail_extra"><br clear="all"><div><br></div>
</div></div></div></div></div>