Upgrade from 3.3.5 to 4.2.beta3 on Drupal 6 falls at first hurdle

[davej]

Hi,

I began this discussion on the civicrm-planning list following the call there for people to test upgrades. This seems a more appropriate place to continue it.

The initial problem was:

--------------------
Initially at /civicrm/upgrade?reset=1 I got this:

----8<----
Warning:
Could not determine path to civicrm.settings.php. Please manually locate it and add these lines:

require_once 'CRM/Core/ClassLoader.php';
CRM_Core_ClassLoader::singleton()->register();
----8<----

civicrm.settings.php is in sites/default/ so if it can't find it there, it's not going to find it anywhere! I added those lines at the start of civicrm.settings.php and got this error:

Failed opening required 'CRM/Core/ClassLoader.php' (include_path='.:/usr/share/php:/usr/share/pear') in .../sites/default/civicrm.settings.php on line 4

Looking at civicrm.settings.php it then became obvious that these lines need to be added at/near the end, after the include path is modified, which means after the comment "Do not change anything below this line. Keep as is". This may not be obvious to all so I suggest making that clear in the message on the upgrade page.

I was then able once again to get to the initial upgrade page without error, though still with the warning "Could not determine path to civicrm.settings.php. Please manually locate it and add these lines..."

After clicking the upgrade button & confirming, I then got a screen saying "CiviCRM Upgrade Tasks", with a single line below as follows:

[]                                                             Retry Skip

Clicking Retry didn't seem to change anything. Neither did clicking Skip.
--------------------

Tim Otten helpfully replied and asked me to try the latest drupal6 code from svn (/branches/v3.4/drupal). I've tried this and it gets past the problem of not finding civicrm.settings.php (hoorah!). It didn't ask me to add the ClassLoader stuff to civicrm.settings.php so, keeping my naive tester hat on* I didn't add it and didn't make civicrm.settings.php writeable by apache (as I wouldn't normally). It didn't complain about this and, as before, it then just took me to the next problem, at /civicrm/upgrade/queue/runner?reset=1&qrid=CRM_Upgrade:

--------------------
After clicking the upgrade button & confirming, I then got a screen saying "CiviCRM Upgrade Tasks", with a single line below as follows:

[]                                                             Retry Skip
--------------------

* Arguments about whether I have any other hats can wait for the code sprint, after a few Butcombe ales.

The same happened if I did add the ClassLoader stuff to civicrm.settings.php, or if I made civicrm.settings.php writeable. (I reset the db each time & cleared caches to make sure I was starting from a consistent point.)

CiviCRM.blah.log sometimes has this error after clicking the upgrade button & confirming:

----8<----
Aug 02 12:26:50  [info] Ignoring exception thrown by nullHandler: -18, DB Error: no such table

Aug 02 12:26:50  [info] $backTrace = .../sites/all/modules/civicrm/CRM/Core/Error.php, backtrace, 568
, nullHandler,
.../sites/all/modules/civicrm/packages/PEAR.php, call_user_func, 931
.../sites/all/modules/civicrm/packages/DB.php, PEAR_Error, 968
.../sites/all/modules/civicrm/packages/PEAR.php, DB_Error, 564
.../sites/all/modules/civicrm/packages/DB/common.php, raiseError, 1903
.../sites/all/modules/civicrm/packages/DB/mysql.php, raiseError, 898
.../sites/all/modules/civicrm/packages/DB/mysql.php, mysqlRaiseError, 327
.../sites/all/modules/civicrm/packages/DB/common.php, simpleQuery, 1216
.../sites/all/modules/civicrm/packages/DB/DataObject.php, query, 2427
.../sites/all/modules/civicrm/packages/DB/DataObject.php, _query, 1613
.../sites/all/modules/civicrm/CRM/Core/DAO.php, query, 155
.../sites/all/modules/civicrm/CRM/Core/DAO.php, query, 888
.../sites/all/modules/civicrm/CRM/Core/BAO/Setting.php, executeQuery, 491
.../sites/all/modules/civicrm/CRM/Core/BAO/ConfigSetting.php, retrieveDirectoryAndURLPreferences, 334
.../sites/all/modules/civicrm/CRM/Core/Config.php, retrieve, 404
.../sites/all/modules/civicrm/CRM/Core/Config.php, _initVariables, 197
.../sites/all/modules/civicrm/drupal/civicrm.module, singleton, 283
.../sites/all/modules/civicrm/drupal/civicrm.module, civicrm_initialize, 943, civicrm_preprocess_page,
.../includes/theme.inc, call_user_func_array, 710
.../includes/common.inc, theme, 397
.../index.php, drupal_not_found, 23
----8<----

The civicrm_domain table still shows version 3.3.5 .

Dave J

[Deepak Srivastava]

Did you also change CIVICRM_UF from 'Drupal' to 'Drupal6' in civicrm.settings.php file ?

When doing upgrade for a school db recently, we found that this step is also required.

[davej]

Hi Deepak,

Thanks for your response.

Did you also change CIVICRM_UF from 'Drupal' to 'Drupal6' in civicrm.settings.php file ?

Yes, I changed that. It falls over earlier without that step.

Hope you're well,

Dave J

[totten]

Background: The "no such table" error refers to "civicrm_setting" (CRM/Core/BAO/Setting.php) which was added in 4.1, and reading this table is a normal part of the Civi bootstrap. During an upgrade from <=4.0, the table doesn't exist, so the bootstrap includes a special workaround to ignore the table during upgrades. The logic looks at the request URL.

Comment 1: The bottom three lines of the callstack look fishy -- it's trying to render "page not found" which triggers theming and then Civi's bootstrap. What URL isn't found? (The workaround only applies to civicrm/upgrade.) You might be able to check the Apache log, Firebug, HttpFox, or something similar. Or to be more certain, you might hack CRM_Core_Error::backtrace() to simultaneously log $_SERVER/$_GET.

Comment 2: Before you running the upgrade (while you still have the old codebase), you might enable debugging. This should make the upgrade UI display more detailed error messages.

[davej]

Hi Tim,

Thanks for the background & suggestions.

Re comment 1:
turns out the 404 was for:
/sites/all/modules/civicrm/packages/jquery/jquery-ui-1.8.5/css/custom-theme/images/ui-bg_flat_40_70716b_40x100.png
so that's a red herring.

Re comment 2:
I enabled debugging in the UI in 3.3.5 pre-upgrade but I'm not seeing any additional info during the upgrade.

I don't know my way around the upgrade code but I've had a little poke around and thrown in some debug statements. So far I've found...
CRM_Upgrade_Page_Upgrade::runBegin() calls CRM_Upgrade_Form::buildQueue()
CRM_Upgrade_Form::buildQueue: returns $queue = CRM_Queue_Queue_Sql Object
(
    [_name:private] => CRM_Upgrade
)

Oops. That doesn't look good. It's exactly the same when first created in CRM_Upgrade_Form::buildQueue(). I threw more debug statements into buildQueue() and found...
$revisions looks fine: 91 items ranging from '2.1.2' to '4.2.beta3'.
$beginTask and the two $task instances per iteration through $revisions look sensible AFAICS, e.g. on the first iteration:

Code: [Select]

Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $beginTask = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeStart
        )

    [arguments] => Array
        (
            [0] => 3.3.6
        )

    [title] => Begin Upgrade to 3.3.6
)


Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $task = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeStep
        )

    [arguments] => Array
        (
            [0] => 3.3.6
            [1] => 3.3.5
            [2] => 4.2.beta3
            [3] => /tmp/civicrm-post-upgradehVAseL
        )

    [title] => Upgrade DB to 3.3.6
)


Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $task = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeFinish
        )

    [arguments] => Array
        (
            [0] => 3.3.6
        )

    [title] => Finish Upgrade DB to 3.3.6
)

and the last:

Code: [Select]

Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $beginTask = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeStart
        )

    [arguments] => Array
        (
            [0] => 4.2.beta3
        )

    [title] => Begin Upgrade to 4.2.beta3
)


Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $task = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeStep
        )

    [arguments] => Array
        (
            [0] => 4.2.beta3
            [1] => 3.3.5
            [2] => 4.2.beta3
            [3] => /tmp/civicrm-post-upgradehVAseL
        )

    [title] => Upgrade DB to 4.2.beta3
)


Aug 02 16:17:36  [info] CRM_Upgrade_Form::buildQueue: $task = CRM_Queue_Task Object
(
    [callback] => Array
        (
            [0] => CRM_Upgrade_Form
            [1] => doIncrementalUpgradeFinish
        )

    [arguments] => Array
        (
            [0] => 4.2.beta3
        )

    [title] => Finish Upgrade DB to 4.2.beta3
)

So I guess the problem is with CRM_Queue_Service or CRM_Queue_Queue_Sql. I haven't made any headway understanding what's going on with those. Someone who understands the code might stand more of a chance!

Dave J

[davej]

One thought: we're using PHP 5.2, because we have many Drupal 6 sites using many contrib modules and these don't all support 5.3 . Wonder if that's messing up the ReflectionClass stuff in CRM_Queue_Service or something? Is there any known-5.3-specific code in there?

Also I'm away now until Weds 15th Aug. My colleague Andrew Walker may get a chance to look at this a little in the meantime but he'll probably be pretty busy.

Dave J

[totten]

1) Try manually clearing the templates_c/* cache.

2) It's not clear yet if this is a UI issue, an upgrade-logic issue, or something else. You might try running the upgrade via drush. If drush succeeds, then we know it's a UI issue. (Note: If you use bgm's provision_civicrm, then you may need to upgrade to get the latest civicrm.drush.inc.)

3) I've used ReflectionClass on 5.2 before (and php.net shows it going back to 5.0). We may have introduced other changes which require 5.3, but I can't actually name any. (There were a few times I was personally on the verge of introducing 5.3 requirements but then found a different way.) If you or Andrew have access to 5.3, it would helpful if you could try it and see if that improves things.

4) The upgrade requires jQuery UI to display a progress bar. If there's one error loading jQuery UI (the 404 for png), then perhaps there are others? This is likely to show in request log or in the browser's development console (like Firebug).

5) Background: The CRM_Queue provides the backend to the progress bar -- ie we fill the queue and mark the progress bar at 0%; then we dequeue a task, execute it, and move the bar. Each task is temporarily stored in SQL (civicrm_queue_item).

[davej]

Hi Tim,

Thanks for the further response.

1) Try manually clearing the templates_c/* cache.

Done, it's slightly different now: the page after clicking & confirming Upgrade (/civicrm/upgrade/queue/runner?reset=1&qrid=CRM_Upgrade) now has buttons with reload & double-arrow icons, where previously it had the text "Retry" and "Skip". There's also a new empty white rectangle that looks like it might want to be a progress bar when it grows up.

2) It's not clear yet if this is a UI issue, an upgrade-logic issue, or something else. You might try running the upgrade via drush. If drush succeeds, then we know it's a UI issue. (Note: If you use bgm's provision_civicrm, then you may need to upgrade to get the latest civicrm.drush.inc.)

Andrew is a bit of a whizz with drush, I haven't used it with Civi.

3) I've used ReflectionClass on 5.2 before (and php.net shows it going back to 5.0). We may have introduced other changes which require 5.3, but I can't actually name any. (There were a few times I was personally on the verge of introducing 5.3 requirements but then found a different way.) If you or Andrew have access to 5.3, it would helpful if you could try it and see if that improves things.

'Fraid I'm not going to be able to get that set up before I go away.

4) The upgrade requires jQuery UI to display a progress bar. If there's one error loading jQuery UI (the 404 for png), then perhaps there are others? This is likely to show in request log or in the browser's development console (like Firebug).

I'm guessing the 404 for the png was due to a cached template file that didn't get cleared until I manually rm -r'd templates_c/* . (Civi seems to lose track of where it should be clearing templates if locale isn't en_US.) No other 404s in the access log. No recurrence of the 404 for the png since clearing the template cache.

But the Firefox error console has this:

Error: SyntaxError: JSON.parse: unexpected character
Source File: .../sites/all/modules/civicrm/packages/jquery/jquery.min.js?w
Line: 2
(Line 2 is a massively long line.)

Dave J

[totten]

OK. Hopefully, drush or 5.3 will make a difference. One more thought on your last comment:

But the Firefox error console has this:

Error: SyntaxError: JSON.parse: unexpected character
Source File: .../sites/all/modules/civicrm/packages/jquery/jquery.min.js?w
Line: 2
(Line 2 is a massively long line.)

It sounds like the server sent an invalid response to an AJAX request. The response is supposed to be JSON, but sometimes naughty error-handling code will return error messages as HTML documents. For Firefox, the addon HttpFox or FireBug could log the content of the invalid AJAX response. (Note: With either tool you have to make sure the tool is open/active before running the upgrade screen.)

[Eileen]

Just a note on drush - I managed to get a d6 site upgraded using to 4.2 using drush once by copying the drush file from the d7 install. I had multiple errors on that upgrade attempt & did log some but didn't follow the drush trail.

[Donald Lobo]

While we are on D6, we do hope that D6 will continue to be community supported. we are fine creating a release and will make our best effort not to break things intentionally or unintentionally

We are considering renaming the release to: civicrm-4.1.5-drupal6-unsupported.tar.gz to start pushing more folks towards a supported D7 + Civi release

lobo

[andyw]

Hi All,

Just looking into this in Dave's absence - apologies for the delayed response, it took me a couple of days to get round to, then turned into a bit of a task ..

* Firstly, I think PHP 5.3 is probably a requirement - having moved the site to a machine with a newer php version, I'm certainly not seeing any of the UI weirdness / malformed JSON that Dave was reporting - I would guess totten's theory that server-side errors were being echoed as html into the json response was probably the case the first time we tried this.

* Secondly, using Eileen's tip of copying the drush file from a Drupal 7 install (thanks Eileen), I was able to get the upgrade to run via drush - but this unfortunately doesn't increase the verbosity of the errors, I still get the same error - DB Error: already exists - except I get it as a fully-themed html page, which doesn't make the output very easy to decipher on the command line.

* Thirdly, enabling debugging prior to the upgrade seems to have no effect on the error detail level.

So I've gone back to using the web interface and added some code to log the actual error mysql produces, and have eventually managed to get the site upgraded that way.

I'll provide a list of steps I've gone through below, and changes I've made to get it to work.

This comes with the disclaimer that:

a) we're attempting to go from 3.3 to 4.2, which is quite a leap - so only the last few steps may be of interest here.

b) I've very much used a 'this should probably be ok' approach, but I've by no means investigated each problem in great detail, or indeed know what some of these database changes in the upgrade are trying to achieve - so please let me know if I've unwittingly gone and done something stupid ...

---

Stage: Upgrade DB to 3.4.alpha1
Displayed error: DB Error: already exists
Actual error: (Table: civicrm_mailing_recipients already exists)
Action: This table is empty on our install, so dropped before upgrade.

---

Stage: Upgrade DB to 3.4.alpha1
Displayed error: DB Error: already exists
Actual error: (Table 'civicrm_prevnext_cache' already exists)
Action: Dropped before upgrade.

---

Stage: Upgrade DB to 4.1.alpha1
Displayed error: DB Error: already exists
Actual error: (Table 'civicrm_setting' already exists)
Action: Added DROP TABLE IF EXISTS to 4.1.alpha1.mysql.tpl

---

Stage: Upgrade DB to 4.1.alpha1
Displayed error: DB Error: a515ac9c2796ca0e23adbe92c68fc9fc
Actual error: Duplicate column name 'absolute_date'
Action: commented the following lines in 4.1.alpha1.mysql.tpl (these columns already exist at the point they run)

#ALTER TABLE civicrm_action_schedule ADD `absolute_date` date DEFAULT NULL COMMENT 'Date on which the reminder be sent.';
#ALTER TABLE civicrm_action_schedule ADD `recipient_listing` varchar(128) COLLATE utf8_unicode_ci DEFAULT NULL COMMENT 'listing based on recipient field.';

---

Stage: Upgrade DB to 4.1.alpha1
Displayed error: DB Error: already exists
Actual error: Table 'civicrm_job' already exists
Action: Added DROP TABLE IF NOT EXISTS before CREATE TABLE

---

Stage: Upgrade DB to 4.1.alpha1
Displayed error: DB Error: already exists
Actual error: Table 'civicrm_job_log' already exists
Action: Added DROP TABLE IF NOT EXISTS before CREATE TABLE

At this point I see that civicrm_event_carts and civicrm_events_in_carts already exist, but have a CREATE TABLE statement so add a DROP TABLE IF NOT EXISTS on those too

---

Stage: Upgrade DB to 4.2.alpha1: SQL
Displayed error: DB Error: already exists
Actual error: Table 'civicrm_sms_provider' already exists
Action: Added DROP TABLE IF NOT EXISTS before CREATE TABLE

---

Stage: Upgrade DB to 4.2.alpha1: Contributions (16280 => 21279)]
Displayed error: DB Error: already exists
Actual error: Duplicate entry 'civicrm_contribution-18714-13-2' for key 'UI_line_item_value'
Action: Change INSERT INTO to REPLACE INTO in FourTwo.php, line 340

---

Stage: Upgrade DB to 4.2.beta1
Displayed error: DB Error: already exists
Actual error: Table 'civicrm_extension' already exists
Action: Added IF NOT EXISTS to CREATE TABLE

----

Phew - otherwise it .. er .. ran like a dream.

I'm also a bit confused as to why I would see so many CREATE TABLE statements on tables that already exist - makes me feel I might have missed something, but the site seems ok so far .. doesn't seem to have blown up .. yet.

Anyway, many thanks for all your help with this,

Andy

[andyw]

Hey, DROP TABLE IF NOT EXISTS isn't right - I must mean DROP TABLE IF EXISTS or something ..

.. it's been a long day

[totten]

A few things:

1. When one encounters a failed upgrade and then tries to start over, you have to make sure to drop any tables that were created during the failed upgrade attempt. I think most people do this by dropping and recreating the database.

2. In the past couple days, we've modified the upgrader to display preventive, fatal errors if the site has an old PHP (<=5.2) or if the site uses revision-logging (which needs to be disabled during the upgrade).

[sonicthoughts]

I just ran into the same error.  My config:
Single Drupal 7.14 DB and civicrm 4.15
WAMP
PHP 5.3.15
Note that error message refers to alpha upgrade but this is beta5
I didn't clear template files prior to upgrade but did clear the cache. 
This was a FIRST attempt to go to 4.2 (so no left over tables)
UI is a bit strange (i think it's my theme, skip/retry are off the page.
will try w/drush soon.
[Error: Upgrade DB to 4.2.alpha1: SQL]
DB Error: unknown error
#0 [internal function]: CRM_Core_Error::exceptionHandler(Object(DB_Error))
#1 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\PEAR.php(931): call_user_func(Array, Object(DB_Error))
#2 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\DB.php(968): PEAR_Error->PEAR_Error('DB Error: unkno...', -1, 16, Array, 'ALTER TABLE `ci...')
#3 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\PEAR.php(564): DB_Error->DB_Error(-1, 16, Array, 'ALTER TABLE `ci...')
#4 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\DB\common.php(1903): PEAR->raiseError(NULL, -1, NULL, NULL, 'ALTER TABLE `ci...', 'DB_Error', true)
#5 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\DB\mysql.php(898): DB_common->raiseError(-1, NULL, NULL, NULL, '1025 ** Error o...')
#6 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\DB\mysql.php(327): DB_mysql->mysqlRaiseError()
#7 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\packages\DB\common.php(1216): DB_mysql->simpleQuery('ALTER TABLE `ci...')
#8 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Utils\File.php(285): DB_common->query('ALTER TABLE `ci...')
#9 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Upgrade\Form.php(152): CRM_Utils_File->sourceSQLFile('mysql://drupalu...', '?  ?  SELECT @w...', NULL, true)
#10 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Upgrade\Form.php(292): CRM_Upgrade_Form->source('?  ?  SELECT @w...', true)
#11 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Upgrade\Form.php(316): CRM_Upgrade_Form->processLocales('G:\Users\Shawn\...', '4.2.alpha1')
#12 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Upgrade\Incremental\php\FourTwo.php(274): CRM_Upgrade_Form->processSQL('4.2.alpha1')
#13 [internal function]: CRM_Upgrade_Incremental_php_FourTwo::task_4_2_alpha1_runSql(Object(CRM_Queue_TaskContext), '4.2.alpha1')
#14 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Queue\Task.php(79): call_user_func_array(Array, Array)
#15 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Queue\Runner.php(173): CRM_Queue_Task->run(Object(CRM_Queue_TaskContext))
#16 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Queue\Page\AJAX.php(44): CRM_Queue_Runner->runNext(true)
#17 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Queue\ErrorPolicy.php(80): {closure}()
#18 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Queue\Page\AJAX.php(51): CRM_Queue_ErrorPolicy->call(Object(Closure))
#19 [internal function]: CRM_Queue_Page_AJAX::runNext(Array)
#20 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\CRM\Core\Invoke.php(186): call_user_func(Array, Array)
#21 G:\Users\Shawn\Documents\drupal\shawntest\sites\all\modules\civicrm\drupal\civicrm.module(497): CRM_Core_Invoke::invoke(Array)
#22 [internal function]: civicrm_invoke('upgrade', 'queue', 'ajax', 'runNext')
#23 G:\Users\Shawn\Documents\drupal\shawntest\includes\menu.inc(516): call_user_func_array('civicrm_invoke', Array)
#24 G:\Users\Shawn\Documents\drupal\shawntest\index.php(21): menu_execute_active_handler()
#25 {main}