tcalmant / jsonrpclib

A Python (2 & 3) JSON-RPC over HTTP that mirrors the syntax of xmlrpclib (aka jsonrpclib-pelix)
https://jsonrpclib-pelix.readthedocs.io/
Apache License 2.0
54 stars 24 forks source link

Huge memory leak on high load #13

Closed byaka closed 9 years ago

byaka commented 9 years ago

Source of server:

import sys, re, os, random, math, imp, threading, gc, datetime, time
import jsonrpclib
from jsonrpclib.SimpleJSONRPCServer import SimpleJSONRPCServer
from jsonrpclib.SimpleJSONRPCServer import SimpleJSONRPCRequestHandler
import SocketServer
import logging

class ThreadedJSONRPCServer(SocketServer.ThreadingMixIn, SimpleJSONRPCServer):
   pass

class myRequestHandler(SimpleJSONRPCRequestHandler):
    rpc_paths=('/test')
    clientIp=None

    def do_OPTIONS(self):
        self.send_response(200)
        self.end_headers()

    def do_GET(self):
        self.send_response(200)
        self.end_headers()

    def do_POST(self):
        # global clientIp
        # clientIp, clientPort=self.client_address
        SimpleJSONRPCRequestHandler.do_POST(self)

    def end_headers(self):
        self.send_header('Access-Control-Allow-Headers', 'Origin, Authorization, X-Requested-With, Content-Type, Accept')
        self.send_header('Access-Control-Allow-Origin', '*')
        self.send_header('Access-Control-Max-Age', '0')
        self.send_header('Access-Control-Allow-Methods', 'GET, PUT, POST, DELETE, OPTIONS')
        SimpleJSONRPCRequestHandler.end_headers(self)

class mySharedMethods:
    def test(self):
        # this method do nothing!
        return time.sleep(2) # without sleep i'm need waiting more time before problem happened

if __name__=='__main__':
    print 'Running Api...'
    logging.getLogger('jsonrpclib').setLevel(logging.DEBUG)
    server=ThreadedJSONRPCServer(("0.0.0.0", 8099), requestHandler=myRequestHandler,logRequests=False)
    server.register_instance(mySharedMethods())
    server.serve_forever()

on this server i'm give high load (near 5-15 connections per second). Because i'm use ThreadedJSONRPCServer(), for every incoming connection creating new thread. In htop with tree view i'm see them very well. Threads added and removed, all work well. Every thread eat ~0.1% of cpu.

BUT.. after 10-60 minutes one(sometimes two or three) threads not removed. I'm name them 'Ghosts'. Each Ghost eat near 50% cpu. And it never stop this and it never removed. After first Ghost happened, process start eating memory. After 2-3 hours process takes 6-7 gigabytes of RAM. Peak is 22 gigabytes.

I'm think i'm do something wrong but i can't understand what...

p.s. If i'm use SimpleJSONRPCServer() instead ThreadedJSONRPCServer() all work so sloooow. And so many timeouted connections...

tcalmant commented 9 years ago

I've made a quick load test from your server code, and it works well on my computer (Ubuntu 14.04, Python 2.7.6). The client spawns a new thread every 50ms (so ~20 clients/second): the client uses from 10% (after 5min) to 40% (after 60min) of CPU while the server uses less 5% (according to htop), and memory usage seems to be stable, even after 60 minutes.

Although, your problem might come from unreleased connections: are you sure your ServerProxy objects are cleaned up correctly after use ?

About SimpleJSONRPCServer vs. ThreadedJSONRPCServer: that is logical because in SimpleJSONRPCServer, requests are treated one after one : clients are blocked until the server handles them, which might be after their time limit (30 or 60 seconds I think).

Here is my test client:

from __future__ import print_function
import jsonrpclib
import threading
import time

lock = threading.Lock()
tidx = 0

def call_server():
    with lock:
        global tidx
        tidx += 1
        current_idx = tidx

    server = jsonrpclib.ServerProxy('http://localhost:8099')
    print(current_idx, ":: Running test...")
    result = server.test()
    print(current_idx, ":: Done:", result)

while True:
    thread = threading.Thread(target=call_server)
    thread.daemon = True
    thread.start()
    time.sleep(.05)
byaka commented 9 years ago

17 gigabytes used now((( and 4 "Ghosts". Python 2.7.6 , Debian 6 For testing (and generating high load) i'm use real peoples. Clients, connected to my server, is browsers. Code in client side is simple ajax request.

is any method to "find" and simply kill this unreleased connections (Ghosts)? But i'm think it's not normal, that unreleased connections eat memory..

tcalmant commented 9 years ago

Sorry, I couldn't work on my open source projects this week... Could you send me a javascript test code ?

A solution might be to use a thread pool for the connection part, it would avoid to use too much resources at once.

byaka commented 9 years ago

No problems, i'm understand u.

   var url='';
   var data='{"jsonrpc": "2.0", "method": "test", "params": [], "id":'+Math.round(Math.random()*65536)+'}';
   var req=null;
   if(window.XMLHttpRequest) req=new XMLHttpRequest();
   else req=new ActiveXObject("Microsoft.XMLHTTP");
   if(!req) return;
   req.onreadystatechange=function(e){
      if(req.readyState!==4) return;
      console.log('!!!', req.responseText, req.status, req);
      req.abort();
   };
   req.open('post', url);
   req.send(data);

yesterday i'm try to use Flask with json rpc implementation. Only native python, no C modules or wsgi containers (like gevent or tornado). In threaded mode (for every connection new thread) i'm have Ghosts too, BUT they don't eat cpu or memory. After 24h Server take only 100mb of RAM. I'm think it's interesting..

tcalmant commented 9 years ago

Could you try with the latest commit ? I've changed a little the end of request handling, so it might correct some strange behaviours.

Also, I added a PooledJSONRPCServer class, which uses a pool of 30 threads max to handle requests: it might reduce the consumption of resources.

byaka commented 9 years ago

First test (without changing code, only new version of lib) continues 14 hours, no memory leak. You are my hero! Really, u awesome! Can u explain me, what u fixed? I'm need more tests but this is so good result

tcalmant commented 9 years ago

Well, it was two small bugs in fact:

1/ there were no protection against reading closed sockets: if the client closed its socket before the server fully read the request, then the server was stuck in an infinite loop calling socket.read(). => this might explain the threads eating all of the CPU

2/ the server was shutting down the socket in wrting once it had sent the response of request (see socket.shutdown()). As a result, if the client reused the socket to send a second request, the server was able to handle it but couldn't send the response back. The client had to wait for a time out before sending the request again, in another socket. => this might explain the ghost connections: the client was waiting for a response while the server wasn't able to write it.

byaka commented 9 years ago

It's really nice work! Thx again. I think i wait 1 day (i need some special tests) and close this ticket, problem solved.