9 years, 5 months ago.

Serial port on LPC1114 is slow.

Hi everyone,

Following the excellent tutorial by ytsuboi,I got both the standalone DIP LPC1114 chip as well as the Switch-Science board and have enjoyed playing around with both.

I am trying to read data from a sensor via SPI at 1kHz and it seems like there is a lag of around 300us between numbers when I use printf with the LPC1114. The serial port is running at 921600. It is not an SPI issue as the problem is still there when I print a constant integer. This lag is not present when I compile the code for the mbed LPC1768 board instead. Is this a limitation of the LPC1114 at 48MHz versus the LPC1768 at 96MHz? Or is there something else going on that is causing the delay in serial printf?

Any help is appreciated, thanks!

Lag between numbers with LPC1114 /media/uploads/mcx/screenshot_2014-11-04_16.21.16.png

No lag with LPC1768 /media/uploads/mcx/screenshot_2014-11-04_16.04.42.png

Code used to test serial printf on both the LPC1114 and the mbed LPC1768

#include "mbed.h"
#include "mcp3208.h"

MCP3208 input1(dp2, dp1, dp6, dp9); //MCP3208(PinName mosi, PinName miso, PinName clk, PinName cs)
// MCP3208 input1(p5, p6, p7, p8);

Serial pc(dp16,dp15); //(USBTX, USBRX)
// Serial pc(p9,p10);

Ticker datalog;
//Timer t;

int data[6];
bool tickerActivated = false;

void log_data()
{
    tickerActivated = true;
}

int main()
{
    pc.baud(921600);
    pc.printf("Working!!\n\r");

    datalog.attach_us(&log_data,1000); // 1000us = 1ms

    while(1) {
        data[0] = 1114;
        data[1] = 1114;
        data[2] = 1114;
        data[3] = 1114;
        data[4] = 1114;
        data[5] = 1114;        
//        data[5] = input1.binary(5);
        if(tickerActivated == true) {
            tickerActivated = false;
//            pc.printf("%1.3f,%1.3f,%1.3f,%1.3f,%1.3f,%1.3f\n\r",input1.volt(0),input1.volt(1),input1.volt(2),input1.volt(3),input1.volt(4),input1.volt(5));  //.read_input(input pin on MCP3208)
            pc.printf("%4d,%4d,%4d,%4d,%4d,%4d\n\r",data[0],data[1],data[2],data[3],data[4],data[5]);  //.read_input(input pin on MCP3208)

        }
    }
}

UPDATE

As I've mentioned in the comments below, it seems like the amount of data being sent is a factor that affects the delay between numbers being sent over serial.

Another factor that influences the readings is the serial communications speed. It seems that at 921600 bps, the gap between numbers is about 330us and at 115200 bps, the delay is reduced to 200us. The code is really simplified now, so maybe something is wrong with the printf implementation!?

I've tried it on both the bare LPC1114 chip and the platform version from Switch Science, and it seems that having a crystal oscillator (or lack of) doesn't change anything.

/media/uploads/mcx/screenshot_2014-11-07_16.39.33.png

#include "mbed.h"

Serial pc(dp16,dp15);

int main()
{
    pc.baud(921600);
    pc.printf("Working!!\n\r");

    while(1) {
        pc.printf("%4d,%4d,%4d,%4d,%4d,%4d\n\r",1114,1115,1116,1117,1118,1119);
    }
}

Definately not supposed to happen. Can you try more/fewer decimals per number? I wonder if it is in any way related to the numbers, or just always 5 bytes which get send per 'burst'.

posted by Erik - 04 Nov 2014

I think you've hit on something Erik! It is related to the length of the number. With %2d, the gap between numbers goes down to 150us and with %6d, the delay goes up to 500us.

I also tried putting all the numbers into a string and then printing the string. This removes the delay between numbers in each string, but now there is a large delay of 2000us between each string of 6 numbers. This happens even when Ticker is commented out.

sprintf(datastr, "%4d,%4d,%4d,%4d,%4d,%4d\n\r",data[0],data[1],data[2],data[3],data[4],data[5]);
pc.printf("%s\n\r",datastr);
posted by Michael Chuah 04 Nov 2014

That is weird, so it seems to be taking ridiculous long times to calculate which numbers to send. Sure it is a bit slower than an LPC1768, but for sure I wouldn't have expected this. I'll check out later if I can reproduce it, but dunno when I get around to it :).

posted by Erik - 05 Nov 2014

Thanks for taking the time to help out Erik, I've tried everything I could think of and this bug is driving me crazy!

posted by Michael Chuah 05 Nov 2014

1 Answer

9 years, 5 months ago.

I did some quick tests, and I think (based on timer, too lazy to grab logic analyzer), that the LPC11u24 does the same. So maybe the M0/ARM Micro lib simply isn't efficient enough to do it faster.

One option is that it needs to do integer divisions to calculate each character for the values, and M0s are fairly horrible at integer divisions. However 330us seems excessive to me.

First result on search is talking about 150 clock cycles per integer division. You need to do one (plus some other stuff) per character. So for one variable that is 600 clock cycles. At 48MHz that should be, rounded to worst cast, more like 20us.

Accepted Answer

Did some more tests. And the compiler does a pretty good job on optimizing, but later more on that.

Sprintf for a single one of your data's takes a few hunderd microseconds, depending on the number. A simple function I made (a bit too simple, it needs a few more checks, but it does the basic):

void intToString(char *buffer, int value) {
    int temp;
    temp = value / 1000;
    buffer[0] = temp + '0';
    value = value - temp * 1000;
    
    temp = value / 100;
    buffer[1] = temp + '0';
    value = value - temp * 100;
    
    temp = value / 10;
    buffer[2] = temp + '0';
    value = value - temp * 10;
    
    temp = value / 1;
    buffer[3] = temp + '0';
    value = value - temp * 1;
    
    buffer[4] = '\0';
}

Does the same in 45us. That is if I let him output an unitialized RAM location. If I do initialize that location, it is another 20 times faster, apparantly the compiler then optimizes quite a bit since it apparantly does know what is going to happen.

Anyway if you want it good, you got to do it yourself. An important lesson in life :P. But the combination is integer divisions being slow on an M0, and the standard function being even slower.

posted by Erik - 13 Nov 2014

You're my hero Erik! That did the trick! I never expected printf to be so bad, but I guess you learn something new everyday. Could you point me to a link to teach me how to initialize the RAM location for the 20 times speed up? Other than the initialization of 'char datastr0[5]' at the top, I'm not sure what else to do?

Here is the code that worked for me if anyone encounters this problem in the future. I am able to print 6 variables in 340us at 921600 bps, which is only slightly worse than the expected 45us*6 = 270us. This is probably due to the use of ',' and '\n\r'. Most of all, there is no longer any weird delays after printing each group of 6 numbers! :D

#include "mbed.h"

Serial pc(dp16,dp15);

char datastr0[5];
char datastr1[5];
char datastr2[5];
char datastr3[5];
char datastr4[5];
char datastr5[5];

// Credit: Erik Olieman
void intToString(char *buffer, int value) {
    int temp;
    temp = value / 1000;
    buffer[0] = temp + '0';
    value = value - temp * 1000;
    
    temp = value / 100;
    buffer[1] = temp + '0';
    value = value - temp * 100;
    
    temp = value / 10;
    buffer[2] = temp + '0';
    value = value - temp * 10;
    
    temp = value / 1;
    buffer[3] = temp + '0';
    value = value - temp * 1;
    
    buffer[4] = '\0';
}

int main()
{
    pc.baud(921600);
    pc.printf("Working!!\n\r");

    while(1) {
        intToString(datastr0,1114);
        intToString(datastr1,1115);
        intToString(datastr2,1116);
        intToString(datastr3,1117);
        intToString(datastr4,1118);
        intToString(datastr5,1119);
        pc.printf("%s,%s,%s,%s,%s,%s\n\r",datastr0,datastr1,datastr2,datastr3,datastr4,datastr5);

        // pc.printf("%4d,%4d,%4d,%4d,%4d,%4d\n\r",1114,1115,1116,1117,1118,1119);
    }
}

/media/uploads/mcx/screenshot_2014-11-20_17.32.57.png

posted by Michael Chuah 20 Nov 2014

Glad to hear it :).

And if you do it like you got it currently it should already be faster than realistic: The compiler nows the first one you print is 1114. However if this would be for example a value you read from a sensor it will take him 40 us (roughly) to run the intToString function. The only thing you can do about that is send it as binary instead of ascii (which doesn't make your serial protocol easier, it does make it faster though), or use a core M3/M4.

posted by Erik - 21 Nov 2014