[rc-1.6.0] Settings: a failed read no longer warns, and the supervisor reconnects to log

packages/service/lib/service_lib.php

@@ -105,6 +105,13 @@
  */
 function Service_Log_message($logpath, $name, $msg)
 {
+    // The supervisor closes its connection before every fork (#1930), but
+    // formatting the time below can still read a setting -- the log gate
+    // behind it, once the cache entry is past its TTL. On a closed link that
+    // read failed and spilled warnings into this log (GH-1994). Reopen it;
+    // a no-op when connected, and Service_persist() closes it again before
+    // the next fork, so no child inherits it.
+    DatabaseManager::getLink();
     $msg = sprintf(
         "[%s] %s %s\n",
         FOGCore::formatTime('now', 'm-d-y g:i:s a'),

packages/web/src/Base/FOGBase.php

@@ -3528,7 +3528,8 @@ private static function _useSettingsFileCache()
      * Load every global setting from the database in a single query, applying
      * the same normalization as getSetting().
      *
-     * @return array Map of settingKey => normalized value.
+     * @return array|null Map of settingKey => normalized value, or null when
+     *                    the read failed.
      */
     private static function _loadAllSettings()
     {
@@ -3538,6 +3539,14 @@ private static function _loadAllSettings()
             "SELECT `settingKey`, `settingValue` FROM `globalSettings`"
         )->fetch(\PDO::FETCH_ASSOC, 'fetch_all')->get();
 
+        // A failed read answers false, not an empty set. (array) false is
+        // [false], so iterating it walked one "row" that was false itself
+        // (GH-1994). null tells the callers not to replace what they hold
+        // with an empty map -- query() has already logged the cause.
+        if (!is_array($rows)) {
+            return null;
+        }
+
         $data = [];
         foreach ((array) $rows as $row) {
             $data[$row['settingKey']] = trim(
@@ -3675,6 +3684,11 @@ private static function _warmFromFileCache()
         // Missing, stale, or flushed: rebuild from the database and persist.
         ++self::$_settingsCacheQueries;
         $data = self::_loadAllSettings();
+        if (null === $data) {
+            // Leave the file alone: siblings would read an empty map as
+            // "no settings" for a whole TTL. getSetting() reads per key.
+            return;
+        }
         foreach ($data as $k => $v) {
             self::$_settingsCache[$k] = ['value' => $v, 'ts' => $now];
         }
@@ -3743,7 +3757,14 @@ public static function getSetting($key)
             $rows = self::$DB->query($sql)
                 ->fetch(\PDO::FETCH_ASSOC, 'fetch_all')->get();
 
-            foreach ((array) $rows as $row) {
+            // A failed read answers false; (array) false is [false], one
+            // "row" that is false itself (GH-1994). Skip it: a stale entry
+            // keeps its value and is retried on the next call, and query()
+            // has already logged the cause.
+            if (!is_array($rows)) {
+                $rows = [];
+            }
+            foreach ($rows as $row) {
                 self::$_settingsCache[$row['settingKey']] = [
                     'value' => trim(
                         str_replace(
@@ -3850,6 +3871,10 @@ public static function refreshSettingsCache()
     {
         $now = time();
         $data = self::_loadAllSettings();
+        if (null === $data) {
+            // A failed read must not empty the cache it was meant to refresh.
+            return 0;
+        }
 
         self::$_settingsCache = [];
         foreach ($data as $k => $v) {

tests/settings-read-failure.test.php

@@ -0,0 +1,115 @@
+<?php
+/**
+ * A failed settings read must not be iterated as though it were rows.
+ *
+ * PDODB::get() answers false when a read fails, not an empty set, and
+ * (array) false is [false]. getSetting() and _loadAllSettings() cast and
+ * iterated it, so every failed read wrote two "Trying to access array offset
+ * on false" warnings. A daemon supervisor reads settings on a closed link
+ * after #1930, and on RC18 on a socket its child shares, so services filled
+ * servicemaster.log with them (GH-1994).
+ *
+ * This runs the REAL FOGBase against a DB stub whose every read fails, and
+ * checks: no warning, a stale value survives the failed refresh, and
+ * refreshSettingsCache() does not empty the cache it was meant to refresh.
+ * No database.
+ *
+ * Usage: php tests/settings-read-failure.test.php [repo-root]
+ * Exit status 0 = pass, 1 = fail.
+ */
+
+$root = $argv[1] ?? dirname(__DIR__);
+$src = $root . '/packages/web/src/';
+$tmp = sys_get_temp_dir() . '/fog-settings-read-' . getmypid();
+@mkdir($tmp, 0700, true);
+
+define('DS', DIRECTORY_SEPARATOR);
+define('BASEPATH', $root . '/packages/web/');
+define('FOG_CACHE_DIR', $tmp);
+
+spl_autoload_register(function ($class) use ($src) {
+    if (0 !== strpos($class, 'FOG\\')) {
+        return;
+    }
+    $file = $src . str_replace('\\', '/', substr($class, 4)) . '.php';
+    if (is_file($file)) {
+        require $file;
+    }
+});
+
+/**
+ * Stands in for PDODB: answers rows while $fail is false, false after.
+ */
+class FailingDB
+{
+    public $fail = false;
+    public $rows = [];
+    public function query($sql)
+    {
+        return $this;
+    }
+    public function fetch($type, $fetchType)
+    {
+        return $this;
+    }
+    public function get()
+    {
+        return $this->fail ? false : $this->rows;
+    }
+}
+
+$db = new FailingDB();
+$db->rows = [['settingKey' => 'FOG_GH1994', 'settingValue' => 'kept']];
+$prop = new \ReflectionProperty('FOG\Base\FOGBase', 'DB');
+$prop->setAccessible(true);
+$prop->setValue(null, $db);
+
+$warnings = [];
+set_error_handler(function ($no, $str, $file, $line) use (&$warnings) {
+    $warnings[] = "$str at " . basename($file) . ":$line";
+    return true;
+});
+
+$fails = [];
+$base = 'FOG\Base\FOGBase';
+
+// Prime the cache while the database answers.
+if ('kept' !== $base::getSetting('FOG_GH1994')) {
+    $fails[] = 'getSetting() did not read the stub row; the test cannot see its subject';
+}
+
+// Every entry is now stale, and every read fails.
+$base::$settingsCacheTTL = 0;
+$db->fail = true;
+
+$missing = $base::getSetting('FOG_GH1994_ABSENT');
+if (null !== $missing) {
+    $fails[] = 'a failed read of an uncached key answered ' . var_export($missing, true);
+}
+if ('kept' !== $base::getSetting('FOG_GH1994')) {
+    $fails[] = 'a failed read dropped the stale value it was refreshing';
+}
+$loaded = $base::refreshSettingsCache();
+if (0 !== $loaded) {
+    $fails[] = "refreshSettingsCache() reported $loaded settings from a failed read";
+}
+if ('kept' !== $base::getSetting('FOG_GH1994')) {
+    $fails[] = 'a failed refreshSettingsCache() emptied the cache';
+}
+foreach ($warnings as $w) {
+    $fails[] = "warning: $w";
+}
+
+restore_error_handler();
+array_map('unlink', glob($tmp . '/*') ?: []);
+@unlink($tmp . '/.settings_cache_flush');
+@rmdir($tmp);
+
+if ($fails) {
+    foreach ($fails as $f) {
+        fwrite(STDERR, "FAIL: $f\n");
+    }
+    exit(1);
+}
+echo "OK: a failed settings read warns nothing and keeps the cache\n";
+exit(0);