TOPIC:

I noticed that iscsi-cfg status shows the DRBD Connection in "SyncSource state" - could that have anything to do with it?

SyncSource state just means that the drbd resource is still performing its initial sync. this should have no affect since the primary node is read/writable during the initial sync.

Another thing to check. I think that XenCenter has problems when managing multiple pools that have storage repositories that share the same LUN. Any chance you are using the same LUN a cross multiple pools?

If you continue to have trouble, send me a PM To This email address is being protected from spambots. You need JavaScript enabled to view it.

I see. Well, that makes sense.

You're correct about the LUN issue ; XenCenter does have that issue - but it manifests as telling you that the LUN is already in use by another pool. To avoid that completely, I'm working with this cluster on a XenCenter install on a different PC, that has no other pools related connected to it. I've also tried creating the SR via CLI on the pool mater, using the xe sr-create command. Same error.

I'm going to let the replication finish, and if it continues, I'll try failing over to the other host and see if that resolves the situation. If not, I'll email you. Thanks!

Also, if it helps: here is a snippet of the /var/log/user.log with the ha-lizard notifications filtered out so we're just seeing iscsi-ha events:

Dec 28 10:10:54 dc1-vda01 iscsi-ha: 26653 send_replication_network_arp: Updating ARP for device [ xapi1 ] IP [ 10.100.3.2 ]
Dec 28 10:10:55 dc1-vda01 iscsi-ha: iscsi-ha Watchdog: iscsi-ha running - OK
Dec 28 10:10:55 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: ARPING 10.100.3.2 from 10.100.3.2 xapi1
Dec 28 10:10:55 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Sent 2 probes (2 broadcast(s))
Dec 28 10:10:55 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Received 0 response(s)
Dec 28 10:10:55 dc1-vda01 iscsi-ha: 26653 send_replication_network_arp: Updating ARP for device [ xapi1 ] IP [ 10.100.3.1 ]
Dec 28 10:10:56 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: ARPING 10.100.3.1 from 10.100.3.1 xapi1
Dec 28 10:10:56 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Sent 2 probes (2 broadcast(s))
Dec 28 10:10:56 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Received 0 response(s)
Dec 28 10:11:00 dc1-vda01 iscsi-ha: iscsi-ha Watchdog: iscsi-ha running - OK
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 26637 Spawning new instance of iscsi-ha
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 26637 check_logger_processes Checking logger processes
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 26637 check_logger_processes No processes to clear
Dec 28 10:11:04 dc1-vda01 iscsi-ha: Normalized ISCSI_TARGET_SERVICE [ tgtd ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: XenServer Major Release = [ 7 ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: Mail Spool Directory Found /dev/shm/iscsi-ha-mail
Dec 28 10:11:04 dc1-vda01 iscsi-ha: This iteration is count 7863
Dec 28 10:11:04 dc1-vda01 iscsi-ha: Checking if this host is a Pool Master or Slave
Dec 28 10:11:04 dc1-vda01 iscsi-ha: This host's pool status = master
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: Execute [ status ] on [ iscsi-ha ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: System V mode detected
Dec 28 10:11:04 dc1-vda01 iscsi-ha: auto_plug_pbd: Found LVMoISCSI SR List:
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: [ OK ]#015iscsi-ha running: 6606
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: Returning exit status [ 0 ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 DRBD Running on this host: version: 8.4.5 (api:1/proto:86-101) srcversion: 2A6B2FA4F0703B49CA9C727 1: cs:SyncSource ro:Primary/Secondary ds:UpToDate/Inconsistent C r

---

ns:791608192 nr:0 dw:82048 dr:791530148 al:3 bm:0 lo:0 pe:0 ua:0 ap:0 ep:1 wo:f oos:1735344740 [===========>........] sync'ed: 62.9% (1694672/4564796)M finish: 11:46:06 speed: 40,944 (37,160) K/sec
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 validate_drbd_resources_loaded: Checking DRBD has loaded with resources. Checking [ 7 ] > [ 2 ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 validate_drbd_resources_loaded: Resources loaded
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 check_drbd_resource_state: DRBD Resource: iscsi1 in Primary mode
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 DRBD Resource: iscsi1 in SyncSource state - expected Connected state
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 email: Mail Spool Directory Found /dev/shm/iscsi-ha-mail
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 email: Duplicate message - not sending. Content = DRBD Resource: iscsi1 in SyncSource state - expected Connected state
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 email: Message barred for 30 minutes
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: Execute [ status ] on [ tgtd ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: systemctl mode being used
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: ● tgtd.service - tgtd iSCSI target daemon#012 Loaded: loaded (/usr/lib/systemd/system/tgtd.service; disabled; vendor preset: disabled)#012 Drop-In: /etc/systemd/system/tgtd.service.d#012 └─local.conf#012 Active: active (running) since Wed 2017-12-27 12:13:00 EST; 21h ago#012 Process: 7647 ExecStartPost=/usr/sbin/tgtadm --op update --mode sys --name State -v ready (code=exited, status=0/SUCCESS)#012 Process: 7616 ExecStartPost=/usr/sbin/tgt-admin -e -c $TGTD_CONFIG (code=exited, status=0/SUCCESS)#012 Process: 7612 ExecStartPost=/usr/sbin/tgtadm --op update --mode sys --name State -v offline (code=exited, status=0/SUCCESS)#012 Process: 7515 ExecStartPost=/bin/sleep 5 (code=exited, status=0/SUCCESS)#012 Main PID: 7509 (tgtd)#012 CGroup: /system.slice/tgtd.service#012 └─7509 /usr/sbin/tgtd -f
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 service_execute: Returning exit status [ 0 ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 iSCSI target: tgtd status = OK. [ active (running) since Wed 2017-12-27 12:13:00 EST; 21h ago ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 local_ip_list: Local IP list returned 127.0.0.1#01210.100.3.2#01210.100.3.1#01210.100.2.1#012192.168.10.120
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 CHECKING IP 127.0.0.1
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 CHECKING IP 10.100.3.2
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 CHECKING IP 10.100.3.1
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 Virtual IP: 10.100.3.1 discovered on host dc1-vda01
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 send_replication_network_arp: Sending ARP update to peer
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 send_replication_network_arp: IP address list for [ xapi1 ] = [ 10.100.3.2#01210.100.3.1 ]
Dec 28 10:11:04 dc1-vda01 iscsi-ha: 27515 send_replication_network_arp: Updating ARP for device [ xapi1 ] IP [ 10.100.3.2 ]
Dec 28 10:11:05 dc1-vda01 iscsi-ha: iscsi-ha Watchdog: iscsi-ha running - OK
Dec 28 10:11:05 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: ARPING 10.100.3.2 from 10.100.3.2 xapi1
Dec 28 10:11:05 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Sent 2 probes (2 broadcast(s))
Dec 28 10:11:05 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Received 0 response(s)
Dec 28 10:11:05 dc1-vda01 iscsi-ha: 27515 send_replication_network_arp: Updating ARP for device [ xapi1 ] IP [ 10.100.3.1 ]
Dec 28 10:11:06 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: ARPING 10.100.3.1 from 10.100.3.1 xapi1
Dec 28 10:11:06 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Sent 2 probes (2 broadcast(s))
Dec 28 10:11:06 dc1-vda01 iscsi-ha-NOTICE-/etc/iscsi-ha/init/iscsi-ha.mon: Received 0 response(s)

...and from /var/log/xensource.log:

Dec 28 12:20:51 dc1-vda01 xapi: [debug|dc1-vda01|875811 INET :::80||dummytaskhelper] task dispatch:pool.get_all D:259d0de041c2 created by task D:8c9fe256c407
Dec 28 12:20:51 dc1-vda01 xapi: [debug|dc1-vda01|996044 INET :::80||cli] xe host-list name-label=dc1-vda02 minimal=true username=root password=(omitted)
Dec 28 12:20:51 dc1-vda01 xapi: [ info|dc1-vda01|888524 INET :::80|session.logout D:9a60f8a64302|xapi] Session.destroy trackid=091cef235dc5a4db42aba267a5ca1db3
Dec 28 12:20:51 dc1-vda01 xapi: [debug|dc1-vda01|875811 INET :::80||dummytaskhelper] task dispatch:pool.get_all D:b08e0a1b026e created by task D:354224bee10b
Dec 28 12:20:51 dc1-vda01 xapi: [debug|dc1-vda01|996045 INET :::80||cli] xe sr-list type=lvmoiscsi minimal=true username=root password=(omitted)
Dec 28 12:20:51 dc1-vda01 xapi: [ info|dc1-vda01|888524 INET :::80|session.logout D:a0f1a3b5abc5|xapi] Session.destroy trackid=7386f34a146b34a9a55ff37253ee542d
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996046 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_all_records D:d972c21242d9 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996047 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.remove_from_other_config D:9b1f23ba48b3 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996047 UNIX /var/lib/xcp/xapi|dispatch:PBD.remove_from_other_config D:9b1f23ba48b3|api_effect] PBD.remove_from_other_config
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996048 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.add_to_other_config D:556d8e570ad3 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996048 UNIX /var/lib/xcp/xapi|dispatch:PBD.add_to_other_config D:556d8e570ad3|api_effect] PBD.add_to_other_config
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996051 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_other_config D:508740a7d814 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996052 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_sm_config D:546f8f2b7cd1 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996053 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:VM.get_all_records_where D:46788065aa4a created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996054 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_by_uuid D:a9c87dccd3b7 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996055 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_all_records D:4bf5eb101dd4 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996056 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:SR.get_all_records D:450964f67d53 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996057 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.get_all_records D:143f358ebc30 created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996058 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:PBD.remove_from_other_config D:ad6e349794ef created by task D:32ddbd98d513
Dec 28 12:20:53 dc1-vda01 xapi: [debug|dc1-vda01|996058 UNIX /var/lib/xcp/xapi|dispatch:PBD.remove_from_other_config D:ad6e349794ef|api_effect] PBD.remove_from_other_config
Dec 28 12:20:53 dc1-vda01 xapi: [ info|dc1-vda01|995929 |sm_exec D:d745e22822f1|xapi] Session.destroy trackid=e225735c2cbeb8076acc564864a914ee
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] sm_exec D:d745e22822f1 failed with exception Storage_interface.Backend_error(_)
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] Raised Storage_interface.Backend_error(_)
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 1/8 xapi @ dc1-vda01 Raised at file ocaml/xapi/sm_exec.ml, line 216
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 2/8 xapi @ dc1-vda01 Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 22
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 3/8 xapi @ dc1-vda01 Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 26
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 4/8 xapi @ dc1-vda01 Called from file ocaml/xapi/server_helpers.ml, line 73
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 5/8 xapi @ dc1-vda01 Called from file ocaml/xapi/server_helpers.ml, line 91
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 6/8 xapi @ dc1-vda01 Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 22
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 7/8 xapi @ dc1-vda01 Called from file hashtbl.ml, line 194
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace] 8/8 xapi @ dc1-vda01 Called from file lib/debug.ml, line 92
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|backtrace]
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 |SR.create D:32ddbd98d513|storage_access] SR.create failed SR:OpaqueRef:eee4b7f8-bcfc-4c8a-80a3-11832cf32585 error:INTERNAL_ERROR: [ Storage_interface.Backend_error(_) ]
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 ||backtrace] SR.create D:32ddbd98d513 failed with exception Storage_interface.Backend_error(_)
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 ||backtrace] Raised Storage_interface.Backend_error(_)
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 ||backtrace] 1/1 xapi @ dc1-vda01 Raised at file (Thread 995929 has no backtrace table. Was with_backtraces called?, line 0
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995929 ||backtrace]
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995836 INET :::80|dispatch:SR.create D:f6cc8c931da5|backtrace] SR.create R:b14517488dd8 failed with exception Server_error(SR_BACKEND_FAILURE_47, [ ; The SR is not available [opterr=Logical Volume group creation failed]; ])
Dec 28 12:20:53 dc1-vda01 xapi: [error|dc1-vda01|995836 INET :::80|dispatch:SR.create D:f6cc8c931da5|backtrace] Raised Server_error(SR_BACKEND_FAILURE_47, [ ; The SR is not available [opterr=Logical Volume group creation failed]; ])

can you try "vgdisplay" on the master and make sure that the VG is read/writeable?