Merge pull request 'fix(bridge): protocol 13 — a configuration reload that works on Carbon (W1-W5)' (#17) from fix/protocol-13-carbon-reload into edge

Reviewed-on: #17

overlay/oxide/plugins/RunicGateway.cs

@@ -4124,23 +4124,47 @@ namespace Oxide.Plugins
         ///
         ///     <para>
         ///     Lower case, matched case-insensitively. Oxide's are its compiler's and its loader's
-        ///     own words ("Error while compiling", "Failed to initialize plugin", seen on the rig in
+        ///     own words ("Error while compiling", "Failed to initialize plugin", and "Could not
-        ///     configuration step 4). Carbon's differ, and the rest of the list is there so that the
+        ///     initialize plugin 'Kits v4.4.9' (JsonReaderException: …)" when a plugin's own
-        ///     same file works on both (R19); the Carbon pass of the re-walk is what pins them.
+        ///     <c>LoadConfig</c> throws, seen on the rig in configuration step 4). The last one
+        ///     carries the exception, so it is the line an operator needs; Oxide follows it with
+        ///     "Previous version of plugin failed to load", which says nothing about why. Carbon's
+        ///     differ, and the rest of the list is there so that the same file works on both (R19);
+        ///     the Carbon pass of the re-walk is what pins them. The first pinned is Carbon
+        ///     2.0.259's "[Kits] Failed ILoadConfig (Could not convert string to double: abc. …)" —
+        ///     after which Carbon loads the plugin anyway, broken, and raises <c>Loaded</c>.
         ///     </para>
         /// </summary>
         private static readonly string[] ConfigFailureWords =
         {
             "error while compiling",
+            "could not initialize",
             "failed to initialize",
             "failed initializing",
             "failed to compile",
             "failed compiling",
             "failed to load",
             "failed loading",
+            "failed iloadconfig",
             "unable to load",
         };
 
+        /// <summary>
+        ///     What the framework says when it gave up on a compile, beside the plugin's name.
+        ///
+        ///     <para>
+        ///     Not a failure of the file: Oxide shuts its compiler down after a minute idle, and a
+        ///     reload asked for in that moment is dropped with "Timed out waiting for plugin to be
+        ///     compiled: ZoneManager" while the plugin carries on, loaded, on its old file (seen on
+        ///     the rig, configuration step 2b). The compiler starts again on demand, so the reload
+        ///     is asked for once more; only a second give-up settles the job.
+        ///     </para>
+        /// </summary>
+        private static readonly string[] ConfigStallWords =
+        {
+            "timed out waiting for plugin to be compiled",
+        };
+
         /// <summary>Which reload a job is waiting on: the edit's, or the restore's after a rollback.</summary>
         private enum ConfigPhase
         {
@@ -4197,6 +4221,12 @@ namespace Oxide.Plugins
             /// <summary>Whether the target was seen leaving in this phase. It separates "never started" from "did not come back".</summary>
             public bool Unloaded;
 
+            /// <summary>Whether this phase's reload was already asked for again after the framework gave up compiling.</summary>
+            public bool Retried;
+
+            /// <summary>When <c>OnPluginLoaded</c> named the target in this phase, or null. The next log read settles it.</summary>
+            public DateTime? LoadedAt;
+
             /// <summary>The log file being read, and how far into it this job has read.</summary>
             public string LogPath;
 
@@ -4652,16 +4682,32 @@ namespace Oxide.Plugins
         }
 
         /// <summary>
-        ///     Main thread. <c>OnPluginLoaded</c> named the target: in the edit phase the write
+        ///     Main thread. <c>OnPluginLoaded</c> named the target. It is noted, not settled: the
-        ///     stands; in the restore phase the plugin is back on its old file.
+        ///     next log read settles it (W5).
+        ///
+        ///     <para>
+        ///     "Loaded" is not "loaded well" on Carbon. A config its <c>LoadConfig</c> cannot read
+        ///     is logged as a failure and the plugin is loaded anyway, broken, in the same instant
+        ///     (seen on the rig, configuration step 4). Settling on the hook reported that edit as
+        ///     applied; reading the log first rolls it back, for about a second's wait.
+        ///     </para>
         /// </summary>
         private void ConfigReloadArrived()
         {
             ConfigWriteJob job = _configJob;
 
-            if (job == null)
+            if (job == null || job.LoadedAt.HasValue)
                 return;
 
+            job.LoadedAt = DateTime.UtcNow;
+        }
+
+        /// <summary>
+        ///     Main thread. A load that a full log read after it found no failure: in the edit
+        ///     phase the write stands; in the restore phase the plugin is back on its old file.
+        /// </summary>
+        private void ConfigLoadConfirmed(ConfigWriteJob job)
+        {
             if (job.Phase == ConfigPhase.Edit)
                 SettleConfigJob(job, true, false, null, null, null);
             else
@@ -4700,6 +4746,12 @@ namespace Oxide.Plugins
 
             string failure = ReadConfigFailure(job);
 
+            if (failure != null && IsCompileStallOf(failure, job.Reload))
+            {
+                ConfigCompileStalled(job, failure);
+                return;
+            }
+
             if (failure != null)
             {
                 if (job.Phase == ConfigPhase.Edit)
@@ -4716,9 +4768,53 @@ namespace Oxide.Plugins
                 return;
             }
 
+            // A load is trusted once a read that began at least a poll after it found nothing:
+            // the failure it would have to beat is logged before the load, never after.
+            if (job.LoadedAt.HasValue &&
+                (DateTime.UtcNow - job.LoadedAt.Value).TotalSeconds >= ConfigLogPollSeconds)
+            {
+                ConfigLoadConfirmed(job);
+                return;
+            }
+
             if ((DateTime.UtcNow - job.PhaseStarted).TotalSeconds < ConfigReloadCeilingSeconds)
                 return;
 
+            SettleByWhatIsLoaded(job, $"within {ConfigReloadCeilingSeconds:0}s");
+        }
+
+        /// <summary>
+        ///     Main thread. The framework gave up compiling the target (W1). The first time, the
+        ///     reload is asked for again with a fresh ceiling; the second time, the job is settled
+        ///     at once by what is loaded — the same judgement the ceiling makes, without waiting
+        ///     for it, because the framework has already said it is not going to finish.
+        /// </summary>
+        private void ConfigCompileStalled(ConfigWriteJob job, string line)
+        {
+            if (!job.Retried)
+            {
+                job.Retried = true;
+                job.PhaseStarted = DateTime.UtcNow;
+                job.Unloaded = false;
+                job.LoadedAt = null;
+                MarkLogPosition(job);
+
+                Puts($"the framework gave up compiling '{job.Reload}'; asking for the reload once more");
+
+                if (ReloadPluginByName(job.Reload))
+                    return;
+            }
+
+            SettleByWhatIsLoaded(job, $"before the framework gave up compiling it ({ShortLine(line)})");
+        }
+
+        /// <summary>
+        ///     Main thread. Settles a reload that said nothing conclusive, by what is loaded — not
+        ///     by the clock (F10). <paramref name="when"/> finishes the sentence: "within 30s", or
+        ///     why it stopped sooner.
+        /// </summary>
+        private void SettleByWhatIsLoaded(ConfigWriteJob job, string when)
+        {
             bool loaded = IsPluginLoaded(job.Reload);
 
             if (job.Phase == ConfigPhase.Restore)
@@ -4727,7 +4823,7 @@ namespace Oxide.Plugins
                     loaded
                         ? job.RollbackReason
                         : $"{job.RollbackReason}; '{job.Reload}' did not come back on the restored file " +
-                          $"within {ConfigReloadCeilingSeconds:0}s either",
+                          $"{when} either",
                     job.RollbackLog);
                 return;
             }
@@ -4740,7 +4836,7 @@ namespace Oxide.Plugins
             else if (loaded)
             {
                 SettleConfigJob(job, false, false, null,
-                    $"the framework did not reload '{job.Reload}' within {ConfigReloadCeilingSeconds:0}s; " +
+                    $"the framework did not reload '{job.Reload}' {when}; " +
                     "the file stands and applies at its next load",
                     null);
             }
@@ -4748,8 +4844,8 @@ namespace Oxide.Plugins
             {
                 RollBackConfig(job,
                     job.Unloaded
-                        ? $"'{job.Reload}' unloaded and did not come back within {ConfigReloadCeilingSeconds:0}s"
+                        ? $"'{job.Reload}' unloaded and did not come back {when}"
-                        : $"'{job.Reload}' did not load within {ConfigReloadCeilingSeconds:0}s",
+                        : $"'{job.Reload}' did not load {when}",
                     LogTail());
             }
         }
@@ -4771,6 +4867,8 @@ namespace Oxide.Plugins
             job.Phase = ConfigPhase.Restore;
             job.PhaseStarted = DateTime.UtcNow;
             job.Unloaded = false;
+            job.Retried = false;
+            job.LoadedAt = null;
             job.RollbackReason = reason;
             job.RollbackLog = log;
 
@@ -4909,7 +5007,7 @@ namespace Oxide.Plugins
                     if (line.IndexOf(own, StringComparison.OrdinalIgnoreCase) >= 0)
                         continue;
 
-                    if (IsLoadFailureOf(line, job.Reload))
+                    if (IsLoadFailureOf(line, job.Reload) || IsCompileStallOf(line, job.Reload))
                         return line;
                 }
             }
@@ -4924,23 +5022,34 @@ namespace Oxide.Plugins
 
         /// <summary>Whether a log line says <paramref name="plugin"/> failed to compile or to initialise.</summary>
         private static bool IsLoadFailureOf(string line, string plugin)
+        {
+            return SaysAbout(line, plugin, ConfigFailureWords);
+        }
+
+        /// <summary>Whether a log line says the framework gave up compiling <paramref name="plugin"/> (W1).</summary>
+        private static bool IsCompileStallOf(string line, string plugin)
+        {
+            return SaysAbout(line, plugin, ConfigStallWords);
+        }
+
+        private static bool SaysAbout(string line, string plugin, string[] words)
         {
             if (string.IsNullOrEmpty(line) || string.IsNullOrEmpty(plugin))
                 return false;
 
             string lower = line.ToLowerInvariant();
-            bool failed = false;
+            bool said = false;
 
-            foreach (string word in ConfigFailureWords)
+            foreach (string word in words)
             {
                 if (lower.IndexOf(word, StringComparison.Ordinal) >= 0)
                 {
-                    failed = true;
+                    said = true;
                     break;
                 }
             }
 
-            return failed && MentionsName(lower, plugin.ToLowerInvariant());
+            return said && MentionsName(lower, plugin.ToLowerInvariant());
         }
 
         /// <summary>
@@ -5252,9 +5361,16 @@ namespace Oxide.Plugins
         }
 
         /// <summary>
-        ///     The framework's newest log file, or null. The framework's own log is the newest
+        ///     The framework's newest log file, or null. Oxide's own log is the newest <c>*.txt</c>
-        ///     <c>*.txt</c> directly in <c>LogDirectory</c>; plugins that log to files write into
+        ///     directly in <c>LogDirectory</c>; plugins that log to files write into subdirectories
-        ///     subdirectories of it, which this does not look in.
+        ///     of it, which this does not look in.
+        ///
+        ///     <para>
+        ///     Carbon's is <c>Carbon.Core.log</c> in <c>carbon/logs</c>, beside four other
+        ///     <c>*.log</c> files and no <c>*.txt</c> at all (read on the rig, Carbon 2.0.259). Its
+        ///     Harmony log is the one written most often, so "newest" would pick the wrong file;
+        ///     the name is the only reliable way to choose.
+        ///     </para>
         /// </summary>
         private static string NewestLogFile()
         {
@@ -5265,6 +5381,12 @@ namespace Oxide.Plugins
                 if (string.IsNullOrEmpty(dir) || !Directory.Exists(dir))
                     return null;
 
+                if (IsCarbon())
+                {
+                    string core = Path.Combine(dir, "Carbon.Core.log");
+                    return File.Exists(core) ? core : null;
+                }
+
                 string newest = null;
                 DateTime newestAt = DateTime.MinValue;
 
@@ -5336,6 +5458,13 @@ namespace Oxide.Plugins
         /// </summary>
         private bool ReloadPluginByName(string name)
         {
+            // Carbon's Oxide-compatible ReloadPlugin is not a reload (W3, Carbon 2.0.259 on the
+            // rig): one call unloaded Kits and never compiled it again, the next did nothing at
+            // all. Its own console command, typed at the panel, reloads the same plugin in about a
+            // second — so on Carbon the reload IS that command, run on the server console.
+            if (IsCarbon())
+                return RunReloadCommand("c.reload", name);
+
             try
             {
                 System.Reflection.MethodInfo reload = Interface.Oxide.GetType()
@@ -5352,14 +5481,20 @@ namespace Oxide.Plugins
                 Puts($"framework reload of '{name}' threw: {ex.Message}");
             }
 
+            return RunReloadCommand("oxide.reload", name);
+        }
+
+        /// <summary>Runs a reload command on the server console, as an operator at the panel would.</summary>
+        private bool RunReloadCommand(string command, string name)
+        {
             try
             {
-                covalence.Server.Command(IsCarbon() ? "c.reload" : "oxide.reload", name);
+                ConsoleSystem.Run(ConsoleSystem.Option.Server, command, name);
                 return true;
             }
             catch (Exception ex)
             {
-                Puts($"console reload of '{name}' threw: {ex.Message}");
+                Puts($"console {command} of '{name}' threw: {ex.Message}");
                 return false;
             }
         }
@@ -10746,6 +10881,7 @@ namespace Oxide.Plugins
             arg.ReplyWith(
                 $"protocol={ProtocolVersion} framework={(IsCarbon() ? "carbon" : "oxide")} " +
                 $"root={(string.IsNullOrEmpty(root) ? "(none)" : root)}" + Environment.NewLine +
+                $"log={NewestLogFile() ?? "(none: a failed reload waits out the ceiling)"}" + Environment.NewLine +
                 $"waiting={waiting}" + Environment.NewLine +
                 $"last write: {_lastConfigSummary}");
         }