Server crash with Can't set headers after they are sent

[kirbyzjj]

The http api server often crash by the latest release. Please see log below. Thanks.

debug: Session expired. Jid: 13651989110@test.cn
error: Session went offline.
error: uncaughtException: Can't set headers after they are sent. date=Tue Jan 06 2015 19:59:23 GMT+0800 (CST), pid=7526, uid=1000, gid=1000, cwd=/home/mctalk/buddycloud-http-api, execPath=/usr/bin/nodejs, version=v0.10.25, argv=[node, /home/mctalk/buddycloud-http-api/server.js], rss=69156864, heapTotal=60263680, heapUsed=32368696, loadavg=[0.00439453125, 0.021484375, 0.04541015625], uptime=610535.476282095, trace=[column=11, file=http.js, function=ServerResponse.OutgoingMessage.setHeader, line=691, method=OutgoingMessage.setHeader, native=false, column=22, file=/home/mctalk/buddycloud-http-api/node_modules/express/node_modules/connect/lib/patch.js, function=ServerResponse.res.setHeader, line=63, method=res.setHeader, native=false, column=10, file=/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js, function=ServerResponse.res.set.res.header, line=527, method=res.set.res.header, native=false, column=15, file=/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js, function=ServerResponse.res.contentType.res.type, line=396, method=res.contentType.res.type, native=false, column=40, file=/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js, function=ServerResponse.res.send, line=104, method=res.send, native=false, column=17, file=/home/mctalk/buddycloud-http-api/src/util/session.js, function=, line=165, method=null, native=false, column=17, file=events.js, function=Client.EventEmitter.emit, line=92, method=EventEmitter.emit, native=false, column=14, file=/home/mctalk/buddycloud-http-api/node_modules/node-xmpp-client/index.js, function=, line=128, method=null, native=false, column=17, file=events.js, function=Client.EventEmitter.emit, line=92, method=EventEmitter.emit, native=false, column=14, file=/home/mctalk/buddycloud-http-api/node_modules/node-xmpp-client/lib/session.js, function=, line=146, method=null, native=false], stack=[Error: Can't set headers after they are sent., at ServerResponse.OutgoingMessage.setHeader (http.js:691:11), at ServerResponse.res.setHeader (/home/mctalk/buddycloud-http-api/node_modules/express/node_modules/connect/lib/patch.js:63:22), at ServerResponse.res.set.res.header (/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js:527:10), at ServerResponse.res.contentType.res.type (/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js:396:15), at ServerResponse.res.send (/home/mctalk/buddycloud-http-api/node_modules/express/lib/response.js:104:40), at Client. (/home/mctalk/buddycloud-http-api/src/util/session.js:165:17), at Client.EventEmitter.emit (events.js:92:17), at Client. (/home/mctalk/buddycloud-http-api/node_modules/node-xmpp-client/index.js:128:14), at Client.EventEmitter.emit (events.js:92:17), at Connection. (/home/mctalk/buddycloud-http-api/node_modules/node-xmpp-client/lib/session.js:146:14)]

[abmargb]

Hi @kirbyzjj, thanks for the report. I'm now trying to reproduce this locally without much success. Are you on the latest commit from master or using a deb file from downloads.buddycloud.com?
Which endpoints were you accessing before the crash?

[kirbyzjj]

I use the latest commit from mater. the scenario is

1. I use my android client login my server, .everything is ok,
2. Make android client to the background, Uninstall the client directly
3. Install the client again and login, for this time the crash maybe happen.

[lloydwatkin]

@abmargb I think this may happen if the media server isn't running. I never saw crashes but I would see that error.

[kirbyzjj]

I catch more log before crash. Wish it will be useful. See below

the first:
debug: IN xmpp: 0Auto awayaway
debug: IN xmpp: 0Auto awayaway
debug: Session expired. Jid: 18917611535@mctalk.cn
error: Session went offline.

second:
debug: IN xmpp: 0Auto awayaway
debug: IN xmpp: 0Auto awayaway
debug: Session expired. Jid: 18917611535@mctalk.cn
error: Session went offline.

[kirbyzjj]

@abmargb Sorry, It seems I can't post full log here, I send the log to your gmail. .

[kirbyzjj]

@abmargb I tried many times and wish find crash law

a. User login by webclient.
b. Do not operate webclient
c. The server maybe crash when output log by debug:Session expired. Jid:xxx

BY the way I find I change default sessionExpirationTime from 600 to 120 will speed the server crash.

[lloydwatkin]

@abmargb clearly something is timing out and returning after the request is sent (and I'm sure you know that).

One solution is to go through every response send or we could add some middleware to override things, something like:

function(req, res, next) {
  var originalSend = res.send
  res.send = function() {
    if (this.headersSent()) return
    originalSend.apply(this, arguments)
  }
}

[abmargb]

Thanks @kirbyzjj and @lloydwatkin. I wonder if it happens when a request for media, for example, hangs until the session expires, and then two different execution lines try to reply to the same request.
@lloydwatkin, sounds like a good idea. I'm AFK for the next 3 days, but I'll try and fix it when I'm back.
Regardless of the root cause, do you think of a good way to avoid the whole process to crash?
I once tried https://github.com/baryshev/connect-domain without much success.

[lloydwatkin]

@abmargb good? No, however...

process.onUncaughtException(function() { ...stuff... })

[josemolmomillan]

Sorry, is it there some related work or guidance about this issue? we are having the same issue constantly, and we need to restart our container.