The researcher also used ShiViz to debug his own system. A particular example that he de- scribed involved the debugging of a model-checking optimization called distributed partial order reduction (DPOR) [37]. He began by comparing the event schedules produced by DPOR against those generated by a simpler strategy that he knew to be correct. He found that the outputs of the two did not match, even though they should have been equivalent. To pinpoint exact areas of divergence between two such schedules, he used ShiViz to visualize outputs from both strategies and to compare the resulting execution graphs side-by-side. The generated schedules were about

The side-by-side execution comparison helped the researcher efficiently locate points of devia- tion in the DPOR output. He noted that the visual nature of the execution graphs as well as their emphasis on the happens-before relations made it “easy to spot where things diverge”.6 Upon finding the deviation, the researcher traced the event back to the relevant statement in the original console output using the associated log lines on the left of the execution graph

Upon finding the deviation, the researcher traced the event back to the relevant statement in the original console output using the associated log lines on the left of the execution graph

6At the time of this study, ShiViz did not support the explicit highlighting of differences between executions (Section 4.3.1). We have added this feature in part because of this use case.

ACM Transactions on Software Engineering and Methodology, Vol. 29, No. 2, Article 9. Pub. date: March

(Section 4.1.1). This allowed him to debug his implementation of DPOR without having to manu- ally sift through the console output, a process that is both tedious and error-prone. The researcher mentioned that the console output was “enormous and hard to understand,” while ShiViz made the

As with the last use case in Section 2, the juxtaposition of two traces—one generated by the developer’s implementation and one by an implementation known to be correct—enabled visual comparison, aiding in the researcher’s debugging efforts. In this case, the researcher manually looked for points of divergence between the graphs, but the feature for explicitly highlighting differences facilitates this effort by immediately emphasizing any disparities. This study indicates that ShiViz is an effective tool for comparing executions and for identifying divergences in their behavior (RQ3).

Case study 2: Performance debugging of a multi-threaded system. In the second case study, a researcher, as part of her consulting work, used ShiViz for two weeks to debug performance disparities between two mutex implementations used by a multi-threaded key-value system at a small company. We performed two semi-structured interviews with the researcher to understand how she used ShiViz.

The researcher focused on improving two-lock implementation. The original version used pthread mutexes, while the new and optimized implementation used a ticket idea to provide fair- ness. The naive version had each thread spin in a tight loop waiting its turn. This was then opti- mized to have a fixed number of spinners and the remaining threads sleeping. The next (spinning) thread to grab the lock would send a signal to wake up the next sleeping thread so there was a con- stant number of spinners. The performance problem was that the average acquire time of a ticket- based lock was unexpectedly longer than that of a pthread mutex, even though the critical section and the time to release the lock were both shorter. This anomaly was elusive—the researcher spent a few weeks trying to understand the root cause of this problem before we approached her. She noted that existing performance debugging tools were not helpful: “I spent several weeks trying to figure out this subtle problem using conventional performance tools that typically rely on computing averages and aggregates, and I was getting nowhere.”

To use ShiViz, the researcher first implemented an instrumentation tool to track the use of locks in each thread and to associate a fine-grained timestamp with each event. The resulting ShiViz execution graph represented the lock release/acquire events as message send/receive in the graph. To study the anomaly, the researcher generated a log with 16–30 active threads, containing about 70M events. ShiViz did not scale to visualizing the complete log, so she used ShiViz to visualize a 4K subset of events, focusing on “trying to answer the question: what happened that made [the ticket-based lock] wait for so long? Were there unexpected delays to any events?”

ually determined the time that a thread spent acquiring a lock, holding a lock, and so on. She relied heavily on ShiViz to understand the relative ordering of events between threads. She spent sev- eral hours analyzing the log with ShiViz before determining the root cause of the problem: “With ShiViz, which enabled to see thread interactions at granularity of individual events, I figured out what

She found that for the ticket-based lock the elapsed time between one thread releasing the lock and another thread acquiring that lock was non-uniform. This was contrary to the assumption that each time the acquiring thread is spinning, as threads are sent the wake signal. The problem was that a thread may take a while to wake up: It might not wake up early enough to enter the spinning state when the lock becomes available. This explained why the lock wait times were longer than expected.

ACM Transactions on Software Engineering and Methodology, Vol. 29, No. 2, Article 9. Pub. date: March 2020.

Visualizing Distributed System Executions