With ASAN enabled on Linux ARM, the tests completion takes much more time.

[bryce-shang]

With ASAN enabled, BoringSSL blackbox tests are 15 times slower on Linux ARM.

Notes

Hello, below description is very coupled to BoringSSL. If this reproduce step is not specific or needs additional narrow down, would someone provide some suggestions on the investigation/narrow down direction?

Below are the enabled ASAN flags.

  set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -fsanitize=address -fsanitize-address-use-after-scope -fno-omit-frame-pointer")
  set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -fsanitize=address -fsanitize-address-use-after-scope -fno-omit-frame-pointer")

Issue

With ASAN enabled, BoringSSL blackbox tests takes at least 30 minutes to complete 5k test cases on Linux ARM.

• blackbox tests refer to run go test under ssl/test/runner.
• the blackbox tests takes less than 2 minutes on other test dimensions -- X86 without ASAN, X86 with ASAN, ARM without ASAN.

OS & Arch	Time to complete blackbox tests	ASAN enabled
Ubuntu 20.04 X86	< 2 min	No
Ubuntu 20.04 X86	< 2 min	Yes
Ubuntu 20.04 ARM	< 2 min	No
Ubuntu 20.04 ARM	> 30 min	Yes

Expected Behavior

With ASAN enabled, BoringSSL blackbox tests should finish within 2 minutes on Linux ARM.

Reproduce steps on Ubuntu 20.04 ARM

Install tools

set -ex && \
apt-get update && \
apt-get -y --no-install-recommends upgrade && \
apt-get -y --no-install-recommends install \
clang \
pkg-config \
libunwind-dev \
cmake \
ninja-build \
perl \
quilt \
ca-certificates \
wget && \
cd /tmp && \
wget https://dl.google.com/go/go1.13.12.linux-arm64.tar.gz && \
tar -xvf go1.13.12.linux-arm64.tar.gz && \
mv go /usr/local

export CC=clang
export CXX=clang++
export GOROOT=/usr/local/go
export PATH="$GOROOT/bin:$PATH"
export DEPENDENCIES_DIR=/home/dependencies
export LLVM_PROJECT_HOME=${DEPENDENCIES_DIR}/llvm-project

apt-get -y --no-install-recommends install \
llvm \
llvm-dev \
lld \
git \
quilt \
ca-certificates && \
mkdir -p ${DEPENDENCIES_DIR} && \
cd ${DEPENDENCIES_DIR} && \
git clone https://github.com/llvm/llvm-project.git --branch llvmorg-8.0.1  --depth 1 

Run tests

git clone https://github.com/google/boringssl.git
cd boringssl && \
mkdir -p build && \
cd build && \
cmake -GNinja -DASAN=1 -DCMAKE_BUILD_TYPE=Release .. && \
ninja && \
# https://github.com/google/boringssl/blob/master/BUILDING.md
cd ../ssl/test/runner && \
go test

[kcc]

Thanks for the report.
Any chance you can provide a smaller reproducer?

[bryce-shang]

Yes, I can try to do it. :)

But can you help provide some suggestions how to narrow down the reproduce steps? There are 5k test cases. Based on what I have observed, each test process time becomes longer when ASAN enabled.

[kcc]

Given the slowdown is that bad, it should be something simple.
If you can, take a single test that has the biggest relative slowdown, and run it under perf record,
then send perf report here.

Hm... Now that I think of it more, it's probably similar to #703 where lsan takes much time at exit
On a tiny test lsan takes 3 seconds to complete. Which is not too bad for large tests, but if you have 5K small tests, it starts being annoying.

It should be fixable, but AArch64 asan (and lsan) is nowhere near the top of our priorities... :(

[kcc]

Just confirmed, perf shows this:

  99.76%  a.out    a.out             [.] __lsan::ForEachChunk                                                                                                                                                      

[choujayyl]

ASAN support linux arm 32bit now?@kcc

[bryce-shang]

Sorry for late response.

Below is the 1st 100 lines of the perf data. Only 7 of the 5k tests are enabled.

#
# Overhead  Command      Shared Object        Symbol                                                                                                                                                                                           
# ........  ...........  ...................  .................................................................................................................................................................................................
#
    94.89%  bssl_shim    bssl_shim            [.] __lsan::ForEachChunk
     0.33%  vet          vet                  [.] runtime.scanobject
     0.28%  vet          vet                  [.] runtime.greyobject
     0.16%  vet          vet                  [.] runtime.findObject
     0.15%  bssl_shim    bssl_shim            [.] __sanitizer::CombinedAllocator<__sanitizer::SizeClassAllocator32<__asan::AP32<__sanitizer::LocalAddressSpaceView> >, __sanitizer::LargeMmapAllocatorPtrArrayDynamic>::GetBlockBeginFastLocked
     0.11%  vet          vet                  [.] go/token.(*File).SetLines
     0.10%  bssl_shim    [unknown]            [k] 0xffff800010138440
     0.08%  go           go                   [.] runtime.greyobject
     0.07%  link         link                 [.] runtime.scanobject
     0.06%  bssl_shim    bssl_shim            [.] __lsan::GetUserBegin
     0.06%  vet          vet                  [.] runtime.mallocgc
     0.06%  go           go                   [.] runtime.scanobject
     0.05%  link         link                 [.] cmd/link/internal/loader.(*Loader).SymType
     0.05%  vet          vet                  [.] runtime.gcDrain
     0.04%  bssl_shim    bssl_shim            [.] __lsan::LsanMetadata::allocated
     0.04%  link         link                 [.] cmd/link/internal/loader.(*Loader).resolve
     0.04%  bssl_shim    [unknown]            [k] 0xffff800010d6f640
     0.03%  link         link                 [.] runtime.mapaccess2_fast64
     0.03%  bssl_shim    bssl_shim            [.] __lsan::ScanRangeForPointers
     0.03%  link         link                 [.] cmd/link/internal/sym.(*Attribute).Set
     0.03%  go           go                   [.] runtime.findObject
     0.03%  vet          vet                  [.] runtime.memmove
     0.03%  vet          vet                  [.] runtime.mapassign
     0.03%  vet          vet                  [.] runtime.heapBitsSetType
     0.02%  link         link                 [.] indexbytebody
     0.02%  bssl_shim    bssl_shim            [.] __sanitizer::StackDepotReverseMap::StackDepotReverseMap
     0.02%  link         link                 [.] cmd/link/internal/loader.Reloc2.Sym
     0.02%  go           go                   [.] runtime.mallocgc
     0.02%  link         link                 [.] cmd/link/internal/loader.(*Loader).convertRelocations
     0.02%  go           go                   [.] bufio.(*Reader).ReadByte
     0.02%  vet          vet                  [.] runtime.evacuate
     0.02%  link         link                 [.] runtime.memmove
     0.02%  link         link                 [.] runtime.findObject
     0.02%  go           go                   [.] crypto/sha256.sha256block
     0.02%  runner.test  runner.test          [.] 0x00000000001293ec
     0.02%  link         link                 [.] runtime.mapaccess2_faststr
     0.02%  vet          [unknown]            [k] 0xffff800010d6f640
     0.02%  link         link                 [.] cmd/link/internal/loader.(*Loader).SymAttr
     0.02%  link         link                 [.] strings.Index
     0.02%  link         link                 [.] cmd/link/internal/ld.(*workQueue).Less
     0.02%  link         link                 [.] runtime.mapaccess1_fast64
     0.02%  link         [unknown]            [k] 0xffff800010d6f640
     0.02%  bssl_shim    libc-2.31.so         [.] __sched_yield
     0.02%  vet          vet                  [.] runtime.mapassign_fast64ptr
     0.02%  runner.test  runner.test          [.] 0x000000000012938c
     0.02%  vet          vet                  [.] runtime.mapaccess1_faststr
     0.02%  vet          vet                  [.] runtime.wbBufFlush1
     0.02%  bssl_shim    [unknown]            [k] 0xffff80001009eb6c
     0.02%  go           [unknown]            [k] 0xffff800010138474
     0.01%  vet          vet                  [.] go/scanner.(*Scanner).next
     0.01%  link         link                 [.] container/heap.down
     0.01%  link         link                 [.] cmd/link/internal/ld.relocsym2
     0.01%  link         link                 [.] cmd/internal/goobj2.(*Sym).Name
     0.01%  runner.test  runner.test          [.] 0x00000000001291d4
     0.01%  link         link                 [.] runtime.mapassign_faststr
     0.01%  link         link                 [.] cmd/internal/goobj2.(*Reader).RelocOff
     0.01%  vet          vet                  [.] runtime.memclrNoHeapPointers
     0.01%  vet          vet                  [.] runtime.typedmemmove
     0.01%  go           go                   [.] runtime.memclrNoHeapPointers
     0.01%  bssl_shim    [unknown]            [k] 0xffff800010083f24
     0.01%  go           go                   [.] runtime.lock2
     0.01%  runner.test  runner.test          [.] 0x000000000012c2c0
     0.01%  link         link                 [.] cmd/link/internal/ld.(*deadcodePass).flood
     0.01%  link         link                 [.] cmd/link/internal/loader.loadObjFull
     0.01%  vet          vet                  [.] go/types.(*Checker).rawLookupFieldOrMethod
     0.01%  vet          vet                  [.] cmd/vendor/golang.org/x/tools/go/ast/inspector.(*Inspector).Preorder
     0.01%  link         link                 [.] cmd/internal/goobj2.(*Reader).Data
     0.01%  vet          vet                  [.] runtime.(*lfstack).pop
     0.01%  go           [unknown]            [k] 0xffff800010d70120
     0.01%  link         link                 [.] runtime.mallocgc
     0.01%  vet          vet                  [.] runtime.interhash
     0.01%  link         link                 [.] strings.Count
     0.01%  vet          vet                  [.] runtime.typehash
     0.01%  vet          vet                  [.] go/types.(*Checker).ident
     0.01%  vet          vet                  [.] go/types.(*Checker).recordTypeAndValue
     0.01%  bssl_shim    bssl_shim            [.] __sanitizer::SizeClassAllocator32<__asan::AP32<__sanitizer::LocalAddressSpaceView> >::PopulateFreeList
     0.01%  runner.test  runner.test          [.] 0x0000000000134094
     0.01%  link         link                 [.] strings.LastIndexByte
     0.01%  link         link                 [.] cmd/link/internal/loader.(*Loader).UndefinedRelocTargets
     0.01%  vet          vet                  [.] go/types.(*object).sameId
     0.01%  bssl_shim    bssl_shim            [.] __sanitizer::internal_memset
     0.01%  bssl_shim    bssl_shim            [.] __sanitizer::StackDepotBase<__sanitizer::StackDepotNode, 1, 20>::Put
     0.01%  link         link                 [.] cmd/link/internal/loader.(*Loader).SymSize
     0.01%  link         link                 [.] cmd/link/internal/loader.(*Loader).preloadSyms
     0.01%  link         link                 [.] runtime.greyobject
     0.01%  bssl_shim    bssl_shim            [.] __lsan::ResetTagsCb
     0.01%  link         link                 [.] cmd/link/internal/loader.(*Loader).SymName
     0.01%  bssl_shim    [unknown]            [k] 0xffff8000103227dc
     0.01%  go           go                   [.] runtime.(*lfstack).pop