1766058 - MOZ_CRASH and "Assertion failure" output sometimes scramble debug logs

Status: RESOLVED FIXED

(Core :: MFBT, defect)

Description

[Tyson Smith [:tsmith]]

When running a Windows debug build the debug output can periodically be scrambled by "MOZ_CRASH" and "Assertion failure" output.

Here are a couple examples, the rest of the log seems to be unaffected. I am unable to reproduce this locally (I'm guessing it is very timing dependent) but it happens enough to affect triage of fuzzing bugs.

Ass[2022-04-20T22:47:14Z WARN  webrender::space] parent relative transform can't transform the primitive rect for Box2D((50.0, 180.0), (842.65, 187.63333))
ertion failure: !OuterSVGIsCallingReflowSVG(aFrame) (Do not call under ISVGDisplayableFrame::ReflowSVG!), at /builds/worker/checkouts/gecko/layout/svg/SVGUtils.cpp:155
[2022-04-20T22:47:14Z WARN  webrender::space] parent relative transform can't transform the primitive rect for Box2D((16.0, 140.0), (881.65, 187.63333))

[Parent 6880, IndexedDB #7] WARNING: Suboptimal indexes for the SQL statement 0x22ee61ea9c0 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp:113
[Parent 6Hit M880, OZ_CRIndexeASH(dDBto #do7])  WatAR /NIbuNGil: dsSu/wboorptkeimr/alch iecndkoexutess/ fgeorck to/hedo Sm/QLwe sbgtapute/Cmeanntva 0sCx2on2etedbxtd5.h03:5008
 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp:113
[Parent 6880, IndexedDB #7] WARNING: Suboptimal indexes for the SQL statement 0x22ee61ea740 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp:113

Comment 1

[Andrew McCreight [:mccr8]]

I think the logging needs to use fprintf_stderr instead of printf to avoid this, at least in fuzzing builds.. This was a problem for a long time with the old DOMWINDOW++ logging, and that was how they fixed it. It looks like it has some trick to try to avoid the intermixing: "stderr is unbuffered by default so we open a new FILE (which is buffered) so that calls to printf_stderr are not as likely to get mixed together."

Comment 2

[Tyson Smith [:tsmith]]

Attachment: Bug 1766058 - Avoid mixing log output. r=glandium

Comment 3

[Tyson Smith [:tsmith]]

Using fprintf_stderr() in mfbt/Assertions.h is not easy. I think the solution is to use buffered output. Decoder mentioned that buffered output is avoided here because there could be memory corruption in some situations when these calls are made, but I'm not sure how else to handle this or if that is a legitimate concern. So hopefully someone can provide a clear answer.

Comment 4

[Andrew McCreight [:mccr8]]

I think it would be okay to use buffered input only in builds where we're not concerned about hostile code, eg fuzzing and debug builds.

Comment 5

[Jesse Schwartzentruber (:truber)]

Attachment: Bug 1766058 - Avoid mixing log output. r?glandium!

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c59c33e5030c
Avoid mixing log output. r=glandium

Comment 7

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/c59c33e5030c