Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Inconsistent pubsub behavior if last_item_cache is enabled #3335

Open
di72nn opened this issue Jul 21, 2020 · 0 comments
Open

Inconsistent pubsub behavior if last_item_cache is enabled #3335

di72nn opened this issue Jul 21, 2020 · 0 comments

Comments

@di72nn
Copy link
Contributor

di72nn commented Jul 21, 2020 •
edited
Loading

Environment

  • ejabberd version: 20.04
  • Erlang version: Erlang (SMP,ASYNC_THREADS,HIPE) (BEAM) emulator version 11.0
  • OS: Linux (Arch Linux)
  • Installed from: distro package

Configuration:

...
  mod_pubsub:
    db_type: sql
    access_createnode: pubsub_createnode
    ignore_pep_from_offline: false
    last_item_cache: true
    plugins:
      - flat
      - pep
    force_node_config:
      storage:bookmarks:
        access_model: whitelist
...

Errors from error.log/crash.log

No errors

Bug description

Disclaimer: I'm a complete noob in XMPP. The behavior described here may be caused by some mistake in my ejabberd setup - I can't bring myself to set up a new ejabberd instance just to test it.

If last_item_cache is set to true, pubsub seem to use cached value for headlines, but does not update values in DB. Direct queries (as opposed to headline messages) return values from DB (that do not match headlines).

The problem was initially discovered here.

Lengthy details

Value in DB (for the particular PEP node select * from pubsub_item where nodeid = 12;):

itemid publisher creation modification payload
current [email protected]/laptop 001595:328942:525615 001595:329296:110683 <list xmlns='eu.siacs.conversations.axolotl'><device id='542020432'/><device id='820461778'/><device id='578605933'/></list>
  1. Start ejabberd.
  2. Connect using Gajim with XML Console open. Observe the expected message:
<!-- Incoming 2020-07-21T16:06:09 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>
  1. Manually send get request and observe the same result:
<!-- Outgoing 2020-07-21T16:07:25 +04 ([email protected]) -->
<iq type="get" to="[email protected]" id="items1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" />
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:07:25 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="items1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>
  1. Manually publish updated value and observer updated headlines:
<!-- Outgoing 2020-07-21T16:08:38 +04 ([email protected]) -->
<iq type="set" to="[email protected]" id="update1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <publish node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</publish>
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:08:38 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>

<!-- Incoming 2020-07-21T16:08:38 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="update1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <publish node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current" />
</publish>
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:08:38 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>
  1. Query it again and observe outdated value:
<!-- Outgoing 2020-07-21T16:10:31 +04 ([email protected]) -->
<iq type="get" to="[email protected]" id="items1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" />
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:10:32 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="items1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>
  1. Restart Gajim and connect, observe inconsistent results:
<!-- Outgoing 2020-07-21T16:13:00 +04 ([email protected]) -->
<iq xmlns="jabber:client" to="[email protected]" type="get" id="7a8611de-bb3d-4637-a61c-ea55a390fd3b">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" max_items="1" />
  </pubsub>
</iq>

<!-- Incoming 2020-07-21T16:13:00 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>

<!-- Incoming 2020-07-21T16:13:00 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="7a8611de-bb3d-4637-a61c-ea55a390fd3b">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <set xmlns="http://jabber.org/protocol/rsm">
      <count>1</count>
      <first index="0">2020-07-21T10:55:42.525615Z</first>
      <last>2020-07-21T10:55:42.525615Z</last>
</set>
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>
  1. Stop ejabberd. The value in the DB is not updated.
  2. Set last_item_cache to false, start ejabberd.
  3. Connect using Gajim, observe old value in headline:
<!-- Incoming 2020-07-21T16:33:56 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>
  1. Manually query the value, observe expected result:
<!-- Outgoing 2020-07-21T16:35:15 +04 ([email protected]) -->
<iq type="get" to="[email protected]" id="items1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" />
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:35:15 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="items1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="820461778" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>
  1. Manually update the value, observe correct result:
<!-- Outgoing 2020-07-21T16:36:42 +04 ([email protected]) -->
<iq type="set" to="[email protected]" id="update1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <publish node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</publish>
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:36:42 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>

<!-- Incoming 2020-07-21T16:36:42 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="update1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <publish node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current" />
</publish>
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:36:42 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>
  1. Manually query, observe correct result:
<!-- Outgoing 2020-07-21T16:38:38 +04 ([email protected]) -->
<iq type="get" to="[email protected]" id="items1" xmlns="jabber:client">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" />
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:38:38 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="items1">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>

The DB value is updated too:

itemid publisher creation modification payload
current [email protected]/desktop 001595:328942:525615 001595:335002:831753 <list xmlns='eu.siacs.conversations.axolotl'> <device id='542020432'/> <device id='578605933'/> </list>
  1. Reconnect Gajim, observe correct headline:
<!-- Incoming 2020-07-21T16:42:08 +04 ([email protected]) -->
<message xmlns="jabber:client" to="[email protected]/desktop" from="[email protected]" type="headline">
  <event xmlns="http://jabber.org/protocol/pubsub#event">
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</event>
  <addresses xmlns="http://jabber.org/protocol/address">
    <address jid="[email protected]/desktop" type="replyto" />
</addresses>
</message>
  1. Manual query:
<!-- Outgoing 2020-07-21T16:44:10 +04 ([email protected]) -->
<iq xmlns="jabber:client" to="[email protected]" type="get" id="itemsnew">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="eu.siacs.conversations.axolotl.devicelist" max_items="1" />
</pubsub>
</iq>

<!-- Incoming 2020-07-21T16:44:10 +04 ([email protected]) -->
<iq xmlns="jabber:client" xml:lang="en" to="[email protected]/desktop" from="[email protected]" type="result" id="itemsnew">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <set xmlns="http://jabber.org/protocol/rsm">
      <count>1</count>
      <first index="0">2020-07-21T10:55:42.525615Z</first>
      <last>2020-07-21T10:55:42.525615Z</last>
</set>
    <items node="eu.siacs.conversations.axolotl.devicelist">
      <item id="current">
        <list xmlns="eu.siacs.conversations.axolotl">
          <device id="542020432" />
          <device id="578605933" />
</list>
</item>
</items>
</pubsub>
</iq>

I also noticed that pubsub_node_option.persist_items in the DB is set to false for the particular node, but I don't know whether it is relevant.

Update: possibly was caused by the thing discussed here. I don't have time to retest at the moment.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@di72nn