From 7748b83a6b32862e933a28f819665aa28bf9b126 Mon Sep 17 00:00:00 2001
From: Clemens Schwaighofer <clemens.schwaighofer@egplusww.com>
Date: Fri, 16 Jun 2023 13:16:16 +0900
Subject: [PATCH] DB\IO add stack trace to debug/error/warning calls

To add the actuall call reference for DB IO debug calls we add the
call trace as context options
---
 www/admin/class_test.db.single.php       | 14 +++++++++++
 www/lib/CoreLibs/DB/Extended/ArrayIO.php |  2 +-
 www/lib/CoreLibs/DB/IO.php               | 32 +++++++++++++++++++++---
 www/lib/CoreLibs/Logging/Logging.php     |  2 +-
 4 files changed, 45 insertions(+), 5 deletions(-)

diff --git a/www/admin/class_test.db.single.php b/www/admin/class_test.db.single.php
index 03cb6efe..256dc902 100644
--- a/www/admin/class_test.db.single.php
+++ b/www/admin/class_test.db.single.php
@@ -53,6 +53,18 @@ if (($dbh = $db->dbGetDbh()) instanceof \PgSql\Connection) {
 	print "NO DB HANDLER<br>";
 }
 
+/**
+ * Undocumented function
+ *
+ * @param  \CoreLibs\DB\IO $dbc
+ * @return void
+ */
+function testDBS(\CoreLibs\DB\IO $dbc): void
+{
+	echo "Int call<br>";
+	$dbc->dbReturnRow("SELECT test FROM test_foo LIMIT 1");
+}
+
 $uniqid = \CoreLibs\Create\Uids::uniqIdShort();
 $binary_data = $db->dbEscapeBytea(file_get_contents('class_test.db.php') ?:  '');
 $query_params = [
@@ -110,6 +122,8 @@ if (is_array($res)) {
 	var_dump($res);
 }
 
+testDBS($db);
+
 print "</body></html>";
 
 // __END__
diff --git a/www/lib/CoreLibs/DB/Extended/ArrayIO.php b/www/lib/CoreLibs/DB/Extended/ArrayIO.php
index 36a9fd3a..9b6b734c 100644
--- a/www/lib/CoreLibs/DB/Extended/ArrayIO.php
+++ b/www/lib/CoreLibs/DB/Extended/ArrayIO.php
@@ -588,7 +588,7 @@ class ArrayIO extends \CoreLibs\DB\IO
 		// get it at the end, cause now we can be more sure of no double IDs, etc
 		reset($this->table_array);
 		// create select part & addition FK part
-		foreach ($this->table_array as $column => $data_array) {
+		foreach (array_keys($this->table_array) as $column) {
 			// check FK ...
 			if (
 				isset($this->table_array[$column]['fk']) &&
diff --git a/www/lib/CoreLibs/DB/IO.php b/www/lib/CoreLibs/DB/IO.php
index 9c6e4ae5..622c4f72 100644
--- a/www/lib/CoreLibs/DB/IO.php
+++ b/www/lib/CoreLibs/DB/IO.php
@@ -792,19 +792,45 @@ class IO
 				. \CoreLibs\Debug\Support::prAr($error_data)
 				. ']';
 		}
+		// we need to trace back where the first non class call was done
+		// add this stack trace to the context
+		$call_stack = [];
+		foreach (array_reverse(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS)) as $call_trace) {
+			if (
+				!empty($call_trace['file']) &&
+				str_ends_with($call_trace['file'], '/DB/IO.php')
+			) {
+				break;
+			}
+			$call_stack[] =
+				($call_trace['file'] ?? 'n/f') . ':'
+				. ($call_trace['line'] ?? '-') . ':'
+				. (!empty($call_trace['class']) ? $call_trace['class'] . '->' : '')
+				. $call_trace['function'];
+		}
+		$context = [
+			'call_trace' => array_reverse($call_stack)
+		];
 		switch ($id) {
 			case 'DB_ERROR':
-				$this->log->error($debug_id . ' :' . $prefix . $error_string);
+				$this->log->error(
+					$debug_id . ' :' . $prefix . $error_string,
+					$context
+				);
 				break;
 			case 'DB_WARNING':
-				$this->log->warning($debug_id . ' :' . $prefix . $error_string);
+				$this->log->warning(
+					$debug_id . ' :' . $prefix . $error_string,
+					$context
+				);
 				break;
 			default:
 			// used named arguments so we can easy change the order of debug
 				$this->log->debug(
 					group_id: $debug_id,
 					message: $error_string,
-					prefix: $prefix
+					prefix: $prefix,
+					context: $context
 				);
 				break;
 		}
diff --git a/www/lib/CoreLibs/Logging/Logging.php b/www/lib/CoreLibs/Logging/Logging.php
index 443a4bee..6c748452 100644
--- a/www/lib/CoreLibs/Logging/Logging.php
+++ b/www/lib/CoreLibs/Logging/Logging.php
@@ -567,7 +567,7 @@ class Logging
 		$context_str = '';
 		if ($context != []) {
 			// TODO this here has to be changed to something better
-			$context_str = ' ' . print_r($context, true);
+			$context_str = ' :' . print_r($context, true);
 		}
 		// build log string
 		return '[' . $timestamp . '] '