[OPEN-ILS-DEV] Can't connect with client

Bill Ott bott at grpl.org
Sun Mar 18 15:48:42 EDT 2007


Don McMorris wrote:
> How do the logs look? Any changes there?

Tons of data in the osrfsys.log, lots of new cstore debug messages on 
startup, but no errors.  Here is the run of the osrfsys.log during a 
client login attempt.  I only see INFO and DEBG messages, but hopefully 
there will be something telling in the mix.



chopchop 2007-03-18 15:44:04 [DEBG:23143:socket_bundle.c:518:] 1 active 
sockets after select()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:210:] Found node 
for sockid 114 with state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:396:] pushing data 
into xml parser for node 114 with state 2:
<message to="router at openils.grpl.org/open-ils.auth" from="" 
router_from="" router_to="" router_class="" router_command="" 
osrf_xid=""><thread>1174247044.825703.117424704423266</thread><body>[/*--S 
osrfMessage--*/{"threadTrace":"1","type":"REQUEST","payload":/*--S 
osrfMethod--*/{"method":"open-ils.auth.authenticate.init","params":["admin"]}/*--E 
osrfMethod--*/}/*--E osrfMessage--*/]</body></message>
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element message with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element thread with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element body with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:704:] Routing 
message to router at openils.grpl.org/open-ils.auth
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266

chopchop 2007-03-18 15:44:04 [INFO:23143:osrf_chat.c:278:] Sending 
message on local connection
from: 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
to: router at openils.grpl.org/open-ils.auth
chopchop 2007-03-18 15:44:04 [DEBG:23143:socket_bundle.c:518:] 1 active 
sockets after select()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:210:] Found node 
for sockid 77 with state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:396:] pushing data 
into xml parser for node 77 with state 2:
<message 
to="osrf at openils.grpl.org/open-ils.auth_listener_openils.grpl.org_1174246485.796575_23201" 
from="gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266" 
router_from="gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266" 
router_to="" router_class="" router_command="" 
osrf_xid=""><thread>1174247044.825703.117424704423266</thread><body>[/*--S 
osrfMessage--*/{"threadTrace":"1","type":"REQUEST","payload":/*--S 
osrfMethod--*/{"method":"open-ils.auth.authenticate.init","params":["admin"]}/*--E 
osrfMethod--*/}/*--E osrfMessage--*/]</body></message>
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element message with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element thread with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element body with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:704:] Routing 
message to 
osrf at openils.grpl.org/open-ils.auth_listener_openils.grpl.org_1174246485.796575_23201
router at openils.grpl.org/open-ils.auth

chopchop 2007-03-18 15:44:04 [INFO:23143:osrf_chat.c:278:] Sending 
message on local connection
from: router at openils.grpl.org/open-ils.auth
to: 
osrf at openils.grpl.org/open-ils.auth_listener_openils.grpl.org_1174246485.796575_23201
open-ils.auth 2007-03-18 15:44:04 [DEBG:23201:osrf_prefork.c:532:] 
Server received status from a child 23227
open-ils.auth 2007-03-18 15:44:04 [DEBG:23201:osrf_prefork.c:543:] Read 
9 bytes from status buffer: available
open-ils.auth 2007-03-18 15:44:04 [DEBG:23201:osrf_prefork.c:389:] 
Server received inbound data
open-ils.auth 2007-03-18 15:44:04 [DEBG:23201:osrf_prefork.c:400:] 
forker sending data to 23223
open-ils.auth 2007-03-18 15:44:04 [DEBG:23201:osrf_prefork.c:374:] 
Forker going into wait for data...
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_prefork.c:566:] 
Prefork child read 563 bytes of data
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_prefork.c:586:] 
Prefork child got a request.. processing..
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:43:] 
Transport handler received new message
from 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266 
to 
osrf at openils.grpl.org/open-ils.auth_listener_openils.grpl.org_1174246485.796575_23201 
with body

[/*--S 
osrfMessage--*/{"threadTrace":"1","type":"REQUEST","payload":/*--S 
osrfMethod--*/{"method":"open-ils.auth.authenticate.init","params":["admin"]}/*--E 
osrfMethod--*/}/*--E osrfMessage--*/]

open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_app_session.c:241:] 
Initing server session with session id 
1174247044.825703.117424704423266, service open-ils.auth, and remote_id 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:66:] Session 
[1174247044.825703.117424704423266] found or built
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:73:] We 
received 1 messages from 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:208:] Server 
received message of type 1
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:229:] server 
passing message 1 to application handler for session 
1174247044.825703.117424704423266
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:123:] passing 
message 1 / session 1174247044.825703.117424704423266 to app handler
open-ils.auth 2007-03-18 15:44:04 [INFO:23223:oils_auth.c:82:] CALL:    
open-ils.auth open-ils.auth.authenticate.init - ["admin"]
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:oils_auth.c:107:] 
oilsAuthInit(): has seed 083585426204e5cbca49f671a296c4c0 and key 
oils_auth_admin
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_app_session.c:547:] 
AppSession in queue_wait with timeout 0
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_app_session.c:367:] 
App Session [open-ils.auth] [1174247044.825703.117424704423266] 
resetting remote id to 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
chopchop 2007-03-18 15:44:04 [DEBG:23143:socket_bundle.c:518:] 1 active 
sockets after select()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:210:] Found node 
for sockid 68 with state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:396:] pushing data 
into xml parser for node 68 with state 2:
<message 
to="gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266" 
from="" router_from="" router_to="" router_class="" router_command="" 
osrf_xid=""><thread>1174247044.825703.117424704423266</thread><body>[/*--S 
osrfMessage--*/{"threadTrace":"1","type":"RESULT","payload":/*--S 
osrfResult--*/{"status":"OK","statusCode":"200","content":"083585426204e5cbca49f671a296c4c0"}/*--E 
osrfResult--*/}/*--E osrfMessage--*/,/*--S 
osrfMessage--*/{"threadTrace":"1","type":"STATUS","payload":/*--S 
osrfConnectStatus--*/{"status":"Request 
Complete","statusCode":"205"}/*--E osrfConnectStatus--*/}/*--E 
osrfMessage--*/]</body></message>
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element message with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element thread with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:432:] Starting 
element body with namespace (null) and node state 2
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:605:] 
osrfChatHandleConnected()
chopchop 2007-03-18 15:44:04 [DEBG:23143:osrf_chat.c:704:] Routing 
message to 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
osrf at openils.grpl.org/open-ils.auth_drone_openils.grpl.org_1174246485.802461_23223

chopchop 2007-03-18 15:44:04 [INFO:23143:osrf_chat.c:278:] Sending 
message on local connection
from: 
osrf at openils.grpl.org/open-ils.auth_drone_openils.grpl.org_1174246485.802461_23223
to: 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
open-ils.auth 2007-03-18 15:44:04 [INFO:23223:osrf_app_session.c:515:] 
[open-ils.auth] sent 400 bytes of data to 
gateway at openils.grpl.org/1174246505_openils.grpl.org_1174246505.606500_23266
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_app_session.c:518:] 
Sent: [/*--S 
osrfMessage--*/{"threadTrace":"1","type":"RESULT","payload":/*--S 
osrfResult--*/{"status":"OK","statusCode":"200","content":"083585426204e5cbca49f671a296c4c0"}/*--E 
osrfResult--*/}/*--E osrfMessage--*/,/*--S 
osrfMessage--*/{"threadTrace":"1","type":"STATUS","payload":/*--S 
osrfConnectStatus--*/{"status":"Request 
Complete","statusCode":"205"}/*--E osrfConnectStatus--*/}/*--E 
osrfMessage--*/]
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_application.c:335:] 
Postprocessing method open-ils.auth.authenticate.init with retcode 0
open-ils.auth 2007-03-18 15:44:04 [INFO:23223:osrf_stack.c:103:] Message 
processing duration 0.004564
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_stack.c:106:] after 
msg delete
open-ils.auth 2007-03-18 15:44:04 [DEBG:23223:osrf_app_session.c:563:] 
AppSession [open-ils.auth] [1174247044.825703.117424704423266] 
destroying self and deleting requests





More information about the Open-ils-dev mailing list