Actions
Defect #12496
open
Updates through REST API return status 200 response but still fail
Status:
New
Priority:
Normal
Assignee:
-
Category:
REST API
Target version:
-
Start date:
Due date:
% Done:
0%
Estimated time:
Resolution:
Cant reproduce
Affected version:
Description
I am building an internal application for my company which depends on being able to read and update Redmine issues. Although the REST API's GET behavior appears to be working perfectly fine, my attempts to PUT data to Redmine always fail. I discussed this with another developer who previously had done some simple Redmine integration and we found that the little app he had written, which used to be able to send updates to Redmine, now did not work at all either. We believe this is a result of our recent upgrade to 2.0.4, but this is only speculation.
To narrow the possible factors which could cause problems, I have been attempting to test the REST API update feature using cURL. Here's an example. (Domains and IPs obscured for privacy and to get past the spam filter.)
Request:
curl -v -H "Content-Type: application/json" -X PUT --data '{ "issue": { "subject": "Example subject linke" } }' -u username:password DOMAIN/issues/12345.json
* About to connect() to DOMAIN port 80 (#0)
* Trying IP_ADDR... connected
* Connected to DOMAIN (IP_ADDR) port 80 (#0)
* Server auth using Basic with user 'username'
> PUT /issues/12345.json HTTP/1.1
> Authorization: Basic YnVpbGRkdWRlOkJ1MTFk
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: DOMAIN
> Accept: */*
> Content-Type: application/json
> Content-Length: 88
>
< HTTP/1.1 200 OK
< Date: Mon, 03 Dec 2012 22:14:47 GMT
< Server: Apache/2.2.22 (Debian)
< X-Powered-By: Phusion Passenger (mod_rails/mod_rack) 3.0.18
< X-UA-Compatible: IE=Edge,chrome=1
< ETag: "7215ee9c7d9dc229d2921a40e899ec5f"
< Cache-Control: max-age=0, private, must-revalidate
< X-Request-Id: fc14a612df055c426e5b93090d3210c6
< X-Runtime: 0.196459
< X-Rack-Cache: invalidate, pass
< Set-Cookie: _redmine_session=BAh7BkkiD3Nlc3Npb25faWQGOgZFRkkiJTgxMGNiYTRjNWM3YWI2MDM0MmZiMjZkMDA4ZTBmZWIwBjsAVA%3D%3D--1a77c7214ab3dff0d1c7facff14dfe92338f276f; path=/; HttpOnly
< Set-Cookie: autologin=; path=/; expires=Thu, 01-Jan-1970 00:00:00 GMT
< Access-Control-Allow-Methods: POST, GET, OPTIONS, PUT
< Access-Control-Allow-Headers: Content-Type, Authorization
< Status: 200
< Access-Control-Allow-Origin: *
< Content-Length: 1
< Content-Type: application/json; charset=utf-8
<
* Connection #0 to host DOMAIN left intact
* Closing connection #0
That last line there is the empty space response Redmine sends back, along with the status 200.
When I go and check the issue I just updated in Redmine's issue browser, the subject has not changed, but I'll be told that the issue was updated less than a minute ago.
I've tried this with several different fields (description, status, project). I've tried it as JSON and XML. I've tried authenticating using a username/password and by using the app key. Nothing works.
Here are some additional details about our Redmine setup:
Environment: Redmine version 2.0.4.stable.10796 Ruby version 1.9.3 (x86_64-linux) Rails version 3.2.6 Environment production Database adapter Mysql2 Redmine plugins: redmine_backlogs v0.9.26 redmine_code_review 0.5.0 redmine_custom_workflows 0.0.4 redmine_embedded 0.0.2 redmine_fix_title 0.0.1 redmine_impasse 1.2.2 redmine_issue_templates 0.0.3 redmine_query_current_sprint 0.0.1 redmine_wiki_issue 0.0.1
Updated by Jean-Philippe Lang about 12 years ago
That would be nice to have the Redmine log with log level set to debug that is generated when you do this request.
Updated by Adam Lacoste about 12 years ago
I'll work with our RM support guy to get this.
Updated by Adam Lacoste about 12 years ago
Whoops, wrong part of the log, stand by
Updated by Adam Lacoste about 12 years ago
This appears to be the correct segment of the log:
Started PUT "/issues/18073.json" for 130.80.28.6 at 2012-12-04 13:54:43 -0500
Started GET "/my/page" for 130.80.9.118 at 2012-12-04 13:54:43 -0500
Processing by IssuesController#update as JSON
Parameters: {"id"=>"18073"}
WARNING: Can't verify CSRF token authenticity
Processing by MyController#page as HTML
[1m[35m (0.9ms)[0m SELECT MAX(`settings`.`updated_on`) AS max_id FROM `settings`
[1m[36mSetting Load (0.9ms)[0m [1mSELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'rest_api_enabled' LIMIT 1[0m
[1m[35m (1.4ms)[0m SELECT MAX(`settings`.`updated_on`) AS max_id FROM `settings`
[1m[35mUser Load (1.4ms)[0m SELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`login` = 'builddude'
[1m[36mUser Load (0.8ms)[0m [1mSELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` = 252 AND (users.status = 1) LIMIT 1[0m
[1m[36m (6.4ms)[0m [1mBEGIN[0m
[1m[35m (8.3ms)[0m UPDATE `users` SET `last_login_on` = '2012-12-04 13:54:43', `updated_on` = '2012-12-04 13:54:43' WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` = 252
[1m[36mCustomField Load (0.5ms)[0m [1mSELECT `custom_fields`.* FROM `custom_fields` WHERE (type = 'UserCustomField') ORDER BY position[0m
[1m[35mUserPreference Load (2.5ms)[0m SELECT `user_preferences`.* FROM `user_preferences` WHERE `user_preferences`.`user_id` = 252 LIMIT 1
[1m[35mSQL (2.1ms)[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` = 252 AND `custom_values`.`customized_type` = 'Principal' ORDER BY custom_fields.position
[1m[36m (2.4ms)[0m [1mCOMMIT[0m
[1m[35mIssue Load (0.6ms)[0m SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 18073 LIMIT 1
[1m[36mProject Load (0.4ms)[0m [1mSELECT `projects`.* FROM `projects` WHERE `projects`.`id` IN (111)[0m
[1m[35mTracker Load (0.3ms)[0m SELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (2)
[1m[36mIssueStatus Load (0.3ms)[0m [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (1)[0m
[1m[35mUser Load (0.7ms)[0m SELECT `users`.* FROM `users` WHERE `users`.`type` IN ('User', 'AnonymousUser') AND `users`.`id` IN (243)
[1m[36mIssuePriority Load (0.4ms)[0m [1mSELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`id` IN (14) ORDER BY enumerations.position ASC[0m
[1m[35mIssueCategory Load (0.4ms)[0m SELECT `issue_categories`.* FROM `issue_categories` WHERE `issue_categories`.`id` IN (355)
[1m[36mEnabledModule Load (0.5ms)[0m [1mSELECT name FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 111[0m
[1m[35mTimeEntryActivity Load (0.6ms)[0m SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('TimeEntryActivity') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
[1m[36mIssueCustomField Load (0.5ms)[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.4ms)[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` = 111 ORDER BY custom_fields.position
[1m[36mIssueCustomField Load (0.7ms)[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` = 2[0m
[1m[35mIssueStatus Load (0.6ms)[0m SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 1 LIMIT 1
[1m[36mRole Load (0.6ms)[0m [1mSELECT `roles`.* FROM `roles` [0m
[1m[35mWorkflow Load (1.4ms)[0m SELECT `workflows`.* FROM `workflows` WHERE `workflows`.`old_status_id` = 1 AND (role_id IN (1,2,3,4,5) AND tracker_id = 2 AND ((author = 0 AND assignee = 0)))
[1m[36mIssueStatus Load (0.6ms)[0m [1mSELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` IN (11, 7, 8, 12, 2, 10, 3, 4, 6, 9, 13)[0m
[1m[35mIssueRelation Load (0.3ms)[0m SELECT `issue_relations`.* FROM `issue_relations` WHERE `issue_relations`.`issue_to_id` = 18073
[1m[36m (0.3ms)[0m [1mBEGIN[0m
[1m[35mSetting Load (0.4ms)[0m SELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'issue_done_ratio' LIMIT 1
[1m[36mTracker Load (3.1ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35mIssuePriority Load (0.4ms)[0m SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
[1m[36m (1.8ms)[0m [1mselect version from schema_migrations where version like '%-redmine_backlogs'[0m
[1m[35mEnabledModule Load (0.6ms)[0m SELECT `enabled_modules`.* FROM `enabled_modules` WHERE `enabled_modules`.`project_id` = 111
[1m[36mCACHE (0.0ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35mIssue Load (1.4ms)[0m SELECT `issues`.* FROM `issues` WHERE (root_id = 18073 and lft < 1 and rgt > 2 and tracker_id in (1,2)) ORDER BY lft DESC LIMIT 1
[1m[36mCACHE (0.0ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35m (1.0ms)[0m SELECT SUM(COALESCE(remaining_hours, 0)) AS sum_id FROM `issues` WHERE `issues`.`root_id` = 18073 AND (`issues`.`lft` >= 1 AND `issues`.`rgt` <= 2) AND (`issues`.id != 18073) AND (`issues`.`rgt` - `issues`.`lft` = 1)
[1m[36mCustomWorkflow Load (0.8ms)[0m [1mSELECT `custom_workflows`.* FROM `custom_workflows` WHERE `custom_workflows`.`is_for_all` = 1 ORDER BY position ASC[0m
[1m[35mCustomWorkflow Load (0.4ms)[0m SELECT `custom_workflows`.* FROM `custom_workflows` INNER JOIN `custom_workflows_projects` ON `custom_workflows`.`id` = `custom_workflows_projects`.`custom_workflow_id` WHERE `custom_workflows_projects`.`project_id` = 111 ORDER BY position ASC
[1m[36m (1.9ms)[0m [1mUPDATE `issues` SET `updated_on` = '2012-12-04 13:54:44', `lock_version` = 26 WHERE (`issues`.`id` = 18073 AND `issues`.`lock_version` = 25)[0m
[1m[35mSQL (1.1ms)[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` = 18073 AND `custom_values`.`customized_type` = 'Issue' ORDER BY custom_fields.position
[1m[36mTracker Load (0.6ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35mIssuePriority Load (0.6ms)[0m SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
[1m[36m (0.9ms)[0m [1mselect version from schema_migrations where version like '%-redmine_backlogs'[0m
[1m[35mCACHE (0.0ms)[0m SELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)
[1m[36mIssue Load (1.0ms)[0m [1mSELECT `issues`.* FROM `issues` WHERE (root_id=18073 and lft>1 and rgt<2 and
(
(NULL is NULL and not fixed_version_id is NULL)
or
(not NULL is NULL and fixed_version_id is NULL)
or
(not NULL is NULL and not fixed_version_id is NULL and NULL<>fixed_version_id)
))[0m
[1m[35m (0.8ms)[0m update issues
set tracker_id = 4
where root_id = 18073 and lft > 1 and rgt < 2
[1m[36mCACHE (0.0ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35mIssue Load (1.0ms)[0m SELECT `issues`.* FROM `issues` WHERE (root_id = 18073 and lft < 1 and rgt > 2 and tracker_id in (1,2)) ORDER BY lft DESC LIMIT 1
[1m[36mCustomWorkflow Load (1.1ms)[0m [1mSELECT `custom_workflows`.* FROM `custom_workflows` WHERE `custom_workflows`.`is_for_all` = 1 ORDER BY position ASC[0m
[1m[35m (0.7ms)[0m COMMIT
Completed 200 OK in 1322ms (ActiveRecord: 109.9ms)
[1m[36m (0.7ms)[0m [1mSELECT `users`.id FROM `users` INNER JOIN `groups_users` ON `users`.`id` = `groups_users`.`group_id` WHERE `users`.`type` IN ('Group') AND `groups_users`.`user_id` = 252[0m
[1m[35m (1.4ms)[0m SELECT COUNT(DISTINCT `issues`.`id`) FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` LEFT OUTER JOIN `issue_statuses` ON `issue_statuses`.`id` = `issues`.`status_id` WHERE `issues`.`assigned_to_id` IN (252, 10, 62, 119) AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) AND (issue_statuses.is_closed = 0)
[1m[36mCACHE (0.0ms)[0m [1mSELECT `users`.id FROM `users` INNER JOIN `groups_users` ON `users`.`id` = `groups_users`.`group_id` WHERE `users`.`type` IN ('Group') AND `groups_users`.`user_id` = 252[0m
[1m[35mSQL (1.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`.`position` AS t0_r22, `issues`.`remaining_hours` AS t0_r23, `issues`.`is_private` AS t0_r24, `issues`.`story_points` AS t0_r25, `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, `issue_statuses`.`id` AS t2_r0, `issue_statuses`.`name` AS t2_r1, `issue_statuses`.`is_closed` AS t2_r2, `issue_statuses`.`is_default` AS t2_r3, `issue_statuses`.`position` AS t2_r4, `issue_statuses`.`default_done_ratio` AS t2_r5, `trackers`.`id` AS t3_r0, `trackers`.`name` AS t3_r1, `trackers`.`is_in_chlog` AS t3_r2, `trackers`.`position` AS t3_r3, `trackers`.`is_in_roadmap` AS t3_r4, `enumerations`.`id` AS t4_r0, `enumerations`.`name` AS t4_r1, `enumerations`.`position` AS t4_r2, `enumerations`.`is_default` AS t4_r3, `enumerations`.`type` AS t4_r4, `enumerations`.`active` AS t4_r5, `enumerations`.`project_id` AS t4_r6, `enumerations`.`parent_id` AS t4_r7 FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` LEFT OUTER JOIN `issue_statuses` ON `issue_statuses`.`id` = `issues`.`status_id` LEFT OUTER JOIN `trackers` ON `trackers`.`id` = `issues`.`tracker_id` LEFT OUTER JOIN `enumerations` ON `enumerations`.`id` = `issues`.`priority_id` AND `enumerations`.`type` IN ('IssuePriority') WHERE `issues`.`assigned_to_id` IN (252, 10, 62, 119) AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) AND (issue_statuses.is_closed = 0) ORDER BY enumerations.position DESC, issues.updated_on DESC LIMIT 10
Rendered issues/_list_simple.html.erb (1.0ms)
[1m[36mToken Load (0.9ms)[0m [1mSELECT `tokens`.* FROM `tokens` WHERE `tokens`.`user_id` = 252 AND (action='feeds') LIMIT 1[0m
Rendered my/blocks/_issuesassignedtome.html.erb (233.1ms)
[1m[35m (0.7ms)[0m SELECT COUNT(DISTINCT `issues`.`id`) FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` WHERE `issues`.`author_id` = 252 AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking'))
[1m[36mSQL (1.2ms)[0m [1mSELECT `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`.`position` AS t0_r22, `issues`.`remaining_hours` AS t0_r23, `issues`.`is_private` AS t0_r24, `issues`.`story_points` AS t0_r25, `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, `issue_statuses`.`id` AS t2_r0, `issue_statuses`.`name` AS t2_r1, `issue_statuses`.`is_closed` AS t2_r2, `issue_statuses`.`is_default` AS t2_r3, `issue_statuses`.`position` AS t2_r4, `issue_statuses`.`default_done_ratio` AS t2_r5, `trackers`.`id` AS t3_r0, `trackers`.`name` AS t3_r1, `trackers`.`is_in_chlog` AS t3_r2, `trackers`.`position` AS t3_r3, `trackers`.`is_in_roadmap` AS t3_r4 FROM `issues` LEFT OUTER JOIN `projects` ON `projects`.`id` = `issues`.`project_id` LEFT OUTER JOIN `issue_statuses` ON `issue_statuses`.`id` = `issues`.`status_id` LEFT OUTER JOIN `trackers` ON `trackers`.`id` = `issues`.`tracker_id` WHERE `issues`.`author_id` = 252 AND (projects.status=1 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) ORDER BY issues.updated_on DESC LIMIT 10[0m
Rendered issues/_list_simple.html.erb (0.2ms)
Rendered my/blocks/_issuesreportedbyme.html.erb (11.5ms)
[1m[35mSetting Load (0.4ms)[0m SELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'ui_theme' LIMIT 1
Rendered my/page.html.erb within layouts/base (8081.0ms)
[1m[36mSetting Load (0.5ms)[0m [1mSELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'app_title' LIMIT 1[0m
Rendered plugins/redmine_code_review/app/views/code_review/_html_header.html.erb (0.8ms)
[1m[35mSetting Load (0.5ms)[0m SELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'login_required' LIMIT 1
[1m[36mTracker Load (0.3ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[0m
[1m[35mIssuePriority Load (0.5ms)[0m SELECT `enumerations`.* FROM `enumerations` WHERE `enumerations`.`type` IN ('IssuePriority') AND `enumerations`.`is_default` = 1 ORDER BY enumerations.position ASC LIMIT 1
[1m[36m (0.4ms)[0m [1mselect version from schema_migrations where version like '%-redmine_backlogs'[0m
Rendered plugins/redmine_backlogs/app/views/hooks/_rb_include_scripts.html.erb (5.1ms)
[1m[35mSQL (7.8ms)[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, `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` = 252 AND (projects.status=1) ORDER BY projects.name
[1m[36mCACHE (0.0ms)[0m [1mSELECT `trackers`.* FROM `trackers` WHERE `trackers`.`id` IN (1, 2)[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
[1m[36m (0.4ms)[0m [1mselect version from schema_migrations where version like '%-redmine_backlogs'[0m
Rendered plugins/redmine_code_review/app/views/code_review/_body_bottom.html.erb (1.3ms)
Completed 200 OK in 8968ms (Views: 8508.7ms | ActiveRecord: 46.5ms)
Connecting to database specified by database.yml
Creating scope :active. Overwriting existing method User.active.
Creating scope :open. Overwriting existing method Version.open.
DEPRECATION WARNING: The InstanceMethods module inside ActiveSupport::Concern will be no longer included automatically. Please define instance methods directly in CollectiveIdea::Acts::NestedSet::Model instead. (called from include at /opt/redmine-2.0/lib/plugins/awesome_nested_set/lib/awesome_nested_set/awesome_nested_set.rb:58)
DEPRECATION WARNING: The InstanceMethods module inside ActiveSupport::Concern will be no longer included automatically. Please define instance methods directly in CollectiveIdea::Acts::NestedSet::Model instead. (called from include at /opt/redmine-2.0/lib/plugins/awesome_nested_set/lib/awesome_nested_set/awesome_nested_set.rb:58)
Creating scope :open. Overwriting existing method Issue.open.
OpenIdAuthentication.store is nil. Using in-memory store.
Backlogs printable cards: problem loading labels: undefined method `merge' for #<BacklogsPrintableCards::CardPageLayout:0x00000003bfd8f0>
If this data is insufficient and you need a more complete log let me know.
Updated by Jean-Philippe Lang about 12 years ago
- Resolution set to Cant reproduce
This logs combines several requests, it's unusable for debugging purpose. And I see a lot of plugin stuff, please try without plugins first. FYI, updating issues via the REST API is part of the of tests suite.
Updated by Adrian Wilkins almost 12 years ago
I'm also seeing this in conjunction with the Redmine plugin for Mylyn
In my case, the "Estimated time" field is set, but the notes are not.
I think the relevant log segment is as follows :
Started GET "/request/mylyn/token?key=f965c537cec5c75843a73588cfa57d07db54291a" for 10.149.126.35 at Mon Mar 11 17:25:15 +0000 2013
Processing by MylynConnector::InformationController#token as TEXT
Parameters: {"key"=>"f965c537cec5c75843a73588cfa57d07db54291a"}
Current user: adwi2 (id=54)
Completed 200 OK in 10ms (Views: 0.4ms | ActiveRecord: 0.8ms)
Started PUT "/request/issues/2433.xml?key=f965c537cec5c75843a73588cfa57d07db54291a" for 10.149.126.35 at Mon Mar 11 17:25:15 +0000 2013
Processing by IssuesController#update as XML
Parameters: {"issue"=>{"parent_issue_id"=>"", "start_date"=>"", "subject"=>"Test Mylyn", "custom_field_values"=>{"18"=>"", "13"=>"", "12"=>""}, "project_id"=>"1", "watcher_user_ids"=>nil, "fixed_version_id"=>"", "due_date"=>"", "status_id"=>"9", "priority_id"=>"5", "tracker_id"=>"10", "done_ratio"=>"0", "assigned_to_id"=>"54", "estimated_hours"=>"0.0", "description"=>"Tweet tweet.", "category_id"=>""}, "notes"=>"Poot poot.", "id"=>"2433", "key"=>"f965c537cec5c75843a73588cfa57d07db54291a"}
WARNING: Can't verify CSRF token authenticity
Current user: adwi2 (id=54)
Rendered mailer/_issue.text.erb (7.8ms)
Rendered mailer/issue_edit.text.erb within layouts/mailer (10.7ms)
Rendered mailer/_issue.html.erb (5.1ms)
Rendered mailer/issue_edit.html.erb within layouts/mailer (7.8ms)
Rendered text template (0.0ms)
Completed 200 OK in 1002ms (Views: 2.4ms | ActiveRecord: 48.7ms)
Updated by Adrian Wilkins almost 12 years ago
Here's just the parameters from the log above, followed by one from manually updating an issue via IRB / ActiveResource. I've indented the parameters.
Processing by IssuesController#update as XML
Parameters:
{
"issue"=>
{
"parent_issue_id"=>""
, "start_date"=>""
, "subject"=>"Test Mylyn"
, "custom_field_values"=>{"18"=>"", "13"=>"", "12"=>""}
, "project_id"=>"1"
, "watcher_user_ids"=>nil
, "fixed_version_id"=>""
, "due_date"=>""
, "status_id"=>"9"
, "priority_id"=>"5"
, "tracker_id"=>"10"
, "done_ratio"=>"0"
, "assigned_to_id"=>"54"
, "estimated_hours"=>"0.0"
, "description"=>"Tweet tweet."
, "category_id"=>""
}
, "notes"=>"Poot poot."
, "id"=>"2433"
, "key"=>"f965c537cec5c75843a73588cfa57d07db54291a"
}
And the ActiveResource one..
Processing by IssuesController#update as XML
Parameters:
{
"issue"=>
{
"tracker"=>
{"id"=>"10", "name"=>"Request"}
, "created_on"=>"2013-03-11T16:14:15Z"
, "priority"=>{"id"=>"5", "name"=>"P3 (Medium)"}
, "description"=>"Testing mylyn integration"
, "id"=>"2436"
, "notes"=>"Testing from irb"
, "due_date"=>nil
, "updated_on"=>"2013-03-11T16:19:11Z"
, "author"=>{"id"=>"54", "name"=>"Wilkins, Adrian"}
, "start_date"=>nil
, "assigned_to"=>{"id"=>"54", "name"=>"Wilkins, Adrian"}
, "project"=>{"id"=>"1", "name"=>"Redmine Meta Project"}
, "spent_hours"=>"0.0"
, "custom_fields"=>
[
{"id"=>"12", "name"=>"Service", "value"=>nil}
, {"id"=>"13", "name"=>"Customer", "value"=>nil}
, {"id"=>"18", "name"=>"Customer Portfolio", "value"=>nil}
]
, "status"=>{"id"=>"9", "name"=>"Assigned"}
, "subject"=>"Test Mylyn interaction"
, "done_ratio"=>"0"
, "estimated_hours"=>"0.0"
}
, "id"=>"2436"
}
It looks like the notes are being passed as a a parameter outside the issue by the Mylyn API call, whereas ActiveResource passes it as a field on the issue object.
ActiveResource works, the Mylyn call does not.
I suspect from this that the REST API previously accepted "notes" as a parameter on the main update call, rather than as a field on the issue object, since the same client worked properly before upgrading from a 1.4.x series server to 2.2.x
Potential suggestions :
- Patch to accept the old behaviour OR
- Return an error to calls that include a notes parameter at the top level of the call.
- This at least enables broken implementations to be aware that they are broken.
Looking at the logs above on the original issue submitters server.. the parameters list is only the ID. No wonder his client isn't updating the issue.
Updated by Adrian Wilkins almost 12 years ago
Have patched my local copy of the Mylyn plugin to send notes as a field on the issue object rather than as a separate field. Success!
Not sure there is an active maintainer of it but will do best to feed this upstream.
I guess people implementing clients might need to be aware of what seems to be a change in the REST API behaviour (if not it's specification).
Actions