Mysql2::Error: Incorrect string value: '\xE9..' for column `postal-server-4`.`messages`.`subject` at row 1 · Issue #1636 · postalserver/postal · GitHub
Skip to content

Mysql2::Error: Incorrect string value: '\xE9..' for column postal-server-4.messages.subject at row 1 #1636

Closed
#3594
Closed
Mysql2::Error: Incorrect string value: '\xE9..' for column postal-server-4.messages.subject at row 1#1636
#3594
Labels
bug

Description

@omueller
omueller
opened on Oct 8, 2021

Describe the bug

Mail will not be accepted if it is in ISO-8859 format and the Subject contain special chars. It seems similar to #588 which was fixed in #391 ("Message database default character set utf8mb4"), but in this case it is a recent Postal server (a few months old, just before the docker-based version) and all databases/tables are using the utf8mb4 encoding (select * from information_schema.columns where table_name LIKE 'messages' and column_name like 'subject' in DB postal-server-4 shows utf8mb4 / utf8mb4_unicode_ci as CHARACTER_SET_NAME / COLLATION_NAME).

This happened to us for mails sent via a simple php application to postfix, then using postal as a relay.

To Reproduce

  1. copy this to a file named mailtest.sh:
#!/bin/bash

{
	sleep 2
	echo 'ehlo example.org'
	sleep 2
	echo 'mail from: sender@example.org'
	sleep 1
	echo 'rcpt to: target@example.com'
	sleep 1
	echo 'DATA'
	sleep 1
	echo 'To: target@example.com'
	echo 'Subject: Votre livraison de blé cette semaine'
	echo 'From: sender@example.org'
	echo 'Content-type: text/plain; charset=iso-8859-1'
	echo 'Message-Id: <20210926192527.5301F10E1ACC@localhost>'
	echo 'Date: Sun, 26 Sep 2021 21:25:27 +0200 (CEST)'
	echo ''
	echo 'Bla Bla Bla'
	echo ''
	echo '.'
} | telnet postal.example.org 2525
  1. make sure it's iso-8859-1 encoded: with file:
$ file mailtest.sh
mailtest.sh: Bourne-Again shell script, ISO-8859 text executable
  1. if it is not the case, convert it :
$ file mailtest2.sh 
mailtest2.sh: Bourne-Again shell script, UTF-8 Unicode text executable
$ iconv -f UTF-8 -t ISO-8859-1 mailtest2.sh -o mailtest2_converted_iso.sh
$ file mailtest2_converted_iso.sh
mailtest2_converted_iso.sh: Bourne-Again shell script, ISO-8859 text executable
  1. run the shell script : ./mailtest.sh
  2. output in the postal server logs:
==> /opt/postal/log/smtp_server.log <==
[smtp.4:637963] [2021-10-08T17:36:36.695] DEBUG -- : [NN0HHF]    Connection opened from ::ffff:10.0.0.1
[smtp.4:637963] [2021-10-08T17:36:36.695] DEBUG -- : [NN0HHF]    Client identified as ::ffff:10.0.0.1
[smtp.4:637963] [2021-10-08T17:36:38.680] DEBUG -- : [NN0HHF] <= ehlo example.org
[smtp.4:637963] [2021-10-08T17:36:38.691] DEBUG -- : [NN0HHF] => 250-My capabilities are
[smtp.4:637963] [2021-10-08T17:36:38.692] DEBUG -- : [NN0HHF] => 250 AUTH CRAM-MD5 PLAIN LOGIN
[smtp.4:637963] [2021-10-08T17:36:40.682] DEBUG -- : [NN0HHF] <= mail from: sender@example.org
[smtp.4:637963] [2021-10-08T17:36:40.682] DEBUG -- : [NN0HHF] => 250 OK
[smtp.4:637963] [2021-10-08T17:36:41.683] DEBUG -- : [NN0HHF] <= rcpt to: target@example.com
[smtp.4:637963] [2021-10-08T17:36:41.694] DEBUG -- : [NN0HHF] Added external address 'target@example.org'
[smtp.4:637963] [2021-10-08T17:36:41.694] DEBUG -- : [NN0HHF] => 250 OK
[smtp.4:637963] [2021-10-08T17:36:42.685] DEBUG -- : [NN0HHF] <= DATA
[smtp.4:637963] [2021-10-08T17:36:42.685] DEBUG -- : [NN0HHF] => 354 Go ahead
[smtp.4:637963] [2021-10-08T17:36:43.686] DEBUG -- : [NN0HHF] <= To: target@example.com
[smtp.4:637963] [2021-10-08T17:36:43.686] DEBUG -- : [NN0HHF] Not logging further message data.
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] An error occurred while processing data from a client.
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] Mysql2::Error: Incorrect string value: '\xE9 cett...' for column `postal-server-4`.`messages`.`subject` at row 1
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/mysql2-0.5.3/lib/mysql2/client.rb:131:in `_query'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/mysql2-0.5.3/lib/mysql2/client.rb:131:in `block in query'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/mysql2-0.5.3/lib/mysql2/client.rb:130:in `handle_interrupt'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/mysql2-0.5.3/lib/mysql2/client.rb:130:in `query'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/database.rb:319:in `query_on_connection'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/database.rb:224:in `block in insert'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/mysql.rb:20:in `client'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/database.rb:342:in `with_mysql'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/database.rb:223:in `insert'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/message.rb:565:in `_create'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/message_db/message.rb:206:in `save'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/client.rb:428:in `block in finished'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/client.rb:414:in `each'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/client.rb:414:in `finished'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/client.rb:351:in `block in data'
[smtp.4:637963] [2021-10-08T17:36:43.700] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/client.rb:47:in `handle'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:160:in `block (2 levels) in run_event_loop'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:87:in `select'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:87:in `block in run_event_loop'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:85:in `loop'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:85:in `run_event_loop'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/postal/smtp_server/server.rb:260:in `run'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/app/lib/tasks/postal.rake:13:in `block (2 levels) in <top (required)>'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `block in execute'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `each'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `execute'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:214:in `block in invoke_with_call_chain'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /usr/local/rvm/rubies/ruby-2.5.8/lib/ruby/2.5.0/monitor.rb:235:in `mon_synchronize'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:194:in `invoke_with_call_chain'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/task.rb:183:in `invoke'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:160:in `invoke_task'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:116:in `block (2 levels) in top_level'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:116:in `each'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:116:in `block in top_level'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:125:in `run_with_threads'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:110:in `top_level'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:83:in `block in run'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:186:in `standard_exception_handling'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/lib/rake/application.rb:80:in `run'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/gems/rake-12.3.3/exe/rake:27:in `<top (required)>'
[smtp.4:637963] [2021-10-08T17:36:43.701] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/bin/rake:23:in `load'
[smtp.4:637963] [2021-10-08T17:36:43.702] ERROR -- : [NN0HHF] /opt/postal/vendor/bundle/ruby/2.5.0/bin/rake:23:in `<main>'
[smtp.4:637963] [2021-10-08T17:36:43.702] ERROR -- : [NN0HHF] /usr/local/rvm/gems/ruby-2.5.8/bin/ruby_executable_hooks:22:in `eval'
[smtp.4:637963] [2021-10-08T17:36:43.702] ERROR -- : [NN0HHF] /usr/local/rvm/gems/ruby-2.5.8/bin/ruby_executable_hooks:22:in `<main>'

Expected behaviour

Mail should be accepted.

Environment details

$ postal version
1.0.0-2595481b26-stable
$ postal status
Procodile Version 1.0.26
Application Root /opt/postal/app
$ ruby --version
ruby 2.5.8p224 (2020-03-31 revision 67882) [x86_64-linux]

Additional information/context

If somebody could test this against latest version it would be nice, I will try next week otherwise.

Please let me know if you miss any information, and I will update the ticket accordingly.
Thanks & best regards.

Activity

  1. omueller
    added
    bug
    on Oct 8, 2021

  2. adamcooke commented on Feb 14, 2022

    @adamcooke
    adamcooke
    on Feb 14, 2022
    Contributor

    I can't reproduce this.

  3. adamcooke
    closed this as completedon Feb 14, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bug

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions