Internal error about redmine-view-customize HOT 21 CLOSED

環境は、
bitnami redmine
Environment:
Redmine version 4.0.2.stable
Ruby version 2.4.5-p335 (2018-10-18) [i386-mingw32]
Rails version 5.2.2
Environment production
Database adapter Mysql2
Mailer queue ActiveJob::QueueAdapters::AsyncAdapter
Mailer delivery smtp
SCM:
Git 2.19.1
Filesystem
Redmine plugins:
view_customize 2.1.0
となります｡

from redmine-view-customize.

@ojima-takahito
報告ありがとうございます。

Wikiでマルチバイトの文字を含んだページを作成し、そのページにアクセスすれば、必ず発生する形となりますでしょうか。

こちらでマルチバイトを含むWikiページを作成し、それを表示してみましたが、再現させられておりません。

from redmine-view-customize.

外野から失礼します。

私も同様の経験をしました（1ヶ月前頃）。
プラグイン導入直後は問題なく使えていた（と思っていた）のですが、数時間後、利用者からの問い合わせで知ることに…
キャッシュクリア、Redmine再起動で一時的に復旧したのですが、しばらくすると再現するという繰り返し…
マルチバイトリンク（URLエスケープされたリンク）をクリック、再現しない場合はリンクを連打すると100%発生しました。

とても使いたかったのですが…
調査に時間をかけられなかったため、アンインストールしました。

アンインストール後、本事象は再現しなくなり、現在に至っております。

from redmine-view-customize.

@you2mura
情報ありがとうございます。

今までの情報含め、原因を考えてみましたが、まだ原因について特定できていません。
また、手元で再現できればいろいろ試せるのですが、手元では再現できず困っています。

URLに何か規則性があるのではと思っているのですが、問題となったときのURLを教えていただくことは可能でしょうか。

from redmine-view-customize.

仕事先のイントラ環境のため、明日、ログ確認して情報提供できればと思います。

from redmine-view-customize.

ログは以下の通りです（一部マスク化）。
access.log上は想定したURLのようですが、production.logではおかしなURLに変わってしまっていたようです。
解析の手がかりになれば幸いです。

◆access.log (apache)
aaa.aaa.aaa.aaa - - [04/Jun/2019:12:56:13 +0900] "GET /redmine/projects/XXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 200 6022
bbb.bbb.bbb.bbb - - [05/Jun/2019:14:52:12 +0900] "GET /redmine/projects/XXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 500 648

◆production.log (redmine)
Started GET "/redmine/projects/XXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86" for aaa.aaa.aaa.aaa at 2019-06-04 12:56:13 +0900
Processing by WikiController#show as HTML
Parameters: {"project_id"=>"XXXXXXXXXX", "id"=>"リンク集"}
Current user: ********* (id=11)
Rendering wiki/show.html.erb within layouts/base
Rendered wiki/_content.html.erb (22.1ms)
Rendered attachments/_form.html.erb (1.0ms)
Rendered wiki/_sidebar.html.erb (1.2ms)
Rendered wiki/show.html.erb within layouts/base (33.5ms)
Completed 200 OK in 107ms (Views: 39.9ms | ActiveRecord: 57.5ms)
Started GET "/redmine/projects/XXXXXXXXXX/wiki/%E3%83?%E3%83?%E3%82?%E9%9B%86" for bbb.bbb.bbb.bbb at 2019-06-05 14:52:12 +0900
Processing by WikiController#show as HTML
Parameters: {"project_id"=>"XXXXXXXXXX", "id"=>"リンク集"}
Current user: ********** (id=24)
Rendering wiki/show.html.erb within layouts/base
Rendered wiki/_content.html.erb (19.7ms)
Rendered attachments/_form.html.erb (1.0ms)
Rendered wiki/_sidebar.html.erb (1.4ms)
Rendered wiki/show.html.erb within layouts/base (31.7ms)
Completed 500 Internal Server Error in 221ms (ActiveRecord: 41.3ms)

from redmine-view-customize.

@you2mura
情報ありがとうございます。

同じような名前でWikiを作ってみましたが、やはり再現せずでした。
現象からいくつか回避方法が思いついているのですが、実際手元で再現しないため試せない状況です。

もし可能であればですが、、こちらで修正したものを、試していただくことは可能でしょうか。

from redmine-view-customize.

@onozaty
試すことは可能です。
スケジュール調整する必要があるため、結果をご連絡するのに時間を要するかもしれませんが…

from redmine-view-customize.

@onozaty
なお、私の動作環境は @ojima-takahito さんとほぼ同じです。
違いは以下のみとなります。

Redmine plugins:
view_customize 2.2.0

from redmine-view-customize.

@you2mura
ありがとうございます。
対応版が出来ましたら、ご連絡させていただきます。

from redmine-view-customize.

@you2mura
対応版ができましたので、試していただけますでしょうか。

対応版はhotfix/40-incompatible_character_encodingsというbranchにありますので、cloneした後に切り替える必要があります。

cd {RAILS_ROOT}/plugins
git clone https://github.com/onozaty/redmine-view-customize.git view_customize
cd view_customize
git checkout hotfix/40-incompatible_character_encodings
cd ../../
bundle install --without development test
bundle exec rake redmine:plugins:migrate RAILS_ENV=production

バージョンは2.3.0.40-1としています。

お手数をおかけして申し訳ございませんが、よろしくお願いいたします。

from redmine-view-customize.

@onozaty
ご対応感謝です。
以下確認を実施する予定です。

1. バージョン2.2.0（不具合確認した）環境を復元して不具合が再現することを確認する
2. バージョン2.3.0に更新しても不具合が再現することを確認する（多分再現するはず）
3. バージョン2.3.0.40-1に更新したら不具合が再現しないことを確認する

なお、スケジュール調整する必要があるため、結果をご連絡するのに時間を要するかもしれません。
早ければ明日、遅くとも週末までには結果をご報告したいと思います。

from redmine-view-customize.

@you2mura
とても助かります。
確認自体は、ほんといつになっても大丈夫ですので、ご都合の良いタイミングでやっていただければと思います。

from redmine-view-customize.

結果はNGでした。
プラグイン導入直後は問題なかったのですが「表示のカスタマイズ」登録後にNGとなるようです。

以下にログなどを記しました。
前回提供したログとエラー箇所が異なるようです。
解析の手がかりになれば幸いです。

プラグイン導入直後

• access.log (apache)

aaa.aaa.aaa.aaa - - [23/Jul/2019:15:27:13 +0900]
 "GET /redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 200 6098
aaa.aaa.aaa.aaa - - [23/Jul/2019:15:29:32 +0900]
 "GET /redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 200 6116

• production.log (redmine)

Started GET "/redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86"
 for aaa.aaa.aaa.aaa at 2019-07-23 15:27:13 +0900
Processing by WikiController#show as HTML
  Parameters: {"project_id"=>"XXXXXXXXXXX", "id"=>"リンク集"}
  Current user: ********* (id=11)
  Rendering wiki/show.html.erb within layouts/base
  Rendered wiki/_content.html.erb (19.4ms)
  Rendered attachments/_form.html.erb (1.0ms)
  Rendered wiki/_sidebar.html.erb (1.2ms)
  Rendered wiki/show.html.erb within layouts/base (30.3ms)
Completed 200 OK in 87ms (Views: 41.3ms | ActiveRecord: 36.2ms)
Started GET "/redmine/projects/XXXXXXXXXXX/wiki/%E3%83?%E3%83?%E3%82?%E9%9B%86"
 for aaa.aaa.aaa.aaa at 2019-07-23 15:29:32 +0900
Processing by WikiController#show as HTML
  Parameters: {"project_id"=>"XXXXXXXXXXX", "id"=>"リンク集"}
  Current user: ********* (id=11)
  Rendering wiki/show.html.erb within layouts/base
  Rendered wiki/_content.html.erb (20.2ms)
  Rendered attachments/_form.html.erb (1.0ms)
  Rendered wiki/_sidebar.html.erb (1.3ms)
  Rendered wiki/show.html.erb within layouts/base (33.6ms)
Completed 200 OK in 92ms (Views: 44.8ms | ActiveRecord: 37.0ms)

プラグイン導入後（表示のカスタマイズ追加後）

• 表示のカスタマイズ
  パスのパターン: /projects/XXXXXXXXXXX
  挿入位置: 全てのページのヘッダ
  種別: JavaScript
  有効: はい
  プライベート: はい (id=1)
  コード:

$(document).ready(function() {
  var s = "/redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86";
  $('#top-menu > ul').append('<li><a href="' + s + '">リンク集</a></li>');
});

• access.log (apache)

aaa.aaa.aaa.aaa - - [23/Jul/2019:15:51:34 +0900]
 "GET /redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 500 648
aaa.aaa.aaa.aaa - - [23/Jul/2019:15:56:03 +0900]
 "GET /redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86 HTTP/1.1" 200 6120

• production.log (redmine)

Started GET "/redmine/projects/XXXXXXXXXXX/wiki/%E3%83?%E3%83?%E3%82?%E9%9B%86"
 for aaa.aaa.aaa.aaa at 2019-07-23 15:51:34 +0900
Processing by WikiController#show as HTML
  Parameters: {"project_id"=>"XXXXXXXXXXX", "id"=>"リンク集"}
  Current user: ******* (id=1)
  Rendering wiki/show.html.erb within layouts/base
  Rendered wiki/_content.html.erb (19.6ms)
  Rendered attachments/_form.html.erb (1.0ms)
  Rendered wiki/_sidebar.html.erb (1.2ms)
  Rendered wiki/show.html.erb within layouts/base (30.5ms)
Completed 500 Internal Server Error in 143ms (ActiveRecord: 34.6ms)
  
ActionView::Template::Error (invalid byte sequence in UTF-8):
    13: <%= stylesheet_link_tag 'rtl', :media => 'all' if l(:direction) == 'rtl' %>
    14: <%= javascript_heads %>
    15: <%= heads_for_theme %>
    16: <%= call_hook :view_layouts_base_html_head %>
    17: <!-- page specific tags -->
    18: <%= yield :header_tags -%>
    19: </head>
  
plugins/view_customize/lib/view_customize/view_hook.rb:50:in `=~'
plugins/view_customize/lib/view_customize/view_hook.rb:50:in `block in match_customize'
plugins/view_customize/lib/view_customize/view_hook.rb:47:in `match_customize'
plugins/view_customize/lib/view_customize/view_hook.rb:38:in `create_view_customize_html'
plugins/view_customize/lib/view_customize/view_hook.rb:13:in `view_layouts_base_html_head'
lib/redmine/hook.rb:61:in `block (2 levels) in call_hook'
lib/redmine/hook.rb:61:in `each'
lib/redmine/hook.rb:61:in `block in call_hook'
lib/redmine/hook.rb:58:in `tap'
lib/redmine/hook.rb:58:in `call_hook'
lib/redmine/hook.rb:96:in `call_hook'
app/views/layouts/base.html.erb:16:in `_app_views_layouts_base_html_erb___730169334_23247228'
lib/redmine/sudo_mode.rb:63:in `sudo_mode'

Started GET "/redmine/projects/XXXXXXXXXXX/wiki/%E3%83?%E3%83?%E3%82?%E9%9B%86"
 for aaa.aaa.aaa.aaa at 2019-07-23 15:56:03 +0900
Processing by WikiController#show as HTML
  Parameters: {"project_id"=>"XXXXXXXXXXX", "id"=>"リンク集"}
  Current user: ********* (id=11)
  Rendering wiki/show.html.erb within layouts/base
  Rendered wiki/_content.html.erb (19.1ms)
  Rendered attachments/_form.html.erb (1.1ms)
  Rendered wiki/_sidebar.html.erb (1.2ms)
  Rendered wiki/show.html.erb within layouts/base (31.0ms)
Completed 200 OK in 86ms (Views: 42.3ms | ActiveRecord: 34.2ms)

from redmine-view-customize.

@onozaty
すみません、今更なのですが…
ブラウザはIE11（11.0.9600.19400）を使っていて発生しておりました。
試しにChrome（75.0.3770.142）を使ってみたところ… 本事象は発生しませんでした。

IE11（11.0.9600.19400）だとアドレスバーのURLは以下だったのですが…
http://xxx.xxx.xxx.xxx/redmine/projects/XXXXXXXXXXX/wiki/%E3%83%AA%E3%83%B3%E3%82%AF%E9%9B%86

Chrome（75.0.3770.142）のアドレスバーのURLは以下となっており異なっておりました。
http://xxx.xxx.xxx.xxx/redmine/projects/XXXXXXXXXXX/wiki/リンク集

※IE11は動作対象外ということであれば申し訳ございません。

from redmine-view-customize.

@you2mura
情報ありがとうございます。

もともとの問題箇所は回避できたようですが、その先でエラーとなってしまいました。
追加で対応を考えたいと思います。

※IE11は動作対象外ということであれば申し訳ございません。

Redmineが動作するブラウザであれば、View customizeとしても動作するようにしておくべきだとおもっていますので、対応したいと思います。

いろいろお手数、ご迷惑をおかけして申し訳ございません。

from redmine-view-customize.

@you2mura
対応しました。同じbranchを更新しています。
バージョンは2.3.0.40-2としています。

お手数ですが、再度ご確認いただけますでしょうか。

from redmine-view-customize.

@onozaty
ご対応感謝です。
明日、確認可能なので結果をご報告したいと思います。

from redmine-view-customize.

@onozaty
結果はOKでした。
該当リンクの連打するなどの操作にてエラー再現を試みましたが…
エラーは発生しなくなりました。
半日ほど運用した程度ではございますがエラーログもないです。
しばらくこの状態で運用を続けたいと思います。

from redmine-view-customize.

@you2mura
ご確認ありがとうございます。
様子を見ていただき、問題なさそうでしたら、リリースしようと思います。

from redmine-view-customize.

v2.4.0として対応したものをリリースしました。

from redmine-view-customize.