Bug#386653: marked as done (jabberd2-ldap-mysql: Mysql connection failure in sm component when creating user)

[Debian Bug Tracking System]

Your message dated Sun, 03 Aug 2008 21:11:55 +0000
with message-id <[EMAIL PROTECTED]>
and subject line Bug#386653: fixed in jabberd2 2.2.1-1
has caused the Debian Bug report #386653,
regarding jabberd2-ldap-mysql: Mysql connection failure in sm component when 
creating user
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact [EMAIL PROTECTED]
immediately.)


-- 
386653: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=386653
Debian Bug Tracking System
Contact [EMAIL PROTECTED] with problems

--- Begin Message ---

Package: jabberd2-ldap-mysql
Version: 2.0s11-1
Severity: normal

I have the following packages installed:
ii  mysql-client-5.0    5.0.24-1       mysql database client binaries
ii  mysql-common        5.0.24-1       mysql database common files (e.g.
/etc/mysql
ii  mysql-server-5.0    5.0.24-1       mysql database server binaries
ii  jabberd2-ldap-mysql 2.0s11-1

My current configuration is..

Authentication is via ldap.  Sessions are saved to mysql.

Mysql is configured in the sm.  Sm connects to the mysql instance via
TCP socket on a network address.  Valid mysql user credentials are
defined in the config.  Transactions are enabled.

Session manager is configured to automatically create users using the
<auto-create/> directive.

When the sm service starts, no errors are generated..

==> /var/log/jabberd2/sm.log <==
Sat Sep  9 01:22:19 2006 [notice] starting up
Sat Sep  9 01:22:19 2006 [notice] id: yellowguppy.com
Sat Sep  9 01:22:19 2006 [info] process id is 22982, written to
/var/run/jabberd2/sm.pid
Sat Sep  9 01:22:19 2006 [notice] initialised storage driver 'mysql'
Sat Sep  9 01:22:19 2006 [notice] version: jabberd sm 2.0s11
Sat Sep  9 01:22:19 2006 [notice] attempting connection to router at
127.0.0.1, port=5347
Sat Sep  9 01:22:19 2006 [notice] connection to router established
Sat Sep  9 01:22:19 2006 [notice] ready for sessions

During the init, I can see the sm component connect to mysql through the
mysql logging which is enabled..

060909  1:22:19    1113 Connect     [EMAIL PROTECTED] on jabberd2

when i attempt to send a message the authentication is successful in the
c2s component but the sm component generates the following errors are
generated..

==> /var/log/jabberd2/sm.log <==
Fri Sep  8 23:36:21 2006 [error] mysql: connection to database lost
Fri Sep  8 23:36:21 2006 [error] mysql: connection to database lost
Fri Sep  8 23:36:21 2006 [error] mysql: connection to database lost
Fri Sep  8 23:36:21 2006 [notice] created user:
[EMAIL PROTECTED]
Fri Sep  8 23:36:21 2006 [error] mysql: connection to database lost
Fri Sep  8 23:36:21 2006 [notice] couldn't load user, can't start
session: [EMAIL PROTECTED]/DaemonMonitor

No additional mysql activity is logged via Mysql.  I ran the sm process
in debug mode through strace but I did not find any obvious errors.
Below is a subset of the strace.

time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 sess.c:"..., 87Fri Sep  8 02:38:00
2006 sess.c:105 session requested for [EMAIL PROTECTED]/Gaim) =
87
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:62"..., 61Fri Sep  8 02:38:00
2006 mm.c:624 dispatching user-load chain) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:63"..., 55Fri Sep  8 02:38:00
2006 mm.c:633 calling module active) = 55
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 storage"..., 108Fri Sep  8 02:38:00
2006 storage.c:270 storage_get: type=active
[EMAIL PROTECTED] filter=(null)) = 108
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 storage"..., 77Fri Sep  8 02:38:00
2006 storage.c:171 adding type 'active' to driver 'mysql') = 77
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [error]"..., 68) = 68
write(1, "Fri Sep  8 02:38:00 2006 [error]"..., 68Fri Sep  8 02:38:00
2006 [error] mysql: connection to database lost
) = 68
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:64"..., 61Fri Sep  8 02:38:00
2006 mm.c:640 user-load chain returning 1) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 user.c:"..., 88Fri Sep  8 02:38:00
2006 user.c:67 modules failed user load for [EMAIL PROTECTED]) =
88
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 sess.c:"..., 79Fri Sep  8 02:38:00
2006 sess.c:117 auto-creating user [EMAIL PROTECTED]) = 79
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 user.c:"..., 83Fri Sep  8 02:38:00
2006 user.c:91 create user request for [EMAIL PROTECTED]) = 83
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:62"..., 61Fri Sep  8 02:38:00
2006 mm.c:624 dispatching user-load chain) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:63"..., 55Fri Sep  8 02:38:00
2006 mm.c:633 calling module active) = 55
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 storage"..., 108Fri Sep  8 02:38:00
2006 storage.c:270 storage_get: type=active
[EMAIL PROTECTED] filter=(null)) = 108
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [error]"..., 68) = 68
write(1, "Fri Sep  8 02:38:00 2006 [error]"..., 68Fri Sep  8 02:38:00
2006 [error] mysql: connection to database lost
) = 68
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:64"..., 61Fri Sep  8 02:38:00
2006 mm.c:640 user-load chain returning 1) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 user.c:"..., 88Fri Sep  8 02:38:00
2006 user.c:67 modules failed user load for [EMAIL PROTECTED]) =
88
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:65"..., 63Fri Sep  8 02:38:00
2006 mm.c:651 dispatching user-create chain) = 63
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:66"..., 55Fri Sep  8 02:38:00
2006 mm.c:660 calling module active) = 55
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mod_act"..., 81Fri Sep  8 02:38:00
2006 mod_active.c:51 activating user [EMAIL PROTECTED]) = 81
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 object."..., 56Fri Sep  8 02:38:00
2006 object.c:85 creating new object) = 56
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 object."..., 87Fri Sep  8 02:38:00
2006 object.c:136 adding field time (val bffff4ac type 1) to object) =
87
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 storage"..., 105Fri Sep  8 02:38:00
2006 storage.c:244 storage_put: type=active
[EMAIL PROTECTED] os=80D0640) = 105
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [error]"..., 68) = 68
write(1, "Fri Sep  8 02:38:00 2006 [error]"..., 68Fri Sep  8 02:38:00
2006 [error] mysql: connection to database lost
) = 68
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:65"..., 86Fri Sep  8 02:38:00
2006 mm.c:656 module template-roster has no handler for this chain) = 86
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:66"..., 63Fri Sep  8 02:38:00
2006 mm.c:667 user-create chain returning 0) = 63
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [notice"..., 77) = 77
write(1, "Fri Sep  8 02:38:00 2006 [notice"..., 77Fri Sep  8 02:38:00
2006 [notice] created user: [EMAIL PROTECTED]
) = 77
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:62"..., 61Fri Sep  8 02:38:00
2006 mm.c:624 dispatching user-load chain) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:63"..., 55Fri Sep  8 02:38:00
2006 mm.c:633 calling module active) = 55
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 storage"..., 108Fri Sep  8 02:38:00
2006 storage.c:270 storage_get: type=active
[EMAIL PROTECTED] filter=(null)) = 108
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [error]"..., 68) = 68
write(1, "Fri Sep  8 02:38:00 2006 [error]"..., 68Fri Sep  8 02:38:00
2006 [error] mysql: connection to database lost
) = 68
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 mm.c:64"..., 61Fri Sep  8 02:38:00
2006 mm.c:640 user-load chain returning 1) = 61
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(2, "Fri Sep  8 02:38:00 2006 user.c:"..., 88Fri Sep  8 02:38:00
2006 user.c:67 modules failed user load for [EMAIL PROTECTED]) =
88
write(2, "\n", 1
)                       = 1
time(NULL)                              = 1157697480
write(3, "Fri Sep  8 02:38:00 2006 [notice"..., 109) = 109
write(1, "Fri Sep  8 02:38:00 2006 [notice"..., 109Fri Sep  8 02:38:00
2006 [notice] couldn't load user, can't start session:
[EMAIL PROTECTED]/Gaim
) = 109
write(2, "sx (chain.c:106) calling nad wri"..., 40sx (chain.c:106)
calling nad write chain) = 40
write(2, "\n", 1
)                       = 1

I have attempted to research this problem for a solution but haven't
come up with a solution.  There do not appear to be any related bugs in
Debian BTS or the Jabberd2 Bugzilla.

The following mysql document references the change in behavior after
5.0.3 which prevents an automatic reconnect without setting a specific
mysql option.  A possible cause?

http://dev.mysql.com/doc/refman/5.0/en/mysql-ping.html

The following is a reference to a similar sounding problem but in the
c2s component that was fixed.  Unfortunately, the patch doesn't appear
to be in bugzilla anymore.

http://mailman.jabber.org/pipermail/jadmin/2005-May/021240.html

The following is a possible patch which doesn't seem to be applied to
the current jabberd2 tree which may address this issue.

http://lists.pld-linux.org/mailman/pipermail/pld-cvs-commit/Week-of-Mon-20060213/092284.html

Any help would be appreciated?

-- System Information:
Debian Release: testing/unstable
  APT prefers testing
  APT policy: (990, 'testing'), (500, 'unstable'), (1, 'experimental')
Architecture: i386 (i686)
Shell:  /bin/sh linked to /bin/bash
Kernel: Linux 2.4.27-2-386
Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968)

Versions of packages jabberd2-ldap-mysql depends on:
ii  jabber-common                 0.4        Jabber server and transport (commo
ii  libc6                         2.3.6-13   GNU C Library: Shared libraries
ii  libidn11                      0.6.5-1    GNU libidn library, implementation
ii  libldap2                      2.1.30-13  OpenLDAP libraries
ii  libmysqlclient15off           5.0.24-1   mysql database client library
ii  libpam0g                      0.79-3.1   Pluggable Authentication Modules l
ii  libssl0.9.8                   0.9.8b-2   SSL shared libraries
ii  zlib1g                        1:1.2.3-13 compression library - runtime

jabberd2-ldap-mysql recommends no packages.

-- no debconf information

--- End Message ---

--- Begin Message ---

Source: jabberd2
Source-Version: 2.2.1-1

We believe that the bug you reported is fixed in the latest version of
jabberd2, which is due to be installed in the Debian FTP archive:

jabberd2_2.2.1-1.diff.gz
  to pool/main/j/jabberd2/jabberd2_2.2.1-1.diff.gz
jabberd2_2.2.1-1.dsc
  to pool/main/j/jabberd2/jabberd2_2.2.1-1.dsc
jabberd2_2.2.1-1_amd64.deb
  to pool/main/j/jabberd2/jabberd2_2.2.1-1_amd64.deb
jabberd2_2.2.1.orig.tar.gz
  to pool/main/j/jabberd2/jabberd2_2.2.1.orig.tar.gz



A summary of the changes between this version and the previous one is
attached.

Thank you for reporting the bug, which will now be closed.  If you
have further comments please address them to [EMAIL PROTECTED],
and the maintainer will reopen the bug report if appropriate.

Debian distribution maintenance software
pp.
Jorge Salamero Sanz <[EMAIL PROTECTED]> (supplier of updated jabberd2 package)

(This message was generated automatically at their request; if you
believe that there is a problem with it please contact the archive
administrators by mailing [EMAIL PROTECTED])


-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Format: 1.8
Date: Thu, 17 Jul 2008 12:38:05 +0200
Source: jabberd2
Binary: jabberd2
Architecture: source amd64
Version: 2.2.1-1
Distribution: unstable
Urgency: low
Maintainer: Jorge Salamero Sanz <[EMAIL PROTECTED]>
Changed-By: Jorge Salamero Sanz <[EMAIL PROTECTED]>
Description: 
 jabberd2   - Jabber instant messenger server
Closes: 245306 311170 324829 345212 357733 386653 386900 402498 403750 406459 
406460 409765 414152 440302
Changes: 
 jabberd2 (2.2.1-1) unstable; urgency=low
 .
   * New upstream release (Closes: #403750).
     + photo support in mod_iq_vcard included (Closes: #311170).
     + c2s no longer crashes when speaking ssl to the tls port
       (Closes: #245306).
   * Packaging is completly new almost from scratch:
     * Multiple binaries packages merged into a single binary with support for
       all databases and auth methods
       (Closes: #386900, #414152, #406459, #357733, #386653, #406460).
     * compat: updated to version 5.
     * control: no longer depends on jabber-common (Closes: #324829).
     * control: updated to libpq-dev (Closes: #409765).
     * control: built against libgsasl (Closes: #402498).
     * control: Homepage field.
     * copyright: completly new file.
     * default, [pre|post]scripts: daemons run as jabber:jabber
       (Closes: #440302).
     * dirs, docs: updated with minor changes.
     * init: updated to use LSB headers.
     * lintian-overrides: jabberd2 is licensed with the openssl exception.
     * logrotate: logs are rotated (Closes: #345212).
     * watch: new watch file with the new upstream authors.
     * patches:
       + change PKGNAME from jabberd to jabberd2.
       + change defaults paths to LSB compatible.
Checksums-Sha1: 
 e4a40399bdf15eff198e7bdc2d51f91dc2c522cc 1207 jabberd2_2.2.1-1.dsc
 eeac0126e3f697b452cef071093c633b373ccef3 832628 jabberd2_2.2.1.orig.tar.gz
 445de45d143cd297a438431c17608de21bffa011 8956 jabberd2_2.2.1-1.diff.gz
 10e8b8a9b8de732070bc03d2035b87722439f438 977348 jabberd2_2.2.1-1_amd64.deb
Checksums-Sha256: 
 71e11f941d0fca38d144301311ded9b02741570639b7078c897821c325097492 1207 
jabberd2_2.2.1-1.dsc
 794007e65753c28a4daaa161f093a9108e332c23dc526935bdd3db7e1ade4e44 832628 
jabberd2_2.2.1.orig.tar.gz
 9c38eb1ead2943f81e6bbd5094343a8aea51fc9b9ece69b5d5dabb05c5307ec4 8956 
jabberd2_2.2.1-1.diff.gz
 8d209fa66620db2ea00c5b3cf6d105a8dbec52f2fe72aa2232fb193b5a2aaa05 977348 
jabberd2_2.2.1-1_amd64.deb
Files: 
 dceb82ba6517407de3f8742e1625a392 1207 net optional jabberd2_2.2.1-1.dsc
 904b6b6c77138f87acd644fe80ccdb50 832628 net optional jabberd2_2.2.1.orig.tar.gz
 d2d9b21a07142355ce20a61fe382adaf 8956 net optional jabberd2_2.2.1-1.diff.gz
 241e49ad2bf61f13a63fefd0499c0334 977348 net optional jabberd2_2.2.1-1_amd64.deb

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)

iEYEARECAAYFAkh/ZXgACgkQWJqQNHDrD87znwCgyqxXyPLpvKTc2ZE0VfC1I39N
SccAoJgbsv8lJseB6vj84vwuAWvXByxm
=RjKf
-----END PGP SIGNATURE-----

--- End Message ---