Exception: Not Connected - Hookbox daemon stopped

[Andy K]

Hi all,

I am running hookbox 0.3.3 on Ubuntu 10.04.1. Currently, hookbox will
stop working once every 12~18 hours or so, with the number of
connected users around 15-30. There is no noticeable CPU load/RAM
consumption when this happens. My only solution now is to restart the
service.

Hookbox usage is in a chat room (overall users around 15-30), with
these options:
- admin enabled
- moderated_publish: false
- moderated_subscribe: false
- moderated_unsubscribe: false
- history size: 10
- reflective: 10
- presenceful: true
- polling mode simple, interval 10, to a backend written in PHP with
CodeIgniter


Here is the log just before the crash:

File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected
2011-03-08 13:33:31,364 - HookboxConn - WARNING - Unexpected error:
Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected
2011-03-08 13:33:31,395 - hookbox - INFO - Hookbox Daemon Stopped
Traceback (most recent call last):
File "/usr/local/bin/hookbox", line 9, in <module>
load_entry_point('hookbox==0.3.3', 'console_scripts', 'hookbox')()
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/start.py", line 33, in main
server.run().wait()
File "/usr/local/lib/python2.6/dist-packages/eventlet-0.9.13-
py2.6.egg/eventlet/event.py", line 116, in wait
return hubs.get_hub().switch()
File "/usr/local/lib/python2.6/dist-packages/eventlet-0.9.13-
py2.6.egg/eventlet/hubs/hub.py", line 172, in switch
return self.greenlet.switch()
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/server.py", line 110, in _run
rtjp_conn._sock.environ.get('REMOTE_ADDR', ''),
AttributeError: 'NoneType' object has no attribute 'environ'


Did anyone have the same problem? Is this because I'm not using the
right version of hookbox? Is there anything I can do to resolve this
issue?


Regards,
Andy.

[Andy K]

sorry, I forgot to add that "moderated" is set to true.

[Marc Hughes]

I randomly ran into the same problem the other day.  Out of the blue on my development machine I started getting those errors.  I restarted hookbox, and they went away.

The weird thing for me was, everything continued to function correctly.  Clients could still connect, publish, and receive messages.

-Marc

[Andy K]

Marc, thanks for the response.

Before the crash, the console is flooded with these warnings:

2011-03-11 10:25:39,314 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,315 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,315 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,315 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,316 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,316 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,316 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

2011-03-11 10:25:39,317 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-py2.6.egg/
hookbox/protocol.py", line 30, in send_frame
self._rtjp_conn.send_frame(*args, **kw)
File "/usr/local/lib/python2.6/dist-packages/rtjp_eventlet-0.3.2-
py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

These happens all the way since hookbox started running after 1 hour
or so until the crash happened. During this time, hookbox functions
normally.
What could be causing these warnings? Is this issue related to the
crash?

[marie_dk]

Friday morning we went into production with our new hookbox based
chat, and I am experiencing the same thing:

My log is filled with these:

2011-03-11 10:03:00,218 - HookboxConn - WARNING - Unexpected error:

Not Connected
Traceback (most recent call last):

File "/usr/local/lib/python2.6/site-packages/hookbox-0.3.4dev-
py2.6.egg/hookbox/protocol.py", line 31, in send_frame
self._rtjp_conn.send_frame(*args, **kw).wait()
File "/usr/local/lib/python2.6/site-packages/rtjp_eventlet-0.3.2-

py2.6.egg/rtjp_eventlet/server.py", line 143, in send_frame
raise Exception("Not Connected")
Exception: Not Connected

This 'Not Connected' error in the log already started around half an
hour after the first startup. Then it just continues to increase in
frequency. I am not seeing anything unusual in the log prior to the
first "Not Connected" error.

At the moment we only have something like 50-150 users per hookbox
instance and only one channel. All channel options are false/0 except
'moderated' which is true. I have not had an actual crash yet. I
became aware of the "Not Connected" error around 24 hours after
startup, and at that time the admin panel had stopped responding.

Users are not aware that the chat has been implemented, because we
have hidden it until we are sure that it will run smoothly during peak-
hours sunday evening. A javascript connects each user silently
whenever a page is loaded. But all these "Not Connected" errors does
not make me feel confident at all...

We have hookbox running on 5 servers, using REST calls to replicate
data between them. Could these 'Not Connected' errors have something
to do with the extensive use of REST calls?

/marie_dk

[Andy K]

Thanks for the response.

It took me some time to notice that the exceptions are being raised
exactly when frames are being sent (should've noticed earlier, it does
say "in send_frame" after all) . I am not sure whether extensive use
of REST calls could cause that, but I do have all the clients call
rest/get_channel_info everytime someone joins or leaves the channel.

Does any of your hookbox crash after a long streak of those warnings?

[marie_dk]

On 13 Mar., 03:59, Andy K <a...@airslash.net> wrote:
> Does any of your hookbox crash after a long streak of those warnings?

As long as log messages continue to be written in the logfile, hookbox
has not crashed, right?

I am in doubt because hookbox keep adding messages in the log, but the
admin panel does not respond and users are not connected. But both
interfaces are still listening.

Does anybody know how I catch this state, so that I can setup a script
and restart hookbox when this happens?

/marie_dk

[marie_dk]

Just another thought ... At my website, users are connected to hookbox
at all times. This means that users are constantly reconnecting when
the move around the website. Is that an extra stress factor for
hookbox, or is hookbox build to handle that kind of behavior?

/marie_dk

[marie_dk]

Sunday evening is the busiest time of the week at our website and I
must say that even though hookbox is very busy replicating data
between servers, I can hardly see any change in load, memory and cpu
usage.

I we could just get this "Not connected" issue fixed, everything would
be absolutely perfect.

/marie_dk

[Andy K]

Thanks marie_dk.

On mine, the one that stops hookbox (and return to bash) is this:

2011-03-08 13:33:31,395 - hookbox - INFO - Hookbox Daemon Stopped

Traceback (most recent call last):

File "/usr/local/bin/hookbox", line 9, in <module>
load_entry_point('hookbox==0.3.3', 'console_scripts', 'hookbox')
()
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-
py2.6.egg/
hookbox/start.py", line 33, in main
server.run().wait()
File "/usr/local/lib/python2.6/dist-packages/eventlet-0.9.13-
py2.6.egg/eventlet/event.py", line 116, in wait
return hubs.get_hub().switch()
File "/usr/local/lib/python2.6/dist-packages/eventlet-0.9.13-
py2.6.egg/eventlet/hubs/hub.py", line 172, in switch
return self.greenlet.switch()
File "/usr/local/lib/python2.6/dist-packages/hookbox-0.3.3-
py2.6.egg/
hookbox/server.py", line 110, in _run
rtjp_conn._sock.environ.get('REMOTE_ADDR', ''),
AttributeError: 'NoneType' object has no attribute 'environ'

It happens after those warnings, so I assume they are related somehow.
Reading your response I started to believe that is not the case. It
would be good if someone could explain the possible causes of these
two (the "Not Connected" warnings and the INFO - Hookbox Daemon
Stopped). Or perhaps some discussions or dev notes somewhere
containing infos that are not in the docs that I could read into.

[marie_dk]

On 13 Mar., 18:56, marie_dk <derri...@gmail.com> wrote:
> Does anybody know how I catch this state, so that I can setup a script
> and restart hookbox when this happens?
>

I found the answer to this question myself...

In our setup Apache and hookbox coexist on each webserver with
dedicated IPs, because we want both Apache and hookbox to listen on
port 80.

I am using Monit to monitor hookbox. I have configured Monit to
restart hookbox if there is no answer on the hookbox interface. I
could see that there was no answer from the admin interface, and also
hookbox did not accept connections, so I wondered why Monit did not
take any action.

It then dawned on me, that whenever the admin interface didn't answer,
Apache picked up the request. Apache was configured to answer all
requests to port 80 (Listen 80)... So I just had to change this to
12.34.56.78:80. Any http request to hookbox is now failing as it
should, and Monit is able to react on it and restart hookbox.

Monit is checking hookbox every 20 seconds. I hope this is frequent
enough to ensure the user experience is still okay.


/marie_dk

[Andy K]

Just an update:
Hookbox has been running fine for 5 days now. Well, the Warning flood
is still there, but at least it isn't crashing.
Things that's different from last week:
- history size set to 10 from 30.
- less simultaneously online active users. From 10-20 to 5-10 now :(

It makes me assume the error is related to load, however, I still
don't know for sure.