Skip to content

Sugarizer v1.0 migration#814

Merged
holta merged 12 commits intoiiab:masterfrom
georgejhunt:sugar
Jun 21, 2018
Merged

Sugarizer v1.0 migration#814
holta merged 12 commits intoiiab:masterfrom
georgejhunt:sugar

Conversation

@georgejhunt
Copy link
Copy Markdown
Contributor

@georgejhunt georgejhunt commented May 23, 2018

Description of changes proposed in this pull request.

This PR upgrades to the most recent sugarizer [implementing #798]

Smoke-tested in operating system.

2018-04-18 stretch lite.

Known issues: the proxy from apache /sugarizer to localhost:8089 does not work. But then the kiwix, and kalite proxies do not work either. I remember that I had them working once. But I've lost the magic sauce.

Tim's menu system goes directly to the desired port, so maybe it does not matter.

@holta holta added this to the 6.5 milestone May 23, 2018
@holta
Copy link
Copy Markdown
Member

holta commented May 23, 2018

Any idea if applying this PR to an existing Raspbian Lite and then running "./iiab-install --reinstall" might have a shot?

Aside: Is it premature to test that on Ubuntu 18.04 too?

(Obviously a clean install of IIAB is always best, regardless of either OS above, or others!)

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 23, 2018 via email

@holta
Copy link
Copy Markdown
Member

holta commented May 23, 2018

I ran the following on IIAB 6.5/master on U18/Desktop: (10.8.0.10)

cd /opt/iiab/iiab
git checkout -b georgejhunt-sugar master
git pull https://github.com/georgejhunt/iiab.git sugar
iiab-install --reinstall

This completed without error. How should I test?

  1. http://box/sugarizer responds with:
Bad Request

Your browser sent a request that this server could not understand.
Apache/2.4.29 (Ubuntu) Server at [IP Address] Port 80
  1. http://box:8089 does not respond.

@georgejhunt can you log in (10.8.0.10) to confirm things are as they should be?

@holta
Copy link
Copy Markdown
Member

holta commented May 23, 2018

PS i have a U18/Server machine (Ubuntu 18.04/Server @ 10.8.0.26) that can be tested later today if that's also helpful?

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 23, 2018 via email

@holta
Copy link
Copy Markdown
Member

holta commented May 23, 2018

I need to reboot 10.8.0.10

Feel free, Thanks!

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 23, 2018 via email

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 24, 2018 via email

@holta
Copy link
Copy Markdown
Member

holta commented May 24, 2018

Thx @georgejhunt for your tremendous progress! @llaske do you have ideas on some of the MongoDB & api/controlers/users.js issues George is facing on-ticket above?

@holta holta mentioned this pull request May 24, 2018
@holta
Copy link
Copy Markdown
Member

holta commented May 24, 2018

Thanks to @jvonau who reviewed this code (PR #814) quickly earlier today.

@llaske
Copy link
Copy Markdown

llaske commented May 24, 2018

I've reproduced the issue on my Sugarizer testing environment.
This error happens when MongoDB is not running or not reachable from the Sugarizer Server.
Are you sure your MongoDB services is running ?

You could test it by launch the mongo interactive command line:

mongo --port 27018

@holta holta modified the milestones: 6.5, 6.6 May 24, 2018
@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 25, 2018 via email

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 25, 2018 via email

@llaske
Copy link
Copy Markdown

llaske commented May 25, 2018

Hmmm. Strange.

Could you launch in one another terminal the mongo command line to check if mongo is really listening:

mongo --port 27018

Should answer something like that:

MongoDB shell version: 3.2.7
connecting to: 127.0.0.1:27018/test
> 

Also I've seen the line:

ExecStart=/usr/bin/mongod --fork -f /etc/mongod.conf

It don't mention the port 27018. I expected something like:

ExecStart=/usr/bin/mongod --fork --port 27018 -f /etc/mongod.conf

But may be port settings is mentioned in the mongod.conf. Could you check?

@llaske
Copy link
Copy Markdown

llaske commented May 29, 2018

Ooohh, interesting. So it means than Sugarizer can't connect to the MongoDB database :-(
Stupid question: are you sure the port configured in the database section of sugarizer.ini is the same than the one MongoDB is listening ?
Default port in sugarizer.ini is 27018 but default port for MongoDB is often 27017.

Not sure to understand which process open 820 connections to MongoDB ?

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 29, 2018 via email

@llaske
Copy link
Copy Markdown

llaske commented May 30, 2018

If you see continuously the message "Waiting for DB..." when starting node, it means that Sugarizer is unable to connect to MongoDB. It's why I'm assuming that something goes wrong on the connection between node and MongoDB.

Just to eliminate an option, could you ensure than the port configured in the database section of env/sugarizer.ini file is the same than the one MongoDB is listening ?
You should have something like:

[database]
server = localhost
port = 27018
name = sugarizer
waitdb = 1

@jvonau
Copy link
Copy Markdown
Contributor

jvonau commented May 30, 2018

This PR appears to be working on RPi

pi@box:/opt/iiab/iiab $ systemctl status mongodb
● mongodb.service - High-performance, schema-free document-oriented database
Loaded: loaded (/etc/systemd/system/mongodb.service; enabled; vendor preset:
Active: active (running) since Wed 2018-05-30 14:17:12 UTC; 1min 41s ago
Main PID: 589 (mongod)
CGroup: /system.slice/mongodb.service
└─589 /usr/bin/mongod -f /etc/mongod.conf
May 30 14:17:12 box.lan systemd[1]: Started High-performance, schema-free docume
May 30 14:17:15 box.lan mongod[589]: note: noprealloc may hurt performance in ma
May 30 14:17:15 box.lan mongod[589]: all output going to: /var/log/mongodb/mongo
May 30 14:17:15 box.lan mongod[589]: log file [/var/log/mongodb/mongod.log] exis

pi@box:/opt/iiab/iiab $ cat /var/log/mongodb/mongod.log
Wed May 30 14:17:15.573 [initandlisten] MongoDB starting : pid=589 port=27018 dbpath=/library/dbdata/mongodb 32-bit host=box.lan
Wed May 30 14:17:15.574 [initandlisten]
Wed May 30 14:17:15.574 [initandlisten] ** NOTE: This is a 32 bit MongoDB binary.
Wed May 30 14:17:15.574 [initandlisten] ** 32 bit builds are limited to less than 2GB of data (or less with --journal).
Wed May 30 14:17:15.574 [initandlisten] ** See http://dochub.mongodb.org/core/32bit
Wed May 30 14:17:15.574 [initandlisten]
Wed May 30 14:17:15.574 [initandlisten] db version v2.4.14
Wed May 30 14:17:15.574 [initandlisten] git version: nogitversion
Wed May 30 14:17:15.574 [initandlisten] build info: Linux bm-wb-03 3.19.0-trunk-armmp #1 SMP Debian 3.19.1-1~exp1+plugwash1 (2015-03-28) armv7l BOOST_LIB_VERSION=1_58
Wed May 30 14:17:15.574 [initandlisten] allocator: system
Wed May 30 14:17:15.575 [initandlisten] options: { bind_ip: "127.0.0.1", config: "/etc/mongod.conf", dbpath: "/library/dbdata/mongodb", journal: "true", logpath: "/var/log/mongodb/mongod.log", maxConns: 10000, noprealloc: "true", port: 27018, smallfiles: "true" }
Wed May 30 14:17:15.734 [initandlisten] journal dir=/library/dbdata/mongodb/journal
Wed May 30 14:17:15.734 [initandlisten] recover begin
Wed May 30 14:17:15.745 [initandlisten] recover lsn: 0
Wed May 30 14:17:15.745 [initandlisten] recover /library/dbdata/mongodb/journal/j._0
Wed May 30 14:17:15.901 [initandlisten] recover cleaning up
Wed May 30 14:17:15.901 [initandlisten] removeJournalFiles
Wed May 30 14:17:15.975 [initandlisten] recover done
Wed May 30 14:17:15.976 [initandlisten] preallocating a journal file /library/dbdata/mongodb/journal/prealloc.0
Wed May 30 14:17:46.931 [initandlisten] --maxConns too high, can only handle 819
Wed May 30 14:17:46.932 [initandlisten] waiting for connections on port 27018
Wed May 30 14:17:46.932 [websvr] admin web console waiting for connections on port 28018
Wed May 30 14:17:52.306 [initandlisten] connection accepted from 127.0.0.1:35722 #1 (1 connection now open)
Wed May 30 14:17:52.307 [initandlisten] connection accepted from 127.0.0.1:35724 #2 (2 connections now open)
Wed May 30 14:17:52.307 [initandlisten] connection accepted from 127.0.0.1:35726 #3 (3 connections now open)
Wed May 30 14:17:52.431 [initandlisten] connection accepted from 127.0.0.1:35728 #4 (4 connections now open)
Wed May 30 14:17:52.431 [initandlisten] connection accepted from 127.0.0.1:35730 #5 (5 connections now open)
Wed May 30 14:17:52.431 [initandlisten] connection accepted from 127.0.0.1:35732 #6 (6 connections now open)
Wed May 30 14:17:52.484 [initandlisten] connection accepted from 127.0.0.1:35734 #7 (7 connections now open)
Wed May 30 14:17:52.485 [initandlisten] connection accepted from 127.0.0.1:35736 #8 (8 connections now open)
Wed May 30 14:17:52.485 [initandlisten] connection accepted from 127.0.0.1:35738 #9 (9 connections now open)
Wed May 30 14:17:52.534 [initandlisten] connection accepted from 127.0.0.1:35740 #10 (10 connections now open)
Wed May 30 14:17:52.542 [initandlisten] connection accepted from 127.0.0.1:35742 #11 (11 connections now open)
Wed May 30 14:17:52.543 [initandlisten] connection accepted from 127.0.0.1:35744 #12 (12 connections now open)
Wed May 30 14:17:52.560 [initandlisten] connection accepted from 127.0.0.1:35746 #13 (13 connections now open)
Wed May 30 14:17:52.561 [initandlisten] connection accepted from 127.0.0.1:35748 #14 (14 connections now open)
Wed May 30 14:17:52.595 [initandlisten] connection accepted from 127.0.0.1:35750 #15 (15 connections now open)

systemctl status sugarizer -l
● sugarizer.service - Node.js Sugarizer Server
Loaded: loaded (/etc/systemd/system/sugarizer.service; enabled; vendor preset: enabled)
Active: active (running) since Wed 2018-05-30 15:17:13 UTC; 3min 27s ago
Main PID: 583 (node)
CGroup: /system.slice/sugarizer.service
└─583 /usr/bin/node /opt/iiab/sugarizer-server/sugarizer.js
May 30 15:20:23 box.lan sugarizer[583]: at require (internal/module.js:20:19)
May 30 15:20:23 box.lan sugarizer[583]: at Object. (/opt/iiab/sugarizer-server-1.0/node_modules/mong
May 30 15:20:23 box.lan sugarizer[583]: at Module._compile (module.js:577:32)
May 30 15:20:23 box.lan sugarizer[583]: at Object.Module._extensions..js (module.js:586:10)
May 30 15:20:23 box.lan sugarizer[583]: at Module.load (module.js:494:32)
May 30 15:20:23 box.lan sugarizer[583]: at tryModuleLoad (module.js:453:12)
May 30 15:20:23 box.lan sugarizer[583]: at Function.Module._load (module.js:445:3) code: 'MODULE_NOT_FOUND' }
May 30 15:20:23 box.lan sugarizer[583]: js-bson: Failed to load c++ bson extension, using pure JS version
May 30 15:20:26 box.lan sugarizer[583]: Sugarizer Server is listening on port 8089...
May 30 15:20:26 box.lan sugarizer[583]: Presence Server is listening on port 8039...

journalctl -u sugarizer -l
-- Logs begin at Thu 2016-11-03 17:16:43 UTC, end at Wed 2018-05-30 15:22:02 UTC. --
May 30 15:17:13 box.lan systemd[1]: Started Node.js Sugarizer Server.
May 30 15:20:23 box.lan sugarizer[583]: { Error: Cannot find module '../build/Release/bson'
May 30 15:20:23 box.lan sugarizer[583]: at Function.Module._resolveFilename (module.js:476:15)
May 30 15:20:23 box.lan sugarizer[583]: at Function.Module._load (module.js:424:25)
May 30 15:20:23 box.lan sugarizer[583]: at Module.require (module.js:504:17)
May 30 15:20:23 box.lan sugarizer[583]: at require (internal/module.js:20:19)
May 30 15:20:23 box.lan sugarizer[583]: at Object. (/opt/iiab/sugarizer-server-1.0/node_modules/mong
May 30 15:20:23 box.lan sugarizer[583]: at Module._compile (module.js:577:32)
May 30 15:20:23 box.lan sugarizer[583]: at Object.Module._extensions..js (module.js:586:10)
May 30 15:20:23 box.lan sugarizer[583]: at Module.load (module.js:494:32)
May 30 15:20:23 box.lan sugarizer[583]: at tryModuleLoad (module.js:453:12)
May 30 15:20:23 box.lan sugarizer[583]: at Function.Module._load (module.js:445:3) code: 'MODULE_NOT_FOUND' }
May 30 15:20:23 box.lan sugarizer[583]: js-bson: Failed to load c++ bson extension, using pure JS version
May 30 15:20:26 box.lan sugarizer[583]: Sugarizer Server is listening on port 8089...
May 30 15:20:26 box.lan sugarizer[583]: Presence Server is listening on port 8039...

@georgejhunt
Copy link
Copy Markdown
Contributor Author

georgejhunt commented May 30, 2018 via email

@holta
Copy link
Copy Markdown
Member

holta commented Jun 21, 2018

Post-merge conclusions/observations on Raspbian Lite on Rpi 3 B+:

  1. Both of the following were set in /opt/iiab/iiab/vars/local_vars.yml, even if we're not 100% sure both are necessary :)
sugarizer_install: True
sugarizer_enabled: True
  1. "./runrole sugarizer" completed, which also runs mongodb role thanks to @jvonau
  2. http://10.8.0.22:8089 now works!
    a. REBOOT so that Sugarizer registration works all the way thru to the Sugar ring/spiral (thereby avoiding a "500 internal server error")
    b. Run "iiab-gen-iptables" for good measure (though it doesn't seem to fix either below)
  3. http://192.168.0.142:8089 does not work -- @georgejhunt will look into it in coming days
  4. http://10.8.0.22/sugarizer and http://192.168.0.142/sugarizer no longer work, as they did with Sugarizer 0.9

PS http://box:8089 does not work at all on Ubuntu 18.04 for now, which is a Known Issue that would require further help from @llaske

@holta
Copy link
Copy Markdown
Member

holta commented Jun 21, 2018

CLARIF that our re-introduction of MongoDB (as Sugarizer 1.0 truly requires, unlike Sugarizer 0.9) appears to be causing ~768MB (typically 3 prealloc files) to reappear on RPi microSD cards — while unfortunate, this is not a surprise — much as in 2017 with #254:

root@box:~# du -hsc /var/lib/mongodb/journal/*
257M    /var/lib/mongodb/journal/prealloc.0
256M    /var/lib/mongodb/journal/prealloc.1
256M    /var/lib/mongodb/journal/prealloc.2
769M    total

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

@llaske & @georgejhunt: A fresh install of Sugarizer 1.0 and IIAB 6.6/master on a clean Ubuntu 18.04/Server fails at http://box:8089 with this error every time: (on Sugarizer's "Click to change color" screen, right after trying to set a password as a "New user")

Server error code 500

FYI this occurs regardless of which IP address (LAN or VPN) is used in placed of in the URL. Attempting George's earlier trick to run "iiab-gen-iptables", then "cd /opt/iiab/iiab; ./iiab-network" and rebooting did not help in this case.

What else can be tried?

If it helps, these are the version numbers installed by Ubuntu 18.04/Server:

root@box:~# apt -a list mongodb nodejs npm
Listing... Done
mongodb/bionic,now 1:3.6.3-0ubuntu1 amd64 [installed]

nodejs/bionic,now 8.10.0~dfsg-2 amd64 [installed]

npm/bionic,now 3.5.2-0ubuntu4 all [installed]

@llaske
Copy link
Copy Markdown

llaske commented Jul 11, 2018

Server error code 500

Is it possible to see what happens on the server console when this error is displayed on the browser ?

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

Is it possible to see what happens on the server console when this error is displayed on the browser ?

I don't know what you mean by server console but FYI journalctl -u sugarizer -l shows error TypeError: Cannot read property 'find' of undefined immediately prior to showing the 500 error (POST /auth/signup/?0.5124582834064612 500 0.963 ms - 1135) at bottom:

Jul 11 04:55:57 box.lan sugarizer[1033]: GET / 200 1.211 ms - 2472
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/graphics/css/sugar-96dpi.css 200 1.027 ms - 9154
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/graphics/css/sugar-200dpi.css 200 8.714 ms - 9155
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /css/activity.css 200 4.380 ms - 605
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /css/libnotify.css 200 4.312 ms - 4502
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /css/bootstrap-tour-standalone.min.css 200 4.322 ms - 17637
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/init.js 200 4.560 ms - 575
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/jquery.min.js 200 4.416 ms - 86659
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/bootstrap-tour-standalone.min.js 200 1.616 ms - 31828
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/enyo/enyo.css 200 1.834 ms - 14667
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/require.js 200 1.640 ms - 80196
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /cordova.js 200 1.692 ms - 129
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /css/styles.css 200 1.935 ms - 28092
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/constant.js 200 0.893 ms - 6892
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/icon.js 200 0.956 ms - 5085
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/iconbutton.js 200 1.349 ms - 940
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/password.js 200 1.771 ms - 7257
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/enyo/enyo.js 200 2.616 ms - 331182
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/homeview.js 200 8.640 ms - 25130
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/firstscreen.js 200 2.218 ms - 19634
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/neighborhood.js 200 3.265 ms - 25680
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/journal.js 200 3.045 ms - 30463
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/listview.js 200 3.439 ms - 6948
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/popup.js 200 1.112 ms - 5470
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/audio.js 200 1.370 ms - 5533
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/searchfield.js 200 3.306 ms - 1787
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/selectbox.js 200 3.587 ms - 2642
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/dialog.js 200 3.515 ms - 48289
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/loader.js 200 1.006 ms - 103
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /icons/ArrowSmall.cur 200 4.393 ms - 2462
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /js/app.js 200 4.592 ms - 1625
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /locale.ini 200 4.864 ms - 101689
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /favicon.ico 200 0.608 ms - 1150
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/webL10n.js 200 2.195 ms - 28350
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/graphics/icon.js 200 2.985 ms - 2475
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/graphics/xocolor.js 200 5.271 ms - 14518
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/graphics/radiobuttonsgroup.js 200 6.430 ms - 1627
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/datastore.js 200 6.464 ms - 302
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/presence.js 200 4.105 ms - 8200
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/settings.js 200 4.362 ms - 13543
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/server.js 200 3.181 ms - 9447
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/humane.js 200 0.673 ms - 8209
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/util.js 200 2.384 ms - 13865
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/tutorial.js 200 2.775 ms - 8507
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/stats.js 200 3.057 ms - 2254
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/autosync.js 200 3.408 ms - 4598
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/env.js 200 2.338 ms - 3369
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/datastore/sugarizer.js 200 2.405 ms - 9928
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/datastore/sugaros.js 200 2.474 ms - 6581
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/bus.js 200 0.924 ms - 265
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/bus/sugarizer.js 200 2.740 ms - 1962
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/sugar-web/bus/sugaros.js 200 2.763 ms - 5849
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /locale.ini 200 0.804 ms - 101689
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /lib/domReady.js 200 1.324 ms - 4035
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /api/?0.8656747523486812 200 1.228 ms - 217
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /images/spinner-light.gif 200 0.701 ms - 1924
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /icons/newuser-icon.svg 200 4.851 ms - 5177
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /icons/login.svg 200 5.163 ms - 2211
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /icons/owner-icon.svg 200 4.218 ms - 3614
Jul 11 04:55:57 box.lan sugarizer[1033]: GET /icons/owner-icon.svg 200 4.416 ms - 3614
Jul 11 04:56:00 box.lan sugarizer[1033]: GET /icons/go-left.svg 200 2.257 ms - 1647
Jul 11 04:56:00 box.lan sugarizer[1033]: GET /icons/go-right.svg 200 2.781 ms - 2027
Jul 11 04:56:03 box.lan sugarizer[1033]: GET /fonts/NotoEmoji.woff 200 0.842 ms - 293464
Jul 11 04:56:06 box.lan sugarizer[1033]: GET /icons/entry-cancel.svg 200 1.193 ms - 2030
Jul 11 04:56:10 box.lan sugarizer[1033]: TypeError: Cannot read property 'find' of undefined
Jul 11 04:56:10 box.lan sugarizer[1033]: at /opt/iiab/sugarizer-server-1.0/api/controller/users.js:237:14
Jul 11 04:56:10 box.lan sugarizer[1033]: at Db.collection (/opt/iiab/sugarizer-server-1.0/node_modules/mongodb/lib/mongodb/db.js:526:27)
Jul 11 04:56:10 box.lan sugarizer[1033]: at Object.exports.getAllUsers (/opt/iiab/sugarizer-server-1.0/api/controller/users.js:234:5)
Jul 11 04:56:10 box.lan sugarizer[1033]: at Object.exports.addUser (/opt/iiab/sugarizer-server-1.0/api/controller/users.js:396:10)
Jul 11 04:56:10 box.lan sugarizer[1033]: at exports.signup (/opt/iiab/sugarizer-server-1.0/api/controller/auth.js:150:8)
Jul 11 04:56:10 box.lan sugarizer[1033]: at callbacks (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:164:37)
Jul 11 04:56:10 box.lan sugarizer[1033]: at param (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:138:11)
Jul 11 04:56:10 box.lan sugarizer[1033]: at pass (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:145:5)
Jul 11 04:56:10 box.lan sugarizer[1033]: at Router._dispatch (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:173:5)
Jul 11 04:56:10 box.lan sugarizer[1033]: at Object.router [as handle] (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:33:10)
Jul 11 04:56:10 box.lan sugarizer[1033]: POST /auth/signup/?0.5124582834064612 500 0.963 ms - 1135
Jul 11 04:56:10 box.lan sugarizer[1033]: GET /icons/emblem-warning.svg 200 0.687 ms - 974

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

FYI journalctl -u sugarizer -l shows error TypeError: Cannot read property 'find' of undefined immediately prior to showing the 500 error (POST /auth/signup/?0.5124582834064612 500 0.963 ms - 1135) at bottom

The 10 lines after "TypeError" (excerpt below, from above) indicate sugarizer-server appears to be failing in places (like) https://github.com/llaske/sugarizer-server/blob/v1.0/api/controller/users.js#L237

GET /icons/entry-cancel.svg 200 1.193 ms - 2030
TypeError: Cannot read property 'find' of undefined
    at /opt/iiab/sugarizer-server-1.0/api/controller/users.js:237:14
    at Db.collection (/opt/iiab/sugarizer-server-1.0/node_modules/mongodb/lib/mongodb/db.js:526:27)
    at Object.exports.getAllUsers (/opt/iiab/sugarizer-server-1.0/api/controller/users.js:234:5)
    at Object.exports.addUser (/opt/iiab/sugarizer-server-1.0/api/controller/users.js:396:10)
    at exports.signup (/opt/iiab/sugarizer-server-1.0/api/controller/auth.js:150:8)
    at callbacks (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:164:37)
    at param (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:138:11)
    at pass (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:145:5)
    at Router._dispatch (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:173:5)
    at Object.router [as handle] (/opt/iiab/sugarizer-server-1.0/node_modules/express/lib/router/index.js:33:10)
POST /auth/signup/?0.5124582834064612 500 0.963 ms - 1135
GET /icons/emblem-warning.svg 200 0.687 ms - 974

@llaske
Copy link
Copy Markdown

llaske commented Jul 11, 2018

I've just deployed an Ubuntu 18.04 VM on my laptop and tried to run inside Sugarizer Server with node.js v8.10 and mongod v3.6.3.
There is a clear connection issue: the Sugarizer Server don't seem to detect MongoDB connection thought the connection is done correctly from the MongoDB side.
The symptom is that Sugarizer Server wait for ever (without any message on the console).
I guess it's related to the version of node.js mongo API. I'm working on it.

@llaske
Copy link
Copy Markdown

llaske commented Jul 11, 2018

Just done a fix to upgrade to MongoDB driver 2.x: llaske/sugarizer-server@b90104d
Sugarizer Server now works perfectly on my Ubuntu 18.04 VM.
Could you test it ?
You need to do:

git pull
npm install

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

Just done a fix to upgrade to MongoDB driver 2.x: llaske/sugarizer-server@b90104d
Sugarizer Server now works perfectly on my Ubuntu 18.04 VM.
Could you test it ?
You need to do:

git pull
npm install

Will ask @georgejhunt how I can test this on IIAB. Thx Much @llaske

Can you confirm this should also work with Raspbian's brand new (as of 48-72h ago, mandatory when you "apt update" etc) Node.js 8.11 ? Against Raspbian's pre-existing MongoDB 2.4.14 — as earlier outlined by @georgejhunt at #798 (comment) and reconfirmed here:

root@box:~# apt -a list mongodb nodejs npm
Listing... Done
mongodb/stable,now 1:2.4.14-4 armhf [installed]

nodejs/stable,now 8.11.1~dfsg-2~bpo9+1 armhf [installed]
nodejs/unknown 6.14.3-1nodesource1 armhf
nodejs/stable 4.8.2~dfsg-1 armhf

npm/stable 1.4.21+ds-2 all

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

  1. Thanks @llaske this works on Ubuntu 18.04/Server but not on Raspbian (Raspberry Pi) after I moved the old /opt/iiab/sugarizer-server[-1.0] out of the way in both cases, then ran:

I did not touch the original Sugarizer 1.0 "client not server" directory /opt/iiab/sugarizer-1.0 (385MB). Aside: IIAB will add "waitdb = 1" to our sugarizer.ini template if that's wise, as @llaske added 2018-05-29 (llaske/sugarizer-server@0ec8bde).

  1. Question About Timelines: Internet-in-a-Box will need a new http://download.iiab.io/packages/sugarizer-server-1.0.tar.gz to roll this out on all continents in a few short days (Sugarizer 1.0 continues to block installs of IIAB 6.6/master very sadly, another confirmed report came in from South Africa today) and also for the final release of IIAB 6.6 in coming weeks. Does it make sense for Sugarizer to release v1.0.1 or v1.1 including these fixes and confirmation this works on the new Raspbian? (which includes Node.js 8.x and 2.4.14).

  2. Is Raspbian's default npm 1.4.21 sufficient compared to Ubuntu 18.04's npm 3.5.2? As mentioned 2 days ago (Sugarizer 0.9 -> 1.0 #798 (comment)) systemctl restart sugarizer fails within 2 seconds every time. The error on Raspbian seems to be Error: Cannot find module 'body-parser' occurring in both /opt/iiab/sugarizer-server-1.0/config/main.js:5:15 and /opt/iiab/sugarizer-server-1.0/node_modules/mongodb/lib/server.js:327 and is pasted here in full: (from "journalctl -u sugarizer --no-pager")

Jul 11 13:55:52 box.lan sugarizer[29583]: Error: Cannot find module 'body-parser'
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._resolveFilename (module.js:547:15)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._load (module.js:474:25)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module.require (module.js:596:17)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at require (internal/module.js:11:18)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Object.<anonymous> (/opt/iiab/sugarizer-server-1.0/config/main.js:5:15)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module._compile (module.js:652:30)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Object.Module._extensions..js (module.js:663:10)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module.load (module.js:565:32)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at tryModuleLoad (module.js:505:12)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._load (module.js:497:3)
Jul 11 13:55:52 box.lan sugarizer[29583]: /opt/iiab/sugarizer-server-1.0/node_modules/mongodb/lib/server.js:327
Jul 11 13:55:52 box.lan sugarizer[29583]:       process.nextTick(function() { throw err; })
Jul 11 13:55:52 box.lan sugarizer[29583]:                                     ^
Jul 11 13:55:52 box.lan sugarizer[29583]: Error: Cannot find module 'body-parser'
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._resolveFilename (module.js:547:15)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._load (module.js:474:25)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module.require (module.js:596:17)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at require (internal/module.js:11:18)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Object.<anonymous> (/opt/iiab/sugarizer-server-1.0/config/main.js:5:15)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module._compile (module.js:652:30)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Object.Module._extensions..js (module.js:663:10)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Module.load (module.js:565:32)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at tryModuleLoad (module.js:505:12)
Jul 11 13:55:52 box.lan sugarizer[29583]:     at Function.Module._load (module.js:497:3)
Jul 11 13:55:52 box.lan systemd[1]: sugarizer.service: Main process exited, code=exited, status=1/FAILURE
Jul 11 13:55:52 box.lan systemd[1]: sugarizer.service: Unit entered failed state.
Jul 11 13:55:52 box.lan systemd[1]: sugarizer.service: Failed with result 'exit-code'.
Jul 11 13:56:03 box.lan systemd[1]: sugarizer.service: Service hold-off time over, scheduling restart.
Jul 11 13:56:03 box.lan systemd[1]: Stopped Node.js Sugarizer Server.
Jul 11 13:56:03 box.lan systemd[1]: Started Node.js Sugarizer Server.
  1. Testing Sugarizer 1.x on Debian 9.5 can start Saturday when it's released then (in fact, to celebrate Juillet 14 ;)

@llaske
Copy link
Copy Markdown

llaske commented Jul 11, 2018

I can confirm that this fix works too on Raspbian, I've updated my Sugarizer Schoolbox with this patch and it works. Just updated on try.sugarizer.org too.
Mention of missing module 'body-parser' is strange, it's mentioned as a dependency of the 'express' module and appears correctly in your log. Warnings are not an issue, I've got the sames on Ubuntu.
Could you try to clean your node environment and retry:

rm -rf node_modules/
npm install

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

Mention of missing module 'body-parser' is strange, it's mentioned as a dependency of the 'express' module and appears correctly in your log. Warnings are not an issue, I've got the sames on Ubuntu.
Could you try to clean your node environment and retry:

rm -rf node_modules/
npm install

I just ran the above (this is Raspbian Lite on RPi 3 B+, fully updated with "apt update; apt -y dist-upgrade").

Unfortunately the result is the same: "systemctl restart sugarizer" consistently fails 2 seconds later, with both Error: Cannot find module 'body-parser' errors arising every-15-seconds-or-so in logs shown by "journalctl -u sugarizer"

@llaske
Copy link
Copy Markdown

llaske commented Jul 11, 2018

fully updated with "apt update; apt -y dist-upgrade"
It's not about the system environment. Just to be sure: my proposal was to clean the Sugarizer Server node.js environment to ensure that all module are here. So to be more precise I expect something like:

cd <sugarizer-server-directory>
rm -rf node_modules/
npm install

@holta
Copy link
Copy Markdown
Member

holta commented Jul 11, 2018

cd <sugarizer-server-directory>
rm -rf node_modules/
npm install

The above did not work...until I first upgraded npm 1.4.21 to npm 5.6.0 as follows:

This above is likely not the best way (this also upgraded Node.js 8.11.1 to 8.11.3; let's try to conform to the OS's recommended packages wherever possible!) but as a proof-of-concept the above Worked 100% (Sugarizer 1.0 logins work at http://box:8089).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants