1<HTML> 2<HEAD> 3<TITLE>Media Nodes Made Easy (Well, Easier...)</TITLE> 4</HEAD> 5<BODY BGCOLOR="0xFFFFFF"> 6<!-- Developer's Workshop --> 7 8<FONT SIZE=+1><B><A NAME="Workshop"></A>DEVELOPERS' WORKSHOP: Media Nodes Made Easy (Well, Easier...)</B></FONT> 9<br><B>By Christopher Tate (<A HREF="mailto:ctate@be.com">ctate@be.com</A>)</B><BR> 10 11 12<P><FONT="-1">"Developers' Workshop" is a weekly feature that provides 13answers to our developers' questions, or topic requests. 14To submit a question, visit 15<P><A HREF="http://www.be.com/developers/suggestion_box.html">http://www.be.com/developers/suggestion_box.html</A>. 16 17<P> 18<P>As anyone who sat through the Node Track of the recent Be 19Developers Conference can attest, writing Media Kit nodes 20is a complex task. Be's engineering team has been hard at 21work extending the Media Kit APIs to simplify node 22construction; similarly, DTS has been developing tools 23developers can use to debug their own BMediaNodes. This 24week's article introduces a tool for analyzing the behavior 25of any BBufferProducer node or node chain: the 26LoggingConsumer. Designed to work with the Genki/6 beta 27release (I told you the APIs were under construction!), 28this node tracks the behavior of its input stream, logging 29a trace of all activity to a file for post-mortem analysis. 30 31 32<P>Before I discuss what exactly the LoggingConsumer does, 33here's the URL to download it, so that you can follow along 34at home: 35 36 37<P><<a href="ftp://ftp.be.com/pub/samples/media kit/LoggingConsumer.zip">ftp://ftp.be.com/pub/samples/media kit/LoggingConsumer.zip 38</a>> 39 40 41<P> 42<b>So, What Is This "LoggingConsumer" Anyway?</b> 43 44 45<P>As BBufferConsumers go, LoggingConsumer is pretty simple: it 46doesn't manipulate its input buffers in any way, it doesn't 47talk to hardware, and it doesn't pass buffers downstream -- 48it sits at the end of the node chain. It has a single input, 49which can accept any kind of data. You, the developer, connect 50to a node or node chain that you're interested in, point it at 51an output file entry ref, and voila! Useful information about 52buffer flow and internode handshaking is recorded for later 53interpretation. 54 55 56<P>The LoggingConsumer node serves two purposes: it produces a 57trace of node activity, for the purpose of debugging 58producers and producer/filter node chains; and it serves as 59a clean example of BBufferConsumer structure and behavior. 60The node tries to do everything "right," and is commented to 61help you understand what's going on at all points in the 62code. The node uses the latest and greatest 63BMediaEventLooper class. It publishes a set of controllable 64parameters via a BParameterWeb, and handles the 65B MEDIA PARAMETERS buffer type for changing those 66parameters. It reports late buffers to the producer, and 67reports latency changes as well. In short, it demonstrates 68pretty much all of the major functionality that a 69BBufferConsumer has to worry about. 70 71 72<P> 73<b>So, How's It Work?</b> 74 75 76<P>In order to preserve the realtime behavior of a proper Media 77Kit node, the LoggingConsumer doesn't do any disk access 78from within its main BMediaNode control thread. Instead, it 79spawns a separate thread to write logged messages to disk, 80and passes messages to that thread via a kernel port. The 81LogWriter class encapsulates this pattern, managing the 82non-realtime thread and message port transparently to the 83LoggingConsumer node implementation. 84 85 86<P>The LoggingConsumer itself is another example of using the 87new BMediaEventLooper class to handle most of the 88nitty-gritty details of being a node. Because it does very 89little actual media-related processing, it's a pretty clear 90illustration of the organization we recommend that nodes 91use. The example application, which hooks the 92LoggingConsumer up to an audio file reader, also uses a 93simple "Connection" structure to illustrate the necessary 94bookkeeping for setting up and tearing down the connection 95between two nodes. 96 97 98<P> 99<b>What's It Give Me?</b> 100 101 102<P>Lots. Every virtual entry point a media node has generates 103an entry in the log file (with the minor exception of 104GetNextInput() and DisposeInputCookie() -- and you can add 105support for these easily). Log entries are marked with the 106current real time (i.e., system time()) when they are 107generated, as well as the current time according to the 108LoggingConsumer's time source. Some operations log 109additional information, as well. For example, when a buffer 110is received, the logged message will indicate whether it is 111already late. When a buffer is handled (i.e., popped off of 112the BMediaEventLooper's event queue) the buffer's 113performance time is logged, as well as how early the buffer 114was handled. That "offset" needs to lie within the node's 115scheduling latency; if it doesn't, the buffer is late. The 116node also maintains a count of late buffers, so your testing 117application can follow what's happening. 118 119 120<P>LoggingConsumer is a BControllable, too, and you can 121manipulate certain aspects of its behavior while it's 122running. In particular, you can adjust its latency on the 123fly. Reacting to latency changes is one of the trickier 124aspects of BBufferProducer nodes, so having this facility in 125the buffer consumer lets you test a producer in a reliable, 126repeatable fashion. Future versions of the LoggingConsumer 127will have other controllable features as well, such as the 128ability to change media formats on the fly. 129 130 131<P>Here's an example of what you get in the log file: 132 133<blockquote><pre> 134LOG REGISTERED : realtime = 240371553910, perftime = 262890 135LOG ACCEPT FORMAT : realtime = 240371564256, perftime = 2331465007 136LOG CONNECTED : realtime = 240371564475, perftime = 2331465228 137LOG PREROLL : realtime = 240371565650, perftime = 2331466400 138LOG START : realtime = 240372603671, perftime = 2332503192 139LOG START HANDLED : realtime = 240372603726, perftime = 2332503245 140LOG PRODUCER DATA STATUS : realtime = 240372604250, perftime = 2332503773 141LOG DATA STATUS HANDLED : realtime = 240372604285, perftime = 2332503809 142 status = 2 143LOG BUFFER RECEIVED : realtime = 240372604448, perftime = 2332503969 144 start = 2332553303, offset = -5666 145 Buffer received *LATE* 146LOG BUFFER HANDLED : realtime = 240372604481, perftime = 2332504002 147 start = 2332553303, offset = -701 148 Buffer handled *LATE* 149LOG BUFFER RECEIVED : realtime = 240372604687, perftime = 2332504209 150LOG BUFFER RECEIVED : realtime = 240372605766, perftime = 2332505279 151LOG BUFFER RECEIVED : realtime = 240372606497, perftime = 2332506016 152LOG BUFFER RECEIVED : realtime = 240372607226, perftime = 2332506744 153LOG BUFFER RECEIVED : realtime = 240372608545, perftime = 2332508060 154LOG BUFFER RECEIVED : realtime = 240372624297, perftime = 2332523788 155LOG BUFFER HANDLED : realtime = 240372638948, perftime = 2332538420 156 start = 2332593303, offset = 4876 157LOG BUFFER RECEIVED : realtime = 240372678548, perftime = 2332577979 158LOG BUFFER HANDLED : realtime = 240372678965, perftime = 2332578395 159 start = 2332633303, offset = 4906 160</pre></blockquote> 161 162<P>The "realtime" field is the current system time() at the 163moment the message was logged, and "perftime" is the 164LoggingConsumer's idea of the current time according to its 165time source (i.e., the current performance time). As you can 166see, the node is registered, then the format negotiation 167with the producer occurs, the node is Preroll()ed, then it's 168Start()ed. When the producer node was started it sent a 169ProducerDataStatus() message, then began sending buffers. 170Note that there is a distinction between the buffer's 171receipt in BufferReceived() and its eventual handling in 172HandleEvent(). Also note that given our stated scheduling 173latency of 5000 microseconds, the first buffer was sent too 174late for the LoggingConsumer to handle in a timely manner -- 175information to be communicated to whoever wrote this 176particular BBufferProducer node! 177 178 179<P>The LogWriter class can easily be adapted to log other sorts 180of messages. Just add your own custom message codes to the 181log what enum in LogWriter.h, string translations for them 182to the log what to string() function, and appropriate 183handling in LogWriter::HandleMessage(). If you need to pass 184custom information in the log message, add a new variant to 185the union declared in the log message struct. 186 187 188<P>If you're developing BBufferProducer nodes, this class will 189help you debug them. If you're developing BBufferConsumers, 190this node will show you how to structure your code. And if 191you're just writing Media Kit applications, this node gives 192you an easy way to tell whether you've set up the rest of 193the node chain correctly. Any way you slice it, 194LoggingConsumer is a must-have component in any Media Kit 195development suite! 196</HTML>