WebWrangler: transient error showing promise is nil

[noahgibbs]

In a PR that only changed comments, got a test failure (see below.) Got error logs (attached) but they don't have an obvious smoking gun.

Error occured: /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/web_wrangler.rb:657:in `promise_redraw': undefined method `on_fulfilled' for nil:NilClass (NoMethodError)

      promise.on_fulfilled do
             ^^^^^^^^^^^^^
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/web_wrangler.rb:592:in `request_replace'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/web_wrangler.rb:443:in `replace'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/app.rb:103:in `request_redraw!'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/app.rb:45:in `block in init'
	from /Users/runner/work/scarpe/scarpe/vendor/bundle/ruby/3.2.0/gems/webview_ruby-0.1.2/lib/webview_ruby.rb:64:in `block in bind'
	from /Users/runner/work/scarpe/scarpe/vendor/bundle/ruby/3.2.0/gems/webview_ruby-0.1.2/lib/webview_ruby.rb:45:in `webview_run'
	from /Users/runner/work/scarpe/scarpe/vendor/bundle/ruby/3.2.0/gems/webview_ruby-0.1.2/lib/webview_ruby.rb:45:in `run'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/log.rb:60:in `block in method_missing'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/log.rb:64:in `method_missing'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/web_wrangler.rb:[39](https://github.com/scarpe-team/scarpe/actions/runs/7183897947/job/19563703953#step:7:40)0:in `run'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/app.rb:66:in `run'
	from /Users/runner/work/scarpe/scarpe/lib/scarpe/wv/app.rb:35:in `block in initialize'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/display_service.rb:71:in `block in dispatch_event'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/display_service.rb:71:in `each'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/display_service.rb:71:in `dispatch_event'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/display_service.rb:185:in `send_shoes_event'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes/app.rb:187:in `run'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:92:in `app'
	from /Users/runner/work/scarpe/scarpe/examples/legacy/working/shoes_manual/save_download.rb:2:in `<top (required)>'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:127:in `load'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:127:in `block in default_file_loaders'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:113:in `block in run_app'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:112:in `each'
	from /Users/runner/work/scarpe/scarpe/lacci/lib/shoes.rb:112:in `run_app'
	from /Users/runner/work/scarpe/scarpe/exe/scarpe:80:in `<main>'
. 

 Going to terminate
  test_webview_calzini_examples_legacy_working_shoes_manual_save_downloadERROR (1.80s)

test failure logs.zip

The code in web_wrangler.rb from the backtrace looks like schedule_waiting_changes must be returning nil:

      @log.debug("Requesting redraw with #{@waiting_changes.size} waiting changes - scheduling a new redraw for them!")
      promise = schedule_waiting_changes # This clears the waiting changes
      @pending_redraw_promise = promise

      promise.on_fulfilled do                        # This is the failing line
        @redraw_handlers.each(&:call)
        @pending_redraw_promise = nil

That's odd because schedule_waiting_changes should only ever return nil if there are no waiting changes.

Here's a log excerpt:

[1018] DEBUG Webview::WebWrangler::DOMWrangler: Requesting redraw with 1 waiting changes - scheduling a new redraw for them!
[1020] INFO  WebviewAPI: Method: eval Args: ["(function() {\n  var code_string = \"document.getElementById('wrapper-wvroot').innerHTML = `<div id=\\\"2\\\" style=\\\"display:flex;flex-direction:row;flex-wrap:wrap;align-content:flex-start;justify-content:flex-start;align-items:flex-start;width:100%;height:100%\\\"><div id=\\\"3\\\" style=\\\"display:flex;flex-direction:column;align-content:flex-start;justify-content:flex-start;align-items:flex-start\\\"><p id=\\\"4\\\" style=\\\"font-size:16px\\\">Downloading Google image</p><p id=\\\"5\\\" style=\\\"font-size:12px\\\">One moment...</p></div><div id=\\\"root-fonts\\\"></div><div id=\\\"root-alerts\\\"> </div></div>`; true;document.getElementById(\\\"5\\\").innerHTML = `<p id=\\\"5\\\" style=\\\"font-size:12px\\\">Okay, is downloaded.</p>`; true\";\n  try {\n    result = eval(code_string);\n    scarpeAsyncEvalResult(\"success\", 0, result);\n  } catch(error) {\n    scarpeAsyncEvalResult(\"error\", 0, error.message);\n  }\n})();\n"] KWargs: {} Block: n Return: nil
[1021] DEBUG Webview::WebWrangler: Scheduled JS: (0)
(function() {
  var code_string = "document.getElementById('wrapper-wvroot').innerHTML = `<div id=\"2\" style=\"display:flex;flex-direction:row;flex-wrap:wrap;align-content:flex-start;justify-content:flex-start;align-items:flex-start;width:100%;height:100%\"><div id=\"3\" style=\"display:flex;flex-direction:column;align-content:flex-start;justify-content:flex-start;align-items:flex-start\"><p id=\"4\" style=\"font-size:16px\">Downloading Google image</p><p id=\"5\" style=\"font-size:12px\">One moment...</p></div><div id=\"root-fonts\"></div><div id=\"root-alerts\"> </div></div>`; true;document.getElementById(\"5\").innerHTML = `<p id=\"5\" style=\"font-size:12px\">Okay, is downloaded.</p>`; true";
  try {
    result = eval(code_string);
    scarpeAsyncEvalResult("success", 0, result);
  } catch(error) {
    scarpeAsyncEvalResult("error", 0, error.message);
  }
})();

That's the end of the log. Presumably the nil error happened right after that. So it REALLY looks like it scheduled 1 waiting change, which should have returned a new promise. The "Scheduled JS (0)" won't happen if it's mid-shutdown, so I'm pretty sure this is not an "already shut down" bug, especially because I don't see a shutdown in the log.

But if it created the promise (which will happen even if we're mid-shutdown) and returned the promise, then why would the promise be nil?