Fast data logging with STM32F4 using USB_OTG_FS and FatFS

GDall.387 · ‎2019-10-16

Hi everyone,

I'm trying to log data from different sensor into a USB flash drive with a 500Hz sampling frequency.

I set up a timer to define the sampling frequency for data logging and everything seems to work fine.

The problems comes when i try to write the data to a log file (I've tryed txt, csv and bin, but it doesn't seems to make a difference for FatFs) beacuse the writing instruction introduces a irregoular delay.

So far i've tried:

buffering data in different way to match sector size
formatting usb disk in different way (FAT32, FAT16, exFAT)
cleaning code as much as possible to just do the writing operation while logging

Does anyone know a method to speed up writing operation?

Thank you

Here's the main:

 if(eff==1){
 
        	if(fs==1){
       	          HAL_GPIO_WritePin(LED2_GPIO_Port, LED2_Pin, RESET);
       	          myData = LIS3DSH_GetDataScaled();
       	       	  x=(int)(myData.x*9806.65);
       	       	  acc_raw[k]=x;
       	       	  k++;
       	       	  y=(int)(myData.y*9806.65);
       	       	  acc_raw[k]=y;
       	          k++;
       	       	  z=(int)(myData.z*9806.65);
       	       	  acc_raw[k]=z;
       	       	  k++;
       	       	  HAL_GPIO_WritePin(LED2_GPIO_Port, LED2_Pin,  SET);
       	          fs=0;
       	          }
  
        		if(k==99){
        			s++;
        			for(int g=0; g<98; g=g+3){
 
        			f_printf(&myFilea, "%d : %d, %d, %d\n", s, acc_raw[g], acc_raw[g+1], acc_raw[g+2]  );
        				
        			}
       			k=0;
        		bufclear1();
 
        		}
 
 
 if(HAL_GPIO_ReadPin(GPIOA, GPIO_PIN_0) == GPIO_PIN_SET && write_var==0){
 
                         	 i=0;
                         	write_var=1;
                          	 while(deb<250){
 
                          	 	 }
 
                          	 eff=1;
                           	  }
 
  if(one_sec==500 && write_var==1){
          	  	  	  	 for(int g=0; g<98; g=g+3){
 
          f_printf(&myFilea, "%d : %d, %d, %d\n", s+1, acc_raw[g], acc_raw[g+1], acc_raw[g+2]  );
          	          				//g=g+2;
          	          			}
                      	 HAL_GPIO_WritePin(LED2_GPIO_Port, LED2_Pin, GPIO_PIN_RESET);
                      	 HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_RESET);
                      	 HAL_GPIO_WritePin(LED4_GPIO_Port, LED4_Pin, GPIO_PIN_RESET);
                      	 f_close(&myFilea);
                      	 f_close(&myFilet);
                      	 write_var=0;
                      	 s=0;
                      	 deb=0;
                      	 eff=0;
                      	 open=0;
                      	 one_sec=0;
                      	 acqu_count++;
                      	 HAL_Delay(500);
                       	  }
       if(Appli_state == APPLICATION_DISCONNECT){
            	  HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_RESET);
            	  HAL_GPIO_WritePin(LED2_GPIO_Port, LED2_Pin, GPIO_PIN_RESET);
            	  open=0;
              }
      	 	
       if(open==0){
      	 	    switch(Appli_state){
      	 	    case APPLICATION_IDLE:
      	 		break;
      	 	    case APPLICATION_START:
      	 	    	res=f_mount(&myUsbFatFS, (TCHAR const*)USBHPath, 0);
      	 	    	if( res != FR_OK)
      	 	    					{
      	 	    						/* FatFs Initialization Error */
      	 	    						Error_Handler();
      	 	    					}
      	 	    					else
      	 	    					{
      	 	    						//HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_SET);
      	 	    					}
      	 	    					break;
      	 	    case APPLICATION_READY:
      	 	    					sprintf (buffer, "A%d.bin",acqu_count);
      	 	    					res=f_open(&myFilea, buffer, FA_OPEN_APPEND | FA_WRITE );
      	 	    					bufclear();
      	 	    					open=1;
      	  	 	    				HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_SET );
 
      	 	    					//HAL_Delay(500);
      	 	    				//}
 
 
      	 	   	break;
      	 	    case APPLICATION_DISCONNECT:
      	 	    	  //tUTRN GREEN ON
      	 	    	   HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_RESET);
      	 	   	break;
      	 	    }
      	 	  }
      }

Here's the Timer interrupt handler:

void HAL_TIM_PeriodElapsedCallback(TIM_HandleTypeDef *htim)
{
 /* Prevent unused argument(s) compilation warning */
		HAL_GPIO_TogglePin(LED3_GPIO_Port, LED3_Pin);
 
		if(eff==1){
			one_sec++;
		}
 
		if(write_var==1){
		deb++;
		fs=1;
		if(temp_counter <250) temp_counter++;
		else {
			fs_temp=1;
			temp_counter=0;
		}
		//i=1-i;
		}
}

GDall.387 · ‎2019-10-22

For sure, i got from the write-speed test ( writing around 10 MBs per test) :

-512B = 0,64 MB/s

-1024B = 0,66 MB/s

-2kB = 0,61 MB/s

-4kB = 0,81 MB/s

-8kB = 0,62 MB/s

-16kB= 0,80 MB/s

So i went for 4 kB buffers (over 16 kB) to prevent future RAM overflow.

I'm sampling at 500 Hz, which result in a 20kB/s datarate, that compared to the tested writing speed should be nothing.

"The input is coming from an ISR. You are burning around 32 bytes with your formatted string per capture. I'll assume you did a 512B buffer. That means you need to write after every 16th ISR. So in your case at 500Hz you need to write every 32ms. Well, if you go back to your write-evaluation test and really dig-in you're going to find that *on occasion* the SD card writes of 512B buffer actually take longer than 32ms as some behind the scenes FAT table updates are getting made. That then implies that a two-buffer system will NOT work. So now the problem becomes perhaps a 3-buffer solution? Or 4?"

I'm actually writing every 100 ISR the data collected on the buffer to the file, but to do so, i had to copy my data from the acquiring buffer to one already acquired, or swap the two ping pong buffers if doing it that way.

And the problem is that everything is running fine until everything freezes. The only one problem i could imagine is when i'm doing a f_write() i'm actually writing just a fraction of the 4 kB buffer, because the acquired data change in size, so i had to keep a margin when deciding how much of them to store in the read buffer and this maybe makes fall all the test on writing speed i made cause i'm not writing always the same length as a buffer.

I'm trying to fix this too.

I've made even a 3 buffer version, but without any difference unfortunately, like shown below as a part of the ISR. And in the main i'm always copying it to a write buffer to write it to the file.

// In ISR if writing is enabled, i start to store data in the read buffer	
if(eff==1){
			if(ping==true){
				sprintf(USB_buff_read1, "%s%f, %f, %f\n",USB_buff_read1, myData.x, myData.y, myData.z );
			}else{
				sprintf(USB_buff_read2, "%s%f, %f, %f\n",USB_buff_read2, myData.x, myData.y, myData.z );
		}
			k++;
			//one_sec++;
 
		}

Thank you so much, with your help i'm gradually reaching the result

Bill Dempsey · ‎2019-10-22

It seems as if you're missing a basic concept of how to do the ping-pong-etc buffers. I get this from the sense of your replies and missing code segments...

I can't see all your code but it should have some kind of pointer swap logic in it. Two pointers would be a useful way of implementing this such as below:

char bufferA[4096];
char bufferB[4096];
 
char * isrPtr = bufferA;
char * wrtPtr = bufferB;

Never would you need to copy. isrPtr is changed to point to bufferA or to bufferB and at the same time wrtPtr would point to the opposite buffer. Above shows a starting condition but of course the data is not full so out of the gate the write side pends until the isr buffer is full.

Somehow in your code you need to have a software mutex (https://en.wikipedia.org/wiki/Mutual_exclusion) such that you can't swap if the "other" side is busy.

According to your math, this should never happen but I suspect due to unexpected timing events you have a race-case where either the main loop is trying to advance before the ISR is done or vice-versa.

The trick is signaling when it's time to write and then making sure the write is complete before a swap can occur (enough_bytes && write_not_busy). If you encounter a situation where the case is not true, stop the code and debug why. I'll bet you'll find this race-case exists.

Even though you show the *average* write-rate is high enough, did you set a watermark for the worst-case write? Go ahead and write a GB worth of data and time each block-write and keep track of the highest time. This can be card specific so be aware. Hopefully no blocks exceed 50ms or so...

Also why not go ahead and write the full 4096 bytes during the write? That simplifies things on the capture side... set your 3rd argument to the buffer size (4096). http://irtos.sourceforge.net/FAT32_ChaN/doc/en/write.html

If you're already doing all this above, I have not seen it in the code you've posted so feel free to share any additional code that might be useful.

GDall.387 · ‎2019-10-23

Again a big thanks,

I'm trying to explain the situation as clear as possible:

Here my global variables i'm working with: (nevermind the presence of temperature or t related variables)

//Buffer fro file names
char buffer[8];
//Acc data buffers
char USB_buff_read1[4096];
char USB_buff_read2[4096];
//Temp data buffers
char USB_buff_readt[2048];
char USB_buff_writet[2048];
//usb variables
extern ApplicationTypeDef Appli_state;
//Button behaviour flag
bool write_var=0;
//USB mounted & File opened flag
bool mounted=0;
bool open=0;
//Sampling frequency flag
bool fs=0;
//Number of acquisition made
int acqu_count=0;
//Temperature sampling flags&counter
uint16_t temp_counter;
uint16_t fs_temp=0;
//buffer filling counters
int k=0;
int t=0;
//Actually acquiring flag
int eff=0;
//Ping pong flag
bool ping=0;

After everything has been init, the first thing the program does is wayting the usb to be mounted and opening a file to be ready to acquire:

MX_USB_HOST_Process();
 
if(open==0){
      	 	    switch(Appli_state){
      	 	    case APPLICATION_IDLE:
      	 		break;
 
      	 	    case APPLICATION_START:
      	 	    	if(mounted == 0){
      	 	    	res=f_mount(&myUsbFatFS, (TCHAR const*)USBHPath, 0);
      	 	    	if( res != FR_OK)
      	 	    					{
      	 	    						/* FatFs Initialization Error */
      	 	    						Error_Handler();
      	 	    					}
      	 	    					else
      	 	    					{
      	 	    						mounted=1;
      	 	    		      	 	    					}
      	 	    	}
      	 	    					break;
      	 	    case APPLICATION_READY:
                                   //Open file to log datas
      	 	    					sprintf (buffer, "A%d.bin",acqu_count);
      	 	    					res=f_open(&myFilea, buffer, FA_OPEN_APPEND | FA_WRITE );
      	 	    					bufclear();
      	 	    					open=1;
      	 	   	break;
      	 	    case APPLICATION_DISCONNECT:
      	 	    	  //Turn greed led on
      	 	    	   HAL_GPIO_WritePin(LED1_GPIO_Port, LED1_Pin, GPIO_PIN_RESET);
      	 	   	break;
      	 	    }
      	 	  }
      }

When file is open and ready to be written, a button press is waited to start acquiring, when pressed, the acquisition can start:

if(HAL_GPIO_ReadPin(GPIOA, GPIO_PIN_0) == GPIO_PIN_SET && write_var==0){
                         	 k=0;
                         	 t=0;
                         	 write_var=1;
                         	 clearUSB_L(USB_buff_read1);
                         	 clearUSB_L(USB_buff_read2);
                          	 HAL_Delay(500);
                          	 temp_counter=0;
                          	 eff=1;
                           	  }

When this happen, the ISR starts to acquire data and store them in one of the two buffers, depending on the ping_pong state:

if(eff==1){
 	          myData = LIS3DSH_GetDataScaled();
			if(ping==0){
				sprintf(USB_buff_read1, "%s%f, %f, %f\n",USB_buff_read1, myData.x, myData.y, myData.z );
			}else{
				sprintf(USB_buff_read2, "%s%f, %f, %f\n",USB_buff_read2, myData.x, myData.y, myData.z );
		}
			k++;
			//one_sec++;
 
		}

As soon as the buffer is full (counter k reach 150) in the main the buffers are swapped and the full one is written to file and then cleared:

if(k==100){
        				ping=1-ping;
        				k=0;
 
        				if(ping==1){
        				f_write(&myFilea, USB_buff_read1, 4096, NULL);
            			        clearUSB_L(USB_buff_read1);
        				}else{
                		        f_write(&myFilea, USB_buff_read2, 4096, NULL);
                		        clearUSB_L(USB_buff_read2);
        				}
 
        					}

And this goes on until i repress the button and close and save the file, restore all the flags and open a new one ready to be logged again.

I didint use a pointer approach for swapping buffers, but i change them based on flags as you can see from the code above.

And the program runs fine for acquisition of 2 minutes, even ten of them, but when trying to log for a longer time the previously disussed errors came into the game.

I try to find some hint about Mutex implementation, but everything i found was based on RTOS, and for me it's a complete new world, since this step is something i'm doing as a step of a more long and complex project which is supposed to use the data i can retrieve.

Is correct the way i implemented the double buffering or i must rearrange it to work with pointers logic?
Is there anyway i can implement a software mutex without using RTOS?

Thank you

GDall.387 · ‎2019-10-23

Furthermore, analyzing the hard fault, i get :