lost bytes on UART when SD logging enabled.

General discussions and questions abound development of code with MicroPython that is not hardware specific.
Target audience: MicroPython Users.
Post Reply
jcsduncan
Posts: 6
Joined: Thu Feb 26, 2015 9:07 am

lost bytes on UART when SD logging enabled.

Post by jcsduncan » Thu Feb 26, 2015 4:17 pm

I have an interesting issue whereby bytes are lost during a UART rx loop which includes a binary write to file.

I have investigated it as much as i can and i can state the following facts:

It is not time related i.e. The buffer is not filling - i am reading bytes and writing bytes only.

I have tried many read_buf_len sizes and read byte sizes - no change in results.

Virtual Serial Port is disabled (not plugged in). REPL redirected to UART3 (for prints)

I have inserted artificial delays before and after file write to no avail


RX loop: (All bytes received when file.write() commented)

Buffer returns no more than 70 bytes per read with the following code (sd write enabled)

self.ser.init(9600, read_buf_len=512, timeout=1000)
file = open(logFile, 'ab')
total_bytes = 0

while self.logging:
data = ser.read(128)
# print (data)
total_bytes += len(data)
delay(25)
if log_file:
file.write(data)
delay(25)
print (str(total_bytes))

logging enabled/disabled via interrupt.

Any help would be appreciated.

Thanks,
Chris

User avatar
dhylands
Posts: 3821
Joined: Mon Jan 06, 2014 6:08 pm
Location: Peachland, BC, Canada
Contact:

Re: lost bytes on UART when SD logging enabled.

Post by dhylands » Thu Feb 26, 2015 6:11 pm

I think that the issue is happening because the UART has no FIFO (or perhaps you could think of it as a FIO of length 1).

I seem to recall that we did (perhaps still do) disable interrupts during part of the write to disk. If interrupts are disabled for longer than a character time then characters will be dropped.

Are you running on a recent firmware? I know that we had code in the write to flash path which disabled interrupts, but I'm not seeing it anymore, or not looking in the right place.

I seem to recall reading somewhere that there might be a way of using timers/DMA on uart RX to make it so we don't drop characters, but that code doesn't currently exist in our tree.

jcsduncan
Posts: 6
Joined: Thu Feb 26, 2015 9:07 am

Re: lost bytes on UART when SD logging enabled.

Post by jcsduncan » Thu Feb 26, 2015 6:47 pm

I flashed the pyboard with (what I believe to be) the latest firmware.

pybv10-2015-02-26-v1.3.10-99-g7a074a1.dfu

Losing byte(s) doesn't occur on every write (to file).

Do you think if I manually disabled/enables interrupts before and after a write it would make a difference?

Thanks Dave :-)

User avatar
dhylands
Posts: 3821
Joined: Mon Jan 06, 2014 6:08 pm
Location: Peachland, BC, Canada
Contact:

Re: lost bytes on UART when SD logging enabled.

Post by dhylands » Thu Feb 26, 2015 7:17 pm

Having interrupts disabled is most likely the cause of the problem. So manually disabling/enabling interrupts will just make it worse.

I found the culprit:
https://github.com/micropython/micropyt ... #L175-L180

So when this gets re-written to use DMA, or the UART RX path gets rewritten to use DMA, then the problem of dropping characters should go away.

jcsduncan
Posts: 6
Joined: Thu Feb 26, 2015 9:07 am

Re: lost bytes on UART when SD logging enabled.

Post by jcsduncan » Thu Feb 26, 2015 7:24 pm

Ok. I will have to wait for the update :-(

User avatar
SureshVakati
Posts: 42
Joined: Fri Feb 24, 2017 3:52 pm

Re: lost bytes on UART when SD logging enabled.

Post by SureshVakati » Sun Mar 05, 2017 6:46 am

I am having exactly the same problem. I am downloading a firmware (1MB) from internet to SD card using a Telit cellular module. Module transmits the data serially to STM32F4 via UART6, I tried different buffer lengths and different ways, it is receiving the file without dropping any bytes once out of 15 tries. 6 external interrupts are enabled in my project. What is the solution to this?

User avatar
SureshVakati
Posts: 42
Joined: Fri Feb 24, 2017 3:52 pm

Re: lost bytes on UART when SD logging enabled.

Post by SureshVakati » Sun Mar 05, 2017 6:39 pm

Hi Dave,
Could you suggest anything on this issue?

User avatar
dhylands
Posts: 3821
Joined: Mon Jan 06, 2014 6:08 pm
Location: Peachland, BC, Canada
Contact:

Re: lost bytes on UART when SD logging enabled.

Post by dhylands » Sun Mar 05, 2017 7:40 pm

Not sure. I'm assuming that you're not doing your writes to the sdcard from within an IRQ.

The serial IRQ is already at he highest IRQ level (just lower than systick)
https://github.com/micropython/micropyt ... irq.h#L106

so there are only a few reasons for dropped characters:
1 - interrupts are being disabled for too long
2 - Perhaps your buffer is getting filled because you're not reading it frequently enough (i.e. being delayed by sdcard writes) so you might want to increase your buffer size. It's 64 bytes by default.

User avatar
SureshVakati
Posts: 42
Joined: Fri Feb 24, 2017 3:52 pm

Re: lost bytes on UART when SD logging enabled.

Post by SureshVakati » Sun Mar 05, 2017 9:45 pm

1 - interrupts are being disabled for too long
file write method disables all interrupts? I am not disabling any interrupts manually in my code. What interrupts actually you mean?

Code: Select all

@classmethod
    def FTP(cls):
        cls.Enable_Socket('web.omwtoday.com')        
        cls.Receive('AT#FTPTO=1000',2)
        cls.Receive('AT#FTPOPEN="ftp.drivehq.com","SURESHVAKATI","password",0',10)
        cls.Receive('AT#FTPTYPE=0',2)
        while 'CONNECT' not in cls.Receive('AT#FTPGET="t2pypack.bin"',10):
            time.sleep(0.5)
        #cls.Receive('AT#FTPGET="t2pypack.bin"',10)
        data=b''
        le=0        
        #f=open('update_t2pypack.bin','w')           
        cls.uart=pyb.UART(6,115200,read_buf_len=3000,timeout=1000)
        print("dcd:",cls.DCD.value())
        gc.collect()
        while(cls.DCD.value()!=1):            
            if cls.uart.any():         
                data=cls.uart.read(3000)               
                if b'\r\nNO CARRIER' in data:
                    x=data.find(b'\r\nNO CARRIER')
                    data=data[:x]
                    
                #f.write(data)
                print(data)
                le+=len(data)
                print(le)
                
        #f.close()
        cls.Receive('AT#FTPCLOSE',2)
        os.sync()
        gc.collect()
        print(le)
This is my code, I am using buffer-length 3000. If I comment out file write then I am receiving all the data correctly. When Initializing UART, I haven't set "timeout_char" value. Do I have to set this? I started at 256, tried 512 and finally 3000. If I go beyond that memory allocation errors, lower buffer_lengths more data drops! Do I need to enable Hardware flow control to avoid drops? In my Config File I haven't define CTS/RTS lines because they were on different ports. I was told UART still uses PORT/GPIO method three four months ago.

Is this way changed already, like defining port names and choosing GPIO pins for UART? My modem Tx,Rx connected to PC6 and PC7 and CTS/RTS are at PG15,PG12 and DSR,Ring,DCD,DTR are at PD3,PD7,PD8,PD9. Now I see PBYV10 has no #define MICROPY_HW_UART1_PORT (GPIOB), all of them are now PIN object based.

My config File.

Code: Select all

#define MICROPY_HW_UART1_PORT (GPIOB)
#define MICROPY_HW_UART1_PINS (GPIO_PIN_6 | GPIO_PIN_7)

#define MICROPY_HW_UART2_PORT (GPIOD)
#define MICROPY_HW_UART2_PINS (GPIO_PIN_5 | GPIO_PIN_6)
#define MICROPY_HW_UART2_RTS  (GPIO_PIN_4)

// T2 PORTS GPIOD and GPIOB used!!
#define MICROPY_HW_UART3_PORT (GPIOD)
#define MICROPY_HW_UART3_PINS (GPIO_PIN_8 | GPIO_PIN_9)
#define MICROPY_HW_UART3_RTS  (GPIO_PIN_12)
#define MICROPY_HW_UART3_CTS  (GPIO_PIN_11)

// T2 PORTS GPIOC and GPIOG used!!
#define MICROPY_HW_UART6_PORT (GPIOC)
#define MICROPY_HW_UART6_PINS (GPIO_PIN_6 | GPIO_PIN_7)

PBYV11 board Configuration

Code: Select all

// UART config
#define MICROPY_HW_UART1_NAME   "XB"
#define MICROPY_HW_UART1_TX     (pin_B6)
#define MICROPY_HW_UART1_RX     (pin_B7)
#define MICROPY_HW_UART2_TX     (pin_A2)
#define MICROPY_HW_UART2_RX     (pin_A3)
#define MICROPY_HW_UART2_RTS    (pin_A1)
#define MICROPY_HW_UART2_CTS    (pin_A0)
#define MICROPY_HW_UART3_NAME   "YB"
#define MICROPY_HW_UART3_TX     (pin_B10)
#define MICROPY_HW_UART3_RX     (pin_B11)
#define MICROPY_HW_UART3_RTS    (pin_B14)
#define MICROPY_HW_UART3_CTS    (pin_B13)
#define MICROPY_HW_UART4_NAME   "XA"
#define MICROPY_HW_UART4_TX     (pin_A0)
#define MICROPY_HW_UART4_RX     (pin_A1)
#define MICROPY_HW_UART6_NAME   "YA"
#define MICROPY_HW_UART6_TX     (pin_C6)
#define MICROPY_HW_UART6_RX     (pin_C7)
:roll: If I download a Master-Micropython from Github, how would I know which version I am making and what are the changes to it from previous version? I don't see these details in Readme file.

User avatar
dhylands
Posts: 3821
Joined: Mon Jan 06, 2014 6:08 pm
Location: Peachland, BC, Canada
Contact:

Re: lost bytes on UART when SD logging enabled.

Post by dhylands » Mon Mar 06, 2017 2:11 am

You definitely want to be reading less than the buffer size, otherwise it more or less defeats the purpose of using a buffer.
If you're waiting for the entire buffer to become full before returning from the read then you essentially only get a single character time to read the whole buffer.

You should time how long the sdcard writes are taking and ensure that the buffer size holds more characters than can arrive during that time period. I'd also recommend that you make your reads be a power of 2, since the filesystem blocks are going to be a power of 2.

So try using a read size of 1024 bytes and a buffer size of 2048 bytes.

But you still need to know how long the sdcard writes are taking and make sure that your buffer is big enough. You should measure each sdcard write and keep track of the longest write time, since that's the one that's important.

And as you noticed, the uart configuration has changed to be pin based so there is no longer any requirement that TX/RX/CTS/RTS all be on the same port.

After checking out a branch, you can use

Code: Select all

git describe HEAD
to see what version it is. The latest shows up as:

Code: Select all

2041 >git describe HEAD
v1.8.7-348-gfe866d9
You can use git log to see what has changed. Note that there have been close to 600 commits in the last 3 months.

Post Reply