Services hanging after multiple calls

OpenSrf

# some basic system info
Python 2.6.6 
OpenSrf svn checkout from 11/30/2010
> uname -a
Linux capstest 2.6.35-22-server #33-Ubuntu SMP Sun Sep 19 20:48:58 UTC 2010 x86_64 GNU/Linux

>cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=10.10
DISTRIB_CODENAME=maverick
DISTRIB_DESCRIPTION="Ubuntu 10.10"


### start up logs
[2010-12-01 08:43:36] opensrf.settings [INFO:11789:Server.pm:433:] server: registering with router [email protected]/router
opensrf 2010-12-01 08:43:39 [INFO:11798:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf 2010-12-01 08:43:39 [INFO:11798:osrf_app_session.c:991:] [opensrf.settings] sent 189 bytes of data to [email protected]/opensrf.settings
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [localhost]
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.010
opensrf 2010-12-01 08:43:39 [INFO:11798:osrf_stack.c:159:] Message processing duration 0.000005
opensrf 2010-12-01 08:43:39 [INFO:11799:osrf_system.c:283:] Launching application opensrf.math with implementation osrf_math.so
opensrf 2010-12-01 08:43:39 [INFO:11799:osrf_system.c:291:] Running application child opensrf.math: process id 11804
opensrf 2010-12-01 08:43:39 [INFO:11799:osrf_system.c:283:] Launching application opensrf.dbmath with implementation osrf_dbmath.so
opensrf 2010-12-01 08:43:39 [INFO:11799:osrf_system.c:291:] Running application child opensrf.dbmath: process id 11805
opensrf 2010-12-01 08:43:39 [INFO:11805:osrf_system.c:318:]  * Running application opensrf.dbmath

opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_application.c:150:] Registering application opensrf.dbmath with file osrf_dbmath.so
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_application.c:193:] Application opensrf.dbmath registered successfully
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_prefork.c:131:] Loading config in osrf_forker for app opensrf.dbmath
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_prefork.c:506:] Prefork launching child with max_request=1000,min_children=5, max_children=15
opensrf 2010-12-01 08:43:39 [INFO:11804:osrf_system.c:318:]  * Running application opensrf.math

opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_application.c:150:] Registering application opensrf.math with file osrf_math.so
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_application.c:193:] Application opensrf.math registered successfully
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_application.c:221:] registering exit handler for opensrf.math
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_prefork.c:131:] Loading config in osrf_forker for app opensrf.math
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_prefork.c:219:] opensrf.dbmath registering with router [email protected]/router
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11807:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11807:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11809:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_prefork.c:506:] Prefork launching child with max_request=1000,min_children=5, max_children=15
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_prefork.c:219:] opensrf.math registering with router [email protected]/router
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_prefork.c:219:] opensrf.math registering with router [email protected]/router
opensrf.math 2010-12-01 08:43:39 [INFO:11804:osrf_prefork.c:194:] Launching osrf_forker for app opensrf.math
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11809:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11811:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.math 2010-12-01 08:43:39 [INFO:11811:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11812:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11807:osrf_application.c:254:] opensrf.dbmath child init succeeded
opensrf.math 2010-12-01 08:43:39 [INFO:11813:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.math 2010-12-01 08:43:39 [INFO:11813:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11815:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11809:osrf_application.c:254:] opensrf.dbmath child init succeeded
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11805:osrf_prefork.c:194:] Launching osrf_forker for app opensrf.dbmath
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11806:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11806:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11808:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11808:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11815:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11810:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11810:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11814:osrf_system.c:198:] Adding cache server 127.0.0.1:11211
opensrf.math 2010-12-01 08:43:39 [INFO:11814:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11812:osrf_system.c:628:] Bootstrapping system with domain private.localhost, port 5222, and unixpath (none)
opensrf.math 2010-12-01 08:43:39 [INFO:11811:osrf_application.c:254:] opensrf.math child init succeeded
opensrf.math 2010-12-01 08:43:39 [INFO:11813:osrf_application.c:254:] opensrf.math child init succeeded
[2010-12-01 08:43:39] opensrf.persist [INFO:11796:Server.pm:433:] server: registering with router [email protected]/router
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11806:osrf_application.c:254:] opensrf.dbmath child init succeeded
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11808:osrf_application.c:254:] opensrf.dbmath child init succeeded
opensrf.math 2010-12-01 08:43:39 [INFO:11815:osrf_application.c:254:] opensrf.math child init succeeded
opensrf.dbmath 2010-12-01 08:43:39 [INFO:11810:osrf_application.c:254:] opensrf.dbmath child init succeeded
2010-12-01 08:43:39.212 [INFO:11803:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:43:39] opensrf.settings [INFO:11794:Application.pm:130:] CALL: opensrf.settings.host_config.get [localhost]
[2010-12-01 08:43:39] opensrf.settings [INFO:11794:Transport.pm:161:] Message processing duration: 0.006
opensrf.math 2010-12-01 08:43:39 [INFO:11814:osrf_application.c:254:] opensrf.math child init succeeded
2010-12-01 08:43:39.357 [INFO:11821:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [localhost]
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.007
2010-12-01 08:43:39.377 [INFO:11822:app.py:79:MainThread:] Loading application module opensrf101.fixity_service
2010-12-01 08:43:39.448 [INFO:11825:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.453 [INFO:11824:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.454 [INFO:11823:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.456 [INFO:11827:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.462 [INFO:11826:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.587 [INFO:11828:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:43:39] opensrf.settings [INFO:11794:Application.pm:130:] CALL: opensrf.settings.host_config.get [localhost]
[2010-12-01 08:43:39] opensrf.settings [INFO:11794:Transport.pm:161:] Message processing duration: 0.004
2010-12-01 08:43:39.601 [INFO:11829:app.py:79:MainThread:] Loading application module opensrf101.versioning_service
2010-12-01 08:43:39.645 [INFO:11831:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.647 [INFO:11832:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.648 [INFO:11834:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.649 [INFO:11830:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.652 [INFO:11833:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.733 [INFO:11835:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [localhost]
[2010-12-01 08:43:39] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.004
2010-12-01 08:43:39.747 [INFO:11836:app.py:79:MainThread:] Loading application module opensrf101.identity_service
2010-12-01 08:43:39.788 [INFO:11838:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.790 [INFO:11837:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.791 [INFO:11839:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.792 [INFO:11841:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.796 [INFO:11840:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.906 [INFO:11822:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:39.906 [INFO:11822:server.py:273:MainThread:] registering with router [email protected]/router
2010-12-01 08:43:39.908 [INFO:11822:server.py:273:MainThread:] registering with router [email protected]/router
2010-12-01 08:43:40.132 [INFO:11829:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:40.132 [INFO:11829:server.py:273:MainThread:] registering with router [email protected]/router
2010-12-01 08:43:40.134 [INFO:11829:server.py:273:MainThread:] registering with router [email protected]/router
2010-12-01 08:43:40.274 [INFO:11836:net.py:163:MainThread:] Successfully connected to the opensrf network
2010-12-01 08:43:40.274 [INFO:11836:server.py:273:MainThread:] registering with router [email protected]/router
2010-12-01 08:43:40.278 [INFO:11836:server.py:273:MainThread:] registering with router [email protected]/router
opensrf.math 2010-12-01 08:43:42 [INFO:11812:osrf_application.c:254:] opensrf.math child init succeeded



# logs when I run the fixity service call 3x (the first 2 are successfull the third one hangs)


2010-12-01 08:44:23.169 [INFO:11843:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:44:23] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [private.localhost]
[2010-12-01 08:44:23] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.004
2010-12-01 08:44:23.186 [INFO:11827:app.py:118:MainThread:] CALL: psu.dlt.fixity psu.dlt.fixity.generate "/opt/caps/opensrf101/README", "md5"
2010-12-01 08:44:23.187 [INFO:11827:stack.py:37:MainThread:] Message processing duration 0.001519
2010-12-01 08:44:24.635 [INFO:11844:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:44:24] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [private.localhost]
[2010-12-01 08:44:24] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.007
2010-12-01 08:44:24.662 [INFO:11826:app.py:118:MainThread:] CALL: psu.dlt.fixity psu.dlt.fixity.generate "/opt/caps/opensrf101/README", "md5"
2010-12-01 08:44:24.664 [INFO:11826:stack.py:37:MainThread:] Message processing duration 0.002713
2010-12-01 08:44:25.945 [INFO:11845:net.py:163:MainThread:] Successfully connected to the opensrf network
[2010-12-01 08:44:25] opensrf.settings [INFO:11795:Application.pm:130:] CALL: opensrf.settings.host_config.get [private.localhost]
[2010-12-01 08:44:25] opensrf.settings [INFO:11795:Transport.pm:161:] Message processing duration: 0.007
2010-12-01 08:44:25.969 [ERR :11827:net.py:178:MainThread:] XMPP error message received from [email protected]/python_client_capstest:11843_mainthread


# code being run to generate a fixity - 
# fixity_client.py

import sys
import osrf.ses
import osrf.system

conf_file = "/opensrf/conf/opensrf_core.xml"
osrf.system.System.connect(config_file=conf_file,
                           config_context="config.opensrf")


# take a file
f = sys.argv[1]

# grab its fixity value
checksum = osrf.ses.ClientSession.atomic_request("psu.dlt.fixity",
                                                 "psu.dlt.fixity.generate",
                                                    f,      
                                                 "md5")  
print "fixity %s generated for %s" % (checksum, f)


# fixity service registered with opensrf
# fixity_service.py

import hashlib 
from osrf.app import Application


class Fixity(Application):

    Application.register_method(
        api_name='psu.dlt.fixity.generate',
        method='generate',
        argc=2, 
        stream=False
        )       
    def generate(self, request, file_location, algorithm):
        h = hashlib.new(algorithm)
        h.update(open(file_location).read())
        request.respond(h.hexdigest())


Application.register_app(Fixity())

# command being run call fixity client
> python fixity_client.py /opt/caps/opensrf101/README