Stuck geom and middlewareerror trying to reuse disks from iSCSI device extent.

[ddayton]

Hostname.........: RVDPA-VEEAMNAS02.mittalco.com
Build................: FreeNAS-8.2.0-RELEASE-p1-x64 (r11950)
Platform...........: Intel(R) Core(TM)2 CPU E8400 @ 3.00GHz
Memory...........: 963MB
System Time....: Mon Nov 19 08:46:05 CST 2012
Uptime............: 8:46AM up 11:11, 0 users
Load Average...: 0.08, 0.04, 0.01

On this system at first I tried zfs, but obviously it had insuffient RAM, so I created two ufs RAID 1 volumes and used CIFS to share them. These volumes are target storage for backing up my VMware files using Veeam Backup. Installed in the desktop computer are four 2TB SATA drives.

All was working fine but I had heard iSCSI was better than CIFS so I decided to give iSCSI a try. I deleted the CIFS share for RAID 1 volume with ada2 and ada3 with a destroy. I added them as Device Extents (extent2 and extent3) and targets (iSCSI2 and iSCSI3). This worked fine, but I wanted RAID protection so decided to try instead using a file based extent to a ufs RAID 1 volume (path "/mnt/VeeamBackup/data" size 1600GB). After removing the extents and targets it left these two disks unusable. I can't create any kind of volume, import or even set them back as an iSCSI device extent. Now the weird thing is I then did the same with ada0 and ada1 and it worked without a problem.

When I tried to create the volume iSCSI1 as ufs RAID 1 it failed, but now when I try auto import volume it see iSCSI1(geom). I assume removing this from the list may be the ticket to success, but can' figure out how. It appears during the reboot an attempt is even made to mount iSCSI1 volume, but below in the log you can see this and all my attempts at wiping the disk, auto imports, etc.

LOG:

Nov 18 21:36:01 RVDPA-VEEAMNAS02 newsyslog[1305]: logfile first created
Nov 18 21:36:01 RVDPA-VEEAMNAS02 syslogd: kernel boot file is /boot/kernel/kernel
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: Copyright (c) 1992-2011 The FreeBSD Project.
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: The Regents of the University of California. All rights reserved.
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: FreeBSD 8.2-RELEASE-p9 #0: Thu Jul 19 12:39:10 PDT 2012
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: root@build.ixsystems.com:/build/home/jpaetzel/8.2.0/os-base/amd64/build/home/jpaetzel/8.2.0/FreeBSD/src/sys/FREENAS.amd64 amd64
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: CPU: Intel(R) Core(TM)2 CPU E8400 @ 3.00GHz (3001.46-MHz K8-class CPU)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: Origin = "GenuineIntel" Id = 0x1067a Family = 6 Model = 17 Stepping = 10
...
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada0 at ahcich0 bus 0 scbus4 target 0 lun 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada0: ATA-8 SATA 2.x deviceda0 at umass-sim0 bus 0 scbus10 target 0 lun 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: da0: Removable Direct Access SCSI-0 device
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: da0: 40.000MB/s transfers
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: da0: 3864MB (7913472 512 byte sectors: 255H 63S/T 492C)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel:
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada0: Command Queueing enabled
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada0: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada1 at ahcich1 bus 0 scbus5 target 0 lun 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada1: ATA-8 SATA 2.x device
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada1: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada1: Command Queueing enabled
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada1: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada2 at ahcich2 bus 0 scbus6 target 0 lun 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada2: ATA-8 SATA 2.x device
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada2: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada2: Command Queueing enabled
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada2: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada3 at ahcich4 bus 0 scbus8 target 0 lun 0
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada3: ATA-8 SATA 2.x device
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada3: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada3: Command Queueing enabled
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: ada3: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: SMP: AP CPU #1 Launched!
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: GEOM: da0s1: geometry does not match label (16h,63s != 255h,63s).
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: GEOM_MIRROR: Device mirror/iSCSI0 launched (2/2).
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: GEOM_MIRROR: Device mirror/iSCSI1 launched (2/2).
Nov 18 21:36:01 RVDPA-VEEAMNAS02 kernel: Trying to mount root from ufs:/dev/ufs/FreeNASs1a
Nov 18 21:36:01 RVDPA-VEEAMNAS02 root: /etc/rc: WARNING: Dump device does not exist. Savecore not run.
Nov 18 21:36:01 RVDPA-VEEAMNAS02 ntpd[1471]: ntpd 4.2.4p5-a (1)
Nov 18 21:36:01 RVDPA-VEEAMNAS02 root: /etc/rc: WARNING: failed precmd routine for vmware_guestd
Nov 18 21:36:13 RVDPA-VEEAMNAS02 kernel: ZFS NOTICE: Prefetch is disabled by default if less than 4GB of RAM is present;
Nov 18 21:36:13 RVDPA-VEEAMNAS02 kernel: to enable, add "vfs.zfs.prefetch_disable=0" to /boot/loader.conf.
Nov 18 21:36:13 RVDPA-VEEAMNAS02 kernel: ZFS filesystem version 4
Nov 18 21:36:13 RVDPA-VEEAMNAS02 kernel: ZFS storage pool version 15
Nov 18 21:39:19 RVDPA-VEEAMNAS02 ntpd[1472]: time reset +1.137946 s
Nov 18 21:40:17 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 21:40:17 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 21:40:17 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 21:40:17 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 21:40:17 RVDPA-VEEAMNAS02 notifier: geom: Command 'load' not available.
Nov 18 21:40:17 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Volume creation failed: "geom: Can't store metadata on /dev/ada2: Operation not permitted., "]
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: istgt not running? (check /var/run/istgt.pid).
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: istgt not running? (check /var/run/istgt.pid).
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: Starting istgt.
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: istgt version 0.4 (20111008)
Nov 18 21:42:17 RVDPA-VEEAMNAS02 istgt[3128]: istgt version 0.4 (20111008)
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: normal mode
Nov 18 21:42:17 RVDPA-VEEAMNAS02 istgt[3128]: normal mode
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: istgt_lu.c: 911:istgt_lu_check_iscsi_name: ***ERROR*** invalid iqn format. expect "iqn.YYYY-MM.reversed.domain.name"
Nov 18 21:42:17 RVDPA-VEEAMNAS02 istgt[3128]: istgt_lu.c: 911:istgt_lu_check_iscsi_name: ***ERROR*** invalid iqn format. expect "iqn.YYYY-MM.reversed.domain.name"
Nov 18 21:42:17 RVDPA-VEEAMNAS02 istgt[3128]: istgt_lu.c:1287:istgt_lu_add_unit: ***ERROR*** TargetName iqn.RVDPA-VEEAMNAS02.istgt:iscsi0 contains an invalid character or format.
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: istgt_lu.c:1287:istgt_lu_add_unit: ***ERROR*** TargetName iqn.RVDPA-VEEAMNAS02.istgt:iscsi0 contains an invalid character or format.
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3 HDD UNIT
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 file=/mnt/iSCSI0/VeeamBackup/data, size=1717986918400
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 3355443200 blocks, 512 bytes/block
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 1600.0GB storage for iqn.RVDPA-VEEAMNAS02.istgt:iscsi0
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 serial 001cc008074c020
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 read cache enabled, write cache enabled
Nov 18 21:42:17 RVDPA-VEEAMNAS02 notifier: LU3: LUN0 command queuing enabled, depth 32
Nov 18 21:42:18 RVDPA-VEEAMNAS02 istgt[3129]: Login from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on iqn.rvdpa-veeamnas02.istgt:iscsi0 LU3 (10.130.151.132:3260,1), ISID=400001370000, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:43:33 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 18 21:43:33 RVDPA-VEEAMNAS02 notifier: gpart: geom 'ada3': Operation not permitted
Nov 18 21:43:33 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 18 21:43:33 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Failed to wipe ada3: dd: /dev/ada3: Operation not permitted ]
Nov 18 21:43:46 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada2': Invalid argument
Nov 18 21:43:46 RVDPA-VEEAMNAS02 notifier: gpart: geom 'ada2': Operation not permitted
Nov 18 21:43:46 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada2': Invalid argument
Nov 18 21:43:46 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Failed to wipe ada2: dd: /dev/ada2: Operation not permitted ]
Nov 18 21:45:47 RVDPA-VEEAMNAS02 istgt[3129]: istgt_lu.c: 465:istgt_lu_find_target: ***WARNING*** can't find target iqn.rvdpa-veeamnas02.istgt:iscsi2
Nov 18 21:45:47 RVDPA-VEEAMNAS02 istgt[3129]: istgt_iscsi.c:2088:istgt_iscsi_op_login: ***ERROR*** lu_find_target() failed
Nov 18 21:45:48 RVDPA-VEEAMNAS02 istgt[3129]: istgt_lu.c: 465:istgt_lu_find_target: ***WARNING*** can't find target iqn.rvdpa-veeamnas02.istgt:iscsi3
Nov 18 21:45:48 RVDPA-VEEAMNAS02 istgt[3129]: istgt_iscsi.c:2088:istgt_iscsi_op_login: ***ERROR*** lu_find_target() failed
Nov 18 21:45:48 RVDPA-VEEAMNAS02 istgt[3129]: Login from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on iqn.rvdpa-veeamnas02.istgt:iscsi0 LU3 (10.130.151.132:3260,1), ISID=400001370001, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:45:50 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:45:50 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:51:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 21:51:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 21:51:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 21:51:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 21:51:01 RVDPA-VEEAMNAS02 notifier: geom: Command 'load' not available.
Nov 18 21:51:01 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Volume creation failed: "geom: Can't store metadata on /dev/ada2: Operation not permitted., "]
Nov 18 21:54:33 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:54:33 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:54:50 RVDPA-VEEAMNAS02 ntpd[1472]: kernel time sync status change 2001
Nov 18 21:59:28 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=3, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:59:28 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=3, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:59:31 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 21:59:31 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 22:08:15 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=5, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 22:08:15 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=5, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 22:08:22 RVDPA-VEEAMNAS02 istgt[3129]: Login(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=6, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 22:08:22 RVDPA-VEEAMNAS02 istgt[3129]: Logout(discovery) from iqn.1991-05.com.microsoft:rvdpa-wsus.americas.mittalco.com (10.130.151.138) on (10.130.151.132:3260,1), ISID=400001370000, TSIH=6, CID=1, HeaderDigest=off, DataDigest=off
Nov 18 22:30:15 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 22:30:15 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 22:30:15 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 22:30:15 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 22:30:15 RVDPA-VEEAMNAS02 notifier: geom: Command 'load' not available.
Nov 18 22:30:15 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Volume creation failed: "geom: Can't store metadata on /dev/ada2: Operation not permitted., "]
Nov 18 22:30:36 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 22:30:36 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 22:30:36 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Unable to GPT format the disk "ada2"]
Nov 18 22:30:55 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 22:30:55 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 22:30:55 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Unable to GPT format the disk "ada3"]
Nov 18 23:33:13 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 18 23:33:13 RVDPA-VEEAMNAS02 notifier: gpart: geom 'ada3': Operation not permitted
Nov 18 23:33:13 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 18 23:33:13 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Failed to wipe ada3: dd: /dev/ada3: Operation not permitted ]
Nov 18 23:36:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 23:36:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 18 23:36:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 23:36:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 18 23:36:01 RVDPA-VEEAMNAS02 notifier: geom: Command 'load' not available.
Nov 18 23:36:01 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Volume creation failed: "geom: Can't store metadata on /dev/ada2: Operation not permitted., "]
Nov 19 00:04:30 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada2': Invalid argument
Nov 19 00:04:30 RVDPA-VEEAMNAS02 notifier: gpart: geom 'ada2': Operation not permitted
Nov 19 00:04:30 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada2': Invalid argument
Nov 19 00:04:30 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Failed to wipe ada2: dd: /dev/ada2: Operation not permitted ]
Nov 19 00:04:31 RVDPA-VEEAMNAS02 manage.py: [storage.views:985] Could not check for disk wipe progress: [Errno 3] No such process
Nov 19 00:04:33 RVDPA-VEEAMNAS02 last message repeated 2 times
Nov 19 00:05:01 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 19 00:05:01 RVDPA-VEEAMNAS02 notifier: gpart: geom 'ada3': Operation not permitted
Nov 19 00:05:01 RVDPA-VEEAMNAS02 notifier: gpart: geom '/dev/ada3': Invalid argument
Nov 19 00:05:01 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Failed to wipe ada3: dd: /dev/ada3: Operation not permitted ]
Nov 19 00:05:02 RVDPA-VEEAMNAS02 manage.py: [storage.views:985] Could not check for disk wipe progress: Nov 19 09:10:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 19 09:10:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada2: Operation not permitted
Nov 19 09:10:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 19 09:10:01 RVDPA-VEEAMNAS02 notifier: dd: /dev/ada3: Operation not permitted
Nov 19 09:10:01 RVDPA-VEEAMNAS02 notifier: geom: Command 'load' not available.
Nov 19 09:10:01 RVDPA-VEEAMNAS02 manage.py: [middleware.exceptions:38] [MiddlewareError: Volume creation failed: "geom: Can't store metadata on /dev/ada2: Operation not permitted., "]

 

[jgreco]

I'd say:

1) DBAN the disks
2) Reload the USB drive (possibly after saving the configuration if it matters to you)
3) Move on with life

There could well be a bug in there but it isn't clear to me exactly what's gone wrong. FreeBSD likes to prevent writes to the critical areas of disks in most cases unless sysctl geom.debugflags=16, so it's possible there's a code path where that didn't happen and a failure wasn't properly detected and now you're hosed until you fix it manually, in which case the fix that's virtually guaranteed to work is listed in 1-3) above.

 

[ddayton]

Assuming I try 1) DBAN the disks. I am not familar with "DBAN". As far as unix (freeBSD) I am pretty green. FreeNAS has been pretty much plug-and-play up until this point, so I haven't had to learn too much. I will try to Google DBAN, but if you could please elaborate. Saving my configuration probably won't work because the error might restore with it. The first volume already has close to a terabyte of data backed up to it that took more than 24 hours to create, so I pretty much would like to fix the second volume without destroying the first volume or whole system.

Thanks,
Don

 

[jgreco]

Ah. Well, DBAN will wipe your disk clean. It's a trivial way to start fresh. Good thing to run before you get rid of a drive too.

I'm out of time right now so maybe someone else will be able to determine what's happened... it's almost certainly recoverable if that's what you want or need though.

 

[ddayton]

I Googled and download the DBAN iso. I'll have to go out to our DR site later today to insert and boot the disk. I assume it will list the four disks in the system and allow me to choose the ones to wipe clean, else I'll have to open up the box and unplug the cables for the drives I want to keep.

Anyway I'll follow up and post my results. Worse case I'll have to wipe everything, reinstall the freeNAS on the thumb drive and loose the full backups and incrementals done thus far. I sure hope that a better workaround is developed that doesn't require software tools outside of what is provide with freeNAS.

 

[ddayton]

For the benefit of others that get caught in the same boat I'll elaborate my actions and results. As suggested I downloaded the DBAN iso image and burned a bootable CD. I hadn't used it before and documentation for this free utility was sparse. When it booted to the initial menu it said that it would wipe all storage devices attached to the system, so I shut it down and unplugged all the hard drives and thumb drive that I didn't want wiped. This time I allowed it to continue but then it presented the drives that it found and allowed the option of selecting which to wipe. Oh well better safe than sorry. I selected my two 2TB drives and used the default wipe setting. It took around 19 hours. I shut down, reconnected the other drives, plugged in the freeNAS thumb drive and booted up. I went straight to the volume manager, selected ada2 and ada3 as a ufs mirror and wa la I now had the volume I had been trying to create. I set up the volume as an iSCSI extent as a file extent and all is good. Now we'll see how this performs verses a CIFS share. I will say that over a several days I did have a Windows write fail error on a couple of backups, but stopped when I reduced the max concurrent backup jobs.

Thanks for the help!

 

[paleoN]

FYI, FreeNAS 8.2 and up has a GUI disk wipe, full wipe in your case, which likely would have worked for you.

AFAIR, DBAN uses DoD short, 3 pass patterns, as the default wiping scheme. You only needed the single pass Quick Erase, writes zeroes, which would have been faster.

 

[ddayton]

Yes the GUI does have a disk wipe but unfortunately it also failed and generated errors, "Operation not permitted", when attempted. My timing wasn't good when I went to use DBAN for the first time. I went out to our DR site before leaving for home thinking I would boot wipe and go. I was going to use our VPN later to attempt finishing from home, but by the time I took the system apart to unplug drives I was pressed for time and took the defaults without much reading of the options. So I wasn't going to complete until the next day anyway. I'll add your suggestion in the sleeve with the DBAN CD for the next time I need it.