Upgrade from 11.2-U8 to 11.3-U2.1 stuck at "middlewared: setting up plugins (system) [2/34]"

norbert.hanke

Dabbler
Joined
Aug 6, 2019
Messages
11
Hi,

I'm trying to upgrade FreeNAS from 11.2-U8 to 11.3-U2.1 ..

When starting up the updated version console output is stuck showing the message

middlewared: setting up plugins (system) [2/34] .

and after a while

Middleware startup is idle for more than 240 seconds
##############################################################
MIDDLEWARED FAILED TO START, SYSTEM WILL NOT BEHAVE CORRECTLY!
##############################################################

and barely anything works afterwards.

I get the same result when updating through the GUI or updating using a 11.3-U2.1 boot CD.

Any hint what I should look for to find the reason for the failure?

I also tried a fresh install of 11.3-U2.1 on a new boot disk: I get a working system with that. But when I try to upload the configuration from the old version through the GUI that fails with the message
[EFAULT] The uploaded file is not valid: no such table: south_migrationhistory

The old version still works fine.

I'm stuck. Any help is appreciated.

Thanks
Norbert
 

Apollo

Wizard
Joined
Jun 13, 2013
Messages
1,450
Just wait. Some have reported this step to take nearly 1 hour.
 

norbert.hanke

Dabbler
Joined
Aug 6, 2019
Messages
11
I repeated while waiting for more than an hour. It times out after a few minutes, but I still waited, nothing appeared to have happend.

So I retried a fresh installation and then loading the existing configuration, this time with fresh and not an empty .tar file as last time. (Shame on me for that mistake)

That fails again. Looking at /data/update.failed it says:

Operations to perform:
Apply all migrations: account, auth, contenttypes, directoryservice, jails, network, plugins, services, sessions, sharing, storage, system, tasks, vm
Running migrations:
Applying account.0010_auto_20190221_0824... OK
Applying account.0011_remove_netdata_user... OK
Applying directoryservice.0006_certificate_model... OK
Applying directoryservice.0007_migrate_to_nslcd... OK
Applying directoryservice.0008__alter_kerberos_principal... OK
Applying directoryservice.0009__add_createcomputer_to_ad... OK
Applying directoryservice.0010_encrypt_keytabs... OK
Applying directoryservice.0011_add_new_idmap_model...Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
return self.cursor.execute(sql, params)
File "/usr/local/www/freenasUI/freeadmin/sqlite3_ha/base.py", line 381, in execute
execute = super().execute(query, params)
sqlite3.IntegrityError: UNIQUE constraint failed: directoryservice_idmap_rid.idmap_rid_domain_id

The above exception was the direct cause of the following exception:

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/python3.7/site-packages/django/core/management/__init__.py", line 367, in execute_from_command_line
utility.execute()
File "/usr/local/lib/python3.7/site-packages/django/core/management/__init__.py", line 359, in execute
self.fetch_command(subcommand).run_from_argv(self.argv)
File "/usr/local/lib/python3.7/site-packages/django/core/management/base.py", line 294, in run_from_argv
self.execute(*args, **cmd_options)
File "/usr/local/lib/python3.7/site-packages/django/core/management/base.py", line 345, in execute
output = self.handle(*args, **options)
File "/usr/local/lib/python3.7/site-packages/django/core/management/commands/migrate.py", line 204, in handle
fake_initial=fake_initial,
File "/usr/local/lib/python3.7/site-packages/django/db/migrations/executor.py", line 115, in migrate
state = self._migrate_all_forwards(state, plan, full_plan, fake=fake, fake_initial=fake_initial)
File "/usr/local/lib/python3.7/site-packages/django/db/migrations/executor.py", line 145, in _migrate_all_forwards
state = self.apply_migration(state, migration, fake=fake, fake_initial=fake_initial)
File "/usr/local/lib/python3.7/site-packages/django/db/migrations/executor.py", line 244, in apply_migration
state = migration.apply(state, schema_editor)
File "/usr/local/lib/python3.7/site-packages/django/db/migrations/migration.py", line 129, in apply
operation.database_forwards(self.app_label, schema_editor, old_state, project_state)
File "/usr/local/lib/python3.7/site-packages/django/db/migrations/operations/special.py", line 189, in database_forwards
self.code(from_state.apps, schema_editor)
File "/usr/local/www/freenasUI/directoryservice/migrations/0011_add_new_idmap_model.py", line 52, in migrate_to_new_idmap
o.save()
File "/usr/local/lib/python3.7/site-packages/django/db/models/base.py", line 796, in save
force_update=force_update, update_fields=update_fields)
File "/usr/local/lib/python3.7/site-packages/django/db/models/base.py", line 824, in save_base
updated = self._save_table(raw, cls, force_insert, force_update, using, update_fields)
File "/usr/local/lib/python3.7/site-packages/django/db/models/base.py", line 889, in _save_table
forced_update)
File "/usr/local/lib/python3.7/site-packages/django/db/models/base.py", line 939, in _do_update
return filtered._update(values) > 0
File "/usr/local/lib/python3.7/site-packages/django/db/models/query.py", line 654, in _update
return query.get_compiler(self.db).execute_sql(CURSOR)
File "/usr/local/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 1148, in execute_sql
cursor = super(SQLUpdateCompiler, self).execute_sql(result_type)
File "/usr/local/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 835, in execute_sql
cursor.execute(sql, params)
File "/usr/local/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
return self.cursor.execute(sql, params)
File "/usr/local/lib/python3.7/site-packages/django/db/utils.py", line 94, in __exit__
six.reraise(dj_exc_type, dj_exc_value, traceback)
File "/usr/local/lib/python3.7/site-packages/django/utils/six.py", line 685, in reraise
raise value.with_traceback(tb)
File "/usr/local/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
return self.cursor.execute(sql, params)
File "/usr/local/www/freenasUI/freeadmin/sqlite3_ha/base.py", line 381, in execute
execute = super().execute(query, params)
django.db.utils.IntegrityError: UNIQUE constraint failed: directoryservice_idmap_rid.idmap_rid_domain_id


How could I get around that propblem?
 

rv23

Cadet
Joined
Jun 6, 2020
Messages
4
I'm also having this problem, which persists I believe due to significant changes in how samba handles the rid backend (and possibly others). Namely samba is now enforcing some "rules" that it didn't seem to be enforcing previously, and FreeNAS isn't doing anything to prevent/warn/fix users who have an "invalid" samba configuration from attempting an ill-fated upgrade.

So it barfs on your (and mine) rid backend config.
 

rv23

Cadet
Joined
Jun 6, 2020
Messages
4
from: https://wiki.samba.org/index.php/Up...ap_config_Parameters_Set_in_the_smb.conf_File
Failure To Access Shares on Domain Controllers If idmap config Parameters Set in the smb.conf File
4.4.6 or later

The winbindd service on a Samba Active Directory (AD) domain controller (DC) automatically uses the IDs set in the Active Directory uidNumber and gidNumber attributes of user accounts and groups. If the attributes are not set, Samba generates IDs locally on the DC and stores them in the idmap.ldb database. Thus, on a Samba AD DC, idmap config parameters set in the smb.conf file were ignored. Due to a bug in Samba 4.4.6 and later, the parameters are no longer ignored and clients fail to connect to shares on the DC. To fix the problem:

  • Remove all idmap config parameters in the smb.conf file on DCs.
  • Restart the samba service.
  • Restart the clients.
As a result, clients now correctly connect to shares on the DC.
 

rv23

Cadet
Joined
Jun 6, 2020
Messages
4
While I'm sure it's very useful to remember old configurations, unfortunately that feature looks to be causing an upgrade problem. Even if you remove all your samba shares AND leave the domain the upgrade will fail (or at least it does for me). If I take a backup of my 11.2U8 config and browse the backup I can see the "old" and "invalid" rid entries that are causing the upgrade to fail even tho I no longer HAVE and active samba config ..

Entry #1 and #3 are configs I believe are invalid now in 11.3x and will cause Samba to barf, while #2 is what 11.3 defaults to for the rid backend on 11.3 for me.
1591544749510.png


I highly expect this leftover cruft is the issue, unfortunately I have no idea how to clear it out of a running system. However in a very very limited test, I edited out #1 and #3 above (switching the ID of 2 to 1 as well) of a backup of an 11.2U8 System, restored the backup (now minus that cruft) and then updated to 11.3 .. The upgrade at least succeeded :)

However as it was just a quick thrown together VM, the config could not be tested with all the things I normally use my real physical NAS for... But at least as far as the 11.2U8 to 11.3U2 upgrade is concerned .. It worked.

So my next step is to update my running config to the new RID values, and update every single ACL (sucks).. Then take a backup while on 11.2U8, remove the offending cruft, restore BACK to 11.2U8 and THEN try the 11.3U2 upgrade again...

What a PITA. If there is a way to clear this cruft out of the running system that would make things quite a bit easier ..
 

norbert.hanke

Dabbler
Joined
Aug 6, 2019
Messages
11
My FreeNAS is joined to a samba ad domain and I do not make use of the rid id backend at all and never did. So why should rid play a role at all?

The smb.conf here says
idmap config *: backend = tdb
idmap config *: range = 3000-7999
idmap config MYDOMAIN: backend = ad
idmap config MYDOMAIN: range = 10000-999999
idmap config MYDOMAIN: schema mode = rfc2307
idmap config MYDOMAIN: unix_primary_group = no
idmap config MYDOMAIN: unix_nss_info = no
idmap config MYDOMAIN: unix_primary_group = yes
idmap config MYDOMAIN:unix_nss_info = yes
The duplicates are the result by me setting the last two lines via the GUI. Not nice but they work.

The DB correctly reflects the id ranges:
1591743614550.png

1591743653887.png

The rid ranges must be some built-in default - I never used it -, and it indeed overlaps with the above, so NAS-102169 could be true.
1591743559748.png

Next I'll try to move rid settings out of the way (only number-wise, no more overlapping with tdb and ad and maybe others) and look if that will improve things.

Interestingly I was able to upgrade another system with the same settings to 11.3U2, and there are no duplicates in the smb.conf at least after the upgrade, taking my settings from the GUI only. I don't know how it looked on 11.2.
 

norbert.hanke

Dabbler
Joined
Aug 6, 2019
Messages
11
I deleted records 2 and 3 from directoryservice_idmap_rid above and restored the so patched configuration via the FreeNAS GUI. Then the update went through, to version FreeNAS-11.3-U3.2 this time.

AD membership got lost during the update, and rejoining did not work right away: The update procedure had converted my site's trusted CA certificate into an own certificate with a missing private key. I had to delete that from the configuration and then I was able to join my domain again.
One extra reboot required to get SMB shares and winbind operational.

Finally it looks like everything works again.
Thanks rv for the hint about the idmap rid ranges.
 
Top