Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Switch aarch64-darwin codegen to JITLink (ObjectLinkingLayer) and small code model #43664

Merged
merged 3 commits into from
Jan 19, 2022

Conversation

dnadlinger
Copy link
Member

@dnadlinger dnadlinger commented Jan 5, 2022

This fixes #41440, #43285 and similar runtime crashes, which stem from CodeModel::Large not being correctly implemented on MachO/ARM64.

With it, the only testsuite failures remaining on my M1 Max machine are occasional thread.jl hangs, which appear to be the same as #41820.

Now that master is on LLVM 13, this should work against the default BinaryBuilder LLVM. LLVM 14 (Git main) is still preferred, as debugger integration (ENABLE_GDBLISTENER) is not supported on 13.x. I tested dnadlinger/llvm-project@57eb8c1, which is llvm/llvm-project@1dd5e6fed5db with our 13.x patches. Our LLVM patch set (julia-releases/13.x) is absolutely required so that __eh_frame unwind information is generated and passed through the stack, without which backtraces silently won't work (see llvm/llvm-project#52921).

Profiler integration (ENABLE_JITPROFILING) is not currently supported on either version; this is an upstream LLVM restriction.


As pointed out in the comments, this currently doesn't use the custom Julia RTDyld memory manager, as the API has changed quite significantly. We'll probably want to port the dual-map optimisations to JITLinkMemoryManager soon, but I believe the random segfaults are much more disruptive, and thus the JITLink switch shouldn't be held up by that.

@vchuravy
Copy link
Member

vchuravy commented Jan 5, 2022

Tentatively marking this for 1.8 (feature freeze is on February 15th)

@vchuravy vchuravy requested a review from vtjnash January 5, 2022 05:44
Copy link
Member

@vchuravy vchuravy left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great work!

@Keno we should chat about CI for M1

src/codegen.cpp Outdated Show resolved Hide resolved
src/debuginfo.cpp Outdated Show resolved Hide resolved
jitlink::JITLinkContext &Ctx,
MemoryBufferRef InputObject) override
{
// Keeping around a full copy of the input object file (and re-parsing it) is
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How bad is the performance/memory impact?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I haven't measured it, but it's the same as before in the RTDyld implementation – apparently even for ELF, where getObjectForDebug isn't a no-op, a full copy is made internally.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't we still pretend that getObjectForDebug is meaningfully implemented however?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Where do you mean? It's RTDyld only, and we do use it there if available.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looking at the upcoming plugin support in llvm/lib/ExecutionEngine/Orc/DebuggerSupportPlugin.cpp, it appears good support for this will appear in the future, so perhaps not worth working on now.

Alternatively, could we enable split-debug, and parse the .dwo files instead, instead of making JITLink deal with implementing the extract-dwo objcopy pass itself?

Copy link
Member Author

@dnadlinger dnadlinger Jan 20, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can't use DebuggerSupportPlugin verbatim. I actually planned on using that first – hence the whole LLVM 14 effort –, but it already patches the section addresses to match the runtime memory layout, so we can't re-parse it using llvm::ObjectFile.

I was about to try patching that out, but in the end, decided to just copy the input buffer as that's what we do on x86_64 MachO and other platforms anyway.

In the long run, particularly as more platforms will move onto JITLink, it will certainly be a good idea to remove the ObjectFile references from debuginfo and keep track of the required tables/… at a finer granularity.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As for split DWARF information, I haven't really thought about how that would interact with OrcJIT at all.

src/jitlayers.cpp Show resolved Hide resolved
// (with the llvm_orc_registerJITLoaderGDBAllocAction symbol being in either
// libjulia-codegen or yet another shared library for LLVM depending on the build
// flags, etc.).
const auto Addr = ExecutorAddr::fromPtr(&llvm_orc_registerJITLoaderGDBAllocAction);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lhames this might be of interest to you.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting. @dnadlinger Can you describe what made the lookup fragile?

If possible we want to make ::Create smooth enough to use that it's the natural default, even for in-process setups. (Just because it makes switching between in-process and out-of-process modes trivial)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lhames I'm not actually sure – I didn't want to touch the existing JITDylib setup code, as I'm not very familiar with the history of the Julia codebase, and apparently orc::DynamicLibrarySearchGenerator::GetForCurrentProcess wasn't enough to make it work. I didn't check whether that is supposed to work only for symbols in the main image or also for loaded dylibs, but just based on a quick glance, it appeared to be the former. In the "canonical" configuration, Julia links LLVM as a dylib dependency of an internal dylib used by the main process, so rather than trying to figure out what the correct setup is there, it seemed easier to just rely on the host linker to figure this out. Happy to incorporate any suggestions to avoid duplicating the symbol name, though!

@dnadlinger
Copy link
Member Author

dnadlinger commented Jan 5, 2022

The Buildkite failures appear to be due to #43415.

I should also note that I more or less exclusively tested this on LLVM Git main locally. LLVM 13.x should run though make test fine (or rather, not any worse than when building against main), but for anybody eager to test this, I'd recommend also giving LLVM Git main a try if you encounter any weird issues.

@Keno
Copy link
Member

Keno commented Jan 5, 2022

@Keno we should chat about CI for M1

We have one machine ready to go. We should be able to set that up right away.

@dnadlinger
Copy link
Member Author

dnadlinger commented Jan 5, 2022

For CI, you'll probably want to make sure that there is a robust timeout mechanism in place that, if necessary, uses kill -9 – at least manually on the command line, Ctrl+C-ing the threads.jl test quite often left behind a process in a non-SIGTERM-able state.

Any ideas regarding the tester_linux64 failure? At first glance, it looks like it hits an internal assertion in rr ('npid == waited->rec_tid' failed to hold.)?

@dnadlinger
Copy link
Member Author

Fixed the typos, rebased on top of master, and removed the extra commit from #43612 – without it, there will be some stacktrace-related failures in test.

@Keno
Copy link
Member

Keno commented Jan 5, 2022

Any ideas regarding the tester_linux64 failure? At first glance, it looks like it hits an internal assertion in rr (npid == waited->rec_tid' failed to hold.)?

Known bug, I'll be looking at it today.

@oscardssmith oscardssmith added the system:mac Affects only macOS label Jan 6, 2022
@dnadlinger
Copy link
Member Author

None of the remaining failures seem to be related to this PR.

The same interface used to be called two different ways depending on
the JIT implementation: via llvm::JITEventListener for use with the
old JIT APIs, as well as through our own ORCNotifyObjectEmitted()
callback for use with the new ORC-based JIT. Legacy JIT and MCJIT
support is long gone, so this removes the unused
llvm::JITEventListener interface.

Since there was a single instance held in a static global in
debuginfo.cpp anyway, I also removed CreateJuliaJITEventListener(),
etc. in favour of a single static global instance – this of course
still isn't exactly clean lifetime management.
…ll code model

This fixes JuliaLang#41440, JuliaLang#43285 and similar issues, which stem from
CodeModel::Large not being correctly implemented on MachO/ARM64.

Requires LLVM 13.x or Git main (tested: 1dd5e6fed5db with patches
from the JuliaLang/llvm-project julia-release/13.x branch, available
at https://github.com/dnadlinger/llvm-project/commits/julia-main).

Requires an LLVM patch to pass through __eh_frame unwind information,
without which backtraces silently won't work (already applied on
JuliaLang/llvm-project@julia-release/13.x):
llvm/llvm-project#52921
@dnadlinger
Copy link
Member Author

Rebased on top of latest master and fixed backtraces when linking against LLVM as a shared library (the default).

@dnadlinger
Copy link
Member Author

Tests now pass on my M1 Max when building with default options (LLVM 13 from BinaryBuilder):

❱ make -j10 test
Whitespace check found no issues
    CC src/jitlayers.o
/Users/dpn/Build/Source/julia.13/src/jitlayers.cpp:1016:4: warning: #warning is a language extension [-Wpedantic]
#  warning "JIT debugging (GDB integration) not available on LLVM < 14.0 (for JITLink)"
   ^
/Users/dpn/Build/Source/julia.13/src/jitlayers.cpp:1016:4: warning: "JIT debugging (GDB integration) not available on LLVM < 14.0 (for JITLink)" [-W#warnings]
2 warnings generated.
    LINK usr/lib/libjulia-codegen.1.8.dylib
    LINK usr/lib/libjulia-codegen.dylib
    LINK usr/lib/libjulia-codegen.1.dylib
    JULIA test/default
Test                          (Worker) | Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB)
LinearAlgebra/matmul               (5) |        started at 2022-01-10T15:42:09.075
LinearAlgebra/qr                   (3) |        started at 2022-01-10T15:42:09.115
LinearAlgebra/dense                (4) |        started at 2022-01-10T15:42:09.132
LinearAlgebra/schur                (6) |        started at 2022-01-10T15:42:09.132
LinearAlgebra/special              (7) |        started at 2022-01-10T15:42:09.132
LinearAlgebra/triangular           (2) |        started at 2022-01-10T15:42:09.132
LinearAlgebra/special              (7) |    43.60 |   1.87 |  4.3 |   11222.47 |   818.31
LinearAlgebra/eigen                (7) |        started at 2022-01-10T15:42:52.868
LinearAlgebra/qr                   (3) |    54.79 |   3.01 |  5.5 |   17859.16 |  1112.17
LinearAlgebra/bunchkaufman         (3) |        started at 2022-01-10T15:43:04.002
LinearAlgebra/bunchkaufman         (3) |    18.26 |   0.57 |  3.1 |    3519.57 |  1265.02
LinearAlgebra/svd                  (3) |        started at 2022-01-10T15:43:22.264
LinearAlgebra/eigen                (7) |    34.50 |   1.51 |  4.4 |    7629.88 |  1209.33
LinearAlgebra/lapack               (7) |        started at 2022-01-10T15:43:27.372
LinearAlgebra/schur                (6) |    81.14 |   0.82 |  1.0 |    4319.05 |   559.25
LinearAlgebra/tridiag              (6) |        started at 2022-01-10T15:43:30.341
LinearAlgebra/lapack               (7) |    16.08 |   0.53 |  3.3 |    3561.98 |  1371.98
LinearAlgebra/bidiag               (7) |        started at 2022-01-10T15:43:43.453
LinearAlgebra/svd                  (3) |    25.12 |   1.28 |  5.1 |    5803.13 |  1473.39
LinearAlgebra/diagonal             (3) |        started at 2022-01-10T15:43:47.385
LinearAlgebra/tridiag              (6) |    27.86 |   1.10 |  3.9 |    6498.07 |   839.27
LinearAlgebra/cholesky             (6) |        started at 2022-01-10T15:43:58.203
LinearAlgebra/matmul               (5) |   120.34 |   4.82 |  4.0 |   22310.23 |  1125.20
LinearAlgebra/lu                   (5) |        started at 2022-01-10T15:44:09.532
LinearAlgebra/dense                (4) |   130.07 |   5.91 |  4.5 |   28150.70 |  1623.97
LinearAlgebra/symmetric            (4) |        started at 2022-01-10T15:44:19.287
LinearAlgebra/bidiag               (7) |    63.36 |   2.10 |  3.3 |   11954.35 |  1851.11
LinearAlgebra/generic              (7) |        started at 2022-01-10T15:44:46.816
LinearAlgebra/cholesky             (6) |    50.14 |   1.83 |  3.6 |    9219.04 |  1297.70
LinearAlgebra/uniformscaling       (6) |        started at 2022-01-10T15:44:48.342
LinearAlgebra/lu                   (5) |    54.49 |   2.05 |  3.8 |   11312.46 |  1609.00
LinearAlgebra/lq                   (5) |        started at 2022-01-10T15:45:04.030
LinearAlgebra/generic              (7) |    18.59 |   1.08 |  5.8 |    3681.84 |  2127.67
LinearAlgebra/hessenberg           (7) |        started at 2022-01-10T15:45:05.407
LinearAlgebra/uniformscaling       (6) |    31.03 |   1.71 |  5.5 |    6300.53 |  1646.81
LinearAlgebra/blas                 (6) |        started at 2022-01-10T15:45:19.376
LinearAlgebra/lq                   (5) |    19.57 |   1.36 |  6.9 |   10382.57 |  1917.06
LinearAlgebra/adjtrans             (5) |        started at 2022-01-10T15:45:23.600
LinearAlgebra/blas                 (6) |     9.62 |   0.36 |  3.7 |    2079.26 |  1646.81
LinearAlgebra/pinv                 (6) |        started at 2022-01-10T15:45:28.995
LinearAlgebra/hessenberg           (7) |    28.22 |   0.88 |  3.1 |    5849.44 |  2146.36
LinearAlgebra/givens               (7) |        started at 2022-01-10T15:45:33.634
LinearAlgebra/pinv                 (6) |     4.84 |   0.27 |  5.6 |    1372.05 |  1683.38
LinearAlgebra/structuredbroadcast  (6) |        started at 2022-01-10T15:45:33.834
LinearAlgebra/adjtrans             (5) |    11.18 |   0.54 |  4.8 |    2791.42 |  1932.11
LinearAlgebra/addmul               (5) |        started at 2022-01-10T15:45:34.782
LinearAlgebra/givens               (7) |     2.13 |   0.06 |  2.6 |     323.20 |  2146.36
LinearAlgebra/ldlt                 (7) |        started at 2022-01-10T15:45:35.770
LinearAlgebra/ldlt                 (7) |     0.35 |   0.00 |  0.0 |      60.86 |  2146.36
LinearAlgebra/factorization        (7) |        started at 2022-01-10T15:45:36.124
LinearAlgebra/factorization        (7) |     1.86 |   0.05 |  2.9 |     369.31 |  2146.36
ambiguous                          (7) |        started at 2022-01-10T15:45:37.982
      From worker 7:	Skipping Base.active_repl
      From worker 7:	Skipping Base.active_repl_backend
      From worker 7:	Skipping Pkg.Types.find_registered!
      From worker 7:	Skipping Pkg.BinaryPlatforms.compiler_abi
      From worker 7:	Skipping Base.active_repl
      From worker 7:	Skipping Base.active_repl_backend
ambiguous                          (7) |     2.49 |   0.09 |  3.4 |     481.46 |  2146.36
compiler/inference                 (7) |        started at 2022-01-10T15:45:40.471
compiler/inference                 (7) |     7.57 |   0.23 |  3.1 |    1346.19 |  2146.36
compiler/validation                (7) |        started at 2022-01-10T15:45:48.047
compiler/validation                (7) |     0.17 |   0.00 |  0.0 |      30.75 |  2146.36
compiler/ssair                     (7) |        started at 2022-01-10T15:45:48.215
compiler/ssair                     (7) |     1.52 |   0.03 |  1.9 |     140.15 |  2146.36
compiler/irpasses                  (7) |        started at 2022-01-10T15:45:49.742
compiler/irpasses                  (7) |     0.98 |   0.05 |  5.4 |     187.13 |  2146.36
compiler/codegen                   (7) |        started at 2022-01-10T15:45:50.722
LinearAlgebra/diagonal             (3) |   128.24 |   5.58 |  4.4 |   27036.75 |  2016.78
compiler/inline                    (3) |        started at 2022-01-10T15:45:55.633
LinearAlgebra/structuredbroadcast  (6) |    23.10 |   1.00 |  4.3 |    4547.69 |  1788.78
compiler/inline                    (3) |     1.30 |   0.00 |  0.0 |     137.77 |  2016.78
compiler/contextual                (6) |        started at 2022-01-10T15:45:56.934
subarray                           (3) |        started at 2022-01-10T15:45:56.935
compiler/contextual                (6) |     1.23 |   0.02 |  1.4 |      95.98 |  1788.78
strings/basic                      (6) |        started at 2022-01-10T15:45:58.164
strings/basic                      (6) |     4.02 |   0.16 |  4.0 |     657.31 |  1788.78
strings/search                     (6) |        started at 2022-01-10T15:46:02.187
compiler/codegen                   (7) |    11.81 |   1.04 |  8.8 |     230.66 |  2159.73
strings/util                       (7) |        started at 2022-01-10T15:46:02.538
strings/search                     (6) |     2.34 |   0.03 |  1.4 |     245.66 |  1788.78
strings/io                         (6) |        started at 2022-01-10T15:46:04.527
strings/io                         (6) |     1.76 |   0.09 |  5.0 |     335.27 |  1788.78
strings/types                      (6) |        started at 2022-01-10T15:46:06.287
LinearAlgebra/symmetric            (4) |   107.36 |   3.20 |  3.0 |   17728.62 |  1947.47
unicode/utf8                       (4) |        started at 2022-01-10T15:46:06.652
unicode/utf8                       (4) |     0.06 |   0.00 |  0.0 |       7.02 |  1947.47
core                               (4) |        started at 2022-01-10T15:46:06.715
strings/util                       (7) |     5.08 |   0.17 |  3.3 |     726.52 |  2159.73
worlds                             (7) |        started at 2022-01-10T15:46:07.619
strings/types                      (6) |     1.61 |   0.14 |  8.6 |    1061.07 |  1788.78
atomics                            (6) |        started at 2022-01-10T15:46:07.897
worlds                             (7) |     0.77 |   0.03 |  3.6 |     121.35 |  2159.73
keywordargs                        (7) |        started at 2022-01-10T15:46:08.391
keywordargs                        (7) |     0.85 |   0.02 |  2.7 |      99.26 |  2159.73
numbers                            (7) |        started at 2022-01-10T15:46:09.241
atomics                            (6) |     8.08 |   0.27 |  3.4 |    1730.00 |  1825.27
subtype                            (6) |        started at 2022-01-10T15:46:15.976
LinearAlgebra/triangular           (2) |   250.93 |   9.88 |  3.9 |   52690.87 |  2547.36
char                               (2) |        started at 2022-01-10T15:46:20.137
char                               (2) |     1.09 |   0.03 |  3.0 |     179.18 |  2547.36
triplequote                        (2) |        started at 2022-01-10T15:46:21.227
triplequote                        (2) |     0.02 |   0.00 |  0.0 |       0.45 |  2547.36
intrinsics                         (2) |        started at 2022-01-10T15:46:21.253
intrinsics                         (2) |     1.33 |   0.05 |  3.6 |     226.68 |  2547.36
dict                               (2) |        started at 2022-01-10T15:46:22.581
subtype                            (6) |    11.43 |   0.57 |  5.0 |    1826.30 |  2519.81
hashing                            (6) |        started at 2022-01-10T15:46:27.412
dict                               (2) |    11.53 |   0.99 |  8.6 |    2112.56 |  2547.36
iobuffer                           (2) |        started at 2022-01-10T15:46:34.115
hashing                            (6) |     7.32 |   0.31 |  4.3 |    1714.00 |  2519.81
staged                             (6) |        started at 2022-01-10T15:46:34.739
iobuffer                           (2) |     0.65 |   0.02 |  2.4 |     101.53 |  2547.36
offsetarray                        (2) |        started at 2022-01-10T15:46:34.769
staged                             (6) |     1.46 |   0.06 |  3.9 |     321.70 |  2519.81
arrayops                           (6) |        started at 2022-01-10T15:46:36.198
numbers                            (7) |    30.78 |   1.04 |  3.4 |    4719.27 |  2816.47
tuple                              (7) |        started at 2022-01-10T15:46:40.027
tuple                              (7) |     2.70 |   0.10 |  3.8 |     705.55 |  2816.47
reduce                             (7) |        started at 2022-01-10T15:46:42.734
core                               (4) |    42.45 |  10.74 | 25.3 |   12614.33 |  3853.19
reducedim                          (4) |        started at 2022-01-10T15:46:49.246
reduce                             (7) |     8.91 |   0.41 |  4.6 |    2158.03 |  2816.47
abstractarray                      (7) |        started at 2022-01-10T15:46:51.649
offsetarray                        (2) |    18.29 |   0.79 |  4.3 |    4246.32 |  2547.36
intfuncs                           (2) |        started at 2022-01-10T15:46:53.065
intfuncs                           (2) |    23.18 |   0.12 |  0.5 |     723.47 |  2547.36
simdloop                           (2) |        started at 2022-01-10T15:47:16.250
reducedim                          (4) |    27.62 |   0.60 |  2.2 |    5514.61 |  3853.19
vecelement                         (4) |        started at 2022-01-10T15:47:16.867
simdloop                           (2) |     1.01 |   0.04 |  4.1 |     219.55 |  2547.36
rational                           (2) |        started at 2022-01-10T15:47:17.266
vecelement                         (4) |     3.79 |   0.15 |  4.1 |    1403.45 |  3853.19
bitarray                           (4) |        started at 2022-01-10T15:47:20.657
subarray                           (3) |    83.98 |   3.23 |  3.9 |   19851.22 |  2650.75
copy                               (3) |        started at 2022-01-10T15:47:20.921
copy                               (3) |     0.99 |   0.00 |  0.0 |     205.70 |  2661.00
math                               (3) |        started at 2022-01-10T15:47:21.912
arrayops                           (6) |    49.80 |   2.11 |  4.2 |   11131.61 |  2604.09
fastmath                           (6) |        started at 2022-01-10T15:47:26.123
rational                           (2) |    11.21 |   0.28 |  2.5 |    1927.76 |  2547.36
functional                         (2) |        started at 2022-01-10T15:47:28.480
fastmath                           (6) |     3.30 |   0.08 |  2.3 |     627.29 |  2604.09
iterators                          (6) |        started at 2022-01-10T15:47:29.429
functional                         (2) |     2.92 |   0.14 |  4.7 |     675.43 |  2547.36
operators                          (2) |        started at 2022-01-10T15:47:31.402
operators                          (2) |     3.20 |   0.11 |  3.4 |     765.73 |  2547.36
ordering                           (2) |        started at 2022-01-10T15:47:34.606
ordering                           (2) |     1.12 |   0.03 |  2.5 |     127.49 |  2547.36
path                               (2) |        started at 2022-01-10T15:47:35.727
path                               (2) |     0.62 |   0.00 |  0.0 |     130.41 |  2547.36
ccall                              (2) |        started at 2022-01-10T15:47:36.344
math                               (3) |    17.14 |   0.47 |  2.8 |    3174.77 |  2849.61
parse                              (3) |        started at 2022-01-10T15:47:39.058
parse                              (3) |     1.98 |   0.06 |  3.3 |     341.70 |  2849.61
loading                            (3) |        started at 2022-01-10T15:47:41.041
ccall                              (2) |    12.21 |   0.35 |  2.9 |     688.45 |  2547.36
gmp                                (2) |        started at 2022-01-10T15:47:48.554
abstractarray                      (7) |    58.70 |   1.94 |  3.3 |   10270.35 |  2940.00
gmp                                (2) |     2.39 |   0.08 |  3.2 |     413.15 |  2547.36
spawn                              (2) |        started at 2022-01-10T15:47:50.952
      From worker 2:	       [stdio passthrough ok]
sorting                            (7) |        started at 2022-01-10T15:47:53.150
      From worker 3:	┌ Error: active project callback #19 failed
      From worker 3:	└ @ Base initdefs.jl:325
      From worker 3:	WARNING: replacing module Foo.
      From worker 3:	this_prefs = Dict{String, Any}("pref2" => "outer-jlp", "pref4" => "inner-lp", "pref1" => "outer-project", "pref3" => "inner-project", "__clear__" => ["pref6"], "pref5" => "outer-project")
      From worker 3:	this_prefs = Dict{String, Any}("pref2" => "outer-jlp", "pref4" => "inner-lp", "pref1" => "outer-project", "pref3" => "inner-project", "__clear__" => ["pref6"], "pref5" => "outer-project")
loading                            (3) |    20.61 |   0.38 |  1.9 |    2370.95 |  2849.61
backtrace                          (3) |        started at 2022-01-10T15:48:01.653
      From worker 3:	[ Info:
backtrace                          (3) |     1.40 |   0.00 |  0.0 |      89.01 |  2849.61
exceptions                         (3) |        started at 2022-01-10T15:48:03.058
exceptions                         (3) |     1.51 |   0.37 | 24.5 |      30.95 |  2849.61
file                               (3) |        started at 2022-01-10T15:48:04.568
file                               (3) |     5.49 |   0.05 |  0.9 |     398.12 |  2849.61
read                               (3) |        started at 2022-01-10T15:48:10.065
spawn                              (2) |    20.81 |   0.33 |  1.6 |     675.46 |  2547.36
version                            (2) |        started at 2022-01-10T15:48:11.761
version                            (2) |     0.52 |   0.04 |  8.6 |      69.06 |  2547.36
namedtuple                         (2) |        started at 2022-01-10T15:48:12.279
namedtuple                         (2) |     1.29 |   0.04 |  3.0 |     187.18 |  2547.36
mpfr                               (2) |        started at 2022-01-10T15:48:13.573
mpfr                               (2) |     7.83 |   0.14 |  1.8 |    1551.72 |  2547.36
broadcast                          (2) |        started at 2022-01-10T15:48:21.401
iterators                          (6) |    55.68 |   2.28 |  4.1 |   14018.80 |  2688.52
complex                            (6) |        started at 2022-01-10T15:48:25.107
complex                            (6) |     5.17 |   0.16 |  3.2 |    1069.23 |  2688.52
floatapprox                        (6) |        started at 2022-01-10T15:48:30.280
floatapprox                        (6) |     0.46 |   0.03 |  5.9 |      75.22 |  2688.52
reflection                         (6) |        started at 2022-01-10T15:48:30.746
reflection                         (6) |     2.64 |   0.06 |  2.2 |     405.97 |  2688.52
regex                              (6) |        started at 2022-01-10T15:48:33.385
regex                              (6) |     1.12 |   0.03 |  2.8 |     150.40 |  2688.52
float16                            (6) |        started at 2022-01-10T15:48:34.504
float16                            (6) |     2.64 |   0.19 |  7.1 |    1273.50 |  2688.52
combinatorics                      (6) |        started at 2022-01-10T15:48:37.145
combinatorics                      (6) |     3.74 |   0.19 |  5.2 |    1329.75 |  2688.52
sysinfo                            (6) |        started at 2022-01-10T15:48:40.891
sysinfo                            (6) |     0.07 |   0.00 |  0.0 |      21.34 |  2688.52
env                                (6) |        started at 2022-01-10T15:48:40.966
env                                (6) |     0.23 |   0.02 | 10.8 |      24.62 |  2688.52
rounding                           (6) |        started at 2022-01-10T15:48:41.197
rounding                           (6) |     2.41 |   0.05 |  2.2 |     411.50 |  2688.52
ranges                             (6) |        started at 2022-01-10T15:48:43.610
sorting                            (7) |    50.90 |   1.36 |  2.7 |    8609.83 |  2940.00
mod2pi                             (7) |        started at 2022-01-10T15:48:44.124
mod2pi                             (7) |     0.18 |   0.00 |  0.0 |      21.59 |  2940.00
euler                              (7) |        started at 2022-01-10T15:48:44.309
euler                              (7) |     0.56 |   0.00 |  0.0 |     103.67 |  2940.00
show                               (7) |        started at 2022-01-10T15:48:44.876
read                               (3) |    39.31 |   0.64 |  1.6 |    3923.78 |  3851.09
client                             (3) |        started at 2022-01-10T15:48:49.381
client                             (3) |     0.81 |   0.05 |  5.7 |     120.45 |  3851.09
errorshow                          (3) |        started at 2022-01-10T15:48:50.196
errorshow                          (3) |     3.63 |   0.00 |  0.0 |     412.05 |  3851.09
sets                               (3) |        started at 2022-01-10T15:48:53.828
broadcast                          (2) |    41.12 |   1.20 |  2.9 |    7228.88 |  2547.36
goto                               (2) |        started at 2022-01-10T15:49:02.519
goto                               (2) |     0.03 |   0.00 |  0.0 |       0.91 |  2547.36
llvmcall                           (2) |        started at 2022-01-10T15:49:02.554
show                               (7) |    17.90 |   0.56 |  3.1 |    3475.04 |  2940.00
llvmcall2                          (7) |        started at 2022-01-10T15:49:02.779
llvmcall2                          (7) |     0.02 |   0.00 |  0.0 |       1.71 |  2940.00
ryu                                (7) |        started at 2022-01-10T15:49:02.804
llvmcall                           (2) |     0.65 |   0.00 |  0.0 |      18.31 |  2547.36
some                               (2) |        started at 2022-01-10T15:49:03.212
some                               (2) |     0.49 |   0.00 |  0.0 |      91.12 |  2547.36
meta                               (2) |        started at 2022-01-10T15:49:03.699
ryu                                (7) |     0.96 |   0.00 |  0.0 |      90.64 |  2958.55
stacktraces                        (7) |        started at 2022-01-10T15:49:03.765
meta                               (2) |     0.80 |   0.03 |  3.6 |     107.53 |  2547.36
docs                               (2) |        started at 2022-01-10T15:49:04.501
stacktraces                        (7) |     1.06 |   0.03 |  3.3 |     186.44 |  2967.25
misc                               (7) |        started at 2022-01-10T15:49:04.826
sets                               (3) |    11.34 |   0.26 |  2.3 |    1595.16 |  3851.09
binaryplatforms                    (3) |        started at 2022-01-10T15:49:05.194
docs                               (2) |     2.07 |   0.06 |  2.9 |     425.79 |  2547.36
atexit                             (2) |        started at 2022-01-10T15:49:06.570
ranges                             (6) |    23.50 |   1.43 |  6.1 |    9680.78 |  2688.52
enums                              (6) |        started at 2022-01-10T15:49:07.116
      From worker 7:	  0.000000 seconds
      From worker 7:	message: 0.000000 seconds
      From worker 7:	message: 0.000000 seconds
      From worker 7:	message: 0.001001 seconds (30 allocations: 1.688 KiB, 80.82% compilation time)
      From worker 7:	  0.000000 seconds
      From worker 7:	elapsed time (ns): 125
      From worker 7:	message: 0.000000 seconds
      From worker 7:	elapsed time (ns): 125
      From worker 7:	message: 0.000000 seconds
      From worker 7:	elapsed time (ns): 125
      From worker 7:	message: 0.000005 seconds (6 allocations: 192 bytes)
      From worker 7:	elapsed time (ns): 4750
      From worker 7:	bytes allocated:   192
      From worker 7:	pool allocs:       6
      From worker 7:	true: 0.000000 seconds
      From worker 7:	foo(): 0.000046 seconds (355 allocations: 24.734 KiB, 89.41% compilation time)
      From worker 7:	foo(): 0.000059 seconds (355 allocations: 24.734 KiB, 91.15% compilation time)
binaryplatforms                    (3) |     2.62 |   0.08 |  2.9 |     448.65 |  3851.09
cmdlineargs                        (3) |        started at 2022-01-10T15:49:07.815
enums                              (6) |     1.82 |   0.08 |  4.2 |     337.05 |  2688.52
int                                (6) |        started at 2022-01-10T15:49:08.947
bitarray                           (4) |   111.81 |   2.05 |  1.8 |   18156.88 |  3853.19
interpreter                        (4) |        started at 2022-01-10T15:49:12.484
interpreter                        (4) |     1.10 |   0.00 |  0.0 |       7.12 |  3853.19
checked                            (4) |        started at 2022-01-10T15:49:13.596
int                                (6) |     5.55 |   0.13 |  2.3 |     560.26 |  2688.52
bitset                             (6) |        started at 2022-01-10T15:49:14.541
atexit                             (2) |     7.99 |   0.04 |  0.4 |      18.98 |  2547.36
floatfuncs                         (2) |        started at 2022-01-10T15:49:14.563
bitset                             (6) |     1.32 |   0.04 |  2.7 |     204.42 |  2688.52
boundscheck                        (6) |        started at 2022-01-10T15:49:15.865
      From worker 6:	Test Summary:                                               | Pass  Total  Time
      From worker 6:	pass inbounds meta to getindex on CartesianIndices (#42115) |    2      2  0.0s
checked                            (4) |     4.77 |   0.08 |  1.6 |     240.00 |  3853.19
error                              (4) |        started at 2022-01-10T15:49:18.371
      From worker 6:	Test Summary:                                               | Pass  Total  Time
      From worker 6:	pass inbounds meta to getindex on CartesianIndices (#42115) |    2      2  0.0s
error                              (4) |     1.00 |   0.00 |  0.0 |      52.93 |  3853.19
cartesian                          (4) |        started at 2022-01-10T15:49:19.377
      From worker 6:	Test Summary:                                               | Pass  Total  Time
      From worker 6:	pass inbounds meta to getindex on CartesianIndices (#42115) |    2      2  0.0s
boundscheck                        (6) |     5.19 |   0.00 |  0.0 |       2.60 |  2688.52
osutils                            (6) |        started at 2022-01-10T15:49:21.066
osutils                            (6) |     0.05 |   0.00 |  0.0 |       0.84 |  2688.52
channels                           (6) |        started at 2022-01-10T15:49:21.114
      From worker 7:	  0.000001 seconds
      From worker 7:	Test Summary: | Pass  Total  Time
      From worker 7:	@deprecate    |    6      6  0.4s
      From worker 7:	Test Summary: | Pass  Total  Time
      From worker 7:	firstcaller   |    1      1  0.0s
      From worker 7:	Test Summary:              | Broken  Total  Time
      From worker 7:	parser syntax deprecations |      1      1  0.0s
      From worker 7:	  2.030056 seconds (1.27 M allocations: 70.024 MiB, 1.30% gc time, 25.79% compilation time)
      From worker 7:	GC: pause 32.64ms. collected 0.057744MB. full recollect
      From worker 7:	GC: pause 258.23ms. collected 0.000000MB. incr
cartesian                          (4) |     5.63 |   0.09 |  1.6 |     813.67 |  3853.19
iostream                           (4) |        started at 2022-01-10T15:49:25.013
misc                               (7) |    20.58 |   3.09 | 15.0 |    2212.72 |  3109.06
secretbuffer                       (7) |        started at 2022-01-10T15:49:25.582
iostream                           (4) |     0.76 |   0.00 |  0.0 |     152.89 |  3853.19
specificity                        (4) |        started at 2022-01-10T15:49:25.780
      From worker 4:	WARNING: Method definition f(Tuple{Vararg{Int64, N}}, AbstractArray{T, N}) where {T, N} in module Test81Main_specificity at /Users/dpn/Build/Source/julia.13/test/specificity.jl:87 overwritten at /Users/dpn/Build/Source/julia.13/test/specificity.jl:93.
specificity                        (4) |     0.12 |   0.00 |  0.0 |       3.49 |  3853.19
reinterpretarray                   (4) |        started at 2022-01-10T15:49:25.926
      From worker 7:	testing position
secretbuffer                       (7) |     1.05 |   0.68 | 64.6 |      40.88 |  3109.06
syntax                             (7) |        started at 2022-01-10T15:49:26.670
      From worker 7:	WARNING: Method definition (::Test1Main_syntax.var"#f#150"{var"#s36577"})() in module Test1Main_syntax overwritten.
syntax                             (7) |     4.72 |   0.03 |  0.6 |     466.31 |  3109.06
      From worker 7:	┌ Warning: a SecretBuffer was `shred!`ed by the GC; use `shred!` manually after use to minimize exposure.
      From worker 7:	└ @ Base secretbuffer.jl:169
      From worker 7:	┌ Warning: a SecretBuffer was `shred!`ed by the GC; use `shred!` manually after use to minimize exposure.
      From worker 7:	└ @ Base secretbuffer.jl:169
      From worker 7:	┌ Warning: a SecretBuffer was `shred!`ed by the GC; use `shred!` manually after use to minimize exposure.
      From worker 7:	└ @ Base secretbuffer.jl:169
corelogging                        (7) |        started at 2022-01-10T15:49:31.495
reinterpretarray                   (4) |     7.25 |   0.18 |  2.5 |    1410.22 |  3853.19
missing                            (4) |        started at 2022-01-10T15:49:33.175
corelogging                        (7) |     2.42 |   0.08 |  3.1 |     309.44 |  3194.33
asyncmap                           (7) |        started at 2022-01-10T15:49:33.954
LinearAlgebra/addmul               (5) |   240.16 |   5.90 |  2.5 |   34451.81 |  1986.83
smallarrayshrink                   (5) |        started at 2022-01-10T15:49:34.949
smallarrayshrink                   (5) |     0.27 |   0.00 |  0.0 |      24.39 |  1986.83
opaque_closure                     (5) |        started at 2022-01-10T15:49:35.222
opaque_closure                     (5) |     0.44 |   0.02 |  3.8 |      64.76 |  1986.83
filesystem                         (5) |        started at 2022-01-10T15:49:35.679
filesystem                         (5) |     0.10 |   0.00 |  0.0 |      17.31 |  1986.83
download                           (5) |        started at 2022-01-10T15:49:35.789
asyncmap                           (7) |     6.50 |   0.11 |  1.7 |     574.13 |  3247.47
SparseArrays/higherorderfns        (7) |        started at 2022-01-10T15:49:40.507
channels                           (6) |    20.15 |   5.54 | 27.5 |     368.84 |  3146.39
SparseArrays/sparse                (6) |        started at 2022-01-10T15:49:41.268
missing                            (4) |     9.47 |   0.12 |  1.3 |    1334.37 |  3853.19
SparseArrays/sparsevector          (4) |        started at 2022-01-10T15:49:42.645
download                           (5) |    31.85 |   0.00 |  0.0 |       1.65 |  1986.83
LibGit2/libgit2                    (5) |        started at 2022-01-10T15:50:07.645
SparseArrays/higherorderfns        (7) |    64.41 |   1.81 |  2.8 |   10542.80 |  3397.31
Dates/accessors                    (7) |        started at 2022-01-10T15:50:44.925
Dates/accessors                    (7) |     4.47 |   0.51 | 11.4 |    3423.22 |  3397.31
Dates/adjusters                    (7) |        started at 2022-01-10T15:50:49.398
Dates/adjusters                    (7) |     4.50 |   0.07 |  1.6 |     302.29 |  3397.31
Dates/query                        (7) |        started at 2022-01-10T15:50:53.905
Dates/query                        (7) |     0.83 |   0.11 | 13.9 |     107.85 |  3397.31
Dates/periods                      (7) |        started at 2022-01-10T15:50:54.733
Dates/periods                      (7) |    10.83 |   0.32 |  3.0 |    1709.30 |  3397.31
Dates/ranges                       (7) |        started at 2022-01-10T15:51:05.568
LibGit2/libgit2                    (5) |    67.50 |   0.38 |  0.6 |    1336.15 |  2482.23
Dates/rounding                     (5) |        started at 2022-01-10T15:51:15.153
Dates/ranges                       (7) |    10.02 |   0.29 |  2.9 |    1174.90 |  3397.31
Dates/types                        (7) |        started at 2022-01-10T15:51:15.587
Dates/rounding                     (5) |     1.02 |   0.00 |  0.0 |     168.61 |  2523.94
Dates/io                           (5) |        started at 2022-01-10T15:51:16.178
Dates/types                        (7) |     0.74 |   0.00 |  0.0 |     100.30 |  3397.31
Dates/arithmetic                   (7) |        started at 2022-01-10T15:51:16.330
Dates/arithmetic                   (7) |     4.62 |   0.15 |  3.2 |     755.52 |  3397.31
Dates/conversions                  (7) |        started at 2022-01-10T15:51:20.955
Dates/conversions                  (7) |     0.43 |   0.00 |  0.0 |      34.70 |  3397.31
ArgTools                           (7) |        started at 2022-01-10T15:51:21.385
SparseArrays/sparsevector          (4) |    99.80 |   2.46 |  2.5 |   21964.96 |  4064.33
Artifacts                          (4) |        started at 2022-01-10T15:51:22.452
Dates/io                           (5) |     6.37 |   0.37 |  5.8 |    1093.85 |  2988.92
Base64                             (5) |        started at 2022-01-10T15:51:22.550
      From worker 4:	 Downloading artifact: HelloWorldC
Base64                             (5) |     1.28 |   0.19 | 14.5 |    1606.95 |  2988.92
CRC32c                             (5) |        started at 2022-01-10T15:51:23.837
      From worker 4:	 Downloading artifact: HelloWorldC
CRC32c                             (5) |     0.34 |   0.02 |  5.1 |      60.24 |  2988.92
CompilerSupportLibraries_jll       (5) |        started at 2022-01-10T15:51:24.182
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
CompilerSupportLibraries_jll       (5) |     0.73 |   0.00 |  0.0 |       8.06 |  2988.92
DelimitedFiles                     (5) |        started at 2022-01-10T15:51:24.911
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
DelimitedFiles                     (5) |     3.33 |   0.14 |  4.2 |     650.01 |  2988.92
Downloads                          (5) |        started at 2022-01-10T15:51:28.240
      From worker 4:	 Downloading artifact: HelloWorldC
      From worker 4:	 Downloading artifact: HelloWorldC
Artifacts                          (4) |     8.17 |   0.10 |  1.2 |     260.98 |  4064.33
FileWatching                       (4) |        started at 2022-01-10T15:51:30.625
cmdlineargs                        (3) |   143.34 |   0.29 |  0.2 |     792.16 |  3851.09
Future                             (3) |        started at 2022-01-10T15:51:31.161
Future                             (3) |     0.00 |   0.00 |  0.0 |       0.05 |  3851.09
GMP_jll                            (3) |        started at 2022-01-10T15:51:31.170
GMP_jll                            (3) |     0.42 |   0.00 |  0.0 |       0.70 |  3851.09
InteractiveUtils                   (3) |        started at 2022-01-10T15:51:31.592
ArgTools                           (7) |    11.21 |   0.50 |  4.5 |    1242.00 |  3397.31
LLVMLibUnwind_jll                  (7) |        started at 2022-01-10T15:51:32.601
LLVMLibUnwind_jll                  (7) |     0.34 |   0.00 |  0.0 |       8.14 |  3397.31
LazyArtifacts                      (7) |        started at 2022-01-10T15:51:32.939
      From worker 7:	 Downloading artifact: socrates
      From worker 7:	 Downloading artifact: socrates
LazyArtifacts                      (7) |     4.41 |   0.09 |  2.0 |     482.05 |  3397.31
LibCURL                            (7) |        started at 2022-01-10T15:51:37.355
LibCURL                            (7) |     1.38 |   0.00 |  0.0 |      11.44 |  3397.31
LibCURL_jll                        (7) |        started at 2022-01-10T15:51:38.734
LibCURL_jll                        (7) |     0.02 |   0.00 |  0.0 |       0.94 |  3397.31
LibGit2_jll                        (7) |        started at 2022-01-10T15:51:38.760
LibGit2_jll                        (7) |     0.94 |   0.00 |  0.0 |       2.36 |  3397.31
LibSSH2_jll                        (7) |        started at 2022-01-10T15:51:39.710
LibSSH2_jll                        (7) |     0.02 |   0.00 |  0.0 |       0.87 |  3397.31
LibUV_jll                          (7) |        started at 2022-01-10T15:51:39.727
LibUV_jll                          (7) |     0.45 |   0.00 |  0.0 |       6.36 |  3397.31
LibUnwind_jll                      (7) |        started at 2022-01-10T15:51:40.182
LibUnwind_jll                      (7) |     0.30 |   0.00 |  0.0 |       0.35 |  3397.31
Libdl                              (7) |        started at 2022-01-10T15:51:40.487
Libdl                              (7) |     0.51 |   0.00 |  0.0 |      42.19 |  3397.31
Logging                            (7) |        started at 2022-01-10T15:51:41
Logging                            (7) |     0.82 |   0.00 |  0.0 |     177.28 |  3397.31
MPFR_jll                           (7) |        started at 2022-01-10T15:51:41.827
MPFR_jll                           (7) |     0.34 |   0.00 |  0.0 |       1.35 |  3397.31
Markdown                           (7) |        started at 2022-01-10T15:51:42.165
InteractiveUtils                   (3) |    11.62 |   0.39 |  3.3 |    2416.76 |  3851.09
MbedTLS_jll                        (3) |        started at 2022-01-10T15:51:43.219
MbedTLS_jll                        (3) |     0.02 |   0.00 |  0.0 |       3.38 |  3851.09
Mmap                               (3) |        started at 2022-01-10T15:51:43.244
floatfuncs                         (2) |   149.25 |   6.30 |  4.2 |   55572.01 |  2590.00
MozillaCACerts_jll                 (2) |        started at 2022-01-10T15:51:43.812
MozillaCACerts_jll                 (2) |     0.00 |   0.00 |  0.0 |       0.09 |  2590.00
NetworkOptions                     (2) |        started at 2022-01-10T15:51:43.846
NetworkOptions                     (2) |     0.60 |   0.00 |  0.0 |      63.87 |  2590.00
OpenBLAS_jll                       (2) |        started at 2022-01-10T15:51:44.453
OpenBLAS_jll                       (2) |     0.35 |   0.00 |  0.0 |       8.79 |  2590.00
OpenLibm_jll                       (2) |        started at 2022-01-10T15:51:44.807
OpenLibm_jll                       (2) |     0.30 |   0.00 |  0.0 |       1.11 |  2590.00
PCRE2_jll                          (2) |        started at 2022-01-10T15:51:45.107
PCRE2_jll                          (2) |     0.26 |   0.00 |  0.0 |       4.02 |  2590.00
Printf                             (2) |        started at 2022-01-10T15:51:45.370
Markdown                           (7) |     3.56 |   0.17 |  4.9 |     601.70 |  3397.31
Profile                            (7) |        started at 2022-01-10T15:51:45.724
Printf                             (2) |     7.34 |   0.27 |  3.7 |    1841.46 |  2590.00
REPL                               (2) |        started at 2022-01-10T15:51:52.711
Profile                            (7) |     7.29 |   0.06 |  0.8 |     538.42 |  3397.31
Random                             (7) |        started at 2022-01-10T15:51:53.018
      From worker 2:	foo
      From worker 2:	foo foo
Mmap                               (3) |    13.62 |  12.46 | 91.5 |     211.76 |  3851.09
SHA                                (3) |        started at 2022-01-10T15:51:56.866
      From worker 3:	[ Info: Loaded hash types: SHA1, SHA2-224, SHA2-256, SHA2-384, SHA2-512, SHA3-224, SHA3-256, SHA3-384 and SHA3-512
REPL                               (2) |    12.41 |   0.36 |  2.9 |    1884.03 |  2590.00
Serialization                      (2) |        started at 2022-01-10T15:52:05.122
FileWatching                       (4) |    35.20 |   4.17 | 11.8 |     110.39 |  4064.33
Sockets                            (4) |        started at 2022-01-10T15:52:05.832
Serialization                      (2) |     2.65 |   0.11 |  4.2 |     729.96 |  2590.00
Statistics                         (2) |        started at 2022-01-10T15:52:07.773
Random                             (7) |    24.01 |   0.65 |  2.7 |    4113.62 |  3397.31
SuiteSparse                        (7) |        started at 2022-01-10T15:52:17.033
Sockets                            (4) |    15.19 |   0.00 |  0.0 |     232.88 |  4064.33
SuiteSparse_jll                    (4) |        started at 2022-01-10T15:52:21.030
SuiteSparse_jll                    (4) |     1.42 |   0.00 |  0.0 |       9.70 |  4064.33
TOML                               (4) |        started at 2022-01-10T15:52:22.450
TOML                               (4) |     5.71 |   0.15 |  2.7 |     927.45 |  4064.33
Tar                                (4) |        started at 2022-01-10T15:52:28.159
Statistics                         (2) |    27.08 |   1.32 |  4.9 |    5393.31 |  2590.00
Test                               (2) |        started at 2022-01-10T15:52:34.859
SHA                                (3) |    40.57 |   0.05 |  0.1 |     753.29 |  3851.09
UUIDs                              (3) |        started at 2022-01-10T15:52:37.435
UUIDs                              (3) |     0.19 |   0.00 |  0.0 |      40.31 |  3851.09
Unicode                            (3) |        started at 2022-01-10T15:52:37.623
Unicode                            (3) |     2.46 |   0.08 |  3.4 |     438.90 |  3851.09
Zlib_jll                           (3) |        started at 2022-01-10T15:52:40.085
Zlib_jll                           (3) |     0.28 |   0.00 |  0.0 |       1.15 |  3851.09
dSFMT_jll                          (3) |        started at 2022-01-10T15:52:40.369
dSFMT_jll                          (3) |     0.26 |   0.00 |  0.0 |       1.17 |  3851.09
libLLVM_jll                        (3) |        started at 2022-01-10T15:52:40.637
libLLVM_jll                        (3) |     0.24 |   0.00 |  0.0 |       0.37 |  3851.09
libblastrampoline_jll              (3) |        started at 2022-01-10T15:52:40.878
libblastrampoline_jll              (3) |     0.01 |   0.00 |  0.0 |       1.36 |  3851.09
nghttp2_jll                        (3) |        started at 2022-01-10T15:52:40.896
nghttp2_jll                        (3) |     0.03 |   0.00 |  0.0 |       1.40 |  3851.09
p7zip_jll                          (3) |        started at 2022-01-10T15:52:40.925
p7zip_jll                          (3) |     0.00 |   0.00 |  0.0 |       0.11 |  3851.09
Downloads                          (5) |    77.40 |   0.40 |  0.5 |     378.36 |  2988.92
Test                               (2) |    15.46 |   0.21 |  1.4 |     744.04 |  2590.00
Tar                                (4) |    41.53 |   1.11 |  2.7 |    4865.18 |  4064.33
      From worker 7:	Test Summary:              | Pass  Total  Time
      From worker 7:	threaded SuiteSparse tests |    1      1  6.4s
SuiteSparse                        (7) |    61.90 |   2.03 |  3.3 |    8983.04 |  3701.77
SparseArrays/sparse                (6) |   222.64 |  56.95 | 25.6 |   23185.01 |  3146.39

Executing tests that run on node 1 only:
precompile                         (1) |        started at 2022-01-10T15:53:24.173
precompile                         (1) |    15.11 |   0.09 |  0.6 |     543.11 |   351.28
SharedArrays                       (1) |        started at 2022-01-10T15:53:39.286
SharedArrays                       (1) |    11.37 |   0.51 |  4.5 |    1542.02 |   442.45
threads                            (1) |        started at 2022-01-10T15:53:50.656
Test Summary:                     | Pass  Total  Time
Threads.Conditions must be locked |    5      5  0.0s
Test Summary:      | Pass  Total  Time
InvasiveLinkedList |   72     72  0.1s
Test Summary:        | Pass  Total  Time
@spawn interpolation |   10     10  0.2s
Test Summary:        | Pass  Total  Time
@async interpolation |    8      8  0.0s
Test Summary:                   | Pass  Total  Time
spawn interpolation: macrocalls |    2      2  1.7s
Test Summary: | Pass  Total  Time
Co-schedule   |    1      1  0.0s
Test Summary:                 | Pass  Total  Time
Threads.foreach(f, ::Channel) |    7      7  1.1s
Test Summary:     | Pass  Total  Time
Task-local random |    4      4  0.1s
Test Summary: | Pass  Total  Time
Racy `@spawn` |    1      1  0.1s
Test Summary:   | Pass  Total  Time
package loading |    1      1  0.3s
Warning: threaded loop executed in order
Test Summary:                     | Pass  Total  Time
Threads.Conditions must be locked |    5      5  0.0s
Test Summary:      | Pass  Total  Time
InvasiveLinkedList |   72     72  0.1s
Test Summary:        | Pass  Total  Time
@spawn interpolation |   10     10  0.2s
Test Summary:        | Pass  Total  Time
@async interpolation |    8      8  0.0s
Test Summary:                   | Pass  Total  Time
spawn interpolation: macrocalls |    2      2  1.7s
Test Summary: | Pass  Total  Time
Co-schedule   |    1      1  0.0s
Test Summary:                 | Pass  Total  Time
Threads.foreach(f, ::Channel) |    7      7  1.2s
Test Summary:     | Pass  Total  Time
Task-local random |    4      4  0.0s
Test Summary: | Pass  Total  Time
Racy `@spawn` |    1      1  0.1s
Test Summary:   | Pass  Total  Time
package loading |    1      1  0.0s
Test Summary:                     | Pass  Total  Time
Threads.Conditions must be locked |    5      5  0.0s
Test Summary:      | Pass  Total  Time
InvasiveLinkedList |   72     72  0.1s
Test Summary:        | Pass  Total  Time
@spawn interpolation |   10     10  0.2s
Test Summary:        | Pass  Total  Time
@async interpolation |    8      8  0.0s
Test Summary:                   | Pass  Total  Time
spawn interpolation: macrocalls |    2      2  1.8s
Test Summary: | Pass  Total  Time
Co-schedule   |    1      1  0.0s
Test Summary:                 | Pass  Total  Time
Threads.foreach(f, ::Channel) |    7      7  1.2s
Test Summary:     | Pass  Total  Time
Task-local random |    4      4  0.0s
Test Summary: | Pass  Total  Time
Racy `@spawn` |    1      1  0.1s
Test Summary:   | Pass  Total  Time
package loading |    1      1  0.0s
Test Summary:                     | Pass  Total  Time
Threads.Conditions must be locked |    5      5  0.0s
Test Summary:      | Pass  Total  Time
InvasiveLinkedList |   72     72  0.1s
Test Summary:        | Pass  Total  Time
@spawn interpolation |   10     10  0.2s
Test Summary:        | Pass  Total  Time
@async interpolation |    8      8  0.0s
Test Summary:                   | Pass  Total  Time
spawn interpolation: macrocalls |    2      2  1.7s
Test Summary: | Pass  Total  Time
Co-schedule   |    1      1  0.0s
Test Summary:                 | Pass  Total  Time
Threads.foreach(f, ::Channel) |    7      7  1.3s
Test Summary:     | Pass  Total  Time
Task-local random |    4      4  0.0s
Test Summary: | Pass  Total  Time
Racy `@spawn` |    1      1  0.1s
Test Summary:   | Pass  Total  Time
package loading |    1      1  0.0s
threads                            (1) |    81.25 |   0.02 |  0.0 |      71.64 |   445.62
Distributed                        (1) |        started at 2022-01-10T15:55:11.904
[ Info: SO_REUSEPORT is unsupported, skipping reuseport tests
Distributed                        (1) |    78.08 |   0.01 |  0.0 |      66.62 |   448.33
stress                             (1) |        started at 2022-01-10T15:56:29.988
stress                             (1) |     7.27 |   0.02 |  0.3 |      97.64 |   449.69
Test Summary: |     Pass  Broken     Total      Time
  Overall     | 39519519  352638  39872157  11m15.7s
    SUCCESS

This is with an extra hack to avoid the task switching hangs, see #41820.

@dnadlinger
Copy link
Member Author

dnadlinger commented Jan 14, 2022

Gentle ping – anything I can do to help the review along? It would be nice for M1 to get some more testing before 1.8. Note that there are no (intended) changes to non-aarch64-darwin platforms.

@MilesCranmer
Copy link
Member

MilesCranmer commented Jan 14, 2022

Just tested this on my M1 Pro. Works great! It solves all of the segfaults I was seeing in my package SymbolicRegression.jl.

Julia maintainers, please merge this ASAP. My packages are broken on M1 without this change; with the change, they are working well.

To summarize my test:

This lets me run the example code on the README of SymbolicRegression.jl. Before this change, on Julia 1.7.1, I encountered immediate segfaults in both distributed and multithreaded mode (but serial mode seemed to work).

@dnadlinger
Copy link
Member Author

dnadlinger commented Jan 14, 2022

@MilesCranmer: Glad to hear this does the job for you. I'm actually a bit surprised that upstream LLVM main without the Julia patches is working for you – backtraces will certainly be broken, and there is also a known AArch64 miscompilation. Or is your build perhaps using the BinaryBuilder LLVM after all? If you do want to use LLVM 14, you can e.g. rebase my julia-main branch onto latest upstream main: https://github.com/dnadlinger/llvm-project/commits/julia-main

(Let's not rush the people who'll have to review this slight mess of a change, though.)

@MilesCranmer
Copy link
Member

MilesCranmer commented Jan 14, 2022

Yes, this is using the LLVM main branch as of 2291413554ff (i.e., LLVM 14). I didn't use any of the LLVM patches you mentioned which I also find surprising. I don't see compilation issues either - do you mean a silent bug or an error message?

I did see some issues with mislinked LLVM libraries but those went away after setting LLVMROOT. I'm not using BinaryBuilder. I installed LLVM with brew install --HEAD llvm which just triggers cmake/make on the latest Git commit. (I couldn't build LLVM 14 manually due to some dependency issues which brew sorted out for me.)

Update: I get similar test numbers (LLVM 14 main branch)

Test Summary: |     Pass  Broken     Total      Time
  Overall     | 39530433  352638  39883071  16m55.8s
    SUCCESS

@dnadlinger
Copy link
Member Author

Ah, 2291413554ff does already have my __eh_frame JITLink patch (with Lang's tests), so it's not entirely implausible, but I'm still surprised that the stacktrace-related tests pass without the other patch that unconditionally enables __eh_frame generation.

Regarding the miscompilation, I was referring to code generated by Julia – see Keno's commit for details. The original issue is probably linked from the M1 tracking issue.

@chriselrod
Copy link
Contributor

Do you have any idea why I may be getting this error when using an llvm installed from homebrew?

In file included from /opt/homebrew/opt/llvm/bin/../include/c++/v1/iosfwd:98:
/opt/homebrew/opt/llvm/bin/../include/c++/v1/wchar.h:119:15: fatal error: 'wchar.h' file not found
#include_next <wchar.h>
              ^~~~~~~~~
1 error generated.

If I remove this from the path, I can build this PR.
However, another project needs llvm.
Maybe I just need to find a different way to set paths for different projects. On Linux, this all "just works".

This isn't really a problem I have with this PR, unless errors building with certain libraries like this is related more to it than user error/inexperience on my behalf.

About this PR itself: great work! I tried a few tests that consistently segfaulted before. Now, it all works! Will be great when this gets merged.

@dnadlinger
Copy link
Member Author

@chriselrod Unfortunately, I'm (mostly) not using Homebrew myself these days, so I don't really know. Looking at the LLVM formula, it seems that they are overriding libcxx; not sure if that could be related.

@DilumAluthge
Copy link
Member

DilumAluthge commented Jan 19, 2022

It seems like a bug that the Julia build process is finding an LLVM from elsewhere on your system. Unless you explicitly pass USE_SYSTEM_LLVM=1, we shouldn't be doing that.

Comment on lines +665 to +673
size_t SepPos = Sec.getName().find(',');
if (SepPos >= 16 || (Sec.getName().size() - (SepPos + 1) > 16)) {
LLVM_DEBUG({
dbgs() << "JLDebuginfoPlugin: Ignoring section '" << Sec.getName()
<< "'\n";
});
continue;
}
auto SecName = Sec.getName().substr(SepPos + 1);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
size_t SepPos = Sec.getName().find(',');
if (SepPos >= 16 || (Sec.getName().size() - (SepPos + 1) > 16)) {
LLVM_DEBUG({
dbgs() << "JLDebuginfoPlugin: Ignoring section '" << Sec.getName()
<< "'\n";
});
continue;
}
auto SecName = Sec.getName().substr(SepPos + 1);
auto SecName = Sec.getName().split(',')[2];
if (SecName.empty()) {
LLVM_DEBUG({
dbgs() << "JLDebuginfoPlugin: Ignoring section '" << Sec.getName()
<< "'\n";
});
continue;
}

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, this was more complex at first to transparently handle non-MachO formats (where the segment name doesn't appear in the JITLink section name), but I then figured we'd cross that bridge when we get there.

@vtjnash vtjnash merged commit 487f0b4 into JuliaLang:master Jan 19, 2022
@staticfloat
Copy link
Member

This is fantastic! Thank you all!

@fonsp
Copy link
Member

fonsp commented Jan 27, 2022

It looks like this PR fixed many segfault issues for M1 users (in CSV, Pkg, MLJ), yayy!

Would it be possible to backport this into the 1.7.2 release?

@giordano
Copy link
Contributor

Would it be possible to backport this into the 1.7.2 release?

No: #42295 (comment)

@MilesCranmer
Copy link
Member

@vchuravy for CI would it be enough to run it in a docker with a aarch64 platform (i.e., on linux) rather than an M1 machine? e.g., with https://github.com/marketplace/actions/run-on-architecture?

@giordano
Copy link
Contributor

Julia CI already runs on aarch64-linux-gnu

@dnadlinger
Copy link
Member Author

@MilesCranmer: Nice idea, but unfortunately no; apart from all the other platform-dependent issues that running on Linux would miss, we also don't currently use JITLink on Linux, as ELF support is very much WIP for it still.

@MilesCranmer
Copy link
Member

Got it, thanks for the explanation

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
system:mac Affects only macOS
Projects
None yet
Development

Successfully merging this pull request may close these issues.

SVD test segfaults on Apple M1