Problems upgrading from 4.4.1 to CVS 2004-09-26

By kbahey on 27 Sep 2004 at 14:39 UTC

I have a working Drupal installation that uses the 4.4.1 and the xtemplate / pushbutton.

This installation hosts 3 separate domains on one installation, in the same database, but with different prefixes in the conf files.

I tried to upgrade to yesterday (2004-09-26 CVS), and ran into problems.

Here are the steps I did:

Created the users_roles and locales_meta tables for each domain

  CREATE TABLE site1_users_roles (
    uid int(10) unsigned NOT NULL default '0',
    rid int(10) unsigned NOT NULL default '0',
    PRIMARY KEY (uid, rid)
  );
  CREATE TABLE site2_locales_meta (
    locale varchar(12) NOT NULL default '',
    name varchar(64) NOT NULL default '',
    enabled int(2) NOT NULL default '0',
    isdefault int(2) NOT NULL default '0',
    plurals int(1) NOT NULL default '0',
    formula varchar(128) NOT NULL default '',
    PRIMARY KEY  (locale)
  );

(same for site2, and site3)

Ran the update.php script

At this point, I can browse the site with no problem.

However, when I go into the admin menus and change anything (I tried going into admin/themes and unchecking 'primary links' one time, and tried to remove the path to the logo at another time), and then clock on Save configuration, the site becomes unusable with the following message for any access:

     Fatal error: Maximum execution time of 30 seconds exceeded in /home/myusername/html/includes/menu.inc on line 653

The two other sites are unaffected, until I try to change anything in the admin menus, then it is ruined as well.

I tried going into the database and deleting the variable 'theme_settings', but the results were the same (time out of script).

Luckily, this is just my test site at home, and not the live site, otherwise it would be a big problem.

What is going on?

Comments

Even no need to update anything

kbahey commented 27 September 2004 at 15:50

Well, I did one more test. I decided to just browse the admin menus, and not update anything there. After sometime, it experienced the same symptom (script timeout), without me updating anything! Very strange.

Here is a database dump of the last few accesses in the access_log table before the system locked up, sorted descending by timestamp.The last successful access was to admin/settings/story. Nothing worked after that:

url   	  					hostname   	 timestamp 	title   	  	path
http://example.com/admin/settings/story  	1.1.1.1  1  	1096297237  	modules  	admin/modules
http://example.com/admin/settings/statistics 	1.1.1.1	1 	1096297222 	story 		admin/settings/story
http://example.com/admin/settings/sitemap 	1.1.1.1	1 	1096297210 	statistics 	admin/settings/statistics
http://example.com/admin/settings/forum 	1.1.1.1	1 	1096297202 	sitemap 	admin/settings/sitemap
http://example.com/admin/settings/contact 	1.1.1.1	1 	1096297192 	forum 		admin/settings/forum
http://example.com/admin/settings 		1.1.1.1	1 	1096297182 	contact 	admin/settings/contact
http://example.com/admin 			1.1.1.1	1 	1096297154 	settings 	admin/settings
http://example.com/index.html 			1.1.1.1	1 	1096297147 	administer 	admin

The code that causes this in the following function, specifically on the array_unshift() line:

function _menu_get_active_trail() {
  static $trail;

  if (!isset($trail)) {
    $menu = menu_get_menu();

    $trail = array();

    $mid = menu_get_active_item();

    // Follow the parents up the chain to get the trail.
    while ($mid && $menu['items'][$mid]) {
      array_unshift($trail, $mid);
      $mid = $menu['items'][$mid]['pid'];
    }
  }
  return $trail;
}

If I comment out the while loop and what is inside it, the page does display, but the dynamic menus are invisible.

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

More investigation

kbahey commented 27 September 2004 at 16:39

Well, I tried doing the following:

I added the line:

 print_r ($menu['items'][$mid]);

Before the commented out while loop (see previous comment), and here is the output:

Array ( [path] => node/5/view [title] => view [type] => 640 [weight] => -10 [pid] => -160 )

I am not sure what to make out of this, but the 'node/5/view' seems like it should be 'node/view/5' doesn't it?

And what about pid being negative? Would that affect the loop?

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

Similar symptom, different code

kbahey commented 28 September 2004 at 00:42

Seems that the symptom is similar, but the code is different in each of the cases.

Yours in in theme.in mine is in menu.inc

Seems that your problem is not related to an upgrade as well (if you started with an empty database). I urge you to submit a bug report on it then. Mine is most probably related to the upgrade.

Either that, or the CVS version is still unstable.

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

Database update failures

kbahey commented 28 September 2004 at 00:55

I tried the upgrade again. So I loaded the old database backup, then ran the update.php script again.

The update script select 2004-05-10 as the date that updates after which will be applied.

I noticed that there were some failures

Some of those are not an issue (e.g. the users_roles and locales_meta, which were created manually before the update). The rest are problems, but I am not sure if they are related to the problem at hand or not.

Here is a copy and paste of the failed portions:

user error: Table 'site1_node_access' already exists
query: CREATE TABLE be_node_access (
     nid int(10) unsigned NOT NULL default '0',
     gid int(10) unsigned NOT NULL default '0',
     realm varchar(255) NOT NULL default '',
     grant_view tinyint(1) unsigned NOT NULL default '0',
     grant_update tinyint(1) unsigned NOT NULL default '0',
     grant_delete tinyint(1) unsigned NOT NULL default '0',
     PRIMARY KEY  (nid,gid,realm)
     ) in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Duplicate entry '0-0-all' for key 1
query: INSERT INTO be_node_access VALUES (0, 0, 'all', 1, 0, 0); in /home/myusername/html/includes/database.mysql.inc on line 125.

CREATE TABLE {node_access} (
     nid int(10) unsigned NOT NULL default '0',
     gid int(10) unsigned NOT NULL default '0',
     realm varchar(255) NOT NULL default '',
     grant_view tinyint(1) unsigned NOT NULL default '0',
     grant_update tinyint(1) unsigned NOT NULL default '0',
     grant_delete tinyint(1) unsigned NOT NULL default '0',
     PRIMARY KEY  (nid,gid,realm)
     ) 
FAILED

INSERT INTO {node_access} VALUES (0, 0, 'all', 1, 0, 0); 
FAILED

user error: Table 'site1_filter_formats' already exists
query: CREATE TABLE be_filter_formats (
      format int(4) NOT NULL auto_increment,
      name varchar(255) NOT NULL default '',
      roles varchar(255) NOT NULL default '',
      cache tinyint(2) NOT NULL default '1',
      PRIMARY KEY  (format)
    ) in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Duplicate entry '1' for key 1
query: INSERT INTO be_filter_formats VALUES (1,'Filtered HTML',',1,2,',1) in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Duplicate entry '2' for key 1
query: INSERT INTO be_filter_formats VALUES (2,'PHP code',',',0) in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Duplicate entry '3' for key 1
query: INSERT INTO be_filter_formats VALUES (3,'Full HTML','',1) in /home/myusername/html/includes/database.mysql.inc on line 125.

CREATE TABLE {filter_formats} (
      format int(4) NOT NULL auto_increment,
      name varchar(255) NOT NULL default '',
      roles varchar(255) NOT NULL default '',
      cache tinyint(2) NOT NULL default '1',
      PRIMARY KEY  (format)
    ) 
FAILED

INSERT INTO {filter_formats} VALUES (1,'Filtered HTML',',1,2,',1) 
FAILED

INSERT INTO {filter_formats} VALUES (2,'PHP code',',',0) 
FAILED

INSERT INTO {filter_formats} VALUES (3,'Full HTML','',1) 
FAILED

user error: Table 'site1_locales_source' already exists
query: CREATE TABLE be_locales_source (
      lid int(11) NOT NULL auto_increment,
      location varchar(128) NOT NULL default '',
      source blob NOT NULL,
      PRIMARY KEY  (lid)
    ) in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Table 'site1_locales_target' already exists
query: CREATE TABLE be_locales_target (
      lid int(11) NOT NULL default '0',
      translation blob NOT NULL,
      locale varchar(12) NOT NULL default '',
      plid int(11) NOT NULL default '0',
      plural int(1) NOT NULL default '0',
      KEY lid (lid),
      KEY lang (locale),
      KEY plid (plid),
      KEY plural (plural)
    ) in /home/myusername/html/includes/database.mysql.inc on line 125.

CREATE TABLE {locales_source} (
      lid int(11) NOT NULL auto_increment,
      location varchar(128) NOT NULL default '',
      source blob NOT NULL,
      PRIMARY KEY  (lid)
    ) 
FAILED

CREATE TABLE {locales_target} (
      lid int(11) NOT NULL default '0',
      translation blob NOT NULL,
      locale varchar(12) NOT NULL default '',
      plid int(11) NOT NULL default '0',
      plural int(1) NOT NULL default '0',
      KEY lid (lid),
      KEY lang (locale),
      KEY plid (plid),
      KEY plural (plural)
    ) 
FAILED

user error: Table 'site1_files' already exists
query: CREATE TABLE be_files (
      fid int(10) unsigned NOT NULL default '0',
      nid int(10) unsigned NOT NULL default '0',
      filename varchar(255) NOT NULL default '',
      filepath varchar(255) NOT NULL default '',
      filemime varchar(255) NOT NULL default '',
      filesize int(10) unsigned NOT NULL default '0',
      list tinyint(1) unsigned NOT NULL default '0',
      PRIMARY KEY  (fid)
    ) in /home/myusername/html/includes/database.mysql.inc on line 125.

CREATE TABLE {files} (
      fid int(10) unsigned NOT NULL default '0',
      nid int(10) unsigned NOT NULL default '0',
      filename varchar(255) NOT NULL default '',
      filepath varchar(255) NOT NULL default '',
      filemime varchar(255) NOT NULL default '',
      filesize int(10) unsigned NOT NULL default '0',
      list tinyint(1) unsigned NOT NULL default '0',
      PRIMARY KEY  (fid)
    ) 
FAILED

user error: Table 'site1_node_comment_statistics' already exists
query: CREATE TABLE be_node_comment_statistics (
      nid int(10) unsigned NOT NULL auto_increment,
      cid int(10) unsigned NOT NULL default '0',
      last_comment_timestamp int(11) NOT NULL default '0',
      last_comment_name varchar(60) default NULL,
      last_comment_uid int(10) NOT NULL default '0',
      comment_count int(10) unsigned NOT NULL default '0',
      PRIMARY KEY (nid),
      KEY node_comment_timestamp (last_comment_timestamp)
      ) TYPE=MyISAM in /home/myusername/html/includes/database.mysql.inc on line 125.

user error: Duplicate entry '61' for key 1
query: INSERT INTO be_node_comment_statistics (nid, cid, last_comment_timestamp, last_comment_name, last_comment_uid, comment_count) SELECT n.nid, 0, n.created, NULL, n.uid, 0 FROM be_node n in /home/myusername/html/includes/database.mysql.inc on line 125.

CREATE TABLE {node_comment_statistics} (
      nid int(10) unsigned NOT NULL auto_increment,
      cid int(10) unsigned NOT NULL default '0',
      last_comment_timestamp int(11) NOT NULL default '0',
      last_comment_name varchar(60) default NULL,
      last_comment_uid int(10) NOT NULL default '0',
      comment_count int(10) unsigned NOT NULL default '0',
      PRIMARY KEY (nid),
      KEY node_comment_timestamp (last_comment_timestamp)
      ) TYPE=MyISAM 
FAILED

INSERT INTO {node_comment_statistics} (nid, cid, last_comment_timestamp, last_comment_name, last_comment_uid, comment_count) SELECT n.nid, 0, n.created, NULL, n.uid, 0 FROM {node} n 
FAILED

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

It is probably the cache

kbahey commented 28 September 2004 at 04:11

I am not 100% sure yet, but after an evening of testing, I think this has to do with Drupal's cache.

I recall when I first installed Drupal about a year ago, I had some problem with the cache (can't remember what), and turned it off ever since.

Cache is still off, but it seems the newer versions of Drupal cache other things, caches the filter, the menus, ..etc. regardless of what the cache setting is.

When I delete the site1_cache table, the site starts to work for a bit, then gets stuck again.

Did anyone face something similar to this?

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

More troubleshooting

kbahey commented 28 September 2004 at 16:36

I tried to do some more troubleshooting.
I reloaded the old database, ran the update.php, then saved the database dump (before.sql). Then I went to /admin/settings and pressed 'Save' (without changing anything), and I got the script time out error message. I then saved the database dump to another file.

I ran a diff between the two databases, and here is the result. Drupal inserted several rows in the menu table for various menus. Also, it inserted a sequence for the menu id. It also cached something in the session.

Can anyone familiar with the menus and cache code see anything that could be the reason for the menus timing out? I am stuck on this.

69319a69320
> INSERT INTO site1_accesslog VALUES ('http://site1.example.com/admin/settings','10.0.0.1',1,1096388482,'','admin/settings');
69756a69758,69806
> INSERT INTO site1_menu VALUES (1,1,'admin','administer',9,22,'');
> INSERT INTO site1_menu VALUES (2,1,'admin/block','blocks',0,22,'');
> INSERT INTO site1_menu VALUES (3,17,'node/add/book','book page',0,22,'');
> INSERT INTO site1_menu VALUES (4,15,'admin/node/book','books',4,22,'');
> INSERT INTO site1_menu VALUES (5,4,'admin/node/book/orphan','orphan pages',8,22,'');
> INSERT INTO site1_menu VALUES (6,4,'admin/node/book/129','\"Something\" book',0,22,'');
> INSERT INTO site1_menu VALUES (7,1,'book','books',0,16,'');
> INSERT INTO site1_menu VALUES (8,1,'admin/comment','comments',0,22,'');
> INSERT INTO site1_menu VALUES (9,1,'contact','contact us',0,22,'');
> INSERT INTO site1_menu VALUES (10,1,'admin/filters','input formats',0,22,'');
> INSERT INTO site1_menu VALUES (11,1,'filter/tips','compose tips',0,16,'');
> INSERT INTO site1_menu VALUES (12,17,'node/add/forum','forum topic',0,22,'');
> INSERT INTO site1_menu VALUES (13,1,'admin/help','help',9,22,'');
> INSERT INTO site1_menu VALUES (14,1,'admin/menu','menus',0,22,'');
> INSERT INTO site1_menu VALUES (15,1,'admin/node','content',0,22,'');
> INSERT INTO site1_menu VALUES (16,1,'node','content',0,16,'');
> INSERT INTO site1_menu VALUES (17,16,'node/add','create content',1,28,'');
> INSERT INTO site1_menu VALUES (18,17,'node/add/page','page',0,22,'');
> INSERT INTO site1_menu VALUES (19,1,'admin/path','url aliases',0,22,'');
> INSERT INTO site1_menu VALUES (20,17,'node/add/poll','poll',0,22,'');
> INSERT INTO site1_menu VALUES (21,1,'poll','polls',0,16,'');
> INSERT INTO site1_menu VALUES (22,1,'profile','user list',0,16,'');
> INSERT INTO site1_menu VALUES (23,1,'search','search',0,16,'');
> INSERT INTO site1_menu VALUES (24,23,'search/help','search help',0,16,'');
> INSERT INTO site1_menu VALUES (25,1,'sitemap','site map',0,22,'');
> INSERT INTO site1_menu VALUES (26,1,'statistics','most popular content',0,16,'');
> INSERT INTO site1_menu VALUES (27,49,'admin/logs/hits','hits',3,22,'');
> INSERT INTO site1_menu VALUES (28,27,'admin/logs/hits/posts','posts',1,22,'');
> INSERT INTO site1_menu VALUES (29,27,'admin/logs/hits/pages','pages',1,22,'');
> INSERT INTO site1_menu VALUES (30,27,'admin/logs/hits/users','users',2,22,'');
> INSERT INTO site1_menu VALUES (31,27,'admin/logs/hits/hostnames','hostnames',3,22,'');
> INSERT INTO site1_menu VALUES (32,49,'admin/logs/referrers','referrers',4,22,'');
> INSERT INTO site1_menu VALUES (33,32,'admin/logs/referrers/internal','internal',0,22,'');
> INSERT INTO site1_menu VALUES (34,32,'admin/logs/referrers/external','external',0,22,'');
> INSERT INTO site1_menu VALUES (35,17,'node/add/story','story',0,22,'');
> INSERT INTO site1_menu VALUES (36,1,'admin/themes','themes',0,22,'');
> INSERT INTO site1_menu VALUES (37,1,'admin/settings','settings',0,22,'');
> INSERT INTO site1_menu VALUES (38,37,'admin/settings/contact','contact',0,22,'');
> INSERT INTO site1_menu VALUES (39,37,'admin/settings/forum','forum',0,22,'');
> INSERT INTO site1_menu VALUES (40,37,'admin/settings/sitemap','sitemap',0,22,'');
> INSERT INTO site1_menu VALUES (41,37,'admin/settings/statistics','statistics',0,22,'');
> INSERT INTO site1_menu VALUES (42,37,'admin/settings/story','story',0,22,'');
> INSERT INTO site1_menu VALUES (43,1,'admin/modules','modules',0,22,'');
> INSERT INTO site1_menu VALUES (44,1,'admin/taxonomy','categories',0,22,'');
> INSERT INTO site1_menu VALUES (45,1,'tracker','recent posts',1,22,'');
> INSERT INTO site1_menu VALUES (46,1,'admin/user','users',0,22,'');
> INSERT INTO site1_menu VALUES (47,0,'user/1','my account',0,22,'');
> INSERT INTO site1_menu VALUES (48,1,'logout','log out',10,22,'');
> INSERT INTO site1_menu VALUES (49,1,'admin/logs','logs',0,22,'');
113383a113434
> INSERT INTO site1_sequences VALUES ('site1_menu_mid',49);
114289c114340
< INSERT INTO site1_sessions VALUES (1,'3dfd7765f1a1bd26f2793cab34e8ce28','10.0.0.1',1096388455,'messages|a:0:{}');
---
> INSERT INTO site1_sessions VALUES (1,'3dfd7765f1a1bd26f2793cab34e8ce28','10.0.0.1',1096388512,'messages|a:1:{s:6:\"status\";a:1:{i:0;s:42:\"The configuration options have been saved.\";}}');
115265a115317,115318
> INSERT INTO site1_variable VALUES ('configurable_timezones','s:1:\"1\";');
> INSERT INTO site1_variable VALUES ('date_first_day','s:1:\"0\";');

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba

Solved!

kbahey commented 28 September 2004 at 18:20

Well, finally I have a solution to this.

Load the database dump from 4.4.1
Create the needed tables manually (as in the original article)
Run the update by pointing your browse to http://site1.example.com/update.php
From phpmyadmin, or the mysql prompt, delete the existing entries in the menu table: delete from site1_menu;
Then, log in as admin to your site, and then browse to this URL: http://site1.example.com/admin/menu/reset
Click on Reset to confirm resetting of menus

That is it. The site works perfectly now. I am not sure what menus will be lost when this is done, but they can be rebuilt manually, rather than having your site not functional.

--
Drupal performance tuning and optimization, hosting, development, and consulting: 2bits.com, Inc. and Twitter at: @2bits
Personal blog: Ba