Fix live message ordering during chat log restoration

src/main/java/obro1961/chatpatches/ChatLog.java

@@ -25,9 +25,11 @@
 import net.minecraft.client.multiplayer.chat.GuiMessageSource;
 //?}
 import net.minecraft.network.chat.Component;
+import net.minecraft.network.chat.MessageSignature;
 import net.minecraft.util.GsonHelper;
 import obro1961.chatpatches.config.Config;
 import obro1961.chatpatches.mixin.security.ClickEvent$ActionMixin;
+import obro1961.chatpatches.util.ChatUtil;
 import obro1961.chatpatches.util.TextUtil;
 import org.apache.commons.lang3.StringEscapeUtils;
 import org.intellij.lang.annotations.Language;
@@ -39,7 +41,11 @@
 import java.nio.file.Files;
 import java.nio.file.Path;
 import java.nio.file.StandardOpenOption;
+import java.util.ArrayDeque;
+import java.util.Deque;
+import java.util.Date;
 import java.util.List;
+import java.util.concurrent.CompletableFuture;
 import java.util.function.Function;
 
 import static obro1961.chatpatches.ChatPatches.*;
@@ -50,6 +56,24 @@
  * backing up the messages and history stored within.
  */
 public class ChatLog {
+	public enum RestoreState {
+		NOT_STARTED,
+		LOADING,
+		RESTORING,
+		DRAINING,
+		READY
+	}
+
+	private record PendingChatMessage(
+		Component component,
+		MessageSignature signature,
+		ChatUtil.MessageData messageData,
+		/*? if <=1.20.4 {*//*int addedTime,*//*?}*/
+		/*? if >=26.1 {*/GuiMessageSource source,/*?}*/
+		GuiMessageTag tag
+		/*? if <=1.20.4 {*//*, boolean refreshing*//*?}*/
+	) {}
+
     /**
      * Serializes as a {@link Pair} to avoid needing a dedicated class.
 	 * {@link #messages} are first and {@link #history} is second, and the native
@@ -87,12 +111,8 @@ public class ChatLog {
 
 	private static Minecraft mc() { return Minecraft.getInstance(); }
 
-    /**
-     * Used to suspend the addition of messages and access to the chat log
-	 * while restoring. Prevents log spam of restored messages and other
-	 * related issues like {?}.
-     */
-    private static boolean restoring = false;
+	private static final Deque<PendingChatMessage> pendingMessages = new ArrayDeque<>();
+	private static volatile RestoreState restoreState = RestoreState.NOT_STARTED;
     private static int lastHistoryCount = -1, lastMessageCount = -1;
     private static int ticksUntilSave = config.chatlogSaveInterval * SharedConstants.TICKS_PER_MINUTE;
 
@@ -110,18 +130,59 @@ static <T> ObjectList<T> newSyncedObjectList(@Nullable List<T> source) {
     }
 
 
-    public static boolean isRestoring() { return restoring; }
+    public static boolean isRestoring() { return restoreState == RestoreState.RESTORING; }
+    public static boolean isLoading() { return restoreState == RestoreState.LOADING; }
+
+	/**
+	 * Captures an incoming message before the asynchronous chat log load can
+	 * replace the in-memory message list. Called only from the client thread.
+	 *
+	 * @return {@code true} when the original addMessage call should be cancelled.
+	 */
+	public static boolean queueMessage(
+		Component component,
+		MessageSignature signature,
+		/*? if <=1.20.4 {*//*int addedTime,*//*?}*/
+		/*? if >=26.1 {*/GuiMessageSource source,/*?}*/
+		GuiMessageTag tag
+		/*? if <=1.20.4 {*//*, boolean refreshing*//*?}*/
+	) {
+		if(!isLoading() || RESTORED_INDICATOR.equals(tag)) {
+			return false;
+		}
+
+		ChatUtil.MessageData data = ChatUtil.messageData;
+		ChatUtil.MessageData snapshot = new ChatUtil.MessageData(
+			data.sender(),
+			new Date(data.timestamp().getTime()),
+			data.vanilla()
+		);
+		pendingMessages.addLast(new PendingChatMessage(
+			component,
+			signature,
+			snapshot,
+			/*? if <=1.20.4 {*//*addedTime,*//*?}*/
+			/*? if >=26.1 {*/source,/*?}*/
+			tag
+			/*? if <=1.20.4 {*//*, refreshing*//*?}*/
+		));
+		ChatUtil.messageData = ChatUtil.NIL_MESSAGE_DATA;
+		if(pendingMessages.size() == 1) {
+			LOGGER.info("Queuing live chat messages until chat history is restored");
+		}
+		return true;
+	}
 
     public static void addMessage(Component message) {
-        if(restoring) {
+		if(isRestoring()) {
 			return;
 		}
 
         enforceLimits();
         messages.add(message);
     }
     public static void addHistory(String sentMessage) {
-        if(restoring) {
+		if(isRestoring()) {
 			return;
 		}
 
@@ -387,18 +448,78 @@ public static void restore() {
 
 			// todo i think we just need to mixin to the delayed message queue thing, and here we cache the current setting, set it to ~5s delay, and mark some flag field true to be used in the mixin(s)!
 
-			restoring = true;
 			history.forEach(chat::addRecentChat);
 			messages.forEach(msg -> chat.addMessage(msg, null, /*? if >=26.1 {*/GuiMessageSource.SYSTEM_CLIENT,/*?}*/ RESTORED_INDICATOR));
-			restoring = false;
-
-			config.sendBoundaryLine(); // ensures the check that the chat isn't empty passes, which often doesn't due to multithreading
-			hideRecentMessages();
 		}
 
 		LOGGER.info("Restored {} messages and {} history messages!", messageCount(), historyCount());
 	}
 
+	private static void finishLoading(Throwable loadFailure) {
+		boolean hasSavedEntries = messageCount() > 0 || historyCount() > 0;
+
+		try {
+			if(loadFailure != null) {
+				LOGGER.error("Chat log loading failed; queued messages will still be replayed:", loadFailure);
+			} else {
+				restoreState = RestoreState.RESTORING;
+				restore();
+				hasSavedEntries = messageCount() > 0 || historyCount() > 0;
+			}
+		} catch(RuntimeException | AssertionError e) {
+			LOGGER.error("Chat log restoration failed; queued messages will still be replayed:", e);
+		} finally {
+			restoreState = RestoreState.DRAINING;
+			try {
+				try {
+					if(hasSavedEntries) {
+						config.sendBoundaryLine();
+						hideRecentMessages();
+					}
+				} catch(RuntimeException | AssertionError e) {
+					LOGGER.error("Failed to finish restored chat history presentation:", e);
+				}
+
+				try {
+					drainPendingMessages();
+				} catch(RuntimeException | AssertionError e) {
+					LOGGER.error("Failed to drain queued chat messages:", e);
+				}
+			} finally {
+				ChatUtil.messageData = ChatUtil.NIL_MESSAGE_DATA;
+				restoreState = RestoreState.READY;
+			}
+		}
+	}
+
+	private static void drainPendingMessages() {
+		ChatComponent chat = mc().gui.hud.getChat();
+		int pendingCount = pendingMessages.size();
+		int replayed = 0;
+
+		while(!pendingMessages.isEmpty()) {
+			PendingChatMessage pending = pendingMessages.poll();
+			try {
+				ChatUtil.messageData = pending.messageData();
+				chat.addMessage(
+					pending.component(),
+					pending.signature(),
+					/*? if <=1.20.4 {*//*pending.addedTime(),*//*?}*/
+					/*? if >=26.1 {*/pending.source(),/*?}*/
+					pending.tag()
+					/*? if <=1.20.4 {*//*, pending.refreshing()*//*?}*/
+				);
+				replayed++;
+			} catch(RuntimeException | AssertionError e) {
+				LOGGER.error("Failed to replay a queued chat message:", e);
+			} finally {
+				ChatUtil.messageData = ChatUtil.NIL_MESSAGE_DATA;
+			}
+		}
+
+		LOGGER.info("Replayed {} of {} pending chat messages", replayed, pendingCount);
+	}
+
 	/**
 	 * Hides the most recent messages in chat, so they don't render instantly when
 	 * restored or when a boundary line is added. This is done by setting {@link
@@ -449,8 +570,18 @@ public static void hideRecentMessages() {
 	 * assumes the render thread will always be used.
      */
     public static void load(boolean force) {
-        if(config.chatlog && ((messages == EMPTY_LIST && history == EMPTY_LIST) || force)) {
-			executeIoTask(ChatLog::deserialize).thenAcceptAsync(x -> restore(), mc());
+		if(config.chatlog && ((messages == EMPTY_LIST && history == EMPTY_LIST) || force)) {
+			if(restoreState == RestoreState.LOADING || restoreState == RestoreState.RESTORING || restoreState == RestoreState.DRAINING) {
+				return;
+			}
+
+			restoreState = RestoreState.LOADING;
+			try {
+				CompletableFuture.runAsync(ChatLog::deserialize, Util.ioPool())
+					.whenCompleteAsync((unused, error) -> finishLoading(error), mc());
+			} catch(RuntimeException e) {
+				finishLoading(e);
+			}
         }
     }
 
@@ -488,4 +619,4 @@ public static void saveIfPaused(Screen screen) {
 			serialize();
 		}
     }
-}
+}

src/main/java/obro1961/chatpatches/mixin/gui/ChatComponentMixin.java

@@ -11,10 +11,15 @@
 import net.fabricmc.api.EnvType;
 import net.fabricmc.api.Environment;
 import net.minecraft.client.multiplayer.chat.GuiMessage;
+import net.minecraft.client.multiplayer.chat.GuiMessageTag;
+//? if >=26.1 {
+import net.minecraft.client.multiplayer.chat.GuiMessageSource;
+//?}
 import net.minecraft.client.Minecraft;
 import net.minecraft.client.gui.components.ChatComponent;
 import net.minecraft.client.gui.screens.Screen;
 import net.minecraft.network.chat.Component;
+import net.minecraft.network.chat.MessageSignature;
 import obro1961.chatpatches.ChatLog;
 import obro1961.chatpatches.accessor.ChatComponentAccess;
 import obro1961.chatpatches.config.Config;
@@ -225,9 +230,33 @@ private double moveChatLineY(double y) {
      * @see ChatUtil#modifyMessage(Component)
      * @see ChatUtil#tryCondenseDupes(Component)
      */
+	@Inject(method = ADD_MESSAGE_TARGET_REFERENCE, at = @At("HEAD"), cancellable = true)
+	private void queueMessageWhileLoading(
+		Component message,
+		MessageSignature signature,
+		/*? if <=1.20.4 {*//*int addedTime,*//*?}*/
+		/*? if >=26.1 {*/GuiMessageSource source,/*?}*/
+		GuiMessageTag tag
+		/*? if <=1.20.4 {*//*, boolean refreshing*//*?}*/,
+		CallbackInfo ci
+	) {
+		if(ChatLog.queueMessage(
+			message,
+			signature,
+			/*? if <=1.20.4 {*//*addedTime,*//*?}*/
+			/*? if >=26.1 {*/source,/*?}*/
+			tag
+			/*? if <=1.20.4 {*//*, refreshing*//*?}*/
+		)) {
+			ci.cancel();
+		}
+	}
+
     @ModifyVariable(method = ADD_MESSAGE_TARGET_REFERENCE, at = @At("HEAD"), argsOnly = true)
     private Component modifyMessage(Component m /*? if <=1.20.4 {*//*, @Local(argsOnly = true) boolean refreshing*//*?}*/) {
-        return /*? if <=1.20.4 {*//* refreshing ? m : *//*?}*/ ChatUtil.modifyMessage(m);
+		// The cancellable injector may be ordered after this variable modifier.
+		// Leave both the component and its temporary metadata untouched until queued.
+        return ChatLog.isLoading() ? m : /*? if <=1.20.4 {*//* refreshing ? m : *//*?}*/ ChatUtil.modifyMessage(m);
     }
 
     @Inject(
@@ -268,4 +297,4 @@ private void ignoreRestoredMessages(GuiMessage message, CallbackInfo ci) {
 			ci.cancel();
 		}
     }
-}
+}

src/main/java/obro1961/chatpatches/util/TextUtil.java

@@ -299,7 +299,7 @@ public static String toLegacyString(Component text, boolean prettyPrint) { //tod
 	 * (ex. {@code #55FF55} for {@link ChatFormatting#GREEN}) will return as the formatting
 	 * code (ex. {@code &a}).
 	 *
-	 * @see TextColor#formatValue()
+	 * @see TextColor#serialize()
 	 */
 	public static String getFormattingCodes(Style style, Style last) {
 		StringJoiner joiner = new StringJoiner("&", "&", "").setEmptyValue(""); // adds the & at the start of the string
@@ -327,7 +327,7 @@ public static String getFormattingCodes(Style style, Style last) {
 		{
 			Optional<String> code = Colors.getCode(thisColor);
 			// if thisColor is named, add its formatting code, else add its hex color
-			joiner.add( code.orElse(thisColor.formatValue()) ); // thisColor.serialize() also works bc at that point we know it's not named so it will call formatValue() for us
+			joiner.add( code.orElse(thisColor.serialize()) );
 		}
 		else if(style.equals(Style.EMPTY) && !last.equals(Style.EMPTY))
 		{
@@ -342,4 +342,4 @@ else if(style.equals(Style.EMPTY) && !last.equals(Style.EMPTY))
 
 		return joiner.toString();
 	}
-}
+}

src/main/resources/access.ct

@@ -16,6 +16,10 @@ accessible field net/minecraft/client/gui/components/ChatComponent trimmedMessag
 accessible field net/minecraft/client/gui/components/ChatComponent chatScrollbarPos I
 accessible method net/minecraft/client/gui/components/ChatComponent getLineHeight ()I
 
+#? if <=1.20.4 {
+accessible method net/minecraft/client/gui/components/ChatComponent addMessage (Lnet/minecraft/network/chat/Component;Lnet/minecraft/network/chat/MessageSignature;ILnet/minecraft/client/GuiMessageTag;Z)V
+#?}
+
 #? if >=1.21.11 {
 accessible method net/minecraft/client/gui/components/ChatComponent getWidth ()I # ContextMenu#extractSelectionOutline()
 accessible method net/minecraft/client/gui/components/ChatComponent getScale ()D
@@ -77,4 +81,4 @@ accessible field net/minecraft/client/gui/components/Button onPress Lnet/minecra
 accessible field net/minecraft/client/gui/components/Button DEFAULT_NARRATION Lnet/minecraft/client/gui/components/Button$CreateNarration;
 
 #~ if <1.21.11 'Button$Plain ' -> 'Button ' >> '<init>'
-accessible method net/minecraft/client/gui/components/Button$Plain <init> (IIIILnet/minecraft/network/chat/Component;Lnet/minecraft/client/gui/components/Button$OnPress;Lnet/minecraft/client/gui/components/Button$CreateNarration;)V
+accessible method net/minecraft/client/gui/components/Button$Plain <init> (IIIILnet/minecraft/network/chat/Component;Lnet/minecraft/client/gui/components/Button$OnPress;Lnet/minecraft/client/gui/components/Button$CreateNarration;)V