Post to /api/users/logout crashes node

[arlaneenalra]

Steps to reproduce:

1. Create an application with slc lb project bug-test
2. Start application with npm start or slc start
3. Run curl -X 'POST' localhost:3000/api/users/logout

I've seen this happen with and without an access token parameter.

Console output:

csalch@Chriss-MacBook-Air ~/bug-test $ npm start

> bug-test@0.0.0 start /Users/csalch/bug-test
> node app.js

StrongOps not configured to monitor. Please refer to http://docs.strongloop.com/strong-agent for usage.
connect.multipart() will be removed in connect 3.0
visit https://github.com/senchalabs/connect/wiki/Connect-3.0 for alternatives
connect.limit() will be removed in connect 3.0
Browse your REST API at http://0.0.0.0:3000/explorer
LoopBack server listening @ http://0.0.0.0:3000/

/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:83
          throw new Error(name + ' is a required arg');
                ^
Error: access_token is a required arg
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:83:17
    at Array.forEach (native)
    at SharedMethod.invoke (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:74:13)
    at HttpContext.invoke (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/http-context.js:221:12)
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/remote-objects.js:416:9
    at execStack (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/remote-objects.js:287:7)
    at /Users/csalch/bug-test/node_modules/loopback/lib/application.js:177:13
    at /Users/csalch/bug-test/node_modules/loopback/lib/models/acl.js:445:17
    at /Users/csalch/bug-test/node_modules/loopback/lib/models/acl.js:408:19
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/async/lib/async.js:229:13

npm ERR! bug-test@0.0.0 start: `node app.js`
npm ERR! Exit status 8
npm ERR!
npm ERR! Failed at the bug-test@0.0.0 start script.
npm ERR! This is most likely a problem with the bug-test package,
npm ERR! not with npm itself.
npm ERR! Tell the author that this fails on your system:
npm ERR!     node app.js
npm ERR! You can get their info via:
npm ERR!     npm owner ls bug-test
npm ERR! There is likely additional logging output above.
npm ERR! System Darwin 12.5.0
npm ERR! command "/usr/local/Cellar/node/0.10.24/bin/node" "/usr/local/bin/npm" "start"
npm ERR! cwd /Users/csalch/bug-test
npm ERR! node -v v0.10.24
npm ERR! npm -v 1.3.21
npm ERR! code ELIFECYCLE
npm ERR!
npm ERR! Additional logging details can be found in:
npm ERR!     /Users/csalch/bug-test/npm-debug.log
npm ERR! not ok code 0

npm ls

bug-test@0.0.0 /Users/csalch/bug-test
├─┬ loopback@1.4.1
│ ├── async@0.2.9
│ ├── bcryptjs@0.7.10
│ ├── debug@0.7.4
│ ├── ejs@0.8.5
│ ├─┬ express@3.4.7
│ │ ├── buffer-crc32@0.2.1
│ │ ├─┬ commander@1.3.2
│ │ │ └── keypress@0.1.0
│ │ ├─┬ connect@2.12.0
│ │ │ ├── batch@0.5.0
│ │ │ ├── bytes@0.2.1
│ │ │ ├─┬ multiparty@2.2.0
│ │ │ │ ├─┬ readable-stream@1.1.9
│ │ │ │ │ ├── core-util-is@1.0.0
│ │ │ │ │ └── debuglog@0.0.2
│ │ │ │ └── stream-counter@0.2.0
│ │ │ ├── negotiator@0.3.0
│ │ │ ├── pause@0.0.1
│ │ │ ├── qs@0.6.6
│ │ │ └── raw-body@1.1.2
│ │ ├── cookie@0.1.0
│ │ ├── cookie-signature@1.0.1
│ │ ├── fresh@0.2.0
│ │ ├── merge-descriptors@0.0.1
│ │ ├── methods@0.1.0
│ │ ├── mkdirp@0.3.5
│ │ ├── range-parser@0.0.4
│ │ └─┬ send@0.1.4
│ │   └── mime@1.2.11
│ ├── inflection@1.2.7
│ ├─┬ nodemailer@0.5.15
│ │ ├── directmail@0.1.6
│ │ ├── he@0.3.6
│ │ ├─┬ mailcomposer@0.2.7
│ │ │ ├── dkim-signer@0.1.0
│ │ │ ├── follow-redirects@0.0.3
│ │ │ ├── mime@1.2.9
│ │ │ ├─┬ mimelib@0.2.14
│ │ │ │ ├── addressparser@0.2.0
│ │ │ │ └─┬ encoding@0.1.7
│ │ │ │   └── iconv-lite@0.2.11
│ │ │ └── punycode@1.2.3
│ │ ├── public-address@0.1.0
│ │ ├─┬ readable-stream@1.1.9
│ │ │ ├── core-util-is@1.0.0
│ │ │ └── debuglog@0.0.2
│ │ └─┬ simplesmtp@0.3.16
│ │   ├── rai@0.1.9
│ │   └── xoauth2@0.1.8
│ ├─┬ passport@0.1.17
│ │ ├── pause@0.0.1
│ │ └── pkginfo@0.2.3
│ ├─┬ passport-local@0.1.6
│ │ └── pkginfo@0.2.3
│ ├─┬ strong-remoting@1.1.5
│ │ ├── cors@2.1.1
│ │ ├── eventemitter2@0.4.13
│ │ └─┬ jayson@1.0.11
│ │   ├── commander@2.1.0
│ │   └── eyes@0.1.8
│ ├── uid2@0.0.3
│ ├── underscore@1.5.2
│ └── underscore.string@2.3.3
├─┬ loopback-datasource-juggler@1.2.11
│ ├── async@0.2.9
│ ├── inflection@1.2.7
│ ├── qs@0.6.6
│ └── traverse@0.6.6
├── loopback-explorer@1.0.1
├─┬ strong-agent@0.2.19
│ ├── async@0.1.22
│ ├── measured@0.1.3
│ ├── memwatch@0.2.2
│ ├── nodefly-gcinfo@0.0.15
│ ├── nodefly-uvmon@0.0.7
│ ├── restler@2.0.1
│ ├── semver@2.2.1
│ ├── strong-cpu-profiler@0.1.0
│ ├─┬ timekit@0.1.8
│ │ └── bindings@1.1.1
│ ├─┬ uhura@0.1.0
│ │ ├─┬ connect@2.8.8
│ │ │ ├── buffer-crc32@0.2.1
│ │ │ ├── bytes@0.2.0
│ │ │ ├── cookie@0.1.0
│ │ │ ├── cookie-signature@1.0.1
│ │ │ ├── debug@0.7.4
│ │ │ ├── formidable@1.0.14
│ │ │ ├── fresh@0.2.0
│ │ │ ├── methods@0.0.1
│ │ │ ├── pause@0.0.1
│ │ │ ├── qs@0.6.5
│ │ │ ├─┬ send@0.1.4
│ │ │ │ ├── mime@1.2.11
│ │ │ │ └── range-parser@0.0.4
│ │ │ └── uid2@0.0.2
│ │ ├─┬ JSONStream@0.6.4
│ │ │ ├── jsonparse@0.0.5
│ │ │ └── through@2.2.7
│ │ ├── node-uuid@1.4.1
│ │ └── uid2@0.0.3
│ ├── underscore@1.5.2
│ └── zeparser@0.0.7
└─┬ strong-cluster-control@0.1.0
  ├─┬ commander@1.3.2
  │ └── keypress@0.1.0
  ├── debuglog@0.0.2
  └─┬ rc@0.3.2
    ├── deep-extend@0.2.6
    ├── ini@1.1.0
    └─┬ optimist@0.3.7
      └── wordwrap@0.0.2

[ritch]

Thanks again for the detailed bug report.

All errors from strong remoting should be caught and written to the response. This specific error should have a statusCode 400.

[arlaneenalra]

The crash is related, but there's another underlying issue that's a problem. I'm seeing the same crash even when I have an access token in the as described by the api docs. Here's a script to reproduce what I'm seeing in a freshly created application as described above:

#!/bin/sh

# create user
curl -X POST -H 'Content-Type: application/json' -d '{"email":"test@a.com", "password":"1234"}' localhost:3000/api/users

# login
RAW_TOKEN=`curl -X POST -H 'Content-Type: application/json' -d '{"email":"test@a.com", "password":"1234"}' localhost:3000/api/users/login`
TOKEN=`echo $RAW_TOKEN | sed -e 's/.*"id": "\(.*\)", "ttl.*/\1/'`

echo
echo "Token: $TOKEN"

curl -X POST "localhost:3000/api/users/logout?access_token=$TOKEN"

And here's the crash log:

csalch@Chriss-MacBook-Air ~/bug-test $ npm start

> bug-test@0.0.0 start /Users/csalch/bug-test
> node app.js

StrongOps not configured to monitor. Please refer to http://docs.strongloop.com/strong-agent for usage.
connect.multipart() will be removed in connect 3.0
visit https://github.com/senchalabs/connect/wiki/Connect-3.0 for alternatives
connect.limit() will be removed in connect 3.0
Browse your REST API at http://0.0.0.0:3000/explorer
LoopBack server listening @ http://0.0.0.0:3000/
POST /api/users 200 350ms - 157b
POST /api/users/login 200 329ms - 152b

/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:83
          throw new Error(name + ' is a required arg');
                ^
Error: access_token is a required arg
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:83:17
    at Array.forEach (native)
    at SharedMethod.invoke (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/shared-method.js:74:13)
    at HttpContext.invoke (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/http-context.js:221:12)
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/remote-objects.js:416:9
    at execStack (/Users/csalch/bug-test/node_modules/loopback/node_modules/strong-remoting/lib/remote-objects.js:287:7)
    at /Users/csalch/bug-test/node_modules/loopback/lib/application.js:177:13
    at /Users/csalch/bug-test/node_modules/loopback/lib/models/acl.js:445:17
    at /Users/csalch/bug-test/node_modules/loopback/lib/models/acl.js:408:19
    at /Users/csalch/bug-test/node_modules/loopback/node_modules/async/lib/async.js:229:13

npm ERR! bug-test@0.0.0 start: `node app.js`
npm ERR! Exit status 8
npm ERR!
npm ERR! Failed at the bug-test@0.0.0 start script.
npm ERR! This is most likely a problem with the bug-test package,
npm ERR! not with npm itself.
npm ERR! Tell the author that this fails on your system:
npm ERR!     node app.js
npm ERR! You can get their info via:
npm ERR!     npm owner ls bug-test
npm ERR! There is likely additional logging output above.
npm ERR! System Darwin 12.5.0
npm ERR! command "/usr/local/Cellar/node/0.10.24/bin/node" "/usr/local/bin/npm" "start"
npm ERR! cwd /Users/csalch/bug-test
npm ERR! node -v v0.10.24
npm ERR! npm -v 1.3.21
npm ERR! code ELIFECYCLE
npm ERR!
npm ERR! Additional logging details can be found in:
npm ERR!     /Users/csalch/bug-test/npm-debug.log
npm ERR! not ok code 0

And the output from the script:

csalch@Chriss-MacBook-Air ~ $ ./test.sh
{
  "password": "$2a$10$eIvT9M.iB/KBdk0jCiE1P.Maqi.N4iTiU.8ntL/o3lG9UMa6d35EG",
  "email": "test@a.com",
  "credentials": [],
  "challenges": [],
  "id": 1
}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   193  100   152  100    41    456    123 --:--:-- --:--:-- --:--:--   459

Token: yrsuBVX6xar52hgjjCxtN5u0CdkiKu78Mf5rlFYDSI3A6sFeAoalaSrNK3iBCtvC
curl: (52) Empty reply from server

[ritch]

I'm 99% sure the issue is that app.js is missing the loopback.token middleware. You can manually add this, and look for it to be added to the workspace (scaffolding) in the next version. This will require updating your version of slc to include in new projects. Below is the expected order of middleware:

app.use(loopback.cookieParser('secret'));
app.use(loopback.token({model: app.models.accessToken}));
app.use(apiPath, loopback.rest());
app.use(app.router);
app.use(loopback.urlNotFound());
app.use(loopback.errorHandler());
app.enableAuth();

[arlaneenalra]

That looks like it was the underlying issue for me. I had seen the token middleware in the loopback but nothing on how it was used/configured.

[ritch]

Here is a link to the docs.

http://apidocs.strongloop.com/loopback/#loopbacktokenoptions

Thinking of the bigger picture, the fact that you have to read those docs is what I'd consider a "UX bug". One we can fix fairly easily by ensuring the correct middleware are included in the scaffolded app. Thanks for pointing this issue out. Look for a fix shortly.

[arlaneenalra]

I think this is the first time I've seen those docs. A cursory look over the site leads me to docs.strongloop.com but I can't find a link to apidocs.strongloop.com It would be really nice to have an intuitive means of finding them.

[sam-github]

/to @crandmck, note doc site feedback at https://github.com/strongloop/loopback/issues/117#issuecomment-31409114

[ritch]

Fixed in loopback workspace 2.1.3 and strong remoting 1.1.6