processone / ejabberd

Robust, Ubiquitous and Massively Scalable Messaging Platform (XMPP, MQTT, SIP Server)
https://www.process-one.net/en/ejabberd/
Other
6k stars 1.5k forks source link

ejabberd sends 'presence's', 'photo' element with no hash value, after user publishes a new avatar #4182

Closed cmeng-git closed 3 months ago

cmeng-git commented 3 months ago

Before creating a ticket, please consider if this should fit the discussion forum better.

Environment

Configuration (only if needed): grep -Ev '^$|^\s*#' ejabberd.yml

// ========== ejabberd v23.01; ejabberd.yml settings ======== //
  ## Convert all avatars posted by Android clients from WebP to JPEG
  ## mod_avatar:  # this module needs compile option --enable-graphics
  ##   convert:
  ##     webp: jpeg

  mod_vcard:
    db_type: sql
    search: false
  mod_vcard_xupdate:
    use_cache: true
    cache_size: 1000  # size of entries
    cache_life_time: 604800 # maximum life time of cached data e.g. 7 day=7*24*3600  

Errors from error.log/crash.log

No errors

Bug description

ejabberd server has been configured with mod_vcard_xupdate enabled. Per ejaberd online documentation, If this module is enabled, all the outgoing client presence stanzas get automatically the avatar hash on behalf of the client.

ejabberd's vard_xupdate works according under normal condition. However when a user publishes a new avatar, ejabberd behave as shown below; refer to aTalk logcat. a. After user published a new avatar b. ejabberd sends a presence stanza with photo element but without the photo hash.
c. This triggers aTalk to remove the user avatar from its cache.

This behaviour is not per XEP-0153: vCard-Based Avatars: 3.1 User Publishes Avatar i.e.

Example 3. User's Client Includes Avatar Hash in Presence Broadcast[¶](https://xmpp.org/extensions/xep-0153.html#example-3)
<presence from='juliet@capulet.com/balcony'>
  <x xmlns='vcard-temp:x:update'>
    <photo>01b87fcd030b72895ff8e88db57ec525450f000d</photo>
  </x>
</presence>

When user exits and re-logins to ejabberd server, aTalk sends the user \ status. It is found that ejabberd responses with a total of 4 \ stanzas, with 2 of them as \. The first two \ stanzas came in with only 2ms apart. This causes aTalk to request the new avatar twice.

aTalk is configure to allow sending of messages to itself, i.e. two entities. I am not sure if has caused ejabberd to send 2 \ stanza for the user. conversations does not allow sending messages to itself (or not configured?), ejaberd only send 2 \ stanzas, one of them is a \ stanza.

Any reason why ejabberd also send a delayed of the same \ stanza to the user on first login.

// ========== on aTalk update Vcard with photo ======== //
12:41:06.171  D  SENT (0): 
                 <iq id='NJ2GT-44' type='set'>
                   <vCard xmlns='vcard-temp'>
                     <PHOTO>
                       <BINVAL>
                         iVBORw0KGgoAAAANSUhEUgAA .... XnXHLtj70bRaCjYW8IBOMdSaAsIbjSa/9y882jGzYaicUCR6aPqVB3WvMa
                       </BINVAL>
                       <TYPE>
                         image/jpeg
                       </TYPE>
                     </PHOTO>
                   </vCard>
                 </iq>

12:41:14.776  D  RECV (0): 
                 <iq xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net' type='result' id='NJ2GT-44'/>                     

12:41:14.780  D  RECV (0): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='KAQ48-5'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='pXo+ozOv1jCza0GcntYYclQ5aNg='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo/>
                   </x>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>
12:41:14.782  E  Received vcard-temp: swan@atalk.sytes.net 9cfeedbe288834ebfa9497ecaa53cd6246bc3b59 ''

12:41:14.783  D  RECV (0): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='KAQ48-5'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='pXo+ozOv1jCza0GcntYYclQ5aNg='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo/>
                   </x>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>
12:41:14.786  E  Received vcard-temp: swan@atalk.sytes.net 9cfeedbe288834ebfa9497ecaa53cd6246bc3b59 ''

// ======== On user re-login ========= //
12:47:03.903  D  SENT (1): 
                 <presence id='ASZPF-6'>
                   <status/>
                   <priority>
                     30
                   </priority>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='i/QosNuYTO9lDz6/GUxZBJxCfKk='/>
                 </presence>

12:47:05.146  D  RECV (1): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='ASZPF-6'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='i/QosNuYTO9lDz6/GUxZBJxCfKk='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo>
                       9cfeedbe288834ebfa9497ecaa53cd6246bc3b59
                     </photo>
                   </x>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>
12:47:05.147  E  Received vcard-temp: swan@atalk.sytes.net null '9cfeedbe288834ebfa9497ecaa53cd6246bc3b59'

12:47:05.148  D  RECV (1): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='ASZPF-6'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='i/QosNuYTO9lDz6/GUxZBJxCfKk='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo>
                       9cfeedbe288834ebfa9497ecaa53cd6246bc3b59
                     </photo>
                   </x>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>
12:47:05.149  D  SENT (1): 
                 <iq to='swan@atalk.sytes.net' id='NJ2GT-69' type='get'>
                   <vCard xmlns='vcard-temp'/>
                 </iq>
12:47:05.150  E  Received vcard-temp: swan@atalk.sytes.net null '9cfeedbe288834ebfa9497ecaa53cd6246bc3b59'
12:47:05.152  D  SENT (1): 
                 <iq to='swan@atalk.sytes.net' id='NJ2GT-70' type='get'>
                   <vCard xmlns='vcard-temp'/>
                 </iq>

12:47:05.170  D  RECV (1): 
                 <iq xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net' type='result' id='NJ2GT-67'>
                   <vCard xmlns='vcard-temp'>
                     <PHOTO>
                       <BINVAL>
                          iVBORw0KGgoAAAANSUhEUgAAAGwAAABsCAIAAAAABMCaAAAAAXN.....9IyxAAAAABJRU5ErkJggg==
                       </BINVAL>
                       <TYPE>
                         image/jpeg
                       </TYPE>
                     </PHOTO>
                   </vCard>
                 </iq>
12:47:05.213  I  [226] org.jivesoftware.smackx.avatar.vcardavatar.packet.VCardTempXUpdate.setAvatarHash() Account avatar hash updated with (old => new): 
                 null
                 9cfeedbe288834ebfa9497ecaa53cd6246bc3b59                 

12:47:05.223  D  RECV (1): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='ASZPF-6'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='i/QosNuYTO9lDz6/GUxZBJxCfKk='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo>
                       9cfeedbe288834ebfa9497ecaa53cd6246bc3b59
                     </photo>
                   </x>
                   <delay from='swan@atalk.sytes.net/atalk-1ds79b5' stamp='2024-03-20T04:47:08.469396Z' xmlns='urn:xmpp:delay'/>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>

12:47:05.229  E  Received vcard-temp: swan@atalk.sytes.net 9cfeedbe288834ebfa9497ecaa53cd6246bc3b59 '9cfeedbe288834ebfa9497ecaa53cd6246bc3b59'

12:47:05.232  D  RECV (1): 
                 <presence xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net/atalk-1ds79b5' id='ASZPF-6'>
                   <c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='https://android.atalk.org' ver='i/QosNuYTO9lDz6/GUxZBJxCfKk='/>
                   <x xmlns='vcard-temp:x:update'>
                     <photo>
                       9cfeedbe288834ebfa9497ecaa53cd6246bc3b59
                     </photo>
                   </x>
                   <delay from='swan@atalk.sytes.net/atalk-1ds79b5' stamp='2024-03-20T04:47:08.469396Z' xmlns='urn:xmpp:delay'/>
                   <priority>
                     30
                   </priority>
                   <status/>
                 </presence>
12:47:05.237  E  Received vcard-temp: swan@atalk.sytes.net 9cfeedbe288834ebfa9497ecaa53cd6246bc3b59 '9cfeedbe288834ebfa9497ecaa53cd6246bc3b59'

12:47:05.672  D  RECV (1): 
                 <iq xml:lang='en-US' to='swan@atalk.sytes.net/atalk-1ds79b5' from='swan@atalk.sytes.net' type='result' id='NJ2GT-69'>
                   <vCard xmlns='vcard-temp'>
                     <PHOTO>
                       <BINVAL>
                         iVBORw0KGgoAAAANSUhEUgAAAGwAAAB....6o9IyxAAAAABJRU5ErkJggg==
                       </BINVAL>
                       <TYPE>
                         image/jpeg
                       </TYPE>
                     </PHOTO>
                   </vCard>
                 </iq>
prefiks commented 3 months ago

Thank you for that detailed report. I added commit c5437235f3942214a0122bee63ed44903e8be9ad which should fix this.