11 Replies Latest reply on May 13, 2020 4:19 AM by JaPh_4667081

    Heap Size causing strange printf delay behavior.

    JaPh_4667081

      Hello! I was hoping someone with more insight than myself might be able to point me in the right direction.

       

      I am using a PSOC LP5 (CY8C5888LTI-LP097 on the CY8CKIT-059). I used the UART_FULL_DuplexExample project as a base which enables printf by rewriting the _write function. All this works as expected. However, when I needed to print floats to the screen I had to up the heap size from 0x300 to 0x400 which makes sense to me.

       

      Here is the real confusing part for me. I made the following function for some debugging. There is an interrupt that decrements the timer variable every 1ms. It should print /hi every 100 ms.

       

      //Initialize display delay to zero
          g_Timer_Display_Delay_ms = 0;
          
          for(;;)
          {
              if(g_Timer_Display_Delay_ms == 0)
              {
                  g_Timer_Display_Delay_ms = 100u; //Reset timer
                  Pin_Debug_Write(!Pin_Debug_Read()); //Toggle pin for testing
                  //Print values
                  UART_PutString("/"); 
                  printf("hi");
              }
              
          }
      

       

      If I periodically increase the heap size :

      • 0x400 Pass
      • 0x500 Pass

      I get the expected output:

      /hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi

      /hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/

       

      But when I increase the heap size further:

      • 0x600 FAIL

       

      At 0x600 I get the following output:

      ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////

      ////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////

      /////////////////////////////////////////////////////////////////////////////////////////hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

      hihihihihihihihihihihihi///////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////

       

      I have the debug IO on a scope and it is toggled at a constant at 100ms so the printf function is not blocking. It seems to buffer a whole bunch of characters and then spits it out 51.3 seconds later! The compiler has no warning about the heap size allocation. I expect I am exceeding some memory limit and stepping on some control register or buffer somewhere?

        • 1. Re: Heap Size causing strange printf delay behavior.
          LePo_1062026

          japh,

           

          There is no logical reason increasing the heap size should cause what you are witnessing based on your description.

          Are you willing to share your project with the forum for others to reproduce your results?

           

          Len

          • 2. Re: Heap Size causing strange printf delay behavior.
            JaPh_4667081

            Since this project now contains a lot of other development for a company, I will make a cleaned up version I can share and post it shortly. Thank you!

            • 3. Re: Heap Size causing strange printf delay behavior.
              JaPh_4667081

              Here is a real quick and very dirty example. I did a complete archive just in case there was an issue with my compilation.

              Steps to recreate:

              • Start with uart full duplex example
              • Change the device using the device selector to the CY8C588LTI-LP097
              • Added the clock and isr
              • Added the minimum code modifications as seen in the project main.c
              • Change the heap size in the system tab to 0x600
              • Run and view uart output. It delays printing the hi text as previously described

               

              Thank you very much!

              • 4. Re: Heap Size causing strange printf delay behavior.
                LePo_1062026

                vjaph,

                 

                I tried your example project.  I have been able to reproduce your results.

                 

                With heap = 0x500:

                UART Full Duplex and printf() support Code Example Project

                Test printf function. long:444444444, Single float:55.56

                Multi float:55.56 55.56 55.56 55.56 55.56 55.56 55.56 55.56 55.56 55.56

                Enter the characters to transmit

                /hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi/hi

                 

                With heap = 0x600:

                UART Full Duplex and printf() support Code Example Project

                Test printf function. long:444444444, Single float:?. 

                Multi float:?.  ?.  ?.  ?.  ?.  ?.  ?.  ?.  ?.  ?. 

                Enter the characters to transmit

                ///////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////

                ///////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////

                ///////////////////////////////////////////////////////////////////////////////////hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

                hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihih

                ihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihih

                ihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

                hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihih

                ihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihi

                hihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihihih

                ihihihihihi/////////////////////////////////////////////////////////////////////////////////////////////

                Besides the printf() for the float being wrong/incomplete, the '/' is put out every 10msec but the 'hi' when it does come out comes out virtually at the same time with no perceivable delay.

                 

                Len

                1 of 1 people found this helpful
                • 5. Re: Heap Size causing strange printf delay behavior.
                  LePo_1062026

                  japh,

                   

                  More updates:

                  There are two issues at play here.

                   

                  Issue #1

                  • In your code you have the followings two lines in the for(;;) loop:
                  UART_PutString("/");
                  printf("hi");
                  

                   

                  The printf() code uses a different buffering scheme from the UART_PutString(). 

                  UART_PutString() places the data almost directly in the FIFO buffer of the UART. 

                   

                  The printf() places the UART data on the heap AND (this is very important) the printf() function will not move the data from the heap to the UART FIFO unless a CRLF is sent OR the heap is full.   This explains in part why the '/' character is output every 10msec but the "hi" strings aren't dumped to the UART until the heap is full.

                   

                  My advice is to only use the UART_Putxxx() functions or the printf() functions with a CRLF.

                   

                  For example,  I changed your printf("hi") to UART_PutString("hi").  No problem.

                  I changed the UART_PutString("/"); printf("hi");   to printf("/hi\r\n");.  No problem.

                   

                  Issue #2

                  At this point you're wondering why if Issue #1 is true,  then why didn't this show up when the heap < 0x600?

                   

                  Good question.  Someone will have to analyze the printf() function and its' relationship to the heap.  Since the printf() is a part of the GCC library and the source code is not included this will be difficult.

                   

                  Len

                  1 of 1 people found this helpful
                  • 6. Re: Heap Size causing strange printf delay behavior.
                    JaPh_4667081

                    Thanks for the response! I am actually not using UART_PutString regularly. I only added it as an example as I knew it would write directly to the uart.

                     

                    In my regular use case I am attempting to print several values with just a line return rather than a next line to overwrite the line. So my prints would regularly be printf("stuff\r"); I do still see the issue there.

                     

                    You are absolutely right though, adding a \r\n to the print statement fixes the update issue!

                     

                     

                    I am a bit confused on one thing though. So if you update the code to the following by removing the UART_PutString call:

                     

                    //Initalize display delay to zero
                        g_Timer_Display_Delay_ms = 0;
                        
                        for(;;)
                        {
                            if(g_Timer_Display_Delay_ms == 0)
                            {
                                g_Timer_Display_Delay_ms = 100u; //Reset timer
                                Pin_Debug_Write(!Pin_Debug_Read()); //Toggle pin for testing
                                //Print values
                                printf("hi ");
                            }
                            
                        }
                    

                     

                    There is no CLRF, and only printf is being used right?

                     

                    But with a heap size of 0x500 it does not wait to print. It prints right on time every time. It's not waiting to fill the heap before printing.

                    With a heap size of 0x600 it doesn't print anything for a while then dumps it all out!

                     

                    So if what you said before was true, I would expect when I set the heap to 0x500 that it would just dump a little sooner because the heap is getting fuller sooner.

                     

                    Also if printf requires a CLRF or a full heap, then wouldn't any printf without \r\n always wait until you fill up the heap to print? I have several programs that only print a small amount on boot-up that would never have filled the heap and doesn't have a return that prints right away.

                    • 7. Re: Heap Size causing strange printf delay behavior.
                      LePo_1062026

                      japh,

                       

                      This is the paradox of Issue #2.

                       

                      Without the source code for printf() this will not be easily solvable.

                       

                      Len

                      • 8. Re: Heap Size causing strange printf delay behavior.
                        MoTa_728816

                        Hi,

                         

                        What I learned about standard I/O and buffered I/O of Unix (actually it was HP-UX) was that

                        since a print to tty is an expensive operation, buffered IO such as printf (which is actually fprintf(stdout,...))

                        is trying to reduce the frequency of print as much as possible.

                        On the other hand a non buffered IO such fprintf(stderr, ...) outputs the result immediately.

                         

                        Now it seems that what happening here is when heap is small the internal buffer size of printf  (actually stdout) is small,

                        and when heap is larger the internal buffer size of  printf is larger.

                         

                        And printf prints out the buffer when

                        (1) Encounter an EOL (end of line)

                        (2) When buffer is FULL

                        (3) When flush() is requested.

                         

                        Current situation is caused by the case (2).

                         

                        If you intentionally do either (1) or (3)  the output will appear immediately.

                         

                        So I added  fflush(stdout) just after printf("hi")  in your program and the result was

                        000-TeraTerm-log.JPG

                         

                        =================

                                if(g_Timer_Display_Delay_ms == 0)

                                {

                                    g_Timer_Display_Delay_ms = 100u; //Reset timer

                                    Pin_Debug_Write(!Pin_Debug_Read()); //Toggle pin for testing

                                    //Print values

                                    UART_PutString("/");

                                    printf("hi");

                                    fflush(stdout) ;

                                }

                        =================

                         

                        Attached is a modified project of yours.

                         

                        moto

                        2 of 2 people found this helpful
                        • 9. Re: Heap Size causing strange printf delay behavior.
                          JaPh_4667081

                          Thank you Moto!

                           

                          I was unaware of the manual flush option and your explanation was very good. I appreciate it! Indeed the modification works exactly as you described. I'm going to do some research and see if I can find a way to rewrite part of the printf functionality to reduce this delay. That or write a wrapper for printf and add the flush in.

                           

                          Thanks!

                          • 10. Re: Heap Size causing strange printf delay behavior.
                            JaPh_4667081

                            Marking the issue solved, thank you both Len and Moto!

                            • 11. Re: Heap Size causing strange printf delay behavior.
                              JaPh_4667081

                              I wanted to reply with a helpful bit of information. Some searching turned up the function setbuf()

                               

                              You can disable buffering of stdout (and other streams I imagine) with this:

                              setbuf(stdout, NULL);

                               

                              I confirmed it works without needing to manually add the fflush line.

                               

                              Thanks again for all the help!