[JDEV] [help] server dying/crashing after login... long log (sorry)
temas
temas at box5.net
Mon May 7 12:54:36 CDT 2001
Could we possibly see two things? The server log without any extras
(Sorry I'm used to reading it and then this with it), and the server
config.
--temas
On 04 May 2001 06:47:15 -0700, Stephane Lunati wrote:
> 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 at -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 at -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 at 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 at 988915968=0x17eb30" moved to top of ready queue
> 547:pth_sched.c:0206: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" selected (prio=0, qprio=0)
> 547:pth_sched.c:0231: pth_scheduler: switching to thread 0x1a5a90
> ("main.child at 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 at 988915968=0x17eb30" as dead
> 547:pth_lib.c:0393: pth_exit: switching from thread
> "main.child at 988915968=0x17eb30" to scheduler
> ==== THREAD CONTEXT SWITCH ===========================================
> 547:pth_sched.c:0247: pth_scheduler: cameback from thread 0x1a5a90
> ("main.child at 988915968=0x17eb30")
> 547:pth_sched.c:0256: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" ran 0.009513
> 547:pth_sched.c:0325: pth_scheduler: marking thread
> "main.child at 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 at -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 at -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 at 988915968=0x17eb30" moved to top of ready queue
> 547:pth_sched.c:0206: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" selected (prio=0, qprio=0)
> 547:pth_sched.c:0231: pth_scheduler: switching to thread 0x1a5a90
> ("main.child at 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 at 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 at 988915968=0x17eb30"
> 547:pth_high.c:0490: pth_read_ev: enter from thread
> "main.child at 988915968=0x17eb30"
> 547:pth_high.c:0532: pth_read_ev: leave to thread
> "main.child at 988915968=0x17eb30"
> 547:pth_high.c:0490: pth_read_ev: enter from thread
> "main.child at 988915968=0x17eb30"
> 547:pth_event.c:0388: pth_wait: enter from thread
> "main.child at 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 at 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 at 988915968=0x17eb30")
> 547:pth_sched.c:0256: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" ran 0.005230
> 547:pth_sched.c:0338: pth_scheduler: moving thread
> "main.child at 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 at 988915968=0x17eb30"
> 547:pth_sched.c:0760: pth_sched_eventmanager: thread
> "main.child at 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 at 988915968=0x17eb30" selected (prio=0, qprio=0)
> 547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
> ("main.child at 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 at 988915968=0x17eb30"
> 547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
> 547:pth_event.c:0422: pth_wait: leave to thread
> "main.child at 988915968=0x17eb30"
> 547:pth_event.c:0388: pth_wait: enter from thread
> "main.child at 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 at 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 at 988915968=0x17eb30")
> 547:pth_sched.c:0256: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" ran 0.002490
> 547:pth_sched.c:0338: pth_scheduler: moving thread
> "main.child at 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 at 988915968=0x17eb30"
> 547:pth_sched.c:0760: pth_sched_eventmanager: thread
> "main.child at 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 at 988915968=0x17eb30" selected (prio=0, qprio=0)
> 547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
> ("main.child at 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 at 988915968=0x17eb30"
> 547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
> 547:pth_event.c:0422: pth_wait: leave to thread
> "main.child at 988915968=0x17eb30"
> 547:pth_event.c:0388: pth_wait: enter from thread
> "main.child at 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 at 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 at 988915968=0x17eb30")
> 547:pth_sched.c:0256: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" ran 0.003113
> 547:pth_sched.c:0338: pth_scheduler: moving thread
> "main.child at 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 at 988915968=0x17eb30"
> 547:pth_sched.c:0760: pth_sched_eventmanager: thread
> "main.child at 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 at 988915968=0x17eb30" selected (prio=0, qprio=0)
> 547:pth_sched.c:0231: pth_scheduler: switching to thread 0x17eee0
> ("main.child at 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 at 988915968=0x17eb30"
> 547:pth_event.c:0417: pth_wait: occurred event 0x18a4c0
> 547:pth_event.c:0422: pth_wait: leave to thread
> "main.child at 988915968=0x17eb30"
> 547:pth_event.c:0388: pth_wait: enter from thread
> "main.child at 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 at 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 at 988915968=0x17eb30")
> 547:pth_sched.c:0256: pth_scheduler: thread
> "main.child at 988915968=0x17eb30" ran 0.003442
> 547:pth_sched.c:0338: pth_scheduler: moving thread
> "main.child at 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 at coolserver/test' from='11 at 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 at coolserver/test' from='11 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at coolserver/test' to='11 at 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 at 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 at coolserver/test
> Thu May 3 11:52:52 2001 deliver.c:460 DELIVER 4:coolserver <route
> type='session' to='slunati at coolserver/test' from='11 at 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 at coolserver/test' from='11 at c2s/1A6A40'/>
> Thu May 3 11:52:52 2001 users.c:137 js_user(slunati at coolserver,24A000)
> Thu May 3 11:52:52 2001 sessions.c:79 session_create
> slunati at 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 at c2s/1A6A40' from='slunati at 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 at coolserver/21FA40
> has an active session, delivering packet
> Thu May 3 11:52:52 2001 log.c:175 <log type='record'
> from='slunati at 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 at 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
> jdev at jabber.org
> http://mailman.jabber.org/listinfo/jdev
More information about the JDev
mailing list