Cannot import, upload, restore project backup

[jumson]

Steps to reproduce

From main page, with an exported project.zip file waiting:

1. click "Upload output from tool"
2. under "Choose a tool" select Dradis::Plugins::Projects::Upload::Package
3. click "Choose File" button and select the *zip created by the project export tool.

Expected behavior

I expect that my old project nodes, hosts, issues, evidence and everything get populated to the current project.

Actual behavior

The "console" shows this message:

Nothing exciting happens in the http://127.0.0.1:3001/jobs/overview area

Nothing from my old project appears, except that .zip file is now in my uploaded files.

I suspect this particular error is the culprit: [ActiveJob] [UploadJob] [f805ebce-2ea2-40be-9f5c-531088331b54] Error performing UploadJob (Job ID: f805ebce-2ea2-40be-9f5c-531088331b54) from Async(dradis_upload) in 0.26ms: ArgumentError (unknown keyword: project_id):

from the development.log:

Started POST "/projects/1/upload.js" for 127.0.0.1 at 2019-01-05 16:10:21 +0000
Processing by UploadController#create as JS
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"nRlvMMreSuWfHYjGclRpv4tquoxBY4Ju11Oao011HRK5CU1dWQq4kwhgDQ6fQvsz+NjsLGVCUD7ODA+x2Hkamg==", "uploader"=>"Dradis::Plugins::Projects::Upload::Package", "file"=>#<ActionDispatch::Http::UploadedFile:0x0000557d77131768 @tempfile=#<Tempfile:/tmp/RackMultipart20190105-1976-bjwpfg.zip>, @original_filename="dradis-export_04_jan_2019.zip", @content_type="application/x-zip-compressed", @headers="Content-Disposition: form-data; name=\"file\"; filename=\"dradis-export_04_jan_2019.zip\"\r\nContent-Type: application/x-zip-compressed\r\n">, "item_id"=>"13", "project_id"=>"1"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  Configuration Load (0.1ms)  SELECT  "configurations".* FROM "configurations" WHERE "configurations"."name" = ? LIMIT ?  [["name", "admin:plugins:uploads_node"], ["LIMIT", 1]]
  Node Load (0.1ms)  SELECT  "nodes".* FROM "nodes" WHERE "nodes"."label" = ? LIMIT ?  [["label", "Uploaded files"], ["LIMIT", 1]]
  Node Exists (0.1ms)  SELECT  1 AS one FROM "nodes" WHERE "nodes"."id" = ? LIMIT ?  [["id", 6], ["LIMIT", 1]]
  Rendering upload/create.js.erb
  Rendered upload/create.js.erb (1.5ms)
Completed 200 OK in 25ms (Views: 6.3ms | ActiveRecord: 0.6ms)

Started POST "/projects/1/upload/parse" for 127.0.0.1 at 2019-01-05 16:10:21 +0000
Processing by UploadController#parse as JS
  Parameters: {"item_id"=>"13", "uploader"=>"Dradis::Plugins::Projects::Upload::Package", "file"=>"dradis-export_04_jan_2019.zip", "project_id"=>"1"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  Configuration Load (0.2ms)  SELECT  "configurations".* FROM "configurations" WHERE "configurations"."name" = ? LIMIT ?  [["name", "admin:plugins:uploads_node"], ["LIMIT", 1]]
  Node Load (0.3ms)  SELECT  "nodes".* FROM "nodes" WHERE "nodes"."label" = ? LIMIT ?  [["label", "Uploaded files"], ["LIMIT", 1]]
  Node Exists (0.2ms)  SELECT  1 AS one FROM "nodes" WHERE "nodes"."id" = ? LIMIT ?  [["id", 6], ["LIMIT", 1]]
   (0.0ms)  begin transaction
  SQL (2.6ms)  INSERT INTO "logs" ("uid", "text", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["uid", 13], ["text", "Enqueueing job to start in the background."], ["created_at", "2019-01-05 16:10:21.860997"], ["updated_at", "2019-01-05 16:10:21.860997"]]
   (10.5ms)  commit transaction
[ActiveJob] Enqueued UploadJob (Job ID: f805ebce-2ea2-40be-9f5c-531088331b54) to Async(dradis_upload) with arguments: {:default_user_id=>1, :file=>"/home/ec2-user/dradis-ce/attachments/6/dradis-export_04_jan_2019.zip", :plugin_name=>"Dradis::Plugins::Projects::Upload::Package", :project_id=>1, :uid=>13}
[ActiveJob] [UploadJob] [f805ebce-2ea2-40be-9f5c-531088331b54] Performing UploadJob (Job ID: f805ebce-2ea2-40be-9f5c-531088331b54) from Async(dradis_upload) with arguments: {:default_user_id=>1, :file=>"/home/ec2-user/dradis-ce/attachments/6/dradis-export_04_jan_2019.zip", :plugin_name=>"Dradis::Plugins::Projects::Upload::Package", :project_id=>1, :uid=>13}
Completed 200 OK in 21ms (ActiveRecord: 14.0ms)

[ActiveJob] [UploadJob] [f805ebce-2ea2-40be-9f5c-531088331b54] Error performing UploadJob (Job ID: f805ebce-2ea2-40be-9f5c-531088331b54) from Async(dradis_upload) in 0.26ms: ArgumentError (unknown keyword: project_id):
/home/ec2-user/dradis-ce/app/jobs/upload_job.rb:4:in `perform'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/execution.rb:37:in `block in perform_now'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/i18n-1.1.1/lib/i18n.rb:284:in `with_locale'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/translation.rb:7:in `block (2 levels) in <module:Translation>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `instance_exec'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/logging.rb:24:in `block (4 levels) in <module:Logging>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/notifications.rb:166:in `block in instrument'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/notifications.rb:166:in `instrument'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/logging.rb:23:in `block (3 levels) in <module:Logging>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/logging.rb:44:in `block in tag_logger'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/tagged_logging.rb:69:in `block in tagged'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/tagged_logging.rb:26:in `tagged'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/tagged_logging.rb:69:in `tagged'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/logging.rb:44:in `tag_logger'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/logging.rb:20:in `block (2 levels) in <module:Logging>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `instance_exec'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/execution.rb:33:in `perform_now'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/execution.rb:22:in `block in execute'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/railtie.rb:26:in `block (4 levels) in <class:Railtie>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/execution_wrapper.rb:85:in `wrap'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/reloader.rb:68:in `block in wrap'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/execution_wrapper.rb:85:in `wrap'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/reloader.rb:67:in `wrap'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/railtie.rb:25:in `block (3 levels) in <class:Railtie>'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `instance_exec'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activesupport-5.1.6.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/execution.rb:20:in `execute'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/activejob-5.1.6.1/lib/active_job/queue_adapters/async_adapter.rb:68:in `perform'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/home/ec2-user/dradis-ce/ruby/2.5.0/gems/concurrent-ruby-1.1.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
Started GET "/console/status?item_id=13&after=0&_=1546704464767" for 127.0.0.1 at 2019-01-05 16:10:22 +0000
Processing by ConsoleController#status as JS
  Parameters: {"item_id"=>"13", "after"=>"0", "_"=>"1546704464767"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  Log Exists (0.1ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 0) LIMIT ?  [["LIMIT", 1]]
  Log Load (0.1ms)  SELECT  "logs".* FROM "logs" WHERE (uid = 13 and id > 0) ORDER BY "logs"."id" DESC LIMIT ?  [["LIMIT", 1]]
  Rendering console/status.js.erb
  CACHE Log Exists (0.0ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 0) LIMIT ?  [["LIMIT", 1]]
  CACHE Log Exists (0.0ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 0) LIMIT ?  [["LIMIT", 1]]
  Log Load (0.1ms)  SELECT "logs".* FROM "logs" WHERE (uid = 13 and id > 0)
  Rendered collection of logs/_log.html.erb [1 times] (0.4ms)
  Rendered console/status.js.erb (4.8ms)
Completed 200 OK in 17ms (Views: 12.0ms | ActiveRecord: 0.6ms)

Started GET "/console/status?item_id=13&after=8&_=1546704464768" for 127.0.0.1 at 2019-01-05 16:10:23 +0000
Processing by ConsoleController#status as JS
  Parameters: {"item_id"=>"13", "after"=>"8", "_"=>"1546704464768"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  Log Exists (0.1ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 8) LIMIT ?  [["LIMIT", 1]]
  Rendering console/status.js.erb
  CACHE Log Exists (0.0ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 8) LIMIT ?  [["LIMIT", 1]]
  CACHE Log Exists (0.0ms)  SELECT  1 AS one FROM "logs" WHERE (uid = 13 and id > 8) LIMIT ?  [["LIMIT", 1]]
  Rendered console/status.js.erb (1.3ms)
Completed 200 OK in 12ms (Views: 8.1ms | ActiveRecord: 0.2ms)

System configuration

Dradis version: master branch as of today Ruby version: ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux-gnu] OS version: Linux kali 4.17.0-kali1-amd64 #1 SMP Debian 4.17.8-1kali1 (2018-07-24) x86_64 GNU/Linux

[jumson]

Until this is fixed, my workaround to backup and restore my project (or move to another server!) is to copy the *.db from the dradis-ce/db directory, and copy the dradis-ce/attachments directory. Then on my other server I simply overwrite the ones on my recently git clone of dradis-ce, and it appears to all be functioning well.

[aapomm]

Hi @jumson, can you confirm if #420 resolves your issue? Thanks.

[jumson]

@aapomm I made the edits you did (in upload_job.rb) and forced it to process_upload_background and it worked! Thanks. Issue resolved.