Get "Query failed." during drush sql-sync in blt local:refresh

[geerlingguy]

My system information:

• Operating system type: macOS
• Operating system version: 10.12.2
• BLT version: 8.6.4

When I run this command:

blt local:refresh

I get the following output:

blt > local:sync:

'drush' cache was cleared.                                                                                   [success]
Do you really want to drop all tables in the database drupal? (y/n): y
You will destroy data in drupal and replace with data from staging-21390.prod.hosting.acquia.com/projectnamestg.
Do you really want to continue? (y/n): y
Starting to create database on Destination.                                                                  [ok]
Creating database drupal. Any possible existing database will be dropped!
Do you really want to continue? (y/n): y
Starting to dump database on Source.                                                                         [ok]
Database dump saved to /home/projectname/drush-backups/projectnamestg/20170105150939/projectnamestg_20170105_150939.sql.gz  [success]
Starting to discover temporary files directory on Destination.                                               [ok]
You will delete files in /tmp/projectnamestg_20170105_150939.sql.gz and replace with data from projectname.test@staging-21390.prod.hosting.acquia.com:/home/projectname/drush-backups/projectnamestg/20170105150939/projectnamestg_20170105_150939.sql.gz
Do you really want to continue? (y/n): y
Copying dump file from Source to Destination.                                                                [ok]
Starting to import dump file onto Destination database.                                                      [ok]
Query failed.                                                                                                [error]

BUILD FAILED
/Users/jgeerling/Sites/acquia/projectname/vendor/acquia/blt/phing/tasks/local-sync.xml:22:39: Drush exited with code 1

Total time: 36.7180 seconds

And I expected this to happen:

The local environment refresh should've worked.

If I run either of the following commands, everything works:

drush sql-sync @projectname.test @projectname.local --create-db --structure-tables-key="lightweight"

./vendor/bin/drush sql-sync @projectname.test @projectname.local --create-db --structure-tables-key="lightweight"

[grasmash]

@geerlingguy Can you share the verbose output that displays the drush command BLT is actually executing?

[geerlingguy]

blt > local:sync:

    [drush] Changing working directory to: /Users/jgeerling/Sites/acquia/projectname/docroot
    [drush] Executing: /Users/jgeerling/Sites/acquia/projectname/vendor/bin/drush @self --uri=default --yes --verbose cc drush
Executing: mysql --defaults-extra-file=/private/tmp/drush_hKzVSp --database=drupal --host=localhost --port=3306 --silent  < /private/tmp/drush_etrRFn
'drush' cache was cleared.                                                                                   [success]
Command dispatch complete                                                                                       [notice]
    [drush] Changing working directory back to /Users/jgeerling/Sites/acquia/projectname/vendor/acquia/blt/phing.
    [drush] Changing working directory to: /Users/jgeerling/Sites/acquia/projectname/docroot
    [drush] Executing: /Users/jgeerling/Sites/acquia/projectname/vendor/bin/drush @self --uri=default --yes --verbose sql-drop
Do you really want to drop all tables in the database drupal? (y/n): y
Executing: mysql --defaults-extra-file=/private/tmp/drush_Zu80DC --database=drupal --host=localhost --port=3306 --silent  < /private/tmp/drush_XTBNMV
Executing: mysql --defaults-extra-file=/private/tmp/drush_O2jxpx --database=drupal --host=localhost --port=3306 --silent  < /private/tmp/drush_GQ1xSV
Command dispatch complete                                                                                       [notice]
    [drush] Changing working directory back to /Users/jgeerling/Sites/acquia/projectname/vendor/acquia/blt/phing.
Property ${drush.aliases.remote} => projectname.test
Property ${drush.aliases.local} => self
    [drush] Changing working directory to: /Users/jgeerling/Sites/acquia/projectname/docroot
    [drush] Executing: /Users/jgeerling/Sites/acquia/projectname/vendor/bin/drush --structure-tables-key=lightweight --create-db --uri=default --yes --verbose sql-sync @projectname.test @self
Loaded alias @projectname.test from file                                                                             [notice]
/Users/jgeerling/Sites/acquia/projectname/docroot/../drush/site-aliases/aliases.drushrc.php
ssh -o PasswordAuthentication=no projectname.test@staging-21390.prod.hosting.acquia.com 'env COLUMNS=120 drush8      [notice]
--backend=2 --verbose --yes --root=/var/www/html/projectname.test/docroot --uri=projectnamestg.prod.acquia-sites.com 
sql-conf   --all 2>&1' 2>&1
env COLUMNS=120 /Users/jgeerling/Sites/acquia/projectname/docroot/../vendor/bin//drush.launcher  --backend=2         [notice]
--verbose --yes --root=/Users/jgeerling/Sites/acquia/projectname/docroot --uri=default  sql-conf   --all 2>&1
You will destroy data in drupal and replace with data from staging-21390.prod.hosting.acquia.com/projectnamestg.
Do you really want to continue? (y/n): y
Starting to create database on Destination.                                                                  [ok]
env COLUMNS=120 /Users/jgeerling/Sites/acquia/projectname/docroot/../vendor/bin//drush.launcher  --backend=2 --yes   [notice]
--verbose --strict=0 --root=/Users/jgeerling/Sites/acquia/projectname/docroot --uri=default  sql-create  
--structure-tables-key=lightweight --create-db 2>&1
Creating database drupal. Any possible existing database will be dropped!
Do you really want to continue? (y/n): y
Executing: mysql --defaults-extra-file=/private/tmp/drush_x9wiWe --database=information_schema --host=localhost --port=3306 --silent  < /private/tmp/drush_rI3vH2
Command dispatch complete                                                                                       [notice]
Starting to dump database on Source.                                                                         [ok]
ssh -o PasswordAuthentication=no projectname.test@staging-21390.prod.hosting.acquia.com 'env COLUMNS=120 drush8      [notice]
--backend=2 --yes --verbose --strict=0 --root=/var/www/html/projectname.test/docroot
--uri=projectnamestg.prod.acquia-sites.com  sql-dump   --structure-tables-key=lightweight --create-db --gzip
--result-file 2>&1' 2>&1
Executing: mysql --defaults-extra-file=/mnt/tmp/projectnamestg/drush_pqr4MR --database=projectnamestg --host=staging-21390 --port=3306 --silent  < /mnt/tmp/projectnamestg/drush_8JZirP
Calling system(mysqldump --defaults-extra-file=/mnt/tmp/projectnamestg/drush_Ai3MaU  projectnamestg --host=staging-21390 --port=3306 --no-autocommit --single-transaction --opt -Q  | gzip -f > /home/projectname/drush-backups/projectnamestg/20170105151946/projectnamestg_20170105_151946.sql.gz);
Database dump saved to /home/projectname/drush-backups/projectnamestg/20170105151946/projectnamestg_20170105_151946.sql.gz  [success]
Command dispatch complete                                                                                       [notice]
Starting to discover temporary files directory on Destination.                                               [ok]
env COLUMNS=120 /Users/jgeerling/Sites/acquia/projectname/docroot/../vendor/bin//drush.launcher  --backend=2         [notice]
--verbose --yes --root=/Users/jgeerling/Sites/acquia/projectname/docroot --uri=default  core-status 2>&1
env COLUMNS=120 /Users/jgeerling/Sites/acquia/projectname/docroot/../vendor/bin//drush.launcher  --backend=2 --yes   [notice]
--verbose --root=/Users/jgeerling/Sites/acquia/projectname/docroot --uri=default  core-rsync
'@projectname.test:/home/projectname/drush-backups/projectnamestg/20170105151946/projectnamestg_20170105_151946.sql.gz'
'@self:/tmp/projectnamestg_20170105_151946.sql.gz'   --remove-source-files 2>&1
Loaded alias @projectname.test from file                                                                             [notice]
/Users/jgeerling/Sites/acquia/projectname/docroot/../drush/site-aliases/aliases.drushrc.php
You will delete files in /tmp/projectnamestg_20170105_151946.sql.gz and replace with data from projectname.test@staging-21390.prod.hosting.acquia.com:/home/projectname/drush-backups/projectnamestg/20170105151946/projectnamestg_20170105_151946.sql.gz
Do you really want to continue? (y/n): y
Calling system(rsync -e 'ssh ' -akzv --exclude=".git" --exclude=".gitignore" --exclude=".hg" --exclude=".hgignore" --exclude=".hgrags" --exclude=".bzr" --exclude=".bzrignore" --exclude=".bzrtags" --exclude=".svn" --stats --progress --remove-source-files projectname.test@staging-21390.prod.hosting.acquia.com:/home/projectname/drush-backups/projectnamestg/20170105151946/projectnamestg_20170105_151946.sql.gz /tmp/projectnamestg_20170105_151946.sql.gz);
receiving file list ... 
1 file to consider
projectnamestg_20170105_151946.sql.gz
      470812 100%  332.45kB/s    0:00:01 (xfer#1, to-check=0/1)

Number of files: 1
Number of files transferred: 1
Total file size: 470812 bytes
Total transferred file size: 470812 bytes
Literal data: 470812 bytes
Matched data: 0 bytes
File list size: 89
File list generation time: 0.001 seconds
File list transfer time: 0.000 seconds
Total bytes sent: 155
Total bytes received: 471122

sent 155 bytes  received 471122 bytes  134650.57 bytes/sec
total size is 470812  speedup is 1.00
Command dispatch complete                                                                                       [notice]
Copying dump file from Source to Destination.                                                                [ok]
Starting to import dump file onto Destination database.                                                      [ok]
env COLUMNS=120 /Users/jgeerling/Sites/acquia/projectname/docroot/../vendor/bin//drush.launcher  --backend=2 --yes   [notice]
--verbose --strict=0 --root=/Users/jgeerling/Sites/acquia/projectname/docroot --uri=default  sql-query  
--structure-tables-key=lightweight --create-db --file=/tmp/projectnamestg_20170105_151946.sql.gz --file-delete
2>&1
Executing: gzip -d /tmp/projectnamestg_20170105_151946.sql.gz
Executing: mysql --defaults-extra-file=/private/tmp/drush_P6gTgV --database=drupal --host=localhost --port=3306 --silent  < /tmp/projectnamestg_20170105_151946.sql
Query failed.                                                                                                [error]

[geerlingguy]

So... maybe a corrupt backup being imported?

[geerlingguy]

Drush versions are 9.0.0-alpha1 both on cloud and local. Checking if BLT 8.6.6 fixes this (with it's different Drush version).

[geerlingguy]

8.6.6 didn't fix it—same issue, same place.

[geerlingguy]

To add a little more madness... On one of my Macs, everything is working fine. blt local:refresh runs without issue. I did a vagrant provision again to make sure the VM was set exactly the same (it is), and it still works.

On the Mac I'm using now, and another developer's Mac, we're getting this 'Query failed' error.

[geerlingguy]

This is still working on my other Mac (the one it's always been working on) after running vagrant destroy -f && vagrant up to rebuild the VM from scratch.

Maybe it's something laying dormant in the /vendor directory? Some cached file that's allowing it to succeed? This is definitely one of the weirdest things I've run into.

[geerlingguy]

I'm going to run blt local:refresh -verbose on both of my Macs (working and non working) and diff the two. Generally speaking, every bit of configuration on the Macs is identical. Heck, I use the mac-dev-playbook to further enforce that :P

[geerlingguy]

AHA! I think I'm onto something... diffing the output gets me:

  [property] Loading /Users/jgeerling/Sites/acquia/projectname/blt/project.local.yml
-Overriding previous definition of property drush.default_alias
-Overriding previous definition of reference to drush.default_alias
-Overriding previous definition of property drush.aliases.local
-Overriding previous definition of reference to drush.aliases.local
...
      [echo] Executing commands against multisite "default"
-Property ${drush.default_alias} => projectname.local
+Property ${drush.default_alias} => self
...
-    [drush] Executing: /Users/jgeerling/Sites/acquia/projectname/vendor/bin/drush @projectname.local --uri=default --yes --verbose cc drush
-Loaded alias @projectname.local from file                                                                            [notice]
-/Users/jgeerling/Sites/acquia/projectname/docroot/../drush/site-aliases/aliases.drushrc.php
-Begin redispatch via drush_invoke_process().

So it looks like on the working machine, it's finding the projectname.local alias. On the non-working machines, it's finding the self alias (which blows up).

[geerlingguy]

Found the issue! Previously, it seems the blt/project.local.yml file had been tracked in Git, and contained the drush.aliases.local property... but at some point it was no longer tracked, and new git clones never got the file, so the default of self was being used... and failing.

drush:
    default_alias: projectname.local
    aliases:
        local: projectname.local

@grasmash - I think we can close this... but could there have been a change in 8.6.6 or the last couple days that might've caused this latent issue?

[geerlingguy]

The fix was:

diff --git a/blt/project.yml b/blt/project.yml
index c7a481a..7ae4c17 100644
--- a/blt/project.yml
+++ b/blt/project.yml
@@ -14,7 +14,7 @@ git:
 drush:
   aliases:
     remote: '${project.machine_name}.test'
-    local: self
+    local: projectname.local

[grasmash]

Shouldn't this have been in project.local.yml?

[geerlingguy]

Maybe so... hmm. Did BLT formerly include project.local.yml with the git repo? (Is it supposed to?). Because I know I set it up by hand on my other Mac, but I thought that was committed to the repo because other devs had the file after that.

[grasmash]

It get generated during initial setup, I think when you runblt vm too.

[geerlingguy]

@grasmash - Ah... after the first time one dev runs blt vm and then the config is committed to the project, nobody else runs blt vm.

[grasmash]

Oh, the intention is that every dev runs blt vm once on their machine for initial, local setup.

[geerlingguy]

Ah, didn't realize that. I think we can close this out, as at least it's all documented in the issue for anyone else hitting the same error.

It's still annoying that Drush outputs this and not something slightly more helpful.