In my previous post, we saw how to setup two CE devices and run a Bluetooth performance test. In this one, we'll see how to process and analyze the log file generated on the DUT device. I will use Excel to perform some calculations on the data and to display a graph.
The first step is to use pparse.exe (available in CETK) to convert the log file to a comma delimited format:
D:\temp>pparse -c perf_bluetooth_NOPLAT_ARMV4I_VER5_1_204.LOG
Logging to csv files...
Creating output file perf_bluetooth_ARMV4I_SmartPhone_VER5.1.204.csv
Now open the .csv file in Excel. You will see this (I edited a bit to make shorter lines):
Bluetooth RFCOMM Connection Setup : (ms) 523 153
BT Data Xfer: Send BufSize = 16 bytes : (ms) 20003 18207
BT Data Xfer: Recv BufSize = 16 bytes : (ms) 54480 43345
BT Data Xfer: Send BufSize = 512 bytes : (ms) 4479 4725
BT Data Xfer: Recv BufSize = 512 bytes : (ms) 2848 2836
BT Data Xfer: Send BufSize = 1024 bytes : (ms) 4044 4318
BT Data Xfer: Recv BufSize = 1024 bytes : (ms) 2668 2806
BT Data Xfer: Send BufSize = 2048 bytes : (ms) 4168 4357
BT Data Xfer: Recv BufSize = 2048 bytes : (ms) 3055 4970
BT Data Xfer: Send BufSize = RANDOM bytes : (ms) 4195 4318
BT Data Xfer: Recv BufSize = RANDOM bytes : (ms) 2988 3004
Bluetooth RFCOMM Connection Teardown : (ms) 30 4
There is one row per basic operation. Each row contains multiple numeric values (one per iteration) where each numeric value is basically “the number of milliseconds it took to perform the operation in this iteration”. In this particular example, I ran 2 iterations, so we see 2 numeric columns in the log.
We can ignore the RFCOMM setup/teardown measurements for now because they are not relevant for throughput measurements.
How can we obtain results in kbps from this table? Let’s analyze the measurement for the first transfer operation, in the first iteration: “20003”. This number is telling us the following: “it took 20003 milliseconds to perform the operation of sending 163480 bytes in chunks of 16 bytes”. We can now type the following formula in another cell:
throughput = (163840 *8 /1000)/(C2/1000) = 66 kbits / sec
(163840*8/1000) = total number of transferred kbits
C2 = Excel cell where “20003” is located (it may be different in your spreadsheet)
(C2/1000)= (20003 / 10000) = 20.003 = elapsed time in seconds
At this point you can use your favorite mechanism in Excel to copy this formula over and over until you generate another table where measurements will be in kbps. Here it is (I also changed the operation names for convenience):
SND_16 66 72
RCV_16 24 30
SND_512 293 277
RCV_512 460 462
SND_1024 324 304
RCV_1024 491 467
SND_2048 314 301
RCV_2048 429 264
SND_RND 312 304
RCV_RND 439 436
And to better see what’s going on, we can use the data from the table to create a graph:
The operations are on the horizontal axis, and each line in the graph (called “series” here) correspond to a column in the source table. We can observe the following things:
- Throughput on both send and receive is very low when a 16 byte buffer is used. Bad choice of packet size is actually a very common reason for low performance in networking components.
- Average throughput for normal cases is around 400kbps, as can be expected for a non-EDR Bluetooth module such as the one I used.
- In general, receive throughput appears to be higher than send. This is because in this case the DUT was the slave in the asymmetrical link, and forward rate is typically higher than reverse rate.
- The two iterations report very different measurements for RCV_2048. This may be a transient glitch caused by RF conditions, CPU usage, etc. As we run more iterations I expect all lines to be comparable.
The other interesting measurement in the Excel sheet is the connection setup/teardown time. We can see that connection time for the first iteration is around 500 msec. and < 200 msec. for subsequent iterations. This is because the first connection requires a baseband page and ACL link establishment, but the following ones reuse the established link. This data point is mostly informational for a transport driver developer, because nothing can be done at this level to improve it.
As a last comment, it’s worth mentioning that we can use the same data in Excel to calculate other performance metrics such as average throughput, standard deviation, etc.