In the last several days, I noticed many forms of warning during test of debug version of the form: ``` 4:04.07 GECKO(10206) [Parent 10206, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 ``` The warning are visible in other people's debug version tests on try-com-central. See, for example, Geoff's job: https://treeherder.mozilla.org/jobs?repo=try-comm-central&selectedTaskRun=CFiSiwt3Tbao5Pzmc6ujZg.0&revision=0c1e010093278608ba5fec2f6e0eee879ce6ccb0 bct1, live.log https://firefoxci.taskcluster-artifacts.net/CFiSiwt3Tbao5Pzmc6ujZg/0/public/logs/live_backing.log The lines are so many and easily noticeable. About a week ago, it appeared 503 times during local mochitest, and 326 times during xpcshell test. I am running xpcshell tests with "--serialize --verbose" switches to capture these warning and error messages. ``` ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ grep "Malformed header" /FF-NEW/log1392-mochitest-12.txt | wc 503 7042 86406 ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ grep "Malformed header" /FF-NEW/log1393-xpctest-12.txt | wc 326 4564 55094 ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ ``` I got worried since I am testing bufferred-write and other I/O related patches locally and I thought I broke TB, but it turns out TB without my patches showed the same behavior as I explained at the beginning of my post. Other people's debug builds spew out same warnings. I got curious and modified HeaderReader.h as follows and tried to capture the unrecognized lines. ``` diff --git a/mailnews/base/src/HeaderReader.h b/mailnews/base/src/HeaderReader.h --- a/mailnews/base/src/HeaderReader.h +++ b/mailnews/base/src/HeaderReader.h @@ -257,16 +257,32 @@ bool HeaderReader::HandleLine(mozilla::S mHdr = Hdr(); } auto colon = std::find(line.cbegin(), line.cend(), ':'); if (colon == line.cend()) { // UHOH. We were expecting a "name: value" line, but didn't find one. // Just ignore this line. NS_WARNING("Malformed header (expected 'name: value')"); +#ifdef DEBUG + { + auto start = line.cbegin(); + fflush(stdout); + printf("{debug} line-> '"); + + // I am lazy to find out more about std span data type and its + // associated operation. + long unsigned i = 1; + for (; i <= line.Length() && start < line.cend() && *start != '\0'; start++, i++) { + printf("%c", *start); + } + printf("'\n"); + } +#endif + mPos += line.Length(); return keepGoing; } auto val = colon + 1; if (*val == ' ' || *val == '\t') { // Skip single leading whitespace. ++val; } ``` The result is revealing. The following is the first such output lines from a modified xpcshell test run. ``` 0:06.21 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.21 pid:201682 {debug} line-> 'From chris@clarke.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From emily@ekberg.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From gillian@gilbert.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From idina@ivarsson.invalid 0:06.22 pid:201682 ' ``` It seems that the code does not handle the mbox-format well. Each message block in mbox-format file starts with the first line of the following form. ```From sender-email-address ``` That is, it contains NO COLON at all. Here is the start of a real-world mbox file. ``` From root@vm-debian-amd64.example.com Tue Nov 12 00:35:17 2013 Return-path: <root@vm-debian-amd64.example.com> Envelope-to: root@vm-debian-amd64.example.com Delivery-date: Tue, 12 Nov 2013 00:35:17 +0900 Received: from root by vm-debian-amd64.example.com with local (Exim 4.80) (envelope-from <root@vm-debian-amd64.example.com>) id 1VftWH-0006rx-Jp for root@vm-debian-amd64.example.com; Tue, 12 Nov 2013 00:35:17 +0900 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: 7bit Auto-Submitted: auto-generated Subject: apt-listchanges: news for vm-debian-amd64 To: root@vm-debian-amd64.example.com Message-Id: <E1VftWH-0006rx-Jp@vm-debian-amd64.example.com> From: root <root@vm-debian-amd64.example.com> Date: Tue, 12 Nov 2013 00:35:17 +0900 Status: RO libhtml-tree-perl (5.03-1) unstable; urgency=low [rest omitted] ``` (I unwisely used example.com for internal home LAN domain back then. Subsequently I changed the name.) We should properly recognize these lines that start messages in an mbox file. I have no idea whether the failure to do so resulted in other unwanted warnings/errors. The code seems to have been modified lately in bug 1756520.
Bug 1762161 Comment 0 Edit History
Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.
In the last several days, I noticed many forms of warning during test of debug version of the form: ``` 4:04.07 GECKO(10206) [Parent 10206, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 ``` The warning are visible in other people's debug version tests on try-com-central. See, for example, Geoff's job: https://treeherder.mozilla.org/jobs?repo=try-comm-central&selectedTaskRun=CFiSiwt3Tbao5Pzmc6ujZg.0&revision=0c1e010093278608ba5fec2f6e0eee879ce6ccb0 bct1, live.log https://firefoxci.taskcluster-artifacts.net/CFiSiwt3Tbao5Pzmc6ujZg/0/public/logs/live_backing.log The lines are so many and easily noticeable. About a week ago, it appeared 503 times during local mochitest, and 326 times during xpcshell test. I am running xpcshell tests with "--serialize --verbose" switches to capture these warning and error messages. ``` ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ grep "Malformed header" /FF-NEW/log1392-mochitest-12.txt | wc 503 7042 86406 ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ grep "Malformed header" /FF-NEW/log1393-xpctest-12.txt | wc 326 4564 55094 ishikawa@ip030:/NREF-COMM-CENTRAL/mozilla$ ``` I got worried since I am testing bufferred-write and other I/O related patches locally and I thought I broke TB, but it turns out TB without my patches showed the same behavior as I explained at the beginning of my post. Other people's debug builds spew out same warnings. I got curious and modified HeaderReader.h as follows and tried to capture the unrecognized lines. ``` diff --git a/mailnews/base/src/HeaderReader.h b/mailnews/base/src/HeaderReader.h --- a/mailnews/base/src/HeaderReader.h +++ b/mailnews/base/src/HeaderReader.h @@ -257,16 +257,32 @@ bool HeaderReader::HandleLine(mozilla::S mHdr = Hdr(); } auto colon = std::find(line.cbegin(), line.cend(), ':'); if (colon == line.cend()) { // UHOH. We were expecting a "name: value" line, but didn't find one. // Just ignore this line. NS_WARNING("Malformed header (expected 'name: value')"); +#ifdef DEBUG + { + auto start = line.cbegin(); + fflush(stdout); + printf("{debug} line-> '"); + + // I am lazy to find out more about std span data type and its + // associated operation. + long unsigned i = 1; + for (; i <= line.Length() && start < line.cend() && *start != '\0'; start++, i++) { + printf("%c", *start); + } + printf("'\n"); + } +#endif + mPos += line.Length(); return keepGoing; } auto val = colon + 1; if (*val == ' ' || *val == '\t') { // Skip single leading whitespace. ++val; } ``` The result is revealing. The following is the first such output lines from a modified xpcshell test run. ``` 0:06.21 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.21 pid:201682 {debug} line-> 'From chris@clarke.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From emily@ekberg.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From gillian@gilbert.invalid 0:06.22 pid:201682 ' 0:06.22 pid:201682 [Parent 201682, Main Thread] WARNING: Malformed header (expected 'name: value'): file /NEW-SSD/moz-obj-dir/objdir-tb3/dist/include/HeaderReader.h:264 0:06.22 pid:201682 {debug} line-> 'From idina@ivarsson.invalid 0:06.22 pid:201682 ' ``` It seems that the code does not handle the mbox-format well. Each message block in mbox-format file starts with the first line of the following form. ``` From sender-email-address ``` That is, it contains NO COLON at all. Here is the start of a real-world mbox file. ``` From root@vm-debian-amd64.example.com Tue Nov 12 00:35:17 2013 Return-path: <root@vm-debian-amd64.example.com> Envelope-to: root@vm-debian-amd64.example.com Delivery-date: Tue, 12 Nov 2013 00:35:17 +0900 Received: from root by vm-debian-amd64.example.com with local (Exim 4.80) (envelope-from <root@vm-debian-amd64.example.com>) id 1VftWH-0006rx-Jp for root@vm-debian-amd64.example.com; Tue, 12 Nov 2013 00:35:17 +0900 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: 7bit Auto-Submitted: auto-generated Subject: apt-listchanges: news for vm-debian-amd64 To: root@vm-debian-amd64.example.com Message-Id: <E1VftWH-0006rx-Jp@vm-debian-amd64.example.com> From: root <root@vm-debian-amd64.example.com> Date: Tue, 12 Nov 2013 00:35:17 +0900 Status: RO libhtml-tree-perl (5.03-1) unstable; urgency=low [rest omitted] ``` (I unwisely used example.com for internal home LAN domain back then. Subsequently I changed the name.) We should properly recognize these lines that start messages in an mbox file. I have no idea whether the failure to do so resulted in other unwanted warnings/errors. The code seems to have been modified lately in bug 1756520.