#1507 Backtrace in c2s module

Reporter tmolitor
Owner Zash
Created
Updated
Stars ★ (1)
Tags
  • Priority-Medium
  • Type-Defect
  • Status-Fixed
  • Milestone-0.11
  1. tmolitor on

    If the event "resource-bind" takes longer (due to modules loaded that may delay the completion of the event) the following sequence can trigger a backtrace: 1. Client connects and sends bind request 2. Same client or other client connects and binds to the same resource 3. The stream of (1) gets closed and the tcp connection dropped due to conflicting resource (default prosody config) 4. The resource-bind event returns and the backtrace occurs On a mobile device that changes its connectivity (wifi to mobile or vice versa) just after the bind request was send and thus reconnects can trigger this bug. Backtraces (mod_kwo_roster.lua delays the completion of the event via async wait() and done() while fetching the roster in the background via http, thus the timing): Mar 14 18:39:28 http error Traceback[http]: /usr/lib/prosody/modules/mod_c2s.lua:238: attempt to index field 'conn' (a nil value) stack traceback: /usr/lib/prosody/modules/mod_c2s.lua:238: in function 'handler' /usr/lib/prosody/util/async.lua:211: in function 'run' /usr/lib/prosody/util/async.lua:63: in function 'runner_continue' /usr/lib/prosody/util/async.lua:79: in function 'done' ...r/local/lib/prosody-modules.local/mod_kwo_roster.lua:256: in function 'cb' ...r/local/lib/prosody-modules.local/mod_kwo_roster.lua:240: in function 'cb' ...r/local/lib/prosody-modules.local/mod_kwo_roster.lua:174: in function <...r/local/lib/prosody-modules.local/mod_kwo_roster.lua:164> [C]: in function 'xpcall' /usr/lib/prosody/net/http.lua:104: in function 'callback' /usr/lib/prosody/net/http.lua:76: in function 'success_cb' /usr/lib/prosody/net/http/parser.lua:171: in function 'feed' /usr/lib/prosody/net/http.lua:86: in function 'reader' /usr/lib/prosody/net/http.lua:158: in function 'onincoming' /usr/lib/prosody/net/server_event.lua:641: in function </usr/lib/prosody/net/server_event.lua:590> [C]: in function 'loop' /usr/lib/prosody/net/server_event.lua:796: in function </usr/lib/prosody/net/server_event.lua:795> [C]: in function 'xpcall' /usr/bin/prosody:76: in function 'loop' /usr/bin/prosody:86: in main chunk [C]: ? Mar 14 18:39:28 http error Request '<nil>': error in callback: /usr/lib/prosody/modules/mod_c2s.lua:238: attempt to index field 'conn' (a nil value) Mar 14 18:39:28 general error Top-level error, please report: /usr/lib/prosody/net/http.lua:45: /usr/lib/prosody/modules/mod_c2s.lua:238: attempt to index field 'conn' (a nil value) stack traceback: [C]: in function 'error' /usr/lib/prosody/net/http.lua:45: in function </usr/lib/prosody/net/http.lua:41> (tail call): ? /usr/lib/prosody/net/http.lua:76: in function 'success_cb' /usr/lib/prosody/net/http/parser.lua:171: in function 'feed' /usr/lib/prosody/net/http.lua:86: in function 'reader' /usr/lib/prosody/net/http.lua:158: in function 'onincoming' /usr/lib/prosody/net/server_event.lua:641: in function </usr/lib/prosody/net/server_event.lua:590> [C]: in function 'loop' /usr/lib/prosody/net/server_event.lua:796: in function </usr/lib/prosody/net/server_event.lua:795> [C]: in function 'xpcall' /usr/bin/prosody:76: in function 'loop' /usr/bin/prosody:86: in main chunk [C]: ? Mar 14 18:39:28 general error stack traceback: [C]: in function 'loop' /usr/lib/prosody/net/server_event.lua:796: in function </usr/lib/prosody/net/server_event.lua:795> [C]: in function 'xpcall' /usr/bin/prosody:76: in function 'loop' /usr/bin/prosody:86: in main chunk [C]: ?

  2. Zash on

    Thanks for the report. It would be great if you could reduce your non-public code to something that can be used to reproduce

    Changes
    • tags Status-Accepted
  3. Thilo Molitor on

    This code should be the minimal version of the roster module...but it seems to be a timing issue (like the osser issue I posted) because it only happened once in over 2 weeks. local http = require "net.http"; local async = require "util.async"; function call_http(cb) local x = {headers = {}}; local ok, err = http.request( "https://www.example.org", x, function (data, code) cb(true); end ); if not ok then cb(false); end end module:hook("resource-bind", function(event) local wait, done = async.waiter(); call_http(function (ok) done(); end); module:log("debug", "Halting resource-bind event while waiting for http request"); wait(); module:log("debug", "Restarting resource-bind event"); end);

  4. Thilo Molitor on

    I think my patch in https://issues.prosody.im/1515 will solve this, too

  5. Zash on

    https://hg.prosody.im/0.11/rev/133e8ed291fe Thanks

    Changes
    • tags Milestone-0.11 Status-Fixed
    • owner Zash

New comment

Not published. Used for spam prevention and optional update notifications.