Internal Error after MySQL conversion from latin1 to utf8

Added by Martin Jungowski almost 8 years ago

We're running a Redmine 2.5.0 wiki on Ubuntu 12.04 LTS (Ruby 1.8.7, MySQL 5.5, rails 3.2.17, passenger 4.0.38) with a ~100MB MySQL database. For historical reasons (we've been running this wiki for several years now) we've used latin1 for the database encoding. However, we now need to incorporate some Polish speaking colleagues which is why I would like to convert the database to UTF8. And it has almost worked like a charm - conversion took place by altering the database and every single table to utf8. Polish special signs now display correctly where before they would only render as a ? and I'm pretty happy.... Except that now occasionaly searching returns an internal error. It's reproducible because it only happens when searching for certain words, but these words never work. For example: searching for 'windows' works, searching for 'svnet' doesn't work. Searching for 'svnet windows' or 'svnet1' works, however searching for 'svnet 1', 'svnet a' or 'svnet ab' doesn't work, searching for 'svnet abc' does work (but doesn't return any results). It's only certain words that don't work, I'd say more than 99% of all search queries work just fine. When it doesn't work I get an "Internal error" after a few seconds, Redmine log throws an Error 500 exception. As soon as I restore the pre-conversion dump search is back to normal behavior and I can search for everything just fine.

This is the log for searching for 'svnet' with the latin1 database:

Started GET "/search?utf8=%E2%9C%93&q=svnet" for 10.200.0.81 at Wed Mar 19 08:23:40 +0100 2014
Processing by SearchController#index as HTML
  Parameters: {"q"=>"svnet", "utf8"=>"✓"}
  Current user: martin (id=26)
  Rendered search/index.html.erb within layouts/base (43.6ms)
  Rendered plugins/progressive_projects_list/app/views/application/_progressive_sidebar.html.erb (0.1ms)
  Rendered plugins/progressive_projects_list/app/views/application/_progressive_recent_projects.html.erb (3.2ms)
  Rendered plugins/sidebar_hide/app/views/sidebar/_hideButton_partial.html.erb (0.8ms)
Completed 200 OK in 620.3ms (Views: 251.1ms | ActiveRecord: 6.9ms)

And here it is when searching for 'svnet' with the converted utf8 database:

Started GET "/search?utf8=%E2%9C%93&q=svnet" for 10.200.0.81 at Wed Mar 19 08:25:30 +0100 2014
Processing by SearchController#index as HTML
  Parameters: {"q"=>"svnet", "utf8"=>"✓"}
  Current user: martin (id=26)
Completed 500 Internal Server Error in 4749.3ms

ActiveRecord::StatementInvalid (Mysql2::Error: Lost connection to MySQL server during query: 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, `issues`.`closed_on` AS t0_r23, `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`.`inherit_members` AS t1_r12, `journals`.`id` AS t2_r0, `journals`.`journalized_id` AS t2_r1, `journals`.`journalized_type` AS t2_r2, 
`journals`.`user_id` AS t2_r3, `journals`.`notes` AS t2_r4, `journals`.`created_on` AS t2_r5, `journals`.`private_notes` AS t2_r6 FROM `issues` LEFT OUTER JOIN 
`projects` ON `projects`.`id` = `issues`.`project_id` LEFT OUTER JOIN `journals` ON `journals`.`journalized_id` = `issues`.`id` AND (journals.private_notes = 0 
OR (1=0)) AND `journals`.`journalized_type` = 'Issue' WHERE `issues`.`id` IN (14112, 11053, 10109, 8501, 8376, 8325, 7391, 6524, 5981, 5638) AND 
(((projects.status <> 9 AND projects.id IN (SELECT em.project_id FROM enabled_modules em WHERE em.name='issue_tracking')) AND ((projects.id IN (337) AND 
((issues.is_private = 0 OR issues.author_id = 26 OR issues.assigned_to_id IN (26,43,98,99,102,103,104,116)))) OR (projects.id IN (303) AND ((issues.is_private = 0 OR 
issues.author_id = 26 OR issues.assigned_to_id IN (26,43,98,99,102,103,104,116)))) OR (projects.id IN 
(60,308,85,84,86,281,249,304,271,238,235,237,234,103,14,159,158,51,279,302,79,15,313,64,121,108,155,140,104,152,2,138,305,110,231,244,191,188,189,10,
1,68,43,224,22,346,47,95,50,287,13,3,268,17,262,217,277,251,219,122,16,38,150,211,314,125,167,73,318,30,206,157,207,210,65,129,58,220,193,319,139,340
,291,229,243,233,8,102,199,41,142,143,213,98,184,148,31,333,185,6,82,156,154,253,254,267,257,276,239,258,259,261,266,270,286,280,21,285,289,290,222,
295,296,297,299,301,161,256,310,311,192,320,215,97,278,118,165,59,312,28,117,334,332,160,347,327,323,42,309,341,345,183,348,45,226,162,208,96,70,12
4,324,170,218,216,232,53,221,20,315,322,34,135,77,145,55,149,107) AND ((issues.is_private = 0 OR issues.author_id = 26 OR issues.assigned_to_id IN 
(26,43,98,99,102,103,104,116)))) OR (projects.id IN (257,258,222,256) AND ((issues.is_private = 0 OR issues.author_id = 26 OR issues.assigned_to_id IN 
(26,43,98,99,102,103,104,116))))))) AND (((LOWER(subject) LIKE '%svnet%') OR (LOWER(issues.description) LIKE '%svnet%') OR (LOWER(journals.notes) LIKE '%svnet%') OR 
issues.id IN (SELECT cfs.customized_id FROM custom_values cfs WHERE cfs.customized_type='Issue' AND cfs.customized_id=issues.id AND LOWER(cfs.value) LIKE 
'%svnet%' AND cfs.custom_field_id IN (5,6) AND ((1=1) AND (issues.tracker_id IN (SELECT tracker_id FROM custom_fields_trackers WHERE custom_field_id = 
cfs.custom_field_id)) AND (EXISTS (SELECT 1 FROM custom_fields ifa WHERE ifa.is_for_all = 1 AND ifa.id = cfs.custom_field_id) OR issues.project_id IN (SELECT 
project_id FROM custom_fields_projects WHERE custom_field_id = cfs.custom_field_id)))))) ORDER BY issues.id DESC):
  lib/plugins/acts_as_searchable/lib/acts_as_searchable.rb:132:in `search'
  app/controllers/search_controller.rb:74:in `index'
  app/controllers/search_controller.rb:73:in `each'
  app/controllers/search_controller.rb:73:in `index'

For comparison, here's a log entry from a search that does work with the utf8 database:

Started GET "/search?utf8=%E2%9C%93&q=svnet+windows" for 10.200.0.81 at Wed Mar 19 08:27:05 +0100 2014
Processing by SearchController#index as HTML
  Parameters: {"q"=>"svnet windows", "utf8"=>"✓"}
  Current user: martin (id=26)
  Rendered search/index.html.erb within layouts/base (72.5ms)
  Rendered plugins/progressive_projects_list/app/views/application/_progressive_sidebar.html.erb (0.1ms)
  Rendered plugins/progressive_projects_list/app/views/application/_progressive_recent_projects.html.erb (2.5ms)
  Rendered plugins/sidebar_hide/app/views/sidebar/_hideButton_partial.html.erb (0.8ms)
Completed 200 OK in 5571.9ms (Views: 263.9ms | ActiveRecord: 4949.8ms)

When copy & pasting the search query into mysql it returns the expected results so it's not a query problem. Not sure what the problem is though, any ideas?

Replies (1)

RE: Internal Error after MySQL conversion from latin1 to utf8 - Added by Martin Jungowski almost 8 years ago

Problem solved. Not sure what exactly caused it but updating from Ubuntu 12.04 LTS/Ruby 1.8.7/Apache 2.2 to Ubuntu 13.10/Ruby 2.0.0/Apache 2.4 fixed it. It's also become significantly faster than before (given the exact same configuration and resources) - loading a ticket with 500+ replies went from ~10s to less than 4s.

(1-1/1)