1792322 - send-warning-email.py should detect `env_logger` `RUST_LOG=info` emitted warnings and we should address the massive number of these warnings that exist

Status: RESOLVED FIXED

(Webtools :: Searchfox, enhancement)

Description

[Andrew Sutherland [:asuth] (he/him)]

grep -i -P '^([ ]*|\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z )warn' index-log successfully matches the rust env_logger warnings as well as the existing case-insensitive "warn" preceded by whitespace pattern. It also matches a massive number of warnings that should probably be downgraded or just addressed.

Specifically, we have the following warnings we see:

derive-per-file-info

These should be info (noting that the whole binary is going away imminently, but I'll need clean runs before I land that):

[2022-09-24T17:00:28Z WARN  derive_per_file_info] No bugzilla-components.json file found
[2022-09-24T17:00:28Z WARN  derive_per_file_info] No test-info-all-tests.json file found
[2022-09-24T17:00:28Z WARN  derive_per_file_info] No wpt-metadata-summary.json file found

rust-indexer

These are useful and we're keeping them but I need to fix the rust-indexer regression probably due to our path normalizations (investigation ongoing):

[2022-09-24T17:04:51Z WARN  rls_analysis::raw] deserialisation error: Error("expected `,` or `}`", line: 1, column: 2799170)
[2022-09-24T17:04:51Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: ')', line: 1, column: 2799093 }

These seem like they can be downgraded to info:

[2022-09-24T17:04:53Z WARN  rust_indexer] Skipping absolute analysis path /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/macros/mod.rs
[2022-09-24T17:05:22Z WARN  rust_indexer] Skipping nonexistent source file with searchfox path '<anon>' which mapped to local path '/mnt/index-scratch/mozilla-central/git/<anon>'

Okay, so this is a variant of one of the above cases and it seems like it might actually be a problem, but it's still going to be info anyways because this probably won't get fixed:

[2022-09-24T17:05:24Z WARN  rust_indexer] Skipping nonexistent source file with searchfox path '__GENERATED__/netwerk/test/http3server/./thumbv7neon-linux-androideabi/debug/build/neqo-crypto-233499ef3bd69995/out/nss_ciphers.rs' which mapped to local path 'generated-android-armv7/netwerk/test/http3server/./thumbv7neon-linux-androideabi/debug/build/neqo-crypto-233499ef3bd69995/out/nss_ciphers.rs'

This also looks interesting:

[2022-09-24T17:05:25Z WARN  rust_indexer] Skipping absolute analysis path /cargo/registry/src/github.com-1ecc6299db9ec823/gimli-0.25.0/src/read/reader.rs

But mainly because before the upgrade to 1.64 it looked like:

[2022-09-22T04:43:59Z WARN  rust_indexer] Skipping absolute analysis path /Users/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/gimli-0.25.0/src/read/reader.rs

mozsearch-mozilla collapse-generated-files.sh

The failed wildcard expansion should likely be suppressed. I'm not sure what's up with the absolute path there; will investigate.

[2022-09-24T17:06:52Z WARN  tools::file_format::analysis] Error trying to open analysis file [analysis-*/__GENERATED__/./xpcom/idl-parser/xpidl/xpidl.stub]
[2022-09-24T17:13:58Z WARN  tools::file_format::analysis] Error trying to open analysis file [/mnt/index-scratch/mozilla-central/analysis/__GENERATED__/ipc/ipdl/_ipdlheaders/mozilla/layers/PCompositorBridgeParent.h]

Comment 1

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: Improve warning regexp, downgrade some warnings to info.

Comment 2

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch-mozilla PR: Note where we could use nullglob to avoid asking for silly merges.

Going to re-trigger config1 again after this to test this out and get our backup web-server back in place.

Comment 3

[Andrew Sutherland [:asuth] (he/him)]

The landing worked but the email seems to indicate that there's still a bunch of other messed up save-analysis JSON files to deal with, possibly due to the transforms that bug 1792327 fixed up:

[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 1167372 }), name: "libaddr2line-90f5ba62e7bc3378.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000182326s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libaddr2line-90f5ba62e7bc3378.json" 0.000222467s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 77167371 }), name: "liblibc-304d7f6977c84a4b.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000582936s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/liblibc-304d7f6977c84a4b.json" 0.000655853s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 81167370 }), name: "libgetopts-837e1b3652a82f52.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000265975s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libgetopts-837e1b3652a82f52.json" 0.000302099s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 85167370 }), name: "libmemchr-fe7e1c99889a2039.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000668145s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libmemchr-fe7e1c99889a2039.json" 0.000751331s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 105167370 }), name: "libcompiler_builtins-cfe8447efe28cb1e.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000872730s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libcompiler_builtins-cfe8447efe28cb1e.json" 0.000989864s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 109167370 }), name: "libproc_macro-ce8faae9dc63c90a.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3116)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'p', line: 1, column: 3116 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libproc_macro-ce8faae9dc63c90a.json" 0.000200227s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 169167369 }), name: "libpanic_abort-e29a30163f495e05.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3324)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'p', line: 1, column: 3324 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libpanic_abort-e29a30163f495e05.json" 0.000056744s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 181167369 }), name: "libpanic_unwind-aebdd47781a8ded3.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3463)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'p', line: 1, column: 3463 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libpanic_unwind-aebdd47781a8ded3.json" 0.000060719s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 185167369 }), name: "libminiz_oxide-aebeb1235b6ade9b.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000680245s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libminiz_oxide-aebeb1235b6ade9b.json" 0.000746758s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 197167369 }), name: "libtest-dcbb57969e13b791.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000729103s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libtest-dcbb57969e13b791.json" 0.000796236s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 205167368 }), name: "librustc_demangle-75d00692298b803c.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000143047s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/librustc_demangle-75d00692298b803c.json" 0.000167665s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 229167368 }), name: "libunwind-57642f47c953f1ca.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3134)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'n', line: 1, column: 3134 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libunwind-57642f47c953f1ca.json" 0.000056896s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 233167368 }), name: "librustc_std_workspace_core-015e9ae63a74e3a1.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000019807s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/librustc_std_workspace_core-015e9ae63a74e3a1.json" 0.000031957s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 245167368 }), name: "libprofiler_builtins-24c82300ff5f43c3.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3055)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'p', line: 1, column: 3055 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libprofiler_builtins-24c82300ff5f43c3.json" 0.000049975s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 281167367 }), name: "libobject-a5459549f895e57b.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.017377628s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libobject-a5459549f895e57b.json" 0.020887361s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 285167368 }), name: "libstd_detect-212d184ebbb3da0c.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 3610)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 's', line: 1, column: 3610 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libstd_detect-212d184ebbb3da0c.json" 0.000112037s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 449167366 }), name: "librustc_std_workspace_alloc-cdd36af8506e2d87.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000026454s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/librustc_std_workspace_alloc-cdd36af8506e2d87.json" 0.000040745s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 449167366 }), name: "libunicode_width-0edd37a8df586abd.json" }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] deserializing <buffer omitted> 0.000098009s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libunicode_width-0edd37a8df586abd.json" 0.000116250s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072659, tv_nsec: 805167360 }), name: "liballoc-32d7ee0be9e46c85.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 2867)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'a', line: 1, column: 2867 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/liballoc-32d7ee0be9e46c85.json" 0.001717131s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072660, tv_nsec: 777167347 }), name: "libstd-4a00450d169b6eb7.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 5509)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 's', line: 1, column: 5509 }
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] reading "objdir-win64/rustlib/x86_64-pc-windows-msvc/analysis/libstd-4a00450d169b6eb7.json" 0.006533246s
[2022-09-25T02:24:42Z INFO  rls_analysis::raw] Considering Listing { kind: File(SystemTime { tv_sec: 1664072661, tv_nsec: 757167333 }), name: "libcore-15d7d0533432428b.json" }
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] deserialisation error: Error("invalid escape", line: 1, column: 2340)
[2022-09-25T02:24:42Z WARN  rls_analysis::raw] Data was not valid JSON: UnexpectedCharacter { ch: 'c', line: 1, column: 2340 }

Comment 4

[Andrew Sutherland [:asuth] (he/him)]

Ah, yeah, the problem seems to be the backslash normalization is eating 1 out of the 2 backslashes that correspond to a properly escaped backslash in a JSON-encoded string. Example: {"span":{"file_name":"__GENERATED__/__RUST_STDLIB__/\proc_macro\\src\\lib.rs"

There's an idiom in the normalizations of [/\\] but that's obviously ignoring the reality that JSON strings will end up with 2 backslashes. The easiest thing is probably to add a + since we always normalize to forward slashes and repeated slashes should not otherwise legally exist in these cases.

Comment 5

[Andrew Sutherland [:asuth] (he/him)]

This morning's harvest of warnings indicates:

• I need to add a "re-parse as a module" fallback for encountered exports, not just imports (I was sleepy :).
• There's preprocess functionality in js-analyze that is causing real problems with classes that use private symbols resulting in a variety of errors (not a known private symbol, unexpected "." token following a reference to a private symbol). In particular, the logic ends up commenting out every line that starts with a # which ends up removing all the private symbol definitions! Unfortunately, https://searchfox.org/mozilla-central/source/toolkit/modules/AppConstants.jsm is still preprocessed and is fairly important, so we it's probably not helpful to entirely disable it. However, we can:
  • Remove the fallback case that was commenting out any line that starts with #. The preprocessor is documented at https://firefox-source-docs.mozilla.org/build/buildsystem/preprocessor.html so we can make sure we have all of the tokens supported.
• Unfortunately, for preprocessing we CANNOT:
  • Require directives have no leading whitespace. https://searchfox.org/mozilla-central/source/toolkit/modules/AppConstants.jsm explicitly has indented directives. They are explicitly only when nested inside other if cases, so we could add a heuristic for that, potentially, but requiring the directives to be known can potentially get us there.

Comment 6

[Andrew Sutherland [:asuth] (he/him)]

(I'm now digging into the full index-log contents, not just what hit the 50 warning limit in the email.)

We're also getting a bunch of warnings related to JSX that look like:

WARN Unable to parse JS file /mnt/index-scratch/kaios/git/devtools/client/debugger/src/components/SecondaryPanes/CommandBar.js:1.

WARN because SyntaxError: expected expression, got '<': /mnt/index-scratch/kaios/git/devtools/client/debugger/src/components/SecondaryPanes/CommandBar.js:208

This is something scip-typescript can potentially help with, but not something our js analysis script can reasonably handle at this time. I'm going to downgrade this to an INFO and it would be a great candidate for reporting in the UI as proposed in bug 1789515 through use of diagnostic analysis records.

Comment 7

[Andrew Sutherland [:asuth] (he/him)]

Our export handling also needs more smarts for export default update; as reported in this warning where the statement is just an identifier (because, without checking the spec, export default probably is an expression context which is why it's so limited in what it can do in practice):

WARN In /mnt/index-scratch/kaios/git/devtools/client/debugger/src/reducers/file-search.js, got: Unexpected statement: Identifier {"loc":{"start":{"line":70,"column":15},"end":{"line":70,"column":21},"source":"/mnt/index-scratch/kaios/git/devtools/client/debugger/src/reducers/file-search.js"},"type":"Identifier","name":"update"}

I'll specialize our export logic here to not warn and ensure we have a check that we don't fail but I think I'm going to have us not emit anything in the interest of time and consistency, but patches will be accepted!

Comment 8

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: Warning fixes

Comment 9

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch-mozilla PR: sed fix

Comment 10

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: More warning reduction

Comment 11

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: Warning file patterns must be pre-lowercased.

Comment 12

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: Failsafe JSON heuristic, plus l10n prefs intervention.

I'd successfully eliminated the mozilla-central warnings but config1 still had some comm-central "suite" warnings, plus config4 had some l10n pref file warnings. This should bring us to 0 warnings on config1 and config4 and we'll see what tomorrow brings.

Comment 13

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: some last warning downgrades for the other indexers

This should be the last of the warnings other than a discovery about some corrupt analysis JSON for mozilla-esr91 I'm dealing with.

Comment 14

[Andrew Sutherland [:asuth] (he/him)]

We're at zero warnings for config1 and should be for everything else after this, modulo that mozilla-esr91 thing.

Comment 15

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: Fix a mozilla-esr91 warning due to import()

Comment 16

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: label warnings with parse mode, wubkat intervention.

Comment 17

[Andrew Sutherland [:asuth] (he/him)]

Attachment: Landed mozsearch PR: (Very old) ESR trees don't need to be warnings.