I tried to install Panopoly which failed (#1837312: Troubles Implementing Default Permissions for Panelizer).
The anoying thing is that log in hostmaster was not helping.
There are a lot of green lines, and some white. But none red...
After the standard site setup stuff it gets interesting with:
Backend invoke: php /usr/share/php/drush/drush.php --backend=2 --yes @panopoly2.dev.example.com provision-install-backend --client_email='webmaster@example.com' 2>&1
But then the inconspicuous line:
Undefined index: login_link install.provision.inc:60
And provision begins to clean up the site.
Is this related to #1166530: Aegir use of $integrate = FALSE in drush backend invoke?
If we don't want to integrate the full backend output, could we at least print a summary line to state a failure?
Comments
Comment #1
anarcat CreditAttribution: anarcat commentedWe should get the full log in the frontend, that's for sure.
Comment #2
helmo CreditAttribution: helmo commentedThis is still bugging me every now and then.
A usecase:
The http://drupal.org/project/hosting_site_backup_manager module.
When you run a 'Export backup' task a second time it fails.
The reason is clear, the link this task is trying to create already exists. (I should aad a test for that ;))
In the aegir frontend I only see green and white lines. But still the task itself is 'Failed'.
When I run the same task on the commandline:
So the drush_shell_cd_and_exec() call gives an error, the else branch of the if logs it. But the output is lost....
Comment #3
anarcat CreditAttribution: anarcat commentedI wonder if this is related with #1982502: Reduce complexity of backend invoke; consider removing concurrency - it seems that between drush 5.4 and 5.5, DRUSH_BACKEND packets started being redirected to stderr (see comment #4). In the debian package, I fixed this problem by merging stderr to stdout (see #2002076: the debian package shows a lot of drush backend garbage).
Also, I believe this is a critical bug that should be fixed before 2.0 is released.
Comment #4
anarcat CreditAttribution: anarcat commentedi got a patch that sends the drush packets in the right place in #1982502: Reduce complexity of backend invoke; consider removing concurrency
Comment #5
helmo CreditAttribution: helmo commentedI also assumed that this was caused by #1982502: Reduce complexity of backend invoke; consider removing concurrency
I now have a Debian Wheezy, php 5.4, Drush 6.x-dev(with drush-correct-minor-defects-1982502-40.patch) , Aegir 6.x-2.x,
A task has a failed status, but no red log lines.
From the command line:
drush @hostmaster hosting-task <task-nid> --force
Gives no output lines there. Viewing the task node now does include the error lines.
A retry initiated from the frontend results in a log without the error lines.
---
Disclaimer: I'm messing with devshop and valkyrie
Comment #6
helmo CreditAttribution: helmo commentedRunning such a task via the regular cron hosting-dispatch also works OK.
So I guess it's a hosting-queued daemon issue
Cron does: drush.php '@hostmaster' hosting-dispatch
Queued does: php /usr/bin/drush @hostmaster hosting-queued
Do these invoke in a different way?
Comment #7
ergonlogicIn hosting-queued, we invoke like so:
whereas in hosting-dispatch, we invoke a queue command (hosting-tasks), which in turn does:
Comment #8
ergonlogicFirst I tried just changing hosting-queued to invoke like hosting-dispatch in hosting_tasks_queue():
This resulted in getting the error output into the front-end task log, but resulted in an error in queued:
So it looks like queued is trying to run the task twice. In fact, this is what happens when we pass '--force':
If we remove the 'fork' backend option, we lose the output in the front-end task, but the task doesn't try to run twice:
If we instead set the 'fork' backend option to FALSE, we don't get the output in the front-end, but we get a bunch of output from hosting-queued:
I'm not really sure what's going on here, nor how to fix it.
Comment #9
ergonlogicFirst I tried just changing hosting-queued to invoke like hosting-dispatch in hosting_tasks_queue():
This resulted in getting the error output into the front-end task log, but resulted in an error in queued:
So it looks like queued is trying to run the task twice. In fact, this is what happens when we pass '--force':
If we remove the 'fork' backend option, we lose the output in the front-end task, but the task doesn't try to run twice:
If we instead set the 'fork' backend option to FALSE, we don't get the output in the front-end, but we get a bunch of output from hosting-queued:
I'm not really sure what's going on here, nor how to fix it. The Drush documentation of these invoke commands is pretty opaque.
Comment #10
helmo CreditAttribution: helmo commentedI just tried "changing hosting-queued to invoke like hosting-dispatch in hosting_tasks_queue():"
After starting the queue-daemon manually with --verbose:
I also saw the "This task is already running, use --force" error three times.. also three invokes for the task... odd, but the task succeeds.
Setting the hosting_queued_post_task_delay variable to 30 seconds, prevented these from occurring.
So... concurrency?
the queue daemon loops... finds a task, forks, and restarts the loop to look for a new one....
The "This task is already running, use --force" seems to be what's saving us from having the task executed multiple times... a good thing.
Setting the hosting_queued_post_task_delay variable to 2 seconds, reduced it to just one already running error.
So this side effect of forking seems to be just a race condition that's already being caught. drush_hosting_task_validate updates the task status, maybe that can be done earlier.... ? But more important, we do get the full log.
Comment #11
ergonlogicOkay, so I think we've identified the proper solution here. So this is fixed 850e53cb. We've also identified a new bug, which I've documented in #2025173: Possible race condition with _hosting_get_new_tasks().
Feel free to revert the commit and re-open this issue, if anyone feels we've taken the wrong approach.
Comment #12
anarcat CreditAttribution: anarcat commentedSo i changd that to --quiet instead of fork, because that's what we were looking for. This still needs some testing, but forking definitely is not the right way to do this. To quote my commit:
Comment #13
anarcat CreditAttribution: anarcat commentedso this doesn't work, so there's got to be another magic thing going on here.
Comment #14
ergonlogicUnfortunately, that doesn't work. Here's the output after that change:
and here's what was happening with 'fork':
The proc_open() is apparently what's making this work. So here's what happens when we replace 'fork' with 'interactive':
This appears to fail because of the redirect to 'tty' in interactive. Commenting out the relevant bit from _drush_backend_generate_command() in includes/backend.inc in Drush makes this work properly:
Comment #15
anarcat CreditAttribution: anarcat commentedI have opened #2025527: > `tty` is evil and killed my cat for this, let's see if we can factor this into drush 5, even as a custom package or something...
So note that this affects only hosting-queued, and only if it is ran through sudo aegir. If you fix your terminal so that aegir can actually write to `tty`, you should be able to use #interactive without problems.
Comment #16
ergonlogicThis is fixed in a33d62da4e by switching to use 'interactive' mode. Unfortunately, it requires the patch in #4 of #2025527: > `tty` is evil and killed my cat. Marking as 'postponed' pending resolution of that issue, so we don't lose track of this.
Comment #17
Steven Jones CreditAttribution: Steven Jones commentedCan we instead introduce something into Drush that does something like 'interactive' but only does the thing that we want, which I think it returning all the output at the end rather than sending packets as the command runs?
Comment #18
ergonlogicIs there some benefit to getting all the output at the end? The AJAX stuff you did for Aegir 3.x, that allows our task log to be updated live is really cool. Wouldn't switching away from packets break this?
Comment #19
ergonlogic#2025527: > `tty` is evil and killed my cat has been committed to Drush 8.x-6.x, and I've requested it be backported to Drush 5. Perhaps we should revisit #2002804: [meta] depend on Drush 8.x-6.x?
Comment #20
anarcat CreditAttribution: anarcat commentedI would prefer lobby for inclusion in drush 5.10.
Comment #21
anarcat CreditAttribution: anarcat commentedso, what's the status here? we're waiting for drush 5.10?
Comment #22
ergonlogicI believe so. Moshe want a 5.10 too, so it'll happen sooner or later. The issue to track is https://github.com/drush-ops/drush/issues/71
Comment #23
helmo CreditAttribution: helmo commentedThe 5.10 drush release is there... so whatever drush major version we ship with this issue should be fixed now right?
Comment #24
anarcat CreditAttribution: anarcat commentedlet's assume so, we'll see soon enough...
Comment #25.0
(not verified) CreditAttribution: commentedcleanup