Merge pull request #4448 from Goober5000/async_mprintfs

add some logging to waitAsync

Author: Goober5000

code/osapi/outwnd.cpp

@@ -29,7 +29,8 @@ static const char *FILTERS_ENABLED_BY_DEFAULT[] =
 {
 	"error",
 	"warning",
-	"general"
+	"general",
+	"scripting"
 };
 
 struct outwnd_filter_struct {

code/scripting/api/LuaPromise.cpp

@@ -92,7 +92,7 @@ LuaPromise::LuaPromise(const std::shared_ptr<resolve_context>& resolveContext) :
 {
 	m_state->state = State::Pending;
 
-	// This executes promises eagerly since registering the callback kicks of the async operation
+	// This executes promises eagerly since registering the callback kicks off the async operation
 	m_state->registerResolveCallback(resolveContext);
 }
 

code/scripting/api/libs/async.cpp

@@ -111,7 +111,7 @@ ADE_FUNC(promise,
 	"function(function(any resolveVal) => void resolve, function(any errorVal) => void reject) => void body",
 	"Creates a promise that resolves when the resolve function of the callback is called or errors if the reject "
 	"function is called. The function will be called "
-	"on it's own.",
+	"on its own.",
 	"promise",
 	"The promise or nil on error")
 {

code/scripting/api/libs/mission.cpp

@@ -1729,19 +1729,25 @@ ADE_FUNC(waitAsync,
 
 	class time_resolve_context : public resolve_context, public std::enable_shared_from_this<time_resolve_context> {
 	  public:
-		time_resolve_context(int timestamp) : m_timestamp(timestamp) {}
+		time_resolve_context(int timestamp) : m_timestamp(timestamp) {
+			static int unique_id_counter = 0;
+			m_unique_id = unique_id_counter++;
+			nprintf(("scripting", "waitAsync: Creating asynchronous context %d.\n", m_unique_id));
+		}
 		void setResolver(Resolver resolver) override
 		{
 			// Keep checking the time until the timestamp is elapsed
 			auto self = shared_from_this();
 			auto cb = [this, self, resolver](
 						  executor::IExecutionContext::State contextState) {
 				if (contextState == executor::IExecutionContext::State::Invalid) {
+					mprintf(("waitAsync: Context is invalid, possibly due to a game state change (current state is %s).  Aborting asynchronous context %d.\n", GS_state_text[gameseq_get_state()], m_unique_id));
 					resolver(true, luacpp::LuaValueList());
 					return executor::Executor::CallbackResult::Done;
 				}
 
 				if (timestamp_elapsed(m_timestamp)) {
+					nprintf(("scripting", "waitAsync: Timestamp has elapsed for asynchronous context %d.\n", m_unique_id));
 					resolver(false, luacpp::LuaValueList());
 					return executor::Executor::CallbackResult::Done;
 				}
@@ -1756,6 +1762,7 @@ ADE_FUNC(waitAsync,
 
 	  private:
 		int m_timestamp = -1;
+		int m_unique_id = -1;
 	};
 	return ade_set_args(L,
 		"o",