search

wolfgangimig / itol

JOA based issue tracker for Microsoft Outlook
23 stars 6 forks source link

Redmine 500 error when submitting issue #16

Closed dan-sorion closed 9 years ago

dan-sorion commented 9 years ago

ITOL 32-bit, Outlook 2013, Redmine 2.6.2

When pressing the Create button to add a new issue to Redmine I get a popup dialog with the HTML from a 500 server error in Redmine. Looking in the production.log file in Redmine I see the following:

Started POST "/issues.json" for 192.168.4.31 at 2015-03-12 10:08:55 +0000
Processing by IssuesController#create as JSON
  Parameters: {"issue"=>{"id"=>"", "project_id"=>21, "tracker_id"=>1, "status_id"=>1, "priority_id"=>2, "subject"=>"Testing ITOL", "description"=>"This is a test bug", "notes"=>"", "assigned_to_id"=>"", "category_id"=>"", "fixed_version_id"=>"", "start_date"=>"2015-03-12", "due_date"=>"", "estimated_hours"=>"", "done_ratio"=>"0", "custom_fields"=>nil, "uploads"=>nil}}
  Current user: dan.crichton (id=3)
Completed 500 Internal Server Error in 187.2ms

NoMethodError (undefined method `inject' for nil:NilClass):
  lib/plugins/acts_as_customizable/lib/acts_as_customizable.rb:55:in `custom_fields='
  app/models/issue.rb:350:in `assign_attributes_with_project_and_tracker_first'
  app/models/issue.rb:473:in `safe_attributes='
  app/controllers/issues_controller.rb:431:in `build_new_issue_from_params'

The itol.log file shows the following (this appears to be the relevant log extract)

2015-03-12 10:08:55,077 FINE jdk.nashorn.internal.scripts.Script$IssueServiceImpl writeIssue writeIssue(
2015-03-12 10:08:55,077 FINE jdk.nashorn.internal.scripts.Script$IssueServiceImpl ddump send={
  "issue": {
    "id": "",
    "project_id": 21,
    "tracker_id": 1,
    "status_id": 1,
    "priority_id": 2,
    "subject": "Testing ITOL",
    "description": "This is a test bug",
    "notes": "",
    "assigned_to_id": "",
    "category_id": "",
    "fixed_version_id": "",
    "start_date": "2015-03-12",
    "due_date": "",
    "estimated_hours": "",
    "done_ratio": "0",
    "custom_fields": [],
    "uploads": []
  }
}
2015-03-12 10:08:55,077 FINE jdk.nashorn.internal.scripts.Script$IssueServiceImpl writeIssue issueId=, isUpdate=false
2015-03-12 10:08:55,078 FINE com.wilutions.itol.db.HttpClient send send(POST, url=http://<serverurl>:<port>/issues.json
2015-03-12 10:08:55,078 FINE com.wilutions.itol.db.HttpClient send headers=[Content-Type: application/json, X-Redmine-API-Key: <apikey>]
2015-03-12 10:08:55,078 FINE com.wilutions.itol.db.HttpClient send content={"issue":{"id":"","project_id":21,"tracker_id":1,"status_id":1,"priority_id":2,"subject":"Testing ITOL","description":"This is a test bug","notes":"","assigned_to_id":"","category_id":"","fixed_version_id":"","start_date":"2015-03-12","due_date":"","estimated_hours":"","done_ratio":"0","custom_fields":[],"uploads":[]}}
2015-03-12 10:08:55,078 INFO com.wilutions.itol.db.HttpClient send POST http://<serverurl>:<port>/issues.json #-1
2015-03-12 10:08:55,220 FINE sun.net.www.protocol.http.HttpURLConnection writeRequests sun.net.www.MessageHeader@f1619d10 pairs: {POST /issues.json HTTP/1.1: null}{Content-Type: application/json}{X-Redmine-API-Key: <apikey>}{Cache-Control: no-cache}{Pragma: no-cache}{User-Agent: Java/1.8.0_31}{Host: <serverurl>:<port>}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}{Transfer-Encoding: chunked}
2015-03-12 10:08:55,222 FINE com.wilutions.itol.db.HttpClient writeStringIntoStream writeStringIntoStream(length=320
2015-03-12 10:08:55,222 FINE com.wilutions.itol.db.HttpClient writeStringIntoStream )writeStringIntoStream
2015-03-12 10:08:55,222 FINE com.wilutions.itol.db.HttpClient send getResponseCode...
2015-03-12 10:08:55,490 FINE sun.net.www.protocol.http.HttpURLConnection getInputStream0 sun.net.www.MessageHeader@d738009 pairs: {null: HTTP/1.1 500 Internal Server Error}{Content-Length: 648}{Content-Type: text/html; charset=utf-8}{Server: Microsoft-IIS/7.5}{X-Rack-Cache: invalidate, pass}{X-Request-Id: 5a71afe1a1dbff138c0322b13ffcc19f}{X-Runtime: 0.265198}{X-Powered-By: ASP.NET}{Date: Thu, 12 Mar 2015 10:08:55 GMT}
2015-03-12 10:08:55,491 FINE com.wilutions.itol.db.HttpClient send status=500
2015-03-12 10:08:55,491 FINE com.wilutions.itol.db.HttpClient send response header=null, values=[HTTP/1.1 500 Internal Server Error]
2015-03-12 10:08:55,492 FINE com.wilutions.itol.db.HttpClient send response header=Server, values=[Microsoft-IIS/7.5]
2015-03-12 10:08:55,492 FINE com.wilutions.itol.db.HttpClient send response header=X-Request-Id, values=[5a71afe1a1dbff138c0322b13ffcc19f]
2015-03-12 10:08:55,492 FINE com.wilutions.itol.db.HttpClient send response header=X-Runtime, values=[0.265198]
2015-03-12 10:08:55,492 FINE com.wilutions.itol.db.HttpClient send response header=Content-Length, values=[648]
2015-03-12 10:08:55,493 FINE com.wilutions.itol.db.HttpClient send response header=Date, values=[Thu, 12 Mar 2015 10:08:55 GMT]
2015-03-12 10:08:55,493 FINE com.wilutions.itol.db.HttpClient send response header=X-Rack-Cache, values=[invalidate, pass]
2015-03-12 10:08:55,493 FINE com.wilutions.itol.db.HttpClient send response header=X-Powered-By, values=[ASP.NET]
2015-03-12 10:08:55,493 FINE com.wilutions.itol.db.HttpClient send response header=Content-Type, values=[text/html; charset=utf-8]
2015-03-12 10:08:55,494 FINE com.wilutions.itol.db.HttpClient send read from input...
2015-03-12 10:08:55,494 INFO com.wilutions.itol.db.HttpClient send send failed, exception=java.io.IOException: Server returned HTTP response code: 500 for URL: http://dev-server2:3000/issues.json
2015-03-12 10:08:55,494 FINE com.wilutions.itol.db.HttpClient send read from error...
2015-03-12 10:08:55,495 FINE com.wilutions.itol.db.HttpClient send )send=500, ret=[status=500,headers=[: HTTP/1.1 500 Internal Server Error, Server: Microsoft-IIS/7.5, X-Request-Id: 5a71afe1a1dbff138c0322b13ffcc19f, X-Runtime: 0.265198, Content-Length: 648, Date: Thu, 12 Mar 2015 10:08:55 GMT, X-Rack-Cache: invalidate, pass, X-Powered-By: ASP.NET, Content-Type: text/html; charset=utf-8],content=<!DOCTYPE html>
<html>
<head>
  <meta charset="utf-8" />
  <title>Redmine 500 error</title>
  <style>
    body {font-family: "Trebuchet MS", Georgia, "Times New Roman", serif; color: #303030; margin: 10px;}
    h1 {font-size:1.5em;}
    p {font-size:0.8em;}
  </style>
</head>
<body>
  <h1>Internal error</h1>
  <p>An error occurred on the page you were trying to access.<br />
  If you continue to experience problems please contact your Redmine administrator for assistance.</p>
  <p>If you are the Redmine administrator, check your log files for details about the error.</p>
  <p><a href="javascript:history.back()">Back</a></p>
</body>
</html>]
2015-03-12 10:08:55,496 SEVE com.wilutions.itol.IssueTaskPane lambda$13 Failed to update issue
file:/C:/Users/<myusername>/AppData/Local/Issue%20Tracker%20for%20Microsoft%20Outlook%2032bit/app/IssueServiceImpl.js:217:3 java.io.IOException: HTTP Status 500, Server returned HTTP response code: 500 for URL: http://<serverurl>:<port>/issues.json, <!DOCTYPE html>
<html>
<head>
  <meta charset="utf-8" />
  <title>Redmine 500 error</title>
  <style>
    body {font-family: "Trebuchet MS", Georgia, "Times New Roman", serif; color: #303030; margin: 10px;}
    h1 {font-size:1.5em;}
    p {font-size:0.8em;}
  </style>
</head>
<body>
  <h1>Internal error</h1>
  <p>An error occurred on the page you were trying to access.<br />
  If you continue to experience problems please contact your Redmine administrator for assistance.</p>
  <p>If you are the Redmine administrator, check your log files for details about the error.</p>
  <p><a href="javascript:history.back()">Back</a></p>
</body>
</html>
    at jdk.nashorn.internal.runtime.ECMAException.create(ECMAException.java:111)
    at jdk.nashorn.internal.scripts.Script$IssueServiceImpl$3.L:196(file:/C:/Users/<myusername>/AppData/Local/Issue%20Tracker%20for%20Microsoft%20Outlook%2032bit/app/IssueServiceImpl.js:217)
    at jdk.nashorn.internal.scripts.Script$IssueServiceImpl$3.L:233(file:/C:/Users/<myusername>/AppData/Local/Issue%20Tracker%20for%20Microsoft%20Outlook%2032bit/app/IssueServiceImpl.js:236)
    at jdk.nashorn.internal.scripts.Script$IssueServiceImpl.writeIssue(file:/C:/Users/<myusername>/AppData/Local/Issue%20Tracker%20for%20Microsoft%20Outlook%2032bit/app/IssueServiceImpl.js:500)
    at jdk.nashorn.internal.scripts.Script$IssueServiceImpl$2.updateIssue(file:/C:/Users/<myusername>/AppData/Local/Issue%20Tracker%20for%20Microsoft%20Outlook%2032bit/app/IssueServiceImpl.js:1285)
    at com.wilutions.itol.db.IssueService$$NashornJavaAdapter.updateIssue(Unknown Source)
    at com.wilutions.itol.IssueTaskPane.updateIssueChangedMembers(IssueTaskPane.java:1182)
    at com.wilutions.itol.IssueTaskPane.lambda$13(IssueTaskPane.java:1129)
    at com.wilutions.itol.IssueTaskPane$$Lambda$484/10666522.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at com.wilutions.com.BackgTask$1$1.run(BackgTask.java:80)
Caused by: java.io.IOException: HTTP Status 500, Server returned HTTP response code: 500 for URL: http://<serverurl>:<port>/issues.json, <!DOCTYPE html>
<html>
<head>
  <meta charset="utf-8" />
  <title>Redmine 500 error</title>
  <style>
    body {font-family: "Trebuchet MS", Georgia, "Times New Roman", serif; color: #303030; margin: 10px;}
    h1 {font-size:1.5em;}
    p {font-size:0.8em;}
  </style>
</head>
<body>
  <h1>Internal error</h1>
  <p>An error occurred on the page you were trying to access.<br />
  If you continue to experience problems please contact your Redmine administrator for assistance.</p>
  <p>If you are the Redmine administrator, check your log files for details about the error.</p>
  <p><a href="javascript:history.back()">Back</a></p>
</body>
</html>
    ... 12 more

I have removed all plugins and get the same result. I have no custom fields configured in Redmine.

Dan

wolfgangimig commented 9 years ago

Hello Dan, Probably, Redmine does not like an empty list of custom fields. Please try this patch. Regards Wolfgang

dan-sorion commented 9 years ago

I replicated the POST in VBScript and obtained the same error. I then removed "custom_fields":[], from the JSON and tried again, and it worked. Looks like the Redmine REST API does not handle empty custom fields value.

EDIT: I was writing my followup when you sent your reply. The patch works. I wasn't aware of this page in the Wiki with this already noted, I'm still new to Github and finding my feet. Thanks for the help.

Dan

wolfgangimig commented 9 years ago

Thank you for your investigation. I supposed that this error only appears with 2.6.0. Since you received it in 2.6.2 too, I tested with 2.6.1 and also ran into this problem: If no custom fields are defined, it is not possible to create an issue.

The script file mentioned here solves the problem for all 2.6.x versions.