Top Menu

Jump to content
Home
    Modules
      • Projects
      • Activity
      • Work packages
      • Gantt charts
      • Calendars
      • Team planners
      • Boards
      • News
    • Getting started
    • Introduction video
      Welcome to OpenProject Community
      Get a quick overview of project management and team collaboration with OpenProject. You can restart this video from the help menu.

    • Help and support
    • Upgrade to Enterprise edition
    • User guides
    • Videos
    • Shortcuts
    • Community forum
    • Enterprise support

    • Additional resources
    • Data privacy and security policy
    • Digital accessibility (DE)
    • OpenProject website
    • Security alerts / Newsletter
    • OpenProject blog
    • Release notes
    • Report a bug
    • Development roadmap
    • Add and edit translations
    • API documentation
  • Sign in
      Forgot your password?

      or sign in with your existing account

      Google

Side Menu

  • Overview
  • Activity
    Activity
  • Roadmap
  • Work packages
    Work packages
  • Gantt charts
    Gantt charts
  • Calendars
    Calendars
  • Team planners
    Team planners
  • Boards
    Boards
  • News
  • Forums

Content

General discussion
  1. OpenProject
  2. Forums
  3. General discussion
  4. PUT requests always take 30(ish) seconds !!

PUT requests always take 30(ish) seconds !!

Added by Tiago Geada over 11 years ago

Hi,

I deployed openproject with apache (mod passenger) and I can’t figure why PUT requests are taking so long.

browser hits ‘submit’ on the update issue screen, and takes 30 seconds to get status 302 back from server. Also, on browser shows as a POST request, but production.log shows as PUT

funny thing is that apache log will also be written past those same 30 seconds, same time that production.log will have new lines..

What should I be looking at?


Replies (23)

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Also, I turned on MySQL logging, and:

These were the last queries before updating a issue (look at the time before each query)

130 Query SELECT `users`.* FROM `users` INNER JOIN `watchers` ON `users`.id = `watchers`.user_id WHERE ((`watchers`.watchable_type = ‘Issue’) AND (`watchers`.watchable_id = 312)) AND (users.status = 1) AND ( (`users`.`type` = ‘User’ OR `users`.`type` = ‘AnonymousUser’ OR `users`.`type` = ‘DeletedUser’ ) )
130 Query SELECT * FROM `users` WHERE (LOWER (mail) IN (‘luciano.dias@domain’,‘tiago.geada@domain’)) AND ( (`users`.`type` = ‘User’ OR `users`.`type` = ‘AnonymousUser’ OR `users`.`type` = ‘DeletedUser’ ) )
130 Query SELECT * FROM `trackers` WHERE (`trackers`.`id` = 11)
130 Query SELECT * FROM `issue_statuses` WHERE (`issue_statuses`.`id` = 9)
130 Query SELECT * FROM `enumerations` WHERE (`enumerations`.`id` = 4) AND ( (`enumerations`.`type` = ‘IssuePriority’ ) ) ORDER BY enumerations.position ASC
130 Query SELECT * FROM `custom_fields` WHERE (is_for_all=1) AND ( (`custom_fields`.`type` = ‘IssueCustomField’ ) ) ORDER BY position
130 Query SELECT * FROM `custom_fields` INNER JOIN `custom_fields_projects` ON `custom_fields`.id = `custom_fields_projects`.custom_field_id WHERE (`custom_fields_projects`.project_id = 10 ) AND ( (`custom_fields`.`type` = ‘IssueCustomField’ ) ) ORDER BY custom_fields.position
130 Query SELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_trackers` ON `custom_fields`.id = `custom_fields_trackers`.custom_field_id WHERE (`custom_fields_trackers`.tracker_id = 11 ) AND ( (`custom_fields`.`type` = ‘IssueCustomField’ ) )
140202 18:29:07 130 Query SELECT * FROM `user_preferences` WHERE (`user_preferences`.user_id = 3) LIMIT 1

Then it took about 25 seconds or so and performed these:

140202 18:29:38 130 Query SELECT `journals`.id FROM `journals` WHERE (`journals`.`version` = 14 AND `journals`.`journaled_id` = 312 AND `journals`.`type` = ‘IssueJournal’ AND `journals`.id <> 1570) LIMIT 1
130 Query UPDATE `journals` SET `changes` = ‘—- {}\n\n’ WHERE `id` = 1570
130 Query SELECT * FROM `journals` WHERE (`journals`.journaled_id = 312) AND ( (`journals`.`type` = ‘IssueJournal’ ) ) ORDER BY journals.version DESC LIMIT 1
130 Query SELECT * FROM `users` WHERE (`users`.`id` = 3) AND ( (`users`.`type` = ‘User’ OR `users`.`type` = ‘AnonymousUser’ OR `users`.`type` = ‘DeletedUser’ ) )
130 Query COMMIT

And it took a few more seconds to show the response in the browser and everything else

RE: PUT requests always take 30(ish) seconds !! - Added by Philipp Tessenow over 11 years ago

Hi Tiago,

I don’t have an idea what the problem is (I have never heard of such a problem before), but we might be able to debug it :)

From your log I see that you use OpenProject 2.4 - is it an option for you to migrate to the recent 3.0 version? It is not officially marked as ‘stable’. However, our production systems (esp. openproject.org) are already running version 3.

Because we upgraded the whole software stack (ruby 2.0, rails 3) you might get rid of that problem. We don’t have an official upgrade guide yet, but I’ll ask Markus if he can answer here with his personal instructions. Once you are on OpenProject 3, you might consider using memcached for caching.

From your e-mail, I see that you have posted this related question (http://stackoverflow.com/questions/21514078) on StackOverflow. The wordpress site you added should not make a difference. The upgrades you did might change a thing - which ruby do you use? A system provided 1.8 ruby?

Do you have the same problem with the PUT request when you acces the site from a stand alone passenger? (so that we can be certain that your apache settings do no harm).
What if you start openproject via RAILS_ENV=production script/server?

yours,
Philipp

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Hi Philipp,

Thank you for your quick reply.

I did try running as a standalone (development, and now as RAILS_ENV=production) and same issue is happening.

I did try at the beginning to install 3.0, but it required ruby1.9 and there was some gem (can’t remember the problem for sure) that was giving me trouble regarding ruby 1.9, and as ruby 1.8 is default in debian wheezy, I stucked with 2.4

I never used ruby on rails before, and I’m a bit afraid of running into problems.

We already configured openproject to our needs and would like to have the lst problems possible.

Also you state ruby 2.0, I would need to install it from testing… I guess that would be OK.

We run a system provided ruby 1.8

How could I debug further?

What steps would one need to migrate to openproject 3?

Thank you in advance

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Hi,

I created a chroot on Debian, messed arround installing ruby 2.0 and all… and managed after a few hick ups, to get openproject 3.0 up and running.

Looks great, and promissing. Deserves praise!

I must state, it is slightly sluggish’er than 2.4 … not sure if it is because both are running, or it is using memcached .. or whatever… I’ll try and figure out that later

Now, how would I replicate all data on existing 2.4 to this 3.0 instance? So we cold see what it would be like in production?

RE: PUT requests always take 30(ish) seconds !! - Added by Philipp Tessenow over 11 years ago

Hello again,

I really appreciate the praise :)

As I told you in my last post, I asked Markus if he can provide migration instructions (we need them anyway before the final release). He promised me to write those instructions and give you a response here, if the guide is online.

Basically the migration should go smooth. The only thing is that you have to be careful with plugins. Any plugin, which is not ported to OpenProject 3 cannot be used (until someone updates it). Do you use any plugins for your installation (and which ones)?

— philipp

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Hello Philipp,

Again, thank you for your feedback, much welcome.

All the modules I installed, were the ones on https://www.openproject.org/projects/openproject/wiki/Installation_OpenProject_2_4#32-Install-plugins which I did remove just now. This should not represent a issue, right?

I guess I could try and clone the DB of 2.4 into the 3.0 ? haven’t checked if the SQL structure is the same…

I look forward to read Markus instructions, meanwhile, can I simply try and use a copy of 2.4 SQL structure on 3.0? Or is there some basic steps to perform?
While there are no instructions I could try and make it work. I’m not big on ruby nor ruby on rails, but I’m great with linux, sql and alikes…

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Well I noticed that the SQL structure differs.

I will be waiting for Markus …

RE: PUT requests always take 30(ish) seconds !! - Added by Philipp Tessenow over 11 years ago

If you have removed the modules things should be fine (at a first glance) - most of these plugins have been merged into the OpenProject core anyways.

The SQL structure differs, but if you copy your 2.4 database and execute bundle exec rake db:migrate within the OpenProject 3 installation, it should be automatically updated.

You also need to migrate uploaded files (attachments to issues etc.) - I am not sure on how this is done and will wait with you for Markus’ instructions :)

— philipp

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Once again I thank you Philipp for your availability to help :)

I’m getting incomplete journals errors when migrating … what can I do?

I dumped 2.4 bd, imported it to newBD_development and ran db:migrate
after a short while the following popped:

==  LegacyIssueJournalData: migrating =========================================
rake aborted!
An error has occurred, all later migrations canceled:

It appears there are incomplete journals. Please make sure journals are consistent and that for every journal, there is an initial journal containing all attribute values at the time of creation. The offending journal ids are: [{"id"=>1507}, {"id"=>1508}, {"id"=>1509}, {"id"=>1526}, {"id"=>1527}, {"id"=>1570}, {"id"=>1571}, {"id"=>1584}, {"id"=>1588}, {"id"=>1590}, {"id"=>1605}, {"id"=>1606}, {"id"=>1607}, {"id"=>1617}, {"id"=>1621}, {"id"=>1624}, {"id"=>1627}, {"id"=>1660}, {"id"=>1661}, {"id"=>1662}, {"id"=>1665}, {"id"=>1666}, {"id"=>1667}, {"id"=>1668}, {"id"=>1669}, {"id"=>1687}, {"id"=>1694}, {"id"=>1716}]
/root/openproject/db/migrate/migration_utils/legacy_journal_migrator.rb:386:in `check_legacy_journal_completeness'
/root/openproject/db/migrate/migration_utils/legacy_journal_migrator.rb:348:in `preconditions_met?'
/root/openproject/db/migrate/migration_utils/legacy_journal_migrator.rb:66:in `run'
/root/openproject/db/migrate/20130920094524_legacy_issue_journal_data.rb:39:in `up'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:410:in `block (2 levels) in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:410:in `block in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract/connection_pool.rb:129:in `with_connection'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:389:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:528:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:720:in `block (2 levels) in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:777:in `call'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:777:in `ddl_transaction'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:719:in `block in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:700:in `each'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:700:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:570:in `up'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:551:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/railties/databases.rake:193:in `block (2 levels) in <top (required)>'

RE: PUT requests always take 30(ish) seconds !! - Added by Hagen Schink over 11 years ago

Hi Tiago,

just remove those journals from your database that are mentioned in the list and execute db:migrate again.

Kind regards,
Hagen

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

would that be journals.id or journals.journable_id ?

RE: PUT requests always take 30(ish) seconds !! - Added by Hagen Schink over 11 years ago

Hi Tiago,

please excuse, you need to delete those journals from the legacy journals table:

DELETE FROM legacy_journals
WHERE id IN ('1507', '1508', '1509', '1526', '1527', '1570', '1571', '1584', '1588') # and so on

Cheers,
Hagen

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Thanks Hagen, will try

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Hi,

seems that INSERT statements are not being escaped …

I will try and find this line and replace the ’

==  AddMissingCustomizableJournals: migrating =================================
-- Add missing customizable journals
rake aborted!
An error has occurred, all later migrations canceled:

Mysql2::Error: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 's e fizemos reboot ao servidor e situação mantém-se')' at line 2:             INSERT INTO customizable_journals (journal_id, custom_field_id, value)
            VALUES (711, 3, 'Simulamos as chamadas de vários números e para vários números e com as extensões configuradas em diferentes pc's e fizemos reboot ao servidor e situação mantém-se')
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:245:in `query'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:245:in `block in execute'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract_adapter.rb:280:in `block in log'
/var/lib/gems/2.0.0/gems/activesupport-3.2.16/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract_adapter.rb:275:in `log'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:245:in `execute'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/mysql2_adapter.rb:213:in `execute'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/mysql2_adapter.rb:236:in `exec_insert'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract/database_statements.rb:90:in `insert'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract/query_cache.rb:14:in `insert'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:466:in `block in method_missing'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:438:in `block in say_with_time'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:438:in `say_with_time'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:458:in `method_missing'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:50:in `block (2 levels) in repair_journals'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:49:in `each'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:49:in `block in repair_journals'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:46:in `each'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:46:in `repair_journals'
/root/openproject/db/migrate/migration_utils/customizable_utils.rb:26:in `add_missing_customizable_journals'
/root/openproject/db/migrate/20131018134590_add_missing_customizable_journals.rb:20:in `block in up'
/root/openproject/db/migrate/migration_utils/utils.rb:19:in `block (2 levels) in say_with_time_silently'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:446:in `suppress_messages'
/root/openproject/db/migrate/migration_utils/utils.rb:18:in `block in say_with_time_silently'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:438:in `block in say_with_time'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:438:in `say_with_time'
/root/openproject/db/migrate/migration_utils/utils.rb:17:in `say_with_time_silently'
/root/openproject/db/migrate/20131018134590_add_missing_customizable_journals.rb:19:in `up'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:410:in `block (2 levels) in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:410:in `block in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/connection_adapters/abstract/connection_pool.rb:129:in `with_connection'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:389:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:528:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:720:in `block (2 levels) in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:777:in `call'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:777:in `ddl_transaction'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:719:in `block in migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:700:in `each'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:700:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:570:in `up'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/migration.rb:551:in `migrate'
/var/lib/gems/2.0.0/gems/activerecord-3.2.16/lib/active_record/railties/databases.rake:193:in `block (2 levels) in <top (required)>'
Tasks: TOP => db:migrate
(See full trace by running task with --trace)

RE: PUT requests always take 30(ish) seconds !! - Added by Hagen Schink over 11 years ago

Hi Tiago,

alternatively, you may just add ActiveRecord::Base.connection.quote to db/migrate/migration_utils/customizable_utils.rb line 52 (right in front of m.value). This saves you from adapting each value by hand. And you may remove the single quotes ’ then too.

Cheers

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

Thank you for your feedback. In the meanwhile I did use a UPDATE set value=REPLACE()….

Now I made it work, seems all great…

I now am on a stage where I’m trying to make it work in a production environment (I don’t mean openproject env, but system wide)

after fiddling with ruby versions and all, I’m now at a stage where opening openproject web page shows:

Internal error

An error occurred on the page you were trying to access.
If you continue to experience problems please contact your OpenProject administrator for assistance.

If you are the OpenProject administrator, check your log files for details about the error.

Back

and production.log shows:

Started GET "/login?back_url=https%3A%2F%2Fproject.domain.pt%2F" for 85.245.38.95 at 2014-02-05 15:39:12 +0000
Processing by AccountController#login as HTML
  Parameters: {"back_url"=>"https://project.domain.pt/"}
  Rendered account/login.html.erb within layouts/base (5.0ms)
Completed 500 Internal Server Error in 17.4ms

ActionView::Template::Error (favicon.ico isn't precompiled):
    36: <meta name="current_menu_item" content="<%= current_menu_item %>" />
    37: <meta name="accessibility-mode" content="<%= current_user.impaired? %>" />
    38: <%= csrf_meta_tags %>
    39: <%= favicon_link_tag 'favicon.ico' %>
    40: <%= stylesheet_link_tag current_theme.stylesheet_manifest, :media => "all" %>
    41: <% if User.current.impaired? && accessibility_css_enabled? %>
    42:   <%= stylesheet_link_tag 'accessibility' %>
  lib/open_project/themes/view_helpers.rb:53:in `image_path'
  app/views/layouts/base.html.erb:39:in `_app_views_layouts_base_html_erb__4095478284791925714_73475480'

RE: PUT requests always take 30(ish) seconds !! - Added by Philipp Tessenow over 11 years ago

This is a rails 3 thing.

RAILS_ENV=production bundle exec rake assets:precompile

should solve this.

RE: PUT requests always take 30(ish) seconds !! - Added by Tiago Geada over 11 years ago

It worked!

I now have a working openproject 3.0 :)

I will be waiting for the attachments instructions and other comments…

We will move soon to 3.0 tho

RE: PUT requests always take 30(ish) seconds !! - Added by Markus Kahl over 11 years ago

Hey,

I wrote some instructions once for migrating one of our configurations from 1.5 to 3.0.
It’s pretty specific to those configurations but it might help you out: click

Didn’t have as much time today as I thought I would and still have to generalize those instructions a bit.
I’ll go over it tomorrow.
If you are using Project and Version documents let me know and I can give you a more detailed explanation on what you need to do to save those.
All other documents should be fine by using the openproject-documents plugin.

~ Markus

P.S. you don’t need to (and probably can’t) use the repositories mentioned in the instructions. Although there is a migration branch of openproject on github.
But I would try doing the migration with the plain openproject dev branch first.

RE: PUT requests always take 30(ish) seconds !! - Added by Joey Ferwerda over 11 years ago

Philipp Tessenow wrote:

This is a rails 3 thing.

RAILS_ENV=production bundle exec rake assets:precompile

should solve this.

I tried this option, and the result is a big speedup.
The only big problem is that all drop down menu’s stopped working, which is quite a big issue.

RE: PUT requests always take 30(ish) seconds !! - Added by Hagen Schink over 11 years ago

Hello Joey,

asset:precompile only works for the production environment. Thus, you need to start the rails server like this:

RAILS_ENV="production" bundle exec rails s

Does this work for you?

Kind regards,
Hagen

RE: PUT requests always take 30(ish) seconds !! - Added by Christian Ratz over 11 years ago

If you start your server with:

RAILS_ENV=production bundle exec rails server

You have to deliver the assetes through the rails application. To make this happen you have to change this:

File: config/environments/production.rb line 44

from:
  config.serve_static_assets = false
to:
  config.serve_static_assets = true

Best Ratzi

RE: PUT requests always take 30(ish) seconds !! - Added by Joey Ferwerda over 11 years ago

Aparantly i installed a development database instead of a production database for what reason, so that explains why i had issues with this.
Now when i run in Production mode, i get a error about some things not being found.
(in `query’: Mysql2::Error: Table ‘openproject.work_package_journals’ doesn’t exist: SHOW FULL FIELDS FROM `work_package_journals` etc…)

Is there a simple way to migrate the database to production?

EDIT: I already tried: ‘RAILS_ENV=production bundle exec rake db:migrate’ but that does not seems to copy anything, it just creates the tables in the database

EDIT2: NVM dirty fixed it just doing a dirty mysql copy of the development database to production. Thanks btw!

  • (1 - 23/23)
Loading...