Restoring Project Backups


#1

Hi,

I’m trying to restore a project backup but nothing happens. I upload the dradis-project.zip and get the following messages in the progress window:

[15:23:26] Enqueueing job to start in the background.

[15:23:26] Job id is 82d11b50-9566-4dd2-a478-1402f5249602.

[15:23:28] Running Ruby version 2.3.1

[15:23:28] Worker process starting background task.

It seems to do something but hours later, I never get the “Worker process completed” as per this guide.

Any help on why this is happening would be appreciated. Thanks in advance.


#2

@elb is your background worker running? More details here: https://dradisframework.com/ce/documentation/install_git.html

In a new terminal tab, run:
$ bundle exec rake resque:work

I trust this will get uploads working again as expected! Any questions? Let us know!


#3

Yes the worker is running. here is the output when I start it.

dradis@dradis-VirtualBox:~$ cd opt/dradis-ce/
dradis@dradis-VirtualBox:~/opt/dradis-ce$ bundle exec rake resque:work
DEPRECATION WARNING: before_filter is deprecated and will be removed in Rails 5.1. Use before_action instead. (called from <top (required)> at /home/dradis/opt/dradis-ce/config/application.rb:16)
DEPRECATION WARNING: before_filter is deprecated and will be removed in Rails 5.1. Use before_action instead. (called from <top (required)> at /home/dradis/opt/dradis-ce/config/application.rb:16)

Should there be some kind of output in the terminal window when the new job gets created?


#4

@elb Thanks for the update! That’s the expected output. A few more things to check:

  1. Do you see anything on the /jobs/overview page in your browser while the upload runs?
  2. Any clues/stack traces in log/development.log or log/resque.log?

#5
  1. I didn’t know that that page even existed hahaha. Here are the errors.

    Worker
    dradis-VirtualBox:2141 on dradis_upload at about 2 hours ago
    Retry or Remove
    Class
    ActiveJob::QueueAdapters::ResqueAdapter::JobWrapper
    Arguments

     ---
     job_class: UploadJob
     job_id: 82d11b50-9566-4dd2-a478-1402f5249602
     queue_name: dradis_upload
     priority: 
     arguments:
     - file: "/home/dradis/opt/dradis-ce/attachments/5/dradis-export.zip"
       plugin: Dradis::Plugins::Projects::Upload::Package
       uid: 4
       _aj_symbol_keys:
       - file
       - plugin
       - uid
     locale: en
    

    Exception
    NameError
    Error
    undefined local variable or method `plugin_name’ for #UploadJob:0x00000006c12f68 Did you mean? plugin

    Worker
    dradis-VirtualBox:2141 on dradis_upload at about 2 hours ago
    Retry or Remove
    Class
    ActiveJob::QueueAdapters::ResqueAdapter::JobWrapper
    Arguments

     ---
     job_class: UploadJob
     job_id: dcce72d3-eadc-427a-b3c1-fb435d4096b6
     queue_name: dradis_upload
     priority: 
     arguments:
     - file: "/home/dradis/opt/dradis-ce/attachments/4/dradis-export.zip"
       plugin: Dradis::Plugins::Projects::Upload::Package
       uid: 3
       _aj_symbol_keys:
       - file
       - plugin
       - uid
     locale: en
    

    Exception
    NameError
    Error
    undefined local variable or method `plugin_name’ for #UploadJob:0x007f90181c98c8 Did you mean? plugin

    Worker
    dradis-VirtualBox:699 on dradis_upload at about 2 hours ago
    Retry or Remove
    Class
    ActiveJob::QueueAdapters::ResqueAdapter::JobWrapper
    Arguments

     ---
     job_class: UploadJob
     job_id: c823da66-25d0-42f8-b0f3-01efd6073dda
     queue_name: dradis_upload
     priority: 
     arguments:
     - file: "/home/dradis/opt/dradis-ce/attachments/4/dradis-export.zip"
       plugin: Dradis::Plugins::Projects::Upload::Package
       uid: 2
       _aj_symbol_keys:
       - file
       - plugin
       - uid
     locale: en
    

    Exception
    ActiveRecord::StatementInvalid
    Error
    Could not find table ‘logs’

  2. I don’t see anything bad in those log files.


#6

Hi there,

undefined local variable or method `plugin_name’ for # Did you mean? plugin

That one seems to indicate an out of date codebase, can you git pull on your dradis-ce folder, restart resque and restart the app and see if that helps?

-Daniel


#7

It worked! Thanks

That’s weird that upon a fresh install of dradis from git I would still have to do a git pull to get the most updated code. Wouldn’t a git clone done yesterday give me the latest code?


#8

Wouldn’t a git clone done yesterday give me the latest code?

It would, if we were not busy improving things all the time. The code / issue you were seeing was related / fixed by a PR that was merged 16h ago: https://github.com/dradis/dradis-ce/pull/103

Glad it’s working for now!


#9

Hahaha wow. You guys do update things all the time! Kudos.

On an other note, is there a way to migrate projects from Dradis 2.10 to the current version?


#10

@elb Rachael here again! I’m assuming you have 1 instance of Dradis running v2.10 and another running the latest version, correct? If so, you can export the project from Instance A and import it into Instance B: https://dradisframework.com/pro/support/guides/projects/import.html (that’s a Pro guide but the interface is the same on CE!)

Give it a try and let us know how it goes.


#11

Yes, I’m running both instances. I already tried importing my old project into the newest version of Dradis and everything appears to complete normally but then I get virtually no data to show up. One node appears but contains no data. I also get this error at the end of the import process. This is by no means the entire log. I just pasted the last part of it. I’m trying to import a large project.

[11:50:02] New node detected: Note 564, parent_id: 467, type_id: 0

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:02] Note category rewrite, used to be 1, now is 3

[11:50:02] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] New note added.

[11:50:03] Note category rewrite, used to be 1, now is 3

[11:50:03] Validation failed: Text is too long (maximum is 65535 characters)

[11:50:03] ["/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/validations.rb:78:in `raise_validation_error'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/validations.rb:50:in `save!'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/attribute_methods/dirty.rb:30:in `save!'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/transactions.rb:324:in `block in save!'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/transactions.rb:211:in `transaction'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/transactions.rb:324:in `save!'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/suppressor.rb:45:in `save!'", "/var/lib/gems/2.3.0/gems/activerecord-5.0.2/lib/active_record/persistence.rb:51:in `create!'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/v1/template.rb:309:in `block in parse_node_notes'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:187:in `block in each'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:186:in `upto'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:186:in `each'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/v1/template.rb:299:in `parse_node_notes'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/v1/template.rb:245:in `parse_node'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/v1/template.rb:258:in `block in parse_nodes'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:187:in `block in each'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:186:in `upto'", "/var/lib/gems/2.3.0/gems/nokogiri-1.6.8/lib/nokogiri/xml/node_set.rb:186:in `each'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/v1/template.rb:256:in `parse_nodes'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/template.rb:63:in `parse'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/template.rb:55:in `import'", "/home/dradis/.bundle/ruby/2.3.0/dradis-projects-9b8838096cad/lib/dradis/plugins/projects/upload/package.rb:43:in `import'", "/home/dradis/opt/dradis-ce/app/jobs/upload_job.rb:17:in `perform'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/execution.rb:34:in `block in perform_now'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:126:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:455:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:448:in `block (2 levels) in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:286:in `block (2 levels) in halting'", "/var/lib/gems/2.3.0/gems/i18n-0.7.0/lib/i18n.rb:257:in `with_locale'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/translation.rb:7:in `block (2 levels) in <module:Translation>'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `instance_exec'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `block in make_lambda'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:285:in `block in halting'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:447:in `block in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:455:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:448:in `block (2 levels) in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:286:in `block (2 levels) in halting'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/logging.rb:24:in `block (4 levels) in <module:Logging>'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/notifications.rb:164:in `block in instrument'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/notifications/instrumenter.rb:21:in `instrument'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/notifications.rb:164:in `instrument'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/logging.rb:23:in `block (3 levels) in <module:Logging>'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/logging.rb:44:in `block in tag_logger'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/tagged_logging.rb:69:in `block in tagged'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/tagged_logging.rb:26:in `tagged'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/tagged_logging.rb:69:in `tagged'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/logging.rb:44:in `tag_logger'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/logging.rb:20:in `block (2 levels) in <module:Logging>'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `instance_exec'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `block in make_lambda'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:285:in `block in halting'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:447:in `block in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:455:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:101:in `__run_callbacks__'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:750:in `_run_perform_callbacks'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:90:in `run_callbacks'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/execution.rb:33:in `perform_now'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/execution.rb:22:in `block in execute'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:126:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:455:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:448:in `block (2 levels) in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:286:in `block (2 levels) in halting'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/railtie.rb:26:in `block (4 levels) in <class:Railtie>'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/execution_wrapper.rb:85:in `wrap'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/reloader.rb:68:in `block in wrap'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/execution_wrapper.rb:85:in `wrap'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/reloader.rb:67:in `wrap'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/railtie.rb:25:in `block (3 levels) in <class:Railtie>'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `instance_exec'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:391:in `block in make_lambda'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:285:in `block in halting'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:447:in `block in around'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:455:in `call'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:101:in `__run_callbacks__'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:750:in `_run_execute_callbacks'", "/var/lib/gems/2.3.0/gems/activesupport-5.0.2/lib/active_support/callbacks.rb:90:in `run_callbacks'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/execution.rb:20:in `execute'", "/var/lib/gems/2.3.0/gems/activejob-5.0.2/lib/active_job/queue_adapters/resque_adapter.rb:45:in `perform'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/job.rb:164:in `perform'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/worker.rb:290:in `perform'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/worker.rb:229:in `block in work'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/worker.rb:206:in `loop'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/worker.rb:206:in `work'", "/var/lib/gems/2.3.0/gems/resque-1.26.0/lib/resque/tasks.rb:19:in `block (2 levels) in <top (required)>'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:250:in `block in execute'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:250:in `each'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:250:in `execute'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:194:in `block in invoke_with_call_chain'", "/usr/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:187:in `invoke_with_call_chain'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/task.rb:180:in `invoke'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:152:in `invoke_task'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:108:in `block (2 levels) in top_level'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:108:in `each'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:108:in `block in top_level'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:117:in `run_with_threads'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:102:in `top_level'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:80:in `block in run'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:178:in `standard_exception_handling'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/lib/rake/application.rb:77:in `run'", "/var/lib/gems/2.3.0/gems/rake-12.0.0/exe/rake:27:in `<top (required)>'", "/usr/local/bin/rake:23:in `load'", "/usr/local/bin/rake:23:in `<main>'"]

[11:50:03] Done.

[11:50:03] Moving attachments to their final destinations...

[11:50:03] undefined method `each' for false:FalseClass

[11:50:03] Worker process completed.

I also looked in the database and I can see that there have been a lot of entries made in the “nodes” tables that seem to be accurate but they are not showing up anywhere in the web interface.


#12

@elb it looks like the project isn’t importing correctly so I am not surprised that the web interface isn’t displaying correctly.

This line looks to be the key:

Could you check out the content at /nodes/564 and look for a particularly long Note? Once you identify the one that is >65535 characters and trim it down (maybe splitting into more than one Note?), the project should export/import as expected sans errors.


#13

Thank you for the reply. On my 2.10 instance, browsing to the /nodes/564 gives me a blank page and on my 3.1 instance I get an error:

ActiveRecord::RecordNotFound in NodesController#show
Couldn't find Node with 'id'=564

Am I doing this right? Should I be looking for the node 564 elsewhere?


#14

Hi @elb I think I misread the log output here:

Do you have a Node in the project called Note 564? If so, there is a Note under that Node that is above the max character limit (65535 characters). How large of a project are you working with here? Once we find and trim down that large Note, the project should work as expected!


#15

No there is no node named Note 564. The project is very large. Is there a way of running a query on the database to find out what node would be too large to import?


#16

Hi @elb, this should get you the info that you need. Navigate to the dradis-ce folder on your local system (for the old instance!), then run:

$ bundle exec rails console
irb> Note.where("length(text) > 65535")

That will output all of the Notes that are larger than the character limit we’re hitting during the import into the latest version of Dradis. Edit that Note (or Notes!) and run the Note.where command until no more results remain.

To exit the rails console, run:

irb> exit

Once you have edited the Note(s), export the project from your old instance again, and you should be able to import it into your new instance without a problem! Keep us posted with any updates.


#17

I managed to find all the notes that were causing me problems and successfully imported the data into the newest version.

Thanks for all the help!