Improve explain on db_logging (#1898)

LycheeOrg · Jun 24, 2023 · 1a8a3c3 · 1a8a3c3
1 parent f3ff892
commit 1a8a3c3
Show file tree

Hide file tree

Showing 5 changed files with 108 additions and 6 deletions.
diff --git a/Makefile b/Makefile
@@ -109,7 +109,16 @@ release_major: gen_major
 TESTS_PHP := $(shell find tests/Feature -name "*Test.php" -printf "%f\n")
 TEST_DONE := $(addprefix build/,$(TESTS_PHP:.php=.done))
 
-build/%.done: tests/Feature/%.php
-	XDEBUG_MODE=coverage vendor/bin/phpunit --filter $* && touch build/$*.done
+build:
+	mkdir build
+
+build/Base%.done:
+	touch build/Base$*.done
+
+build/%UnitTest.done:
+	touch build/$*UnitTest.done
+
+build/%.done: tests/Feature/%.php build
+	vendor/bin/phpunit --no-coverage --filter $* && touch build/$*.done
 
 all_tests: $(TEST_DONE)
diff --git a/app/Providers/AppServiceProvider.php b/app/Providers/AppServiceProvider.php
@@ -35,8 +35,24 @@
 
 class AppServiceProvider extends ServiceProvider
 {
-	public array $singletons
-	= [
+	/**
+	 * Defines which queries to ignore when doing explain.
+	 *
+	 * @var array<int,string>
+	 */
+	private array $ignore_log_SQL =
+	[
+		'information_schema', // Not interesting
+
+		// We do not want infinite loops
+		'EXPLAIN',
+
+		// Way too noisy
+		'configs',
+	];
+
+	public array $singletons =
+	[
 		SymLinkFunctions::class => SymLinkFunctions::class,
 		Helpers::class => Helpers::class,
 		CheckUpdate::class => CheckUpdate::class,
@@ -146,4 +162,45 @@ public function register()
 			SizeVariantDefaultFactory::class
 		);
 	}
+
+	private function logSQL(QueryExecuted $query): void
+	{
+		// Quick exit
+		if (
+			Str::contains(request()->getRequestUri(), 'logs', true)
+		) {
+			return;
+		}
+
+		// Get message with binding outside.
+		$msg = '(' . $query->time . 'ms) ' . $query->sql . ' [' . implode(', ', $query->bindings) . ']';
+
+		// For pgsql and sqlite we log the query and exit early
+		if (config('database.default', 'mysql') !== 'mysql' ||
+			config('database.explain', false) === false ||
+			!Str::contains($query->sql, 'select') ||
+			Str::contains($query->sql, $this->ignore_log_SQL)
+		) {
+			Log::debug($msg);
+
+			return;
+		}
+
+		// For mysql we perform an explain as this is usually the one being slower...
+		$bindings = collect($query->bindings)->map(function ($q) {
+			return match (gettype($q)) {
+				'NULL' => "''",
+				'string' => "'{$q}'",
+				'boolean' => $q ? '1' : '0',
+				default => $q
+			};
+		})->all();
+
+		$sql_with_bindings = Str::replaceArray('?', $bindings, $query->sql);
+
+		$explain = DB::select('EXPLAIN ' . $sql_with_bindings);
+		$renderer = new ArrayToTextTable();
+		$renderer->setIgnoredKeys(['possible_keys', 'key_len', 'ref']);
+		Log::debug($msg . PHP_EOL . $renderer->getTable($explain));
+	}
 }
diff --git a/database/migrations/2018_08_15_102039_move_albums.php b/database/migrations/2018_08_15_102039_move_albums.php
@@ -38,10 +38,10 @@ public function up(): void
 					]);
 				}
 			} else {
-				Log::notice(__FUNCTION__ . ':' . __LINE__ . ' ' . env('DB_OLD_LYCHEE_PREFIX', '') . 'lychee_albums does not exist!');
+				Log::notice(__METHOD__ . ':' . __LINE__ . ' ' . env('DB_OLD_LYCHEE_PREFIX', '') . 'lychee_albums does not exist!');
 			}
 		} else {
-			Log::notice(__FUNCTION__ . ':' . __LINE__ . ' albums is not empty.');
+			Log::notice(__METHOD__ . ':' . __LINE__ . ' albums is not empty.');
 		}
 	}
 

diff --git a/phpunit.xml b/phpunit.xml
@@ -1,6 +1,41 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <phpunit xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" bootstrap="vendor/autoload.php" colors="true" processIsolation="false" stopOnFailure="false" xsi:noNamespaceSchemaLocation="./vendor/phpunit/phpunit/phpunit.xsd">
   <coverage>
+    <report>
+      <clover outputFile="clover.xml"/>
+      <text outputFile="php://stdout" showUncoveredFiles="false"/>
+    </report>
+  </coverage>
+  <testsuites>
+    <testsuite name="Feature">
+      <directory suffix="Test.php">./tests/Feature</directory>
+      <directory suffix="Test.php">./tests/Feature</directory>
+      <exclude>./tests/Feature/Base/BasePhotoTest.php</exclude>
+      <exclude>./tests/Feature/Base/BasePhotosRotateTest.php</exclude>
+      <exclude>./tests/Feature/Base/BaseSharingTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/AlbumsUnitTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/PhotosUnitTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/RootAlbumUnitTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/SessionUnitTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/SharingUnitTest.php</exclude>
+      <exclude>./tests/Feature/LibUnitTests/UsersUnitTest.php</exclude>
+    </testsuite>
+  </testsuites>
+  <extensions>
+    <bootstrap class="Tests\BootExtension"/>
+  </extensions>
+  <logging/>
+  <php>
+    <env name="APP_ENV" value="testing"/>
+    <env name="DB_LOG_SQL" value="true"/>
+    <env name="DB_LOG_SQL_EXPLAIN" value="true"/>
+    <env name="BCRYPT_ROUNDS" value="4"/>
+    <env name="CACHE_DRIVER" value="array"/>
+    <env name="SESSION_DRIVER" value="array"/>
+    <env name="QUEUE_CONNECTION" value="sync"/>
+    <env name="MAIL_DRIVER" value="array"/>
+  </php>
+  <source>
     <include>
       <directory suffix=".php">
         ./app

diff --git a/tests/Feature/WebAuthTest.php b/tests/Feature/WebAuthTest.php
@@ -30,6 +30,7 @@ public function setUp(): void
 	{
 		parent::setUp();
 		$this->setUpRequiresEmptyWebAuthnCredentials();
+		config(['app.url' => 'https://localhost']);
 	}
 
 	public function tearDown(): void