Exercise 2: Debugging Deadline-Misses using the Thread Scheduling Visualizer
Expected duration: 30 minutes
The ability to reproduce the scheduling behavior this exercise attempts to demonstrate is
dependent on the number of processors in the system and the configuration of the real-time garbage collector (RTGC).
To see the behavior you must have at least two processors (these can be physical processors or multi-core/hyper-threaded processors) and the RTGC must be configured to create at least as many worker-threads as there are processors. If Java RTS is executed from the command-line, then the default
configuration of the RTGC will create a worker-thread per processor. When run inside Netbeans, under the control of the Java RTS Netbeans module, the project properties determine how many RTGC worker-threads to create. To change the number of worker-threads in the project properties, right-click on the project within Netbeans and select Properties, then in the dialog set the values of Worker Threads and Boostable Worker Threads to the number of processors.
If you have a uniprocessor/single-core system then the test program is unlikely to miss a deadline. In that case you can
use a pre-existing log file from a failed run that is in the exercises directory:
/export/home/lab5538/realtimejava/exercises/exercise2/log2222.jrt3
To see how many processors are available to you execute the following command:
/usr/sbin/psrinfo | grep on-line | wc -l
In addition, the tracing tool used by this exercise only works on Solaris OS as it is based on the DTrace tool. If running
on Linux you can still perform the visualization part of the exercise by using the pre-existing log file just described.
The goal of this exercise is to use the "Thread Scheduling Visualizer" (TSV) to examine the scheduling behavior of your application from Exercise 1, to determine where, and why, a deadline miss is being encountered by your periodic no-heap real-time-thread.
Background Information
Read the material in the presentation, up to the slide titled "Exercise 2".
The Sun Java RTS Netbeans module provides a simple interface to execute an application with tracing enabled and then launch TSV to display the generated log file. If not using this module you will need to launch the application manually under the control of the crecord shell script, using the simple.d DTrace script. You will then need to launch TSV itself. Consult the TSV documentation for details of this process.
Steps to Follow
- Start the Netbeans IDE if not already started.
- There are three ways to proceed with this exercise:
- If you completed Exercise 1 and wish to use your solution to that then select the project Ex1 and make it the main project by right-clicking on it and selecting Set as Main Project.
- If you wish to use a provided solution to Exercise 1 then select the project Ex2 and make it the main project by right-clicking on it and selecting Set as Main Project.
- Otherwise, if you are on Linux and unable to perform the tracing part of the exercise, or you are on a uniprocessor and unable to generate the deadline miss, then go to the File menu, select Open and navigate to the pre-defined log file:
/export/home/lab5538/realtimejava/exercises/exercise2/log2222.jrt3 and open it. This launches TSV and you can skip to step 4.
As the example we will be using project Ex2.
- From the Debug menu select TSV Recording which displays the TSV configuration dialog:

Ensure that the correct application is selected (in this case Ex2.jar) and that the TSV script is simple.d, and click Run. The output window will show something like the following:
Application started ...
Elapsed time is (4 ms, 151667 ns)
Elapsed time is (4 ms, 928250 ns)
Elapsed time is (4 ms, 998667 ns)
Elapsed time is (5 ms, 26500 ns)
Elapsed time is (4 ms, 985833 ns)
Elapsed time is (5 ms, 4417 ns)
Elapsed time is (5 ms, 15750 ns)
Elapsed time is (4 ms, 981250 ns)
Elapsed time is (5 ms, 14166 ns)
Elapsed time is (4 ms, 990667 ns)
Elapsed time is (5 ms, 4250 ns)
Elapsed time is (4 ms, 991000 ns)
Elapsed time is (5 ms, 25000 ns)
Elapsed time is (4 ms, 992583 ns)
Elapsed time is (4 ms, 983583 ns)
Elapsed time is (5 ms, 11501 ns)
Elapsed time is (5 ms, 5250 ns)
Elapsed time is (4 ms, 975999 ns)
Elapsed time is (5 ms, 29500 ns)
Elapsed time is (4 ms, 963750 ns)
Elapsed time is (5 ms, 22834 ns)
Elapsed time is (4 ms, 998167 ns)
Elapsed time is (5 ms, 13917 ns)
Elapsed time is (4 ms, 980832 ne, or you are on a uniprocessor and unable to generate the deadline miss,s)
Elapsed time is (5 ms, 14334 ns)
Elapsed time is (4 ms, 989750 ns)
Elapsed time is (5 ms, 14500 ns)
Elapsed time is (4 ms, 969584 ns)
Elapsed time is (5 ms, 8416 ns)
Elapsed time is (5 ms, 20417 ns)
Elapsed time is (4 ms, 976750 ns)
Elapsed time is (5 ms, 1500 ns)
Elapsed time is (5 ms, 22000 ns)
Elapsed time is (4 ms, 993666 ns)
Elapsed time is (5 ms, 1250 ns)
Elapsed time is (4 ms, 987084 ns)
Elapsed time is (5 ms, 14583 ns)
Elapsed time is (4 ms, 984250 ns)
Elapsed time is (4 ms, 991417 ns)
Elapsed time is (5 ms, 14832 ns)
Elapsed time is (4 ms, 999834 ns)
Elapsed time is (5 ms, 3500 ns)
Elapsed time is (4 ms, 990500 ns)
Elapsed time is (5 ms, 0 ns)
Elapsed time is (5 ms, 8000 ns)
Elapsed time is (4 ms, 995666 ns)
Elapsed time is (4 ms, 997750 ns)
Elapsed time is (5 ms, 1 ns)
Elapsed time is (5 ms, 28250 ns)
Elapsed time is (4 ms, 974583 ns)
Elapsed time is (5 ms, 24667 ns)
Elapsed time is (4 ms, 970417 ns)
Elapsed time is (5 ms, 28000 ns)
Elapsed time is (4 ms, 982166 ns)
Elapsed time is (5 ms, 5750 ns)
Elapsed time is (5 ms, 3083 ns)
Elapsed time is (4 ms, 989583 ns)
Elapsed time is (4 ms, 996001 ns)
Elapsed time is (5 ms, 115667 ns)
Elapsed time is (4 ms, 983666 ns)
Elapsed time is (9 ms, 463167 ns)
Elapsed time is (0 ms, 417583 ns)
Elapsed time is (4 ms, 996667 ns)
Elapsed time is (4 ms, 990249 ns)
Elapsed time is (4 ms, 993417 ns)
Elapsed time is (176 ms, 611334 ns)
Exception in thread "PeriodicNHRT" java.lang.Error: Deadline missed!
at ex2.PeriodicNHRT.run(PeriodicNHRT.java:29)
Application is shutting down ...
Application DONE
Execution completed, post-processing in progress
Log generated in file log2222.jrt3
Note:If no deadline was missed then close the TSV application and repeat this step. If you can't get a deadline to miss refer back to step 1 and use the existing log file.
- The TSV application is now displaying your log file:

TSV initially displays threads in the order that they were created, with the oldest at the bottom and the most recent at the top. The bottom thread is always the main thread. The top-most threads are those created by your application. In between are all the threads created by the VM, and the core class libraries. Recalling that TSV displays real-time threads in shades of red, and non-realtime threads in shades of green, the periodic NHRT thread should be the top-most red thread. If you hover the mouse over the red area for that thread, its name, PeriodicNHRT , should be displayed in the bottom right section of the screen.
- Zoom in so that you can see the periodic nature of the
PeriodicNHRT thread by dragging a rectangle across the width of the red section as shown here:

You should now see something like the following:

The periodic nature of this thread is readily visible in the regularly spaced sections of red. But we can see that this regular execution suddenly comes to an end.
- Zoom in again to examine the last seven or eight periods of the NHRT:

You should now see something like the following:

Examine the final periods of the NHRT, we would expect to see another release of the NHRT in the circled region here:

But as you can see there is no release of the NHRT. Why not? As you can see from the TSV output at the time that the periodic NHRT should be released again, all the available CPU's are being used by some other real-time threads!
- Identify the interfering threads by hovering the mouse over them. You will find that they are listed as "Gang Worker (RTGC)" threads. Your periodic NHRT has been prevented from running by the Real-Time Garbage Collector! But how can that be? Aren't NHRT's immune from interference by the RTGC?
NHRT's can run to the exclusion of the RTGC and can preempt the RTGC threads, but they have to be configured correctly for that happen. Recall that in the RTSJ the highest-priority threads will always run. Take a look at the priority of the RTGC threads: RTSJ priority 35.

Now take a look at the priority of your periodic NHRT: RTSJ priority 11!
The RTGC threads have priority greater than your periodic NHRT and so they can (and did!) prevent it from being released on time.
- Fix the problem by increasing the priority of your periodic NHRT — for simplicity just use
PriorityScheduler.instance().getMaxPriority() rather than PriorityScheduler.instance().getMinPriority() . Now your application should run with no deadline misses.
- If you have time, run the fixed application under TSV and see how your periodic NHRT now preempts the RTGC threads when necessary.
Summary
In this exercise, you've learned how to use the Netbeans IDE to launch your application such that scheduling information can be gathered and then displayed using the Thread Scheduling Visualizer. You've then used TSV to determine why a periodic thread was not released when expected. Finally, you've hopefully learnt that correct priority assignment is a critical factor when writing a real-time application.
Back to top
Next exercise
|