#850 [mod_c2s] Traceback[c2s]: /usr/lib/prosody/util/stanza.lua:207: bad argument #1 to 's_gsub' (string expected, got boolean)

Reporter Siwei Luo
Owner MattJ
Created
Updated
Stars ★ (1)  
Tags
  • Priority-Medium
  • Type-Defect
  • Status-Fixed
  1. Siwei Luo on

    prosody is flooding the error log after service start. What steps will reproduce the problem? 1. start prosody What is the expected output? What do you see instead? mod_c2s error Traceback[c2s]: /usr/lib/prosody/util/stanza.lua:207: bad argument #1 to 's_gsub' (string expected, got boolean) stack traceback: [C]: in function 's_gsub' /usr/lib/prosody/util/stanza.lua:207: in function '_xml_escape' /usr/lib/prosody/util/stanza.lua:219: in function 'self' /usr/lib/prosody/util/stanza.lua:230: in function '_dostring' /usr/lib/prosody/util/stanza.lua:240: in function </usr/lib/prosody/util/stanza.lua:238> [C]: in function 'tostring' /usr/lib/prosody/core/sessionmanager.lua:39: in function 'send' /usr/lib/prosody/modules/mod_offline.lua:47: in function '?' /usr/lib/prosody/util/events.lua:78: in function </usr/lib/prosody/util/events.lua:74> (tail call): ? ... [C]: in function 'parse' /usr/lib/prosody/util/xmppstream.lua:271: in function 'feed' /usr/lib/prosody/modules/mod_c2s.lua:248: in function 'data' /usr/lib/prosody/modules/mod_c2s.lua:271: in function </usr/lib/prosody/modules/mod_c2s.lua:268> (tail call): ? /usr/lib/prosody/net/server_select.lua:879: in function </usr/lib/prosody/net/server_select.lua:861> [C]: in function 'xpcall' /usr/bin/prosody:396: in function 'loop' /usr/bin/prosody:427: in main chunk [C]: ? What version of the product are you using? On what operating system? prosody 0.10 nightly 361 # OS Debian 8 # Lua Lua 5.1 LuaFileSystem 1.6.2 LuaExpat 1.3.0 LuaSocket 3.0-rc1 ssl: 0.5.PR

  2. MattJ on

    Hi, thanks for the report! This looks like a corrupt message in the offline storage. When the user logs in, Prosody tries to deliver the message to them, but fails. If you temporarily enable debug logging, you should see in the logs just before the error which user is logging in. Then you can move out their store file from (probably) /var/lib/prosody/<encoded domain>/offline/<encoded username>.dat The file can be opened in a text editor, and will contain a representation of the message that Prosody is failing to load. If it does not contain any sensitive data, we would really appreciate it if you could email a copy to developers@prosody.im so that we can see what went wrong.

    Changes
    • owner MattJ
  3. sluo on

    Hi MattJ, thank you for your fast response. Unfortunately due to data privacy restrictions I cannot provide any files. /var/lib/prosody/<encoded domain>/offline/ does not contain any .dat but .list files. Those .list files contain cyrillic characters from time to time. Could that be a problem? Are there any special characters I should particularly look into? Thanks and best regards, Siwei

  4. Zash on

    Cyrillic characters should not be a problem. Can you tell how large the file is, and how many entries there are? The later can be found out by searching for lines that start with "item(".

  5. sluo on

    Largest .list file I found is around 863 KB and contains 658 entries with item({

  6. phil on

    Ran into the same issue. This error resulted in messages not being delivered anymore. There are no special characters, no other voodoo in the messages, they're plain ascii. I took a look at util/stanza.lua and found that in _dostring the table ("t") sometimes had a key/value pair of "id" and "true" (boolean). Dunno why, the id my jabber client sent was something like "308a8fac-5a66-431c-a013-ceb754eec8bd". Anyways: I changed the following line to make it work again: --- util/stanza.lua.orig +++ util/stanza.lua @@ -211,7 +211,7 @@ local function _dostring(t, buf, self, _ nsid = nsid + 1; t_insert(buf, " xmlns:ns"..nsid.."='".._xml_escape(ns).."' ".."ns"..nsid..":"..attrk.."='".._xml_escape(v).."'"); elseif not(k == "xmlns" and v == parentns) then - t_insert(buf, " "..k.."='".._xml_escape(v).."'"); + t_insert(buf, " "..k.."='".._xml_escape(tostring(v)).."'"); end end local len = #t;

  7. phil on

    as a side note: this patch helped to deliver the erroneous message, whatever this message was. Now that the client caught up with the offline storage, the error happens no longer.

  8. MattJ on

    Hi Phil, thanks for your comment. The patch you provided will indeed stop the traceback, but it will send erroneous data to the client. We need to figure out where the bad data is coming from, and fix it there. Tracking it down to the 'id' attribute helps a lot, thanks for that. Could you (both) share what modules you have loaded? Thanks!

  9. sluo on

    Hi Matt, this is our list: modules_enabled = { -- Modules added by our own "reload_modules"; "auto_activate_hosts"; -- Generally required "roster"; "saslauth"; "tls"; "dialback"; "disco"; "posix"; -- Not essential, but recommended "private"; "vcard"; --"compression"; -- Nice to have -- "legacyauth"; "version"; "uptime"; "time"; "ping"; "pep"; "register"; "adhoc"; -- Admin interfaces "admin_adhoc"; -- HTTP modules "http"; "http_files"; -- Other specific functionality --"bosh"; "announce"; "presence"; "mam"; "carbons"; "smacks"; "csi"; "throttle_presence"; "filter_chatstates"; "cloud_notify"; "proxy65"; "blocklist"; };

  10. Zash on

    Perhaps this was the reason (and fix) https://hg.prosody.im/0.10/rev/8e2446cdf6fa?

  11. phil on

    Hi MattJ, here's my list. Too bad I cannot reproduce this issue any longer after my "fix". modules_enabled = { "posix"; "groups"; "roster"; "saslauth"; "tls"; "admin_adhoc"; "bosh"; "bidi"; -- XEP-0288 bidirectional server-to-server connections -- "version"; -- XEP-0092 software version (server) -- "uptime"; -- XEP-0012 last activity (server) -- "register"; -- XEP-0077 in-band registration "time"; -- XEP-0202 entity time, XEP-0090 legacy entity time "delay"; -- XEP-0203 delayed delivery "ping"; -- XEP-0199 xmpp ping "dialback"; -- XEP-0220 server dialback "disco"; -- XEP-0030 service discovery "private"; -- XEP-0049 private xml storage "vcard"; -- XEP-0054 vcard-temp "pep"; -- XEP-0163 personal eventing protocol "pep_vcard_avatar"; -- XEP-0153 vcard-based avatars <-> XEP-0084 user avatar -- "archive"; -- XEP-0136 message archiving (depr'ed) "mam", -- XEP-0313 message archiving management "mam_archive", -- XEP-0136 message archiving "smacks"; -- XEP-0198 stream management "carbons"; -- XEP-0280 carbon copies "carbons_adhoc"; "carbons_copies"; "blocklist"; -- XEP-0191 blocking command "csi"; -- XEP-0352 client state indication "throttle_presence"; -- reqs. csi "filter_chatstates"; -- reqs. csi }; storage = "internal"; default_storage = "internal" storage = { archive2 = "sql"; } sql = { driver = "SQLite3", database = "prosody.sqlite3" }

  12. Zash on

    Pretty sure we figured out that these issues were caused by archive:append() returning the wrong thing in mod_storage_sql, and the previously mentioned commit fixed it. If you are affected you may need to delete or remove the broken part offline message store manually.

    Changes
    • tags Status-Fixed

New comment