{"id":3364,"date":"2010-07-15T01:53:34","date_gmt":"2010-07-15T05:53:34","guid":{"rendered":"http:\/\/g33kinfo.com\/info\/?p=3364"},"modified":"2010-07-15T01:53:34","modified_gmt":"2010-07-15T05:53:34","slug":"php-slow-log","status":"publish","type":"post","link":"https:\/\/g33kinfo.com\/info\/php-slow-log\/","title":{"rendered":"PHP slow log"},"content":{"rendered":"

From xrado.hopto.org<\/a> Just as mysql has a slow log which is enable through the \/etc\/my.cnf, php slow logging can be enabled via the following info…<\/p>\n

A few days ago a friend called me, asking me how could he find the slowest PHP scripts on its server? ..and didn’t think of anything. Of course there are tools like xdebug, but they are only useful in development. If you have a server with hundred websites and you are trying to find out what it taking the most of your cpu time, you will probably need something like mysql slow query log. <\/p>\n

I remembered that php.ini has auto_prepend_file and auto_append_file setting, and that can help me wrap every php request with the timer. I made two simple scripts that wont add much extra overhead. It works exactly as mysql slow log. You just set up the SLOW_LOG_TIME and SLOW_LOG_FILE destination. All php requests that take more than SLOW_LOG_TIME will be logged. <\/p>\n

php.ini
\n
\n1
\nauto_prepend_file = \"\/path_to\/before.php\"
\n2
\nauto_append_file = \"\/path_to\/after.php\"<\/code><\/p>\n

before.php
\n
\n1
\n< ?php\n2\ndefine('SLOW_LOG_START',microtime(TRUE));\n<\/code><\/p>\n

after.php
\n<\/code>
\n01
\n< ?php\n02\n\/\/ SETTINGS\n03\ndefine('SLOW_LOG_TIME', 0.5); \/\/ (SEC)\n04\ndefine('SLOW_LOG_FILE', '\/tmp\/php_slow.log');\n05\n \n06\n\/\/ LOGGING\n07\ndefine('SLOW_LOG_END', microtime(TRUE));\n08\n$time = SLOW_LOG_END - SLOW_LOG_START;\n09\nif ($time > SLOW_LOG_TIME)
\n10
\n{
\n11
\n $log = date('Y-m-d H:i:s').\"\\t\".round($time,3).\"\\t\".$_SERVER['SERVER_NAME'].$_SERVER['REQUEST_URI'].\"\\n\";
\n12
\n file_put_contents(SLOW_LOG_FILE, $log, FILE_APPEND);
\n13
\n}
\n<\/code><\/p>\n

sample output with SLOW_LOG_TIME set to 0.1 sec ( on my home server P4 Celeron 2Ghz, 1Gb Ram )
\n
\n1
\n2010-07-08 23:15:19 0.178 xrado.hopto.org\/post\/baked-lasagna-and-potatoes-kebab-style-seitan
\n2
\n2010-07-08 23:16:32 0.115 xrado.hopto.org\/post\/extract-emails
\n3
\n2010-07-08 23:16:34 0.13 xrado.hopto.org\/
\n4
\n2010-07-08 23:16:38 0.121 xrado.hopto.org\/post\/going-freelance
\n5
\n...
\n<\/code><\/p>\n

Actually this wont tell you which are the slowest script, but you’ll get the list of PHP requests that take the most processing time. That will give you the clue where to start looking.<\/p>\n

Final notes:<\/p>\n

do not set SLOW_LOG_TIME too low, otherwise your log will be screaming, your server too, depending on number of requests you get
\ncheck syntax in before.php and after.php, any error can break all your sites
\nremove auto_prepend_file and auto_append_file whey you are done, otherwise logs can go big and you don’t need extra disk load
\nIt will be nice to see your timings before and after the optimization.<\/p>\n","protected":false},"excerpt":{"rendered":"

From xrado.hopto.org Just as mysql has a slow log which is enable through the \/etc\/my.cnf, php slow logging can be enabled via the following info… A few days ago a friend called me, asking me how could he find the slowest PHP scripts on its server? ..and didn’t think of anything. Of course there are… <\/p>\n

Read More<\/i><\/a><\/div>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[9],"tags":[],"class_list":["post-3364","post","type-post","status-publish","format-standard","hentry","category-info"],"yoast_head":"\nPHP slow log - Linux Shtuff<\/title>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/g33kinfo.com\/info\/php-slow-log\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"PHP slow log - Linux Shtuff\" \/>\n<meta property=\"og:description\" content=\"From xrado.hopto.org Just as mysql has a slow log which is enable through the \/etc\/my.cnf, php slow logging can be enabled via the following info… A few days ago a friend called me, asking me how could he find the slowest PHP scripts on its server? ..and didn’t think of anything. Of course there are... Read More\" \/>\n<meta property=\"og:url\" content=\"https:\/\/g33kinfo.com\/info\/php-slow-log\/\" \/>\n<meta property=\"og:site_name\" content=\"Linux Shtuff\" \/>\n<meta property=\"article:publisher\" content=\"https:\/\/fb.me\/g33kinf0\" \/>\n<meta property=\"article:author\" content=\"https:\/\/fb.me\/g33kinf0\" \/>\n<meta property=\"article:published_time\" content=\"2010-07-15T05:53:34+00:00\" \/>\n<meta name=\"author\" content=\"g33kadmin\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:creator\" content=\"@https:\/\/twitter.com\/drsinger1111\" \/>\n<meta name=\"twitter:site\" content=\"@drsinger1111\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\\\/\\\/schema.org\",\"@graph\":[{\"@type\":\"Article\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/#article\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/\"},\"author\":{\"name\":\"g33kadmin\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#\\\/schema\\\/person\\\/c022e4c40b13ea1b678e6f020756f547\"},\"headline\":\"PHP slow log\",\"datePublished\":\"2010-07-15T05:53:34+00:00\",\"mainEntityOfPage\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/\"},\"wordCount\":315,\"publisher\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#\\\/schema\\\/person\\\/c022e4c40b13ea1b678e6f020756f547\"},\"articleSection\":[\"General Info\"],\"inLanguage\":\"en-US\"},{\"@type\":\"WebPage\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/\",\"url\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/\",\"name\":\"PHP slow log - Linux Shtuff\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#website\"},\"datePublished\":\"2010-07-15T05:53:34+00:00\",\"breadcrumb\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/php-slow-log\\\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"PHP slow log\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#website\",\"url\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/\",\"name\":\"Linux Shtuff\",\"description\":\"Because I have CRS Syndrome...\",\"publisher\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#\\\/schema\\\/person\\\/c022e4c40b13ea1b678e6f020756f547\"},\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-US\"},{\"@type\":[\"Person\",\"Organization\"],\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/#\\\/schema\\\/person\\\/c022e4c40b13ea1b678e6f020756f547\",\"name\":\"g33kadmin\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/wp-content\\\/uploads\\\/2022\\\/07\\\/minion-researchA.gif\",\"url\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/wp-content\\\/uploads\\\/2022\\\/07\\\/minion-researchA.gif\",\"contentUrl\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/wp-content\\\/uploads\\\/2022\\\/07\\\/minion-researchA.gif\",\"width\":512,\"height\":512,\"caption\":\"g33kadmin\"},\"logo\":{\"@id\":\"https:\\\/\\\/g33kinfo.com\\\/info\\\/wp-content\\\/uploads\\\/2022\\\/07\\\/minion-researchA.gif\"},\"description\":\"I am a g33k, Linux blogger, developer, student and Tech Writer for Liquidweb.com\\\/kb. My passion for all things tech drives my hunt for all the coolz. I often need a vacation after I get back from vacation....\",\"sameAs\":[\"https:\\\/\\\/thelinuxreport.com\",\"https:\\\/\\\/fb.me\\\/g33kinf0\",\"https:\\\/\\\/x.com\\\/https:\\\/\\\/twitter.com\\\/drsinger1111\"]}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"PHP slow log - Linux Shtuff","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/g33kinfo.com\/info\/php-slow-log\/","og_locale":"en_US","og_type":"article","og_title":"PHP slow log - Linux Shtuff","og_description":"From xrado.hopto.org Just as mysql has a slow log which is enable through the \/etc\/my.cnf, php slow logging can be enabled via the following info… A few days ago a friend called me, asking me how could he find the slowest PHP scripts on its server? ..and didn’t think of anything. Of course there are... Read More","og_url":"https:\/\/g33kinfo.com\/info\/php-slow-log\/","og_site_name":"Linux Shtuff","article_publisher":"https:\/\/fb.me\/g33kinf0","article_author":"https:\/\/fb.me\/g33kinf0","article_published_time":"2010-07-15T05:53:34+00:00","author":"g33kadmin","twitter_card":"summary_large_image","twitter_creator":"@https:\/\/twitter.com\/drsinger1111","twitter_site":"@drsinger1111","schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"Article","@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/#article","isPartOf":{"@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/"},"author":{"name":"g33kadmin","@id":"https:\/\/g33kinfo.com\/info\/#\/schema\/person\/c022e4c40b13ea1b678e6f020756f547"},"headline":"PHP slow log","datePublished":"2010-07-15T05:53:34+00:00","mainEntityOfPage":{"@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/"},"wordCount":315,"publisher":{"@id":"https:\/\/g33kinfo.com\/info\/#\/schema\/person\/c022e4c40b13ea1b678e6f020756f547"},"articleSection":["General Info"],"inLanguage":"en-US"},{"@type":"WebPage","@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/","url":"https:\/\/g33kinfo.com\/info\/php-slow-log\/","name":"PHP slow log - Linux Shtuff","isPartOf":{"@id":"https:\/\/g33kinfo.com\/info\/#website"},"datePublished":"2010-07-15T05:53:34+00:00","breadcrumb":{"@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/g33kinfo.com\/info\/php-slow-log\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/g33kinfo.com\/info\/php-slow-log\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/g33kinfo.com\/info\/"},{"@type":"ListItem","position":2,"name":"PHP slow log"}]},{"@type":"WebSite","@id":"https:\/\/g33kinfo.com\/info\/#website","url":"https:\/\/g33kinfo.com\/info\/","name":"Linux Shtuff","description":"Because I have CRS Syndrome...","publisher":{"@id":"https:\/\/g33kinfo.com\/info\/#\/schema\/person\/c022e4c40b13ea1b678e6f020756f547"},"potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/g33kinfo.com\/info\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-US"},{"@type":["Person","Organization"],"@id":"https:\/\/g33kinfo.com\/info\/#\/schema\/person\/c022e4c40b13ea1b678e6f020756f547","name":"g33kadmin","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/g33kinfo.com\/info\/wp-content\/uploads\/2022\/07\/minion-researchA.gif","url":"https:\/\/g33kinfo.com\/info\/wp-content\/uploads\/2022\/07\/minion-researchA.gif","contentUrl":"https:\/\/g33kinfo.com\/info\/wp-content\/uploads\/2022\/07\/minion-researchA.gif","width":512,"height":512,"caption":"g33kadmin"},"logo":{"@id":"https:\/\/g33kinfo.com\/info\/wp-content\/uploads\/2022\/07\/minion-researchA.gif"},"description":"I am a g33k, Linux blogger, developer, student and Tech Writer for Liquidweb.com\/kb. My passion for all things tech drives my hunt for all the coolz. I often need a vacation after I get back from vacation....","sameAs":["https:\/\/thelinuxreport.com","https:\/\/fb.me\/g33kinf0","https:\/\/x.com\/https:\/\/twitter.com\/drsinger1111"]}]}},"_links":{"self":[{"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/posts\/3364","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/comments?post=3364"}],"version-history":[{"count":0,"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/posts\/3364\/revisions"}],"wp:attachment":[{"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/media?parent=3364"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/categories?post=3364"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/g33kinfo.com\/info\/wp-json\/wp\/v2\/tags?post=3364"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}