Studying multi-threaded behavior with TSViz - - PowerPoint PPT Presentation

studying multi threaded behavior with tsviz
SMART_READER_LITE
LIVE PREVIEW

Studying multi-threaded behavior with TSViz - - PowerPoint PPT Presentation

Studying multi-threaded behavior with TSViz http://bestchai.bitbucket.io/tsviz/ Matheus Nunes, Harjeet Lalh, Ashaya Sharma, Augustine Wong, Svetozar Miucin, Alexandra Fedorova, Ivan Beschastnikh U. Federal de Minas Gerais U. of British


slide-1
SLIDE 1

Studying multi-threaded behavior with TSViz

Matheus Nunes, Harjeet Lalh, Ashaya Sharma, Augustine Wong, Svetozar Miucin, Alexandra Fedorova, Ivan Beschastnikh

http://bestchai.bitbucket.io/tsviz/

  • U. of British Columbia

Canada

  • U. Federal de Minas Gerais

Brazil

slide-2
SLIDE 2

University of British Columbia Ivan Beschastnikh

Concurrency is everywhere

  • Coordination:
  • Today’s apps depend on

numerous services

2

  • Performance:
  • Moore’s law is dying out
  • iPhone 7 has 4 CPU

cores and 6 GPU cores

slide-3
SLIDE 3

University of British Columbia Ivan Beschastnikh

Concurrency is everywhere

  • Coordination:
  • Today’s apps depend on

numerous services

3

  • Performance:
  • Moore’s law is dying out
  • iPhone 7 has 4 CPU

cores and 6 GPU cores

Developers must embrace concurrency

slide-4
SLIDE 4

University of British Columbia Ivan Beschastnikh

Concurrency complexities

  • Multi-threading with shared state is the

dominant model

  • Challenging to reason about order of events
  • Requires explicit concurrency control (e.g., locks)
  • Few tools support concurrency comprehension
  • Commonly used tools: profilers/tracing tools
  • Many tools target distributed computing/systems
  • Most devs study logs, one per thread

4

[1] Debugging Distributed Systems: Challenges and options for validation and debugging, Beschastnikh et al. CACM 2016 [2] Combing the Communication Hairball: Visualizing Parallel Execution Traces using Logical Time. Isaacs et al. TVCG 2014 [3] Ordering Traces Logically to Identify Lateness in Message Passing Programs. Isaacs et al. TPDS 2016
 


slide-5
SLIDE 5

Concurrency analysis in the small

Our view: understanding inter-thread interactions require understanding runtime behavior in the small

University of British Columbia Ivan Beschastnikh

5

  • A solution requires two pieces:
  • 1. Instrumentation
  • e.g., LLVM-based tool called DINAMITE [1]
  • 2. Interactive visualization of captured information
  • TSViz: a new tool based on ShiViz [2]

[1] End-to-end Memory Behavior Profiling with DINAMITE. Miucin et al. Tool demo at FSE 2016 [2] Debugging Distributed Systems: Challenges and options for validation and debugging, Beschastnikh et al. CACM 2016

slide-6
SLIDE 6

Concurrency analysis in the small

University of British Columbia Ivan Beschastnikh

6

  • A solution requires two pieces:
  • 1. Instrumentation
  • e.g., LLVM-based tool called DINAMITE [1]
  • 2. Interactive visualization of captured information
  • TSViz: a new tool based on ShiViz [2]

[1] End-to-end Memory Behavior Profiling with DINAMITE. Miucin et al. Tool demo at FSE 2016 [2] Debugging Distributed Systems: Challenges and options for validation and debugging, Beschastnikh et al. CACM 2016

Focus of this talk Our view: understanding inter-thread interactions require understanding runtime behavior in the small

slide-7
SLIDE 7

University of British Columbia Ivan Beschastnikh

DINAMITE: LLVM-based tracer

7

https://dinamite-toolkit.github.io/

  • Can instrument functions, mutexes,

memory allocations and accesses…

  • Instrument what you care about (or use

reasonable defaults)

  • Possibility of analysis on the fly
  • Controllable overhead between 10% and

30x

  • Get all the debug information in logs!

(even at -O3)

  • People in our lab use it daily for

performance debugging

slide-8
SLIDE 8

University of British Columbia Ivan Beschastnikh

Runtime instrumentation

8

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

? ? ?

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

ShiViz ShiVector

TSViz

DINAMITE App

slide-9
SLIDE 9

University of British Columbia Ivan Beschastnikh

Runtime log visualization

9

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

? ? ?

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

src : 2, dst : 0, type : prepare ["5,"13,"10,"2"] src : 2, dst : 1, type : prepare ["6,"13,"10,"2"] src : 0, dst : 2, type : commit ["7,"13,"10,"2"] src : 1, dst : 2, type : commit ["8,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["9,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["10,"13,"10,"2"] src : 0, dst : 2, type : ack ["11,"13,"10,"2"] src : 1, dst : 2, type : ack ["12,"13,"10,"2"] src : 2, dst : 0, type : prepare ["13,"13,"10,"2"] src : 2, dst : 1, type : prepare ["14,"13,"10,"2"] src : 0, dst : 2, type : commit ["15,"13,"10,"2"] src : 1, dst : 2, type : commit ["16,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["17,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["18,"13,"10,"2"] src : 0, dst : 2, type : ack ["19,"13,"10,"2"] src : 1, dst : 2, type : ack ["20,"13,"10,"2"] src : 2, dst : 0, type : prepare ["21,"13,"10,"2"] src : 2, dst : 1, type : prepare ["22,"13,"10,"2"] src : 0, dst : 2, type : commit ["23,"13,"10,"2"] src : 1, dst : 2, type : commit ["24,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["25,"13,"10"2"] src : 2, dst : 1, type : tx_commit ["26,"13,"10,"2"] src : 0, dst : 2, type : ack ["27,"13,"10,"2"] src : 1, dst : 2, type : ack ["28,"13,"10,"2"] src : 2, dst : 0, type : prepare ["29,"13,"10,"2"] src : 2, dst : 1, type : prepare ["30,"13,"10,"2"] src : 0, dst : 2, type : commit ["31,"13,"10,"2"] src : 1, dst : 2, type : commit ["32,"13,"10,"2"] src : 2, dst : 0, type : tx_commit ["33,"13,"10,"2"] src : 2, dst : 1, type : tx_commit ["34,"13,"10,"2"]

host1

ShiViz ShiVector

TSViz

DINAMITE App

slide-10
SLIDE 10
  • Takes a log with physical timestamps and logical

timestamps as input, outputs a thread interaction graph

  • Interactive tool to explore the

physical and logical orderings

  • Show both orderings
  • To-scale visualization; zooming
  • Search queries
  • Target population:

concurrent system developers

  • Client-side browser impl.

TSViz overview

University of British Columbia Ivan Beschastnikh

10

slide-11
SLIDE 11

TSViz visual abstractions

  • Squares represent threads
  • Circles represent thread events
  • Lines between events represent orderings

University of British Columbia Ivan Beschastnikh

11

Time partial ordering (logical timestamps) total ordering (physical timestamps)

slide-12
SLIDE 12

University of British Columbia Ivan Beschastnikh

Demo on WiredTiger k-v store [1]

12

Public deployment: http://bestchai.bitbucket.io/tsviz/

[1] http://www.wiredtiger.com

slide-13
SLIDE 13

University of British Columbia Ivan Beschastnikh

13

★ TSViz : visualize concurrent executions

Why does my concurrent system behave in a certain manner? Approach: instrument and analyze

State Dynamic analysis Events Visualization

  • Understand ordering of events
  • Query for patterns; compare executions

http://bestchai.bitbucket.io/tsviz/