@Mvolz I've just tested in my local Vagrant and both works for me. Do you have the latest RESTBase code there?

Hmm, odd, thanks for checking.

I've done vagrant git-update a bunch, checked out both restbase and citoid manually as well, it says "everything up to date" - tried both branches of vagrant (master and trusty-compat - I'm on Trusty) Still getting the same thing. :/

@Pchelolo can you tell me your virtualbox and vagrant version? I updated mine to the latest version, destroyed and recreated the machine, and I'm afraid now I can't get restbase to work on vagrant at all :/ Just get "this service is temporarily unavailable" from all services. Ack.

Hmm,

When I ssh into the vagrant machine and try to manually install, I'm getting npm errors:

vagrant ssh
sudo service restbase stop
cd /vagrant/srv/restbase
rm -rf ./node_modules
sudo npm i

npm ERR! path /vagrant/srv/restbase/node_modules/esprima/bin/esparse.js
npm ERR! code ENOENT
npm ERR! errno -2
npm ERR! syscall chmod
npm ERR! enoent ENOENT: no such file or directory, chmod '/vagrant/srv/restbase/node_modules/esprima/bin/esparse.js'
npm ERR! enoent This is most likely not a problem with npm itself
npm ERR! enoent and is related to npm not being able to find a file.

On my own non-virtual machine, I don't get these errors.

vagrant@mediawiki-vagrant:/vagrant/srv/restbase$ node -v
v6.10.2
vagrant@mediawiki-vagrant:/vagrant/srv/restbase$ npm -v
4.5.0

@Mvolz Hm..

Vagrant 1.9.3
VBox 5.1.12
Host machine - macOS Sierra

One critical difference might be that I have vagrant settings nfs_shares off because of T158617

@Mvolz try manually deleted the node modules and re-installing them (rm -rf node_modules && npm install)

In case this helps anyone.... Host machine: Ubuntu Trusty 14.04 and nfs_shares set to no as well.

So far I've tried virtual box 5.1.18 (deb), 5.1.12(deb), 4.3.36 (installed via binary), vagrant 1.9.3 (deb), vagrant 1.9.2(deb) with completely clean clones of the mediawiki vagrant repo in each version. In each case I am able to create the machine, but when I enable the visualeditor role, I get a 503 when trying to access http://dev.wiki.local.wmftest.net:8080/api/rest_v1/....

Error: /usr/bin/npm install --no-bin-links returned 1 instead of one of [0]
==> default: Error: /Stage[main]/Restbase/Service::Node[restbase]/Npm::Install[/vagrant/srv/restbase]/Exec[/vagrant/srv/restbase_npm_install]/returns: change from notrun to 0 failed: /usr/bin/npm install --no-bin-links returned 1 instead of one of [0]
==> default: No

Warning: /Stage[main]/Restbase/Service::Node[restbase]/Systemd::Service[restbase]/Service[restbase]: Skipping because of failed dependencies

When I do vagrant ssh, and try to install from there (rm -rf node_modules && sudo npm install) I get errors, but I am able to install using the --no-bin-links flag.

sudo npm install --no-bin-links
> sqlite3@3.1.8 install /vagrant/srv/restbase/node_modules/sqlite3
> node-pre-gyp install --fallback-to-build

[sqlite3] Success: "/vagrant/srv/restbase/node_modules/sqlite3/lib/binding/node-v48-linux-x64/node_sqlite3.node" is installed via remote

However when I get it to that point and do sudo service restbase start, and load the page, I still get a 503 page on http://dev.wiki.local.wmftest.net:8080/api/rest_v1/

>systemctl status restbase

● restbase.service - "restbase service"
   Loaded: loaded (/lib/systemd/system/restbase.service; disabled)
   Active: inactive (dead)

The restbase logs look like this

>tail vagrant/logs/restbase.log 

{"name":"restbase","hostname":"mediawiki-vagrant","pid":2778,"level":60,"err":{"message":"Cannot find module 'npmlog'","name":"Error","stack":"Error: Cannot find module 'npmlog'\n    at Function.Module._resolveFilename (module.js:469:15)\n    at Function.Module._load (module.js:417:25)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp/lib/node-pre-gyp.js:15:11)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)\n    at tryModuleLoad (module.js:446:12)\n    at Function.Module._load (module.js:438:3)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/lib/sqlite3.js:1:76)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)","code":"MODULE_NOT_FOUND"},"stack":"Error: Cannot find module 'npmlog'\n    at Function.Module._resolveFilename (module.js:469:15)\n    at Function.Module._load (module.js:417:25)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp/lib/node-pre-gyp.js:15:11)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)\n    at tryModuleLoad (module.js:446:12)\n    at Function.Module._load (module.js:438:3)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/lib/sqlite3.js:1:76)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)","levelPath":"fatal/startup","msg":"Message not supplied","time":"2017-04-20T13:54:57.798Z","v":0}
{"name":"restbase","hostname":"mediawiki-vagrant","pid":2340,"level":50,"message":"worker 2778 died (1), restarting.","levelPath":"error/service-runner/master","msg":"worker 2778 died (1), restarting.","time":"2017-04-20T13:54:59.804Z","v":0}

So I went into the problem library folder and just directly installed the libraries there:

/vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp$ sudo npm install
npm WARN lifecycle node-pre-gyp@0.6.31~prepublish: cannot run in wd %s %s (wd=%s) node-pre-gyp@0.6.31 retire -n && npm ls && jshint test/build.test.js test/s3_setup.test.js test/versioning.test.js /vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp

Now restbase is running.

Seems to be some sort of issue with vagrant and symlinks and npm.

BUT AFTER ALL OF THAT:

the original issue, with the citoid config being wrong in restbase... is still there! After installing totally different versions of virtualbox/vagrant and using completely clean installs of mediawiki, I'm still having exactly the same issue as reported with citoid.

I'm getting this consistently in Vagrant and haven't found a way around it.

Trying to load VisualEditor always results in an error from RESTBase (HTTP 503). Error in the logs:

{"name":"restbase","hostname":"mediawiki-vagrant","pid":10368,"level":60,"err":{"message":"Cannot find module 'npmlog'","name":"Error","stack":"Error: Cannot find module 'npmlog'\n    at Function.Module._resolveFilename (module.js:469:15)\n    at Function.Module._load (module.js:417:25)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp/lib/node-pre-gyp.js:15:11)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)\n    at tryModuleLoad (module.js:446:12)\n    at Function.Module._load (module.js:438:3)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/lib/sqlite3.js:1:76)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)","code":"MODULE_NOT_FOUND"},"stack":"Error: Cannot find module 'npmlog'\n    at Function.Module._resolveFilename (module.js:469:15)\n    at Function.Module._load (module.js:417:25)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp/lib/node-pre-gyp.js:15:11)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)\n    at tryModuleLoad (module.js:446:12)\n    at Function.Module._load (module.js:438:3)\n    at Module.require (module.js:497:17)\n    at require (internal/module.js:20:19)\n    at Object.<anonymous> (/vagrant/srv/restbase/node_modules/sqlite3/lib/sqlite3.js:1:76)\n    at Module._compile (module.js:570:32)\n    at Object.Module._extensions..js (module.js:579:10)\n    at Module.load (module.js:487:32)","levelPath":"fatal/startup","msg":"Message not supplied","time":"2017-05-20T17:02:31.282Z","v":0}

I've already tried vagrant provision and vagrant git-update --force. I've also tried rm -rf node_modules; npm install inside /vagrant/srv/restbase. And I tried this both from within the VM, as well as plainly from the host terminal (in case it's got something to do with mounts or something).

The installation succeeds without issue and looking at restbase/node_modules/sqlite3/node_modules/node-pre-gyp/node_modules shows that npmlog exists just fine.

I've also tried rm -rf node_modules; npm install inside /vagrant/srv/restbase/node_modules/sqlite3/node_modules/node-pre-gyp and again succeeds without issue. Yet, on the next RESTBase request, it still fails the same way.

System: Mac OS X.
Versions: Node 6, npm 3. (Same on host and guest)

Tried debugging this with @Pchelolo and @GWicke but no luck. No matter which directory we run npm install or sudo or --no-bin-links, whether from the host or from within the guest, whether for all of restbase or just inside node_modules/node-pre-gyp, it fails.

We finally worked around it by manually running npm install npmlog@4.0 inside /vagrant/srv/restbase/, but that's only a temporary solution until the next reinstall.

@Catrope mentioned having some issues with npm running out of memory in Vagrant before. The way I understood him, this wasn't hitting the node heap limit, so wouldn't necessarily print the "Heap exceeded" exception. Perhaps worth checking by keeping an eye on overall memory usage, or by running /usr/bin/time npm install, and then looking at peak RSS in the time printout after npm exited.

I'm still having this issue.

I'm getting around the npmlog errors by installing it manually as above, but I'm still getting those hyperswitch errors for citations. However I am having difficulty debugging. When I tail the logs for both restbase and citoid, the last message I get is "startup finished" - any requests I make after that does not seem to be getting written to the logs.

Are the two issues in this bug report related?

Any thoughts? @Krinkle are you still getting the same issues, and do you get a hyperswitch error with http://dev.wiki.local.wmftest.net:8080/api/rest_v1/data/citation/mediawiki/http%3A%2F%2Fwww.example.com? Does it get written to your logs? I'm trying to figure out whether this is the same issue or a separate one.

@Pchelolo, I remember that you had this issue as well. Is that still the case?

@GWicke This is still happening for me. I've tried today to test various npm versions and find answers on google, but no luck for now.

Change 364929 had a related patch set uploaded (by Ppchelko; owner: Ppchelko):
[mediawiki/vagrant@master] Puppet: Downgrade npm to version 2

https://gerrit.wikimedia.org/r/364929

Found a workaround that seems to work for me - downgrading npm to version 2. Uglyish solution, I know, but I couldn't find anything nicer in tens on npm bugs related to this.

@Mvolz @Krinkle Could you check out the patch above and test if this works for you as well?

In T162468#3433910, @Pchelolo wrote:

Found a workaround that seems to work for me - downgrading npm to version 2. Uglyish solution, I know, but I couldn't find anything nicer in tens on npm bugs related to this.

@Mvolz @Krinkle Could you check out the patch above and test if this works for you as well?

Worked for me as well!

vagrant reload
vagrant provision
vagrant git-update --force
vagrant reload

The git-update portion (as usual) failed at RESTBase with Maximum call stack size exceeded . But then inside the vm, the following worked.

vagrant@mediawiki-vagrant:$ sudo npm install -g npm@2.x
vagrant@mediawiki-vagrant:/vagrant/srv/restbase$ sudo -u vagrant npm install --no-bin-links

After another vagrant reload, RESTBase is now working.

The git-update portion (as usual) failed at RESTBase with Maximum call stack size exceeded . But then inside the vm, the following worked.

Hm... That's not ideal, I've actually only checked whether it works via installing inside the VM, git-update --force takes too long..
Lemme try to make this work even for the vagrant git-update. The truth is out there

@Krinkle Interestingly, for me vagrant git-update also works with my patch.

Change 364929 merged by jenkins-bot:
[mediawiki/vagrant@master] Puppet: Downgrade npm to version 2

https://gerrit.wikimedia.org/r/364929

In T162468#3434045, @Pchelolo wrote:

The git-update portion (as usual) failed at RESTBase with Maximum call stack size exceeded . But then inside the vm, the following worked.

[..] npm@2.x [..]

Hm... That's not ideal

To clarify, I didn't apply your patch. I was just re-confirming that a clean run still failed, and that for me too, using npm 2 made it work.

I'm sure it'll work directly with vagrant git-update once your patch is applied :)