search

NixOS / nixpkgs

Nix Packages collection & NixOS
MIT License
18.01k stars 14.02k forks source link

Unifi does not start in NixOS 23.05 #236293

Open Dehumanizer77 opened 1 year ago

Dehumanizer77 commented 1 year ago

Describe the bug

Unifi controller does not start after NixOS upgrade.

Steps To Reproduce

Steps to reproduce the behavior:

  1. enable unifi service with services.unifi.unifiPackage = pkgs.unifi; (i.e. unifi 7.3.83 as of now)
  2. the service does not start (due to mongodb restarting in a loop, see bellow)

Additional context

mongodb is restarting in a loop, producing these logs:

2023-06-06T13:56:58.005+0000 I  CONTROL  [main] ***** SERVER RESTARTED *****
2023-06-06T13:56:58.011+0000 I  CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
2023-06-06T13:56:58.012+0000 W  ASIO     [main] No TransportLayer configured during NetworkInterface startup
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] MongoDB starting : pid=7712 port=27117 dbpath=/var/lib/unifi/data/db 64-bit host=unifi1
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] db version v4.2.24
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] git version: 5e4ec1d24431fcdd28b579a024c5c801b8cde4e2
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 3.0.8 7 Feb 2023
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] allocator: tcmalloc
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] modules: none
2023-06-06T13:56:58.013+0000 I  CONTROL  [initandlisten] build environment:
2023-06-06T13:56:58.014+0000 I  CONTROL  [initandlisten]     distarch: x86_64
2023-06-06T13:56:58.014+0000 I  CONTROL  [initandlisten]     target_arch: x86_64
2023-06-06T13:56:58.014+0000 I  CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27117, unixDomainSocket: { pathPrefix: "/var/lib/unifi/run" } }, processManagement: { pidFilePath: "/var/lib/unifi/run/mongod.pid" }, storage: { dbPath: "/var/lib/unifi/data/db", wiredTiger: { engineConfig: { configString: "cache_size=256M" } } }, systemLog: { destination: "file", logAppend: true, logRotate: "reopen", path: "/var/lib/unifi/logs/mongod.log" } }
2023-06-06T13:56:58.014+0000 I  STORAGE  [initandlisten] Detected data files in /var/lib/unifi/data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2023-06-06T13:56:58.015+0000 I  STORAGE  [initandlisten] 
2023-06-06T13:56:58.015+0000 I  STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2023-06-06T13:56:58.015+0000 I  STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2023-06-06T13:56:58.015+0000 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=445M,cache_overflow=(file_max=0M),session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress],cache_size=256M
2023-06-06T13:56:58.661+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059818:661279][7712:0x7f83dd33eb00], txn-recover: Recovering log 1671 through 1672
2023-06-06T13:56:58.746+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059818:746092][7712:0x7f83dd33eb00], txn-recover: Recovering log 1672 through 1672
2023-06-06T13:56:58.830+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059818:830461][7712:0x7f83dd33eb00], txn-recover: Main recovery loop: starting at 1671/768 to 1672/256
2023-06-06T13:56:58.925+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059818:925578][7712:0x7f83dd33eb00], txn-recover: Recovering log 1671 through 1672
2023-06-06T13:56:58.990+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059818:990704][7712:0x7f83dd33eb00], txn-recover: Recovering log 1672 through 1672
2023-06-06T13:56:59.036+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:36803][7712:0x7f83dd33eb00], txn-recover: Set global recovery timestamp: (0, 0)
2023-06-06T13:56:59.072+0000 I  RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
2023-06-06T13:56:59.075+0000 I  STORAGE  [initandlisten] WiredTigerKVEngine shutting down
2023-06-06T13:56:59.075+0000 I  STORAGE  [initandlisten] Shutting down session sweeper thread
2023-06-06T13:56:59.075+0000 I  STORAGE  [initandlisten] Finished shutting down session sweeper thread
2023-06-06T13:56:59.075+0000 I  STORAGE  [initandlisten] Shutting down journal flusher thread
2023-06-06T13:56:59.175+0000 I  STORAGE  [initandlisten] Finished shutting down journal flusher thread
2023-06-06T13:56:59.175+0000 I  STORAGE  [initandlisten] Shutting down checkpoint thread
2023-06-06T13:56:59.175+0000 I  STORAGE  [initandlisten] Finished shutting down checkpoint thread
2023-06-06T13:56:59.175+0000 I  STORAGE  [initandlisten] Downgrading WiredTiger datafiles.
2023-06-06T13:56:59.208+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:208616][7712:0x7f83dd33eb00], txn-recover: Recovering log 1672 through 1673
2023-06-06T13:56:59.257+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:257215][7712:0x7f83dd33eb00], txn-recover: Recovering log 1673 through 1673
2023-06-06T13:56:59.342+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:342575][7712:0x7f83dd33eb00], txn-recover: Main recovery loop: starting at 1672/2176 to 1673/256
2023-06-06T13:56:59.437+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:437246][7712:0x7f83dd33eb00], txn-recover: Recovering log 1672 through 1673
2023-06-06T13:56:59.501+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:501616][7712:0x7f83dd33eb00], txn-recover: Recovering log 1673 through 1673
2023-06-06T13:56:59.549+0000 I  STORAGE  [initandlisten] WiredTiger message [1686059819:549393][7712:0x7f83dd33eb00], txn-recover: Set global recovery timestamp: (0, 0)
2023-06-06T13:56:59.634+0000 I  STORAGE  [initandlisten] exception in initAndListen: MustDowngrade: Collection does not have UUID in KVCatalog. Collection: ace.account, terminating
2023-06-06T13:56:59.634+0000 I  REPL     [initandlisten] Stepping down the ReplicationCoordinator for shutdown, waitTime: 10000ms
2023-06-06T13:56:59.634+0000 I  SHARDING [initandlisten] Shutting down the WaitForMajorityService
2023-06-06T13:56:59.634+0000 I  NETWORK  [initandlisten] shutdown: going to close listening sockets...
2023-06-06T13:56:59.634+0000 I  NETWORK  [initandlisten] Shutting down the global connection pool
2023-06-06T13:56:59.634+0000 I  STORAGE  [initandlisten] Shutting down the FlowControlTicketholder
2023-06-06T13:56:59.634+0000 I  -        [initandlisten] Stopping further Flow Control ticket acquisitions.
2023-06-06T13:56:59.635+0000 I  INDEX    [initandlisten] Shutting down the IndexBuildsCoordinator
2023-06-06T13:56:59.635+0000 I  NETWORK  [initandlisten] Shutting down the ReplicaSetMonitor
2023-06-06T13:56:59.635+0000 I  CONTROL  [initandlisten] Shutting down free monitoring
2023-06-06T13:56:59.635+0000 I  FTDC     [initandlisten] Shutting down full-time data capture
2023-06-06T13:56:59.635+0000 I  STORAGE  [initandlisten] Shutting down the HealthLog
2023-06-06T13:56:59.635+0000 I  -        [initandlisten] Dropping the scope cache for shutdown
2023-06-06T13:56:59.635+0000 I  CONTROL  [initandlisten] now exiting
2023-06-06T13:56:59.635+0000 I  CONTROL  [initandlisten] shutting down with code:100

services.unifi.mongodbPackage is not set, so the mongodb is default at 4.2. With our previous generation, mongodb was 3.4

Notify maintainers

@globin @Patryk27 @pennae

Metadata

Please run nix-shell -p nix-info --run "nix-info -m" and paste the result.

 - system: `"x86_64-linux"`
 - host os: `Linux 6.1.31, NixOS, 23.05 (Stoat), 23.05pre-git`
 - multi-user?: `yes`
 - sandbox: `yes`
 - version: `nix-env (Nix) 2.13.3`
 - channels(root): `"nixos-23.05"`
 - nixpkgs: `/nix/var/nix/profiles/per-user/root/channels/nixos`
pennae commented 1 year ago

it seems that unifi needs to be upgrade piecemeal to the new mongodb version in at least some instances, starting at the version used previously. this may require temporarily pulling mongodb from older releases, cf https://github.com/NixOS/nixpkgs/pull/207382#issuecomment-1371303817

Dehumanizer77 commented 1 year ago

I confirm that upgrading unifi gradually to mongodb 3.6, 4.0 and 4.2 before upgrading nixos to 23.05 fixes the issue. After upgrading to mongo 4.0 I also had to change featureCompatibilityVersion to 4.0 as per https://www.mongodb.com/docs/manual/release-notes/4.2-upgrade-standalone/ , otherwise the mongodb refused to start after upgrade to 4.2

Ralith commented 1 year ago

After noticing strange behavior following my upgrade to 23.05, I set unifiPackage = pkgs.unifi6;, mongodbPackage = pkgs.mongodb-4_2;, and followed the manual mongodb upgrade instructions, and now Unifi seems to be more broken than ever: it opens a socket, but returns "HTTP Status 404 – Not Found" for all requests, and the log files don't seem to get written so I don't have anything else to go on. Mongodb does not seem to be running at all. Help?

Edit: Looks like I just got the permissions wrong on the db, and was looking at an obsolete log file path.

andar1an commented 11 months ago

Does it take a long time for Monodb to build? or can this issue affect build time also in a clean build (i.e. could I be looping in build)?

Dehumanizer77 commented 11 months ago

It's long, but it's not like several hours... Depending on the HW where you build it ofc.

andar1an commented 11 months ago

Thank you, it seems I hit a lot of warnings, but not errors. And it was running for 15 min so I cancelled. I will try again

Dehumanizer77 commented 11 months ago

it's certainly longer then 15 mins. I can't remember exactly but even one hour would be reasonable with weaker HW IMHO.

andar1an commented 11 months ago

ouch haha. I have an i7 and 16gb of ram on this machine. Is it possible to create an FHS version to just install debian package?

vtechev commented 11 months ago

mongodb takes around 80 minutes to build on my rather elderly server. If you want to save yourself some time, or if you, like me, wound up unable to roll back after taking drastic measures to make enough room for mongo to build, this is what worked for me: grab the most recent autobackup and save it off, set your unifi package to unifi7, your mongodbPackage to mongodb-4_4, and blow away /var/lib/unifi/data/db. After the app comes up you should be able to restore from the backup.

This was a rough one.

andar1an commented 11 months ago

mongodb takes around 80 minutes to build on my rather elderly server. If you want to save yourself some time, or if you, like me, wound up unable to roll back after taking drastic measures to make enough room for mongo to build, this is what worked for me: grab the most recent autobackup and save it off, set your unifi package to unifi7, your mongodbPackage to mongodb-4_4, and blow away /var/lib/unifi/data/db. After the app comes up you should be able to restore from the backup.

This was a rough one.

I ended up leaving mine building and walked away for a while. I dk how long it took at end of day, but everything I read about building mongodb pointed at "A LONG TIME" HAHA.

Dehumanizer77 commented 10 months ago

Same problem with 23.11 but I haven't found a solution (yet) :-/

Ralith commented 10 months ago

Still working fine for me on 23.11 after fixing things on 23.05 (setting unifiPackage = pkgs.unifi7; mongodbPackage = pkgs.mongodb-4_4; and performing manual migration).

Dehumanizer77 commented 10 months ago

I haven't set unifiPackage = pkgs.unifi7; but I suppose it's default... What do you mean by manual migration?

Ralith commented 10 months ago

My notes say I followed the instructions at https://github.com/NixOS/nixpkgs/pull/207382#issuecomment-1371303817. I think the official mongodb documentation for migrations is also a good reference.

Dehumanizer77 commented 10 months ago

@Ralith oh I see, thank you, yes, recreating the mongo database helped.

tv42 commented 1 month ago

Oh god what pain. I had a unifi setup that apparently had been running mongodb 4.2, you can only migrate that to 4.4, I didn't notice that in time, and mongodb-4_4 has been removed from NixOS 24.05.. Currently waiting for this monster to build to try the upgrade:

NIXPKGS_ALLOW_UNFREE=1 nix \
  --extra-experimental-features nix-command \
  --extra-experimental-features flakes \
  shell  --impure \
  github:nixos/nixpkgs/nixos-23.11#mongodb-4_4
Ralith commented 1 month ago

I think the way to go here is:

  1. boot your old working generation
  2. export/backup the Unifi state via the webui
  3. stop Unifi
  4. back up the state directory manually just in case
  5. nuke the state directory, then reboot into current NixOS with your desired Unifi and mongodb builds
  6. import the Unifi backup

That's what I did for my 24.05 update. Saves the laborious and error-prone series of manual database upgrades.

tv42 commented 1 month ago

Unfortunately a combo of 1) I don't really check this Unifi controller often and 2) I was tight on disk space means the old generation is already gone.