A Disciplined Approach to Debugging - PowerPoint Presentation

342 views
Uploaded On 2022-08-03

A Disciplined Approach to Debugging - PPT Presentation

Embedded Linux Conference June 30 2020 Lev Iserovich DE Shaw Research LLC Independent research lab founded in 2002 Founder and Chief Scientist David E Shaw Main office in New York NY ID: 933465

git heap profile error heap git error profile hprof tmp lwp lib64 dumping libpthread wait mkl read www 22293

Link:

Copy

Embed:

<iframe width="560" height="315" src="https://www.docslides.com/embed/933465" frameborder="0" allowfullscreen></iframe>

Download Presentation from below link

Download Presentation The PPT/PDF document "A Disciplined Approach to Debugging" is the property of its rightful owner. Permission is granted to download and print the materials on this web site for personal, non-commercial use only, and to display it on your personal computer provided you do not modify the materials and that you retain all copyright notices contained in the materials. By downloading content from our website, you accept the terms of this agreement.

Presentation Transcript

Slide1

A Disciplined Approach to Debugging

Embedded Linux Conference

June 30, 2020

Lev

Iserovich

D.E. Shaw Research, LLC

Slide2

Independent research lab founded in 2002

Founder and Chief Scientist:

David E. ShawMain office in New York, NYHigh-level goal: Make an impact in the fields of biology and chemistry using advances in computational methods and computer hardwareDevelop Anton supercomputers for acceleration of molecular dynamics simulations

Slide3

Debugging Statistics

~50% of developer time spent on admin tasks

1~50% of programming time is spent debugging1~25% of your time is spent debuggingAbout 1.5M SW developers in US, total wages ≈ $150B2≈ $37B spent debugging in the USLittle methodology, very few CS courses deal with debuggingMIT course catalog3 : grep ‘debugging’ => 3/10,299 words1. Britton, T., Jeng, L., Carver, G., Cheak

, P., Katzenellenbogen, T. 2013. Reversible debugging software. Cambridge Judge Business School; http://citeseerx.ist.psu.edu/viewdoc/download?doi=10.1.1.444.9094&rep=rep1&type=pdf.3. http://student.mit.edu/catalog/m6a.html

https://

www.bls.gov/oes/current/oes_nat.htm#15-0000

Slide4

Step 0 – Testing

Always cheaper than debugging

Unit testsFor each subcomponent / class / functionIntegration testEntire systemMore expensive bugs -> More testingASIC design> $10M, months of time for each mistakeEntire teams devoted to design verification and test“Everyone knows that debugging is twice as hard as writing a program in the first place. So if you’re as clever as you can be when you write it, how will you ever debug it?” -Brian Kernighan

Slide5

Tenets of Debugging

Slide6

Reproduce

User / bug reports often are missing information

Or missing vital informationLow signal / noise ratioNeeds to be reproducible to properly instrument / observeConfirmed fix only possible when reproducedIntermittent problemsLoad or environmental related bugs can come and goOften bugs found ‘by inspection’ don’t actually fix the problemThere are lots of bugs in software, did you find the right one?

Slide7

Observe

Visibility into program is vital

LoggingprintfLogging frameworks (single machine)C++: Google’s glog (https://github.com/google/glog)Python: logging module (https://docs.python.org/3.5/library/logging.html)Shell: logger (man logger), file redirectMany languages: fluentd (

www.fluentd.org) / fluentbit (www.fluentbit.io)Logging aggregators (many machines)Splunk (https://www.splunk.com/

)

ElasticStack

(

ElasticSearch

Kibana / Logstash) (https://

www.elastic.co/elastic-stack

)

Graphana

(visualization) (

https://grafana.com

)

Check and print all return codes

assert() is your friend

Slide8

Observe

strace

– trace system callsgdbAttach to running processGet core with gcore / kill -SEGV (set ulimit -c unlimited)Don’t forget debug symbols (gcc -g)Recompile with -O0 for straightforward flowAlways use -Wall -WerrorReverse debuggingSounds cool, not super usefulWireshark / tcpdump

Hardware analyzersi2c/SPI, PCI-Express, etc

Slide9

Observe

Performance monitoring

gperftools (Google perf tools)iostat (man iostat), sar, etc.htopoprofile, other kernel profiling toolsMemory / access debugginggperftools memory profilevalgrind (10-100x slowdown)Dr. Memory (similar to valgrind)

Slide10

From Brendan Gregg

http

://www.brendangregg.com/linuxperf.html

Slide11

Bisect

With or without hypothesis

Educated or uneducated guessDisable parts of program / workflowSwitch compiler optimization levelsSwitch tool versionOne at a time!Always move up the trust stackYour code < library < compiler < OS < hardwareTrust but verify

Slide12

Classifying Bugs

Hard error (Easy)

CrashUnrecoverable errorWrong (but consistent) data outputResource exhaustion (eg. out of memory)Soft error (Difficult)Intermittent failure / crashInconsistent data outputRecovered errorPerformance degradationDifference: reproducibility!Take the easy way

Slide13

Turning Soft Errors into Hard Errors

Tracing and logging

Turn up debug levelCatch first instance of errorTrace external events – logs, network, CPU load, I/O loadTry to replicate error messageStress test applicationLoad testingDebuggerBreakpointsWatchpoints

Slide14

Example: Disk I/O Error

I/O error log in program

2019-06-25 11:48:37.353: Uncategorized and unmanaged std::runtime_error exception:2019-06-25 11:48:37.353: boost::filesystem::status: Input/output error

: "/f/a/job/10085698/system.dms"2019-06-25 11:48:37.353: details: boost::filesystem

::status: Input/output error: "/f/a/job/10085698/

system.dms

2019-06-25 11:48:37.355: Recording error code BAD_ERROR 1001 (priority 1

)

“Soft error” – intermittent – EIO is unpredictable

Trying other errors (ENOENT, EPERM) does not result in the same failure

Look at

usr

/include/

asm

-generic/

errno.h

and

errno-base.h

How about ELOOP

$ ln –s a b

$ ln –s b a

$ cat a

cat: a: Too many levels of symbolic links

Slide15

Bingo!

int

main() { printf("exists foo: %d\n", boost::filesystem::exists("foo"));

printf("exists a: %d\n", boost::filesystem::exists("a")); return 0;

}

$ ./test

exists foo: 0

terminate called after throwing an instance of 'boost::

filesystem

filesystem_error

what(): boost::

filesystem

::status: Too many levels of symbolic links: "a"

Aborted

boost::

filesystem

::exists throws on certain errors

Soltion

: use

noexcept

variant

bool e

xists(

const

path& p); bool exists

(

const

path& p, system::

error_code

)

noexcept

;

Returns:

exists(status(p))

exists(status(p,

))

, respectively. If ec != 0 and an errorThrows: As specified in Error reporting.

Slide16

Start-up Problem

Program fails to start

# Somewhere in log file:Intel MKL FATAL ERROR: Cannot load /opt/intel/mkl/lib/intel64_lin/libmkl_rt.so.$ ls /opt/intel/mkl/lib/intel64_lin/libmkl_rt.so/opt/intel/mkl/lib/intel64_lin/libmkl_rt.soStep 1: ReproduceWhen running the same command from command line, works fine!

Library is not on NFS, present on the machine where command fails

Slide17

Step 2: Observe

Use

strace when starting program, look for failing traceUse ‘-f’ to follow forked processesLook for errors different than working trace22293 mprotect(0x7f7cddbf4000, 2097152, PROT_NONE) = 022293 mmap(0x7f7cdddf4000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4b1000) = 0x7f7cdddf400022293 mmap

(0x7f7cdddfc000, 73280, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f7cdddfc00022293 close(3) = 022293 mprotect(0x7f7cdddf4000, 24576, PROT_READ) = 0

22293

mprotect

(0x7f7cde184000, 8192, PROT_READ) = 0

22293

getcwd

(0x7f7cdddfe1a0, 4096) = -1 ENOENT (No such file or directory)

22293 open("/

usr

/share/locale/C/mkl_msg.cat", O_RDONLY) = -1 ENOENT (No such file or directory)

22293 open("/

usr

/share/locale/C/LC_MESSAGES/mkl_msg.cat", O_RDONLY) = -1 ENOENT (No such file or directory)

22293 open("/

usr

/share/locale/C/mkl_msg.cat", O_RDONLY) = -1 ENOENT (No such file or directory)

22293 open("/

usr

/share/locale/C/LC_MESSAGES/mkl_msg.cat", O_RDONLY) = -1 ENOENT (No such file or directory)

22293 write(2, "Intel MKL FATAL ERROR: Cannot lo"..., 132) = 132

22293 write(2, "\n", 1) = 1

22293

exit_group

(2) = ?

22293 +++ exited with 2 +++

22290 <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 2}], 0, NULL) = 22293

22290

rt_sigprocmask

(SIG_SETMASK, [], NULL, 8) = 0

Slide18

Step 3: Bisect

getcwd

() called on removed directoryReproduce with shell script, observe behavior#!/bin/bashmkdir testcd test

( sleep 1; prog ) &

cd ..

rmdir

test

ait

$ ./mkl-test.sh

...

Intel MKL FATAL ERROR: Cannot load /

opt/intel/mkl/lib/intel64_lin/libmkl_rt.so

Concusion

: MKL is very particular where you run it, don’t remove underlying directory

Slide19

Observe with GDB

For hangs, or to debug live process:

gdb <exe> <pid>Stops process, so be careful!gcore will generate a core from running process without stopping itMake sure to set ulimit -c unlimited to get core dumpsNot sure which executable? Gdb will tell you:$

gdb /bin/ls core.1234….Core was generated by ‘/path/to/my/exe’Thread support:Show all threads:

info threads

Switch to thread:

thread 1

Command on all threads: thread apply all

backtrace

Slide20

More GDB Features

Remote debugging for embedded platforms (

gdb-server and target command)Watchpoints – triggers on memory access – useful to watch for corruptionwatch <expression> (write), rwatch (read), awatch (r/w)HW watchpoints are free, but limited in number – 4 on x86SW watchpoints – unlimited, but expensiveConditional breakpointsbreak <location> [thread <n>] if <condition>Observe values at each break

command <breakpoint>print valcontinue

catch [exception | fork | signal | …]

Slide21

Debug Hang with GDB

Application hanging periodically (once every 10,000 runs approximately)

Job scheduler kills applicationStep 1: ReproduceRerun of the same inputs doesn’t lead to hangDifficult to reproduceStep 2: ObserveAdd code to scheduler that detects hung application to request coredump (gcore)(Tip: core files are large but gzip really well)Analyze core dumpgdb /my/app core.1234

Slide22

(

gdb

) info threads Id Target Id Frame * 1 LWP 5088 0x00007efc1b74d1ad in glob64 () from /lib64/libc.so.6 2 LWP 5263 0x00007efc1ff50945 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 3 LWP 5265 0x00007efc1ff5370d in read () from /lib64/libpthread.so.0 4 LWP 5732 0x00007efc1ff50945 in pthread_cond_wait

@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 5 LWP 5733 0x00007efc1ff50945 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0 6 LWP 5734 0x00007efc1ff50945 in

pthread_cond_wait