Working through "easing gently into opensrf", I can't seem to invoke my method via srfsh

opensrf newb

# First, basic system stuff

$ uname -a
Linux cardinal 2.6.35-22-generic #35-Ubuntu SMP Sat Oct 16 20:36:48 UTC 2010 i686 GNU/Linux

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

# Installed OpenSRF 1.6.1 (w/ --enable-python) per: 
#   http://www.open-ils.org/dokuwiki/doku.php?id=opensrf:1.6:install
# following each step 

# Can make requests to opensrf.math service via srfsh, so:
#   * services ought to be installed and running properly
#   * srfsh.xml ought to be ok

# Tried to work through Easing Gently into OpenSRF, Part 1:
#   http://journal.code4lib.org/articles/3284
# ... but am doing so in Python, so I know I've got something wrong

# Added opensrf.test service to public router in opensrf_core.xml
      <router>
        <name>router</name>
        <domain>public.localhost</domain>
        <services>
            <service>opensrf.math</service> 
            <service>opensrf.test</service>
        </services>
      </router>

# Added opensrf.test service to opensrf.xml, though no idea how to use the "implementation" element to hook to my (python) service code
      <opensrf.test>
        <keepalive>3</keepalive>
        <stateless>1</stateless>
        <language>python</language>
        <implementation>osrf.test</implementation>
        <max_requests>100</max_requests>
        <unix_config>
          <max_requests>1000</max_requests>
          <unix_log>opensrf.test.reverse.log</unix_log>
          <unix_sock>opensrf.test.reverse.sock</unix_sock>
          <unix_pid>opensrf.test.reverse.pid</unix_pid>
          <min_children>5</min_children>
          <max_children>15</max_children>
          <min_spare_children>2</min_spare_children>
          <max_spare_children>5</max_spare_children>
        </unix_config>
      </opensrf.test>

# Added app to activeapps in opensrf.xml
      <activeapps>
        <appname>opensrf.persist</appname>
        <appname>opensrf.settings</appname>
        <appname>opensrf.math</appname>
        <appname>opensrf.dbmath</appname>
        <appname>opensrf.test</appname>
      </activeapps>

# Restarted everything
$ osrf_ctl.sh -a restart_all
...

# Python service code at ~/workspace/opensrf101/osrf_reverse.py
from osrf.app import Application
class Reverse(Application):
    def reverse_text(self, request, message=''):
        i = len(message) - 1
        while i:
            request.respond(message[i])
            i -= 1
    Application.register_method(
        api_name='opensrf.test.reverse',
        method='reverse_text',
        argc=1,
        stream=True
        )
Application.register_app(Reverse())

# Ran the code, nothing was displayed (assume that was desired behavior)
$ python osrf_reverse.py

# Futzed around in srfsh
srfsh# request opensrf.math add 2 2
Received Data: 4
srfsh# request opensrf.test opensrf.test.reverse "foobar"
Received no data from server
srfsh# request opensrf.test reverse "foobar"
Received no data from server

# Grepping for "test" {router,osrfsys}.log == no hits
# But I see this in srfsh.log
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_app_session.c:486:1288399336264321] opensrf.test session is stateless
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_app_session.c:497:1288399336264321] Building a new client session with id [opensrf.test] [1288399378.969662.128839937826432]
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_app_session.c:759:1288399336264322] App Session [opensrf.test] [1288399378.969662.128839937826432] resetting remote id to router@private.localhost/opensrf.test
srfsh 2010-10-29 20:42:58 [INFO:26432:osrf_app_session.c:991:1288399336264322] [opensrf.test] sent 161 bytes of data to router@private.localhost/opensrf.test
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_app_session.c:714:1288399336264322] Pushing [1] onto request queue for session [opensrf.test] [1288399378.969662.128839937826432]
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_stack.c:44:1288399336264322] Received message from transport code from router@private.localhost/opensrf.test
from router@private.localhost/opensrf.test to opensrf@private.localhost/_cardinal_1288399336.310986_26432 with body 
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_stack.c:123:1288399336264322] We received 1 messages from router@private.localhost/opensrf.test
srfsh 2010-10-29 20:42:58 [WARN:26432:osrf_stack.c:144:1288399336264322]  * Jabber Error is for top level remote  id [router@private.localhost/opensrf.test], no one to send my message to!  Cutting request short...
srfsh 2010-10-29 20:42:58 [DEBG:26432:osrf_app_session.c:1063:1288399336264322] AppSession [opensrf.test] [1288399378.969662.128839937826432] destroying self and deleting requests

# Not sure at all that what I put in opensrf.xml is linked to the code I wrote.  
# Suspect error in "implementation" element above?

First stab: the value of should be a python module name found in the opensrf user's python path. For a c service, implementation is a .so file usually in /openils/lib, for perl it's a perl package name like OpenILS::Application::Circ loaded from /openils/lib/perl5/OpenILS/Application/Circ.pm

Long story short, try "export PYTHONPATH=/openils/lib/python" in the opensrf user's .profile or .bashrc (I recommend wherever you're currently setting your PATH), move your .py file there, and change the value of from osrf.test (the name of the service) to osrf_reverse (the name of the python module). Use osrf_ctl.sh to stop then start all services.

That might not be the only problem, but hopefully it helps with the understanding.

Thanks, jeff. That makes sense. Here's what I have now.

• Reset implementation to "opensrf.test"
• Added /path/to/python/src to opensrf's PYTHONPATH in .bashrc
• Sourced .bashrc
• Under /path/to/python/src is a directory called opensrf, in which there's an init.py and a test.py (which contains the python code)
• Confirmed I could "import opensrf.test" in python REPL
• Restarted all

Sadly, no dice in srfsh. Generates this log entry:

srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:486:1288408621295570] opensrf.test session is stateless
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:497:1288408621295570] Building a new client session with id [opensrf.test] [1288408633.621746.128840863329557]
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:1044:1288408621295571] AppSession in queue_wait with timeout 0
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:759:1288408621295571] App Session [opensrf.test] [1288408633.621746.128840863329557] resetting remote id to router@private.localhost/opensrf.test
srfsh 2010-10-29 23:17:13 [INFO:29557:osrf_app_session.c:991:1288408621295571] [opensrf.test] sent 166 bytes of data to router@private.localhost/opensrf.test
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:994:1288408621295571] Sent: [{"__c":"osrfMessage","__p":{"threadTrace":"1","locale":"en-US","type":"REQUEST","payload":{"__c":"osrfMethod","__p":{"method":"reverse_text","params":["foobar"]}}}}]
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:714:1288408621295571] Pushing [1] onto request queue for session [opensrf.test] [1288408633.621746.128840863329557]
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:275:1288408621295571] In app_request receive with remaining time [120]
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:1044:1288408621295571] AppSession in queue_wait with timeout 0
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:1044:1288408621295571] AppSession in queue_wait with timeout 120
srfsh 2010-10-29 23:17:13 [INFO:29557:transport_session.c:667:1288408621295571] Received message with type cancel and code 503
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_stack.c:44:1288408621295571] Received message from transport code from router@private.localhost/opensrf.test
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_stack.c:87:1288408621295571] Transport handler received new message
from router@private.localhost/opensrf.test to opensrf@private.localhost/_cardinal_1288408621.434113_29557 with body

[{"__c":"osrfMessage","__p":{"threadTrace":"1","locale":"en-US","type":"REQUEST","payload":{"__c":"osrfMethod","__p":{"method":"reverse_text","params":["foobar"]}}}}]

srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_stack.c:123:1288408621295571] We received 1 messages from router@private.localhost/opensrf.test
srfsh 2010-10-29 23:17:13 [WARN:29557:osrf_stack.c:134:1288408621295571] !!! Received Jabber layer error message
srfsh 2010-10-29 23:17:13 [WARN:29557:osrf_stack.c:144:1288408621295571] * Jabber Error is for top level remote id [router@private.localhost/opensrf.test], no one to send my message to! Cutting request short...
srfsh 2010-10-29 23:17:13 [INFO:29557:osrf_stack.c:159:1288408621295571] Message processing duration 0.000130
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_stack.c:162:1288408621295571] after msg delete
srfsh 2010-10-29 23:17:13 [ERR :29557:osrf_app_session.c:302:1288408621295571] Transport error in recv()
srfsh 2010-10-29 23:17:13 [DEBG:29557:osrf_app_session.c:1063:1288408621295571] AppSession [opensrf.test] [1288408633.621746.128840863329557] destroying self and deleting requests
srfsh 2010-10-29 23:17:16 [DEBG:29557:socket_bundle.c:475:1288408621295571] removing socket 3

This worked for me. Hopefully I won't forget a step/detail:

osrf_ctl.sh doesn't deal with python services.

Copy src/python/opensrf.py from the OpenSRF tarball to /openils/bin -- this will be used later to start the our python service.

The python dns libs used by the python XMPP libs don't support /etc/hosts -- install dnsmasq, which by default seeds from /etc/hosts. You'll need to add "nameserver 127.0.0.1" to your /etc/resolv.conf file (or similar).

http://www.open-ils.org/dokuwiki/doku.php?id=opensrf:python has reference to the DNS issue.

You can test your dnsmasq install by trying to run srfsh.py -- if you get a prompt, you're good. If you get a NXDOMAIN error, you won't get far.

To get around import errors when trying to "import opensrf.test" within a script named "opensrf.py", I moved renamed test.py's containing directory to "opensrfcustom" and changed the "implementation" value in opensrf.xml to "opensrfcustom.test". Upon further reflection, I could also have renamed opensrf.py to opensrf_ctl.py or something.

The opensrf.py script has a problem with comments in opensrf.xml. I added a simple check in do_init() to skip over instead of trip and die on them:

for key in settings.keys():
    if key == '#comment':
            continue
    svc = settings[key]
    if isinstance(svc, dict) and svc['language'] == 'python':
        services[key] = svc

At this point, I'd recommend doing an opensrf_ctl.sh -l -a stop_all followed by a start_all -- just to ensure that the latest copy of opensrf.xml is loaded, etc.

Then, start the opensrf.test service in the foreground -- as a daemon doesn't work for me, haven't looked into it:

opensrf.py -f /openils/conf/opensrf_core.xml -l -a start -s opensrf.test -p /openils/var/run

And test with srfsh:
srfsh# request opensrf.test opensrf.test.reverse "foobar"

Here, I got:

Received Data: "r"
Received Data: "a"
Received Data: "b"
Received Data: "o"
Received Data: "o"

Fixing the lack of an "f" is left as an exercise to the reader.

As you can see, OpenSRF services written in Python is lightly documented, lightly tested. It actually worked a lot better than I expected going into this.

Please let me know if this doesn't work for you -- I'll see if I overlooked something in my notes.

now I see updates to this - good to see that jeff and I basically share a brain. Asides:

• I was running on Fedora 13, OpenSRF trunk, Python 2.6.4
  • Didn't have any problems with comments in opensrf.xml
  • Didn't have any problems running opensrf.py in daemonize mode

Might just be a distro thing? I blame Canonical. Otherwise, yay!

Thanks a bunch, y'all. Combined your suggestions and got it working. Btw, I did have problems with comments in opensrf.py, and but did not have problems with daemon mode (though I used start_all instead of the -s flag).

Replying to open-ils-dev thread.