Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

again about highload #20

Open
byaka opened this issue Mar 7, 2015 · 28 comments
Open

again about highload #20

byaka opened this issue Mar 7, 2015 · 28 comments

Comments

@byaka
Copy link

byaka commented Mar 7, 2015

Sorry, but i again...

Simple server (dispathers do only adding and editing global dict, no mysql or some IO or any special).
About 40-50 connections per time.
PooledJSONRPCServer(min=10, max=100) as server.

After 3-4 hours server don't response to connection.
In log no any strange.

I have no ideas how to catch problem..
Now i add logging to every dispatcher (in begin and in end of function). But i don't think this help to locate problem.

@byaka
Copy link
Author

byaka commented Mar 7, 2015

After it happened, i have ~15 thread (more then min pool for requests) without CPU usage. But Main Thread load one CPU's core to 100%. No memory leak.

@byaka
Copy link
Author

byaka commented Mar 7, 2015

Test give no result. All dispatchers ended correctly (for every i see start and end section in log every time it called)

@tcalmant
Copy link
Owner

tcalmant commented Mar 9, 2015

Hi,

Could you remind me the exact version of Python and of the operating system you use ?

About the 5 threads still alive, it might be their "grace time": the threads are stopped 1 minute after their last operation.
Due to the server not responding, it could also be caused by a dead lock in the ThreadPool (but I can't see one for now).

Also, the 100% CPU usage on the main thread might indicate that the socket reading process has a problem. Maybe you should add logs to the standard library file socketserver.py, in the BaseServer.serve_forever method (around line 220); to see if their is a 0.5 seconds pause between loop iterations.

If this doesn't show up the problem, maybe it would be interesting to use the threads command of my other project, the iPOPO framework. It would list the current stack trace of all running threads.

@byaka
Copy link
Author

byaka commented Mar 9, 2015

Python 2.7.6
Debian 6

i check all my code again, no any thread lock() or any like this.
Now i'm want to try one idea. If no result, i'll try your solution (with adding a log to socketserver.py).

One big strange thing: in another physical server i have another server, where i have strange IO, mysql and another bad things in dispatchers. And i have medium load (near 10-30 connections). But all connections created by my python clients (from another physical servers), not by browsers. And now this server has uptime 4 days and no any issues.

@byaka
Copy link
Author

byaka commented Mar 9, 2015

It so strange..

import SocketServer
...
class ThreadedJSONRPCServer(SocketServer.ThreadingMixIn, SimpleJSONRPCServer):
   pass
...
server=ThreadedJSONRPCServer(("0.0.0.0", 8099), requestHandler=myRequestHandler, logRequests=False)
server.register_instance(mySharedMethods())
server.serve_forever()

uptime 6 hours, no issues

@tcalmant
Copy link
Owner

By now, I can only think about concurrency problems...

If the problem only comes from browsers, you should log the user agent in SimpleJSONRPCServer.py",SimpleJSONRPCRequestHandler.do_POST()``, around line 400.

You should log to a file the content of self.headers["user-agent"] at the beginning and at the end of the method (with a timestamp).
Then, you'll be able to count the number of beginning/ending log lines with grep and wc -l: if there is a difference, you'll be able to find if there is a bad user agent, i.e. a browser which causes the error.

@byaka
Copy link
Author

byaka commented Mar 10, 2015

18 hours and no issues..
It's really strange...
what diffrence between PooledJSONRPCServer() and class ThreadedJSONRPCServer(SocketServer.ThreadingMixIn, SimpleJSONRPCServer)?

@tcalmant
Copy link
Owner

The PooledJSONRPCServer uses a thread pool, which limits the maximum number of threads active at a given time. This allows you to control the resources consumed by your server. It is specific to this version of the jsonrpclib library.
The ThreadedJSONRPCServer starts a thread for every client request, which means that under high load, you'll drown your server with a high number of threads to handle.

@byaka
Copy link
Author

byaka commented Mar 10, 2015

Server with ThreadedJSONRPCServer still work, and it's good.
BUT number of threads now more then 100. And ofcourse i have not so many real connections now.
I'm think it's some problem, that don't give threads be ended. And i'm think same problem block PooledJSONRPCServer after some time.

Is it possible to get all created threads, see when it last used and stop old? It will be a temporary solution for server with ThreadedJSONRPCServer.

@tcalmant
Copy link
Owner

I've tried some other tests, but I can't reproduce your situation.

To debug threads, I use the threads and thread <tid> commands of the iPOPO framework.

  1. Install the iPOPO framework: pip install iPOPO
  2. Copy the script below, and add it the missing classes (request handler and methods)
  3. Run it: it will show you a command prompt
  4. Type threads to list the active threads with their ID and their current code position
  5. Type thread <id> (give the ID, not the name) to print the whole stack trace of the given thread.
# Herald constants
from jsonrpclib.SimpleJSONRPCServer import PooledJSONRPCServer

# Pelix
import pelix.framework

# Standard library
import logging
import threading

# ------------------------------------------------------------------------------


def main():
    """
    Runs the framework

    :param http_port: HTTP port to listen to
    """
    # Create the framework
    framework = pelix.framework.create_framework(
        ('pelix.ipopo.core',
         'pelix.ipopo.waiting',
         'pelix.shell.core',
         'pelix.shell.ipopo',
         'pelix.shell.console'))

    # Start the framework
    print("Starting framework")
    framework.start()

    # Start the server
    server = PooledJSONRPCServer(("0.0.0.0", 8099),
                                 requestHandler=myRequestHandler,
                                 logRequests=False)
    server.register_instance(mySharedMethods())

    # Run it in a separate thread
    print("Starting server...")
    thread = threading.Thread(target=server.serve_forever,
                              name="JSON-RPC Server Thread")
    thread.daemon = True
    thread.start()

    # Start the framework and wait for it to stop
    framework.wait_for_stop()

    print("Stopping server...")
    server.server_close()
    thread.join(1)
    print("The End.")

# ------------------------------------------------------------------------------

if __name__ == "__main__":
    # Configure the logging package
    logging.basicConfig(level=logging.DEBUG)

    # Run the framework
    main()

@byaka
Copy link
Author

byaka commented Mar 16, 2015

Thx for response. I'm start new test.

@byaka
Copy link
Author

byaka commented Mar 16, 2015

OK, i'm ended test (process now eat 100% CPU and don't response over rpc).
OUTPUT for [threads]

Thread ID: -1436583056 - Name: PooledJSONRPCServer-30649
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1359127696 - Name: PooledJSONRPCServer-23080
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1325556880 - Name: PooledJSONRPCServer-21541
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1317164176 - Name: PooledJSONRPCServer-5529
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1301312656 - Name: PooledJSONRPCServer-13870
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1290798224 - Name: PooledJSONRPCServer-29393
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1263535248 - Name: PooledJSONRPCServer-23132
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1242563728 - Name: PooledJSONRPCServer-28809
Line:
  File "/usr/lib/python2.6/socket.py", line 444, in readline
    data = self._sock.recv(self._rbufsize)

Thread ID: -1233081488 - Name: JSON-RPC Server Thread
Line:
  File "/usr/lib/python2.6/socket.py", line 197, in accept
    sock, addr = self._sock.accept()

Thread ID: -1224660112 - Name: Pelix-Shell-TextConsole
Line:
  File "/usr/local/lib/python2.6/dist-packages/pelix/shell/core.py", line 1133, in threads_list
    for line in traceback.format_stack(stack, 1))

Thread ID: -1220921664 - Name: MainThread
Line:
  File "/usr/lib/python2.6/threading.py", line 239, in wait
    waiter.acquire()

It's so strange. 8 threads waiting for response, and one WAITING for connections! why he wait?i'm don't understand. About 8 "stucked" threads - i'm think they GHOSTS (in ThreadedJSONRPCServer() i'm see them as freezed. For example now one of my servers, launched via ThreadedJSONRPCServer() has 150 freezed threads, but working and response to requests). OUTPUT for [thread] one of them.

Thread ID: -1242563728 - Name: PooledJSONRPCServer-28809
Stack trace:
  File "/usr/lib/python2.6/threading.py", line 504, in Thread::__bootstrap
    - self = <Thread(PooledJSONRPCServer-28809, started daemon -1242563728)>

         # reported.  Also, we only suppress them for daemonic threads;
         # if a non-daemonic encounters this, something else is wrong.
         try:
      >>     self.__bootstrap_inner()
         except:
             if self.__daemonic and _sys is None:
                 return

  File "/usr/lib/python2.6/threading.py", line 532, in Thread::__bootstrap_inner
    - self = <Thread(PooledJSONRPCServer-28809, started daemon -1242563728)>

             _sys.setprofile(_profile_hook)

         try:
      >>     self.run()
         except SystemExit:
             if __debug__:
                 self._note("%s.__bootstrap(): raised SystemExit", self)

  File "/usr/lib/python2.6/threading.py", line 484, in Thread::run
    - self = <Thread(PooledJSONRPCServer-28809, started daemon -1242563728)>

         def run(self):
             try:
                 if self.__target:
      >>             self.__target(*self.__args, **self.__kwargs)
             finally:
                 # Avoid a refcycle if the thread is running a function with
                 # an argument that has a member that points to the thread.

  File "/usr/local/lib/python2.6/dist-packages/jsonrpclib/threadpool.py", line 469, in ThreadPool::__run
    - self = <jsonrpclib.threadpool.ThreadPool object at 0x9ed380c>
  File "/usr/local/lib/python2.6/dist-packages/jsonrpclib/threadpool.py", line 191, in FutureResult::execute
    - self = <jsonrpclib.threadpool.FutureResult object at 0xc00822c>
    - method = <bound method PooledJSONRPCServer.process_request_thread of <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>>
    - args = (<socket._socketobject object at 0xc00217c>, ('83.149.35.135', 22327))
    - kwargs = {}
  File "/usr/lib/python2.6/SocketServer.py", line 560, in PooledJSONRPCServer::process_request_thread
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xc00217c>
    - client_address = ('83.149.35.135', 22327)


          try:
      >>     self.finish_request(request, client_address)
             self.close_request(request)
         except:
             self.handle_error(request, client_address)

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xc00217c>
    - client_address = ('83.149.35.135', 22327)


         def finish_request(self, request, client_address):
             """Finish one request by instantiating RequestHandlerClass."""
      >>     self.RequestHandlerClass(request, client_address, self)

         def close_request(self, request):
             """Called to clean up an individual request."""

  File "/usr/lib/python2.6/SocketServer.py", line 617, in instance::__init__
    - self = <__main__.myRequestHandler instance at 0xc3d4e4c>
    - request = <socket._socketobject object at 0xc00217c>
    - client_address = ('83.149.35.135', 22327)
    - server = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>

         self.server = server
         try:
             self.setup()
      >>     self.handle()
             self.finish()
         finally:
             sys.exc_traceback = None    # Help garbage collection

  File "/usr/lib/python2.6/BaseHTTPServer.py", line 329, in instance::handle
    - self = <__main__.myRequestHandler instance at 0xc3d4e4c>

         """Handle multiple requests if necessary."""
         self.close_connection = 1

      >> self.handle_one_request()
         while not self.close_connection:
             self.handle_one_request()


  File "/usr/lib/python2.6/BaseHTTPServer.py", line 312, in instance::handle_one_request
    - self = <__main__.myRequestHandler instance at 0xc3d4e4c>

         commands such as GET and POST.

      >> self.raw_requestline = self.rfile.readline()
         if not self.raw_requestline:
             self.close_connection = 1
             return

  File "/usr/lib/python2.6/socket.py", line 444, in _fileobject::readline
    - self = <socket._fileobject object at 0x9edc72c>
    - size = -1

         self._rbuf = StringIO()  # reset _rbuf.  we consume it via buf.
         while True:
             try:
      >>         data = self._sock.recv(self._rbufsize)
             except error, e:
                 if e.args[0] == EINTR:
                     continue

forever loop when error of reading?

and OUTPUT for [thread] WAITING for connections.

Stack trace:
  File "/usr/lib/python2.6/threading.py", line 504, in Thread::__bootstrap
    - self = <Thread(JSON-RPC Server Thread, started daemon -1233081488)>

         # reported.  Also, we only suppress them for daemonic threads;
         # if a non-daemonic encounters this, something else is wrong.
         try:
      >>     self.__bootstrap_inner()
         except:
             if self.__daemonic and _sys is None:
                 return

  File "/usr/lib/python2.6/threading.py", line 532, in Thread::__bootstrap_inner
    - self = <Thread(JSON-RPC Server Thread, started daemon -1233081488)>

             _sys.setprofile(_profile_hook)

         try:
      >>     self.run()
         except SystemExit:
             if __debug__:
                 self._note("%s.__bootstrap(): raised SystemExit", self)

  File "/usr/lib/python2.6/threading.py", line 484, in Thread::run
    - self = <Thread(JSON-RPC Server Thread, started daemon -1233081488)>

         def run(self):
             try:
                 if self.__target:
      >>             self.__target(*self.__args, **self.__kwargs)
             finally:
                 # Avoid a refcycle if the thread is running a function with
                 # an argument that has a member that points to the thread.

  File "/usr/lib/python2.6/SocketServer.py", line 226, in PooledJSONRPCServer::serve_forever
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - poll_interval = 0.5

                 # shutdown request and wastes cpu at all other times.
                 r, w, e = select.select([self], [], [], poll_interval)
                 if self in r:
      >>             self._handle_request_noblock()
         finally:
             self.__shutdown_request = False
             self.__is_shut_down.set()

  File "/usr/lib/python2.6/SocketServer.py", line 280, in PooledJSONRPCServer::_handle_request_noblock
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>

         try:
             request, client_address = self.get_request()
         except socket.error:
      >>     return
         if self.verify_request(request, client_address):
             try:
                 self.process_request(request, client_address)

  File "/usr/lib/python2.6/SocketServer.py", line 446, in PooledJSONRPCServer::get_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>

             May be overridden.

      >>     return self.socket.accept()

         def close_request(self, request):
             """Called to clean up an individual request."""

  File "/usr/lib/python2.6/socket.py", line 197, in _socketobject::accept
    - self = <socket._socketobject object at 0x9e970d4>

         close.__doc__ = _realsocket.close.__doc__

         def accept(self):
      >>     sock, addr = self._sock.accept()
             return _socketobject(_sock=sock), addr
         accept.__doc__ = _realsocket.accept.__doc__

I'm don't understand this output. Not enough deep of stack trace? I can't see jsonrpclib's code, only standart python modules.

I don't kill process. If u want to check something else, text me.

@byaka
Copy link
Author

byaka commented Mar 16, 2015

image
screenshot from htop

@tcalmant
Copy link
Owner

It's OK if you don't see jsonrpclib methods: it's only the stack trace of the threads, so you see where the thread goes along, which is the standard library code jsonrpclib uses.

The threads waiting for a connection are OK, as they are "paused" waiting for the result of accept().

The ghost threads are apparently looping in the readline() method, which might mean that they are trying to read a closed socket.
But as we can see in the logs, the loop seems to come before the protection that should stop the calls:

>> self.raw_requestline = self.rfile.readline()
     if not self.raw_requestline:
         self.close_connection = 1
         return

In the beginning of the thread trace, you can see the arguments given to the thread:

 File "/usr/local/lib/python2.6/dist-packages/jsonrpclib/threadpool.py", line 191, in FutureResult::execute
    - self = <jsonrpclib.threadpool.FutureResult object at 0xc00822c>
    - method = <bound method PooledJSONRPCServer.process_request_thread of <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>>
    - args = (<socket._socketobject object at 0xc00217c>, ('83.149.35.135', 22327))
    - kwargs = {}

Could you send me this information for some of the ghost threads ?
If the threads share the same socket object, it could be the cause of the trouble.

@byaka
Copy link
Author

byaka commented Mar 16, 2015

Ofcourse :)

[thread -1436583056]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xc508a3c>
    - client_address = ('94.180.107.4', 64639)

[thread -1359127696]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xbbf9684>
    - client_address = ('92.101.111.156', 52146)

[thread -1325556880]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xb7d1454>
    - client_address = ('109.188.125.12', 21899)

[thread -1317164176]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xa544d14>
    - client_address = ('195.229.60.225', 62050)

[thread -1301312656]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xb0574fc>
    - client_address = ('79.141.237.50', 6321)

[thread -1290798224]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xc462b54>
    - client_address = ('94.180.107.4', 64523)

[thread -1263535248]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xbb271b4>
    - client_address = ('79.141.237.50', 61481)

[thread -1242563728]

  File "/usr/lib/python2.6/SocketServer.py", line 322, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x9e1ac0c>
    - request = <socket._socketobject object at 0xc00217c>
    - client_address = ('83.149.35.135', 22327)

as i see, all sockets unique..

@byaka
Copy link
Author

byaka commented Mar 16, 2015

i also checked SELF variable in

File "/usr/lib/python2.6/socket.py", line 444, in _fileobject::readline

they also unique

@tcalmant
Copy link
Owner

I hadn't notice you are using Python 2.6.
Could you try with Python 2.7 ?

@byaka
Copy link
Author

byaka commented Mar 16, 2015

i'm tried (some of my servers has 2.7, some 2.6). No different..
If u want to see trace in 2.7, i can start new test in other server. But i think we see no difference. All symptoms in other versions of python same.

@tcalmant
Copy link
Owner

It would be nice to have the stack trace of a single ghost thread on Python 2.7, so that I could have the right line numbers in the standard library files :)

@byaka
Copy link
Author

byaka commented Mar 16, 2015

No problems.
I started new test. Waiting...

@byaka
Copy link
Author

byaka commented Mar 16, 2015

Test ended.
OUTPUT [threads]

Thread ID: 140115215312640 - Name: JSON-RPC Server Thread
Line:
  File "/usr/lib/python2.7/socket.py", line 202, in accept

Thread ID: 140115223705344 - Name: Pelix-Shell-TextConsole
Line:
  File "/usr/local/lib/python2.7/dist-packages/pelix/shell/core.py", line 1133, in threads_list

Thread ID: 140115289155328 - Name: MainThread
Line:
  File "/usr/lib/python2.7/threading.py", line 339, in wait

strange... No ghosts, only thread, waiting for accept. And again 100% CPU load.

OUTPUT [thread] for this thread. I have two difference outputs...

Stack trace:
  File "/usr/lib/python2.7/threading.py", line 783, in Thread::__bootstrap
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/threading.py", line 810, in Thread::__bootstrap_inner
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/threading.py", line 763, in Thread::run
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/SocketServer.py", line 236, in PooledJSONRPCServer::serve_forever
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x238f790>
    - poll_interval = 0.5
  File "/usr/lib/python2.7/SocketServer.py", line 155, in _eintr_retry
    - func = <built-in function select>
    - *args = ([<jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x238f790>], [], [], 0.5)
Stack trace:
  File "/usr/lib/python2.7/threading.py", line 783, in Thread::__bootstrap
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/threading.py", line 810, in Thread::__bootstrap_inner
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/threading.py", line 763, in Thread::run
    - self = <Thread(JSON-RPC Server Thread, started daemon 140115215312640)>
  File "/usr/lib/python2.7/SocketServer.py", line 238, in PooledJSONRPCServer::serve_forever
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x238f790>
    - poll_interval = 0.5
  File "/usr/lib/python2.7/SocketServer.py", line 292, in PooledJSONRPCServer::_handle_request_noblock
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x238f790>
  File "/usr/lib/python2.7/SocketServer.py", line 463, in PooledJSONRPCServer::get_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x238f790>
  File "/usr/lib/python2.7/socket.py", line 202, in _socketobject::accept
    - self = <socket._socketobject object at 0x2411b40>

@tcalmant
Copy link
Owner

This is a quite strange behaviour...

  • Maybe you could modify the accept method in socket.py, line 202; to add some logs (even catch exceptions, log them and raise them again).
  • Do you use signals in your application ? It could the EINTR "error", which implies restarting the accept() call
  • Do you have any firewall (other than iptables) or HIP software on your machine ? It could cut off the connection, without closing it.

@byaka
Copy link
Author

byaka commented Mar 17, 2015

  1. Yes, no problems.
  2. No.
  3. No firewall on all servers. i checked.
    I restart last test. Last time we don't have ghosts. I'm think this is because this time problem happened before any ghost.

@byaka
Copy link
Author

byaka commented Mar 17, 2015

OUTPUT for ghost in python 2.7

Stack trace:
  File "/usr/lib/python2.7/threading.py", line 783, in Thread::__bootstrap
    - self = <Thread(PooledJSONRPCServer-6707, started daemon 140298647172864)>
  File "/usr/lib/python2.7/threading.py", line 810, in Thread::__bootstrap_inner
    - self = <Thread(PooledJSONRPCServer-6707, started daemon 140298647172864)>
  File "/usr/lib/python2.7/threading.py", line 763, in Thread::run
    - self = <Thread(PooledJSONRPCServer-6707, started daemon 140298647172864)>
  File "/usr/local/lib/python2.7/dist-packages/jsonrpclib/threadpool.py", line 469, in ThreadPool::__run
    - self = <jsonrpclib.threadpool.ThreadPool object at 0x1c69450>
  File "/usr/local/lib/python2.7/dist-packages/jsonrpclib/threadpool.py", line 191, in FutureResult::execute
    - self = <jsonrpclib.threadpool.FutureResult object at 0x7f99780f0410>
    - method = <bound method PooledJSONRPCServer.process_request_thread of <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x1b7a790>>
    - args = (<socket._socketobject object at 0x1c9b1a0>, ('83.220.239.188', 39602))
    - kwargs = {}
  File "/usr/lib/python2.7/SocketServer.py", line 593, in PooledJSONRPCServer::process_request_thread
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x1b7a790>
    - request = <socket._socketobject object at 0x1c9b1a0>
    - client_address = ('83.220.239.188', 39602)


         try:
      >>     self.finish_request(request, client_address)
             self.shutdown_request(request)
         except:
             self.handle_error(request, client_address)

  File "/usr/lib/python2.7/SocketServer.py", line 334, in PooledJSONRPCServer::finish_request
    - self = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x1b7a790>
    - request = <socket._socketobject object at 0x1c9b1a0>
    - client_address = ('83.220.239.188', 39602)


         def finish_request(self, request, client_address):
             """Finish one request by instantiating RequestHandlerClass."""
      >>     self.RequestHandlerClass(request, client_address, self)

         def shutdown_request(self, request):
             """Called to shutdown and close an individual request."""

  File "/usr/lib/python2.7/SocketServer.py", line 649, in instance::__init__
    - self = <__main__.myRequestHandler instance at 0x7f9978173098>
    - request = <socket._socketobject object at 0x1c9b1a0>
    - client_address = ('83.220.239.188', 39602)
    - server = <jsonrpclib.SimpleJSONRPCServer.PooledJSONRPCServer object at 0x1b7a790>

         self.server = server
         self.setup()
         try:
      >>     self.handle()
         finally:
             self.finish()


  File "/usr/lib/python2.7/BaseHTTPServer.py", line 340, in instance::handle
    - self = <__main__.myRequestHandler instance at 0x7f9978173098>

         """Handle multiple requests if necessary."""
         self.close_connection = 1

      >> self.handle_one_request()
         while not self.close_connection:
             self.handle_one_request()


  File "/usr/lib/python2.7/BaseHTTPServer.py", line 310, in instance::handle_one_request
    - self = <__main__.myRequestHandler instance at 0x7f9978173098>


         try:
      >>     self.raw_requestline = self.rfile.readline(65537)
             if len(self.raw_requestline) > 65536:
                 self.requestline = ''
                 self.request_version = ''

  File "/usr/lib/python2.7/socket.py", line 476, in _fileobject::readline
    - self = <socket._fileobject object at 0x1c7cdd0>
    - size = 65537

         self._rbuf = StringIO()  # reset _rbuf.  we consume it via buf.
         while True:
             try:
      >>         data = self._sock.recv(self._rbufsize)
             except error, e:
                 if e.args[0] == EINTR:
                     continue

@tcalmant
Copy link
Owner

I have absolutely no idea why it consumes so much CPU.

  • We've seen that no socket is shared between threads
  • The standard library code checks for empty results of recv(), to stop loops if the socket is closed
  • Exceptions while reading sockets are not silently passed: we should see a trace if an exception occurred
  • You don't use signals, so a loop due to multiple interruptions (EINTR) can't be the cause (and the standard library as a special protection for that case)

So.. I have no clue :(

@byaka
Copy link
Author

byaka commented Mar 18, 2015

Thx for try..

@tcalmant
Copy link
Owner

Last thing to try: could you run your code on virtual (or real) machines with different OSes ?
Like Ubuntu, Fedora, ... or even with the Windows 10 preview or a clean Debian install ?

Maybe it's a system configuration or a Python system-specific version issue...

@byaka
Copy link
Author

byaka commented Mar 19, 2015

It's so difficult. I can't install vm to servers. And my own machine has no white ip..
I'll think how to do this...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants