0

Timing bug in Adafruit thermal printer library
Moderators: adafruit_support_bill, adafruit

Please be positive and constructive with your questions and comments.

Timing bug in Adafruit thermal printer library

by cdj on Sat Feb 11, 2017 1:10 am

Problem:
Under certain conditions, as explained below, it appears that an unintended delay in Arduino processing is introduced by the timeoutWait routine in the Adafruit thermal printer library. The Adafruit_Thermal.cpp file includes the following line of code:

while((long)(micros() - resumeTime) < 0L); // (syntax is rollover-proof)

I believe that the timeoutWait routine is intended to pace the output to the printer in order to avoid overrunning printer's internal buffer. The length of time that it takes to print a character is variable, and the time depends on how many dots are required to form the character. After a character is sent to the printer, the required delay time is calculated and then used to calculate a "resume" time in microseconds. The resume time is the counter value returned by the micros() routine beyond which it is ok to send the next character. If the next character is ready to be sent to the printer before the resume time is reached, then the above line of code is intended to introduce a delay until the resume time is reached.

The while loop is a pretty tricky line of code because of a couple of things. It is doing arithmetic and comparison on 32 bit unsigned counters, AND it is also casting these unsigned integers into signed integers. This line works ok if the next character to print arrives shortly after the last character, and either slightly before the resume time, or slightly after it. However, there are some other cases which produce the wrong result. The above line is necessary, but it alone is insufficient. A wrong result can cause the while loop to execute for some period of time when it should not be executed at all, as explained below.

The problem occurs when the next character to be printed arrives after a long delay. For instance, if a line of output is produced every few hours, then the time between the last char of the previous line and the first character of the next line is quite long, and also unpredictable. If the time between characters to print is longer than 1/2 of the maximum value of a 32 bit microsecond counter, which translates to about 36 minutes, then there can be problems. In the case of such a delay there is actually no need for executing the while loop at all before sending the newly arrived character to the printer.

However, with the existing code, a resume time was calculated for the previous character, and the resume time value was set after that character was sent to the printer. The microsecond timer could wrap many times before the application decides to send the next character (or line of characters) to the printer. When the next character arrives, the microsecond counter could have any random value from 0 to 4 billion (maximum 32 bit value), and the above line of code is going to do arithmetic with the current counter, and the ancient history value of the resume time.

An analysis of the arithmetic led to this conclusion: There is a definite problem when micros() returns a number that is within 1/2 of the microsecond counter cycle behind the resume time (this includes rollover). The value might be considered legitimate if it is within a few seconds of the resume time. However, anything more represents a long delay between characters and the above code will introduce a needless and undesirable wait that is up to 1/2 of the microsecond cycle counter, or from 0 to about 36 minutes.

I have observed this random, variable, and very undesirable delay in my thermostat project. It is not nice to hold up the operation of the thermostat, especially on a cold day. I was motivated to find the cause. I presented the damning evidence in this Adafruit forum post: viewtopic.php?f=25&t=109151&p=546358&hilit=software+serial+hangs+system#p546358, but it did not lead to any relief.

The problem can be demonstrated quite easily, and a thermal printer is not required, just the thermal printer library. I wrote a simple program that writes 2 lines to the printer with a delay between them. The delay is for a few seconds less than 1/2 the microsecond counter cycle. Time stamps taken before and after the second print line confirm a 30+ minute delay in getting it printed.

The FIX

I believe that the problem can be fixed by adding a few lines of code to the timeoutSet and timeoutWait methods. I do not know what the absolute character delay time limit is for the printer, so I selected an arbitrary value of 10 seconds as the maximum time that the while loop should ever run. With the code below, the while loop is invoked only when the current time is 10 seconds or less behind the resume time (including rollover). A calculation that yields a value of more than 10 seconds would indicate a rollover condition whereby the current time is well past the resume time.

I believe that without either a real time clock or a significantly different library design it is not possible to truly expunge this bug. However, with the proposed fix the chance of hitting the "error window" is (a) extremely small, and (b) the maximum erroneous and unnecessary delay is no more than 10 seconds. So, I think that applying the fix with the millisecond timer provides a reasonable solution, and the best one that I know of.

The proposed fix requires an additional 4 byte variable. It uses the millisecond counter for protection, and retains the microsecond counter for the while loop.

I realize that data space in SRAM is precious. The need for an additional variable can be eliminated by using the existing resumeTime variable with its microsecond value. However, the roll over cycle of the microsecond timer is 4295 seconds, or about 1.2 hours. If the microsecond counter rolls multiple times before the call to print the next character then an erroneous wait will occur if the call is made within 10 seconds of the resume time. On a random basis, the probability of hitting the "error window" is 10 seconds in the roll over cycle, or about 0.2%. Using an additional variable and the millisecond counter instead of the microsecond counter reduces the chance of hitting the window by 3 orders of magnitude, or to about 0.0002%. Therefore, I think that using the millisecond counter is the better solution and the additional variable is an acceptable cost.

Another, and slightly simpler code solution that crossed my mind is to round the required delay time to up to the nearest millisecond and then use the millisecond timer in the while loop. This eliminates the added "if" logic of the proposed fix. But this simple technique suffers from the same problem as the existing code of running the while loop at times when it should not be run at all. And worse, if you happen to hit the "error window", then the while loop can run for days. I therefore rejected this solution.

I have tested the proposed fix in my thermostat application. Before the fix I encountered the error in 28 of 192 heat cycles over 7 days. After the fix, there were 0 errors in 110 heat cycles over 7 days (the weather was warmer so there were fewer heat cycles).

How does one go about getting a fix reviewed and adopted into the officially released library?

I have an additional suggestion for this library. The printer's test page shows an example of printing using "font B", which prints 42 characters per line. The implicit font A prints 32 characters per line. However, there are no helper methods for setting either font A or font B. It required forum queries to determine how to set font B. I have included below a suggestion for helper methods called setFontA and setFontB. I have tested both with my thermal printer, and I think that they should be included in the Adafruit Thermal Printer library.

The code below shows the updated methods in the cpp file of the library. This also requires the inclusion of <limits.h> in the header file (for the ULONG_MAX value).

Code: Select all | TOGGLE FULL SIZE
// This method sets the estimated completion time for a just-issued task.
void Adafruit_Thermal::timeoutSet(unsigned long x) {
  if(!dtrEnabled) {
    resumeTimeMs = millis() + (x / 1000);
    resumeTime   = micros() +  x;
    }
  }

// This function waits (if necessary) for the prior task to complete.
#define MAX_CHAR_WAIT 10000
void Adafruit_Thermal::timeoutWait() {
  if(dtrEnabled) {
    while(digitalRead(dtrPin) == HIGH);
  } else {
    boolean doWait = false;
    if (resumeTimeMs > millis()) {             
      if (resumeTimeMs - millis() < MAX_CHAR_WAIT) {
        doWait = true;
        }
      }
    else {
      if (ULONG_MAX - millis() + resumeTimeMs < 10000) {
        doWait = true;
        }
      }
    if (doWait) {
      while((long)(micros() - resumeTime) < 0L); // (syntax is rollover-proof)
      }
    }
  } // end of timeoutWait function


void Adafruit_Thermal::setFontA() {
  writeBytes(ASCII_ESC, '!', 0x00);
}

void Adafruit_Thermal::setFontB() {
  writeBytes(ASCII_ESC, '!', 0x01);
}


cdj
 
Posts: 19
Joined: Mon Oct 24, 2016 3:44 pm

Re: Timing bug in Adafruit thermal printer library

by adafruit2 on Thu Feb 16, 2017 3:49 pm

cool! can you submit a short/concise/clear issue to the github repo - or better yet a simple pull req? a tested pull req will get the issue fixed fastest :)

https://github.com/adafruit/Adafruit-Th ... er-Library

adafruit2
Site Admin
 
Posts: 18659
Joined: Fri Mar 11, 2005 7:36 pm

Re: Timing bug in Adafruit thermal printer library

by Palliser on Fri Sep 13, 2019 4:19 pm

Hello cdj.
I am interested to know if your fix for this timing bug finally alleviated this problem and worked out in your thermostat project. Also, I noticed that up to date no changes have been implemented (updated) in the Adafruit thermal printer library.

Regards,
Wilfredo
Palliser
 
Posts: 3
Joined: Sat Aug 31, 2013 11:26 am

Re: Timing bug in Adafruit thermal printer library

by cdj on Fri Sep 13, 2019 9:45 pm

Hello Wilfredo,

You asked if my proposed fix to the adafruit thermal printer library alleviated the timing problem that I discovered in this library.

The answer is unequivocally YES IT DID.

I didn't elaborate too much in the posting about my background work. I wrote a test program that demonstrated the problem. Because the test program was designed to show the problem, it did, and as expected, it failed 100% of the time. I implemented the fix and then ran the test program and demonstrated for myself that it failed 0% of the time.

Prior to implementing the fix in my thermostat application I recorded the failures over a period of a week, as noted in the posting. I then implemented the fix and recorded the failures over another week. As noted in the posting, and as I expected due to the testing mentioned above, there were zero failures.

I am disappointed to hear that the fix has not been integrated into the adafruit library. My first interaction was with Adafruit. They asked me to submit certain materials to github to describe the problem and the fix, which I did. I was told at the time that the fix would be reviewed and eventually incorporated into the library.

I have been using this fix since I developed it. My most mission critical application is the thermostat, which continues to control the heat in my house. The fix eliminated the outrageous "30 minute delay getting heat" problem that occurred before the fix.

I typically develop an Arduino application on my laptop. I often use the thermal printer for debug output so that I don't have to dedicate my laptop to the Arduino serial port output. Although it depends on the application, it is common that debug output might only occur every hour or so. In these cases, the thermal printer timing bug could cause a serious delayed output problem. I am happy to say that those problems don't exist with the updated library.

Once I understood the problem I considered several ways that the problem could be fixed. I attempted to discuss the pros and cons of the various choices in the posting. While some readers may see this extra verbiage as "too much information" I decided to include it to "justify" the proposed fix as the best of various alternatives. I am very conscious of the storage limitations of the Arduino. My thinking was that a few lines of code (bytes in the code space memory) and 4 bytes of data storage (bytes in the data space memory) were a reasonable price to pay for the fix.

Charles Johnson
Boulder, Colorado

cdj
 
Posts: 19
Joined: Mon Oct 24, 2016 3:44 pm

Re: Timing bug in Adafruit thermal printer library

by adafruit2 on Sun Sep 15, 2019 7:25 pm

hiya - did you submit an issue to github? its been 2 yrs since the last post, we dont see it here, but maybe its somewhere else :)
https://github.com/adafruit/Adafruit-Th ... ary/issues
https://github.com/adafruit/Adafruit-Th ... rary/pulls
let us know!

adafruit2
Site Admin
 
Posts: 18659
Joined: Fri Mar 11, 2005 7:36 pm

Please be positive and constructive with your questions and comments.