15 August 2011, 10:01

I was attempting to upgrade a 1.2.10 site to 1.4.1(testing) - today's build in fact. I got this error message while upgrading core...

Could not execute command: ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id)

The full story from the logs is...

[Mon Aug 15 16:27:27 2011] [error] [DBG] 56 (lib/dml.php:159) mysql error: [1005: Can't create table './dev_mahara2011/#sql-1d1c_8a9e.frm' (errno: 121)] in adodb_throw(ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id), )
[Mon Aug 15 16:27:27 2011] [error] [DBG] 56 (lib/dml.php:159) Command was: ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id)
[Mon Aug 15 16:27:27 2011] [error] [WAR] 56 (lib/errors.php:745) Could not execute command: ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id)
[Mon Aug 15 16:27:27 2011] [error] Call stack (most recent first):
[Mon Aug 15 16:27:27 2011] [error]   * log_message("Could not execute command: ALTER TABLE notificatio...", 8, true, true) at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/errors.php:109
[Mon Aug 15 16:27:27 2011] [error]   * log_warn("Could not execute command: ALTER TABLE notificatio...") at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/errors.php:745[Mon Aug 15 16:27:27 2011] [error]   * SQLException->__construct("Could not execute command: ALTER TABLE notificatio...") at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/dml.php:161
[Mon Aug 15 16:27:27 2011] [error]   * execute_sql("ALTER TABLE notification_internal_activity ADD CON...", true) at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/dml.php:1394[Mon Aug 15 16:27:27 2011] [error]   * execute_sql_arr(array(size 1), true, true) at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/ddl.php:972
[Mon Aug 15 16:27:27 2011] [error]   * add_key(object(XMLDBTable), object(XMLDBKey)) at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/db/upgrade.php:1663
[Mon Aug 15 16:27:27 2011] [error]   * xmldb_core_upgrade("2009111024") at /usr/local/apache/htdocs/mahara/maharatest/htdocs/lib/upgrade.php:301
[Mon Aug 15 16:27:27 2011] [error]   * upgrade_core(object(stdClass)) at /usr/local/apache/htdocs/mahara/maharatest/htdocs/admin/upgrade.json.php:94

I'll try going via 1.3 but while I'm doing that - any thoughts?

UPDATE:

I restored from a backup and attempted an upgrade to 1.3.7(testing) - exactly the same problem :(

15 August 2011, 11:29

Hi Howard,

Can you provide a bit more information about your installation? We ideally need to know (at the very least):

• database type (e.g. postgresql);
• database version;
• operating system (I'm guessing red hat from the log outputs); and
• web server (looks like apache2).

I seem to recall that there was a problem with one of the upgrades between 1.2 and 1.3, which is where this is coming into effect, but I thought that this upgrade issue had been resolved. Have you previously attempted an upgrade which failed for some reason?

It looks like mahara is trying to add a constraint to a table, but I suspect that the constraint in question already exists. The constraint is on notification_internal_activity.

Could you check whether this constraint already exists?

Andrew

15 August 2011, 13:00

Hi Andrew,

Thanks for taking the trouble to look at this.....

* MySQL
* 5.0.51 I appreciate this may be an issue and am going to try on a server with a newer version
* I've forgotten (!) - It's not my server. It's some French Linux distro but I think that the LAMP stack was compiled from source.
* It's Apache2

I'm currently on the wrong side of a fearsome vpn that I don't have set up. But I'll get back to you on checking the constraint asap. 

UPDATE:

I forgot to mention, the 1.2 site has been running successfully for some time and has not had any recent upgrade attempts successful or not. Here's the table creation script from the backup dump...

CREATE TABLE `notification_internal_activity` ( 
`id` bigint(10) NOT NULL auto_increment, 
`type` bigint(10) NOT NULL,  `usr` bigint(10) NOT NULL, 
`ctime` datetime NOT NULL, 
`subject` text collate utf8_unicode_ci, 
`message` text collate utf8_unicode_ci, 
`url` text collate utf8_unicode_ci, 
`read` tinyint(1) NOT NULL default '0', 
PRIMARY KEY  (`id`), 
KEY `notiinteacti_typ_ix` (`type`), 
KEY `notiinteacti_usr_ix` (`usr`), 
CONSTRAINT `notiinteacti_typ_fk` FOREIGN KEY (`type`) REFERENCES `activity_type` (`id`), 
CONSTRAINT `notiinteacti_usr_fk` FOREIGN KEY (`usr`) REFERENCES `usr` (`id`)) ENGINE=InnoDB AUTO_INCREMENT=142245 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;/*!40101 SET character_set_client = @saved_cs_client */;

So, it would appear that the constraint did not already exist. 

16 August 2011, 4:32

Yet more info....

Did the following.....

* Restored the 1.2 site from a backup (all working fine)
* Switched the code to the latest 1.3 branch 
* ran the upgrade. Upgrade fails complaining about  ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id)
* Dumped the table schema as it stands...

CREATE TABLE `notification_internal_activity` ( 
`id` bigint(10) NOT NULL auto_increment, 
`type` bigint(10) NOT NULL, 
`usr` bigint(10) NOT NULL, 
`ctime` datetime NOT NULL, 
`subject` text collate utf8_unicode_ci, 
`message` text collate utf8_unicode_ci, 
`url` text collate utf8_unicode_ci, 
`read` tinyint(1) NOT NULL default '0', 
`parent` bigint(10) default NULL, 
`from` bigint(10) default NULL, 
PRIMARY KEY  (`id`), 
KEY `notiinteacti_typ_ix` (`type`), 
KEY `notiinteacti_usr_ix` (`usr`), 
KEY `notiinteacti_par_ix` (`parent`), 
KEY `notiinteacti_fro_ix` (`from`), 
CONSTRAINT `notiinteacti_fro_fk` FOREIGN KEY (`from`) REFERENCES `usr` (`id`), 
CONSTRAINT `notiinteacti_par_fk` FOREIGN KEY (`parent`) REFERENCES `notification_internal_activity` (`id`), 
CONSTRAINT `notiinteacti_typ_fk` FOREIGN KEY (`type`) REFERENCES `activity_type` (`id`), 
CONSTRAINT `notiinteacti_usr_fk` FOREIGN KEY (`usr`) REFERENCES `usr` (`id`))
ENGINE=InnoDB AUTO_INCREMENT=142245 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci  

So clearly notiinteacti_par_fk *does* exist but I'm unsure why. Is Mahara trying to execute the ADD statement twice or did it throw the error yet actually create the constraint (unlikely I suspect)?

One more thing - I did a clean install of Mahara using the same 1.2 code and then upgraded to the same 1.3 code and the error did NOT happen, so it's clearly something related to the actuall data in that table. 

ANOTHER UPDATE....

Tried this..
* Restore 1.2 site (yet again)

mysql> alter table notification_internal_activity add parent bigint(10) default null;
Query OK, 119749 rows affected (10.21 sec)
Records: 119749  Duplicates: 0  Warnings: 0

mysql> ALTER TABLE notification_internal_activity ADD CONSTRAINT notiinteacti_par_fk FOREIGN KEY (parent) REFERENCES notification_internal_activity (id);
Query OK, 119749 rows affected (10.80 sec)
Records: 119749  Duplicates: 0  Warnings: 0

So it worked doing it manuall!!! Now at a complete loss..... any help or other things I can try very much appreciated. 

16 August 2011, 5:57

Sorry... even more info. It's hitting the upgrade script for $oldversion<2010042600 (in lib/db/upgrade.php) twice!!  I added some log_debug() calls and it's definitely going in twice...

[Tue Aug 16 12:23:38 2011] [error] [DBG] e6 (lib/db/upgrade.php:1686) hitting upgrade script 2009111024 ***
[Tue Aug 16 12:23:49 2011] [error] [DBG] e6 (lib/db/upgrade.php:1692) parent field added ***
[Tue Aug 16 12:24:12 2011] [error] [DBG] e6 (lib/db/upgrade.php:1697) parentfk constraint added << THIS ONE ***
[Tue Aug 16 12:24:42 2011] [error] [DBG] 13 (lib/mahara.php:1302) Field mailssent exists. Create skipped
[Tue Aug 16 12:24:42 2011] [error] [DBG] 13 (lib/mahara.php:1302) Field mailsbounced exists. Create skipped
[Tue Aug 16 12:24:42 2011] [error] [DBG] 13 (lib/mahara.php:1302) Field theme exists. Create skipped
[Tue Aug 16 12:24:42 2011] [error] [DBG] 13 (lib/mahara.php:1302) Field submittedtime exists. Create skipped
[Tue Aug 16 12:24:52 2011] [error] [DBG] 13 (lib/db/upgrade.php:1686) hitting upgrade script 2009111024 ***
[Tue Aug 16 12:24:52 2011] [error] [DBG] 13 (lib/mahara.php:1302) Field parent exists. Create skipped
[Tue Aug 16 12:24:52 2011] [error] [DBG] 13 (lib/db/upgrade.php:1692) parent field added ***

*** = the debug lines I added. The script is run a second time. How can that happen?

16 August 2011, 17:26

Ouch, I'd like to know what's causing the second request.  But we really should try to add something that'll stop two upgrades from happening simultaneously.  Maybe putting an "upgrade in progress" record in the config table would be enough, as long as we can delete it reliably when there's an error.

17 August 2011, 1:11

Thanks Richard,

So.. I'm really struggling with this. Is there anything I can bodge / try / hack that might sort this to get my update done. My Mahara code knowledge isn't good enough and I don't know where to start looking for this. 

I have now tried this on another machine (Ubuntu 11.04 - everything standard packages) and this is much less conclusive but it seemed to get the error just the same yet carry on and complete!! So, I'm completely at a loss :(

17 August 2011, 16:54

Hi Howard,

Without knowing how the second request gets triggered, all I can suggest at the moment is putting something in to stop the second one running, maybe what I'd try first is putting something like this near the top of the xmldb_core_upgrade function in htdocs/lib/db/upgrade.php:

try {
    insert_record('config', (object) array('field' => 'coreupgradeinprogress', 'value' => $oldversion));
}
catch (SQLException $e) {
    // Assume it's a primary key error due to the record having already been inserted by
    // an earlier call to xmldb_core_upgrade.
    log_warn("eek");
    return; // or exit;?
}

Or something.  A similar thing works to stop multiple copies of cron from running.  You will still get some nasty errors showing up, but hopefully the first request will finish, even if you don't get a success message on screen.  You should be able to tell if it succeeded by looking at the config table afterwards and checking that the 'version' row has the same number as the one in htdocs/lib/version.php (don't forget to delete the 'coreupgradeinprogress' record).

Then hit admin/upgrade.php a second time and see what it says.

18 August 2011, 10:13

That sounds like a plan... much to my surprise (!) the server IT staff have agreed to install the latest version of MySQL (5.5) so we now strictly meet the requirements. We'll try again with that first. If that fails, I'll try your suggestion. 

I'll let you know :)

25 August 2011, 7:45

I eventually worked out (sort of) what was going wrong - I would appreciate some assistance fixing it though..

In lib/db/upgrade.php (this is the latest version of 1.3) at the bit for $oldversion < 2010042600. There is this line(s):

        // Set from column for old user messages
        $usermessages = get_records_array(            'notification_internal_activity',
            'type',
            get_field('activity_type', 'id', 'name', 'usermessage')
        );

This just bombs out (doesn't complete) with no error and then the upgrade script restarts back at admin/upgrade.json.php.

That call tries to return (in my case) over 6,000 complete records from the notification_internal_activity table, which I assume is hitting a limit somewhere. I don't really know what this table does, is there something sensible I can do about this?