latency.c (9908B)
1 /* latency.c -- measure latency of OS */ 2 3 #include "porttime.h" 4 #include "portmidi.h" 5 #include "stdlib.h" 6 #include "stdio.h" 7 #include "string.h" 8 #include "assert.h" 9 10 /* Latency is defined here to mean the time starting when a 11 process becomes ready to run, and ending when the process 12 actually runs. Latency is due to contention for the 13 processor, usually due to other processes, OS activity 14 including device drivers handling interrupts, and 15 waiting for the scheduler to suspend the currently running 16 process and activate the one that is waiting. 17 18 Latency can affect PortMidi applications: if a process fails 19 to wake up promptly, MIDI input may sit in the input buffer 20 waiting to be handled, and MIDI output may not be generated 21 with accurate timing. Using the latency parameter when 22 opening a MIDI output port allows the caller to defer timing 23 to PortMidi, which in most implementations will pass the 24 data on to the OS. By passing timestamps and data to the 25 OS kernel, device driver, or even hardware, there are fewer 26 sources of latency that can affect the ultimate timing of 27 the data. On the other hand, the application must generate 28 and deliver the data ahead of the timestamp. The amount by 29 which data is computed early must be at least as large as 30 the worst-case latency to avoid timing problems. 31 32 Latency is even more important in audio applications. If an 33 application lets an audio output buffer underflow, an audible 34 pop or click is produced. Audio input buffers can overflow, 35 causing data to be lost. In general the audio buffers must 36 be large enough to buffer the worst-case latency that the 37 application will encounter. 38 39 This program measures latency by recording the difference 40 between the scheduled callback time and the current real time. 41 We do not really know the scheduled callback time, so we will 42 record the differences between the real time of each callback 43 and the real time of the previous callback. Differences that 44 are larger than the scheduled difference are recorded. Smaller 45 differences indicate the system is recovering from an earlier 46 latency, so these are ignored. 47 Since printing by the callback process can cause all sorts of 48 delays, this program records latency observations in a 49 histogram. When the program is stopped, the histogram is 50 printed to the console. 51 52 Optionally the system can be tested under a load of MIDI input, 53 MIDI output, or both. If MIDI input is selected, the callback 54 thread will read any waiting MIDI events each iteration. You 55 must generate events on this interface for the test to actually 56 put any appreciable load on PortMidi. If MIDI output is 57 selected, alternating note on and note off events are sent each 58 X iterations, where you specify X. For example, with a timer 59 callback period of 2ms and X=1, a MIDI event is sent every 2ms. 60 61 62 INTERPRETING RESULTS: Time is quantized to 1ms, so there is 63 some uncertainty due to rounding. A microsecond latency that 64 spans the time when the clock is incremented will be reported 65 as a latency of 1. On the other hand, a latency of almost 66 1ms that falls between two clock ticks will be reported as 67 zero. In general, if the highest nonzero bin is numbered N, 68 then the maximum latency is N+1. 69 70 CHANGE LOG 71 72 18-Jul-03 Mark Nelson -- Added code to generate MIDI or receive 73 MIDI during test, and made period user-settable. 74 */ 75 76 #define HIST_LEN 21 /* how many 1ms bins in the histogram */ 77 78 #define STRING_MAX 80 /* used for console input */ 79 80 #define INPUT_BUFFER_SIZE 100 81 #define OUTPUT_BUFFER_SIZE 0 82 83 #ifndef max 84 #define max(a, b) ((a) > (b) ? (a) : (b)) 85 #endif 86 #ifndef min 87 #define min(a, b) ((a) <= (b) ? (a) : (b)) 88 #endif 89 90 int get_number(char *prompt); 91 92 PtTimestamp previous_callback_time = 0; 93 94 int period; /* milliseconds per callback */ 95 96 int histogram[HIST_LEN]; 97 int max_latency = 0; /* worst latency observed */ 98 int out_of_range = 0; /* how many points outside of HIST_LEN? */ 99 100 int test_in, test_out; /* test MIDI in and/or out? */ 101 int output_period; /* output MIDI every __ iterations if test_out true */ 102 int iteration = 0; 103 PmStream *in, *out; 104 int note_on = 0; /* is the note currently on? */ 105 106 /* callback function for PortTime -- computes histogram */ 107 void pt_callback(PtTimestamp timestamp, void *userData) 108 { 109 PtTimestamp difference = timestamp - previous_callback_time - period; 110 previous_callback_time = timestamp; 111 112 /* allow 5 seconds for the system to settle down */ 113 if (timestamp < 5000) return; 114 115 iteration++; 116 /* send a note on/off if user requested it */ 117 if (test_out && (iteration % output_period == 0)) { 118 PmEvent buffer[1]; 119 buffer[0].timestamp = Pt_Time(NULL); 120 if (note_on) { 121 /* note off */ 122 buffer[0].message = Pm_Message(0x90, 60, 0); 123 note_on = 0; 124 } else { 125 /* note on */ 126 buffer[0].message = Pm_Message(0x90, 60, 100); 127 note_on = 1; 128 } 129 Pm_Write(out, buffer, 1); 130 iteration = 0; 131 } 132 133 /* read all waiting events (if user requested) */ 134 if (test_in) { 135 PmError status; 136 PmEvent buffer[1]; 137 do { 138 status = Pm_Poll(in); 139 if (status == TRUE) { 140 Pm_Read(in,buffer,1); 141 } 142 } while (status == TRUE); 143 } 144 145 if (difference < 0) return; /* ignore when system is "catching up" */ 146 147 /* update the histogram */ 148 if (difference < HIST_LEN) { 149 histogram[difference]++; 150 } else { 151 out_of_range++; 152 } 153 154 if (max_latency < difference) max_latency = difference; 155 } 156 157 158 int main() 159 { 160 char line[STRING_MAX]; 161 int i; 162 int len; 163 int choice; 164 PtTimestamp stop; 165 printf("Latency histogram.\n"); 166 period = 0; 167 while (period < 1) { 168 period = get_number("Choose timer period (in ms, >= 1): "); 169 } 170 printf("Benchmark with:\n\t%s\n\t%s\n\t%s\n\t%s\n", 171 "1. No MIDI traffic", 172 "2. MIDI input", 173 "3. MIDI output", 174 "4. MIDI input and output"); 175 choice = get_number("? "); 176 switch (choice) { 177 case 1: test_in = 0; test_out = 0; break; 178 case 2: test_in = 1; test_out = 0; break; 179 case 3: test_in = 0; test_out = 1; break; 180 case 4: test_in = 1; test_out = 1; break; 181 default: assert(0); 182 } 183 if (test_in || test_out) { 184 /* list device information */ 185 for (i = 0; i < Pm_CountDevices(); i++) { 186 const PmDeviceInfo *info = Pm_GetDeviceInfo(i); 187 if ((test_in && info->input) || 188 (test_out && info->output)) { 189 printf("%d: %s, %s", i, info->interf, info->name); 190 if (info->input) printf(" (input)"); 191 if (info->output) printf(" (output)"); 192 printf("\n"); 193 } 194 } 195 /* open stream(s) */ 196 if (test_in) { 197 int i = get_number("MIDI input device number: "); 198 Pm_OpenInput(&in, 199 i, 200 NULL, 201 INPUT_BUFFER_SIZE, 202 (PmTimestamp (*)(void *)) Pt_Time, 203 NULL); 204 /* turn on filtering; otherwise, input might overflow in the 205 5-second period before timer callback starts reading midi */ 206 Pm_SetFilter(in, PM_FILT_ACTIVE | PM_FILT_CLOCK); 207 } 208 if (test_out) { 209 int i = get_number("MIDI output device number: "); 210 PmEvent buffer[1]; 211 Pm_OpenOutput(&out, 212 i, 213 NULL, 214 OUTPUT_BUFFER_SIZE, 215 (PmTimestamp (*)(void *)) Pt_Time, 216 NULL, 217 0); /* no latency scheduling */ 218 219 /* send a program change to force a status byte -- this fixes 220 a problem with a buggy linux MidiSport driver, and shouldn't 221 hurt anything else 222 */ 223 buffer[0].timestamp = 0; 224 buffer[0].message = Pm_Message(0xC0, 0, 0); /* program change */ 225 Pm_Write(out, buffer, 1); 226 227 output_period = get_number( 228 "MIDI out should be sent every __ callback iterations: "); 229 230 assert(output_period >= 1); 231 } 232 } 233 234 printf("%s%s", "Latency measurements will start in 5 seconds. ", 235 "Type return to stop: "); 236 Pt_Start(period, &pt_callback, 0); 237 fgets(line, STRING_MAX, stdin); 238 stop = Pt_Time(); 239 Pt_Stop(); 240 241 /* courteously turn off the last note, if necessary */ 242 if (note_on) { 243 PmEvent buffer[1]; 244 buffer[0].timestamp = Pt_Time(NULL); 245 buffer[0].message = Pm_Message(0x90, 60, 0); 246 Pm_Write(out, buffer, 1); 247 } 248 249 /* print the histogram */ 250 printf("Duration of test: %g seconds\n\n", max(0, stop - 5000) * 0.001); 251 printf("Latency(ms) Number of occurrences\n"); 252 /* avoid printing beyond last non-zero histogram entry */ 253 len = min(HIST_LEN, max_latency + 1); 254 for (i = 0; i < len; i++) { 255 printf("%2d %10d\n", i, histogram[i]); 256 } 257 printf("Number of points greater than %dms: %d\n", 258 HIST_LEN - 1, out_of_range); 259 printf("Maximum latency: %d milliseconds\n", max_latency); 260 printf("\nNote that due to rounding, actual latency can be 1ms higher\n"); 261 printf("than the numbers reported here.\n"); 262 printf("Type return to exit..."); 263 fgets(line, STRING_MAX, stdin); 264 265 if(choice == 2) 266 Pm_Close(in); 267 else if(choice == 3) 268 Pm_Close(out); 269 else if(choice == 4) 270 { 271 Pm_Close(in); 272 Pm_Close(out); 273 } 274 return 0; 275 } 276 277 278 /* read a number from console */ 279 int get_number(char *prompt) 280 { 281 char line[STRING_MAX]; 282 int n = 0, i; 283 printf(prompt); 284 while (n != 1) { 285 n = scanf("%d", &i); 286 fgets(line, STRING_MAX, stdin); 287 288 } 289 return i; 290 }