From dfba656355391d669c90e2ef7ab2104c329dda93 Mon Sep 17 00:00:00 2001 From: Shish Date: Mon, 24 Nov 2014 02:21:45 +0000 Subject: [PATCH 1/5] die more explicitly when memcache is missing (PHP is terrible) --- core/database.class.php | 3 +++ 1 file changed, 3 insertions(+) diff --git a/core/database.class.php b/core/database.class.php index f59ed418..18998dc9 100644 --- a/core/database.class.php +++ b/core/database.class.php @@ -284,6 +284,9 @@ class MemcacheCache implements CacheEngine { $this->memcache = new Memcache; @$this->memcache->pconnect($hp[0], $hp[1]); } + else { + print "no memcache"; exit; + } } /** From 1c60942730910e59a64b89d623729378466065ed Mon Sep 17 00:00:00 2001 From: Shish Date: Wed, 26 Nov 2014 13:07:30 +0000 Subject: [PATCH 2/5] log hit/miss when DEBUG_CACHE is on --- core/database.class.php | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/core/database.class.php b/core/database.class.php index 18998dc9..fd9bade2 100644 --- a/core/database.class.php +++ b/core/database.class.php @@ -295,10 +295,11 @@ class MemcacheCache implements CacheEngine { */ public function get($key) { assert(!is_null($key)); - if((DEBUG_CACHE === true) || (is_null(DEBUG_CACHE) && @$_GET['DEBUG_CACHE'])) { - file_put_contents("data/cache.log", "Cache lookup: $key\n", FILE_APPEND); - } $val = $this->memcache->get($key); + if((DEBUG_CACHE === true) || (is_null(DEBUG_CACHE) && @$_GET['DEBUG_CACHE'])) { + $hit = $val === false ? "miss" : "hit"; + file_put_contents("data/cache.log", "Cache $hit: $key\n", FILE_APPEND); + } if($val !== false) { $this->hits++; return $val; From 4721d666cde7a8aec43aa12a3309426e534bc68c Mon Sep 17 00:00:00 2001 From: Shish Date: Wed, 26 Nov 2014 13:09:22 +0000 Subject: [PATCH 3/5] log time spent waiting for database queries --- core/database.class.php | 14 +++++++++++++- core/util.inc.php | 5 +++-- ext/statsd/main.php | 1 + 3 files changed, 17 insertions(+), 3 deletions(-) diff --git a/core/database.class.php b/core/database.class.php index fd9bade2..da68d598 100644 --- a/core/database.class.php +++ b/core/database.class.php @@ -384,6 +384,7 @@ class Database { * @var null|PDO */ private $db = null; + public $dbtime = 0.0; /** * Meta info about the database engine. @@ -580,7 +581,10 @@ class Database { * @return array */ public function get_all($query, $args=array()) { - return $this->execute($query, $args)->fetchAll(); + $_start = microtime(true); + $data = $this->execute($query, $args)->fetchAll(); + $this->dbtime += microtime(true) - $_start; + return $data; } /** @@ -591,7 +595,9 @@ class Database { * @return mixed|null */ public function get_row($query, $args=array()) { + $_start = microtime(true); $row = $this->execute($query, $args)->fetch(); + $this->dbtime += microtime(true) - $_start; return $row ? $row : null; } @@ -603,11 +609,13 @@ class Database { * @return array */ public function get_col($query, $args=array()) { + $_start = microtime(true); $stmt = $this->execute($query, $args); $res = array(); foreach($stmt as $row) { $res[] = $row[0]; } + $this->dbtime += microtime(true) - $_start; return $res; } @@ -619,11 +627,13 @@ class Database { * @return array */ public function get_pairs($query, $args=array()) { + $_start = microtime(true); $stmt = $this->execute($query, $args); $res = array(); foreach($stmt as $row) { $res[$row[0]] = $row[1]; } + $this->dbtime += microtime(true) - $_start; return $res; } @@ -635,7 +645,9 @@ class Database { * @return mixed */ public function get_one($query, $args=array()) { + $_start = microtime(true); $row = $this->execute($query, $args)->fetch(); + $this->dbtime += microtime(true) - $_start; return $row[0]; } diff --git a/core/util.inc.php b/core/util.inc.php index 6f510ca2..029fcee0 100644 --- a/core/util.inc.php +++ b/core/util.inc.php @@ -1344,12 +1344,13 @@ function get_debug_info() { else { $commit = " (".$config->get_string("commit_hash").")"; } - $time = sprintf("%5.2f", microtime(true) - $_load_start); + $time = sprintf("%.2f", microtime(true) - $_load_start); + $dbtime = sprintf("%.2f", $database->dbtime); $i_files = count(get_included_files()); $hits = $database->cache->get_hits(); $miss = $database->cache->get_misses(); - $debug = "
Took $time seconds and {$i_mem}MB of RAM"; + $debug = "
Took $time seconds (db:$dbtime) and {$i_mem}MB of RAM"; $debug .= "; Used $i_files files and $_execs queries"; $debug .= "; Sent $_event_count events"; $debug .= "; $hits cache hits and $miss misses"; diff --git a/ext/statsd/main.php b/ext/statsd/main.php index c80acd39..5a17fbb3 100644 --- a/ext/statsd/main.php +++ b/ext/statsd/main.php @@ -23,6 +23,7 @@ class StatsDInterface extends Extension { $time = microtime(true) - $_load_start; StatsDInterface::$stats["shimmie.$type.hits"] = "1|c"; StatsDInterface::$stats["shimmie.$type.time"] = "$time|ms"; + StatsDInterface::$stats["shimmie.$type.time-db"] = "{$database->dbtime}|ms"; StatsDInterface::$stats["shimmie.$type.memory"] = memory_get_peak_usage(true)."|c"; StatsDInterface::$stats["shimmie.$type.files"] = count(get_included_files())."|c"; StatsDInterface::$stats["shimmie.$type.queries"] = $_execs."|c"; From c0dfd9adc0fe84a8c618542c66c21d8889f8e113 Mon Sep 17 00:00:00 2001 From: Shish Date: Wed, 26 Nov 2014 13:09:49 +0000 Subject: [PATCH 4/5] a little extra consistency in cache variable names --- core/user.class.php | 4 ++-- ext/featured/main.php | 4 ++-- ext/index/main.php | 4 ++-- ext/pm/main.php | 4 ++-- 4 files changed, 8 insertions(+), 8 deletions(-) diff --git a/core/user.class.php b/core/user.class.php index d9b9c45d..60c8fa48 100644 --- a/core/user.class.php +++ b/core/user.class.php @@ -67,7 +67,7 @@ class User { */ public static function by_session(/*string*/ $name, /*string*/ $session) { global $config, $database; - $row = $database->cache->get("user-session-$name-$session"); + $row = $database->cache->get("user-session:$name-$session"); if(!$row) { if($database->get_driver_name() === "mysql") { $query = "SELECT * FROM users WHERE name = :name AND md5(concat(pass, :ip)) = :sess"; @@ -76,7 +76,7 @@ class User { $query = "SELECT * FROM users WHERE name = :name AND md5(pass || :ip) = :sess"; } $row = $database->get_row($query, array("name"=>$name, "ip"=>get_session_ip($config), "sess"=>$session)); - $database->cache->set("user-session-$name-$session", $row, 600); + $database->cache->set("user-session:$name-$session", $row, 600); } return is_null($row) ? null : new User($row); } diff --git a/ext/featured/main.php b/ext/featured/main.php index e0a23676..0b643633 100644 --- a/ext/featured/main.php +++ b/ext/featured/main.php @@ -60,13 +60,13 @@ class Featured extends Extension { global $config, $database, $page, $user; $fid = $config->get_int("featured_id"); if($fid > 0) { - $image = $database->cache->get("featured_image_object-$fid"); + $image = $database->cache->get("featured_image_object:$fid"); if($image === false) { $image = Image::by_id($fid); if($image) { // make sure the object is fully populated before saving $image->get_tag_array(); } - $database->cache->set("featured_image_object-$fid", $image, 600); + $database->cache->set("featured_image_object:$fid", $image, 600); } if(!is_null($image)) { if(class_exists("Ratings")) { diff --git a/ext/index/main.php b/ext/index/main.php index c3250bf7..99921d27 100644 --- a/ext/index/main.php +++ b/ext/index/main.php @@ -260,10 +260,10 @@ class Index extends Extension { #log_debug("index", "Search for ".implode(" ", $search_terms), false, array("terms"=>$search_terms)); $total_pages = Image::count_pages($search_terms); if(SPEED_HAX && $count_search_terms === 0 && ($page_number < 10)) { // extra caching for the first few post/list pages - $images = $database->cache->get("post-list-$page_number"); + $images = $database->cache->get("post-list:$page_number"); if(!$images) { $images = Image::find_images(($page_number-1)*$page_size, $page_size, $search_terms); - $database->cache->set("post-list-$page_number", $images, 600); + $database->cache->set("post-list:$page_number", $images, 600); } } else { diff --git a/ext/pm/main.php b/ext/pm/main.php index 2deaf4e4..e07d44a4 100644 --- a/ext/pm/main.php +++ b/ext/pm/main.php @@ -197,7 +197,7 @@ class PrivMsg extends Extension { private function count_pms(User $user) { global $database; - $count = $database->cache->get("pm-count-{$user->id}"); + $count = $database->cache->get("pm-count:{$user->id}"); if(is_null($count) || $count === false) { $count = $database->get_one(" SELECT count(*) @@ -205,7 +205,7 @@ class PrivMsg extends Extension { WHERE to_id = :to_id AND is_read = :is_read ", array("to_id" => $user->id, "is_read" => "N")); - $database->cache->set("pm-count-{$user->id}", $count, 600); + $database->cache->set("pm-count:{$user->id}", $count, 600); } return $count; } From e4be2c24c688f677f992314bd3cd444d27654665 Mon Sep 17 00:00:00 2001 From: Shish Date: Sun, 30 Nov 2014 12:49:08 +0000 Subject: [PATCH 5/5] update lib/context.php --- lib/context.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/context.php b/lib/context.php index 39e0bb92..9372b3c7 100644 --- a/lib/context.php +++ b/lib/context.php @@ -20,7 +20,7 @@ function ctx_log_msg($func, $text, $type) { microtime(true), # returning a float is 5.0+ php_uname('n'), # gethostname() is 5.3+ posix_getpid(), - posix_getpid(), //gettid(), + function_exists("hphp_get_thread_id") ? hphp_get_thread_id() : posix_getpid(), $type, $func, $text ); }