Hi
I just finish porting Jabber 1.4.1 on a new unix system (compiled in
single). The server start OK and wait for incoming connection. Everytime
a client initiate a login or try to register a new user, then the server
is dying/crashing.
In order to understand what's happening I compiled the PTH lib with
debug turned on, and I added some extra log in jabber's source
especially in the mio.c file (when it raise SIGUSR2 and when it's
waiting for this signal).
After looking the code and trying to understand why it's dying I still
did not figure out the reason. The server is able to send back data to
the client (so write on the socket) since I received correctly the
initial <?xml vresion="1.0"><stream ...
Any help will be appreciate. Here is the log I got (sorry it's long... I
removed some thread context switch that does not add extra useful info) :
..
Thu May 3 11:52:48 2001 mio.c:1120 io_select to listen on 5222 [(null)]
547:pth_lib.c:0443: pth_yield: enter from thread "main"
547:pth_lib.c:0453: return 0x0 with errno 22("Invalid argument")
Thu May 3 11:52:48 2001 mio.c:1144 io_select starting to listen on
5222 [(null)]
Thu May 3 11:52:48 2001 deliver.c:277 Registering elogger with
instance elogger
Thu May 3 11:52:48 2001 deliver.c:277 Registering * with instance
elogger
Thu May 3 11:52:48 2001 deliver.c:383 Registering logtype * with
instance elogger
Thu May 3 11:52:48 2001 base_format.c:112 base_format configuring
instance elogger
Thu May 3 11:52:48 2001 base_file.c:80 base_file configuring instance
elogger
Thu May 3 11:52:48 2001 base_stderr.c:64 base_stderr configuring
instnace elogger
Thu May 3 11:52:48 2001 deliver.c:277 Registering rlogger with
instance rlogger
Thu May 3 11:52:48 2001 deliver.c:277 Registering * with instance
rlogger
Thu May 3 11:52:48 2001 deliver.c:383 Registering logtype record with
instance rlogger
Thu May 3 11:52:48 2001 base_format.c:112 base_format configuring
instance rlogger
Thu May 3 11:52:48 2001 base_file.c:80 base_file configuring instance
rlogger
Thu May 3 11:52:48 2001 deliver.c:277 Registering dnsrv with instance
dnsrv
Thu May 3 11:52:48 2001 deliver.c:277 Registering * with instance dnsrv
Thu May 3 11:52:48 2001 deliver.c:235 @-internal processing <xdb
type='get' to='config@-internal' from='dnsrv' ns='jabber:config:dnsrv'
id='0'/>
Thu May 3 11:52:48 2001 deliver.c:651 delivering to instance 'dnsrv'
Thu May 3 11:52:48 2001 xdb.c:41 xdb_results checking xdb packet <xdb
type='result' to='dnsrv' from='config@-internal'
ns='jabber:config:dnsrv' id='0'><dnsrv xmlns='jabber:config:dnsrv'>
<resend service='_jabber._tcp'>s2s</resend> <resend>s2s</resend>
</dnsrv></xdb>
Thu May 3 11:52:48 2001 dnsrv.c:536 dnsrv debug: <dnsrv
xmlns='jabber:config:dnsrv'>
<resend service='_jabber._tcp'>s2s</resend> <resend>s2s</resend>
</dnsrv>
547:pth_lib.c:0192: pth_spawn: enter
547:pth_mctx.c:0247: pth_mctx_set: enter
547:pth_mctx.c:0391: pth_mctx_set_trampoline: return to caller
547:pth_mctx.c:0395: pth_mctx_set_trampoline: reentered from caller
547:pth_mctx.c:0433: pth_mctx_set_trampoline_jumpin: switch back to
caller
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0363: pth_mctx_set: leave
547:pth_lib.c:0280: pth_spawn: leave
547:pth_lib.c:0414: pth_join: joining thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0388: pth_wait: enter from thread "main"
547:pth_event.c:0394: pth_wait: waiting on event 0x1a5e40
547:pth_lib.c:0443: pth_yield: enter from thread "main"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x17eb30
("main")
547:pth_sched.c:0256: pth_scheduler: thread "main" ran 0.147137
547:pth_sched.c:0338: pth_scheduler: moving thread "main" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0560: pth_sched_eventmanager: [non-I/O] event occurred
for thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0189: pth_scheduler: new thread
"main.child@988915968=0x17eb30" moved to top of ready queue
547:pth_sched.c:0206: pth_scheduler: thread
"main.child@988915968=0x17eb30" selected (prio=0, qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x1a5a90
("main.child@988915968=0x17eb30")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
548:pth_lib.c:0116: return 0x0 with errno 1("Operation not permitted")
Thu May 3 11:52:48 2001 dnsrv.c:132 DNSRV CHILD: starting
547:pth_lib.c:0369: pth_exit: marking thread
"main.child@988915968=0x17eb30" as dead
547:pth_lib.c:0393: pth_exit: switching from thread
"main.child@988915968=0x17eb30" to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x1a5a90
("main.child@988915968=0x17eb30")
547:pth_sched.c:0256: pth_scheduler: thread
"main.child@988915968=0x17eb30" ran 0.009513
547:pth_sched.c:0325: pth_scheduler: marking thread
"main.child@988915968=0x17eb30" as dead
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0560: pth_sched_eventmanager: [non-I/O] event occurred
for thread "main"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "main" moved from
waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_event.c:0417: pth_wait: occurred event 0x1836f0
547:pth_event.c:0417: pth_wait: occurred event 0x185120
547:pth_event.c:0422: pth_wait: leave to thread "unknown"
547:pth_high.c:0261: return 0xffffffff with errno 4("Interrupted system
call")
Thu May 3 11:52:48 2001 mio.c:599 pth_select_ev end waiting
(receiving) !!
Thu May 3 11:52:48 2001 mio.c:627 socket 5 has restore karma -100 -=>
10
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
[...CRUNCH...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0363: pth_mctx_set: leave
547:pth_lib.c:0280: pth_spawn: leave
Thu May 3 11:52:48 2001 deliver.c:277 Registering s2s with instance s2s
Thu May 3 11:52:48 2001 dialback.c:265 dialback loading
Thu May 3 11:52:48 2001 deliver.c:235 @-internal processing <xdb
type='get' to='config@-internal' from='s2s' ns='jabber:config:dialback'
id='0'/>
Thu May 3 11:52:48 2001 deliver.c:651 delivering to instance 's2s'
Thu May 3 11:52:48 2001 xdb.c:41 xdb_results checking xdb packet <xdb
type='result' to='s2s' from='config@-internal'
ns='jabber:config:dialback' id='0'><dialback
xmlns='jabber:config:dialback'>
<legacy/>
<ip port='5269'/>
<karma>
<init>50</init>
<max>50</max>
<inc>4</inc>
<dec>1</dec>
<penalty>-5</penalty>
<restore>50</restore>
</karma>
</dialback></xdb>
Thu May 3 11:52:48 2001 mio.c:1120 io_select to listen on 5269 [(null)]
547:pth_lib.c:0443: pth_yield: enter from thread "main"
547:pth_lib.c:0462: pth_yield: give up control to scheduler in favour of
thread "unknown"
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x17eb30
("main")
547:pth_sched.c:0256: pth_scheduler: thread "main" ran 0.013371
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0189: pth_scheduler: new thread
"main.child@988915968=0x17eb30" moved to top of ready queue
547:pth_sched.c:0206: pth_scheduler: thread
"main.child@988915968=0x17eb30" selected (prio=0, qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x1a5a90
("main.child@988915968=0x17eb30")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
547:pth_high.c:0555: pth_write_ev: enter from thread
"main.child@988915968=0x17eb30"
Thu May 3 11:52:48 2001 dnsrv.c:147 DNSRV CHILD: Read from buffer:
<stream>
547:pth_high.c:0628: pth_write_ev: leave to thread
"main.child@988915968=0x17eb30"
547:pth_high.c:0490: pth_read_ev: enter from thread
"main.child@988915968=0x17eb30"
547:pth_high.c:0532: pth_read_ev: leave to thread
"main.child@988915968=0x17eb30"
547:pth_high.c:0490: pth_read_ev: enter from thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0388: pth_wait: enter from thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0394: pth_wait: waiting on event 0x219880
547:pth_lib.c:0443: pth_yield: enter from thread
"main.child@988915968=0x17eb30"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x1a5a90
("main.child@988915968=0x17eb30")
547:pth_sched.c:0256: pth_scheduler: thread
"main.child@988915968=0x17eb30" ran 0.005230
547:pth_sched.c:0338: pth_scheduler: moving thread
"main.child@988915968=0x17eb30" to waiting queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
Thu May 3 11:52:48 2001 mio.c:596 pth_select_ev waiting !!
547:pth_high.c:0159: pth_select_ev: called from thread "unknown"
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x1836f0
547:pth_event.c:0394: pth_wait: waiting on event 0x185120
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.003308
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0708: pth_sched_eventmanager: [signal] event occurred
for thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "main" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eb30
("main")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "main"
Thu May 3 11:52:48 2001 mio.c:1144 io_select starting to listen on
5269 [(null)]
547:pth_msg.c:0136: return 0x0 with errno 22("Invalid argument")
547:pth_event.c:0388: pth_wait: enter from thread "main"
547:pth_event.c:0394: pth_wait: waiting on event 0x1a69a0
547:pth_lib.c:0443: pth_yield: enter from thread "main"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
[...CRUNCH...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.000338
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in waiting mode
547:pth_sched.c:0633: pth_sched_eventmanager: [timeout] event occurred
for thread "main.child@988915968=0x17eb30"
547:pth_sched.c:0760: pth_sched_eventmanager: thread
"main.child@988915968=0x17eb30" moved from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread
"main.child@988915968=0x17eb30" selected (prio=0, qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
("main.child@988915968=0x17eb30")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
547:pth_event.c:0422: pth_wait: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0388: pth_wait: enter from thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0394: pth_wait: waiting on event 0x18a4c0
547:pth_lib.c:0443: pth_yield: enter from thread
"main.child@988915968=0x17eb30"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x17eee0
("main.child@988915968=0x17eb30")
547:pth_sched.c:0256: pth_scheduler: thread
"main.child@988915968=0x17eb30" ran 0.002490
547:pth_sched.c:0338: pth_scheduler: moving thread
"main.child@988915968=0x17eb30" to waiting queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in waiting mode
547:pth_sched.c:0633: pth_sched_eventmanager: [timeout] event occurred
for thread "main.child@988915968=0x17eb30"
547:pth_sched.c:0760: pth_sched_eventmanager: thread
"main.child@988915968=0x17eb30" moved from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread
"main.child@988915968=0x17eb30" selected (prio=0, qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
("main.child@988915968=0x17eb30")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
547:pth_event.c:0422: pth_wait: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0388: pth_wait: enter from thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0394: pth_wait: waiting on event 0x18a4c0
547:pth_lib.c:0443: pth_yield: enter from thread
"main.child@988915968=0x17eb30"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x17eee0
("main.child@988915968=0x17eb30")
547:pth_sched.c:0256: pth_scheduler: thread
"main.child@988915968=0x17eb30" ran 0.003113
547:pth_sched.c:0338: pth_scheduler: moving thread
"main.child@988915968=0x17eb30" to waiting queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in waiting mode
547:pth_sched.c:0697: pth_sched_eventmanager: [I/O] event occurred for
thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
[...CRUNCH...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
Thu May 3 11:52:51 2001 mio.c:368 _mio_accept calling accept on fd #5
547:pth_high.c:0436: pth_accept_ev: enter from thread "unknown"
547:pth_high.c:0470: pth_accept_ev: leave to thread "unknown"
Thu May 3 11:52:51 2001 mio.c:395 new socket accepted (fd: 11, ip:
192.168.168.50, port: 49293)
547:pth_lib.c:0299: return 0x0 with errno 22("Invalid argument")
Thu May 3 11:52:51 2001 mio.c:596 pth_select_ev waiting !!
547:pth_high.c:0159: pth_select_ev: called from thread "unknown"
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x1836f0
547:pth_event.c:0394: pth_wait: waiting on event 0x185120
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.005843
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in waiting mode
547:pth_sched.c:0633: pth_sched_eventmanager: [timeout] event occurred
for thread "main.child@988915968=0x17eb30"
547:pth_sched.c:0760: pth_sched_eventmanager: thread
"main.child@988915968=0x17eb30" moved from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread
"main.child@988915968=0x17eb30" selected (prio=0, qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
("main.child@988915968=0x17eb30")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
547:pth_event.c:0422: pth_wait: leave to thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0388: pth_wait: enter from thread
"main.child@988915968=0x17eb30"
547:pth_event.c:0394: pth_wait: waiting on event 0x18a4c0
547:pth_lib.c:0443: pth_yield: enter from thread
"main.child@988915968=0x17eb30"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x17eee0
("main.child@988915968=0x17eb30")
547:pth_sched.c:0256: pth_scheduler: thread
"main.child@988915968=0x17eb30" ran 0.003442
547:pth_sched.c:0338: pth_scheduler: moving thread
"main.child@988915968=0x17eb30" to waiting queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in waiting mode
547:pth_sched.c:0697: pth_sched_eventmanager: [I/O] event occurred for
thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_event.c:0417: pth_wait: occurred event 0x1836f0
547:pth_event.c:0417: pth_wait: occurred event 0x185120
547:pth_event.c:0422: pth_wait: leave to thread "unknown"
Thu May 3 11:52:52 2001 mio.c:599 pth_select_ev end waiting
(receiving) !!
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.002912
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_high.c:0490: pth_read_ev: enter from thread "unknown"
547:pth_high.c:0532: pth_read_ev: leave to thread "unknown"
Thu May 3 11:52:52 2001 mio.c:701 MIO read from socket 11: <?xml
version="1.0"?><stream:stream to="coolserver"
xmlns:stream="http://etherx.jabber.org/streams"; xmlns="jabber:client">
Thu May 3 11:52:52 2001 client.c:243 pthsock_client_read called with:
m:1A6A40 flag:2 arg:1A6B50
Thu May 3 11:52:52 2001 client.c:276 root received for 11
Thu May 3 11:52:52 2001 mio.c:911 mio_write called on x: 0 buffer:
Thu May 3 11:52:52 2001 mio.c:976 pth_raise SIGUSR2 !!
547:pth_lib.c:0299: return 0x0 with errno 22("Invalid argument")
Thu May 3 11:52:52 2001 mio.c:268 write_dump writing data: <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' id='3AF1A904'
xmlns='jabber:client' from='coolserver'>
547:pth_high.c:0555: pth_write_ev: enter from thread "unknown"
547:pth_high.c:0628: pth_write_ev: leave to thread "unknown"
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
[...CRUNCH...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
Thu May 3 11:52:52 2001 mio.c:596 pth_select_ev waiting !!
547:pth_high.c:0159: pth_select_ev: called from thread "unknown"
Thu May 3 11:52:52 2001 mio.c:599 pth_select_ev end waiting
(receiving) !!
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.000356
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_high.c:0490: pth_read_ev: enter from thread "unknown"
547:pth_high.c:0532: pth_read_ev: leave to thread "unknown"
Thu May 3 11:52:52 2001 mio.c:701 MIO read from socket 11:
<iq id="011" type="set">
<query xmlns="jabber:iq:auth">
<username>slunati</username>
<password>password</password>
<resource>test</resource>
</query>
</iq>
Thu May 3 11:52:52 2001 client.c:243 pthsock_client_read called with:
m:1A6A40 flag:3 arg:1A6B50
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 4:coolserver <route
type='auth' to='slunati@coolserver/test' from='11@c2s/1A6A40'><iq
id='011' type='set'>
<query xmlns='jabber:iq:auth'>
<username>slunati</username>
<password>password</password>
<resource>test</resource>
</query>
</iq></route>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'sessions'
Thu May 3 11:52:52 2001 deliver.c:83 (1951D0)incoming packet <route
type='auth' to='slunati@coolserver/test' from='11@c2s/1A6A40'><iq
id='011' type='set'>
<query xmlns='jabber:iq:auth'>
<username>slunati</username>
<password>password</password>
<resource>test</resource>
</query>
</iq></route>
Thu May 3 11:52:52 2001 util.c:92 config query maxusers
Thu May 3 11:52:52 2001 deliver.c:89 creating user hash 24A000 for
coolserver
Thu May 3 11:52:52 2001 deliver.c:91 checking 24A000
Thu May 3 11:52:52 2001 util.c:92 config query auth
547:pth_lib.c:0192: pth_spawn: enter
547:pth_mctx.c:0247: pth_mctx_set: enter
547:pth_mctx.c:0391: pth_mctx_set_trampoline: return to caller
547:pth_mctx.c:0395: pth_mctx_set_trampoline: reentered from caller
547:pth_mctx.c:0433: pth_mctx_set_trampoline_jumpin: switch back to
caller
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0363: pth_mctx_set: leave
547:pth_lib.c:0280: pth_spawn: leave
547:pth_lib.c:0192: pth_spawn: enter
547:pth_mctx.c:0247: pth_mctx_set: enter
547:pth_mctx.c:0391: pth_mctx_set_trampoline: return to caller
547:pth_mctx.c:0395: pth_mctx_set_trampoline: reentered from caller
547:pth_mctx.c:0433: pth_mctx_set_trampoline_jumpin: switch back to
caller
==== THREAD CONTEXT SWITCH ===========================================
[... CRUNCH : 8 repetitions of apparently the same log as above...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0363: pth_mctx_set: leave
547:pth_lib.c:0280: pth_spawn: leave
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.064945
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0189: pth_scheduler: new thread "unknown" moved to top
of ready queue
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=5,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x21ca40
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
Thu May 3 11:52:52 2001 mtq 21CA40 starting
Thu May 3 11:52:52 2001 mtq 21CA40 leaving to pth
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x21b4a0
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x21ca40
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.003278
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0560: pth_sched_eventmanager: [non-I/O] event occurred
for thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=5,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x21ce60
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
Thu May 3 11:52:52 2001 mtq 21CE60 starting
Thu May 3 11:52:52 2001 mtq 21CE60 leaving to pth
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x21b4d0
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x21ce60
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.003280
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=5,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x21d280
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
Thu May 3 11:52:52 2001 mtq 21D280 starting
Thu May 3 11:52:52 2001 mtq 21D280 leaving to pth
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x21f430
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x21d280
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.000379
547:pth_sched.c:0338: pth_scheduler: moving thread "unknown" to waiting
queue
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=5,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x21d6a0
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_mctx.c:0440: pth_mctx_set_trampoline_jumpin: reentered from
scheduler
Thu May 3 11:52:52 2001 mtq 21D6A0 starting
Thu May 3 11:52:52 2001 mtq 21D6A0 leaving to pth
547:pth_event.c:0388: pth_wait: enter from thread "unknown"
547:pth_event.c:0394: pth_wait: waiting on event 0x21f460
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
[...CRUNCH...]
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_event.c:0417: pth_wait: occurred event 0x21b4a0
547:pth_event.c:0422: pth_wait: leave to thread "unknown"
Thu May 3 11:52:52 2001 mtq 21CA40 entering from pth
Thu May 3 11:52:52 2001 mtq 21CA40 one call 21B068
Thu May 3 11:52:52 2001 authreg.c:52 auth request
Thu May 3 11:52:52 2001 users.c:137 js_user(slunati@coolserver,24A000)
Thu May 3 11:52:52 2001 users.c:144 js_user not current
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 2:coolserver <xdb
type='get' to='slunati@coolserver' from='sessions' ns='jabber:iq:auth'
id='1'/>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'xdb'
Thu May 3 11:52:52 2001 xdb_file.c:161 handling xdb request <xdb
type='get' to='slunati@coolserver' from='sessions' ns='jabber:iq:auth'
id='1'/>
Thu May 3 11:52:52 2001 xdb_file.c:98 loading
spool/coolserver/slunati.xml
Thu May 3 11:52:52 2001 xdb_file.c:118 caching
spool/coolserver/slunati.xml
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 1:sessions <xdb
type='result' to='sessions' from='slunati@coolserver'
ns='jabber:iq:auth' id='1'><password
xmlns='jabber:iq:auth'>password</password></xdb>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'sessions'
Thu May 3 11:52:52 2001 xdb.c:41 xdb_results checking xdb packet <xdb
type='result' to='sessions' from='slunati@coolserver'
ns='jabber:iq:auth' id='1'><password
xmlns='jabber:iq:auth'>password</password></xdb>
Thu May 3 11:52:52 2001 users.c:162 js_user debug 21F540 21F540
Thu May 3 11:52:52 2001 modules.c:124 mapi_call 5
Thu May 3 11:52:52 2001 modules.c:147 MAPI 19A450
Thu May 3 11:52:52 2001 mod_auth_plain checking
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 2:coolserver <xdb
type='get' to='slunati@coolserver' from='sessions' ns='jabber:iq:auth'
id='2'/>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'xdb'
Thu May 3 11:52:52 2001 xdb_file.c:161 handling xdb request <xdb
type='get' to='slunati@coolserver' from='sessions' ns='jabber:iq:auth'
id='2'/>
Thu May 3 11:52:52 2001 xdb_file.c:98 loading
spool/coolserver/slunati.xml
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 1:sessions <xdb
type='result' to='sessions' from='slunati@coolserver'
ns='jabber:iq:auth' id='2'><password
xmlns='jabber:iq:auth'>password</password></xdb>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'sessions'
Thu May 3 11:52:52 2001 xdb.c:41 xdb_results checking xdb packet <xdb
type='result' to='sessions' from='slunati@coolserver'
ns='jabber:iq:auth' id='2'><password
xmlns='jabber:iq:auth'>password</password></xdb>
Thu May 3 11:52:52 2001 mod_auth_plain comparing password password
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 4:c2s <route
from='slunati@coolserver/test' to='11@c2s/1A6A40' type='auth'><iq
id='011' type='result'/></route>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'c2s'
Thu May 3 11:52:52 2001 client.c:148 C2S: slunati@coolserver/test has
an active session, delivering packet
Thu May 3 11:52:52 2001 client.c:164 auth for user successful
Thu May 3 11:52:52 2001 client.c:167 C2S requesting Session Start for
slunati@coolserver/test
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 4:coolserver <route
type='session' to='slunati@coolserver/test' from='11@c2s/1A6A40'/>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'sessions'
Thu May 3 11:52:52 2001 deliver.c:83 (1951D0)incoming packet <route
type='session' to='slunati@coolserver/test' from='11@c2s/1A6A40'/>
Thu May 3 11:52:52 2001 users.c:137 js_user(slunati@coolserver,24A000)
Thu May 3 11:52:52 2001 sessions.c:79 session_create
slunati@coolserver/test
Thu May 3 11:52:52 2001 mtq.c:78 MTQ(new)
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 4:c2s <route
type='session' to='11@c2s/1A6A40' from='slunati@coolserver/21FA40'/>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'c2s'
Thu May 3 11:52:52 2001 client.c:148 C2S: slunati@coolserver/21FA40
has an active session, delivering packet
Thu May 3 11:52:52 2001 log.c:175 <log type='record'
from='slunati@coolserver'>login ok 192.168.168.50 test</log>
Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 3:coolserver <log
type='record' from='slunati@coolserver'>login ok 192.168.168.50
test</log>
Thu May 3 11:52:52 2001 deliver.c:651 delivering to instance 'rlogger'
Thu May 3 11:52:52 2001 client.c:202 Writing packet to MIO: <iq
id='011' type='result'/>
Thu May 3 11:52:52 2001 mio.c:911 mio_write called on x: 219DB0
buffer: (null)
Thu May 3 11:52:52 2001 mio.c:976 pth_raise SIGUSR2 !!
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0462: pth_yield: give up control to scheduler in favour of
thread "unknown"
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x21ca40
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.060302
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
547:pth_sched.c:0560: pth_sched_eventmanager: [non-I/O] event occurred
for thread "unknown"
547:pth_sched.c:0760: pth_sched_eventmanager: thread "unknown" moved
from waiting to ready queue
547:pth_sched.c:0769: pth_sched_eventmanager: leaving
547:pth_sched.c:0206: pth_scheduler: thread "unknown" selected (prio=0,
qprio=0)
547:pth_sched.c:0231: pth_scheduler: switching to thread 0x181000
("unknown")
==== THREAD CONTEXT SWITCH ===========================================
547:pth_lib.c:0467: pth_yield: got back control from scheduler
547:pth_lib.c:0469: pth_yield: leave to thread "unknown"
547:pth_lib.c:0443: pth_yield: enter from thread "unknown"
547:pth_lib.c:0465: pth_yield: give up control to scheduler
==== THREAD CONTEXT SWITCH ===========================================
547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x181000
("unknown")
547:pth_sched.c:0256: pth_scheduler: thread "unknown" ran 0.000288
547:pth_sched.c:0399: pth_sched_eventmanager: enter in polling mode
Thu May 3 11:52:52 2001 dnsrv.c:143 dnsrv: Read error on coprocess(1):
1 Operation not permitted
Thu May 3 11:52:52 2001 dnsrv.c:157 DNSRV CHILD: out of loop.. exiting
normal
Thanks for any helps !
Stephane
_______________________________________________
jdev mailing list
[EMAIL PROTECTED]
http://mailman.jabber.org/listinfo/jdev
