Fix #1944 add option to display complete call stack for queries

common/css/rhymix.less

@@ -365,6 +365,12 @@ a img {
 					list-style: disc;
 					margin: 0; padding: 0; text-indent: 0;
 					color: #888;
+					ul {
+						padding-left: 20px;
+						li {
+							list-style: circle;
+						}
+					}
 				}
 			}
 		}

common/defaults/config.php

@@ -101,6 +101,7 @@ return array(
 		'display_content' => array('request_info', 'entries', 'errors', 'queries'),
 		'display_to' => 'admin',
 		'query_comment' => false,
+		'query_full_stack' => false,
 		'write_error_log' => 'fatal',
 		'allow' => array(),
 	),

common/framework/db.php

@@ -42,8 +42,10 @@ class DB
 	protected $_query_id = '';
 	protected $_errno = 0;
 	protected $_errstr = '';
+	protected $_debug_queries = false;
 	protected $_debug_comment = false;
-	
+	protected $_debug_full_stack = false;
+
 	/**
 	 * Transaction level.
 	 */
@@ -130,7 +132,9 @@ class DB
 		$this->db_version = $this->_handle->getAttribute(\PDO::ATTR_SERVER_VERSION);
 		
 		// Cache the debug comment setting.
-		$this->_debug_comment = config('debug.query_comment') ? true : false;
+		$this->_debug_queries = in_array('queries', Config::get('debug.display_content') ?: []);
+		$this->_debug_comment = !!config('debug.query_comment');
+		$this->_debug_full_stack = !!Config::get('debug.query_full_stack');
 	}
 	
 	/**
@@ -1160,13 +1164,6 @@ class DB
 	 */
 	public function getQueryLog(string $query, float $elapsed_time): array
 	{
-		// Cache the debug status to improve performance.
-		static $debug_queries = null;
-		if ($debug_queries === null)
-		{
-			$debug_queries = in_array('queries', Config::get('debug.display_content') ?: []);
-		}
-		
 		// Compose the basic structure of the log entry.
 		$result = array(
 			'query' => preg_replace('!\n/\* .+ \*/$!s', '', $query),
@@ -1183,7 +1180,7 @@ class DB
 		);
 		
 		// Add debug information if enabled.
-		if ($this->_errno || $debug_queries)
+		if ($this->_errno || $this->_debug_queries)
 		{
 			$backtrace = debug_backtrace(\DEBUG_BACKTRACE_IGNORE_ARGS);
 			foreach ($backtrace as $no => $call)
@@ -1196,7 +1193,7 @@ class DB
 					if (isset($backtrace[$no]))
 					{
 						$result['called_method'] = $backtrace[$no]['class'] . $backtrace[$no]['type'] . $backtrace[$no]['function'];
-						$result['backtrace'] = array_slice($backtrace, $no, 1);
+						$result['backtrace'] = $this->_debug_full_stack ? array_slice($backtrace, $no) : [];
 					}
 					else
 					{

common/js/debug.js

@@ -131,6 +131,14 @@ $(function() {
 					description.append($('<li></li>').text("Connection: " + data.queries[i].query_connection));
 					description.append($('<li></li>').text("Query ID: " + data.queries[i].query_id));
 					description.append($('<li></li>').text("Query Time: " + (data.queries[i].query_time ? (data.queries[i].query_time.toFixed(4) + " sec") : "")));
+					if (data.queries[i].backtrace && data.queries[i].backtrace.length) {
+						backtrace = $('<ul></ul>').appendTo(description.find('li:first-child'));
+						for (j in data.queries[i].backtrace) {
+							if (data.queries[i].backtrace[j].file) {
+								backtrace.append($('<li></li>').text(data.queries[i].backtrace[j].file + ":" + data.queries[i].backtrace[j].line));
+							}
+						}
+					}
 				}
 				description.append($('<li></li>').text("Result: " + ((data.queries[i].message === "success" || !data.queries[i].message) ? "success" : data.queries[i].message)));
 			}
@@ -149,6 +157,14 @@ $(function() {
 					description.append($('<li></li>').text("Connection: " + data.slow_queries[i].query_connection));
 					description.append($('<li></li>').text("Query ID: " + data.slow_queries[i].query_id));
 					description.append($('<li></li>').text("Query Time: " + (data.slow_queries[i].query_time ? (data.slow_queries[i].query_time.toFixed(4) + " sec") : "")));
+					if (data.queries[i].backtrace && data.queries[i].backtrace.length) {
+						backtrace = $('<ul></ul>').appendTo(description.find('li:first-child'));
+						for (j in data.queries[i].backtrace) {
+							if (data.queries[i].backtrace[j].file) {
+								backtrace.append($('<li></li>').text(data.queries[i].backtrace[j].file + ":" + data.queries[i].backtrace[j].line));
+							}
+						}
+					}
 				}
 				description.append($('<li></li>').text("Result: " + ((data.slow_queries[i].message === "success" || !data.slow_queries[i].message) ? "success" : ("error " + data.slow_queries[i].error_code + " " + data.slow_queries[i].message))));
 			}

common/tpl/debug_comment.html

@@ -99,6 +99,13 @@ Database Queries
 		$query_result = ($query->message === 'success') ? 'success' : $query->message;
 		echo sprintf('%02d. %s', ++$query_count, $query->query_string) . "\n";
 		echo sprintf('    - Caller:      %s', $query_caller) . "\n";
+		foreach ($query->backtrace ?? [] as $key => $backtrace)
+		{
+			if (isset($backtrace['file']) && isset($backtrace['line']))
+			{
+				echo sprintf('                   %s line %d', $backtrace['file'], $backtrace['line']) . "\n";
+			}
+		}
 		echo sprintf('    - Connection:  %s', $query->query_connection) . "\n";
 		echo sprintf('    - Query ID:    %s', $query->query_id) . "\n";
 		echo sprintf('    - Query Time:  %0.4f sec', $query->query_time) . "\n";
@@ -122,6 +129,13 @@ Slow Queries
 		$query_result = ($query->message === 'success') ? 'success' : sprintf('error %d %s', $query->error_code, $query->message);
 		echo sprintf('%02d. %s', ++$query_count, $query->query_string) . "\n";
 		echo sprintf('    - Caller:      %s', $query_caller) . "\n";
+		foreach ($query->backtrace ?? [] as $key => $backtrace)
+		{
+			if (isset($backtrace['file']) && isset($backtrace['line']))
+			{
+				echo sprintf('                   %s line %d', $backtrace['file'], $backtrace['line']) . "\n";
+			}
+		}
 		echo sprintf('    - Connection:  %s', $query->query_connection) . "\n";
 		echo sprintf('    - Query ID:    %s', $query->query_id) . "\n";
 		echo sprintf('    - Query Time:  %0.4f sec', $query->query_time) . "\n";

modules/admin/admin.admin.controller.php

@@ -918,6 +918,7 @@ class adminAdminController extends admin
 		Rhymix\Framework\Config::set('debug.display_type', $display_type);
 		Rhymix\Framework\Config::set('debug.display_to', strval($vars->debug_display_to) ?: 'admin');
 		Rhymix\Framework\Config::set('debug.query_comment', $vars->debug_query_comment === 'Y');
+		Rhymix\Framework\Config::set('debug.query_full_stack', $vars->debug_query_full_stack === 'Y');
 		Rhymix\Framework\Config::set('debug.write_error_log', strval($vars->debug_write_error_log) ?: 'fatal');
 		
 		// Debug content

modules/admin/admin.admin.view.php

@@ -628,6 +628,7 @@ class adminAdminView extends admin
 		Context::set('debug_display_content', Rhymix\Framework\Config::get('debug.display_content'));
 		Context::set('debug_display_to', Rhymix\Framework\Config::get('debug.display_to'));
 		Context::set('debug_query_comment', Rhymix\Framework\Config::get('debug.query_comment'));
+		Context::set('debug_query_full_stack', Rhymix\Framework\Config::get('debug.query_full_stack'));
 		Context::set('debug_write_error_log', Rhymix\Framework\Config::get('debug.write_error_log'));
 		
 		// IP access control

modules/admin/lang/en.php

@@ -228,6 +228,7 @@ $lang->debug_display_to_ip = 'Visitors from IP adresses listed below';
 $lang->debug_display_to_everyone = 'Everyone';
 $lang->debug_log_filename = 'Log filename';
 $lang->debug_query_comment = 'Add Comment to Queries';
+$lang->debug_query_full_stack = 'Show Complete Call Stack for Queries';
 $lang->debug_write_error_log = 'Write to Error Log';
 $lang->debug_write_error_log_all = 'All errors and warnings';
 $lang->debug_write_error_log_fatal = 'Fatal errors only';
@@ -237,6 +238,7 @@ $lang->about_debug_write_error_log = 'Select how much information will be record
 $lang->about_debug_error_log_path = 'The error log location that is currently configured in php.ini is %s';
 $lang->about_debug_error_log_path_empty = '(none)';
 $lang->about_debug_query_comment = 'Add a comment containing the query name and IP address to every SQL statement. This may help you determine where slow queries are coming from.';
+$lang->about_debug_query_full_stack = 'Show the complete call stack for each query. This can increase the size of debug data considerably.';
 $lang->msg_debug_log_filename_not_writable = 'Rhymix cannot write log files in the specified path.';
 $lang->debug_allowed_ip = 'Allowed IP addresses';
 $lang->seo_main_title = 'Main Page Title';

modules/admin/lang/ko.php

@@ -224,6 +224,7 @@ $lang->debug_display_to_ip = '아래 IP의 방문자에게만 표시';
 $lang->debug_display_to_everyone = '모두에게 표시';
 $lang->debug_log_filename = '디버그 정보 기록 파일';
 $lang->debug_query_comment = '쿼리에 주석 추가';
+$lang->debug_query_full_stack = '쿼리 콜 스택 전체 표시';
 $lang->debug_write_error_log = '에러 로그에 기록';
 $lang->debug_write_error_log_all = '모든 에러와 경고를 기록';
 $lang->debug_write_error_log_fatal = '치명적인 에러만 기록';
@@ -233,6 +234,7 @@ $lang->about_debug_write_error_log = 'PHP 에러 로그에 얼마나 많은 정
 $lang->about_debug_error_log_path = '현재 php.ini에서 설정된 에러 로그 경로는 %s 입니다.';
 $lang->about_debug_error_log_path_empty = '(없음)';
 $lang->about_debug_query_comment = '쿼리명과 IP 주소를 포함하는 주석을 모든 쿼리에 추가하여, 부하를 유발하는 쿼리 및 방문자를 DB에서 쉽게 파악할 수 있도록 합니다.';
+$lang->about_debug_query_full_stack = '쿼리와 관련된 콜 스택을 모두 표시합니다. 디버그 정보의 분량이 크게 늘어날 수 있습니다.';
 $lang->msg_debug_log_filename_not_writable = '지정한 경로에 로그 파일을 작성할 수 없습니다.';
 $lang->debug_allowed_ip = '디버그 허용 IP';
 $lang->seo_main_title = '메인화면 제목';

modules/admin/tpl/config_debug.html

@@ -95,6 +95,14 @@
 				<p class="x_help-block">{$lang->about_debug_query_comment}</p>
 			</div>
 		</div>
+		<div class="x_control-group">
+			<label class="x_control-label">{$lang->debug_query_full_stack}</label>
+			<div class="x_controls">
+				<label for="debug_query_full_stack_Y" class="x_inline"><input type="radio" name="debug_query_full_stack" id="debug_query_full_stack_Y" value="Y" checked="checked"|cond="$debug_query_full_stack" /> {$lang->cmd_yes}</label>
+				<label for="debug_query_full_stack_N" class="x_inline"><input type="radio" name="debug_query_full_stack" id="debug_query_full_stack_N" value="N" checked="checked"|cond="!$debug_query_full_stack" /> {$lang->cmd_no}</label>
+				<p class="x_help-block">{$lang->about_debug_query_full_stack}</p>
+			</div>
+		</div>
 		<div class="x_control-group">
 			<label class="x_control-label">{$lang->debug_write_error_log}</label>
 			<div class="x_controls">