cstm32freertos

Frames from uart logger merging into one


I made my own UART logger on stm32 to practice in freertos. USART is configured in a standard way with DMA. To test my code I use 2 threads to write messages every 500ms and 1 thread to transmit data to pc every 10ms. However I got a strange issue:

Sometimes bytes from multiple frames are merging in one frame. For example from thread 1 I send "[ data ]:task1belbel" and from thread 2 "[status]:task2blabla". Sometimes they can merge into something like "[ data ]:tas[ data ]:ta[status]:task2blabla".

I used a semaphore, queue and mutex. Every access to queue is blocked by mutex in send and transmit functions, semaphore is used to get info about data transmission completion. Code looks as follows:

Logger.c

#include "Logger.h"
#include "BSP_Logger.h"
#include "cmsis_os.h"
#include "string.h"


#define PREFIX_SIZE 9   /* size of a message descriptor*/


/* transmission buffer , non circular*/
uint8_t TransmitBuf[40];

extern osMutexId_t LoggerMutexHandle;
extern osMessageQueueId_t LoggerQueueHandle;
extern osSemaphoreId_t LoggerSemHandle;

/* message descriptors */
const char * const logPrefix[]={"[error ]:",
                                "[status]:",
                                "[ info ]:",
                                "[ data ]:",
                                "unknown: "};
const char * const task2comp={"[status]:task2blabla"};
const char * const task1comp={"[ data ]:task1belbel"};


/** @brief: function to place a message in a send queue
 *  @param: str - pointer to a data to place in a queue
 *  @param: len - lenght of data to place in a queue
 *  @param: type - type of descriptor to add to a message
 *  @retval: 0 - data is placed in a queue , 1 - data is not placed
*/
uint8_t LoggerSend(const char *str, uint8_t len,LogType type) {
  LogDesctiptor msg;
  if(str==NULL || len == 0)
    return 1; // Error: null string or zero length
  if(type>LOG_DATA)
    type=LOG_UNKNOWN;
  msg.type=type;
  if(osMutexAcquire(LoggerMutexHandle,0)!=osOK)
    return 1;
  if(len<=QUEUE_MAX_SIZE)
    msg.size=len;
  else
    msg.size=QUEUE_MAX_SIZE;
  memcpy(&msg.payload,str,msg.size);
  if(osMessageQueuePut(LoggerQueueHandle,&msg,0,0)!=osOK)
    return 1;
  osMutexRelease(LoggerMutexHandle);
  return 0; 

}

/** @brief: function to transmit a single message */
void LoggerTransmit(void){
  if(osSemaphoreAcquire(LoggerSemHandle,0)==osOK){
    if(osMessageQueueGetCount(LoggerQueueHandle)){
      if(osMutexAcquire(LoggerMutexHandle,0)==osOK){
        LogDesctiptor msg;
        osMessageQueueGet(LoggerQueueHandle,&msg,NULL,0);
        memcpy(TransmitBuf,logPrefix[msg.type],PREFIX_SIZE);
        memcpy((TransmitBuf+PREFIX_SIZE),&msg.payload,msg.size);
        BSP_LoggerTransmit(TransmitBuf,PREFIX_SIZE+msg.size);
        osSemaphoreRelease(LoggerSemHandle);
        osMutexRelease(LoggerMutexHandle);
      }
      else
        osSemaphoreRelease(LoggerSemHandle);
    }
    else
      osSemaphoreRelease(LoggerSemHandle);
  }
}

Logger.h

#ifndef __LOGGER_H
#define __LOGGER_H

/** @brief: driver for printing debug messages by USART
    multithread access supported
*/
#include <stdint.h>

#define QUEUE_MAX_SIZE 20

typedef enum __attribute__((packed)){
  LOG_ERROR=0,
  LOG_STATUS=1,
  LOG_INFO=2,
  LOG_DATA=3,
  LOG_UNKNOWN=4
}LogType;


typedef struct{
  LogType type;
  uint8_t size;
  uint8_t payload[QUEUE_MAX_SIZE];
}LogDesctiptor;

/** @brief: function copies data to local buffer , transmission is delayed */
uint8_t LoggerSend(const char *str, uint8_t len,LogType type);

/** @brief: function that sends data from local buffer  */
void LoggerTransmit(void);

#endif /* __LOGGER_H */

BSP_Logger.c

#include "cmsis_os.h"
#include "BSP_Logger.h"

extern UART_HandleTypeDef huart2;
extern osSemaphoreId_t LoggerSemHandle;


void HAL_UART_TxCpltCallback(UART_HandleTypeDef *huart){
  if(huart==&huart2){
    osSemaphoreRelease(LoggerSemHandle);
  }
}

void BSP_LoggerTransmit(const uint8_t * buf,uint8_t size){
  HAL_UART_Transmit_DMA(&huart2,buf,size);
}

All rtos stuff is defined elsewhere in stm32cubemx generated files.

I tried to debug transmitBuf to see whatÄs inside before transmission, but everything seems fine. I think its a problem from hal drivers, but maybe I messed up semaphore, queue logic ?


Solution

  • First point is that FreeRTOS message queues are inherently thread safe. You don't need to separately protect them with your own mutex. So removing everything to do with LoggerMutexHandle will immediately make your code simpler and easier to understand.

    As to your actual problem, you are using LoggerSemHandle for two (incompatible) purposes. You seem to be using it to indicate when a DMA transmission has completed. But you're also using it to protect the message queue in LoggerTransmit().

    Simplified, your code is like:

    void LoggerTransmit(void){
      if(osSemaphoreAcquire(LoggerSemHandle,0)==osOK){
        if(osMessageQueueGetCount(LoggerQueueHandle)){
            // ...
            BSP_LoggerTransmit(TransmitBuf,PREFIX_SIZE+msg.size);
            osSemaphoreRelease(LoggerSemHandle); // <-- BUG here
          }
          else
            osSemaphoreRelease(LoggerSemHandle);
        }
        else
          osSemaphoreRelease(LoggerSemHandle);
    }
    
    void HAL_UART_TxCpltCallback(UART_HandleTypeDef *huart){
        osSemaphoreRelease(LoggerSemHandle);
    }
    

    Ask yourself what would happen if you called LoggerTransmit() twice in quick succession. LoggerTransmit() is itself releasing the LoggerSemHandle which is used to indicate when the transmission has completed. So the second call will proceed immediately without waiting for the previous one to complete.

    The answer is to simply not release the semaphore in LoggerTransmit() if you successfully start a DMA transmission. i.e. you want code like:

    void LoggerTransmit(void){
      if(osMessageQueueGetCount(LoggerQueueHandle)){
        if(osSemaphoreAcquire(LoggerSemHandle,0)==osOK){
            // ...
            BSP_LoggerTransmit(TransmitBuf,PREFIX_SIZE+msg.size);
            // Semaphore release removed here
        }
      }
    }
    
    void HAL_UART_TxCpltCallback(UART_HandleTypeDef *huart){
        osSemaphoreRelease(LoggerSemHandle);
    }
    

    I also swapped the order of checking the message queue and taking the semaphore, so you don't need all the nasty else clauses to tidy up.