Re: Some users cannot connect after upgrade from 2.2.17 to 2.3.2

[Tomasz Sterna]

Dnia 2014-12-21, nie o godzinie 20:44 +0100, Eric Koldeweij pisze:
> Sun Dec 21 14:00:38 2014 c2s.c:439 pre-session packet, bye
> Sun Dec 21 14:00:38 2014 [notice] [20] packet sent before session
> start, closing stream

IIRC this is a buggy behavior of libpurple based clients (ie. Pidgin),
which start the session, but do not wait for session establishment and
send more packets immediately after.




-- 
Tomasz Sterna   :(){ :|:&};:
Instant Messaging Consultant   Open Source Developer 
http://abadcafe.pl/  http://xiaoka.com/portfolio



signature.asc
Description: This is a digitally signed message part

Some users cannot connect after upgrade from 2.2.17 to 2.3.2

[Eric Koldeweij]

Tomasz (and maybe others),

After an upgrade today from 2.2.17 to 2.3.2 a small number of users are 
unable to connect. The strange thing is that they seem to be thrown out 
AFTER they have authenticated correctly and the session has started. I 
have looked but I cannot see why it suddenly should not work any more.


Here is some more info:
I have built with experimental options disabled and superseded options 
enabled. (The last option was added because many other users could not 
connect either including myself using the latest Xabber on Android):


../configure --sysconfdir=/etc/jabberd --enable-mysql --enable-mio=epoll 
--enable-debug --enable-ssl --with-zlib --disable-experimental 
--enable-superseded


In SM the following is logged (one particular user is chosen):
Sun Dec 21 14:00:38 2014 [notice] session started: 
jid=xadvente...@jabber.no-sense.net/WippienIM3
Sun Dec 21 14:00:39 2014 [notice] session ended: 
jid=xadvente...@jabber.no-sense.net/WippienIM3
Sun Dec 21 14:00:39 2014 [notice] user unloaded 
jid=xadvente...@jabber.no-sense.net

So it seems the session is started but ended at the same second.

in c2s, with debugging on, I see the following:

[.]
Sun Dec 21 14:00:38 2014 [notice] [20] [, port=63359] connect
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 144 bytes
Sun Dec 21 14:00:38 2014 ack.c:30 hacking ack namespace decl onto stream 
header

Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 253 bytes written
Sun Dec 21 14:00:38 2014 bind.c:38 not auth'd, offering auth and register
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 278 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 51 bytes
Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 50 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 124 bytes
Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 3626 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 326 bytes
Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 59 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 218 bytes
Sun Dec 21 14:00:38 2014 ack.c:30 hacking ack namespace decl onto stream 
header

Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 330 bytes written
Sun Dec 21 14:00:38 2014 bind.c:38 not auth'd, offering auth and register
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 490 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from 20
Sun Dec 21 14:00:38 2014 c2s.c:106 read 170 bytes
Sun Dec 21 14:00:38 2014 main.c:437 sx sasl callback: get realm: realm 
is 'jabber.no-sense.net'
Sun Dec 21 14:00:38 2014 main.c:456 sx sasl callback: check pass 
(authnid=xadventerur, realm=jabber.no-sense.net)
Sun Dec 21 14:00:38 2014 authreg_mysql.c:109 prepared sql: SELECT 
`password` FROM `authreg` WHERE `username` = 'xadventerur' AND `realm` = 
'jabber.no-sense.net'

Sun Dec 21 14:00:38 2014 c2s.c:42 want write
Sun Dec 21 14:00:38 2014 c2s.c:561 write action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:144 writing to 20
Sun Dec 21 14:00:38 2014 c2s.c:148 122 bytes written
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:37 want read
Sun Dec 21 14:00:38 2014 c2s.c:547 read action on fd 20
Sun Dec 21 14:00:38 2014 c2s.c:47 reading from