Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Installer not working: couldn't add user: not authorized on admin #3662

Open
dagelf opened this issue Sep 12, 2022 · 8 comments
Open

Installer not working: couldn't add user: not authorized on admin #3662

dagelf opened this issue Sep 12, 2022 · 8 comments
Labels
install-config Installation/configuration issues

Comments

@dagelf
Copy link

dagelf commented Sep 12, 2022

~# curl https://install.sandstorm.io|bash
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 76862  100 76862    0     0  48523      0  0:00:01  0:00:01 --:--:-- 48523
Sandstorm makes it easy to run web apps on your own server. You can have:

1. A typical install, to use Sandstorm (press enter to accept this default)
2. A development server, for working on Sandstorm itself or localhost-based app development

How are you going to use this Sandstorm install? [1]
We're going to:

* Install Sandstorm in /opt/sandstorm
* Automatically keep Sandstorm up-to-date
* Configure auto-renewing HTTPS if you use a subdomain of sandcats.io
* Create a service user (sandstorm) that owns Sandstorm's files
* Configure Sandstorm to start on system boot (with systemd)
* Listen for inbound email on port 25.

Rest assured that Sandstorm itself won't run as root.
OK to continue? [yes]
As a Sandstorm user, you are invited to use a free Internet hostname as a subdomain of sandcats.io,
a service operated by the Sandstorm development team.
...
Sandcats.io protects your privacy and is subject to terms of use. By using it,
you agree to the terms of service & privacy policy available here:
https://sandcats.io/terms https://sandcats.io/privacy

Choose your desired Sandcats subdomain (alphanumeric, max 20 characters).
Type the word none to skip this step, or help for help.
What *.sandcats.io subdomain would you like? [] help
Sandcats.io is a free dynamic DNS service run by the Sandstorm development team.

You can:

* Read more about it at:
  https://docs.sandstorm.io/en/latest/administering/sandcats/

* Recover access to a domain you once registered with sandcats

* Just press enter to go to the previous question.
What Sandcats subdomain do you want to recover? [none] lol

Finding latest build for dev channel...
Downloading: https://dl.sandstorm.io/sandstorm-301.tar.xz
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 73.8M  100 73.8M    0     0  55.4M      0  0:00:01  0:00:01 --:--:-- 55.4M
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   310  100   310    0     0   2520      0 --:--:-- --:--:-- --:--:--  2520
GPG signature is valid.
Created symlink /etc/systemd/system/multi-user.target.wants/sandstorm.service → /etc/systemd/system/sandstorm.service.
Your server is coming online. Waiting up to 90 seconds....

Now we're going to fetch a TLS certificate using Let's Encrypt. This is a free
service provided by the nonprofit Electronic Frontier Foundation. By using this
service, you agree to be bound by the subscriber agreement, found here:
  https://letsencrypt.org/repository/#let-s-encrypt-subscriber-agreement
If you do not agree, please press ctrl+C now to cancel installation.

You must provide an email address, which will be shared with Let's Encrypt.
Your email address for Let's Encrypt: [[email protected]]
ERROR: Peer disconnected.
There might be more information in: /opt/sandstorm/var/log/sandstorm.log
*** INSTALLATION FAILED ***

Failed to create Let's Encrypt account.

Hmm, installation failed. Would it be OK to send an anonymous error report to the sandstorm.io team so we know something is wrong?
It would only contain this error code: E_CREATE_ACME_ACCOUNT [yes]
Sending problem report...
Submitting error report failed. Maybe there is a connectivity problem.

You can report bugs at: http://github.com/sandstorm-io/sandstorm

#  cat /etc/issue
Ubuntu 20.04.4 LTS \n \l

# ping 1.1
PING 1.1 (1.0.0.1) 56(84) bytes of data.
64 bytes from 1.0.0.1: icmp_seq=1 ttl=53 time=20.2 ms
^C
--- 1.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 20.216/20.216/20.216/0.000 ms

dig sandcats.io @1.1

; <<>> DiG 9.16.1-Ubuntu <<>> sandcats.io @1.1
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 61339
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;sandcats.io.                   IN      A

;; ANSWER SECTION:
sandcats.io.            60      IN      A       104.197.28.173

;; Query time: 275 msec
;; SERVER: 1.0.0.1#53(1.0.0.1)
;; WHEN: Mon Sep 12 21:46:49 SAST 2022
;; MSG SIZE  rcvd: 56

# cat /opt/sandstorm/var/log/sandstorm.log
** Starting Sandstorm at: Mon Sep 12 21:42:28 2022
** Starting back-end...
** Starting MongoDB...
note: noprealloc may hurt performance in many applications
about to fork child process, waiting until server is ready for connections.
forked process: 8
child process started successfully, parent exiting
2022-09-12T19:42:35.795+0000 Error: couldn't add user: not authorized on admin to execute command { createUser: "sandstorm", pwd: "xxx", roles: [ "readWriteAnyDatabase", "userAdminAnyDatabase", "dbAdminAnyDatabase" ], digestPassword: false, writeConcern: { w: "majority", wtimeout: 30000.0 } } at src/mongo/shell/db.js:1004
failed to load: /tmp/mongo-command.9PQnSs
*** Uncaught exception ***
sandstorm/util.c++:721: failed: expected exitCode == 0 [253 == 0]; child process failed; name = ; exitCode = 253
stack: 4084f1 644dbd 63ccea 635650 632cc4 6313d5 630b8c 496b97 496751
** Server monitor died. Aborting.

@dagelf dagelf changed the title Installer not working Installer not working: couldn't add user: not authorized on admin Sep 12, 2022
@ocdtrekkie
Copy link
Collaborator

ocdtrekkie commented Sep 12, 2022

Did you get anything in that sandstorm.log file? It looks like the failure was maybe in reaching Let's Encrypt here?

EDIT: I see you edited that in, sorry! Thanks.

@ocdtrekkie ocdtrekkie added the install-config Installation/configuration issues label Sep 12, 2022
@dagelf
Copy link
Author

dagelf commented Sep 12, 2022

It looks like the problem is with the command line parameters passed to the bundled mongodb. Creating var/pid and var/mongo and running it manually, ommitting --auth gets it working, and then restarting sandstorm start gets it working.

But in the process I have now created a dozen ddns urls that I can't seem to recover. But maybe with mongod running the recovery will work now... if I can even remember the names I used.

I am guessing mongodb needs to work for certbot etc. to work too? If that's the case, maybe bail out sooner if mongo isn't working?

Thanks anyways. My recommendation is add automated testing inside docker from clean OS installs. Maybe it's something I can contribute?

@dagelf
Copy link
Author

dagelf commented Sep 12, 2022

Scrap that... it installed some things and now is looping with:

** Restarting front-end due to back-end failure
** MongoDB died immediately after starting.
** Sleeping for a bit before trying again...
(node:1676) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
(Use `node --trace-deprecation ...` to show where the warning was created)
Mon, 12 Sep 2022 20:25:09 GMT body-parser deprecated undefined extended: provide extended option at app/app.js:1220:39
Migrations already applied: 41/41
Downloading app: https://app-index.sandstorm.io/packages/c4c975c3adbeeb77fd928bb90202c049
Downloading app: https://app-index.sandstorm.io/packages/a34bc48f6ee44a3dc13b02d165fe0d57
Downloading app: https://app-index.sandstorm.io/packages/bf4d676cf1f6ad39d528ae0c65ca12e1
Downloading app: https://app-index.sandstorm.io/packages/5198a2ec87bcc4b29e787b77079ba590
note: noprealloc may hurt performance in many applications
about to fork child process, waiting until server is ready for connections.
forked process: 1703
child process started successfully, parent exiting
** Restarting front-end due to back-end failure
** MongoDB died immediately after starting.
** Sleeping for a bit before trying again...
(node:1748) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
(Use `node --trace-deprecation ...` to show where the warning was created)
Mon, 12 Sep 2022 20:25:23 GMT body-parser deprecated undefined extended: provide extended option at app/app.js:1220:39
Migrations already applied: 41/41
Downloading app: https://app-index.sandstorm.io/packages/c4c975c3adbeeb77fd928bb90202c049
Downloading app: https://app-index.sandstorm.io/packages/a34bc48f6ee44a3dc13b02d165fe0d57
Downloading app: https://app-index.sandstorm.io/packages/bf4d676cf1f6ad39d528ae0c65ca12e1
Downloading app: https://app-index.sandstorm.io/packages/5198a2ec87bcc4b29e787b77079ba590

(This all the while Mongodb was still running without --auth on port 6081)

@ocdtrekkie
Copy link
Collaborator

I think we would definitely appreciate improvements to installer testing. We have the installer-tests folder, but I don't believe it's part of CI at all, and it currently only tries some very old versions of Linux. It looks like someone started working on it last year, and mentioned following it up, but I don't see that having happened...

What's also intriguing is that I can't find anything that seems like it should've impacted anything in the latest release relating to this, our Mongo setup hasn't changed much in... a long time... and it's generally worked for people pretty well, this seems to be a new issue.

(FWIW, Sandcats does not care about extraneous DDNS URLs. If you don't care about them, neither do we! Your install is only using one.)

@ocdtrekkie
Copy link
Collaborator

(cc: @zenhack to hopefully shed some light on what may have happened here, and maybe cc: @garrison FYI re: installer tests.)

@dagelf
Copy link
Author

dagelf commented Sep 12, 2022

First mongo log: (from initial install)

# cat mongo.log.2022-09-12T20-04-37
2022-09-12T20:03:57.872+0000 [initandlisten] MongoDB starting : pid=8 port=6081 dbpath=/var/mongo 64-bit host=lol
2022-09-12T20:03:57.872+0000 [initandlisten] db version v2.6.7
2022-09-12T20:03:57.872+0000 [initandlisten] git version: nogitversion
2022-09-12T20:03:57.872+0000 [initandlisten] OpenSSL version: OpenSSL 1.0.2 22 Jan 2015
2022-09-12T20:03:57.872+0000 [initandlisten] build info: Linux ip-10-38-181-34 2.6.32-356-ec2 #69-Ubuntu SMP Mon Aug 26 15:32:17 UTC 2013 x86_64 BOOST_LIB_VERSION=1_49
2022-09-12T20:03:57.872+0000 [initandlisten] allocator: tcmalloc
2022-09-12T20:03:57.872+0000 [initandlisten] options: { net: { bindIp: "127.0.0.1", http: { enabled: false }, port: 6081 }, nopreallocj: true, processManagement: { fork: true, pidFilePath: "/var/pid/mongo.pid" }, replication: { oplogSizeMB: 16, replSet: "ssrs" }, security: { authorization: "enabled" }, storage: { dbPath: "/var/mongo", preallocDataFiles: false, smallFiles: true }, systemLog: { destination: "file", path: "/var/log/mongo.log" } }
2022-09-12T20:03:57.874+0000 [initandlisten] journal dir=/var/mongo/journal
2022-09-12T20:03:57.874+0000 [initandlisten] recover : no journal files present, no recovery needed
2022-09-12T20:03:57.877+0000 [initandlisten] allocating new ns file /var/mongo/local.ns, filling with zeroes...
2022-09-12T20:03:57.909+0000 [FileAllocator] allocating new datafile /var/mongo/local.0, filling with zeroes...
2022-09-12T20:03:57.909+0000 [FileAllocator] creating directory /var/mongo/_tmp
2022-09-12T20:03:57.909+0000 [FileAllocator] done allocating datafile /var/mongo/local.0, size: 16MB,  took 0 secs
2022-09-12T20:03:57.911+0000 [initandlisten] build index on: local.startup_log properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "local.startup_log" }
2022-09-12T20:03:57.911+0000 [initandlisten]     added index to empty collection
2022-09-12T20:03:57.912+0000 [initandlisten] waiting for connections on port 6081
2022-09-12T20:03:57.913+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:03:57.913+0000 [rsStart] replSet info you may need to run replSetInitiate -- rs.initiate() in the shell -- if that is not already done
2022-09-12T20:03:58.913+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:03:59.914+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:00.914+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:00.924+0000 [initandlisten] connection accepted from 127.0.0.1:53400 #1 (1 connection now open)
2022-09-12T20:04:00.926+0000 [conn1] Unauthorized not authorized on admin to execute command { replSetInitiate: { _id: "ssrs", members: [ { _id: 0.0, host: "localhost:6081" } ] } }
2022-09-12T20:04:00.928+0000 [conn1] end connection 127.0.0.1:53400 (0 connections now open)
2022-09-12T20:04:01.914+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:02.915+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:03.915+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:04.915+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:04:04.966+0000 [initandlisten] connection accepted from 127.0.0.1:53402 #2 (1 connection now open)
2022-09-12T20:04:04.967+0000 [conn2] Unauthorized not authorized on admin to execute command { createUser: "sandstorm", pwd: "xxx", roles: [ "readWriteAnyDatabase", "userAdminAnyDatabase", "dbAdminAnyDatabase" ], digestPassword: false, writeConcern: { w: "majority", wtimeout: 30000.0 } }
2022-09-12T20:04:04.976+0000 [conn2] end connection 127.0.0.1:53402 (0 connections now open)

The log during what seemed to be working - but obviously didn't


2022-09-12T20:27:18.112+0000 [initandlisten] waiting for connections on port 6081
2022-09-12T20:27:18.190+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:18.191+0000 [rsStart] replSet info you may need to run replSetInitiate -- rs.initiate() in the shell -- if that is not already done
2022-09-12T20:27:18.246+0000 [initandlisten] connection accepted from 127.0.0.1:54330 #1 (1 connection now open)
2022-09-12T20:27:18.488+0000 [initandlisten] connection accepted from 127.0.0.1:54332 #2 (2 connections now open)
2022-09-12T20:27:18.513+0000 [initandlisten] connection accepted from 127.0.0.1:54334 #3 (3 connections now open)
2022-09-12T20:27:18.567+0000 [conn3]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:18.567+0000 [conn3] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:18.601+0000 [conn3] end connection 127.0.0.1:54334 (2 connections now open)
2022-09-12T20:27:19.021+0000 [initandlisten] connection accepted from 127.0.0.1:54336 #4 (3 connections now open)
2022-09-12T20:27:19.191+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:19.213+0000 [initandlisten] connection accepted from 127.0.0.1:54338 #5 (4 connections now open)
2022-09-12T20:27:19.266+0000 [conn5]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:19.266+0000 [conn5] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:19.298+0000 [conn5] end connection 127.0.0.1:54338 (3 connections now open)
2022-09-12T20:27:19.879+0000 [initandlisten] connection accepted from 127.0.0.1:54340 #6 (4 connections now open)
2022-09-12T20:27:19.888+0000 [conn6]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:19.888+0000 [conn6] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:19.895+0000 [conn6] end connection 127.0.0.1:54340 (3 connections now open)
2022-09-12T20:27:20.191+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:20.498+0000 [initandlisten] connection accepted from 127.0.0.1:54342 #7 (4 connections now open)
2022-09-12T20:27:20.507+0000 [conn7]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:20.507+0000 [conn7] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:20.510+0000 [conn7] end connection 127.0.0.1:54342 (3 connections now open)
2022-09-12T20:27:21.112+0000 [initandlisten] connection accepted from 127.0.0.1:54344 #8 (4 connections now open)
2022-09-12T20:27:21.172+0000 [conn8] end connection 127.0.0.1:54344 (3 connections now open)
2022-09-12T20:27:21.173+0000 [conn4] end connection 127.0.0.1:54336 (2 connections now open)
2022-09-12T20:27:21.173+0000 [conn2] end connection 127.0.0.1:54332 (1 connection now open)
2022-09-12T20:27:21.173+0000 [conn1] end connection 127.0.0.1:54330 (0 connections now open)
2022-09-12T20:27:21.191+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:22.192+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:22.367+0000 [initandlisten] connection accepted from 127.0.0.1:54346 #9 (1 connection now open)
2022-09-12T20:27:22.380+0000 [initandlisten] connection accepted from 127.0.0.1:54348 #10 (2 connections now open)
2022-09-12T20:27:22.383+0000 [conn10]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:22.383+0000 [conn10] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:22.386+0000 [conn9] end connection 127.0.0.1:54346 (1 connection now open)
2022-09-12T20:27:22.398+0000 [conn10] end connection 127.0.0.1:54348 (0 connections now open)
2022-09-12T20:27:23.192+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:24.192+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:25.193+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:26.197+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:27.198+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:28.199+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:29.199+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:30.200+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:31.200+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:32.201+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:33.202+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:33.620+0000 [initandlisten] connection accepted from 127.0.0.1:54350 #11 (1 connection now open)
2022-09-12T20:27:33.634+0000 [initandlisten] connection accepted from 127.0.0.1:54352 #12 (2 connections now open)
2022-09-12T20:27:33.638+0000 [conn12]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:33.638+0000 [conn12] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:33.641+0000 [conn11] end connection 127.0.0.1:54350 (1 connection now open)
2022-09-12T20:27:33.654+0000 [conn12] end connection 127.0.0.1:54352 (0 connections now open)
2022-09-12T20:27:34.202+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:35.203+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:36.203+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:37.204+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:38.204+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:39.204+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:40.205+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:41.206+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:42.206+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:43.207+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:44.207+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:44.873+0000 [initandlisten] connection accepted from 127.0.0.1:54354 #13 (1 connection now open)
2022-09-12T20:27:44.887+0000 [initandlisten] connection accepted from 127.0.0.1:54356 #14 (2 connections now open)
2022-09-12T20:27:44.891+0000 [conn14]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:44.892+0000 [conn14] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:44.894+0000 [conn13] end connection 127.0.0.1:54354 (1 connection now open)
2022-09-12T20:27:44.908+0000 [conn14] end connection 127.0.0.1:54356 (0 connections now open)
2022-09-12T20:27:45.208+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:46.209+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:47.209+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:48.209+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:49.210+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:50.210+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:51.210+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:52.211+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:53.211+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:54.211+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:55.212+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
2022-09-12T20:27:56.106+0000 [initandlisten] connection accepted from 127.0.0.1:54358 #15 (1 connection now open)
2022-09-12T20:27:56.120+0000 [initandlisten] connection accepted from 127.0.0.1:54360 #16 (2 connections now open)
2022-09-12T20:27:56.124+0000 [conn16]  authenticate db: admin { authenticate: 1, user: "sandstorm", nonce: "xxx", key: "xxx" }
2022-09-12T20:27:56.124+0000 [conn16] Failed to authenticate sandstorm@admin with mechanism MONGODB-CR: AuthenticationFailed UserNotFound Could not find user sandstorm@admin
2022-09-12T20:27:56.127+0000 [conn15] end connection 127.0.0.1:54358 (1 connection now open)
2022-09-12T20:27:56.140+0000 [conn16] end connection 127.0.0.1:54360 (0 connections now open)
2022-09-12T20:27:56.213+0000 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)

And then the logs from sandstorm trying to start mongo while it's already running.


cat mongo.log.2022-09-12T20-25-03
2022-09-12T20:24:50.446+0000 [initandlisten] MongoDB starting : pid=1559 port=6081 dbpath=/var/mongo 64-bit host=lol
2022-09-12T20:24:50.446+0000 [initandlisten] db version v2.6.7
2022-09-12T20:24:50.446+0000 [initandlisten] git version: nogitversion
2022-09-12T20:24:50.446+0000 [initandlisten] OpenSSL version: OpenSSL 1.0.2 22 Jan 2015
2022-09-12T20:24:50.446+0000 [initandlisten] build info: Linux ip-10-38-181-34 2.6.32-356-ec2 #69-Ubuntu SMP Mon Aug 26 15:32:17 UTC 2013 x86_64 BOOST_LIB_VERSION=1_49
2022-09-12T20:24:50.446+0000 [initandlisten] allocator: tcmalloc
2022-09-12T20:24:50.447+0000 [initandlisten] options: { net: { bindIp: "127.0.0.1", http: { enabled: false }, port: 6081 }, nopreallocj: true, processManagement: { fork: true, pidFilePath: "/var/pid/mongo.pid" }, replication: { oplogSizeMB: 16, replSet: "ssrs" }, security: { authorization: "enabled" }, storage: { dbPath: "/var/mongo", preallocDataFiles: false, smallFiles: true }, systemLog: { destination: "file", path: "/var/log/mongo.log" } }
2022-09-12T20:24:50.449+0000 [initandlisten] journal dir=/var/mongo/journal
2022-09-12T20:24:50.449+0000 [initandlisten] recover : no journal files present, no recovery needed
2022-09-12T20:24:50.464+0000 [initandlisten] ERROR: listen(): bind() failed errno:98 Address already in use for socket: 127.0.0.1:6081
2022-09-12T20:24:50.464+0000 [initandlisten] ERROR:   addr already in use
2022-09-12T20:24:50.464+0000 [initandlisten] now exiting
2022-09-12T20:24:50.464+0000 [initandlisten] dbexit:
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: going to close listening sockets...
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: going to flush diaglog...
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: going to close sockets...
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: waiting for fs preallocator...
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: lock for final commit...
2022-09-12T20:24:50.464+0000 [initandlisten] shutdown: final commit...
2022-09-12T20:24:50.476+0000 [initandlisten] shutdown: closing all files...
2022-09-12T20:24:50.476+0000 [initandlisten] closeAllFiles() finished
2022-09-12T20:24:50.476+0000 [initandlisten] journalCleanup...
2022-09-12T20:24:50.476+0000 [initandlisten] removeJournalFiles
2022-09-12T20:24:50.477+0000 [initandlisten] shutdown: removing fs lock...
2022-09-12T20:24:50.477+0000 [initandlisten] dbexit: really exiting now


Looks like some initial mongodb initialization or admin and sandcats user creation failed. Can I initiate it manually? Or what version should I go back to? I don't see anything obvious in the commits that touched this... but I'm not familiar with the codebase.

@zenhack
Copy link
Collaborator

zenhack commented Sep 13, 2022

How much memory does the machine have? On smaller boxes we've had problems with things being OOM killed on startup. I'd hoped #3637 would hae fixed that, but maybe not.

We generally recommend at least 2GiB, though what you need will depend on how many grains you expect to be running concurrently. You shouldn't need that much just for install but if my fix was inadequate that could be the issue here too.

@dagelf
Copy link
Author

dagelf commented Sep 14, 2022

# grep Mem /proc/meminfo
MemTotal:        2030884 kB
MemFree:          123196 kB
MemAvailable:    1618872 kB

# grep Avail /proc/meminfo
MemAvailable:    1618916 kB

# cat /etc/issue
Ubuntu 20.04.5 LTS \n \l

# df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/vda1        39G   11G   29G  27% /
tmpfs           992M     0  992M   0% /dev/shm


This is a hosted VM. The development installations works fine in Docker. I've been familiarizing myself by trying a few so I can contribute automated tests.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
install-config Installation/configuration issues
Projects
None yet
Development

No branches or pull requests

3 participants