LearnBoost/socket.io — Issue #782: Sends duplicate message or drops messages when used under nginx proxy (w/ more than 1 instance + Redis Store)
Author: rajaraodv
Created: 2012-03-06 04:33:47+00:00
State: open

Sends duplicate message or drops messages when used under nginx proxy (w/ more than 1 instance + Redis Store).

I have a simple chat app that I am running on cloud foundry [https://github.com/rajaraodv/siochat] . This chat app sends "chatdata:0", "chatdata:1" etc until "chatdata:9" every second and bounces-back whatever is sent to the server.

Now, if i have only one instance of the node process running, I get all 0 to 9 chatdata messages. But, if I increase the instance to 2 w/ RedisStore, I start to see things going crazy. Most of the times, I only see 2 or 3 chatdata messages out of 10 being delivered!!!

Where there is only 1 instance of Node.js (w/ RedisStore):
PS: You can see all 0-9 chatdata messages are being received by the server and being bounced back..

debug: client authorized
info: handshake authorized 11705001511476393114
debug: setting request GET /socket.io/1/xhr-polling/11705001511476393114?t=1331008257603
debug: setting poll timeout
debug: client authorized for
debug: clearing poll timeout
debug: xhr-polling writing 1::
debug: set close timeout for client 11705001511476393114
on Connection: sessionId: 11705001511476393114 nId: 295581017 pid: 23380
debug: setting request GET /socket.io/1/xhr-polling/11705001511476393114?t=1331008257662
debug: setting poll timeout
debug: discarding transport
debug: cleared close timeout for client 11705001511476393114
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:0"]}
nodeId 295581017 *** chatdata:0
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:1"]}
nodeId 295581017 *** chatdata:1
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:2"]}
nodeId 295581017 *** chatdata:2
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:3"]}
nodeId 295581017 *** chatdata:3
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:4"]}
nodeId 295581017 *** chatdata:4
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:5"]}
nodeId 295581017 *** chatdata:5
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:6"]}
nodeId 295581017 *** chatdata:6
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:7"]}
nodeId 295581017 *** chatdata:7
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:8"]}
nodeId 295581017 *** chatdata:8
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:9"]}
nodeId 295581017 *** chatdata:9
debug: clearing poll timeout

When there are 2 instances of node process (w/ Redis Store)

Here is the log when there are 2 instances of node process - Notice how "xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:0"]}" is displayed for chatdata:0 but is NOT displayed for chatdata:1, chatdata:2. Again it
is shown for chat data:3, chatdata:4 but several in between are skipped.

debug: client authorized for
debug: clearing poll timeout
debug: xhr-polling writing 1::
debug: set close timeout for client 908813144294196465
on Connection: sessionId: 908813144294196465 nId: 130676681 pid: 7443
debug: setting request GET /socket.io/1/xhr-polling/908813144294196465?t=1331007796335
debug: setting poll timeout
debug: discarding transport
debug: cleared close timeout for client 908813144294196465
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:0"]}
nodeId 130676681 *** chatdata:0
nodeId 130676681 *** chatdata:1
nodeId 130676681 *** chatdata:2
debug: xhr-polling received data packet 5:::{"name":"sendchat","args":["chatdata:3"]}
nodeId 130676681 *** chatdata:3
nodeId 130676681 *** chatdata:4

debug: clearing poll timeout
debug: xhr-polling writing 8::
debug: set close timeout for client 908813144294196465
debug: xhr-polling closed due to exceeded duration
debug: setting request GET /socket.io/1/xhr-polling/908813144294196465?t=1331007816398
debug: setting poll timeout