Redmine

but sometimes, the issue Ammy reported would be filled by Tom, and the login would be changed too.

What is your configuration? How did you install and configure Redmine?

Hi, William Fu Roush,
Thanks.
This is my enviroment. If there's any question, please let me know.

Rails version
Ruby version    1.8.7 (i686-linux)
RubyGems version    1.3.7
Rack version    1.4
Rails version    3.2.6
JavaScript Runtime    Node.js (V8)
Active Record version    3.2.6
Action Pack version    3.2.6
Active Resource version    3.2.6
Action Mailer version    3.2.6
Active Support version    3.2.6
Middleware    

    Rack::Cache
    ActionDispatch::Static
    Rack::Lock
    #<ActiveSupport::Cache::Strategy::LocalCache::Middleware:0xb72a7530>
    Rack::Runtime
    Rack::MethodOverride
    ActionDispatch::RequestId
    Rails::Rack::Logger
    ActionDispatch::ShowExceptions
    ActionDispatch::DebugExceptions
    ActionDispatch::RemoteIp
    ActionDispatch::Callbacks
    ActiveRecord::ConnectionAdapters::ConnectionManagement
    ActiveRecord::QueryCache
    ActionDispatch::Cookies
    ActionDispatch::Session::CookieStore
    ActionDispatch::Flash
    ActionDispatch::ParamsParser
    ActionDispatch::Head
    Rack::ConditionalGet
    Rack::ETag
    ActionDispatch::BestStandardsSupport
    OpenIdAuthentication

Application root    /usr/local/redmine-2.0
Environment    production
Database adapter    mysql
Database schema version    20120627194945

and I used centOS 5.X.

I've installed many plugins. as follows:

Redmine 2.0.3.stable.10207 (MySQL)

Environment:
  Redmine version                          2.0.3.stable.10207
  Ruby version                             1.8.7 (i686-linux)
  Rails version                            3.2.6
  Environment                              production
  Database adapter                         MySQL
Redmine plugins:
  redmine_attachments_size                 0.0.4
  redmine_banner                           0.0.7
  redmine_ckeditor                         0.1.0
  redmine_close_button                     0.0.8
  redmine_code_review                      0.5.0
  redmine_didyoumean                       1.1.0
  redmine_extra_query_operators            0.1.1
  redmine_favourite_projects               0.5
  redmine_graphs                           0.1.0
  redmine_information                      1.0.1
  redmine_inline_attach_screenshot         0.4.2
  redmine_issue_extensions                 0.2.0.1
  redmine_issue_history_tabs               0.0.3
  redmine_issue_priorities_per_tracker     0.0.1
  redmine_issues_summary_graph             0.0.4
  redmine_knowledgebase                    2.1.1
  redmine_lightbox                         0.0.1
  redmine_list_duplicate_views             0.0.5
  redmine_local_avatars                    0.0.3-forked
  redmine_logs                             0.0.4
  redmine_monitoring_controlling           0.1.1
  redmine_my_roadmaps                      0.2.8
  redmine_plugin_views_revisions           0.0.1
  redmine_preview_attach_column            0.1.7
  redmine_private_wiki                     0.2.1
  redmine_projects_accordion               0.0.2
  redmine_reorder_links_arbitrary          0.0.7
  redmine_smart_issues_sort                0.3.1
  redmine_top_bar_links                    0.1
  redmine_vividtone_my_page_blocks         1.2 (20120610)
  redmine_wiki_lists                       0.0.0
  redmine_work_time                        0.2.4
  redmine_xls_export                       0.2.1
  spent_time_required                      0.0.1

I noticed you're running Redmine on port 3000, so a mongrel instance? How do you have that configured?

If you don't have some extremely odd proxy configuration that is somehow mixing/sharing cookies, I'm 99% sure it's going to be a plugin being as this is not identified in Redmine's core software.

How often does this happen?

by the way. I used thin as my server.

Hi, William Roush

Thanks for your help so much.

It's Strange. but I do think the mixing/sharing cookies may caused it. How could I find the mixing/sharing cookies which plugin used?

I'm comfused.

:（

and,　　when somebody used redmine with another user ,if they commit at the same time ,it would happen ... but it's not very accurate， and I still need building another enviroment to test it.

William Roush wrote:

If you don't have some extremely odd proxy configuration that is somehow mixing/sharing cookies, I'm 99% sure it's going to be a plugin being as this is not identified in Redmine's core software.

How often does this happen?

Steven Wong wrote:

by the way. I used thin as my server.

As I understand it, Thin runs on port 3000 like Mongrel did (and well... uses it's parser too), does everyone just access the application on port 3000?

If that's the case, what is the likelihood you can zip up your plugins/ directory? I want to dig into these plugins but getting certain versions is hit and miss (such as forks or older versions).

Also, maybe we don't need this: did this issue crop up after upgrading to Redmine 2.0? Did you validate that every last plugin is Redmine 2.0 compatible (lots of changes were made, a bad plugin could be causing this).

Steven Wong wrote:

It's Strange. but I do think the mixing/sharing cookies may caused it. How could I find the mixing/sharing cookies which plugin used?

The best way I can figure:

• Toughly review code of all plugins (what I'm attempting to do).
  Or:
• Disable plugins one-by-one until the issue goes away (helps if you can replicate it on a clone with some scripts/unit tests or something).

I'm comfused.

:（

and,　　when somebody used redmine with another user ,if they commit at the same time ,it would happen ... but it's not very accurate， and I still need building another enviroment to test it

Yeah, it sounds like a nasty race condition so it will not be fun to hunt down unless you can automate recreating the issue.

Hi, William Roush
OK， I will try to zip these plugins and upload it. thanks so much.

Hi, William Roush

I upload the plugin file as zip and you can download it.
http://yunpan.cn/lk/33c1kd3fvc

you can download it directly as follow url:
http://l5.yunpan.cn/link/downloadfile/surl/33c1kd3fvc

Thanks.

William Roush wrote:

Steven Wong wrote:

It's Strange. but I do think the mixing/sharing cookies may caused it. How could I find the mixing/sharing cookies which plugin used?

The best way I can figure:

• Toughly review code of all plugins (what I'm attempting to do).
  Or:
• Disable plugins one-by-one until the issue goes away (helps if you can replicate it on a clone with some scripts/unit tests or something).

I'm comfused.

:（

and,　　when somebody used redmine with another user ,if they commit at the same time ,it would happen ... but it's not very accurate， and I still need building another enviroment to test it

Yeah, it sounds like a nasty race condition so it will not be fun to hunt down unless you can automate recreating the issue.

hi,William Roush

I just open the debug mode and found something interesting.

Started GET "/projects/upnf/issues/new" for 192.168.3.115 at Mon Aug 20 16:20:13 +0800 2012
Processing by IssuesController#new as HTML
  Parameters: {"project_id"=>"upnf"}
  [1m[36mProject Load (0.5ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`identifier` = 'upnf' LIMIT 1[0m
  [1m[35mEnabledModule Load (0.3ms)[0m  SELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 32
  [1m[36mIssueStatus Load (0.3ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 0 LIMIT 1
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mIssuePriority Load (0.3ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 0 ORDER BY enumerations.position ASC LIMIT 1
  [1m[36mIssuePriority Load (0.3ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mProject Load (0.3ms)[0m  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 0 LIMIT 1
  [1m[36mProject Load (0.3ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 32 LIMIT 1[0m
  [1m[35mTracker Load (0.2ms)[0m  SELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` = 0 LIMIT 1
  [1m[36mTracker Load (0.4ms)[0m  [1mSELECT `trackers`.* FROM `trackers` INNER JOIN `projects_trackers` ON `trackers`.`id` = `projects_trackers`.`tracker_id` WHERE `projects_trackers`.`project_id` = 32 ORDER BY trackers.position LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mWorkflow Load (0.4ms)[0m  [1mSELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (5) AND tracker_id = 1 AND ((author = 0 AND assignee = 0) OR author = 1))[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (7, 1, 2)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mUser Load (0.8ms)[0m  SELECT `users`.* FROM `users` INNER JOIN `members` ON `users`.`id` = `members`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `members`.`project_id` = 32 AND (users.type='User' AND users.status=1)
  [1m[36m (0.3ms)[0m  [1mSELECT MAX(`settings`.`updated_on`) AS max_id FROM `settings` [0m
  [1m[35mUser Load (0.2ms)[0m  SELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` = ? AND (users.status = 1) LIMIT 1  [["id", 163]]
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mSQL (1.7ms)[0m  SELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12, `roles`.`id` AS t2_r0, `roles`.`name` AS t2_r1, `roles`.`position` AS t2_r2, `roles`.`assignable` AS t2_r3, `roles`.`builtin` AS t2_r4, `roles`.`permissions` AS t2_r5, `roles`.`issues_visibility` AS t2_r6 FROM `members` LEFT OUTER JOIN `projects` ON `projects`.`id` = `members`.`project_id` LEFT OUTER JOIN `member_roles` ON `member_roles`.`member_id` = `members`.`id` LEFT OUTER JOIN `roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `members`.`user_id` = 163 AND (projects.status=1) ORDER BY projects.name
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (5) AND tracker_id = 1 AND ((author = 0 AND assignee = 0) OR author = 1))[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (7, 1, 2)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 32[0m
  [1m[35mTracker Load (0.7ms)[0m  SELECT `trackers`.* FROM `trackers` INNER JOIN `projects_trackers` ON `trackers`.`id` = `projects_trackers`.`tracker_id` WHERE `projects_trackers`.`project_id` = 32 ORDER BY trackers.position
  [1m[36mIssuePriority Load (0.5ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` INNER JOIN `issue_priorities_trackers` ON `enumerations`.`id` = `issue_priorities_trackers`.`issue_priority_id` WHERE `enumerations`.`type` IN ('IssuePriority') AND `issue_priorities_trackers`.`tracker_id` = 1 ORDER BY enumerations.position ASC[0m
  [1m[35mSQL (134.7ms)[0m  SELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `users`.`id` AS t1_r0, `users`.`login` AS t1_r1, `users`.`hashed_password` AS t1_r2, `users`.`firstname` AS t1_r3, `users`.`lastname` AS t1_r4, `users`.`mail` AS t1_r5, `users`.`admin` AS t1_r6, `users`.`status` AS t1_r7, `users`.`last_login_on` AS t1_r8, `users`.`language` AS t1_r9, `users`.`auth_source_id` AS t1_r10, `users`.`created_on` AS t1_r11, `users`.`updated_on` AS t1_r12, `users`.`type` AS t1_r13, `users`.`identity_url` AS t1_r14, `users`.`mail_notification` AS t1_r15, `users`.`salt` AS t1_r16, `users`.`landing_page` AS t1_r17, `users`.`last_ip` AS t1_r18 FROM `members` LEFT OUTER JOIN `users` ON `users`.`id` = `members`.`user_id` WHERE `members`.`project_id` = 32 AND (users.type='Group' OR (users.type='User' AND users.status=1))
  [1m[36mRole Load (0.5ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 522[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 523
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 524[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 526
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 528[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 529
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 530[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 542
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 545[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 662
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 664[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 759
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 769[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 783
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 826[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 834
  [1m[36m (0.3ms)[0m  [1mSELECT COUNT(*) FROM `issue_categories` WHERE `issue_categories`.`project_id` = 32[0m
  [1m[35mProject Load (0.5ms)[0m  SELECT `projects`.* FROM `projects` WHERE `projects`.`parent_id` IS NULL AND (`projects`.`lft` <= 70 AND `projects`.`rgt` >= 71) ORDER BY `projects`.`lft` LIMIT 1
  [1m[36mVersion Load (125.2ms)[0m  [1mSELECT `versions`.* FROM `versions` WHERE `versions`.`id` IS NULL LIMIT 1[0m
  [1m[35mSQL (1.2ms)[0m  SELECT `versions`.`id` AS t0_r0, `versions`.`project_id` AS t0_r1, `versions`.`name` AS t0_r2, `versions`.`description` AS t0_r3, `versions`.`effective_date` AS t0_r4, `versions`.`created_on` AS t0_r5, `versions`.`updated_on` AS t0_r6, `versions`.`wiki_page_title` AS t0_r7, `versions`.`status` AS t0_r8, `versions`.`sharing` AS t0_r9, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `versions` LEFT OUTER JOIN `projects` ON `projects`.`id` = `versions`.`project_id` WHERE `versions`.`status` = 'open' AND (projects.id = 32 OR (projects.status = 1 AND ( versions.sharing = 'system' OR (projects.lft >= 69 AND projects.rgt <= 74 AND versions.sharing = 'tree') OR (projects.lft < 70 AND projects.rgt > 71 AND versions.sharing IN ('hierarchy', 'descendants')) OR (projects.lft > 70 AND projects.rgt < 71 AND versions.sharing = 'hierarchy'))))
  [1m[36mIssueCustomField Load (0.8ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND (is_for_all=1) ORDER BY position[0m
  [1m[35mIssueCustomField Load (0.7ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_projects` ON `custom_fields`.`id` = `custom_fields_projects`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_projects`.`project_id` = 32 ORDER BY custom_fields.position
  [1m[36mIssueCustomField Load (0.6ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_trackers` ON `custom_fields`.`id` = `custom_fields_trackers`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_trackers`.`tracker_id` = 1[0m
  [1m[35mSQL (1.6ms)[0m  SELECT `versions`.`id` AS t0_r0, `versions`.`project_id` AS t0_r1, `versions`.`name` AS t0_r2, `versions`.`description` AS t0_r3, `versions`.`effective_date` AS t0_r4, `versions`.`created_on` AS t0_r5, `versions`.`updated_on` AS t0_r6, `versions`.`wiki_page_title` AS t0_r7, `versions`.`status` AS t0_r8, `versions`.`sharing` AS t0_r9, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `versions` LEFT OUTER JOIN `projects` ON `projects`.`id` = `versions`.`project_id` WHERE (projects.id = 32 OR (projects.status = 1 AND ( versions.sharing = 'system' OR (projects.lft >= 69 AND projects.rgt <= 74 AND versions.sharing = 'tree') OR (projects.lft < 70 AND projects.rgt > 71 AND versions.sharing IN ('hierarchy', 'descendants')) OR (projects.lft > 70 AND projects.rgt < 71 AND versions.sharing = 'hierarchy'))))
  Rendered issues/_form_custom_fields.html.erb (28.2ms)
  Rendered issues/_attributes.html.erb (364.6ms)
DEPRECATION WARNING: Passing a template handler in the template name is deprecated. You can simply remove the handler name or pass render :handlers => [:erb] instead. (called from send at /usr/local/redmine-2.0/lib/redmine/hook.rb:111)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 0 LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 0 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
  Rendered plugins/redmine_didyoumean/app/views/issues/_didyoumean_injected.html.erb (7.1ms)
  [1m[36mEnabledModule Load (0.5ms)[0m  [1mSELECT `enabled_modules`.* FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 32[0m
  Rendered plugins/redmine_issue_extensions/app/views/issues/_issue_extensions_view_issues_form_details_bottom.erb (2.2ms)
  Rendered issues/_form.html.erb (399.6ms)
  [1m[35mToken Load (0.4ms)[0m  SELECT `tokens`.* FROM `tokens` WHERE `tokens`.`user_id` = 163 AND (action='feeds') LIMIT 1
  Rendered plugins/redmine_inline_attach_screenshot/app/views/attachments/_form.html.erb (7.3ms)
  Rendered issues/new.html.erb within layouts/base (413.8ms)
  [1m[36mUserPreference Load (0.4ms)[0m  [1mSELECT `user_preferences`.* FROM `user_preferences` WHERE `user_preferences`.`user_id` = 163 LIMIT 1[0m
  Rendered plugins/redmine_attachments_size/app/views/hooks/attachments_size/_view_layouts_base_html_head.erb (0.3ms)
  Rendered plugins/redmine_code_review/app/views/code_review/_html_header.html.erb (0.2ms)
  [1m[35mCustomField Load (0.5ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'Description tooltips' LIMIT 1
  Rendered plugins/redmine_private_wiki/app/views/hooks/_html_header.html.erb (0.1ms)
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` WHERE `roles`.`builtin` = 1 LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `roles`.* FROM `roles` WHERE `roles`.`builtin` = 1 LIMIT 1
  [1m[36mSQL (0.9ms)[0m  [1mSELECT `favourite_projects`.`id` AS t0_r0, `favourite_projects`.`user_id` AS t0_r1, `favourite_projects`.`project_id` AS t0_r2, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `favourite_projects` LEFT OUTER JOIN `projects` ON `projects`.`id` = `favourite_projects`.`project_id` WHERE (user_id = 163) ORDER BY projects.name[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `roles`.* FROM `roles` WHERE `roles`.`builtin` = 1 LIMIT 1
  [1m[36mProject Load (0.9ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE (`projects`.`lft` <= 70 AND `projects`.`rgt` >= 71) AND (`projects`.id != 32) AND (((projects.status=1) AND (projects.id IN (48,45,32,46,35,41,23,44,40,42,47,33,31) OR projects.is_public = 1))) ORDER BY `projects`.`lft`[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `projects`.* FROM `projects` WHERE `projects`.`parent_id` IS NULL AND (`projects`.`lft` <= 70 AND `projects`.`rgt` >= 71) ORDER BY `projects`.`lft` LIMIT 1
  [1m[36m (0.9ms)[0m  [1mSELECT COUNT(DISTINCT `versions`.`id`) FROM `versions` LEFT OUTER JOIN `projects` ON `projects`.`id` = `versions`.`project_id` WHERE (projects.id = 32 OR (projects.status = 1 AND ( versions.sharing = 'system' OR (projects.lft >= 69 AND projects.rgt <= 74 AND versions.sharing = 'tree') OR (projects.lft < 70 AND projects.rgt > 71 AND versions.sharing IN ('hierarchy', 'descendants')) OR (projects.lft > 70 AND projects.rgt < 71 AND versions.sharing = 'hierarchy'))))[0m
  [1m[35mWiki Load (0.3ms)[0m  SELECT `wikis`.* FROM `wikis` WHERE `wikis`.`project_id` = 32 LIMIT 1
  [1m[36m (0.3ms)[0m  [1mSELECT COUNT(*) FROM `boards` WHERE `boards`.`project_id` = 32[0m
  [1m[35mRepository Load (0.4ms)[0m  SELECT `repositories`.* FROM `repositories` WHERE `repositories`.`project_id` = 32 AND (is_default = 1) LIMIT 1
  [1m[36mCodeReviewProjectSetting Load (0.4ms)[0m  [1mSELECT `code_review_project_settings`.* FROM `code_review_project_settings` WHERE (project_id = 32) LIMIT 1[0m
  Rendered plugins/redmine_banner/app/views/banner/_project_body_bottom.html.erb (0.2ms)
  Rendered plugins/redmine_code_review/app/views/code_review/_body_bottom.html.erb (0.1ms)
  [1m[35mCACHE (0.0ms)[0m  SELECT `favourite_projects`.`id` AS t0_r0, `favourite_projects`.`user_id` AS t0_r1, `favourite_projects`.`project_id` AS t0_r2, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `favourite_projects` LEFT OUTER JOIN `projects` ON `projects`.`id` = `favourite_projects`.`project_id` WHERE (user_id = 163) ORDER BY projects.name
  Rendered plugins/redmine_favourite_projects/app/views/favourite_projects/_update_menu.erb (2.9ms)
  Rendered plugins/redmine_private_wiki/app/views/hooks/_body_bottom.html.erb (0.1ms)
Completed 200 OK in 513ms (Views: 202.0ms | ActiveRecord: 285.5ms)

Started POST "/projects/upnt/issues" for 192.168.3.164 at Mon Aug 20 16:20:16 +0800 2012
Processing by IssuesController#create as HTML
  Parameters: {"commit"=>"创建", "project_id"=>"upnt", "authenticity_token"=>"nrk8SiIPkEIQgLxK+F4aFAuBATtUuhJ6/NGQXN1WMHI=", "utf8"=>"?", "issue"=>{"start_date"=>"2012-08-28", "estimated_hours"=>"16", "custom_field_values"=>{"22"=>"", "35"=>""}, "priority_id"=>"5", "parent_issue_id"=>"4970", "is_private"=>"0", "fixed_version_id"=>"", "subject"=>"二阶段性能测试方案设计", "assigned_to_id"=>"190", "tracker_id"=>"11", "due_date"=>"2012-08-29", "description"=>"", "status_id"=>"2"}, "attachments"=>{"1"=>{"description"=>""}}}
  [1m[36mProject Load (0.5ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`identifier` = 'upnt' LIMIT 1[0m
  [1m[35mEnabledModule Load (133.6ms)[0m  SELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 46
  [1m[36mIssueStatus Load (0.5ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 0 LIMIT 1
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mIssuePriority Load (0.3ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 0 ORDER BY enumerations.position ASC LIMIT 1
  [1m[36mIssuePriority Load (0.4ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mProject Load (0.3ms)[0m  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 0 LIMIT 1
  [1m[36mProject Load (0.3ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 46 LIMIT 1[0m
  [1m[35mTracker Load (0.3ms)[0m  SELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` = 0 LIMIT 1
  [1m[36mTracker Load (0.2ms)[0m  [1mSELECT `trackers`.* FROM `trackers` INNER JOIN `projects_trackers` ON `trackers`.`id` = `projects_trackers`.`tracker_id` WHERE `projects_trackers`.`project_id` = 46 AND `trackers`.`id` = ? ORDER BY trackers.position LIMIT 1[0m  [["id", "11"]]
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mWorkflow Load (0.4ms)[0m  [1mSELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (5) AND tracker_id = 11 AND ((author = 0 AND assignee = 0) OR author = 1))[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (7, 8, 1, 2, 3)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 46[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mTracker Load (0.3ms)[0m  [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` = 11 LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (5) AND tracker_id = 11 AND ((author = 0 AND assignee = 0) OR author = 1))
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (7, 8, 1, 2, 3)[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` WHERE `roles`.`builtin` = 1 LIMIT 1
  [1m[36mGroup Load (0.6ms)[0m  [1mSELECT `users`.* FROM `users` INNER JOIN `groups_users` ON `users`.`id` = `groups_users`.`group_id` WHERE `users`.`type` IN ('Group') AND `groups_users`.`user_id` = 163[0m
  [1m[35mIssue Exists (0.8ms)[0m  SELECT 1 AS one FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` WHERE `issues`.`id` = 4970 AND (((projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) AND ((projects.id IN (48,45,32,46,35,41,23,44,40,42,47,33,31) AND ((issues.is_private = 0 OR issues.author_id = 163 OR issues.assigned_to_id IN (163,42))))))) LIMIT 1
  [1m[36mIssue Load (0.4ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 4970 LIMIT 1[0m
  [1m[35mIssueCustomField Load (0.6ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND (is_for_all=1) ORDER BY position
  [1m[36mIssueCustomField Load (0.7ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_projects` ON `custom_fields`.`id` = `custom_fields_projects`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_projects`.`project_id` = 46 ORDER BY custom_fields.position[0m
  [1m[35mIssueCustomField Load (0.7ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_trackers` ON `custom_fields`.`id` = `custom_fields_trackers`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_trackers`.`tracker_id` = 11
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (5) AND tracker_id = 11 AND ((author = 0 AND assignee = 0) OR author = 1))
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (7, 8, 1, 2, 3)[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mUser Load (124.9ms)[0m  [1mSELECT `users`.* FROM `users` INNER JOIN `members` ON `users`.`id` = `members`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `members`.`project_id` = 46 AND (users.type='User' AND users.status=1)[0m
  [1m[35m (0.4ms)[0m  SELECT MAX(`settings`.`updated_on`) AS max_id FROM `settings` 
  [1m[36mUser Load (0.2ms)[0m  [1mSELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` = ? AND (users.status = 1) LIMIT 1[0m  [["id", 39]]
  [1m[35mSQL (0.1ms)[0m  BEGIN
  [1m[36mIssuePriority Load (0.3ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 5 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 2 LIMIT 1
  [1m[36mIssue Load (0.4ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`root_id` IS NULL AND (`issues`.`lft` <= NULL AND `issues`.`rgt` >= NULL) AND (`issues`.id != NULL) ORDER BY `issues`.`lft`[0m
  [1m[35mTracker Exists (0.3ms)[0m  SELECT 1 AS one FROM `trackers` INNER JOIN `projects_trackers` ON `trackers`.`id` = `projects_trackers`.`tracker_id` WHERE `projects_trackers`.`project_id` = 46 AND `trackers`.`id` = 11 LIMIT 1
  [1m[36mIssue Load (0.5ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`root_id` IS NULL ORDER BY `rgt` desc LIMIT 1 FOR UPDATE[0m
  [1m[35mPrincipal Load (0.4ms)[0m  SELECT `users`.* FROM `users` WHERE `users`.`id` = 190 LIMIT 1
  [1m[36mSQL (2.4ms)[0m  [1mINSERT INTO `issues` (`assigned_to_id`, `author_id`, `category_id`, `created_on`, `description`, `done_ratio`, `due_date`, `estimated_hours`, `fixed_version_id`, `is_private`, `lft`, `lock_version`, `parent_id`, `priority_id`, `project_id`, `rgt`, `root_id`, `start_date`, `status_id`, `subject`, `tracker_id`, `updated_on`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)[0m  [["assigned_to_id", 190], ["author_id", 163], ["category_id", nil], ["created_on", Mon, 20 Aug 2012 08:20:16 UTC +00:00], ["description", ""], ["done_ratio", 30], ["due_date", Wed, 29 Aug 2012], ["estimated_hours", 16.0], ["fixed_version_id", nil], ["is_private", false], ["lft", 1], ["lock_version", 0], ["parent_id", nil], ["priority_id", 5], ["project_id", 46], ["rgt", 2], ["root_id", nil], ["start_date", Tue, 28 Aug 2012], ["status_id", 2], ["subject", "二阶段性能测试方案设计"], ["tracker_id", 11], ["updated_on", Mon, 20 Aug 2012 08:20:16 UTC +00:00]]
  [1m[35mSQL (0.2ms)[0m  INSERT INTO `custom_values` (`custom_field_id`, `customized_id`, `customized_type`, `value`) VALUES (?, ?, ?, ?)  [["custom_field_id", 22], ["customized_id", 4976], ["customized_type", "Issue"], ["value", ""]]
  [1m[36mSQL (0.2ms)[0m  [1mINSERT INTO `custom_values` (`custom_field_id`, `customized_id`, `customized_type`, `value`) VALUES (?, ?, ?, ?)[0m  [["custom_field_id", 35], ["customized_id", 4976], ["customized_type", "Issue"], ["value", ""]]
  [1m[35mSQL (1.6ms)[0m  SELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `users`.`id` AS t1_r0, `users`.`login` AS t1_r1, `users`.`hashed_password` AS t1_r2, `users`.`firstname` AS t1_r3, `users`.`lastname` AS t1_r4, `users`.`mail` AS t1_r5, `users`.`admin` AS t1_r6, `users`.`status` AS t1_r7, `users`.`last_login_on` AS t1_r8, `users`.`language` AS t1_r9, `users`.`auth_source_id` AS t1_r10, `users`.`created_on` AS t1_r11, `users`.`updated_on` AS t1_r12, `users`.`type` AS t1_r13, `users`.`identity_url` AS t1_r14, `users`.`mail_notification` AS t1_r15, `users`.`salt` AS t1_r16, `users`.`landing_page` AS t1_r17, `users`.`last_ip` AS t1_r18, `roles`.`id` AS t2_r0, `roles`.`name` AS t2_r1, `roles`.`position` AS t2_r2, `roles`.`assignable` AS t2_r3, `roles`.`builtin` AS t2_r4, `roles`.`permissions` AS t2_r5, `roles`.`issues_visibility` AS t2_r6 FROM `members` LEFT OUTER JOIN `users` ON `users`.`id` = `members`.`user_id` AND `users`.`type` IN ('User', 'AnonymousUser') LEFT OUTER JOIN `member_roles` ON `member_roles`.`member_id` = `members`.`id` LEFT OUTER JOIN `roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `members`.`project_id` = 46 AND (users.type='User' AND users.status=1)
  [1m[36mSQL (1.7ms)[0m  [1mSELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12, `roles`.`id` AS t2_r0, `roles`.`name` AS t2_r1, `roles`.`position` AS t2_r2, `roles`.`assignable` AS t2_r3, `roles`.`builtin` AS t2_r4, `roles`.`permissions` AS t2_r5, `roles`.`issues_visibility` AS t2_r6 FROM `members` LEFT OUTER JOIN `projects` ON `projects`.`id` = `members`.`project_id` LEFT OUTER JOIN `member_roles` ON `member_roles`.`member_id` = `members`.`id` LEFT OUTER JOIN `roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `members`.`user_id` = 190 AND (projects.status=1) ORDER BY projects.name[0m
  [1m[35mSQL (1.1ms)[0m  SELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12, `roles`.`id` AS t2_r0, `roles`.`name` AS t2_r1, `roles`.`position` AS t2_r2, `roles`.`assignable` AS t2_r3, `roles`.`builtin` AS t2_r4, `roles`.`permissions` AS t2_r5, `roles`.`issues_visibility` AS t2_r6 FROM `members` LEFT OUTER JOIN `projects` ON `projects`.`id` = `members`.`project_id` LEFT OUTER JOIN `member_roles` ON `member_roles`.`member_id` = `members`.`id` LEFT OUTER JOIN `roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `members`.`user_id` = 130 AND (projects.status=1) ORDER BY projects.name
  [1m[36mUser Load (0.6ms)[0m  [1mSELECT `users`.* FROM `users` INNER JOIN `watchers` ON `users`.`id` = `watchers`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `watchers`.`watchable_id` = 4976 AND `watchers`.`watchable_type` = 'Issue' AND (users.status = 1)[0m
  Rendered mailer/_issue.text.erb (1.0ms)
  Rendered mailer/issue_add.text.erb within layouts/mailer (1.8ms)
  Rendered mailer/_issue.html.erb (0.8ms)
  Rendered mailer/issue_add.html.erb within layouts/mailer (1.3ms)
  [1m[35mIssueRelation Load (0.5ms)[0m  SELECT `issue_relations`.* FROM `issue_relations` WHERE `issue_relations`.`issue_from_id` = 4976
  [1m[36mIssue Load (0.5ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`root_id` = 4970 ORDER BY `rgt` desc LIMIT 1 FOR UPDATE[0m
  [1m[35mSQL (0.3ms)[0m  UPDATE `issues` SET root_id = 4970, lft = 5, rgt = 6 WHERE (id = 4976)
  [1m[36mIssue Load (0.2ms)[0m  [1mSELECT `lft`, `rgt`, `parent_id` FROM `issues` WHERE `issues`.`id` = ? LIMIT 1 FOR UPDATE[0m  [["id", 4970]]
  [1m[35mIssue Load (0.1ms)[0m  SELECT `lft`, `rgt`, `parent_id` FROM `issues` WHERE `issues`.`id` = ? LIMIT 1 FOR UPDATE  [["id", 4976]]
  [1m[36mSQL (0.7ms)[0m  [1mUPDATE `issues` SET `lft` = CASE WHEN `lft` BETWEEN 4 AND 4 THEN `lft` + 6 - 4 WHEN `lft` BETWEEN 5 AND 6 THEN `lft` + 4 - 5 ELSE `lft` END, `rgt` = CASE WHEN `rgt` BETWEEN 4 AND 4 THEN `rgt` + 6 - 4 WHEN `rgt` BETWEEN 5 AND 6 THEN `rgt` + 4 - 5 ELSE `rgt` END, `parent_id` = CASE WHEN id = 4976 THEN 4970 ELSE `parent_id` END WHERE `issues`.`root_id` = 4970 ORDER BY `issues`.`lft`[0m
  [1m[35mIssue Load (0.2ms)[0m  SELECT `lft`, `rgt`, `parent_id` FROM `issues` WHERE `issues`.`id` = ? LIMIT 1 FOR UPDATE  [["id", 4970]]
  [1m[36mIssue Load (0.2ms)[0m  [1mSELECT `lft`, `rgt`, `parent_id` FROM `issues` WHERE `issues`.`id` = ? LIMIT 1 FOR UPDATE[0m  [["id", 4976]]
  [1m[35mIssue Load (132.8ms)[0m  SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = ? LIMIT 1  [["id", 4976]]
  [1m[36mIssue Load (0.6ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 4970 LIMIT 1[0m
  [1m[35m (3.5ms)[0m  SELECT MAX(enumerations.position) AS max_id FROM `issues` INNER JOIN `enumerations` ON `enumerations`.`id` = `issues`.`priority_id` AND `enumerations`.`type` IN ('IssuePriority') WHERE `issues`.`parent_id` = 4970
  [1m[36mIssuePriority Load (0.4ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`position` = 2 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35m (2.8ms)[0m  SELECT MIN(`issues`.`start_date`) AS min_id FROM `issues` WHERE `issues`.`parent_id` = 4970
  [1m[36m (2.7ms)[0m  [1mSELECT MAX(`issues`.`due_date`) AS max_id FROM `issues` WHERE `issues`.`parent_id` = 4970[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 2 LIMIT 1
  [1m[36m (0.4ms)[0m  [1mSELECT SUM(`issues`.`estimated_hours`) AS sum_id FROM `issues` WHERE `issues`.`root_id` = 4970 AND (`issues`.`lft` >= 1 AND `issues`.`rgt` <= 6) AND (`issues`.id != 4970) AND (`issues`.`rgt` - `issues`.`lft` = 1)[0m
  [1m[35m (0.3ms)[0m  UPDATE `issues` SET `updated_on` = '2012-08-20 16:20:17', `estimated_hours` = 40.0, `lock_version` = 3, `due_date` = '2012-08-29' WHERE (`issues`.`id` = 4970 AND `issues`.`lock_version` = 2)
  [1m[36mProject Load (0.4ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 46 LIMIT 1[0m
  [1m[35mTracker Load (0.3ms)[0m  SELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` = 11 LIMIT 1
  [1m[36mIssueCustomField Load (0.6ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND (is_for_all=1) ORDER BY position[0m
  [1m[35mIssueCustomField Load (0.7ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_projects` ON `custom_fields`.`id` = `custom_fields_projects`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_projects`.`project_id` = 46 ORDER BY custom_fields.position
  [1m[36mIssueCustomField Load (0.5ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_trackers` ON `custom_fields`.`id` = `custom_fields_trackers`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_trackers`.`tracker_id` = 11[0m
  [1m[35mSQL (0.9ms)[0m  SELECT `custom_values`.`id` AS t0_r0, `custom_values`.`customized_type` AS t0_r1, `custom_values`.`customized_id` AS t0_r2, `custom_values`.`custom_field_id` AS t0_r3, `custom_values`.`value` AS t0_r4, `custom_fields`.`id` AS t1_r0, `custom_fields`.`type` AS t1_r1, `custom_fields`.`name` AS t1_r2, `custom_fields`.`field_format` AS t1_r3, `custom_fields`.`possible_values` AS t1_r4, `custom_fields`.`regexp` AS t1_r5, `custom_fields`.`min_length` AS t1_r6, `custom_fields`.`max_length` AS t1_r7, `custom_fields`.`is_required` AS t1_r8, `custom_fields`.`is_for_all` AS t1_r9, `custom_fields`.`is_filter` AS t1_r10, `custom_fields`.`position` AS t1_r11, `custom_fields`.`searchable` AS t1_r12, `custom_fields`.`default_value` AS t1_r13, `custom_fields`.`editable` AS t1_r14, `custom_fields`.`visible` AS t1_r15, `custom_fields`.`multiple` AS t1_r16 FROM `custom_values` LEFT OUTER JOIN `custom_fields` ON `custom_fields`.`id` = `custom_values`.`custom_field_id` WHERE `custom_values`.`customized_id` = 4970 AND `custom_values`.`customized_type` = 'Issue' ORDER BY custom_fields.position
  [1m[36mIssueRelation Load (0.4ms)[0m  [1mSELECT `issue_relations`.* FROM `issue_relations` WHERE `issue_relations`.`issue_from_id` = 4970[0m
  [1m[35m (87.4ms)[0m  COMMIT
  [1m[36mProject Load (0.3ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`id` = ? LIMIT 1[0m  [["id", 46]]
  [1m[35mEnabledModule Load (0.4ms)[0m  SELECT `enabled_modules`.* FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 46
Redirected to http://192.168.2.135:3000/issues/4976
Completed 302 Found in 980ms (ActiveRecord: 516.0ms)

Started GET "/issues/4976" for 192.168.3.164 at Mon Aug 20 16:20:17 +0800 2012
Processing by IssuesController#show as HTML
  Parameters: {"id"=>"4976"}
  [1m[36mIssue Load (0.3ms)[0m  [1mSELECT `issues`.* FROM `issues` WHERE `issues`.`id` = ? LIMIT 1[0m  [["id", "4976"]]
  [1m[35mProject Load (0.4ms)[0m  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` IN (46)
  [1m[36mTracker Load (125.1ms)[0m  [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (11)[0m
  [1m[35mIssueStatus Load (0.4ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (2)
  [1m[36mUser Load (0.4ms)[0m  [1mSELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` IN (163)[0m
  [1m[35mIssuePriority Load (0.3ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` IN (5) ORDER BY enumerations.position ASC
  [1m[36mEnabledModule Load (0.3ms)[0m  [1mSELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 46[0m
  [1m[35m (0.3ms)[0m  SELECT MAX(`settings`.`updated_on`) AS max_id FROM `settings` 
  [1m[36mUser Load (0.3ms)[0m  [1mSELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` = ? AND (users.status = 1) LIMIT 1[0m  [["id", 39]]
  [1m[35mJournal Load (0.5ms)[0m  SELECT `journals`.* FROM `journals` WHERE `journals`.`journalized_id` = 4976 AND `journals`.`journalized_type` = 'Issue' ORDER BY journals.created_on ASC
  [1m[36mUserPreference Load (0.3ms)[0m  [1mSELECT `user_preferences`.* FROM `user_preferences` WHERE `user_preferences`.`user_id` = 39 LIMIT 1[0m
  [1m[35mSQL (1.2ms)[0m  SELECT `changesets`.`id` AS t0_r0, `changesets`.`repository_id` AS t0_r1, `changesets`.`revision` AS t0_r2, `changesets`.`committer` AS t0_r3, `changesets`.`committed_on` AS t0_r4, `changesets`.`comments` AS t0_r5, `changesets`.`commit_date` AS t0_r6, `changesets`.`scmid` AS t0_r7, `changesets`.`user_id` AS t0_r8, `repositories`.`id` AS t1_r0, `repositories`.`project_id` AS t1_r1, `repositories`.`url` AS t1_r2, `repositories`.`login` AS t1_r3, `repositories`.`password` AS t1_r4, `repositories`.`root_url` AS t1_r5, `repositories`.`type` AS t1_r6, `repositories`.`path_encoding` AS t1_r7, `repositories`.`log_encoding` AS t1_r8, `repositories`.`extra_info` AS t1_r9, `repositories`.`identifier` AS t1_r10, `repositories`.`is_default` AS t1_r11, `projects`.`id` AS t2_r0, `projects`.`name` AS t2_r1, `projects`.`description` AS t2_r2, `projects`.`homepage` AS t2_r3, `projects`.`is_public` AS t2_r4, `projects`.`parent_id` AS t2_r5, `projects`.`created_on` AS t2_r6, `projects`.`updated_on` AS t2_r7, `projects`.`identifier` AS t2_r8, `projects`.`status` AS t2_r9, `projects`.`lft` AS t2_r10, `projects`.`rgt` AS t2_r11, `projects`.`landing_page` AS t2_r12 FROM `changesets` LEFT OUTER JOIN `repositories` ON `repositories`.`id` = `changesets`.`repository_id` LEFT OUTER JOIN `projects` ON `projects`.`id` = `repositories`.`project_id` INNER JOIN `changesets_issues` ON `changesets`.`id` = `changesets_issues`.`changeset_id` WHERE `changesets_issues`.`issue_id` = 4976 AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='repository')) ORDER BY changesets.committed_on ASC, changesets.id ASC
  [1m[36mIssueRelation Load (0.3ms)[0m  [1mSELECT `issue_relations`.* FROM `issue_relations` WHERE `issue_relations`.`issue_from_id` = 4976[0m
  [1m[35mIssueRelation Load (0.3ms)[0m  SELECT `issue_relations`.* FROM `issue_relations` WHERE `issue_relations`.`issue_to_id` = 4976
  [1m[36mIssueStatus Load (0.3ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 2 LIMIT 1[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` 
  [1m[36mWorkflow Load (1.0ms)[0m  [1mSELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 2 AND (role_id IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23) AND tracker_id = 11 AND ((author = 0 AND assignee = 0)))[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (6, 3, 2, 7, 8, 5, 1)
  [1m[36mTimeEntryActivity Load (0.4ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('TimeEntryActivity') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35m (0.5ms)[0m  SELECT `users`.id FROM `users` INNER JOIN `watchers` ON `users`.`id` = `watchers`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `watchers`.`watchable_id` = 4976 AND `watchers`.`watchable_type` = 'Issue'
DEPRECATION WARNING: :confirm option is deprecated and will be removed from Rails 4.0. Use ':data => { :confirm => 'Text' }' instead. (called from _app_views_issues__action_menu_html_erb__77236503__620129278 at /usr/local/redmine-2.0/app/views/issues/_action_menu.html.erb:6)
  Rendered issues/_action_menu.html.erb (6.7ms)
  [1m[36mAttachment Load (0.5ms)[0m  [1mSELECT `attachments`.* FROM `attachments` WHERE `attachments`.`container_id` = 163 AND `attachments`.`container_type` = 'Principal' AND `attachments`.`description` = 'avatar' ORDER BY attachments.created_on LIMIT 1[0m
  [1m[35mSQL (122.4ms)[0m  SELECT `issues`.`id` AS t0_r0, `issues`.`tracker_id` AS t0_r1, `issues`.`project_id` AS t0_r2, `issues`.`subject` AS t0_r3, `issues`.`description` AS t0_r4, `issues`.`due_date` AS t0_r5, `issues`.`category_id` AS t0_r6, `issues`.`status_id` AS t0_r7, `issues`.`assigned_to_id` AS t0_r8, `issues`.`priority_id` AS t0_r9, `issues`.`fixed_version_id` AS t0_r10, `issues`.`author_id` AS t0_r11, `issues`.`lock_version` AS t0_r12, `issues`.`created_on` AS t0_r13, `issues`.`updated_on` AS t0_r14, `issues`.`start_date` AS t0_r15, `issues`.`done_ratio` AS t0_r16, `issues`.`estimated_hours` AS t0_r17, `issues`.`parent_id` AS t0_r18, `issues`.`root_id` AS t0_r19, `issues`.`lft` AS t0_r20, `issues`.`rgt` AS t0_r21, `issues`.`is_private` AS t0_r22, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` WHERE `issues`.`root_id` = 4970 AND (`issues`.`lft` <= 4 AND `issues`.`rgt` >= 5) AND (`issues`.id != 4976) AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) ORDER BY `issues`.`lft`
  [1m[36mTracker Load (0.4ms)[0m  [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` = 11 LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 2 LIMIT 1
  [1m[36mIssuePriority Load (0.4ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 5 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mPrincipal Load (0.5ms)[0m  SELECT `users`.* FROM `users` WHERE `users`.`id` = 190 LIMIT 1
  [1m[36mAttachment Load (0.5ms)[0m  [1mSELECT `attachments`.* FROM `attachments` WHERE `attachments`.`container_id` = 190 AND `attachments`.`container_type` = 'Principal' AND `attachments`.`description` = 'avatar' ORDER BY attachments.created_on LIMIT 1[0m
  [1m[35m (0.4ms)[0m  SELECT SUM(time_entries.hours) AS sum_id FROM `issues` LEFT JOIN time_entries ON time_entries.issue_id = issues.id WHERE `issues`.`root_id` = 4970 AND (`issues`.`lft` >= 4 AND `issues`.`rgt` <= 5)
  [1m[36mIssueCustomField Load (0.7ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND (is_for_all=1) ORDER BY position[0m
  [1m[35mIssueCustomField Load (0.7ms)[0m  SELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_projects` ON `custom_fields`.`id` = `custom_fields_projects`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_projects`.`project_id` = 46 ORDER BY custom_fields.position
  [1m[36mIssueCustomField Load (0.6ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` INNER JOIN `custom_fields_trackers` ON `custom_fields`.`id` = `custom_fields_trackers`.`custom_field_id` WHERE `custom_fields`.`type` IN ('IssueCustomField') AND `custom_fields_trackers`.`tracker_id` = 11[0m
  [1m[35mSQL (0.9ms)[0m  SELECT `custom_values`.`id` AS t0_r0, `custom_values`.`customized_type` AS t0_r1, `custom_values`.`customized_id` AS t0_r2, `custom_values`.`custom_field_id` AS t0_r3, `custom_values`.`value` AS t0_r4, `custom_fields`.`id` AS t1_r0, `custom_fields`.`type` AS t1_r1, `custom_fields`.`name` AS t1_r2, `custom_fields`.`field_format` AS t1_r3, `custom_fields`.`possible_values` AS t1_r4, `custom_fields`.`regexp` AS t1_r5, `custom_fields`.`min_length` AS t1_r6, `custom_fields`.`max_length` AS t1_r7, `custom_fields`.`is_required` AS t1_r8, `custom_fields`.`is_for_all` AS t1_r9, `custom_fields`.`is_filter` AS t1_r10, `custom_fields`.`position` AS t1_r11, `custom_fields`.`searchable` AS t1_r12, `custom_fields`.`default_value` AS t1_r13, `custom_fields`.`editable` AS t1_r14, `custom_fields`.`visible` AS t1_r15, `custom_fields`.`multiple` AS t1_r16 FROM `custom_values` LEFT OUTER JOIN `custom_fields` ON `custom_fields`.`id` = `custom_values`.`custom_field_id` WHERE `custom_values`.`customized_id` = 4976 AND `custom_values`.`customized_type` = 'Issue' ORDER BY custom_fields.position
  Rendered plugins/redmine_close_button/app/views/issues/_close_button.html.erb (1.0ms)
  [1m[36m (0.4ms)[0m  [1mSELECT COUNT(*) FROM `attachments` WHERE `attachments`.`container_id` = 4976 AND `attachments`.`container_type` = 'Issue'[0m
  [1m[35mEnabledModule Load (0.4ms)[0m  SELECT `enabled_modules`.* FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 46
  Rendered plugins/redmine_issue_extensions/app/views/issues/_issue_extensions_form.erb (1.8ms)
  Rendered issue_relations/_form.html.erb (1.9ms)
  Rendered issues/_relations.html.erb (3.9ms)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `users`.id FROM `users` INNER JOIN `watchers` ON `users`.`id` = `watchers`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `watchers`.`watchable_id` = 4976 AND `watchers`.`watchable_type` = 'Issue'[0m
DEPRECATION WARNING: :confirm option is deprecated and will be removed from Rails 4.0. Use ':data => { :confirm => 'Text' }' instead. (called from _app_views_issues__action_menu_html_erb__77236503__620129278 at /usr/local/redmine-2.0/app/views/issues/_action_menu.html.erb:6)
  Rendered issues/_action_menu.html.erb (4.9ms)
  [1m[35mProject Load (4.7ms)[0m  SELECT `projects`.* FROM `projects` WHERE (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking'))
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 2 LIMIT 1[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `roles`.* FROM `roles` 
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 2 AND (role_id IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23) AND tracker_id = 11 AND ((author = 0 AND assignee = 0)))[0m
  [1m[35mCACHE (0.0ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (6, 3, 2, 7, 8, 5, 1)
  [1m[36mCACHE (0.0ms)[0m  [1mSELECT `projects`.* FROM `projects` WHERE (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking'))[0m
  [1m[35mTracker Load (0.6ms)[0m  SELECT `trackers`.* FROM `trackers` INNER JOIN `projects_trackers` ON `trackers`.`id` = `projects_trackers`.`tracker_id` WHERE `projects_trackers`.`project_id` = 46 ORDER BY trackers.position
  [1m[36mIssuePriority Load (0.5ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` INNER JOIN `issue_priorities_trackers` ON `enumerations`.`id` = `issue_priorities_trackers`.`issue_priority_id` WHERE `enumerations`.`type` IN ('IssuePriority') AND `issue_priorities_trackers`.`tracker_id` = 11 ORDER BY enumerations.position ASC[0m
  [1m[35mSQL (1.3ms)[0m  SELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `users`.`id` AS t1_r0, `users`.`login` AS t1_r1, `users`.`hashed_password` AS t1_r2, `users`.`firstname` AS t1_r3, `users`.`lastname` AS t1_r4, `users`.`mail` AS t1_r5, `users`.`admin` AS t1_r6, `users`.`status` AS t1_r7, `users`.`last_login_on` AS t1_r8, `users`.`language` AS t1_r9, `users`.`auth_source_id` AS t1_r10, `users`.`created_on` AS t1_r11, `users`.`updated_on` AS t1_r12, `users`.`type` AS t1_r13, `users`.`identity_url` AS t1_r14, `users`.`mail_notification` AS t1_r15, `users`.`salt` AS t1_r16, `users`.`landing_page` AS t1_r17, `users`.`last_ip` AS t1_r18 FROM `members` LEFT OUTER JOIN `users` ON `users`.`id` = `members`.`user_id` WHERE `members`.`project_id` = 46 AND (users.type='Group' OR (users.type='User' AND users.status=1))
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 976[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 977
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 978[0m
  [1m[35mRole Load (127.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 979
  [1m[36mRole Load (0.5ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 980[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 984
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 985[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 986
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 987[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 989
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 997[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 999
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1000[0m
  [1m[35mRole Load (0.3ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1001
  [1m[36mRole Load (0.3ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1002[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1004
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1005[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1006
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1007[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1008
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1050[0m
  [1m[35mRole Load (0.4ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1057
  [1m[36mRole Load (269.2ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1058[0m
  [1m[35mRole Load (0.5ms)[0m  SELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1059
  [1m[36mRole Load (0.4ms)[0m  [1mSELECT `roles`.* FROM `roles` INNER JOIN `member_roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `member_roles`.`member_id` = 1098[0m
  [1m[35m (0.3ms)[0m  SELECT COUNT(*) FROM `issue_categories` WHERE `issue_categories`.`project_id` = 46
  [1m[36mVersion Load (0.3ms)[0m  [1mSELECT `versions`.* FROM `versions` WHERE `versions`.`id` IS NULL LIMIT 1[0m
  [1m[35mSQL (0.8ms)[0m  SELECT `versions`.`id` AS t0_r0, `versions`.`project_id` AS t0_r1, `versions`.`name` AS t0_r2, `versions`.`description` AS t0_r3, `versions`.`effective_date` AS t0_r4, `versions`.`created_on` AS t0_r5, `versions`.`updated_on` AS t0_r6, `versions`.`wiki_page_title` AS t0_r7, `versions`.`status` AS t0_r8, `versions`.`sharing` AS t0_r9, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `versions` LEFT OUTER JOIN `projects` ON `projects`.`id` = `versions`.`project_id` WHERE `versions`.`status` = 'open' AND (projects.id = 46 OR (projects.status = 1 AND ( versions.sharing = 'system' OR (projects.lft >= 15 AND projects.rgt <= 16 AND versions.sharing = 'tree') OR (projects.lft < 15 AND projects.rgt > 16 AND versions.sharing IN ('hierarchy', 'descendants')) OR (projects.lft > 15 AND projects.rgt < 16 AND versions.sharing = 'hierarchy'))))
  Rendered issues/_form_custom_fields.html.erb (1.5ms)
  Rendered issues/_attributes.html.erb (508.3ms)
DEPRECATION WARNING: Passing a template handler in the template name is deprecated. You can simply remove the handler name or pass render :handlers => [:erb] instead. (called from send at /usr/local/redmine-2.0/lib/redmine/hook.rb:111)
  [1m[36mIssueStatus Load (0.4ms)[0m  [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 0 LIMIT 1[0m
  [1m[35mIssueStatus Load (0.3ms)[0m  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE (is_default=1) LIMIT 1
  [1m[36mIssuePriority Load (0.3ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` = 0 ORDER BY enumerations.position ASC LIMIT 1[0m
  [1m[35mIssuePriority Load (0.7ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
  Rendered plugins/redmine_didyoumean/app/views/issues/_didyoumean_injected.html.erb (9.2ms)
  Rendered plugins/redmine_issue_extensions/app/views/issues/_issue_extensions_view_issues_form_details_bottom.erb (0.2ms)
  Rendered issues/_form.html.erb (547.9ms)
  [1m[36mTimeEntryActivity Load (0.4ms)[0m  [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('TimeEntryActivity') AND `enumerations`.`project_id` = 46 ORDER BY enumerations.position ASC[0m
  [1m[35mTimeEntryActivity Load (0.5ms)[0m  SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('TimeEntryActivity') AND `enumerations`.`project_id` IS NULL AND `enumerations`.`active` = 1 ORDER BY enumerations.position ASC
  [1m[36mCustomField Load (0.4ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE (type = 'TimeEntryCustomField') ORDER BY position[0m
  [1m[35mToken Load (0.4ms)[0m  SELECT `tokens`.* FROM `tokens` WHERE `tokens`.`user_id` = 39 AND (action='feeds') LIMIT 1
  Rendered plugins/redmine_inline_attach_screenshot/app/views/attachments/_form.html.erb (7.5ms)
  [1m[36mJournal Load (0.4ms)[0m  [1mSELECT `journals`.* FROM `journals` WHERE `journals`.`journalized_id` = 4976 AND `journals`.`journalized_type` = 'Issue' ORDER BY journals.id DESC LIMIT 1[0m
  Rendered issues/_edit.html.erb (568.8ms)
  [1m[35mSQL (0.9ms)[0m  SELECT `queries`.`id` AS t0_r0, `queries`.`project_id` AS t0_r1, `queries`.`name` AS t0_r2, `queries`.`filters` AS t0_r3, `queries`.`user_id` AS t0_r4, `queries`.`is_public` AS t0_r5, `queries`.`column_names` AS t0_r6, `queries`.`sort_criteria` AS t0_r7, `queries`.`group_by` AS t0_r8, `queries`.`show_desc` AS t0_r9, `queries`.`category` AS t0_r10, `queries`.`sort_by_parent_first` AS t0_r11, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `queries` LEFT OUTER JOIN `projects` ON `projects`.`id` = `queries`.`project_id` WHERE ((queries.project_id IS NULL OR (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking'))) AND (queries.is_public = 1 OR queries.user_id = 39)) AND (project_id IS NULL OR project_id = 46) ORDER BY queries.name ASC
  Rendered issues/_sidebar.html.erb (27.2ms)
  [1m[36m (1.1ms)[0m  [1mSELECT COUNT(*) FROM `users` INNER JOIN `watchers` ON `users`.`id` = `watchers`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `watchers`.`watchable_id` = 4976 AND `watchers`.`watchable_type` = 'Issue'[0m
  [1m[35mUser Load (0.6ms)[0m  SELECT `users`.* FROM `users` INNER JOIN `watchers` ON `users`.`id` = `watchers`.`user_id` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `watchers`.`watchable_id` = 4976 AND `watchers`.`watchable_type` = 'Issue'
  Rendered watchers/_watchers.html.erb (6.1ms)
  Rendered issues/show.html.erb within layouts/base (796.4ms)
  Rendered plugins/redmine_attachments_size/app/views/hooks/attachments_size/_view_layouts_base_html_head.erb (0.3ms)
  Rendered plugins/redmine_code_review/app/views/code_review/_html_header.html.erb (0.1ms)
  [1m[36mCustomField Load (0.6ms)[0m  [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'Description tooltips' LIMIT 1[0m
  Rendered plugins/redmine_private_wiki/app/views/hooks/_html_header.html.erb (0.1ms)
  [1m[35mSQL (147.7ms)[0m  SELECT `favourite_projects`.`id` AS t0_r0, `favourite_projects`.`user_id` AS t0_r1, `favourite_projects`.`project_id` AS t0_r2, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `favourite_projects` LEFT OUTER JOIN `projects` ON `projects`.`id` = `favourite_projects`.`project_id` WHERE (user_id = 39) ORDER BY projects.name
  [1m[36mSQL (1.9ms)[0m  [1mSELECT `members`.`id` AS t0_r0, `members`.`user_id` AS t0_r1, `members`.`project_id` AS t0_r2, `members`.`created_on` AS t0_r3, `members`.`mail_notification` AS t0_r4, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12, `roles`.`id` AS t2_r0, `roles`.`name` AS t2_r1, `roles`.`position` AS t2_r2, `roles`.`assignable` AS t2_r3, `roles`.`builtin` AS t2_r4, `roles`.`permissions` AS t2_r5, `roles`.`issues_visibility` AS t2_r6 FROM `members` LEFT OUTER JOIN `projects` ON `projects`.`id` = `members`.`project_id` LEFT OUTER JOIN `member_roles` ON `member_roles`.`member_id` = `members`.`id` LEFT OUTER JOIN `roles` ON `roles`.`id` = `member_roles`.`role_id` WHERE `members`.`user_id` = 39 AND (projects.status=1) ORDER BY projects.name[0m
  [1m[35m (0.8ms)[0m  SELECT COUNT(DISTINCT `versions`.`id`) FROM `versions` LEFT OUTER JOIN `projects` ON `projects`.`id` = `versions`.`project_id` WHERE (projects.id = 46 OR (projects.status = 1 AND ( versions.sharing = 'system' OR (projects.lft >= 15 AND projects.rgt <= 16 AND versions.sharing = 'tree') OR (projects.lft < 15 AND projects.rgt > 16 AND versions.sharing IN ('hierarchy', 'descendants')) OR (projects.lft > 15 AND projects.rgt < 16 AND versions.sharing = 'hierarchy'))))
  [1m[36mWiki Load (0.4ms)[0m  [1mSELECT `wikis`.* FROM `wikis` WHERE `wikis`.`project_id` = 46 LIMIT 1[0m
  [1m[35m (0.3ms)[0m  SELECT COUNT(*) FROM `boards` WHERE `boards`.`project_id` = 46
  [1m[36mRepository Load (0.4ms)[0m  [1mSELECT `repositories`.* FROM `repositories` WHERE `repositories`.`project_id` = 46 AND (is_default = 1) LIMIT 1[0m
  [1m[35mCodeReviewProjectSetting Load (0.5ms)[0m  SELECT `code_review_project_settings`.* FROM `code_review_project_settings` WHERE (project_id = 46) LIMIT 1
  [1m[36mBanner Load (0.3ms)[0m  [1mSELECT `banners`.* FROM `banners` WHERE (project_id = 46) LIMIT 1[0m
  Rendered plugins/redmine_banner/app/views/banner/_project_body_bottom.html.erb (1.5ms)
  Rendered plugins/redmine_code_review/app/views/code_review/_body_bottom.html.erb (0.1ms)
  [1m[35mCACHE (0.0ms)[0m  SELECT `favourite_projects`.`id` AS t0_r0, `favourite_projects`.`user_id` AS t0_r1, `favourite_projects`.`project_id` AS t0_r2, `projects`.`id` AS t1_r0, `projects`.`name` AS t1_r1, `projects`.`description` AS t1_r2, `projects`.`homepage` AS t1_r3, `projects`.`is_public` AS t1_r4, `projects`.`parent_id` AS t1_r5, `projects`.`created_on` AS t1_r6, `projects`.`updated_on` AS t1_r7, `projects`.`identifier` AS t1_r8, `projects`.`status` AS t1_r9, `projects`.`lft` AS t1_r10, `projects`.`rgt` AS t1_r11, `projects`.`landing_page` AS t1_r12 FROM `favourite_projects` LEFT OUTER JOIN `projects` ON `projects`.`id` = `favourite_projects`.`project_id` WHERE (user_id = 39) ORDER BY projects.name
  Rendered plugins/redmine_favourite_projects/app/views/favourite_projects/_update_menu.erb (3.0ms)
  Rendered plugins/redmine_private_wiki/app/views/hooks/_body_bottom.html.erb

in the line contain the code

SELECT `users`.* FROM `users` INNER JOIN `groups_users` ON `users`.`id` = `groups_users`.`group_id` WHERE `users`.`type` IN ('Group') AND `groups_users`.`user_id` = 163

the user_id should be 39 not 163. why and how it happened?

At present, we think maybe some configuration of the cache caused it. but I have not found how to fix it.

I ran redmine 1.4.X and redmine 2.0.3 in the same machine. in redmine 1.4 there's no issue about it .but on redmine 2.0.3, it appears.

@Tobias tested it and give me some information.

Problem is solved when the cache of Redmine is deleted. Redmine then runs for 10-12 hours … then the error occurs again.

 I think problem is the follow:

 User A creates an issue.
 User B creates an issue… User B is logged in as User A. 
 So… User B got the cache of the session of User A… 

 But why??? ;)

And another question, how to config and manage the redmine cache? anyone has some ideas?

From Rails guide:

rake tmp:clear          # Clear session, cache, and socket files from tmp/ (narrow w/ tmp:sessions:clear, tmp:cache:clear, tmp:sockets:clear)
rake tmp:create         # Creates tmp directories for sessions, cache, sockets, and pids

Hi @all!

Etienne Massip wrote:

From Rails guide:

[...]

Of course this works (for half an hour) - but it´s just a dirty workaround, isn´t it?

You should only have to do that after the upgrade and then be good to go.

Slightly off topic, but how does your log show the SQL, time, etc?

Jon Lumpkin wrote:

You should only have to do that after the upgrade and then be good to go.

Slightly off topic, but how does your log show the SQL, time, etc?

change you log level in configuration file in config folder.

yes, a dirty workaround. I have to make a schedule to avoid the problem. and unfortunately, I have not found how to fixed the issues.

Maybe I should try to use performance test for the issue #11624 to reproduce the problem ?

Tobias Eskowitz wrote:

Hi @all!

Etienne Massip wrote:

From Rails guide:

[...]

Of course this works (for half an hour) - but it´s just a dirty workaround, isn´t it?

But at present, I used the workaround to avoid the problem.
-- I make a schedule task and I hope it would be useful.

Steven Wong wrote:

Jon Lumpkin wrote:

You should only have to do that after the upgrade and then be good to go.

Slightly off topic, but how does your log show the SQL, time, etc?

change you log level in configuration file in config folder.

Did you also change your cache provider or any cache-related setting?

Etienne Massip wrote:

Did you also change your cache provider or any cache-related setting?

Well, not far as I know... Which settings did you think?

William Roush wrote:

If you don't have some extremely odd proxy configuration that is somehow mixing/sharing cookies, I'm 99% sure it's going to be a plugin being as this is not identified in Redmine's core software.

Agreed, even with some odd proxy config.

Steven Wong wrote:

I've installed many plugins. as follows:
[...]
redmine_close_button                     0.0.8

Is this the Close Issue Button (http://www.redmine.org/plugins/redmine_close_button)? I'm asking because you are running Redmine version 2.0.3 and this plugin doesn't say it is compatible with Redmine 2.0.3. Thanks.

My Redmine-system does not include any plugin anymore.

But the error still occurs.

So: Where can the proxy- and cache-settings be configured?