stateful backend sessions now only timeout of no request was received within

the keepalive timeout.  previously, if a request took long enough to process,
the session would timeout after sending the result back because the entire
time the forker waited on queue_wait exceeded the timeout

updated some logging

git-svn-id: svn://svn.open-ils.org/OpenSRF/trunk@787 9efc2488-bf62-4759-914b-345cdb29e865

diff --git a/src/libstack/osrf_app_session.c b/src/libstack/osrf_app_session.c
index ec04d40..0b35537 100644 (file)
--- a/src/libstack/osrf_app_session.c
+++ b/src/libstack/osrf_app_session.c
@@ -36,19 +36,7 @@ void osrfAppSessionCleanup() {
 void _osrf_app_request_free( void * req ){
        if( req == NULL ) return;
        osrfAppRequest* r = (osrfAppRequest*) req;
-
        if( r->payload ) osrf_message_free( r->payload );
-
-       /*
-       osrf_message* cur_msg = req->result;
-       while( cur_msg != NULL ) {
-               osrf_message* next_msg = cur_msg->next;
-               osrf_message_free( cur_msg );
-               cur_msg = next_msg;
-       }
-       osrf_message_free( req->payload );
-       */
-
        free( r );
 }
 
@@ -68,11 +56,6 @@ void _osrf_app_request_push_queue( osrf_app_request* req, osrf_message* result )
                        ptr2 = ptr2->next;
                }
                ptr->next = result;
-
-               /*
-               result->next = req->result;
-               req->result = result;
-               */
        }
 }
 
@@ -118,7 +101,7 @@ osrf_message* _osrf_app_request_recv( osrf_app_request* req, int timeout ) {
                /* tell the session to wait for stuff */
                osrfLogDebug( OSRF_LOG_MARK,  "In app_request receive with remaining time [%d]", (int) remaining );
 
-               osrf_app_session_queue_wait( req->session, 0 );
+               osrf_app_session_queue_wait( req->session, 0, NULL );
 
                if( req->result != NULL ) { /* if we received anything */
                        /* pop off the first message in the list */
@@ -132,7 +115,7 @@ osrf_message* _osrf_app_request_recv( osrf_app_request* req, int timeout ) {
                if( req->complete )
                        return NULL;
 
-               osrf_app_session_queue_wait( req->session, (int) remaining );
+               osrf_app_session_queue_wait( req->session, (int) remaining, NULL );
 
                if( req->result != NULL ) { /* if we received anything */
                        /* pop off the first message in the list */
@@ -253,7 +236,7 @@ osrf_app_session* osrf_app_client_session_init( char* remote_service ) {
 osrf_app_session* osrf_app_server_session_init( 
                char* session_id, char* our_app, char* remote_id ) {
 
-       osrfLogInfo( OSRF_LOG_MARK, "Initing server session with session id %s, service %s,"
+       osrfLogDebug( OSRF_LOG_MARK, "Initing server session with session id %s, service %s,"
                        " and remote_id %s", session_id, our_app, remote_id );
 
        osrf_app_session* session = osrf_app_session_find_session( session_id );
@@ -435,7 +418,7 @@ int osrf_app_session_connect(osrf_app_session* session){
        time_t remaining = (time_t) timeout;
 
        while( session->state != OSRF_SESSION_CONNECTED && remaining >= 0 ) {
-               osrf_app_session_queue_wait( session, remaining );
+               osrf_app_session_queue_wait( session, remaining, NULL );
                remaining -= (int) (time(NULL) - start);
        }
 
@@ -487,12 +470,11 @@ int osrfAppSessionSendBatch( osrfAppSession* session, osrf_message* msgs[], int
        if( !(session && msgs && size > 0) ) return 0;
        int retval = 0;
 
-
        osrfMessage* msg = msgs[0];
 
        if(msg) {
 
-               osrf_app_session_queue_wait( session, 0 );
+               osrf_app_session_queue_wait( session, 0, NULL );
 
                if(session->state != OSRF_SESSION_CONNECTED)  {
 
@@ -520,20 +502,21 @@ int osrfAppSessionSendBatch( osrfAppSession* session, osrf_message* msgs[], int
 
                transport_message* t_msg = message_init( 
                                string, "", session->session_id, session->remote_id, NULL );
-       
-               osrfLogDebug(OSRF_LOG_MARK, "Session [%s] [%s]  sending to %s \nData: %s", 
-                               session->remote_service, session->session_id, t_msg->recipient, string );
 
                retval = client_send_message( session->transport_handle, t_msg );
 
                if( retval ) osrfLogError(OSRF_LOG_MARK, "client_send_message failed");
-       
+
+               osrfLogInfo(OSRF_LOG_MARK, "[%s] sent %d bytes of data to %s",
+                       session->remote_service, strlen(string), t_msg->recipient );
+
+               osrfLogDebug(OSRF_LOG_MARK, "Sent: %s", string );
+
                free(string);
                message_free( t_msg );
        }
 
        return retval; 
-
 }
 
 
@@ -553,11 +536,11 @@ int _osrf_app_session_send( osrf_app_session* session, osrf_message* msg ){
   * payload and message type.  This method will return after
   * any data has arrived.
   */
-int osrf_app_session_queue_wait( osrf_app_session* session, int timeout ){
+int osrf_app_session_queue_wait( osrf_app_session* session, int timeout, int* recvd ){
        if(session == NULL) return 0;
        int ret_val = 0;
        osrfLogDebug(OSRF_LOG_MARK,  "AppSession in queue_wait with timeout %d", timeout );
-       ret_val = osrf_stack_entry_point(session->transport_handle, timeout);
+       ret_val = osrf_stack_entry_point(session->transport_handle, timeout, recvd);
        return ret_val;
 }
 
@@ -604,6 +587,7 @@ int osrfAppRequestRespond( osrfAppSession* ses, int requestId, jsonObject* data
 
        osrf_message* msg = osrf_message_init( RESULT, requestId, 1 );
        char* json = jsonObjectToJSON( data );
+
        osrf_message_set_result_content( msg, json );
        _osrf_app_session_send( ses, msg ); 
 
@@ -641,8 +625,6 @@ int osrfAppRequestRespondComplete(
 
        osrf_message_free( status );
 
-       /* join and free */
-
        return 0;
 }
 

diff --git a/src/libstack/osrf_app_session.h b/src/libstack/osrf_app_session.h
index 8c6dbbf..0d8f814 100644 (file)
--- a/src/libstack/osrf_app_session.h
+++ b/src/libstack/osrf_app_session.h
@@ -22,7 +22,7 @@ enum OSRF_SESSION_STATE { OSRF_SESSION_CONNECTING, OSRF_SESSION_CONNECTED, OSRF_
 enum OSRF_SESSION_TYPE { OSRF_SESSION_SERVER, OSRF_SESSION_CLIENT };
 
 /* entry point for data into the stack.  gets set in osrf_stack.c */
-int (*osrf_stack_entry_point) (transport_client* client, int timeout );
+int (*osrf_stack_entry_point) (transport_client* client, int timeout, int* recvd );
 
 struct osrf_app_request_struct {
        /** Our controlling session */
@@ -159,7 +159,7 @@ int osrf_app_session_disconnect( osrf_app_session* );
   * payload and message type.  This method will return after
   * any data has arrived.
   */
-int osrf_app_session_queue_wait( osrf_app_session*, int timeout );
+int osrf_app_session_queue_wait( osrf_app_session*, int timeout, int* recvd );
 
 /** Disconnects (if client), frees any attached app_reuqests, removes the session from the 
   * global session cache and frees the session.  Needless to say, only call this when the

diff --git a/src/libstack/osrf_application.c b/src/libstack/osrf_application.c
index eec1f30..238417e 100644 (file)
--- a/src/libstack/osrf_application.c
+++ b/src/libstack/osrf_application.c
@@ -210,9 +210,6 @@ int osrfAppRunMethod( char* appName, char* methodName,
        /* this is the method we're gonna run */
        int (*meth) (osrfMethodContext*);       
 
-       osrfLogInfo( OSRF_LOG_MARK, "Running method [%s] for app [%s] with request id %d and "
-                       "thread trace %s", methodName, appName, reqId, ses->session_id );
-
        if( !(app = _osrfAppFindApplication(appName)) )
                return osrfAppRequestRespondException( ses, 
                                reqId, "Application not found: %s", appName );
@@ -317,7 +314,6 @@ int __osrfAppPostProcess( osrfMethodContext* ctx, int retcode ) {
        }
 
        return 0;
-
 }
 
 int osrfAppRequestRespondException( osrfAppSession* ses, int request, char* msg, ... ) {

diff --git a/src/libstack/osrf_prefork.c b/src/libstack/osrf_prefork.c
index 5b7d1f5..b2cad6c 100644 (file)
--- a/src/libstack/osrf_prefork.c
+++ b/src/libstack/osrf_prefork.c
@@ -179,6 +179,7 @@ void prefork_child_process_request(prefork_child* child, char* data) {
        osrfLogDebug( OSRF_LOG_MARK, "Entering keepalive loop for session %s", session->session_id );
        int keepalive = child->keepalive;
        int retval;
+       int recvd;
        time_t start;
        time_t end;
 
@@ -187,9 +188,11 @@ void prefork_child_process_request(prefork_child* child, char* data) {
                osrfLogDebug(OSRF_LOG_MARK, 
                                "osrf_prefork calling queue_wait [%d] in keepalive loop", keepalive);
                start           = time(NULL);
-               retval  = osrf_app_session_queue_wait(session, keepalive);
+               retval  = osrf_app_session_queue_wait(session, keepalive, &recvd);
                end             = time(NULL);
 
+               osrfLogDebug(OSRF_LOG_MARK, "Data received == %d", recvd);
+
                if(retval) {
                        osrfLogError(OSRF_LOG_MARK, "queue-wait returned non-success %d", retval);
                        break;
@@ -198,11 +201,9 @@ void prefork_child_process_request(prefork_child* child, char* data) {
                /* see if the client disconnected from us */
                if(session->state != OSRF_SESSION_CONNECTED) break;
 
-               /* see if the used up the timeout */
-               if( (end - start) >= keepalive ) {
-
-                       osrfLogDebug(OSRF_LOG_MARK, "Keepalive timed out, exiting connected session");
-
+               /* if no data was reveived within the timeout interval */
+               if( !recvd && (end - start) >= keepalive ) {
+                       osrfLogInfo(OSRF_LOG_MARK, "No data was reveived in %d seconds, exiting stateful session", keepalive);
                        osrfAppSessionStatus( 
                                        session, 
                                        OSRF_STATUS_TIMEOUT, 

diff --git a/src/libstack/osrf_stack.c b/src/libstack/osrf_stack.c
index 4d27d7f..c327352 100644 (file)
--- a/src/libstack/osrf_stack.c
+++ b/src/libstack/osrf_stack.c
@@ -5,13 +5,15 @@ osrf_message* _do_client( osrf_app_session*, osrf_message* );
 osrf_message* _do_server( osrf_app_session*, osrf_message* );
 
 /* tell osrf_app_session where the stack entry is */
-int (*osrf_stack_entry_point) (transport_client*, int)  = &osrf_stack_process;
+int (*osrf_stack_entry_point) (transport_client*, int, int*)  = &osrf_stack_process;
 
-int osrf_stack_process( transport_client* client, int timeout ) {
+int osrf_stack_process( transport_client* client, int timeout, int* msg_received ) {
        if( !client ) return -1;
        transport_message* msg = NULL;
+       if(msg_received) *msg_received = 0;
 
        while( (msg = client_recv( client, timeout )) ) {
+               if(msg_received) *msg_received = 1;
                osrfLogDebug( OSRF_LOG_MARK,  "Received message from transport code from %s", msg->sender );
                osrf_stack_transport_handler( msg, NULL );
                timeout = 0;
@@ -162,8 +164,6 @@ osrf_message* _do_client( osrf_app_session* session, osrf_message* msg ) {
                        case OSRF_STATUS_EXPFAILED: 
                                osrf_app_session_reset_remote( session );
                                session->state = OSRF_SESSION_DISCONNECTED;
-                               /* set the session to 'stateful' then resend */
-                       //      osrf_app_session_request_resend( session, msg->thread_trace );
                                return NULL;
 
                        case OSRF_STATUS_TIMEOUT:
@@ -238,9 +238,7 @@ osrf_message* _do_server( osrf_app_session* session, osrf_message* msg ) {
 
 
 
-
 int osrf_stack_application_handler( osrf_app_session* session, osrf_message* msg ) {
-
        if(session == NULL || msg == NULL) return 0;
 
        if(msg->m_type == RESULT && session->type == OSRF_SESSION_CLIENT) {
@@ -255,10 +253,9 @@ int osrf_stack_application_handler( osrf_app_session* session, osrf_message* msg
        jsonObject* params = msg->_params;
 
        osrfAppRunMethod( app, method,  session, msg->thread_trace, params );
-
        osrfMessageFree(msg);
                
        return 1;
-
 }
 
+

diff --git a/src/libstack/osrf_stack.h b/src/libstack/osrf_stack.h
index fbffbe8..0ef6d00 100644 (file)
--- a/src/libstack/osrf_stack.h
+++ b/src/libstack/osrf_stack.h
@@ -9,7 +9,7 @@
 #define OSRF_MAX_MSGS_PER_PACKET 256
 // -----------------------------------------------------------------------------
 
-int osrf_stack_process( transport_client* client, int timeout );
+int osrf_stack_process( transport_client* client, int timeout, int* msg_received );
 osrfAppSession*  osrf_stack_transport_handler( transport_message* msg, char* my_service );
 int osrf_stack_message_handler( osrf_app_session* session, osrf_message* msg );
 int osrf_stack_application_handler( osrf_app_session* session, osrf_message* msg );