[jadmin] Problem: jabberd/sm: couldn't load user, can't start session

Thu Oct 5 12:18:51 CDT 2006

I'm attempting to set up a private Jabber2 server 'version: jabberd  
sm 2.0s11' on my LAN. I've followed the configuration instructions  
from the website, using berkeley db as the  storage and ldap as the  
authentication.  I start it with sudo -u jabber /opt/local/bin/ 
jabberd -D.

When I try to connect to the server from a machine on the same LAN, I  
receive the following error:

Oct  5 11:45:58 vulcan jabberd/c2s[22366]: [9] [192.168.64.103,  
port=54937] connect
Oct  5 11:45:59 vulcan jabberd/c2s[22366]: [9] auth succeeded:  
username=frank, resource=iChat
Oct  5 11:45:59 vulcan jabberd/c2s[22366]: [9] requesting session:  
jid=frank at vulcan/iChat
Oct  5 11:45:59 vulcan jabberd/sm[22364]: created user: jid=frank at vulcan
Oct  5 11:45:59 vulcan jabberd/sm[22364]: couldn't load user, can't  
start session: jid=frank at vulcan/iChat
Oct  5 11:45:59 vulcan jabberd/c2s[22366]: [9] [192.168.64.103,  
port=54937] disconnect

It looks to me like the authentication succeeds, but there is then  
some problem establishing the session. There are no files being  
written to the bdb location, /opt/local/var/jabberd/db, but I don't  
know if that's normal at this stage.

The jabber user owns and can write to /opt/local/var/jabberd and all  
its subdirs.

I compiled jabberd with debug and looked through the copious output.  
I'll attach some lines that look suspicious around the time when I  
try to connect a client to the server.

What other information can I provide from the console output of  
jabberd in order to get some help on troubleshooting this problem?

Thanks,

Frank McPherson

C2S : sx (io.c:205) decoded read data (280 bytes): <route  
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s'  
from='vulcan'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ 
ns/session/1.0' sc:c2s='9' action='start' target='frank at vulcan/iChat'  
id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3' sc:failed='1'/></route>
C2S : sx (io.c:70) completed nad: <route xmlns='http:// 
jabberd.jabberstudio.org/ns/component/1.0' from='vulcan'  
to='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/ 
session/1.0' sc:failed='1'  
id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3' target='frank at vulcan/ 
iChat' action='start' sc:c2s='9'/></route>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:124) tag 7 event 6 data 0x302f40
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:369) queueing for write: <iq xmlns='jabber:client'  
id='iChat_1FB471F4' type='error'><error type='wait'  
code='500'><internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp- 
stanzas'/></error></iq>
C2S : sx (io.c:392) tag 9 event 1 data 0x0
C2S : Thu Oct  5 13:04:06 2006 c2s.c:38 want write
C2S : Thu Oct  5 13:04:06 2006 c2s.c:395 write action on fd 9
C2S : sx (io.c:293) 9 ready for writing
C2S : sx (io.c:251) encoding 170 bytes for writing: <iq  
xmlns='jabber:client' id='iChat_1FB471F4' type='error'><error  
type='wait' code='500'><internal-server-error  
xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:312) handing app 170 bytes to write
C2S : sx (io.c:313) tag 9 event 3 data 0x303340
C2S : Thu Oct  5 13:04:06 2006 c2s.c:104 writing to 9
ROUT: sx (io.c:159) 9 ready for reading
ROUT: sx (io.c:165) tag 9 event 2 data 0x303e40
ROUT: Thu Oct  5 13:04:06 2006 router.c:513 reading from 9
ROUT: Thu Oct  5 13:04:06 2006 router.c:571 read 266 bytes
ROUT: sx (io.c:181) passed 266 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (io.c:205) decoded read data (266 bytes): <route  
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'  
to='vulcan'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/ 
session/1.0' id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3'  
target='frank at vulcan/iChat' action='start' sc:c2s='9'/></route>
ROUT: sx (io.c:70) completed nad: <route xmlns='http:// 
jabberd.jabberstudio.org/ns/component/1.0' to='vulcan'  
from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/ 
session/1.0' sc:c2s='9' action='start' target='frank at vulcan/iChat'  
id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3'/></route>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:124) tag 9 event 6 data 0x301b60
ROUT: Thu Oct  5 13:04:06 2006 router.c:378 unicast route from c2s to  
vulcan
ROUT: Thu Oct  5 13:04:06 2006 router.c:412 writing route for  
'vulcan' to 127.0.0.1, port 50014
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:369) queueing for write: <route xmlns='http:// 
jabberd.jabberstudio.org/ns/component/1.0' to='vulcan'  
from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/ 
session/1.0' sc:c2s='9' action='start' target='frank at vulcan/iChat'  
id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3'/></route>
ROUT: sx (io.c:392) tag 10 event 1 data 0x0
ROUT: Thu Oct  5 13:04:06 2006 router.c:508 want write
ROUT: Thu Oct  5 13:04:06 2006 router.c:860 write action on fd 10
ROUT: sx (io.c:293) 10 ready for writing
ROUT: sx (io.c:251) encoding 266 bytes for writing: <route  
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='vulcan'  
from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/ 
session/1.0' sc:c2s='9' action='start' target='frank at vulcan/iChat'  
id='82ecbe8bceb185c56045f8c86b06cd4f3b1a95c3'/></route>