diff --git a/add.php b/add.php index 116d32f0..e43972d0 100644 --- a/add.php +++ b/add.php @@ -24,3 +24,4 @@ } else { show_error($config['msg']['notadmin']); } +log_timing(); diff --git a/ajax/add_book_tag.php b/ajax/add_book_tag.php index 1263e313..c7bb599a 100644 --- a/ajax/add_book_tag.php +++ b/ajax/add_book_tag.php @@ -11,4 +11,5 @@ } echo ''; +log_timing(true); ?> diff --git a/ajax/anaphora.php b/ajax/anaphora.php index 450ebd42..5ec1011d 100644 --- a/ajax/anaphora.php +++ b/ajax/anaphora.php @@ -41,4 +41,5 @@ $res['error'] = 1; } +log_timing(true); die(json_encode($res)); diff --git a/ajax/annot.php b/ajax/annot.php index 1dfa8cf5..5633ae54 100644 --- a/ajax/annot.php +++ b/ajax/annot.php @@ -30,5 +30,6 @@ catch (Exception $e) { $result = 0; } +log_timing(true); echo ''; ?> diff --git a/ajax/bind_book.php b/ajax/bind_book.php index caec214c..2ffac71a 100644 --- a/ajax/bind_book.php +++ b/ajax/bind_book.php @@ -37,4 +37,5 @@ catch (Exception $e) { echo ''; } +log_timing(true); ?> diff --git a/ajax/clck_log.php b/ajax/clck_log.php index 5463a509..89b6da10 100644 --- a/ajax/clck_log.php +++ b/ajax/clck_log.php @@ -13,3 +13,4 @@ } echo ''; +log_timing(true); diff --git a/ajax/dict_pending.php b/ajax/dict_pending.php index c648ac0e..22166440 100644 --- a/ajax/dict_pending.php +++ b/ajax/dict_pending.php @@ -23,4 +23,5 @@ } echo ''; +log_timing(true); ?> diff --git a/ajax/dict_reload.php b/ajax/dict_reload.php index 2bcbaa6a..922b6af3 100644 --- a/ajax/dict_reload.php +++ b/ajax/dict_reload.php @@ -24,4 +24,5 @@ echo ''; } echo ''; +log_timing(true); ?> diff --git a/ajax/dict_substring_search.php b/ajax/dict_substring_search.php index ef33486e..ec2ae07a 100644 --- a/ajax/dict_substring_search.php +++ b/ajax/dict_substring_search.php @@ -6,4 +6,5 @@ foreach ($res as $line) { echo $line['lemma_text'] . '|' . $line['gr'] . '|' . $line['lemma_id'] ."\n"; } +log_timing(true); ?> diff --git a/ajax/download_url.php b/ajax/download_url.php index 96c26fdb..f2e3e56c 100644 --- a/ajax/download_url.php +++ b/ajax/download_url.php @@ -10,4 +10,5 @@ catch (Exception $e) { echo ''; } +log_timing(true); ?> diff --git a/ajax/game_mark_shown.php b/ajax/game_mark_shown.php index cf9d935a..9c78358f 100644 --- a/ajax/game_mark_shown.php +++ b/ajax/game_mark_shown.php @@ -25,3 +25,4 @@ } echo ''; +log_timing(true); diff --git a/ajax/get_comments.php b/ajax/get_comments.php index 8e5304ce..1e6bd94c 100644 --- a/ajax/get_comments.php +++ b/ajax/get_comments.php @@ -21,6 +21,7 @@ recursive_print(0); echo ''; +log_timing(true); function recursive_print($id) { global $comm; diff --git a/ajax/get_context.php b/ajax/get_context.php index b883ba95..62bdde2f 100644 --- a/ajax/get_context.php +++ b/ajax/get_context.php @@ -11,4 +11,5 @@ } } echo ''; +log_timing(true); ?> diff --git a/ajax/lastpar.php b/ajax/lastpar.php index a5f8784c..4ef291d2 100644 --- a/ajax/lastpar.php +++ b/ajax/lastpar.php @@ -15,4 +15,5 @@ $txt .= $r['end']; echo ''.htmlspecialchars($txt).''; +log_timing(true); ?> diff --git a/ajax/lemma_search.php b/ajax/lemma_search.php index 7121c50a..961f82a1 100644 --- a/ajax/lemma_search.php +++ b/ajax/lemma_search.php @@ -7,4 +7,5 @@ echo ''; } echo ''; +log_timing(true); ?> diff --git a/ajax/merge_tokens.php b/ajax/merge_tokens.php index cdebf0a4..a7022938 100644 --- a/ajax/merge_tokens.php +++ b/ajax/merge_tokens.php @@ -15,4 +15,5 @@ catch (Exception $e) { echo ''; } +log_timing(true); ?> diff --git a/ajax/ner.php b/ajax/ner.php index a49311f7..83de8e7b 100644 --- a/ajax/ner.php +++ b/ajax/ner.php @@ -87,4 +87,5 @@ $res['error'] = 1; } +log_timing(true); die(json_encode($res)); diff --git a/ajax/own_book.php b/ajax/own_book.php index 59267875..63218c74 100644 --- a/ajax/own_book.php +++ b/ajax/own_book.php @@ -26,3 +26,4 @@ catch (Exception $e) { echo ''; } +log_timing(true); diff --git a/ajax/paradigm_info.php b/ajax/paradigm_info.php index aea1a596..53184ce0 100644 --- a/ajax/paradigm_info.php +++ b/ajax/paradigm_info.php @@ -10,4 +10,5 @@ } } echo ''; +log_timing(true); ?> diff --git a/ajax/post_comment.php b/ajax/post_comment.php index cca6ea4d..b543898e 100644 --- a/ajax/post_comment.php +++ b/ajax/post_comment.php @@ -38,5 +38,6 @@ } catch (Exception $e) { echo ''; +log_timing(true); } ?> diff --git a/ajax/publish_update.php b/ajax/publish_update.php index 98f8df7d..59abf5b2 100644 --- a/ajax/publish_update.php +++ b/ajax/publish_update.php @@ -14,5 +14,6 @@ echo '' . ($published['success'] ? 'ok' : 'failed') . ''; echo '' . htmlspecialchars($published['output']) . ''; echo ''; +log_timing(true); ?> diff --git a/ajax/run_generator.php b/ajax/run_generator.php index 67ca3f37..8353f369 100644 --- a/ajax/run_generator.php +++ b/ajax/run_generator.php @@ -14,5 +14,6 @@ echo '' . ($result['success'] ? 'ok' : 'failed') . ''; echo '' . htmlspecialchars($result['output']) . ''; echo ''; +log_timing(true); ?> diff --git a/ajax/run_test.php b/ajax/run_test.php index fb15de1e..d3065ae1 100644 --- a/ajax/run_test.php +++ b/ajax/run_test.php @@ -14,5 +14,6 @@ echo '' . ($result['success'] ? 'ok' : 'failed') . ''; echo '' . htmlspecialchars($result['output']) . ''; echo ''; +log_timing(true); ?> diff --git a/ajax/save_check.php b/ajax/save_check.php index 436c5dc2..9bc322f4 100644 --- a/ajax/save_check.php +++ b/ajax/save_check.php @@ -31,4 +31,5 @@ $result = 0; } echo ''; +log_timing(true); ?> diff --git a/ajax/select_book.php b/ajax/select_book.php index 3c379398..6f2e7a82 100644 --- a/ajax/select_book.php +++ b/ajax/select_book.php @@ -9,4 +9,5 @@ } echo ''.$out.''; +log_timing(true); ?> diff --git a/ajax/set_option.php b/ajax/set_option.php index f0e818de..a766a25d 100644 --- a/ajax/set_option.php +++ b/ajax/set_option.php @@ -15,4 +15,5 @@ $res['error'] = 1; } +log_timing(true); die(json_encode($res)); diff --git a/ajax/syntax_group.php b/ajax/syntax_group.php index 026c5ed9..fa91e38c 100644 --- a/ajax/syntax_group.php +++ b/ajax/syntax_group.php @@ -81,4 +81,5 @@ $res['error'] = 1; } +log_timing(true); die(json_encode($res)); diff --git a/ajax/tag_autocomplete.php b/ajax/tag_autocomplete.php index 7f732f44..e6d685b5 100644 --- a/ajax/tag_autocomplete.php +++ b/ajax/tag_autocomplete.php @@ -6,4 +6,5 @@ foreach ($res as $line) { echo $line['tag_name']."\n"; } +log_timing(true); ?> diff --git a/ajax/tokenizer_monitor.php b/ajax/tokenizer_monitor.php index 7a2ec0d0..16a78ff5 100644 --- a/ajax/tokenizer_monitor.php +++ b/ajax/tokenizer_monitor.php @@ -10,5 +10,6 @@ header('Content-Type: application/x-json; charset=utf-8'); echo json_encode(get_monitor_data($_GET['from'], $_GET['until'])); +log_timing(true); ?> diff --git a/api.php b/api.php index 81a15ee3..fc8cc102 100644 --- a/api.php +++ b/api.php @@ -50,5 +50,6 @@ function json_encode_readable($arr) $answer['error'] = 'Unknown action'; } +log_timing(); die(json_encode_readable($answer)); ?> diff --git a/books.php b/books.php index 23ce022e..4310b37a 100644 --- a/books.php +++ b/books.php @@ -128,4 +128,5 @@ } else { show_error($config['msg']['notadmin']); } +log_timing(); ?> diff --git a/comments.php b/comments.php index 973c236e..8ba4c8df 100644 --- a/comments.php +++ b/comments.php @@ -7,4 +7,5 @@ $smarty->assign('comments', get_latest_comments($skip)); $smarty->assign('skip', $skip); $smarty->display('comments.tpl'); +log_timing(); ?> diff --git a/config.default.ini b/config.default.ini index 3a911a5b..01208128 100644 --- a/config.default.ini +++ b/config.default.ini @@ -70,3 +70,4 @@ morph_annot_moder_context_size = 4 morph_annot_moder_page_size = 15 morph_annot_timeout = 600 morph_annot_user_context_size = 4 +timing_log_threshold = 2 diff --git a/dict.php b/dict.php index 0b62ea66..a30dbf2a 100644 --- a/dict.php +++ b/dict.php @@ -125,4 +125,5 @@ } $smarty->display('dict/main.tpl', (int)user_has_permission('perm_dict')); } +log_timing(); ?> diff --git a/dict_diff.php b/dict_diff.php index 382766bf..c9ec28de 100644 --- a/dict_diff.php +++ b/dict_diff.php @@ -6,4 +6,5 @@ $set_id = (int)$_GET['set_id']; $smarty->assign('diff', dict_diff($lemma_id, $set_id)); $smarty->display('dict/diff.tpl'); +log_timing(); ?> diff --git a/dict_history.php b/dict_history.php index 79a8663f..909843c3 100644 --- a/dict_history.php +++ b/dict_history.php @@ -10,4 +10,5 @@ $smarty->assign('history', dict_history($lemma_id, $skip)); $smarty->assign('skip', $skip); $smarty->display('dict/history.tpl'); +log_timing(); ?> diff --git a/diff.php b/diff.php index 22905ca6..376c3ded 100644 --- a/diff.php +++ b/diff.php @@ -7,4 +7,5 @@ $rev_id = isset($_GET['rev_id']) ? (int)$_GET['rev_id'] : 0; $smarty->assign('diff', main_diff($sent_id, $set_id, $rev_id)); $smarty->display('diff.tpl'); +log_timing(); ?> diff --git a/game_admin.php b/game_admin.php index 54b60389..b627eb53 100644 --- a/game_admin.php +++ b/game_admin.php @@ -17,4 +17,5 @@ $smarty->assign('badges', get_badges_info()); $smarty->display('game_admin.tpl'); } +log_timing(); ?> diff --git a/generator_cp.php b/generator_cp.php index 8e1dd4f8..839fcf24 100644 --- a/generator_cp.php +++ b/generator_cp.php @@ -28,4 +28,5 @@ else { show_error($config['msg']['notadmin']); } +log_timing(); ?> diff --git a/history.php b/history.php index 76993220..1a1dd61c 100644 --- a/history.php +++ b/history.php @@ -24,4 +24,5 @@ $smarty->assign('maa', $maa); } $smarty->display('history.tpl', $cache_id); +log_timing(); ?> diff --git a/index.php b/index.php index dae93bc9..e1440269 100644 --- a/index.php +++ b/index.php @@ -93,4 +93,5 @@ } $smarty->display('index.tpl'); } +log_timing(); ?> diff --git a/lib/common.php b/lib/common.php index 3fdbff7a..70945906 100644 --- a/lib/common.php +++ b/lib/common.php @@ -44,8 +44,8 @@ function sql_query($q, $debug=1, $override_readonly=0) { if (file_exists('/var/lock/oc_readonly.lock') && stripos(trim($q), 'select') > 1 && !$override_readonly) throw new Exception("Database in readonly mode"); $debug = isset($_SESSION['debug_mode']) && $debug; + $time_start = microtime(true); if ($debug) { - $time_start = microtime(true); $q = str_ireplace('select ', 'SELECT SQL_NO_CACHE ', $q); } @@ -53,10 +53,10 @@ function sql_query($q, $debug=1, $override_readonly=0) { if ($debug) printf("", $total_queries, htmlspecialchars($q)); $res = $pdo_db->query($q); + $time = microtime(true)-$time_start; + $total_time += $time; + $total_queries++; if ($debug) { - $time = microtime(true)-$time_start; - $total_time += $time; - $total_queries++; printf("
%dSQL: %s%.4f сек.%.4f сек.
\n", $time, $total_time); } } @@ -80,11 +80,16 @@ function sql_insert_id() { } function sql_prepare($q) { global $pdo_db; + global $total_time; $debug = isset($_SESSION['debug_mode']); + $time_start = microtime(true); if ($debug) printf("
*PREPARE: %s
\n", htmlspecialchars($q)); try { - return $pdo_db->prepare($q); + $q = $pdo_db->prepare($q); + $time = microtime(true)-$time_start; + $total_time += $time; + return $q; } catch (PDOException $e) { if ($debug) @@ -97,15 +102,14 @@ function sql_execute($res, $params) { global $total_time; global $total_queries; $debug = isset($_SESSION['debug_mode']); - if ($debug) - $time_start = microtime(true); + $time_start = microtime(true); try { $res->execute($params); + $time = microtime(true)-$time_start; + $total_time += $time; + $total_queries++; if ($debug) { - $time = microtime(true)-$time_start; - $total_time += $time; - $total_queries++; printf("
%dSQL: %s%.4f сек.%.4f сек.
\n", $total_queries, "(prepared statement)", $time, $total_time); } } diff --git a/lib/header.php b/lib/header.php index 9b254fa7..5f93955e 100644 --- a/lib/header.php +++ b/lib/header.php @@ -8,6 +8,7 @@ require_once('vendor/autoload.php'); // Smarty, something else which was installed via Composer require_once('common.php'); require_once('lib_awards.php'); +require_once('timer.php'); $smarty = new Smarty(); // no need to require the Smarty.php, it was autoloaded $smarty->template_dir = $config['smarty']['template_dir']; diff --git a/lib/header_ajax.php b/lib/header_ajax.php index 57ff3ba1..dd9dd344 100644 --- a/lib/header_ajax.php +++ b/lib/header_ajax.php @@ -7,6 +7,7 @@ $config = parse_ini_file(__DIR__ . '/../config.ini', true); require_once('common.php'); +require_once('timer.php'); $transaction_counter = 0; $nested_transaction_counter = 0; diff --git a/login.php b/login.php index c9619302..17da9dfb 100644 --- a/login.php +++ b/login.php @@ -20,6 +20,7 @@ } else { header('Location:login.php?act=error'); } + log_timing(); exit(); case 'login_openid': $r = user_login_openid($_POST['token']); @@ -36,9 +37,11 @@ default: header('Location:login.php?act=error'); } + log_timing(); exit(); case 'login_openid2': user_login_openid_agree(isset($_POST['agree'])); + log_timing(); header('Location:index.php'); exit(); case 'logout': @@ -48,6 +51,7 @@ } else { header('Location:index.php'); } + log_timing(); exit(); case 'reg_done': $reg_status = user_register($_POST); @@ -71,6 +75,7 @@ $smarty->assign('change_status', user_change_shown_name($_POST['shown_name'])); break; } +log_timing(); if ( isset($_SERVER['HTTP_REFERER']) && diff --git a/manual.php b/manual.php index 25b8b2d0..24936a0b 100644 --- a/manual.php +++ b/manual.php @@ -10,4 +10,5 @@ $smarty->assign('content', get_wiki_page("Инструкция по интерфейсу для снятия омонимии")); $smarty->display('static/doc/annotation.tpl'); +log_timing(); ?> diff --git a/migrations/20140930101915_add_timer.php b/migrations/20140930101915_add_timer.php new file mode 100644 index 00000000..14332ada --- /dev/null +++ b/migrations/20140930101915_add_timer.php @@ -0,0 +1,22 @@ +execute("CREATE TABLE timing ( + `timestamp` TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP, + `user_id` SMALLINT UNSIGNED NOT NULL DEFAULT 0, + `page` VARCHAR(255) NOT NULL, + `total_time` FLOAT NOT NULL, + `is_ajax` TINYINT UNSIGNED NOT NULL + ) ENGINE=INNODB"); + } + + public function down() + { + $this->dropTable("timing"); + } +} diff --git a/ner.php b/ner.php index 9d8023ac..0541b0c6 100644 --- a/ner.php +++ b/ner.php @@ -26,3 +26,4 @@ $smarty->assign('page', get_books_with_NE()); $smarty->display('ner/main.tpl'); } +log_timing(); diff --git a/options.php b/options.php index 91dce243..18ef8cf1 100644 --- a/options.php +++ b/options.php @@ -42,4 +42,5 @@ } } else show_error($config['msg']['notlogged']); +log_timing(); ?> diff --git a/pools.php b/pools.php index a9d143e2..afbf5015 100644 --- a/pools.php +++ b/pools.php @@ -85,3 +85,4 @@ $smarty->assign('pools', get_morph_pools_page((int)$_GET['type'], (int)$_GET['moder_id'], $_GET['filter'])); $smarty->display('qa/pools.tpl'); } +log_timing(); diff --git a/qa.php b/qa.php index b0d9e8e4..289868e9 100644 --- a/qa.php +++ b/qa.php @@ -62,5 +62,6 @@ default: header("Location:index.php"); } +log_timing(); ?> diff --git a/revert.php b/revert.php index ca1f320b..851f7275 100644 --- a/revert.php +++ b/revert.php @@ -23,4 +23,5 @@ revert_dict($rev_id); header("Location:dict_history.php"); } +log_timing(); ?> diff --git a/search.php b/search.php index 2ae9b9d1..669a9535 100644 --- a/search.php +++ b/search.php @@ -8,3 +8,4 @@ $smarty->display('search.tpl'); } else show_error("Не задан поисковый запрос"); +log_timing(); diff --git a/sentence.php b/sentence.php index beba7e61..c01c4e76 100644 --- a/sentence.php +++ b/sentence.php @@ -65,3 +65,4 @@ } else $smarty->display('sentence.tpl'); } +log_timing(); diff --git a/sources.php b/sources.php index d72e79d5..7cf78639 100644 --- a/sources.php +++ b/sources.php @@ -23,4 +23,5 @@ $smarty->assign('skip', $skip); $smarty->display('templates/sources.tpl'); } +log_timing(); ?> diff --git a/syntax.php b/syntax.php index 896e2153..ec7eb377 100644 --- a/syntax.php +++ b/syntax.php @@ -27,4 +27,5 @@ $smarty->assign('page', get_books_with_syntax()); $smarty->display('syntax/main.tpl'); } +log_timing(); ?> diff --git a/tasks.php b/tasks.php index a15735d6..d108d555 100644 --- a/tasks.php +++ b/tasks.php @@ -68,4 +68,5 @@ 4 => 'Очень сложные задания')); $smarty->display('qa/tasks.tpl'); } +log_timing(); ?> diff --git a/user.php b/user.php index 0a925ff6..e3360860 100644 --- a/user.php +++ b/user.php @@ -13,4 +13,5 @@ 4 => 'Очень сложные задания')); $smarty->assign('badges', get_user_badges($id)); $smarty->display('user.tpl'); +log_timing(); ?> diff --git a/users.php b/users.php index 5782a9db..874b5533 100644 --- a/users.php +++ b/users.php @@ -15,4 +15,5 @@ } else { show_error($config['msg']['notadmin']); } +log_timing(); ?>