Upgrade from 9.10 to latest causing CCB errors

[cstanley]

Before I go posting on bugs.freenas.org I wanted to make sure this was in fact a bug and not something else.

I just got done setting up a fresh install of FreeNAS 9.10 from April, 11th

I received a message in the panel about an update that was available. Looks like it is still 9.10 with some bug fixes. So I went through the update gui and applied the update. However, on boot I am getting the following messages:

Code:

(da0:umass-sim0:0:0:0): Read(10). CDB: 28 00 00 3d 55 3b 00 00 00 01 00
(da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error
(da0:umass-sim0:0:0:0): Retrying command
...
(da0:umass-sim0:0:0:0): Error 5, Retries exhausted.

It appears that the USB drive is having problems. This is a brand new USB drive SanCruzer 16GB directly from Amazon just opened.

Am I missing something here?

----------System Specs----------
PSU: FSP ATX 80 Plus Gold 300W
MEM: Crucial 16GB DDR3/DDR3L-1600MT/s ECC
MOBO: ASRock C2750D4I
CASE: U-NAS NSC-800
HDD: 5x Seagate 4TB NAS

Thanks!

EDIT:

Just rebooted and seems like the server boots. Weird?

Now I am getting errors in the Alert window:

Code:

CRITICAL: April 26, 2016, 2:13 p.m. - The volume zfsp1 (ZFS) state is UNAVAIL: One or more devices could not be opened. There are insufficient replicas for the pool to continue functioning.

WARNING: April 26, 2016, 2:13 p.m. - New feature flags are available for volume zfsp1. Refer to the "Upgrading a ZFS Pool" section of the User Guide for instructions.

I will say that my zpool is encrypted and normally it asks me to unlock it at boot, however after the upgrade it did not ask me. When clicking the "Upgrade" button on the ZFS Pool it fails. As of now I am unable to access any of my data.

In an attempt to move forward I locked the device. Now when I try to unlock it I get a window with the following error:

Code:

Environment: Software Version: FreeNAS-9.10-STABLE-201604181743 (74ef270) Request Method: POST Request URL: https://10.0.0.202/storage/volume/1/unlock/?X-Progress-ID=e230dee0-37ea-49ae-88ff-d582cc8eb43c Traceback: File "/usr/local/lib/python2.7/site-packages/django/core/handlers/base.py" in get_response 105. response = middleware_method(request, callback, callback_args, callback_kwargs) File "/usr/local/www/freenasUI/../freenasUI/freeadmin/middleware.py" in process_view 156. return login_required(view_func)(request, *view_args, **view_kwargs) File "/usr/local/lib/python2.7/site-packages/django/contrib/auth/decorators.py" in _wrapped_view 22. return view_func(request, *args, **kwargs) File "/usr/local/www/freenasUI/../freenasUI/storage/views.py" in volume_unlock 1128. form.done(volume=volume) File "/usr/local/www/freenasUI/../freenasUI/storage/forms.py" in done 2546. notifier().sync_encrypted(volume=volume) File "/usr/local/www/freenasUI/../freenasUI/middleware/notifier.py" in sync_encrypted 4756. ed.encrypted_disk and ed.encrypted_disk.id != disk.id Exception Type: AttributeError at /storage/volume/1/unlock/ Exception Value: 'Disk' object has no attribute 'id'

Not sure what's going on. I am not doing anything fancy, just a fresh install of FreeNAS.

At this point the Alerts in the "Alert" box show nothing.

So, with that error I figured, why not try to unlock it again? See what happens:

Now I am getting:

Code:

Error: Volume Cannot be Imported

But now I can see the pool name and the dataset beneath it. When I try to navigate to it over the network the NAS is empty and none of my datasets show up.

At this point when issuing a zpool status here is the output:

Code:

pool: zfsp1
state: ONLINE
  scan: none requested
config:

        NAME                                                STATE     READ WRITE
CKSUM
        zfsp1                                               ONLINE       0     0
     0
          raidz2-0                                          ONLINE       0     0
     0
            gptid/4b414e36-0b70-11e6-9bd7-d05099c0a242.eli  ONLINE       0     0
     0
            gptid/4c03c442-0b70-11e6-9bd7-d05099c0a242.eli  ONLINE       0     0
     0
            gptid/4cd20a8d-0b70-11e6-9bd7-d05099c0a242.eli  ONLINE       0     0
     0
            gptid/4da6ad9f-0b70-11e6-9bd7-d05099c0a242.eli  ONLINE       0     0
     0
            gptid/4e66a9d4-0b70-11e6-9bd7-d05099c0a242.eli  ONLINE       0     0
     0

errors: No known data errors

So, what the heck - I locked the pool again and attempted to unlock it. Now I am getting that same error as before:

Code:

Environment: Software Version: FreeNAS-9.10-STABLE-201604181743 (74ef270) Request Method: POST Request URL: https://10.0.0.202/storage/volume/1/unlock/?X-Progress-ID=e230dee0-37ea-49ae-88ff-d582cc8eb43c Traceback: File "/usr/local/lib/python2.7/site-packages/django/core/handlers/base.py" in get_response 105. response = middleware_method(request, callback, callback_args, callback_kwargs) File "/usr/local/www/freenasUI/../freenasUI/freeadmin/middleware.py" in process_view 156. return login_required(view_func)(request, *view_args, **view_kwargs) File "/usr/local/lib/python2.7/site-packages/django/contrib/auth/decorators.py" in _wrapped_view 22. return view_func(request, *args, **kwargs) File "/usr/local/www/freenasUI/../freenasUI/storage/views.py" in volume_unlock 1128. form.done(volume=volume) File "/usr/local/www/freenasUI/../freenasUI/storage/forms.py" in done 2546. notifier().sync_encrypted(volume=volume) File "/usr/local/www/freenasUI/../freenasUI/middleware/notifier.py" in sync_encrypted 4756. ed.encrypted_disk and ed.encrypted_disk.id != disk.id Exception Type: AttributeError at /storage/volume/1/unlock/ Exception Value: 'Disk' object has no attribute 'id'

I can repeat the steps indefinitely and the same thing occurs.

Perhaps related to: https://bugs.freenas.org/issues/14789

The other errors I experienced before are not listed in Bug 14789

So since the "Update" of the zpool failed, am I going to have to manually upgrade it now? The button is no longer present.

Anyways, I have managed to fix everything by applying the changes in Bug 14789 - Still a little concerned about all the other errors I encountered.

Any input to dampen my uncertainty would be great!

 

[dlavigne]

Man, that sounds painful...

14789 was applied in today's update (went out a few hours ago which may have been after you started updating). Is it still indicating than an update is available? Is System -> Information showing your version as 201604261518?

 

[cstanley]

Yeah it was a pain haha. I am upgrading to the latest one now - My timing was so close!

What about the updating zpool flags button? When I initially clicked it it threw an error - then when I got all of my datasets back online - the button was gone. How can I make sure the zpools were updated?

Fingers crossed that I can boot after updating.

Edit:

Just tried to apply the latest update and got the following errors:

Code:

CRITICAL: April 26, 2016, 6:46 p.m. - The boot volume state is ONLINE: One or more devices has experienced an error resulting in data corruption. Applications may be affected.
CRITICAL: April 26, 2016, 6:46 p.m. - Update failed. Check /data/update.failed for further details.

I am not sure what I am doing wrong, as all I am doing is updating via the GUI and as stated previously, the only thing fancy I am doing is encryption (not really that fancy).

Output of zpool status:

Code:

pool: freenas-boot
state: ONLINE
status: One or more devices has experienced an error resulting in data
        corruption.  Applications may be affected.
action: Restore the file in question if possible.  Otherwise restore the
        entire pool from backup.
   see: http://illumos.org/msg/ZFS-8000-8A
  scan: none requested
config:

        NAME        STATE     READ WRITE CKSUM
        freenas-boot  ONLINE       0     0     0
          da0p2     ONLINE       0     0     0

errors: 1 data errors, use '-v' for a list

Any ideas? I have already reinstalled FreeNAS twice, and really don't want to have to do it again.

Here is the output of update.failed:

Code:

Traceback (most recent call last):
  File "/usr/local/www/freenasUI/manage.py", line 42, in <module>
    execute_from_command_line(sys.argv)
  File "/usr/local/lib/python2.7/site-packages/django/core/management/__init__.py", line 399, in execute_from_command_line
    utility.execute()
  File "/usr/local/lib/python2.7/site-packages/django/core/management/__init__.py", line 392, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/usr/local/lib/python2.7/site-packages/django/core/management/base.py", line 242, in run_from_argv
    self.execute(*args, **options.__dict__)
  File "/usr/local/lib/python2.7/site-packages/django/core/management/base.py", line 285, in execute
    output = self.handle(*args, **options)
  File "/usr/local/lib/python2.7/site-packages/south/management/commands/migrate.py", line 111, in handle
    ignore_ghosts = ignore_ghosts,
  File "/usr/local/lib/python2.7/site-packages/south/migration/__init__.py", line 173, in migrate_app
    Migrations.calculate_dependencies()
  File "/usr/local/lib/python2.7/site-packages/south/migration/base.py", line 240, in calculate_dependencies
    migration.calculate_dependencies()
  File "/usr/local/lib/python2.7/site-packages/south/migration/base.py", line 374, in calculate_dependencies
    for migration in self._get_dependency_objects("depends_on"):
  File "/usr/local/lib/python2.7/site-packages/south/migration/base.py", line 354, in _get_dependency_objects
    for app, name in getattr(self.migration_class(), attrname, []):
  File "/usr/local/lib/python2.7/site-packages/south/migration/base.py", line 326, in migration_class
    return self.migration().Migration
AttributeError: 'module' object has no attribute 'Migration'

Oddly enough my System Build is:
FreeNAS-9.10-STABLE-201604261518 (881b70d)

However those alerts will not go away.

Now I am just lost..... haha

 

[dlavigne]

I'd try a fresh install of 201604261518 on a new stick (save your config first). That version fixes that south error and has another fix for encrypted pools.