1 #!/usr/bin/python 2 # 3 # Copyright 2016 The Chromium OS Authors. All rights reserved. 4 # Use of this source code is governed by a BSD-style license that can be 5 # found in the LICENSE file. 6 # 7 8 """Generates an HTML file with plot of buffer level in the audio thread log.""" 9 10 import argparse 11 import collections 12 import logging 13 import string 14 15 page_content = string.Template(""" 16 <html meta charset="UTF8"> 17 <head> 18 <!-- Load c3.css --> 19 <link href="https://rawgit.com/masayuki0812/c3/master/c3.css" rel="stylesheet" type="text/css"> 20 <!-- Load d3.js and c3.js --> 21 <script src="https://d3js.org/d3.v3.min.js" charset="utf-8"></script> 22 <script src="https://rawgit.com/masayuki0812/c3/master/c3.js" charset="utf-8"></script> 23 <style type="text/css"> 24 .c3-grid text { 25 fill: grey; 26 } 27 .event_log_box { 28 font-family: 'Courier New', Courier, 'Lucida Sans Typewriter', 'Lucida Typewriter', monospace; 29 font-size: 20px; 30 font-style: normal; 31 font-variant: normal; 32 font-weight: 300; 33 line-height: 26.4px; 34 white-space: pre; 35 height:50%; 36 width:48%; 37 border:1px solid #ccc; 38 overflow:auto; 39 } 40 .checkbox { 41 font-size: 30px; 42 border: 2px; 43 } 44 .device { 45 font-size: 15px; 46 } 47 .stream{ 48 font-size: 15px; 49 } 50 .fetch{ 51 } 52 .wake{ 53 } 54 </style> 55 <script type="text/javascript"> 56 draw_chart = function() { 57 var chart = c3.generate({ 58 data: { 59 x: 'time', 60 columns: [ 61 ['time', $times], 62 ['buffer_level', $buffer_levels], 63 ], 64 type: 'bar', 65 types: { 66 buffer_level: 'line', 67 }, 68 }, 69 zoom: { 70 enabled: true, 71 }, 72 73 grid: { 74 x: { 75 lines: [ 76 $grids, 77 ], 78 }, 79 }, 80 81 axis: { 82 y: {min: 0, max: $max_y}, 83 }, 84 }); 85 }; 86 87 logs = `$logs`; 88 put_logs = function () { 89 document.getElementById('logs').innerHTML = logs; 90 }; 91 92 set_initial_checkbox_value = function () { 93 document.getElementById('device').checked = true; 94 document.getElementById('stream').checked = true; 95 document.getElementById('fetch').checked = true; 96 document.getElementById('wake').checked = true; 97 } 98 99 window.onload = function() { 100 draw_chart(); 101 put_logs(); 102 set_initial_checkbox_value(); 103 }; 104 105 function handleClick(checkbox) { 106 var class_name = checkbox.id; 107 var elements = document.getElementsByClassName(class_name); 108 var i; 109 110 if (checkbox.checked) { 111 display_value = "block"; 112 } else { 113 display_value = "none" 114 } 115 116 console.log("change " + class_name + " to " + display_value); 117 for (i = 0; i < elements.length; i++) { 118 elements[i].style.display = display_value; 119 } 120 } 121 122 </script> 123 </head> 124 125 <body> 126 <div id="chart" style="height:50%; width:100%" ></div> 127 <div style="margin:0 auto"; class="checkbox"> 128 <label><input type="checkbox" onclick="handleClick(this);" id="device">Show device removed/added event</label> 129 <label><input type="checkbox" onclick="handleClick(this);" id="stream">Show stream removed/added event</label> 130 <label><input type="checkbox" onclick="handleClick(this);" id="fetch">Show fetch event</label> 131 <label><input type="checkbox" onclick="handleClick(this);" id="wake">Show wake by num_fds=1 event</label> 132 </div> 133 <div class="event_log_box", id="logs", style="float:left;"></div> 134 <textarea class="event_log_box", id="text", style="float:right;"></textarea> 135 </body> 136 </html> 137 """) 138 139 140 Tag = collections.namedtuple('Tag', {'time', 'text', 'position', 'class_name'}) 141 """ 142 The tuple for tags shown on the plot on certain time. 143 text is the tag to show, position is the tag position, which is one of 144 'start', 'middle', 'end', class_name is one of 'device', 'stream', 'fetch', 145 and 'wake' which will be their CSS class name. 146 """ 147 148 class EventData(object): 149 """The base class of an event.""" 150 def __init__(self, time, name): 151 """Initializes an EventData. 152 153 @param time: A string for event time. 154 @param name: A string for event name. 155 156 """ 157 self.time = time 158 self.name = name 159 self._text = None 160 self._position = None 161 self._class_name = None 162 163 def GetTag(self): 164 """Gets the tag for this event. 165 166 @returns: A Tag object. Returns None if no need to show tag. 167 168 """ 169 if self._text: 170 return Tag( 171 time=self.time, text=self._text, position=self._position, 172 class_name=self._class_name) 173 return None 174 175 176 class DeviceEvent(EventData): 177 """Class for device event.""" 178 def __init__(self, time, name, device): 179 """Initializes a DeviceEvent. 180 181 @param time: A string for event time. 182 @param name: A string for event name. 183 @param device: A string for device index. 184 185 """ 186 super(DeviceEvent, self).__init__(time, name) 187 self.device = device 188 self._position = 'start' 189 self._class_name = 'device' 190 191 192 class DeviceRemovedEvent(DeviceEvent): 193 """Class for device removed event.""" 194 def __init__(self, time, name, device): 195 """Initializes a DeviceRemovedEvent. 196 197 @param time: A string for event time. 198 @param name: A string for event name. 199 @param device: A string for device index. 200 201 """ 202 super(DeviceRemovedEvent, self).__init__(time, name, device) 203 self._text = 'Removed Device %s' % self.device 204 205 206 class DeviceAddedEvent(DeviceEvent): 207 """Class for device added event.""" 208 def __init__(self, time, name, device): 209 """Initializes a DeviceAddedEvent. 210 211 @param time: A string for event time. 212 @param name: A string for event name. 213 @param device: A string for device index. 214 215 """ 216 super(DeviceAddedEvent, self).__init__(time, name, device) 217 self._text = 'Added Device %s' % self.device 218 219 220 class LevelEvent(DeviceEvent): 221 """Class for device event with buffer level.""" 222 def __init__(self, time, name, device, level): 223 """Initializes a LevelEvent. 224 225 @param time: A string for event time. 226 @param name: A string for event name. 227 @param device: A string for device index. 228 @param level: An int for buffer level. 229 230 """ 231 super(LevelEvent, self).__init__(time, name, device) 232 self.level = level 233 234 235 class StreamEvent(EventData): 236 """Class for event with stream.""" 237 def __init__(self, time, name, stream): 238 """Initializes a StreamEvent. 239 240 @param time: A string for event time. 241 @param name: A string for event name. 242 @param stream: A string for stream id. 243 244 """ 245 super(StreamEvent, self).__init__(time, name) 246 self.stream = stream 247 self._class_name = 'stream' 248 249 250 class FetchStreamEvent(StreamEvent): 251 """Class for stream fetch event.""" 252 def __init__(self, time, name, stream): 253 """Initializes a FetchStreamEvent. 254 255 @param time: A string for event time. 256 @param name: A string for event name. 257 @param stream: A string for stream id. 258 259 """ 260 super(FetchStreamEvent, self).__init__(time, name, stream) 261 self._text = 'Fetch %s' % self.stream 262 self._position = 'end' 263 self._class_name = 'fetch' 264 265 266 class StreamAddedEvent(StreamEvent): 267 """Class for stream added event.""" 268 def __init__(self, time, name, stream): 269 """Initializes a StreamAddedEvent. 270 271 @param time: A string for event time. 272 @param name: A string for event name. 273 @param stream: A string for stream id. 274 275 """ 276 super(StreamAddedEvent, self).__init__(time, name, stream) 277 self._text = 'Add stream %s' % self.stream 278 self._position = 'middle' 279 280 281 class StreamRemovedEvent(StreamEvent): 282 """Class for stream removed event.""" 283 def __init__(self, time, name, stream): 284 """Initializes a StreamRemovedEvent. 285 286 @param time: A string for event time. 287 @param name: A string for event name. 288 @param stream: A string for stream id. 289 290 """ 291 super(StreamRemovedEvent, self).__init__(time, name, stream) 292 self._text = 'Remove stream %s' % self.stream 293 self._position = 'middle' 294 295 296 class WakeEvent(EventData): 297 """Class for wake event.""" 298 def __init__(self, time, name, num_fds): 299 """Initializes a WakeEvent. 300 301 @param time: A string for event time. 302 @param name: A string for event name. 303 @param num_fds: A string for number of fd that wakes audio thread up. 304 305 """ 306 super(WakeEvent, self).__init__(time, name) 307 self._position = 'middle' 308 self._class_name = 'wake' 309 if num_fds != '0': 310 self._text = 'num_fds %s' % num_fds 311 312 313 class C3LogWriter(object): 314 """Class to handle event data and fill an HTML page using c3.js library""" 315 def __init__(self): 316 """Initializes a C3LogWriter.""" 317 self.times = [] 318 self.buffer_levels = [] 319 self.tags = [] 320 self.max_y = 0 321 322 def AddEvent(self, event): 323 """Digests an event. 324 325 Add a tag if this event needs to be shown on grid. 326 Add a buffer level data into buffer_levels if this event has buffer 327 level. 328 329 @param event: An EventData object. 330 331 """ 332 tag = event.GetTag() 333 if tag: 334 self.tags.append(tag) 335 336 if isinstance(event, LevelEvent): 337 self.times.append(event.time) 338 self.buffer_levels.append(str(event.level)) 339 if event.level > self.max_y: 340 self.max_y = event.level 341 logging.debug('add data for a level event %s: %s', 342 event.time, event.level) 343 344 if (isinstance(event, DeviceAddedEvent) or 345 isinstance(event, DeviceRemovedEvent)): 346 self.times.append(event.time) 347 self.buffer_levels.append('null') 348 349 def _GetGrids(self): 350 """Gets the content to be filled for grids. 351 352 @returns: A str for grid with format: 353 '{value: time1, text: "tag1", position: "position1"}, 354 {value: time1, text: "tag1"},...' 355 356 """ 357 grids = [] 358 for tag in self.tags: 359 content = ('{value: %s, text: "%s", position: "%s", ' 360 'class: "%s"}') % ( 361 tag.time, tag.text, tag.position, tag.class_name) 362 grids.append(content) 363 grids_joined = ', '.join(grids) 364 return grids_joined 365 366 def FillPage(self, page_template): 367 """Fills in the page template with content. 368 369 @param page_template: A string for HTML page content with variables 370 to be filled. 371 372 @returns: A string for filled page. 373 374 """ 375 times = ', '.join(self.times) 376 buffer_levels = ', '.join(self.buffer_levels) 377 grids = self._GetGrids() 378 filled = page_template.safe_substitute( 379 times=times, 380 buffer_levels=buffer_levels, 381 grids=grids, 382 max_y=str(self.max_y)) 383 return filled 384 385 386 class EventLogParser(object): 387 """Class for event log parser.""" 388 def __init__(self): 389 """Initializes an EventLogParse.""" 390 self.parsed_events = [] 391 392 def AddEventLog(self, event_log): 393 """Digests a line of event log. 394 395 @param event_log: A line for event log. 396 397 """ 398 event = self._ParseOneLine(event_log) 399 if event: 400 self.parsed_events.append(event) 401 402 def GetParsedEvents(self): 403 """Gets the list of parsed events. 404 405 @returns: A list of parsed EventData. 406 407 """ 408 return self.parsed_events 409 410 def _ParseOneLine(self, line): 411 """Parses one line of event log. 412 413 Split a line like 414 169536.504763588 WRITE_STREAMS_FETCH_STREAM id:0 cbth:512 delay:1136 415 into time, name, and props where 416 time = '169536.504763588' 417 name = 'WRITE_STREAMS_FETCH_STREAM' 418 props = { 419 'id': 0, 420 'cb_th': 512, 421 'delay': 1136 422 } 423 424 @param line: A line of event log. 425 426 @returns: A EventData object. 427 428 """ 429 line_split = line.split() 430 time, name = line_split[0], line_split[1] 431 logging.debug('time: %s, name: %s', time, name) 432 props = {} 433 for index in xrange(2, len(line_split)): 434 key, value = line_split[index].split(':') 435 props[key] = value 436 logging.debug('props: %s', props) 437 return self._CreateEventData(time, name, props) 438 439 def _CreateEventData(self, time, name, props): 440 """Creates an EventData based on event name. 441 442 @param time: A string for event time. 443 @param name: A string for event name. 444 @param props: A dict for event properties. 445 446 @returns: A EventData object. 447 448 """ 449 if name == 'WRITE_STREAMS_FETCH_STREAM': 450 return FetchStreamEvent(time, name, stream=props['id']) 451 if name == 'STREAM_ADDED': 452 return StreamAddedEvent(time, name, stream=props['id']) 453 if name == 'STREAM_REMOVED': 454 return StreamRemovedEvent(time, name, stream=props['id']) 455 if name in ['FILL_AUDIO', 'SET_DEV_WAKE']: 456 return LevelEvent( 457 time, name, device=props['dev'], 458 level=int(props['hw_level'])) 459 if name == 'DEV_ADDED': 460 return DeviceAddedEvent(time, name, device=props['dev']) 461 if name == 'DEV_REMOVED': 462 return DeviceRemovedEvent(time, name, device=props['dev']) 463 if name == 'WAKE': 464 return WakeEvent(time, name, num_fds=props['num_fds']) 465 return None 466 467 468 class AudioThreadLogParser(object): 469 """Class for audio thread log parser.""" 470 def __init__(self, path): 471 """Initializes an AudioThreadLogParser. 472 473 @param path: The audio thread log file path. 474 475 """ 476 self.path = path 477 self.content = None 478 479 def Parse(self): 480 """Prases the audio thread logs. 481 482 @returns: A list of event log lines. 483 484 """ 485 logging.debug('Using file: %s', self.path) 486 with open(self.path, 'r') as f: 487 self.content = f.read().splitlines() 488 489 # Event logs starting at two lines after 'Audio Thread Event Log'. 490 index_start = self.content.index('Audio Thread Event Log:') + 2 491 # If input is from audio_diagnostic result, use aplay -l line to find 492 # the end of audio thread event logs. 493 try: 494 index_end = self.content.index('=== aplay -l ===') 495 except ValueError: 496 logging.debug( 497 'Can not find aplay line. This is not from diagnostic') 498 index_end = len(self.content) 499 event_logs = self.content[index_start:index_end] 500 logging.info('Parsed %s log events', len(event_logs)) 501 return event_logs 502 503 def FillLogs(self, page_template): 504 """Fills the HTML page template with contents for audio thread logs. 505 506 @param page_template: A string for HTML page content with log variable 507 to be filled. 508 509 @returns: A string for filled page. 510 511 """ 512 logs = '\n<br>'.join(self.content) 513 return page_template.substitute(logs=logs) 514 515 516 def ParseArgs(): 517 """Parses the arguments. 518 519 @returns: The namespace containing parsed arguments. 520 521 """ 522 parser = argparse.ArgumentParser( 523 description='Draw time chart from audio thread log', 524 formatter_class=argparse.ArgumentDefaultsHelpFormatter) 525 parser.add_argument('FILE', type=str, help='The audio thread log file') 526 parser.add_argument('-o', type=str, dest='output', 527 default='view.html', help='The output HTML file') 528 parser.add_argument('-d', dest='debug', action='store_true', 529 default=False, help='Show debug message') 530 return parser.parse_args() 531 532 533 def Main(): 534 """The Main program.""" 535 options = ParseArgs() 536 logging.basicConfig( 537 format='%(asctime)s:%(levelname)s:%(message)s', 538 level=logging.DEBUG if options.debug else logging.INFO) 539 540 # Gets lines of event logs. 541 audio_thread_log_parser = AudioThreadLogParser(options.FILE) 542 event_logs = audio_thread_log_parser.Parse() 543 544 # Parses event logs into events. 545 event_log_parser = EventLogParser() 546 for event_log in event_logs: 547 event_log_parser.AddEventLog(event_log) 548 events = event_log_parser.GetParsedEvents() 549 550 # Reads in events in preparation of filling HTML template. 551 c3_writer = C3LogWriter() 552 for event in events: 553 c3_writer.AddEvent(event) 554 555 # Fills in buffer level chart. 556 page_content_with_chart = c3_writer.FillPage(page_content) 557 558 # Fills in audio thread log into text box. 559 page_content_with_chart_and_logs = audio_thread_log_parser.FillLogs( 560 string.Template(page_content_with_chart)) 561 562 with open(options.output, 'w') as f: 563 f.write(page_content_with_chart_and_logs) 564 565 566 if __name__ == '__main__': 567 Main() 568