No, it should not be that much slower. There's got to be something else. Apache config?

What should I look for? Most settings are default.

I noticed some redirection problems when I tried to apply some 0.9.1 hacks in phoenix so I let them out..

I forgot to mention, I'm using MySQL 4.1.10a

Can you enable debugging (set $debug = 1 in /conf/_advanced.php).

That should give you a table of timers. Maybe there's a hint.

Do you have a lot of plugins installed? They will all get instantiated in the Alpha. But that's the case with 0.9.1, too.

Front page, 5 post, hitlog disabled, not logged in
Plugins: Auto P /Auto Link /Archives /Categories

----------------------------------
Timers
main 3.033 100.00%
sql_queries 0.108 3.56%
plugin_init 0.105 3.46%
--------------------------------------

From frontpage to admin (after login)
---------------------------------
Timers
main 2.955 100.03%
sql_queries 0.203 6.87%
plugin_init 0.106 3.59%
+ 5 < 0.5%
-------------------------------------

Images cashed in browser
Transfer (Apache) and rendering: FF: 1-1.5 sec, IE 1 sec

Thanks for the fast response...

We need more timers..

Sorry, I have no idea, what the cause may be. Actually, as you can see, it's not MySQL or the plugins.

As a comparison, looking at the demo it give 0.5-0.6 seconds (http://demo.b2evolution.net/HEAD.php4/blogs/admin/?login=admin&pwd=demopass&debug=1), but that server has 512MB RAM and a better processor. Probably it's something CPU intensive.

Yes it's CPU intensive, 100% load!

Maybe it has something to do with cross posts (crossposting between cats & blogs enabled) and redirecting because the 0.9.1 hacks (to enable shared posts between blogs) got phoenix sometimes in a infinitive redirection loop. Or maybe not: the timer is set after redirection??

I'll try a default installation next days.

Here is the complete (frontpage) debug unfo:
-----------------------------------------------------

Debug info
Timers
main 3.105 100.00%
sql_queries 0.234 7.54%
plugin_init 0.097 3.12%
Database queries: 24.
Debug messages
note:
Loading plugins...
dataobjects:
Loading User(1) into cache
dataobjectcache - Loading Group(ALL) into cache
Loading Blog(http://83.82.71.224/plammer1/design/) into cache
Item: Object with ID 53 is already cached
Item: Object with ID 51 is already cached
Item: Object with ID 45 is already cached
Item: Object with ID 50 is already cached
Item: Object with ID 42 is already cached
Loading Blog(2) into cache
Loading Blog(3) into cache
detectblog:
No blog param received, checking extra path...
Full requested Host + Path: http://83.82.71.224/plammer1/design/
Looking up absolute url : http://83.82.71.224/plammer1/design/
Using default blog 2
hit:
IP: 83.82.71.224
UserAgent: Mozilla/5.0 (Windows; U; Win98; nl; rv:1.8) Gecko/20051111 Firefox/1.5
Referer: false; type=direct
Remote Host: 535247E0.cable.casema.nl
locale:
default_locale from conf: nl-NL
default_locale from DB: nl-NL
default_locale from HTTP_ACCEPT: nl-NL
Activating blog locale: nl-NL
login:
login: NULL
pass: empty
Was already logged in... [admin]
memory:
Len of serialized $cache_imgsize: 2
Len of serialized $cache_File: 2
params:
init $global_param_list
memorize_param: locale string default=
param(-): blog set to NULL
memorize_param: blog integer default=
param(-): blog typed to integer, new value=2
memorize_param: blog integer default=0
param(-): p set to NULL
memorize_param: p integer default=
param(-): title as string
memorize_param: title string default=
param(-): m set to NULL
memorize_param: m integer default=
param(-): w typed to integer, new value=-1
memorize_param: w integer default=-1
param(-): dstart set to NULL
memorize_param: dstart integer default=
param(-): unit as string
memorize_param: unit string default=
param(-): cat set to NULL
memorize_param: cat /^[*\-]?([0-9]+(,[0-9]+)*)?$/ default=
param(-): catsel typed to array, new value=Array
memorize_param: catsel array default=Array
param(-): author set to NULL
memorize_param: author integer default=
param(-): order as string
memorize_param: order string default=DESC
param(-): orderby as string
memorize_param: orderby string default=
param(-): posts typed to integer, new value=0
memorize_param: posts integer default=0
param(-): paged set to NULL
memorize_param: paged integer default=
param(-): poststart set to NULL
memorize_param: poststart integer default=
param(-): postend set to NULL
memorize_param: postend integer default=
param(-): s as string
memorize_param: s string default=
param(-): sentence as string
memorize_param: sentence string default=AND
param(-): exact set to NULL
memorize_param: exact integer default=
param(-): preview typed to integer, new value=0
memorize_param: preview integer default=0
param(-): calendar as string
memorize_param: calendar string default=
param(-): page set to NULL
memorize_param: page integer default=
param(-): more typed to integer, new value=0
memorize_param: more integer default=0
param(-): c as string
memorize_param: c string default=
param(-): tb typed to integer, new value=0
memorize_param: tb integer default=0
param(-): pb typed to integer, new value=0
memorize_param: pb integer default=0
param(-): disp as string
memorize_param: disp string default=posts
param(-): stats typed to integer, new value=0
param(-): tempskin as string
memorize_param: tempskin string default=
Extra path info found! path_string=
param(-): results_page typed to integer, new value=1
memorize_param: results_page integer default=1
memorize_param: results_order string default=
param(-): template as string
memorize_param: template string default=main
param(-): results_page typed to integer, new value=1
memorize_param: results_page integer default=1
memorize_param: results_order string default=
param(-): results_archivelist_page typed to integer, new value=1
memorize_param: results_archivelist_page integer default=1
param(-): results_archivelist_order as string
memorize_param: results_archivelist_order string default=
perms:
User perm blog_ismember:1:2 => granted
User perm blog_ismember:1:2 => granted
User perm blog_ismember:1:2 => granted
Group perm admin:visible: => granted
User perm admin:visible: => granted
User perm blog_post_statuses:published:2 => granted
User perm blog_post_statuses:published:2 => granted
User perm blog_post_statuses:published:2 => granted
User perm blog_post_statuses:published:2 => granted
User perm blog_post_statuses:published:2 => granted
plugins:
Loading plugin: archives_plugin
Loading plugin: autolinks_plugin
Loading plugin: categories_plugin
Loading plugin: auto_p_plugin
session:
ID (from cookie): 43
ID is valid.
user_ID: '1'
No session data available.
settings:
generalsettings::get( db_version ): '9000'
generalsettings::get( time_difference ): '0'
generalsettings::get( reloadpage_timeout ): '300'
generalsettings::get( default_locale ): 'nl-NL'
generalsettings::get( timeout_sessions ): [DEFAULT]: '604800'
generalsettings::get( default_blog_ID ): '2'
generalsettings::get( posts_per_page ): '5'
generalsettings::get( what_to_show ): 'posts'
generalsettings::get( time_difference ): '0'
generalsettings::get( time_difference ): '0'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( archive_mode ): 'monthly'
generalsettings::get( time_difference ): '0'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( permalink_type ): 'pid'
generalsettings::get( links_extrapath ): '1'
skin:
No skin forced.
$default_skin = main
Forced skin: main
timer:
Starting timer main
Starting timer sql_queries
Starting timer plugin_init
vars:
Getting ReqURI from REQUEST_URI
HTTP_HOST: 83.82.71.224
$ReqURI: /plammer1/design/
$ReqPath: /plammer1/design/
DB
DB queries: 24
Query #1:
SELECT set_name, set_value
FROM plam_settings
Rows: 27 – Time: 0.0154s (6.58%)
Query #2:
SELECT agnt_ID, agnt_type
FROM plam_useragents
WHERE agnt_signature = "Mozilla/5.0 (Windows; U; Win98; nl; rv:1.8) Gecko/20051111 Firefox/1.5"
AND agnt_type = "browser"
Rows: 1 – Time: 0.0050s (2.13%)
Query #3: Hit: Check for reload
SELECT hit_ID
FROM plam_hitlog INNER JOIN plam_sessions ON hit_sess_ID = sess_ID INNER JOIN plam_useragents ON sess_agnt_ID = agnt_ID
WHERE hit_uri = "/plammer1/design/"
AND hit_datetime > "2005-12-08 20:53:54"
AND hit_remote_addr = '83.82.71.224'
AND agnt_signature = 'Mozilla/5.0 (Windows; U; Win98; nl; rv:1.8) Gecko/20051111 Firefox/1.5'
Rows: 0 – Time: 0.0088s (3.77%)
Query #4:
SELECT loc_locale, loc_charset, loc_datefmt, loc_timefmt, loc_startofweek, loc_name, loc_messages, loc_priority, loc_enabled
FROM plam_locales
ORDER BY loc_priority
Rows: 36 – Time: 0.0026s (1.11%)
Query #5:
SELECT sess_ID, sess_key, sess_data, sess_user_ID
FROM plam_sessions
WHERE sess_ID = '43'
AND sess_key = 'bzpLxtibhAM1wnT99itqUfFxgqcyby57'
AND sess_lastseen > 1134071934
Rows: 1 – Time: 0.0026s (1.11%)
Query #6:
UPDATE plam_sessions SET sess_lastseen = "2005-12-08 20:58:54", sess_ipaddress = "83.82.71.224"
WHERE sess_ID = 43
Rows: 1 – Time: 0.0024s (1.01%)
Query #7: DataObjectCache::get_by_ID()
SELECT *
FROM plam_users
WHERE user_ID = 1
Rows: 1 – Time: 0.0018s (0.76%)
Query #8:
SELECT *
FROM plam_groups
Rows: 4 – Time: 0.0017s (0.74%)
Query #9: Blog::get_by_url()
SELECT *
FROM plam_blogs
WHERE ( blog_siteurl = 'http://83.82.71.224/plammer1/design/' )
Rows: 0 – Time: 0.0021s (0.90%)
Query #10:
SELECT *
FROM plam_blogs
ORDER BY blog_ID
Rows: 9 – Time: 0.0031s (1.31%)
Query #11:
SELECT *
FROM plam_blogusers
WHERE bloguser_blog_ID = 2
AND bloguser_user_ID = 1
Rows: 1 – Time: 0.0045s (1.90%)
Query #12: Get ID list for Item List (Main|Lastpostdate) Query
SELECT DISTINCT post_ID
FROM plam_posts INNER JOIN plam_postcats ON post_ID = postcat_post_ID INNER JOIN plam_categories ON postcat_cat_ID = cat_ID
WHERE (cat_blog_ID = 2)
AND ( ( ( post_status = "private"
AND post_creator_user_ID = 1 )
OR post_status IN ('published','protected') ) )
AND (post_datestart <= '2005-12-08 20:58:56')
ORDER BY post_datestart DESC
LIMIT 5
Rows: 5 – Time: 0.0058s (2.47%)
Query #13: Get data for Item List (Main|Lastpostdate) Query
SELECT *
FROM plam_posts
WHERE post_ID IN (53,51,45,50,42)
ORDER BY post_datestart DESC
Rows: 5 – Time: 0.0021s (0.88%)
Query #14: Get ID list for Item List (Main|Lastpostdate) Query
SELECT DISTINCT post_ID
FROM plam_posts INNER JOIN plam_postcats ON post_ID = postcat_post_ID INNER JOIN plam_categories ON postcat_cat_ID = cat_ID
WHERE (cat_blog_ID = 2)
AND ( ( ( post_status = "private"
AND post_creator_user_ID = 1 )
OR post_status IN ('published','protected') ) )
AND (post_datestart <= '2005-12-08 20:58:56')
ORDER BY post_datestart DESC
LIMIT 15
Rows: 13 – Time: 0.0058s (2.46%)
Query #15: Get data for Item List (Main|Lastpostdate) Query
SELECT *
FROM plam_posts
WHERE post_ID IN (53,51,45,50,42,35,29,28,27,30,25,31,46)
ORDER BY post_datestart DESC
Rows: 13 – Time: 0.0058s (2.48%)
Query #16: DataObjectCache::get_by_ID()
SELECT *
FROM plam_blogs
WHERE blog_ID = 2
Rows: 1 – Time: 0.0039s (1.65%)
Query #17:
SELECT *
FROM plam_plugins
ORDER BY plug_priority
Rows: 4 – Time: 0.0017s (0.75%)
Query #18:
SELECT COUNT( DISTINCT YEAR(post_datestart), MONTH(post_datestart) )
FROM plam_posts INNER JOIN plam_postcats ON post_ID = postcat_post_ID INNER JOIN plam_categories ON postcat_cat_ID = cat_ID
WHERE (cat_blog_ID = 2)
AND ( ( ( post_status = "private"
AND post_creator_user_ID = 1 )
OR post_status IN ('published','protected') ) )
AND (post_datestart <= '2005-12-08 20:58:56')
Rows: 1 – Time: 0.0061s (2.60%)
Query #19:
SELECT YEAR(post_datestart) AS year, MONTH(post_datestart) AS month, COUNT(DISTINCT postcat_post_ID) AS count
FROM plam_posts INNER JOIN plam_postcats ON post_ID = postcat_post_ID INNER JOIN plam_categories ON postcat_cat_ID = cat_ID
WHERE (cat_blog_ID = 2)
AND ( ( ( post_status = "private"
AND post_creator_user_ID = 1 )
OR post_status IN ('published','protected') ) )
AND (post_datestart <= '2005-12-08 20:58:56')
GROUP BY year, month
ORDER BY year DESC, month DESC
Rows: 6 – Time: 0.0061s (2.62%)
Query #20:
SELECT cat_ID, cat_parent_ID, cat_name, cat_blog_ID
FROM plam_categories
ORDER BY cat_name
Rows: 18 – Time: 0.0023s (0.98%)
Query #21:
SELECT postcat_post_ID, postcat_cat_ID
FROM plam_postcats
WHERE postcat_post_ID IN (42,50,45,51,53)
ORDER BY postcat_post_ID, postcat_cat_ID
Rows: 8 – Time: 0.0100s (4.27%)
Query #22:
SELECT comment_post_ID, comment_type, COUNT(*) AS type_count
FROM plam_comments
WHERE comment_post_ID IN (42,50,45,51,53)
GROUP BY comment_post_ID, comment_type
Rows: 1 – Time: 0.0109s (4.67%)
Query #23: DataObjectCache::get_by_ID()
SELECT *
FROM plam_blogs
WHERE blog_ID = 3
Rows: 1 – Time: 0.1033s (44.15%)
Query #24: Get result count
SELECT COUNT(post_ID)
FROM plam_posts INNER JOIN plam_postcats ON post_ID = postcat_post_ID INNER JOIN plam_categories ON postcat_cat_ID = cat_ID
WHERE (cat_blog_ID = 2)
AND ( ( ( post_status = "private"
AND post_creator_user_ID = 1 )
OR post_status IN ('published','protected') ) )
AND (post_datestart <= '2005-12-08 20:58:56')
Rows: 1 – Time: 0.0046s (1.95%)
Total rows: 158

Nothing wrong(?), just heavy CPU load!

Front page loaded (FF browser cache cleared, no login)

0.9.1 (my skin)
----------------------------
Debug info
Page processing time: 1.841 seconds.
SQL processing time: 0.187 seconds, 10.16%.

Phoenix (my skin)
-----------------------------
Timers
main 3.445 100.03%
sql_queries 0.143 4.15%
plugin_init 0.108 3.14%

Phoenix (clean installation with default custom skin & demo posts)
-----------------------------------------------------------
Timers
main 4.240 100.00%
plugin_init 0.229 5.40%
sql_queries 0.228 5.38%
+ 1 < 0.5%

That could be a problem on nondedicated servers.....

in evocore/_hit.class.php, replace function get_remote_host() with this one:

	/**
	 * Get the remote hostname.
	 *
	 * @return string
	 */
	function get_remote_host( $allow_nslookup = false )
	{
		global $Timer;
		
		$Timer->start( 'Hit::get_remote_host' );
		
		if( is_null($this->_remoteHost) )
		{
			if( isset( $_SERVER['REMOTE_HOST'] ) )
			{
				$this->_remoteHost = $_SERVER['REMOTE_HOST'];
			}
			elseif( $allow_nslookup )
			{	// We allowed reverse DNS lookup:
				// This can be terribly time consuming (4/5 seconds!) when there is no reverse dns available!
				// This is the case on many intranets and many users' first time installs!!!
				// Some people end up considering evocore is very slow just because of this line!
				// This cannot be enabled by default.
				$this->_remoteHost = @gethostbyaddr($this->IP);
			}
			else
			{
				$this->_remoteHost = '';
			}
		}

		$Timer->pause( 'Hit::get_remote_host' );

		return $this->_remoteHost;
	}

Thanks, its about 1 second faster. It's not far from 0.9.1 performance.

Phoenix (my skin)
---------------------
Timers
main 2.595 100.00%
sql_queries 0.363 13.99%
plugin_init 0.100 3.85%
+ 2 < 0.5%

Phoenix (clean demo)
--------------------
Timers
main 3.109 100.00%
sql_queries 0.183 5.89%
plugin_init 0.183 5.89%
+ 2 < 0.5%

Plam

fplanque, I guess you'll commit this fix.. right? :)

AFAIK I've checked this in to CVS before posting it here...

No, at least not to HEAD and only as far as I can see of course.. ;)

Hello.

I don't see this modification into CVS :
evocms/b2evolution/blogs/evocore/_hit.class.php
Default branch: MAIN
Revision 1.42

It's normal ?

Thanx.

Yes, it is. François just hasn't committed it.

As he wants to do major file organisations now, I'll leave this up to him.

(Normally, he should get notified of new posts to this thread, if he has not disabled it.)

I'll add it to the todo list so we won't forget about it.

Oki.
I'll survey that ;)
Thank you.

I wonder how I screwed this up, but I just check it in (now).