Rake task executing twice when only called once

5
votes

I've written a very simple rake task to try and locate the source of this problem.

namespace :foo do
 task bar: :environment do
  puts 'RUNNING'
 end
end

When executed in the console rake foo:bar the output is:

RUNNING
RUNNING

This occurs when I execute any rake task. Has anyone encountered anything like this before?

EDIT

The above rake task is all that is written in that .rake file.

Here is the Rakefile currently being used.

require File.expand_path('../config/application', __FILE__)

OurApp::Application.load_tasks

Also here is the output from running a --trace.

** Invoke foo:bar (first_time)
** Invoke environment (first_time)
** Execute environment
Hostname is: ourhost
** Execute foo:bar
RUNNING
RUNNING
3
ruby-on-railsrubyrake
The rails_12factor causes double log entries. If you have it installed make sure you're only loading it in the :production environment: gem 'rails_12factor', group: :production - infused
we don't use rails_12factor, thanks for the tip though! - Broc Broccoli
can you please provide additional code. Are you requiring rake or a rake file again possibly? googling "rake executing twice" has a lot of possible reasons why this would happen but most of them seem to boil down to multiple require or initialization where they are not needed. - engineersmnky
Try running rake foo:bar --trace which displays the order of tasks. That might give you an idea of whats calling the particular task twice. - Dharam Gollapudi
From the trace the task seems to be run only once. Can you add a second puts, e.g. puts "STILL RUNNING" and show us the output so that we can rule out a possible double echoing to the console? - Matouš Borák

3 Answers

6
votes

This is reproducible in a brand new app. The problem disappears if you do not pass the :environment parameter to the rake task.

I traced the issue to ~/.rvm/rubies/ruby-2.2.2/lib/ruby/2.2.0/rake/task.rb where we hit the enhance() method twice for this rake task:

[99, 108] in /Users/inovakov/.rvm/rubies/ruby-2.2.2/lib/ruby/2.2.0/rake/task.rb
    99:     # Enhance a task with prerequisites or actions.  Returns self.
   100:     def enhance(deps=nil, &block)
   101:       byebug if self.to_s.include? 'foo'
   102:       @prerequisites |= deps if deps
   103:       @actions << block if block_given?
=> 104:       self
   105:     end
   106: 
   107:     # Name of the task, including any namespace qualifiers.
   108:     def name
(byebug) @actions
[#<Proc:0x007ff492701aa0@/Users/inovakov/source/test_app/lib/tasks/foo.rake:4>, #<Proc:0x007ff4920d3f70@/Users/inovakov/source/test_app/lib/tasks/foo.rake:4>]

Between the first and the second time we hit this method we initialise the environment - in this case app/config/environments/development.rb.

If we have two outputs in the rake task we see them both:

bash-3.2$ bundle exec rake foo:bar --trace
** Invoke foo:bar (first_time)
** Invoke environment (first_time)
** Execute environment
Hostname is: localhost
** Execute foo:bar
RUNNING
STILL RUNNING
RUNNING
STILL RUNNING

(I know this is not an answer but I don't have comment privileges yet and this could hopefully help the discussion.)

5
votes

There are plenty of reasons why a Rake task could be running twice, and in this specific case I think it could have to do with the Rake environment loading more than once, as the question linked by @kucaahbe suggests.

I actually got here looking for help myself but my issue was different and I managed to find the answer. Don't think it will help this particular issue but I'll leave it here too.

Make sure your Rake environment is loading only once

Following the question linked by @kucaahbe, it suggests this would happen if your environment is loading and initializing Rake twice.

In the context a Rake task runs rake has already been required and initialized, so make sure your task does not include the following lines:

require 'rake'
...
Rake.application.init
Rake.application.load_rakefile

In this specific case the task does not seem to be doing anything of the sort, so I would check other tasks or the Rakefile for something forcing the Rake context to be loaded twice.

Clear pre-existing tasks before redefining them

Just had this issue due to a gem creating a Rake task with the same name.

For instance, if you declare the following task in a Rails application:

namespace :assets do
  task :precompile do
    puts "Hello"
  end
end

and run rake assets:precompile:

...
I, [2017-07-31T11:25:09.498897 #9455]  INFO -- : Writing /home/pfac/...css.gz
Hello
Hello

But if you use Rake::Task#clear:

namespace :assets do
  task(:precompile).clear
  task :precompile do
    puts "Hello"
  end
end

it disables any pre-existing behaviour and prints only Hello.

I don't think this option solves this particular issue, unless @broc-broccoli has been defining other foo:bar rake tasks.

Anyway, hope this helps.

0
votes

For me my rake environnement was loading twice in my rails app because of the presence in my test file of :

setup do
  MyApp::Application.load_tasks
end

I removed it and the task was invoked once.

Hope it can help.

Sorry for my english.