Re: missing presence packet
In case anyone is wondering, I found my issue. On the servers where this was happening someone added a script to delete the roster right before the client is restarted. Our setup is used for m2m communication, so there are complicated reasons for why this was done... but all that to say that it wasn't an issue in the jabberd2 server :) Thanks for the help, -stepan - Original Message - From: "Stepan Salenikovich" <stepan.salenikov...@savoirfairelinux.com> To: "jabberd2" <jabberd2@lists.xiaoka.com> Sent: Tuesday, December 8, 2015 4:25:17 PM Subject: Re: missing presence packet > Have you tried running the query on the database itself to check the results? Yes, running the query on the databae directly gives the correct result. Howver, I have just noticed that a minute earlier in the log, this query works as it should as well (returning several rows, including the user(s) I expect to the receive the presence). Its only after user A logs back on that this query returns 0 rows. I'm looking at the log more to see what could have happened in between... I don't see any DELETEs on roter-items where user A is the collection-owner though... -stepan - Original Message - From: "Shawn Debnath" <sh...@debnath.net> To: "jabberd2" <jabberd2@lists.xiaoka.com> Sent: Tuesday, December 8, 2015 3:18:23 PM Subject: Re: missing presence packet Typically, the hyphen is a special character and the string containing it has to be escaped correctly. Also evident from the way “object-sequence” or the column names are escaped in the debug log. Have you tried running the query on the database itself to check the results? Googling for mysql specific escape character suggests usage of ‘`’ character. On 12/8/15, 12:01 PM, "Stepan Salenikovich" <stepan.salenikov...@savoirfairelinux.com> wrote: >Hi, >So I recompiled with --debug-enabled and ran with -D > >checking the sm debug log, it seems the issue is that when user A logs back >on, it's roster appears empty (ie: the mysql query returns with 0 items)... >however, when I perform that same query on the db myself, I get several items. >Heres the relevant log, the important query being "prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence`": > >Tue Dec 8 12:20:36 2015 sess.c:111 session requested for >a...@foo-bar.domain.com/resource-A >Tue Dec 8 12:20:36 2015 mm.c:663 dispatching user-load chain >Tue Dec 8 12:20:36 2015 mm.c:676 calling module active >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=active >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`active` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage_mysql.c:351 1 tuples returned >Tue Dec 8 12:20:36 2015 object.c:85 creating new object >Tue Dec 8 12:20:36 2015 storage_mysql.c:395 unknown field type 8, ignoring it >Tue Dec 8 12:20:36 2015 object.c:136 adding field time (val e1997bdc type 1) >to object >Tue Dec 8 12:20:36 2015 object.c:283 got field time (val 5667115d type 1) to >object >Tue Dec 8 12:20:36 2015 mm.c:676 calling module roster >Tue Dec 8 12:20:36 2015 mod_roster.c:744 loading roster for >a...@foo-bar.domain.com >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-items >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-groups >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-groups` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` > > >The only difference I've been able to find so far between this server and the >one on which the query works as it should, is that the jid of the user on the >working server is "a...@foo.domain.com" instead of >"a...@foo-bar.domain.com"... I don't know if there could be a bug in >mysql_query() causing it to not like value strings containing '-'... seems >unlikely... > >-stepan > >- Original Message - >From: "Tomasz Stern
Re: missing presence packet
Typically, the hyphen is a special character and the string containing it has to be escaped correctly. Also evident from the way “object-sequence” or the column names are escaped in the debug log. Have you tried running the query on the database itself to check the results? Googling for mysql specific escape character suggests usage of ‘`’ character. On 12/8/15, 12:01 PM, "Stepan Salenikovich" <stepan.salenikov...@savoirfairelinux.com> wrote: >Hi, >So I recompiled with --debug-enabled and ran with -D > >checking the sm debug log, it seems the issue is that when user A logs back >on, it's roster appears empty (ie: the mysql query returns with 0 items)... >however, when I perform that same query on the db myself, I get several items. >Heres the relevant log, the important query being "prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence`": > >Tue Dec 8 12:20:36 2015 sess.c:111 session requested for >a...@foo-bar.domain.com/resource-A >Tue Dec 8 12:20:36 2015 mm.c:663 dispatching user-load chain >Tue Dec 8 12:20:36 2015 mm.c:676 calling module active >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=active >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`active` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage_mysql.c:351 1 tuples returned >Tue Dec 8 12:20:36 2015 object.c:85 creating new object >Tue Dec 8 12:20:36 2015 storage_mysql.c:395 unknown field type 8, ignoring it >Tue Dec 8 12:20:36 2015 object.c:136 adding field time (val e1997bdc type 1) >to object >Tue Dec 8 12:20:36 2015 object.c:283 got field time (val 5667115d type 1) to >object >Tue Dec 8 12:20:36 2015 mm.c:676 calling module roster >Tue Dec 8 12:20:36 2015 mod_roster.c:744 loading roster for >a...@foo-bar.domain.com >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-items >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-groups >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-groups` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` > > >The only difference I've been able to find so far between this server and the >one on which the query works as it should, is that the jid of the user on the >working server is "a...@foo.domain.com" instead of >"a...@foo-bar.domain.com"... I don't know if there could be a bug in >mysql_query() causing it to not like value strings containing '-'... seems >unlikely... > >-stepan > >- Original Message - >From: "Tomasz Sterna" <to...@xiaoka.com> >To: "jabberd2" <jabberd2@lists.xiaoka.com> >Sent: Sunday, December 6, 2015 5:19:24 AM >Subject: Re: missing presence packet > >W dniu 04.12.2015, pią o godzinie 15∶05 -0500, użytkownik Stepan >Salenikovich napisał: >> So I'm looking for suggestions as to how this could be debuged... or >> any tips as to where to look. > >Turn on debug logs -D on both c2s and sm and analyse what happens when >A logs back on. > > >-- > /o__ >(_<^' I'm a soldier, not a diplomat. I can only tell the truth. > >
Re: missing presence packet
Hi, So I recompiled with --debug-enabled and ran with -D checking the sm debug log, it seems the issue is that when user A logs back on, it's roster appears empty (ie: the mysql query returns with 0 items)... however, when I perform that same query on the db myself, I get several items. Heres the relevant log, the important query being "prepared sql: SELECT * FROM `roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY `object-sequence`": Tue Dec 8 12:20:36 2015 sess.c:111 session requested for a...@foo-bar.domain.com/resource-A Tue Dec 8 12:20:36 2015 mm.c:663 dispatching user-load chain Tue Dec 8 12:20:36 2015 mm.c:676 calling module active Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=active owner=a...@foo-bar.domain.com filter=(null) Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: `collection-owner` = 'a...@foo-bar.domain.com' Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM `active` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY `object-sequence` Tue Dec 8 12:20:36 2015 storage_mysql.c:351 1 tuples returned Tue Dec 8 12:20:36 2015 object.c:85 creating new object Tue Dec 8 12:20:36 2015 storage_mysql.c:395 unknown field type 8, ignoring it Tue Dec 8 12:20:36 2015 object.c:136 adding field time (val e1997bdc type 1) to object Tue Dec 8 12:20:36 2015 object.c:283 got field time (val 5667115d type 1) to object Tue Dec 8 12:20:36 2015 mm.c:676 calling module roster Tue Dec 8 12:20:36 2015 mod_roster.c:744 loading roster for a...@foo-bar.domain.com Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-items owner=a...@foo-bar.domain.com filter=(null) Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: `collection-owner` = 'a...@foo-bar.domain.com' Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM `roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY `object-sequence` Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-groups owner=a...@foo-bar.domain.com filter=(null) Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: `collection-owner` = 'a...@foo-bar.domain.com' Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM `roster-groups` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY `object-sequence` The only difference I've been able to find so far between this server and the one on which the query works as it should, is that the jid of the user on the working server is "a...@foo.domain.com" instead of "a...@foo-bar.domain.com"... I don't know if there could be a bug in mysql_query() causing it to not like value strings containing '-'... seems unlikely... -stepan - Original Message - From: "Tomasz Sterna" <to...@xiaoka.com> To: "jabberd2" <jabberd2@lists.xiaoka.com> Sent: Sunday, December 6, 2015 5:19:24 AM Subject: Re: missing presence packet W dniu 04.12.2015, pią o godzinie 15∶05 -0500, użytkownik Stepan Salenikovich napisał: > So I'm looking for suggestions as to how this could be debuged... or > any tips as to where to look. Turn on debug logs -D on both c2s and sm and analyse what happens when A logs back on. -- /o__ (_<^' I'm a soldier, not a diplomat. I can only tell the truth.
Re: missing presence packet
> Have you tried running the query on the database itself to check the results? Yes, running the query on the databae directly gives the correct result. Howver, I have just noticed that a minute earlier in the log, this query works as it should as well (returning several rows, including the user(s) I expect to the receive the presence). Its only after user A logs back on that this query returns 0 rows. I'm looking at the log more to see what could have happened in between... I don't see any DELETEs on roter-items where user A is the collection-owner though... -stepan - Original Message - From: "Shawn Debnath" <sh...@debnath.net> To: "jabberd2" <jabberd2@lists.xiaoka.com> Sent: Tuesday, December 8, 2015 3:18:23 PM Subject: Re: missing presence packet Typically, the hyphen is a special character and the string containing it has to be escaped correctly. Also evident from the way “object-sequence” or the column names are escaped in the debug log. Have you tried running the query on the database itself to check the results? Googling for mysql specific escape character suggests usage of ‘`’ character. On 12/8/15, 12:01 PM, "Stepan Salenikovich" <stepan.salenikov...@savoirfairelinux.com> wrote: >Hi, >So I recompiled with --debug-enabled and ran with -D > >checking the sm debug log, it seems the issue is that when user A logs back >on, it's roster appears empty (ie: the mysql query returns with 0 items)... >however, when I perform that same query on the db myself, I get several items. >Heres the relevant log, the important query being "prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence`": > >Tue Dec 8 12:20:36 2015 sess.c:111 session requested for >a...@foo-bar.domain.com/resource-A >Tue Dec 8 12:20:36 2015 mm.c:663 dispatching user-load chain >Tue Dec 8 12:20:36 2015 mm.c:676 calling module active >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=active >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`active` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage_mysql.c:351 1 tuples returned >Tue Dec 8 12:20:36 2015 object.c:85 creating new object >Tue Dec 8 12:20:36 2015 storage_mysql.c:395 unknown field type 8, ignoring it >Tue Dec 8 12:20:36 2015 object.c:136 adding field time (val e1997bdc type 1) >to object >Tue Dec 8 12:20:36 2015 object.c:283 got field time (val 5667115d type 1) to >object >Tue Dec 8 12:20:36 2015 mm.c:676 calling module roster >Tue Dec 8 12:20:36 2015 mod_roster.c:744 loading roster for >a...@foo-bar.domain.com >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-items >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-items` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` >Tue Dec 8 12:20:36 2015 storage.c:224 storage_get: type=roster-groups >owner=a...@foo-bar.domain.com filter=(null) >Tue Dec 8 12:20:36 2015 storage_mysql.c:324 generated filter: >`collection-owner` = 'a...@foo-bar.domain.com' >Tue Dec 8 12:20:36 2015 storage_mysql.c:330 prepared sql: SELECT * FROM >`roster-groups` WHERE `collection-owner` = 'a...@foo-bar.domain.com' ORDER BY >`object-sequence` > > >The only difference I've been able to find so far between this server and the >one on which the query works as it should, is that the jid of the user on the >working server is "a...@foo.domain.com" instead of >"a...@foo-bar.domain.com"... I don't know if there could be a bug in >mysql_query() causing it to not like value strings containing '-'... seems >unlikely... > >-stepan > >- Original Message - >From: "Tomasz Sterna" <to...@xiaoka.com> >To: "jabberd2" <jabberd2@lists.xiaoka.com> >Sent: Sunday, December 6, 2015 5:19:24 AM >Subject: Re: missing presence packet > >W dniu 04.12.2015, pią o godzinie 15∶05 -0500, użytkownik Stepan >Salenikovich napisał: >> So I'm looking for suggestions as to how this could be debuged... or >> any tips as to where to look. > >Turn on debug logs -D on both c2s and sm and analyse what happens when >A logs back on. > > >-- > /o__ >(_<^' I'm a soldier, not a diplomat. I can only tell the truth. > >
Re: missing presence packet
W dniu 04.12.2015, pią o godzinie 15∶05 -0500, użytkownik Stepan Salenikovich napisał: > So I'm looking for suggestions as to how this could be debuged... or > any tips as to where to look. Turn on debug logs -D on both c2s and sm and analyse what happens when A logs back on. -- /o__ (_<^' I'm a soldier, not a diplomat. I can only tell the truth. signature.asc Description: This is a digitally signed message part
