March 2021 - dovecot - dovecot.org

json_parse_number broken by compiler optimization
by Christian Ehrhardt 13 Apr '21

13 Apr '21

Hi, the recent Ubuntu (re)builds uncovered an issue with dovecot 1:2.3.13+dfsg1-1 build log: https://launchpadlibrarian.net/529849650/buildlog_ubuntu-hirsute-amd64.dove… A coworker tried 2.3.14 but got the same result. What fails is the json_parser build time test like: test-json-parser.c:161: Assert(#25) failed: null_strcmp(json_output[pos].value, value) == 0 I was looking into that a bit more and what I found is that it is dependent on the new toolchain of gcc 10.2.0-1. Not all calls to json_parse_* fail, e.g. the first one looks all good and passes I was iterating the tests using a report function defined like (gdb) define repcon >c >p pos >p json_output[pos].type >p type >p json_output[pos].value >p value >call null_strcmp(json_output[pos].value, value) >end The first one to be bad was: Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:161 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $84 = 25 $85 = JSON_TYPE_NUMBER $86 = JSON_TYPE_NUMBER $87 = 0x555555633b25 "-12.456" $88 = 0x555555693110 "" $89 = 45 Earlier and later parsing was happy, for example Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:161 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $90 = 27 $91 = JSON_TYPE_NUMBER $92 = JSON_TYPE_NUMBER $93 = 0x555555633b32 "12.456e9" $94 = 0x555555693110 "12.456e9" $95 = 0 (gdb) We have two things we compare here. 1. json_output[] which is a static define and for this value is 67 »···{ JSON_TYPE_NUMBER, "-12.456" }, 2. the return value that json_parse_next returns. 25 »···" \"sub2\":-12.456,\n" 148 »···»···»···»···ret = json_parse_next(parser, &type, &value); I tried a non negative number and got success which is suspicious Breakpoint 5, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:164 164 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $122 = 25 $123 = JSON_TYPE_NUMBER $124 = JSON_TYPE_NUMBER $125 = 0x555555633b2c "12.456" $126 = 0x555555693110 "12.456" $127 = 0 (gdb) Also the return value otherwise LGTM, it is recognized as a number: 540 } else if ((ret = json_parse_number(parser, value_r)) >= 0) { (gdb) n 541 *type_r = JSON_TYPE_NUMBER; So parsing worked one might think, but the value was not set. (gdb) p *value_r $833 = 0x555555693110 "" It turns out json_parse_number is too optimized. Too optimized for debugging further into json_parse_number. But also optimization is causing the issue. With -O0 or -O1 it works fine, even putting the lower optimization level just around json_parse_number it is enough to avoid the issue. Not a fix but "avoidance" for now: --- a/src/lib/json-parser.c +++ b/src/lib/json-parser.c @@ -386,6 +386,8 @@ static int json_parse_int(struct json_pa return 1; } +#pragma GCC push_options +#pragma GCC optimize ("-O0") static int json_parse_number(struct json_parser *parser, const char **value_r) { int ret; @@ -415,6 +417,7 @@ static int json_parse_number(struct json *value_r = str_c(parser->value); return 1; } +#pragma GCC pop_options static int json_parse_atom(struct json_parser *parser, const char *atom) { I was trying to see what happened and tracked each str_append_c that happened inside json_parse_number. A breakpoint on str_append_c and backtraces showed that we clearly do the "right" parsing. From the backtraces I've seen it does (just from positions): For example (gdb) bt #0 str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 #1 json_parse_digits (parser=<optimized out>) at json-parser.c:366 => that is a digit It does "- digit digit dot digit digit digit" This perfectly matches the input value, but still the result stays empty: (gdb) p (char*)(str->data) $738 = 0x555555693110 "" In comparison - when parsing the latter 12.456e9 which works I see two odd things: 1. the value isn't cleared despite str_truncate(parser->value, 0); at the beginning of json_parse_number 2. the value (this time) is read exactly as I assumed Breakpoint 17, json_parse_number (value_r=0x7fffffffe1a0, parser=0x555555692ee0) at json-parser.c:394 394 str_truncate(parser->value, 0); Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 44 buffer_append_c(str, chr); (gdb) p (char*)(str->data) $741 = 0x555555693110 "sub3" ^^ not cleared, still has "sub3" even later on Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 44 buffer_append_c(str, chr); (gdb) p (char*)(str->data) $742 = 0x555555693110 "1ub3" ^^ reading left to right one char at a time "over the old value", which didn't update the data. So it seems in json_parse_number the ordering of a) str_truncate(parser->value, 0); b) the parsing itself is messed up by optimization. We already know from the above that reducing just this function to -O1 or less avoids the issue. But what is it really - I don't know? Maybe you have a better idea what is going on, the issue should be reproducible when building dovecot with the toolchain present on the latest Ubuntu being 21.04 (Hirsute) right now. -- Christian Ehrhardt Staff Engineer, Ubuntu Server Canonical Ltd

4 8

Quota - Invalid bytes limit
by Gonzalo Palacios Goicolea 08 Apr '21

08 Apr '21

Hi All, Since upgrading to RHEL7 and dovecot-2.2.36-8.el7.x86_64 we're not able to get quota warnings work. We get the error "User initialization failed: Failed to initialize quota: Invalid quota root quota: Invalid rule *:bytes=: Invalid bytes limit:" /mar 16 10:29:27 lda(user@domain): Quota: Executing warning: quota-warning 90 user@domain// //Mar 16 10:29:27 buzonn5 gonzalo: mar 16 10:29:27 lda(user@domain): Quota: Executing warning: quota-warning 90 user@domain// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Loading modules from directory: /usr/lib64/dovecot// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Module loaded: /usr/lib64/dovecot/lib20_mail_log_plugin.so// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: auth USER input: user@domain home=/buzones/externos/4/215283255776546 uid=508 gid=503 quota_rule=*:bytes=2147483648// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Ignoring overridden (-o) userdb setting: plugin/quota_rule// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Effective uid=508, gid=503, home=/buzones/externos/4/215283255776546// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Quota root: name=_backup backend=maildir args=ns=// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Debug: Quota rule: root=_backup mailbox=* bytes=0 messages=0// //Mar 16 10:29:27 buzonn5 dovecot: lda(user@domain): Error: User initialization failed: Failed to initialize quota: Invalid quota root quota: Invalid rule *:bytes=: Invalid bytes limit:// //Mar 16 10:29:27 buzonn5 dovecot: lda: Fatal: Invalid user settings. Refer to server log for more information./ This is the quota-warning script: /#!/bin/sh// //#Variables// //PERCENT=$1// //USER=$2// //FECHA=`date '+%b %d %H:%M:%S'`// // //#Logueo del evento// //echo "$FECHA lda($USER): Quota: Executing warning: quota-warning $PERCENT $USER" >> /var/log/dovecot/dovecot.log// //logger -p local1.notice -f /var/log/dovecot/dovecot.log "$FECHA lda($USER): Quota: Executing warning: quota-warning $PERCENT $USER"// // //cat << EOF | /usr/libexec/dovecot/dovecot-lda -d $USER -o "plugin/quota_rule=*:bytes=%$"// //From: postmaster at domain// //Subject: Alerta de Capacidad// //Date: `date`// // //El espacio asignado para el almacenamiento de su correo ha superado el $PERCENT% de su capacidad total. Por ello, se recomienda que elimine correos y/o vacie la papelera para liberar espacio.// //Mensaje enviado desde `hostname`// // //Atentamente,// // //--// //Responsable correo // //postmaster at domain// // //EOF// / ----------------------------- This is 90-quota.conf /plugin {// // quota = maildir:_backup:ns=// //}// // //plugin {// // quota_exceeded_message = El espacio asignado para el almacenamiento del correo del destinatario ha superado su capacidad total. Por ello, el correo que usted intenta enviar no se puede entregar al destinatario.// // quota_warning = storage=70%% quota-warning 70 %u// // quota_warning1 = storage=90%% quota-warning 90 %u// // quota_warning2 = storage=95%% quota-warning 95 %u// // quota_warning3 = storage=99%% quota-warning 99 %u// //}// // //service quota-warning {// // executable = script /etc/dovecot/scripts_notification_quota/quota-warning.sh// // user = vmail// // unix_listener quota-warning {// // user = vmail// // }// //}/ Getting user attibutes and quota with doveadms works right: /# doveadm user user@domain// //field value// //uid 508// //gid 503// //home /buzones/externos/4/215283255776546// //mail maildir:/buzones/externos/4/215283255776546/Maildir// //quota_rule *:bytes=2147483648// //# doveadm quota get -u user@domain// //Quota name Type Value Limit %// //_backup STORAGE 1153093 2097152 54// //_backup MESSAGE 44347 - / It also works fine with ldapsearch /# ldapsearch -x -D "cn=mail_admin,cn=users,dc=domain,dc=es" -w ********** -b "dc=domain,dc=es" -h ldap.host mail=user@domain mailquotasize// //# extended LDIF// //#// //# LDAPv3// //# base <dc=domain,dc=es> with scope subtree// //# filter: mail=user@domain// //# requesting: mailquotasize// //#// // //# user@domain, users, domain.es// //dn: cn=user@domain,cn=users,dc=domain,dc=es// //mailquotasize: 2147483648/ I've been googling but I can't find where the problem may be. Can you please help me? This is the whole config: /doveconf -n// //# 2.2.36 (1f10bfa63): /etc/dovecot/dovecot.conf// //# Pigeonhole version 0.4.24 (124e06aa)// //# OS: Linux 3.10.0-1160.6.1.el7.x86_64 x86_64 Red Hat Enterprise Linux Server release 7.9 (Maipo)// //# Hostname: host.domain// //auth_cache_negative_ttl = 5 mins// //auth_cache_size = 500 M// //auth_cache_ttl = 5 mins// //auth_failure_delay = 5 secs// //default_vsz_limit = 1 G// //disable_plaintext_auth = no// //hostname = host.domain// //imap_logout_format = in(bytes read)=%i out(bytes sent)=%o// //listen = *// //lock_method = dotlock// //mail_fsync = always// //mail_location = maildir:%h/Maildir// //mail_nfs_index = yes// //mail_nfs_storage = yes// //mail_plugins = " quota mail_log notify"// //managesieve_notify_capability = mailto// //managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext imapflags notify// //mbox_write_locks = fcntl// //mmap_disable = yes// //namespace {// // location = maildir:%h/Maildir/_backup// // prefix = _backup.// // separator = .// // type = private// //}// //namespace inbox {// // inbox = yes// // location =// // mailbox Drafts {// // special_use = \Drafts// // }// // mailbox Junk {// // special_use = \Junk// // }// // mailbox Sent {// // special_use = \Sent// // }// // mailbox "Sent Messages" {// // special_use = \Sent// // }// // mailbox Trash {// // special_use = \Trash// // }// // prefix =// //}// //passdb {// // args = /etc/dovecot/dovecot-ldap.conf.ext// // driver = ldap// //}// //plugin {// // mail_log_events = delete undelete expunge mailbox_delete mailbox_rename mailbox_create save// // mail_log_fields = uid box msgid from subject// // quota = maildir:_backup:ns=// // quota_exceeded_message = El espacio asignado para el almacenamiento del correo del destinatario ha superado su capacidad total. Por ello, el correo que usted intenta enviar no se puede entregar al destinatario.// // quota_warning = storage=70%% quota-warning 70 %u// // quota_warning1 = storage=90%% quota-warning 90 %u// // quota_warning2 = storage=95%% quota-warning 95 %u// // quota_warning3 = storage=99%% quota-warning 99 %u// // sieve = ~/.dovecot.sieve// // sieve_dir = ~/Maildir/sieve// // sieve_extensions = +notify +imapflags// //}// //postmaster_address = postmaster@domain// //protocols = imap pop3 sieve// //service auth {// // unix_listener auth-userdb {// // group = vmail// // mode = 0777// // user = vmail// // }// //}// //service imap-login {// // inet_listener imap {// // port = 143// // }// // process_min_avail = 20// //}// //service imap {// // process_limit = 2048// //}// //service managesieve-login {// // inet_listener sieve {// // port = 4190// // }// // inet_listener sieve_deprecated {// // port = 2000// // }// // process_min_avail = 20// //}// //service pop3-login {// // inet_listener pop3 {// // port = 110// // }// // process_min_avail = 20// //}// //service pop3 {// // process_limit = 2048// //}// //service quota-warning {// // executable = script /etc/dovecot/scripts_notification_quota/quota-warning.sh// // unix_listener quota-warning {// // user = vmail// // }// // user = vmail// //}// //ssl = no// //ssl_cert = </etc/pki/dovecot/certs/dovecot.pem// //ssl_key = # hidden, use -P to show it// //submission_host = smtpi.domain:25// //syslog_facility = local1// //userdb {// // args = /etc/dovecot/dovecot-ldap.conf.ext// // driver = ldap// //}// //protocol lda {// // mail_plugins = " quota mail_log notify sieve"// //}// //protocol imap {// // mail_max_userip_connections = 10000// // mail_plugins = " quota mail_log notify imap_quota"// //}// //protocol pop3 {// // mail_max_userip_connections = 10// //}/ Thanks and best regards -- *Gonzalo Palacios Goicolea* U.T de Infraestructura de Equipos Centrales /Tecnologías de la Información/ Universidad Autónoma de Madrid • Campus de Cantoblanco Antes de imprimir este correo piense si es necesario.Cuidemos el medioambiente.

2 4

[Sieve] Understand Sieve processing
by h8h 07 Apr '21

07 Apr '21

Hi, I have the following configuration: > cat > /etc/dovecot/conf.d/99-local-sieve.conf << EOF; > plugin { > sieve_before = /etc/dovecot/sieve-spam.sieve > sieve_before2 = /mail/sieve/global_before > sieve_after = /mail/sieve/global_after > sieve = /mail/sieve/%d/%n.sieve > sieve_dir = /mail/sieve/%d/%n > } > EOF > cat /etc/dovecot/sieve-spam.sieve > require ["regex", "fileinto", "imap4flags"]; > > if allof (header :regex "X-Spam-Status" "^Yes") { > fileinto "Spam"; > } (I removed the keyword "stop;" to proceed rule processing, which does not work) Now as a user (/mail/sieve/%d/%n.sieve) I want to create my own "Spam" rule: > require ["regex","reject"]; > # rule:[SPAM] > if allof (header :regex "x-spam-status" "^Yes") > { > reject text: > This E-Mail is SPAM. > . > ; > } I activate the traces and see the following if the e-mail is SPAM: > ## Started executing script 'sieve-spam' > 3: jump if result is false > 3: not jumping > 4: fileinto action > 4: store message in mailbox `Spam' > ## Finished executing script 'sieve-spam' If the e-mail is not SPAM: > ## Started executing script 'sieve-spam' > 3: jump if result is false > 3: jumping to line 4 > ## Finished executing script 'sieve-spam' > > > ## Started executing script 'roundcube' > 3: jump if result is false > 3: jumping to line 10 > ## Finished executing script 'roundcube' So my sieve gets only executed if the e-mail is not SPAM. Thats a bit odd. Could you explain how the sieve processing work and how I can solve this problem? dovecot --version 2.2.33.2 (d6601f4ec) on Ubuntu 18.04 LTS Best regards Homy

2 1

Question about doveadm altmove
by María Arrea 05 Apr '21

05 Apr '21

4 4

Mass Stripping Attachments by Directory, Age, Size
by Plutocrat 05 Apr '21

05 Apr '21

Hi, I've been looking around for a solution to this problem. I want to prune down the attachments on a server before a migration. Some of the emails are 7 years old and have 40Mb attachments, so this seems like a good opportunity to rationalize things. So perhaps I'd like to "Remove all attachments from emails older than 2 years, in the .Sent directory", or "Attachments over 10Mb anywhere in the mail tree" I've found the strip_attachments.pl script here <https://fossies.org/linux/Mail-Box/examples/strip-attachments.pl> which works fine on mbox (as tested on my local Thunderbird mboxes), but not on maildir which is on the dovecot server. My Perl isn't strong enough to re-purpose it. I've looked at ripmime and mpack/munpack, and although they seem like useful tools to do the job of deconstructing the mail into its constituent parts, it doesn't seem to help in re-building the email. I think they could be used with a bit of study into mail MIME structure, and used with a helper script. So before I take a deep dive into scripting my own solution, I just wanted to check if anyone else on the list has been through this and has some resources or pointers they can share, or maybe even someone to tell me "Duh, you can do it with doveadm of course". P.

5 8

Virtual folders and mailbox_list_get_root_forced
by Joan Moreau 02 Apr '21

02 Apr '21

Hi The function mailbox_list_get_root_forced returns sometimes the first or the second value of the INDEX param for the same mailbox. How to make sure this returns only the correct one of the corresponding mailbox ? mail_location = maildir:/var/vmail/%d/%n:LAYOUT=fs:INDEX=/var/mailindex namespace { location = virtual:/nix/store/toto-virtual:INDEX=/var/vmail/%d/%n/virtual prefix = virtual/ separator = / subscriptions = no } Thank you

2 5

Replicator: getting full resync requests to sync
by Norman King 31 Mar '21

31 Mar '21

Hello. I'm getting the following output. root@mail:~# doveadm replicator status Queued 'sync' requests 0 Queued 'high' requests 0 Queued 'low' requests 0 Queued 'failed' requests 0 Queued 'full resync' requests 61 Waiting 'failed' requests 4 How can i get the full resync requests to actually sync? Is there a configurable resync delay time that i can use to force a resync of these mailboxes? Also, is there a way using either doveadm replicator or doveadm sync that i can see all the full resync users? Thanks. -- regards Norman King Compass Foundation sysadmin/tech support Phone, 856-974-5335 ext 221 support(a)compassfoundation.io <mailto:support@compassfoundation.io> Website <https://compassfoundation.io>

1 0

RE: Dovecot 2.3.14 - Invalid mailbox name: Name must not have '/'
by Markus Valentin 31 Mar '21

31 Mar '21

> On 03/30/2021 8:25 PM Jürgen Edner <juergen(a)eisfair.org> wrote: > Hi @all, > can anyone please shed some light on the changes of v2.3.14 and what need to be done to get the shared folders working again as in v2.3.13. > I cannot see any invalid characters in the folder names. I would also appreciate any advise on how I can debug the program any further. Hi, can you provide us with the output of `doveconf -n` please? Markus

2 1

Temporary disable push notifications while restoring a mailbox
by Ralf Becker 31 Mar '21

31 Mar '21

We use "doveamd import" to restore mailboxes from a snapshot. Since we use push with Dovecot 2.3.13: mail_plugins = $mail_plugins mail_lua notify push_notification push_notification_lua plugin { push_notification_driver = lua:file=/etc/dovecot/dovecot-push.lua push_lua_url = http://172.17.0.1/ the import creates a flood of push-notifications. Therefore the questions: is there a possibility to disable push for "doveadm import" on the command line (not in general)? Kind regards Ralf -- Ralf Becker EGroupware GmbH [www.egroupware.org] Handelsregister HRB Kaiserslautern 3587 Geschäftsführer Birgit und Ralf Becker Leibnizstr. 17, 67663 Kaiserslautern, Germany Telefon +49 631 31657-0

2 1

Re:dovecot Digest, Vol 215, Issue 77
by 刘莹莹 31 Mar '21

31 Mar '21

------------------ Original ------------------ From: "dovecot" <dovecot-request(a)dovecot.org>; Date: Tue, Mar 30, 2021 11:55 PM To: "dovecot"<dovecot(a)dovecot.org>; Subject: dovecot Digest, Vol 215, Issue 77 Send dovecot mailing list submissions to dovecot(a)dovecot.org To subscribe or unsubscribe via the World Wide Web, visit https://dovecot.org/mailman/listinfo/dovecot or, via email, send a message with subject or body 'help' to dovecot-request(a)dovecot.org You can reach the person managing the list at dovecot-owner(a)dovecot.org When replying, please edit your Subject line so it is more specific than "Re: Contents of dovecot digest..." Today's Topics:    1. special characters in FTS Solr fail (piuma(a)piumalab.org)    2. json_parse_number broken by compiler optimization       (Christian Ehrhardt)    3. Re: json_parse_number broken by compiler optimization (Aki Tuomi) ---------------------------------------------------------------------- Message: 1 Date: Tue, 30 Mar 2021 16:20:56 +0200 From: "piuma(a)piumalab.org" <piuma(a)piumalab.org> To: dovecot(a)dovecot.org Subject: special characters in FTS Solr fail Message-ID: <3c779646-e2fc-9f51-063c-a8816450dbfd(a)piumalab.org> Content-Type: text/plain; charset="utf-8" Hi, I want to report a bug about searching. My dovecot version is 2.3.10.1 (a3d0e1171) and use Solr 7.7.2 for full text search. The issue appear when try to search using solr special characters. For example if I have emails with the subject that contain the only character "(" open parenthesis, then try to search it I receive zero results. In the Solr log seems the "(" is correctly excaped as "\(": 2021-03-30 15:14:20.304 INFO  (qtp333683827-20) [   x:dovecot] o.a.s.c.S.Request [dovecot]  webapp=/solr path=/select params={q={!lucene+q.op%3DAND}subject:\(&fl=uid,score&sort=uid+asc&fq=%2Bbox:6fff5821c5a2365df4060000d0d97f83+%2Buser:titolare01@kendama.it&rows=631&wt=xml} hits=0 status=0 QTime=2 I provide dovecot-sysreport as attachment. Best regards    Danilo -------------- next part -------------- A non-text attachment was scrubbed... Name: dovecot-sysreport-pecbox02.par-tec.it-1617116347.tar.gz Type: application/gzip Size: 7395 bytes Desc: not available URL: <https://dovecot.org/pipermail/dovecot/attachments/20210330/08492366/attachm… ------------------------------ Message: 2 Date: Tue, 30 Mar 2021 17:53:27 +0200 From: Christian Ehrhardt <christian.ehrhardt(a)canonical.com> To: dovecot(a)dovecot.org Subject: json_parse_number broken by compiler optimization Message-ID: <CAATJJ0JB9e4cZrS=hiM0r=yF4-Fz693ZK3qLa41L-rYVfy8QbQ(a)mail.gmail.com> Content-Type: text/plain; charset="UTF-8" Hi, the recent Ubuntu (re)builds uncovered an issue with dovecot 1:2.3.13+dfsg1-1 build log: https://launchpadlibrarian.net/529849650/buildlog_ubuntu-hirsute-amd64.dove… A coworker tried 2.3.14 but got the same result. What fails is the json_parser build time test like:   test-json-parser.c:161: Assert(#25) failed: null_strcmp(json_output[pos].value, value) == 0 I was looking into that a bit more and what I found is that it is dependent on the new toolchain of gcc 10.2.0-1. Not all calls to json_parse_* fail, e.g. the first one looks all good and passes I was iterating the tests using a report function defined like (gdb) define repcon >c >p pos >p json_output[pos].type >p type >p json_output[pos].value >p value >call null_strcmp(json_output[pos].value, value) >end The first one to be bad was: Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:161 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $84 = 25 $85 = JSON_TYPE_NUMBER $86 = JSON_TYPE_NUMBER $87 = 0x555555633b25 "-12.456" $88 = 0x555555693110 "" $89 = 45 Earlier and later parsing was happy, for example Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:161 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $90 = 27 $91 = JSON_TYPE_NUMBER $92 = JSON_TYPE_NUMBER $93 = 0x555555633b32 "12.456e9" $94 = 0x555555693110 "12.456e9" $95 = 0 (gdb) We have two things we compare here. 1. json_output[] which is a static define and for this value is    67 ????{ JSON_TYPE_NUMBER, "-12.456" }, 2. the return value that json_parse_next returns.    25 ????"  \"sub2\":-12.456,\n"   148 ????????????????ret = json_parse_next(parser, &type, &value); I tried a non negative number and got success which is suspicious Breakpoint 5, test_json_parser_success (full_size=<optimized out>) at test-json-parser.c:164 164 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); $122 = 25 $123 = JSON_TYPE_NUMBER $124 = JSON_TYPE_NUMBER $125 = 0x555555633b2c "12.456" $126 = 0x555555693110 "12.456" $127 = 0 (gdb) Also the return value otherwise LGTM, it is recognized as a number: 540 } else if ((ret = json_parse_number(parser, value_r)) >= 0) { (gdb) n 541 *type_r = JSON_TYPE_NUMBER; So parsing worked one might think, but the value was not set. (gdb) p *value_r $833 = 0x555555693110 "" It turns out json_parse_number is too optimized. Too optimized for debugging further into json_parse_number. But also optimization is causing the issue. With -O0 or -O1 it works fine, even putting the lower optimization level just around json_parse_number it is enough to avoid the issue. Not a fix but "avoidance" for now: --- a/src/lib/json-parser.c +++ b/src/lib/json-parser.c @@ -386,6 +386,8 @@ static int json_parse_int(struct json_pa   return 1;  } +#pragma GCC push_options +#pragma GCC optimize ("-O0")  static int json_parse_number(struct json_parser *parser, const char **value_r)  {   int ret; @@ -415,6 +417,7 @@ static int json_parse_number(struct json   *value_r = str_c(parser->value);   return 1;  } +#pragma GCC pop_options  static int json_parse_atom(struct json_parser *parser, const char *atom)  { I was trying to see what happened and tracked each str_append_c that happened inside json_parse_number. A breakpoint on str_append_c and backtraces showed that we clearly do the "right" parsing. From the backtraces I've seen it does (just from positions): For example (gdb) bt #0  str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 #1  json_parse_digits (parser=<optimized out>) at json-parser.c:366 => that is a digit It does "- digit digit dot digit digit digit" This perfectly matches the input value, but still the result stays empty: (gdb) p (char*)(str->data) $738 = 0x555555693110 "" In comparison - when parsing the latter 12.456e9 which works I see two odd things: 1. the value isn't cleared despite     str_truncate(parser->value, 0);    at the beginning of json_parse_number 2. the value (this time) is read exactly as I assumed Breakpoint 17, json_parse_number (value_r=0x7fffffffe1a0, parser=0x555555692ee0) at json-parser.c:394 394 str_truncate(parser->value, 0); Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 44 buffer_append_c(str, chr); (gdb) p (char*)(str->data) $741 = 0x555555693110 "sub3" ^^ not cleared, still has "sub3" even later on Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 44 buffer_append_c(str, chr); (gdb) p (char*)(str->data) $742 = 0x555555693110 "1ub3" ^^ reading left to right one char at a time "over the old value", which didn't update the data. So it seems in json_parse_number the ordering of a) str_truncate(parser->value, 0); b) the parsing itself is messed up by optimization. We already know from the above that reducing just this function to -O1 or less avoids the issue. But what is it really - I don't know? Maybe you have a better idea what is going on, the issue should be reproducible when building dovecot with the toolchain present on the latest Ubuntu being 21.04 (Hirsute) right now. -- Christian Ehrhardt Staff Engineer, Ubuntu Server Canonical Ltd ------------------------------ Message: 3 Date: Tue, 30 Mar 2021 18:55:44 +0300 (EEST) From: Aki Tuomi <aki.tuomi(a)open-xchange.com> To: Christian Ehrhardt <christian.ehrhardt(a)canonical.com>, dovecot(a)dovecot.org Subject: Re: json_parse_number broken by compiler optimization Message-ID: <1219230463.3728.1617119744636(a)appsuite-dev-gw1.open-xchange.com> Content-Type: text/plain; charset=UTF-8 > On 30/03/2021 18:53 Christian Ehrhardt <christian.ehrhardt(a)canonical.com> wrote: > >  > Hi, > the recent Ubuntu (re)builds uncovered an issue with dovecot 1:2.3.13+dfsg1-1 > build log: https://launchpadlibrarian.net/529849650/buildlog_ubuntu-hirsute-amd64.dove… > A coworker tried 2.3.14 but got the same result. > > What fails is the json_parser build time test like: >   test-json-parser.c:161: Assert(#25) failed: > null_strcmp(json_output[pos].value, value) == 0 > > I was looking into that a bit more and what I found is that it is > dependent on the new toolchain > of gcc 10.2.0-1. > > Not all calls to json_parse_* fail, e.g. the first one looks all good and passes > I was iterating the tests using a report function defined like > > (gdb) define repcon > >c > >p pos > >p json_output[pos].type > >p type > >p json_output[pos].value > >p value > >call null_strcmp(json_output[pos].value, value) > >end > > The first one to be bad was: > Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at > test-json-parser.c:161 > 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); > $84 = 25 > $85 = JSON_TYPE_NUMBER > $86 = JSON_TYPE_NUMBER > $87 = 0x555555633b25 "-12.456" > $88 = 0x555555693110 "" > $89 = 45 > > Earlier and later parsing was happy, for example > > Breakpoint 2, test_json_parser_success (full_size=<optimized out>) at > test-json-parser.c:161 > 161 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); > $90 = 27 > $91 = JSON_TYPE_NUMBER > $92 = JSON_TYPE_NUMBER > $93 = 0x555555633b32 "12.456e9" > $94 = 0x555555693110 "12.456e9" > $95 = 0 > (gdb) > > > We have two things we compare here. > 1. json_output[] which is a static define and for this value is >    67 ????{ JSON_TYPE_NUMBER, "-12.456" }, > 2. the return value that json_parse_next returns. >    25 ????"  \"sub2\":-12.456,\n" >   148 ????????????????ret = json_parse_next(parser, &type, &value); > > I tried a non negative number and got success which is suspicious > > Breakpoint 5, test_json_parser_success (full_size=<optimized out>) at > test-json-parser.c:164 > 164 test_assert_idx(null_strcmp(json_output[pos].value, value) == 0, pos); > $122 = 25 > $123 = JSON_TYPE_NUMBER > $124 = JSON_TYPE_NUMBER > $125 = 0x555555633b2c "12.456" > $126 = 0x555555693110 "12.456" > $127 = 0 > (gdb) > > > Also the return value otherwise LGTM, it is recognized as a number: > 540 } else if ((ret = json_parse_number(parser, value_r)) >= 0) { > (gdb) n > 541 *type_r = JSON_TYPE_NUMBER; > > So parsing worked one might think, but the value was not set. > > (gdb) p *value_r > $833 = 0x555555693110 "" > > It turns out json_parse_number is too optimized. > Too optimized for debugging further into json_parse_number. > But also optimization is causing the issue. > With -O0 or -O1 it works fine, even putting the lower optimization > level just around json_parse_number it is enough to avoid the issue. > > > Not a fix but "avoidance" for now: > > --- a/src/lib/json-parser.c > +++ b/src/lib/json-parser.c > @@ -386,6 +386,8 @@ static int json_parse_int(struct json_pa >   return 1; >  } > > +#pragma GCC push_options > +#pragma GCC optimize ("-O0") >  static int json_parse_number(struct json_parser *parser, const char **value_r) >  { >   int ret; > @@ -415,6 +417,7 @@ static int json_parse_number(struct json >   *value_r = str_c(parser->value); >   return 1; >  } > +#pragma GCC pop_options > >  static int json_parse_atom(struct json_parser *parser, const char *atom) >  { > > > I was trying to see what happened and tracked each str_append_c > that happened inside json_parse_number. > A breakpoint on str_append_c and backtraces showed that we clearly do the > "right" parsing. From the backtraces I've seen it does (just from positions): > > For example > (gdb) bt > #0  str_append_c (chr=<optimized out>, str=0x5555556930d0) at str.h:44 > #1  json_parse_digits (parser=<optimized out>) at json-parser.c:366 > => that is a digit > > It does "- digit digit dot digit digit digit" > > This perfectly matches the input value, but still the result stays empty: > (gdb) p (char*)(str->data) > $738 = 0x555555693110 "" > > In comparison - when parsing the latter 12.456e9 which works I see two > odd things: > 1. the value isn't cleared despite >     str_truncate(parser->value, 0); >    at the beginning of json_parse_number > 2. the value (this time) is read exactly as I assumed > > Breakpoint 17, json_parse_number (value_r=0x7fffffffe1a0, > parser=0x555555692ee0) at json-parser.c:394 > 394 str_truncate(parser->value, 0); > Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) > at str.h:44 > 44 buffer_append_c(str, chr); > (gdb) p (char*)(str->data) > $741 = 0x555555693110 "sub3" > > ^^ not cleared, still has "sub3" even later on > > Breakpoint 18, str_append_c (chr=<optimized out>, str=0x5555556930d0) > at str.h:44 > 44 buffer_append_c(str, chr); > (gdb) p (char*)(str->data) > $742 = 0x555555693110 "1ub3" > > ^^ reading left to right one char at a time "over the old value", > which didn't update the data. > > So it seems in json_parse_number the ordering of > a) str_truncate(parser->value, 0); > b) the parsing itself > is messed up by optimization. > > We already know from the above that reducing just this function to -O1 or less > avoids the issue. But what is it really - I don't know? > > Maybe you have a better idea what is going on, the issue should be > reproducible when building > dovecot with the toolchain present on the latest Ubuntu being 21.04 > (Hirsute) right now. > > -- > Christian Ehrhardt > Staff Engineer, Ubuntu Server > Canonical Ltd Thanks! We'll look into this. Aki ------------------------------ Subject: Digest Footer _______________________________________________ dovecot mailing list dovecot(a)dovecot.org https://dovecot.org/mailman/listinfo/dovecot ------------------------------ End of dovecot Digest, Vol 215, Issue 77 ****************************************

1 0