Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Q] Random pauses or hesitation when printing. #2761

Closed
V1EngineeringInc opened this issue Apr 6, 2023 · 135 comments · Fixed by #2827
Closed

[Q] Random pauses or hesitation when printing. #2761

V1EngineeringInc opened this issue Apr 6, 2023 · 135 comments · Fixed by #2827
Labels
question Further information is requested

Comments

@V1EngineeringInc
Copy link

While printing once or twice a print, sometimes more, the machine will stop right in the middle of printing for a second, maybe even two. No errors or anything, it leaves an ugly blob, and it just continues on. It does not happen the same place on the file or on the machine. If I had to say anything, it might happen more often during circle moves, or curves. This does not happen while using the same screens for my CNC machines.

I have 6 printers and 2 CNC's running TFT35 V3 E3 screens. I have noticed this issue for probably as long as I have used the screens, more than two years I would guess. Some screens are brand new and some are very old. I update marlin and the TFT several times a year. Some of my gcode is old and ran perfectly fine on older 1286 screens, and some of my files are new.

So I think this is either some sort of configuration issue, slicer setting, or a screen firmware bug. Any ideas?

Config,
config.zip

@V1EngineeringInc V1EngineeringInc added the question Further information is requested label Apr 6, 2023
@V1EngineeringInc
Copy link
Author

Is there any sort of debugging I can run, check the buffer of the screen, or anything else that might help?

@radek8
Copy link
Contributor

radek8 commented Apr 7, 2023

Can you try recompiling marli with these values?
#define BLOCK_BUFFER_SIZE 16
#define MAX_CMD_SIZE 96
#define BUFSIZE 16
#define TX_BUFFER_SIZE 32
#define RX_BUFFER_SIZE 32

@V1EngineeringInc
Copy link
Author

Thanks I will try that.

#define BLOCK_BUFFER_SIZE 16
#define MAX_CMD_SIZE 96

Those are default values.

I will change the others. Is this in the documentation anywhere, seems like it kind of should be?

@kisslorand
Copy link
Contributor

I would also check the slicer for something like "Maximum Resolution" and/or "Maximum Deviation" and raise them a little. I do not know what slicer you're using, the parameters mentioned are from Cura. I remember the days when I was using Octoprint with an 8 bit mainboard printer and I had a lot of blobs on curved surfaces. Changing the values of these settings mitigated the issue.
By now I use ARC Welder so there's no issue whatsoever having tiny minuscule segments for curved lines. In fact the problem also went away on my 8 bit board using ARC Welder plugin in Octoprint.

@V1EngineeringInc
Copy link
Author

I am using a SKR Pro, and Simplify3D I can reduce the segments. Thanks for the tips.

Seems a bit off to me that it works fine on a rambo (8bit) with a 1286 screen, but the same Gcode only hesitates on the 32 bit board and TFT.

@V1EngineeringInc
Copy link
Author

Waiting for this print to finish before I change the firmware for the memory tweaks. I just watched it happen again. It happened on an outline (90% speed) that was a long 4" straight line and just as it hit the corner it paused before the curves.... So not printing fast, buffer should have easily been full, hmm.

This is really puzzling to me. Neither of you have seen your printers hesitate?

@kisslorand
Copy link
Contributor

kisslorand commented Apr 7, 2023

I totally forgot about this issue since this TFT FW and 32 bits mainboard (and using ARC Welder).
Just for science... try Cura with ARC... :)

On the other hand this TFT FW has a major setback, it sends every command only after receiving "OK" from the mainboard from the previous command. I am contemplating for a while to integrate "Advanced OK" (it allows filling the mainboard's buffer with commands, not send them one by one), but giving the lack of interest from BTT towards this repository I do not feel comfortable wasting my time for nothing. It seems even the free work of the contributors is too expensive for them...

I do not want to spoil the game but I do not think the suggestions of @radek8 will help because of the aforementioned reasons.
I can only hope I'm wrong... :)

@V1EngineeringInc
Copy link
Author

I hear you. I have sold these screens for a while now but I only sold them to use the Marlin side. You made it so the TFT was even reliable. I really hope they give this some more attention, if not I think I will be switching out to ESP3D control direct from the board and skip the screen all together. It is a bummer though I think these screens have huge potential. They need to be more receptive to some changes, stability and customizations.

I appreciate the help I get here though. I have always received sincere help.

(testing the mem changes now, just need to hang out near the printer to see if I can catch some hesitations)

@ETE-Design
Copy link

I totally forgot about this issue since this TFT FW and 32 bits mainboard (and using ARC Welder). Just for science... try Cura with ARC... :)

On the other hand this TFT FW has a major setback, it sends every command only after receiving "OK" from the mainboard from the previous command. I am contemplating for a while to integrate "Advanced OK" (it allows filling the mainboard's buffer with commands, not send them one by one), but giving the lack of interest from BTT towards this repository I do not feel comfortable wasting my time for nothing. It seems even the free work of the contributors is too expensive for them...

I do not want to spoil the game but I do not think the suggestions of @radek8 will help because of the aforementioned reasons. I can only hope I'm wrong... :)

I often tell BTT to merge new PR's but they are really slow at it, I even asked them to hand over the merge process to a person who develop on this but with no luck :-(
Would really love if you could find time to integrate Advanced OK to this Firmware... I know that BTT lack interest of firmware cause they don't make money on it, but I think a lot of us users really like all the work you guys put into this.

/ETE-Design

@V1EngineeringInc
Copy link
Author

I could try and ask my BTT rep to get something looked at or pushed to the front of the list if we had something specific. I have no idea if it would do anything but I could try. Maybe, just maybe, having the request come from two sides would help.

@ETE-Design
Copy link

I could try and ask my BTT rep to get something looked at or pushed to the front of the list if we had something specific. I have no idea if it would do anything but I could try. Maybe, just maybe, having the request come from two sides would help.

There is already a lot of PR who need to be merged, most of then seem to be things who need to be merged

@V1EngineeringInc
Copy link
Author

So I think those memory changes worked. I have been kinda busy but floating around one of the printers all day and I have not caught a single hesitation!!!

Should I (or one of us) add this to the firmware changes section of the INI file?

@kisslorand
Copy link
Contributor

Just another thought...
Do you have PLR (Power Loss Recovery) enabled on your TFTs? Writing speed is much slower than reading speed, printing high poly surfaces can exhaust the buffer pretty quick and it might be happening right when PLR checkpoints are written to SD or USB so the printer makes a slight pause thus creating blobs.
Maybe it worth checking this too.

@V1EngineeringInc
Copy link
Author

No, No power loss recovery. Good idea though.

@ETE-Design
Copy link

So seems like it helped I written to BTT again over messenger... A lot of PR got merged now 😀
@kisslorand Hope you still will consider making Advanced OK for this TFT 😀

@kisslorand
Copy link
Contributor

@ETE-Design

@kisslorand Hope you still will consider making Advanced OK for this TFT 😀

Sure.

@rondlh
Copy link

rondlh commented Apr 14, 2023

I also noticed some stuttering. My buffers are setup even larger than suggested. I use a serial baud rate of 1M bit. Arc welder could possibly help, I will give it a try.
Support for ADVANCED_OK would be amazing, but seems like a big project.

@slwise
Copy link

slwise commented Apr 15, 2023

A friend and I were both running a SKR Mini E3 V3 with the TFT35 V3 E3. We were both experiencing the same issue you described with pausing and blobs in the print. I changed the buffer size in Marlin to 64 but no change. I also increased the baud rate from 115200 to 250000, still no change. I finally fixed the issue on both printers by lowering the baud rate to 57600. We've been running this way for months with no issues. My best guess is apparently 115200 was too fast for the SKR to handle and causing the TFT to have to retransmit the data. Hope this helps.

@V1EngineeringInc
Copy link
Author

Interesting, I need to try that. As well, I think I caught another hesitation with the memory tweaks, but I am not sure. It is definitely happening much much less. I am set to 250000....

@digant73
Copy link
Contributor

digant73 commented Apr 17, 2023

A friend and I were both running a SKR Mini E3 V3 with the TFT35 V3 E3. We were both experiencing the same issue you described with pausing and blobs in the print. I changed the buffer size in Marlin to 64 but no change. I also increased the baud rate from 115200 to 250000, still no change. I finally fixed the issue on both printers by lowering the baud rate to 57600. We've been running this way for months with no issues. My best guess is apparently 115200 was too fast for the SKR to handle and causing the TFT to have to retransmit the data. Hope this helps.

TFT simply sends a gcode when the printer's FW (Marlin etc...) acknowledges the gcode previously sent by TFT. There is no retransmission from TFT. The issue seems to be in Marlin (probably related to buffers and/or connection speed). Ironically, some speed improvements made on TFT fw triggered this issue on some printer's fw with an unbalanced setup

@V1EngineeringInc
Copy link
Author

I still have not gotten to testing the Baud rate change. I can now confirm the memory changes did not fix it. It might be slightly better but my printers still hesitate randomly.

I will test the Baud rate after RMRRF.

@africsnail
Copy link

africsnail commented Apr 30, 2023

I also have a similar issue after updating my board's (SKR Mini E3 V3) fw to Marlin 2.1 (previously I had 2.0 and I had no problems). I also made sure to update the TFT35. Now it seems to have some kind of mess ups with the gcode being corrupted (like a missing or additional character in a command) or it just pauses randomly as described here. I tried many different buffer sizes and neither of them worked.

I am going to try the lower baudrate as mentioned here. I was running at the default 115200.

Edit: It didn't help. Also the problem may be just caused by me not trying to print as fast before. I was playing around with input shaping so I was trying faster speeds after the update.

@kisslorand
Copy link
Contributor

@kisslorand Hope you still will consider making Advanced OK for this TFT 😀

I just remembered why I haven't got working on "Advanced OK". There's a bug on SKR and SKR Mini motherboards (there might be others affected too), a bug that can be avoided only if commands are sent one by one, so "Advanced OK" would be a disaster on these motherboards. I saw the issue came up a while ago on the Marlin repo but there is no sign of anyone working on a solution.

@ETE-Design
Copy link

@kisslorand Hope you still will consider making Advanced OK for this TFT 😀

I just remembered why I haven't got working on "Advanced OK". There's a bug on SKR and SKR Mini motherboards (there might be others affected too), a bug that can be avoided only if commands are sent one by one, so "Advanced OK" would be a disaster on these motherboards. I saw the issue came up a while ago on the Marlin repo but there is no sign of anyone working on a solution.

And how about all other boards that isen't SKR-Series? 😀
Is it not just to make a Note in the first part of Config.ini to tell people not to activate it if they have SKR-Series Boards?

@kisslorand
Copy link
Contributor

Each configuration that has to be taken into account during printing slows down the sending of the gcodes which itself defeats the advantages of the Advanced OK.

@ETE-Design
Copy link

ETE-Design commented May 5, 2023

Each configuration that has to be taken into account during printing slows down the sending of the gcodes which itself defeats the advantages of the Advanced OK.

@kisslorand Think you misunderstood me, make a note in the top of Config.ini like:

"# Advanced_OK (in Configuration_adv.h) - Issue with SKR-Series"

That shouldn't slow down sending of gcodes?

@rondlh
Copy link

rondlh commented May 5, 2023

A friend and I were both running a SKR Mini E3 V3 with the TFT35 V3 E3. We were both experiencing the same issue you described with pausing and blobs in the print. I changed the buffer size in Marlin to 64 but no change. I also increased the baud rate from 115200 to 250000, still no change. I finally fixed the issue on both printers by lowering the baud rate to 57600. We've been running this way for months with no issues. My best guess is apparently 115200 was too fast for the SKR to handle and causing the TFT to have to retransmit the data. Hope this helps.

Interesting, but serial communication is handled in hardware, not in software. The software will get a signal when a command is received completely ('\n' at the end. Then it's up to the processor to handle the command.). I personally run all serial communication at 1M bit. If a command is 40 characters long then it will take at least 10 * 40 / 57600 seconds (=7ms) to transmit. As long as you don't have data corruption I do not see any disadvantage on running the serial lines faster.

@kisslorand
Copy link
Contributor

@kisslorand Think you misunderstood me, make a note in the top of Config.ini like:

"# Advanced_OK (in Configuration_adv.h) - Issue with SKR-Series"

I might have misunderstood you but the issue remains. If Advanced OK is implemented, it should be configurable (enabled/disabled) because of the problematic motherboards. If it's configurable than it adds latency in preparing the gcodes to be sent during printing which defeats the purpose of Advanced OK. The added latency will surely hurt at least the problematic motherboards, they will not benefit the advantages of Advanced OK but will be burdened by this extra latency.
Also for other motherboards I have no way to estimate if the added latency will be less of a problem than the benefits of the Advanced OK. I keep wondering why Gina didn't add Advanced OK to Octoprint, knowing that the Raspberry Pi's MCU is much more powerful than the ones we have in our TFTs.

Only real tests can answer the dilemma, but I do not feel comfortable working huge number of hours for possible negative results, not to mention that a particular user will rip my head off accusing me I made another "useless, stupid, not necessary, full of bugs" modification to this firmware when "everything was working perfectly".

@digant73
Copy link
Contributor

digant73 commented Aug 21, 2023

OK, I will have a look at the comments....

I just noticed a bunch of errors in the DMA register configuration, do you see what I mean?

  cfg->dma_stream->CR |= 3<<16;  // Priority level: Very high
  cfg->dma_stream->CR |= 0<<13;  // Memory data size: 8
  cfg->dma_stream->CR |= 0<<11;  // Peripheral data size: 8
  cfg->dma_stream->CR |= 1<<10;  // Memory increment mode
  cfg->dma_stream->CR |= 0<<9;   // Peripheral not increment mode
  cfg->dma_stream->CR |= 1<<8;   // Circular mode enabled
  cfg->dma_stream->CR |= 0<<6;   // Data transfer direction: Peripheral-to-memory
  cfg->dma_stream->CR |= 1<<0;   // Enable DMA

The 2nd, 3rd, 5th and 7th command do absolutely nothing. It should be "&= ~(1" or "&= ~(3". Some bits should be cleared in these lines.

There are a lot of such kind of lines in the project. They are place holders just to cover the meaning of all bits even if not affecting the value (as you can see comments are also provided). So this is not an issue or something to change.
Anyway, I just committed another update for the comments in config.ini. They should be OK now.

@rondlh
Copy link

rondlh commented Aug 21, 2023

There are a lot of such kind of lines in the project. They are place holders just to cover the meaning of all bits even if not affecting the value (as you can see comments are also provided).

OK, I understand, so I guess the additional "Serial[port].uart->SR;" in the serial interrupt routines are also just placeholders.

To me it seems that a better placeholder for:
cfg->dma_stream->CR |= 0<<13; // Memory data size: 8
would be:
cfg->dma_stream->CR &= ~(3<<13); // Memory data size: 8

It shows that the bits need to be cleared, and that there are actually 2 bits that need to be set, not just 1.

@rondlh
Copy link

rondlh commented Aug 21, 2023

I just committed another update for the comments in config.ini. They should be OK now.

The comments seem quite clear to me, good job!

One more thing just came to mind.
If you set Marlin's tx_slots to 4, then the maximum number of available command slots it will ever report is 3. Just try a G91 or so, it should respond with something like "ok P16 B3", in the Marlin code you can see why this is (the ADVANCED_OK message is the last thing the that is done for a specific command, just before the command is freed.). This actually provides a little bit of extra safety margin...

@kisslorand
Copy link
Contributor

kisslorand commented Aug 21, 2023

I'm stationed in China.

@rondlh
In the next couple of weeks I'll be in Shanghai, Xi'an, Hangzhou. If you are anywhere nearby we can get a coup of coffee.

@rondlh
Copy link

rondlh commented Aug 22, 2023

I'm stationed in China.

@rondlh In the next couple of weeks I'll be in Shanghai, Xi'an, Hangzhou. If you are anywhere nearby we can get a coup of coffee.

What are you doing there? I'm in Guangzhou, south China.

@kisslorand
Copy link
Contributor

What are you doing there?

On vacation with my wife and kid.

I'm in Guangzhou, south China.

I've been there in 2009. I stood in Shamiandao Island, quite a nice place!

Maybe you can take the weekend off and come to Hangzhou. On the 2nd of September we're going to watch again "Romance of Song dynasty" show in the "Song dynasty park". It's a must! I've seen it in 2015.

@rondlh
Copy link

rondlh commented Aug 22, 2023

I will be in the Netherlands at that time to watch some F1.
But back on topic, you also put some effort in solving the hesitation issues, I tested your FW extensively, and that looked good. What approach did you use?
I'm currently trying to get serial writing handled by DMA, which should significantly increase the performance of the TFT. I got it working partially (communication from mobo to TFT to ESP3D works, but the other way around doesn't.

@rondlh
Copy link

rondlh commented Aug 22, 2023

@digant73
I gave some TLC to Serial_Get, if you do things like this then you can completely drop the (hardware dependent) interrupt setup and interrupt routines, and you have the added advantage that you always have the current buffer status and don't have to wait until the serial line goes idle before the data becomes available.

Serial.c

uint16_t Get_wIndex(int port) 
{
  return dmaL1Data[port].cacheSize - Serial[port].dma_stream->NDTR;
}

SerialConnection.c

uint16_t Serial_Get(SERIAL_PORT_INDEX portIndex, char * buf, uint16_t bufSize)
{
  if (!WITHIN(portIndex, PORT_1, SERIAL_PORT_COUNT - 1))
    return 0; // exit if port index is out of range
 
  dmaL1Data[portIndex].wIndex = Get_wIndex(portIndex) ; // update wIndex, DMA is reading and storing serial data in the background

  if (!Serial_Available(portIndex)) // is there any data to process?
    return 0;

  uint16_t wIndex    = dmaL1Data[portIndex].wIndex;
  uint16_t rIndex    = dmaL1Data[portIndex].rIndex;
  uint16_t cacheSize = dmaL1Data[portIndex].cacheSize;

  while (dmaL1Data[portIndex].cache[rIndex] == ' ' && rIndex != wIndex)  // remove leading empty space, if any
    rIndex = (rIndex + 1) % cacheSize;

  for (uint16_t i = 0; i < (bufSize - 1) && rIndex != wIndex; i++)  // retrieve data until buf is full, or L1 cache is empty, or command complete '\n'
  {
    buf[i] = dmaL1Data[portIndex].cache[rIndex];
    rIndex = (rIndex + 1) % cacheSize;

    if (buf[i] == '\n')  // if data end marker is found
    {
      buf[i + 1] = '\0';                     // add end of string character
      dmaL1Data[portIndex].rIndex = rIndex;  // update queue's read index

      return i + 1;  // return the number of bytes stored in buf
    }
  }

  return 0;  // return the number of bytes stored in buf
}

@digant73
Copy link
Contributor

digant73 commented Aug 22, 2023

@digant73 I gave some TLC to Serial_Get, if you do things like this then you can completely drop the (hardware dependent) interrupt setup and interrupt routines, and you have the added advantage that you always have the current buffer status and don't have to wait until the serial line goes idle before the data becomes available.

Serial.c

uint16_t Get_wIndex(int port) 
{
  return dmaL1Data[port].cacheSize - Serial[port].dma_stream->NDTR;
}

SerialConnection.c

uint16_t Serial_Get(SERIAL_PORT_INDEX portIndex, char * buf, uint16_t bufSize)
{
  if (!WITHIN(portIndex, PORT_1, SERIAL_PORT_COUNT - 1))
    return 0; // exit if port index is out of range
 
  dmaL1Data[portIndex].wIndex = Get_wIndex(portIndex) ; // update wIndex, DMA is reading and storing serial data in the background

  if (!Serial_Available(portIndex)) // is there any data to process?
    return 0;

  uint16_t wIndex    = dmaL1Data[portIndex].wIndex;
  uint16_t rIndex    = dmaL1Data[portIndex].rIndex;
  uint16_t cacheSize = dmaL1Data[portIndex].cacheSize;

  while (dmaL1Data[portIndex].cache[rIndex] == ' ' && rIndex != wIndex)  // remove leading empty space, if any
    rIndex = (rIndex + 1) % cacheSize;

  for (uint16_t i = 0; i < (bufSize - 1) && rIndex != wIndex; i++)  // retrieve data until buf is full, or L1 cache is empty, or command complete '\n'
  {
    buf[i] = dmaL1Data[portIndex].cache[rIndex];
    rIndex = (rIndex + 1) % cacheSize;

    if (buf[i] == '\n')  // if data end marker is found
    {
      buf[i + 1] = '\0';                     // add end of string character
      dmaL1Data[portIndex].rIndex = rIndex;  // update queue's read index

      return i + 1;  // return the number of bytes stored in buf
    }
  }

  return 0;  // return the number of bytes stored in buf
}

I don't think this is a better solution.
If USART_IRQHandler is invoked when ​serial line goes idle it also means that the idle is between full messages terminated by \n most of the time (e.g. first_msg\nidlesecond_msg\nidlethird_msg\nidleforthidle_msg\nidle). If so, USART_IRQHandler will set wIndex to the end of a full message most of the time and Serial_Get will also retrieve a full message most of the time.
With your change, Serial_Get will most of the time retrieve partial messages (in particular in faster TFT where Serial_Get is invoked more often per second)

NOTE: with advanced_ok (real or static with tx_slots > 1) the spontaneous message handling (see at the end of parseAck.c) is not properly handled yet (they relies on condition infoHost.wait == false). Consider this limitation in case you are also testing the code from a remote host (OctoPrint, ESP3D etc...).

@rondlh
Copy link

rondlh commented Aug 22, 2023

If USART_IRQHandler is invoked when ​serial line goes idle it also means that the idle is between full messages terminated by \n most of the time (e.g. first_msg\nidlesecond_msg\nidlethird_msg\nidleforthidle_msg\nidle). If so, USART_IRQHandler will set wIndex to the end of a full message most of the time and Serial_Get will also retrieve a full message most of the time.
With your change, Serial_Get will most of the time retrieve partial messages (in particular in faster TFT where Serial_Get is invoked more often per second)

You are correct, certainly the chance that to process a partial message is bigger in this case, but the message response will be faster because the idle status is always delayed by 1 serial character, and if there is no idle between messages then you will have to wait for the second message to be completely received before it has a chance to be processed, like for example when a "ok" message is followed by a temperature report. Also with long message (response M43 etc.) you have no idle in the response causing a buffer overrun. In this proposal you can start processing message as soon as a complete message is received.
If you worry about incomplete messages being processed then you can also raise the requirements to having at least 3 bytes available before scanning the message or you can remember how many characters you have already scanned, or you can start with checking if a message is complete before going in further. Checking an incomplete message doesn't take much time anyway because the messages are short. I can benchmark it if you want to give it some thoughts. And dropping hardware dependent code and interrupt routines is a win in my book anytime.

Update: I just benchmarked the above code to get some more insight into what practically happens. @digant73 is right, there are far more scans of incomplete messages, and most of the time the idle interrupt gives a complete message. I can see that sometimes there is more data in the buffer than is reported by the idle interrupt, but this happens mostly for temperature reports. Even with this faster scanning code a buffer underrun after a M43 cannot be prevented, that is perhaps caused by the lack of a serial write buffer (message is forwarded to ESP3D). I believe the lack of a serial write buffer is probably the biggest remaining bottleneck, currently the TFT has to wait until every single serial byte is written before the program can continue, and there is a lot of writing going on.

NOTE: with advanced_ok (real or static with tx_slots > 1) the spontaneous message handling (see at the end of parseAck.c) is not properly handled yet (they relies on condition infoHost.wait == false). Consider this limitation in case you are also testing the code from a remote host (OctoPrint, ESP3D etc...).

I'm aware if this, I use an ESP3D, and I always commented out the rx_ok check because I want these messages forwarded so I can monitor the printer temps etc. I don't see any issues with that, also OctaPrint can handle this

@digant73
Copy link
Contributor

digant73 commented Aug 22, 2023

pretty much sure that ok message and temp report (or any other standalone message) will be interleaved by an idle (they are processed by mainboard separately. Yes, for long messages with many \n such as the reply to M43, M420 V1 T1 you have to wait the complete message is received but it doesn't change so much (e.g. Mesh Editor reads every report line when available but waits for the entire message is complete before displaying the received information).. I should not consider commands potentially causing buffer overruns (this is not the case during printing; no real gcode causing long message reply). When the TFT is on idle (not printing) we cannot avoid at 100% the possibility of buffer overruns with some debug gcodes (if the rx buffer size is minor than the received information there is not so much we can do).
Serial_Get is also used to read from supplementary serial ports so the solution avoiding to read an incomplete messages is welcome and has to be implemented (think to the case where you read incomplete messages from all serial ports; the TFT will waste all the time on Serial_Get function). With the current solution, the multiple read of incomplete message is limited to only the last fragment (not yet terminated by \n).

Of course there are many possible solutions to avoid multiple read of the same incomplete message. One light solution can make use of a new lastWIndex variable for each serial ports such as:

// if port index is out of range or no data to read from L1 cache
if (!WITHIN(portIndex, PORT_1, SERIAL_PORT_COUNT - 1) || dmaL1Data[portIndex].lastWndex == dmaL1Data[portIndex].wIndex)
  return 0;

....

// if here, a partial message is present on the L1 cache (message not terminated by "\n").
// We temporary skip the message until it is fully received

dmaL1Data[portIndex].lastWndex = dmaL1Data[portIndex].wIndex

With this code a partial message will be read only one time until wIndex is updated by the interrupt handler (wIndex is probably updated to the end of the message or the new fragment will contain \n allowing Serial_Get to retrieve the next full message)

I'm aware if this, I use an ESP3D, and I always commented out the rx_ok check because I want these messages forwarded so I can monitor the printer temps etc. I don't see any issues with that, also OctaPrint can handle this

Do you mean you replaced:

if (infoHost.wait == false && !ack_starts_with("ok"))

with

if (!ack_starts_with("ok"))

?

@rondlh
Copy link

rondlh commented Aug 22, 2023

I don't see a big problem in processing incomplete messages. I did several prints with the code above that processes the available data as soon as anything is available, it doesn't cause any problems. The messages are short anyway, we are mostly talking about "ok P16 B3" or shorter.

Do you mean you replaced:
if (infoHost.wait == false && !ack_starts_with("ok"))
with
if (!ack_starts_with("ok"))

Yes, I have done that for years now. This way I can monitor what is going on via the ESP3D, and the ESP3D doesn't need to send additional message to get a report that is already automatically created.

@digant73
Copy link
Contributor

digant73 commented Aug 22, 2023

I don't see a big problem in processing incomplete messages. I did several prints with the code above that processes the available data as soon as anything is available, it doesn't cause any problems. The messages are short anyway, we are mostly taking about "ok P16 B3" or shorter.

Yes this is on Printer->TFT side where the TFT is the client receiving small reply from the server (printer).
But on ESP3D->TFT side the TFT is the server receiving bigger commands.

Anyway I just made the small improvement in the code (added a flag). I will push the change in minutes. Eventually you could use that updated code for testing (not essential to test advanced ok or print hesitation issue).

@rondlh
Copy link

rondlh commented Aug 23, 2023

@digant73 wIndex should be declared "volatile" (serial.h) this is potentially a cause of the hesitations (probably not).

I implemented a simple buffered serial write algorithm and did some test (based on the 2023-06-05 code base, rx_ok bug fixed, but without the flag optimization).
The algorithm will first store outgoing data into a buffer and then starts sending it in the background (interrupt based), so the serial write is not blocking anymore, unless you run out of serial write buffer space of course.
When not busy my TFT (BTT TFT35 V3, STM32F207 120MHz) can scan incoming data about 35.000x per second. I did some test with low baudrate 57600/115200 baud (lower baudrate benefit most from buffering). When printing fast (I stress the printer on purpose) the scan rate can drop to as low as 100 scans per seconds. Still not bad, but losing 10ms response time is not needed. With 128 bytes serial write buffer the scan rate stays at around 35.000 scans per second. The whole implementation is only a few lines of code, but is unfortunately hardware dependent (interrupts). I think this is a worthwhile addition.

@digant73
Copy link
Contributor

digant73 commented Aug 23, 2023

@digant73 wIndex should be declared "volatile" (serial.h) this is potentially a cause of the hesitations (probably not).

I implemented a simple buffered serial write algorithm and did some test (based on the 2023-06-05 code base, rx_ok bug fixed, but without the flag optimization). The algorithm will first store outgoing data into a buffer and then starts sending it in the background (interrupt based), so the serial write is not blocking anymore, unless you run out of serial write buffer space of course. When not busy my TFT (BTT TFT35 V3, STM32F207 120MHz) can scan incoming data about 35.000x per second. I did some test with low baudrate 57600/115200 baud (lower baudrate benefit most from buffering). When printing fast (I stress the printer on purpose) the scan rate can drop to as low as 100 scans per seconds. Still not bad, but losing 10ms response time is not needed. With 128 bytes serial write buffer the scan rate stays at around 35.000 scans per second. The whole implementation is only a few lines of code, but is unfortunately hardware dependent (interrupts). I think this is a worthwhile addition.

Not necessary to declare wIndex as volatile.
Just created the PR fixing only this bug report (major issue for users due to impact on print quality).
Improvement on writing to serial is welcome but must be provided on a next PR when fully tested.
Making some changes on ADVANCED_OK PR. I will commit the changes when tested.

@rondlh
Copy link

rondlh commented Aug 23, 2023

Not necessary to declare wIndex as volatile.

Please explain...
wIndex is changed in an interrupt so the wise thing to do is to declare it volatile to get predictable results, I agree that it is not likely to cause issues, it's just good programming practice in my view.

@digant73
Copy link
Contributor

digant73 commented Aug 23, 2023

Not necessary to declare wIndex as volatile.

Please explain... wIndex is changed in an interrupt so the wise thing to do is to declare it volatile to get predictable results, I agree that it is not likely to cause issues, it's just good programming practice in my view.

I don't think it's a multithread application. Main thread get the control once the interrupt handler terminates. Even if the application is multithread, it doesn't change too much (Serial_Get will take a snapshot of wIndex while it could be changed by the interrupt handler if invoked in the meanwhile.).

EDIT: your explanation is correct although if it was the case the effects will be very evident. I will define it as volatile just as precaution.

@rondlh
Copy link

rondlh commented Aug 23, 2023

I don't think it's a multithread application. Main thread get the control once the interrupt handler terminates. Even if the application is multithread, it doesn't change too much (Serial_Get will take a snapshot of wIndex while it could be changed by the interrupt handler if invoked in the meanwhile.)

Sure, the FW is not multi-threaded, and there is only a single MCU, but that's not what a volatile variable is about.
A volatile variable makes sure that current (correct) value of a variable is used, and not an outdated value from cache or previously read value. It makes sure that compiler optimizations don't cause issues and the program stays reliable and predictable.

@rondlh
Copy link

rondlh commented Aug 23, 2023

@digant73 First of all, thank you for the great job you have done, these are great improvements, this hesitation bug has bugged me for years, and ADVANCED_OK is a great feature, this a big improvement in my view, excellent job!
I hope we can get your PR merged asap, I'm not sure how to push this forwards...

I just had a look at the new Serial_Get with the flag improvement, that is very smart. It helps against scanning the same uncompleted message again and again, and makes the whole (hardware dependent) serial Idle interrupt obsolete, it could be replaced with the Get_wIndex, so the incoming lines can be processed immediately when they are complete, which helps against buffer overruns.

Not convinced? Here something interesting, can you find the differences?

M43 (Based on IDLE interrupt, buffer overun!)(128 bytes serial write buffer, DMA based, ESP3D captured)
START OF MESSAGE 1 ========================================
_SCK Output HIGH
PIN: PE13 M42 P77 TMC_SPI_MISO Input HIGH
PIN: PE14 M42 P78 TMC_SPI_MOSI Output LOW
PIN: PE15 M42 P79 <unused/unknown> Output HIGH
PIN: PH0 M42 P80 Input LOW
PIN: PH1 M42 P81 Input LOW
END OF MESSAGE 1 ========================================

M43 (Based on updating wIndex in Serial_Get) (128 bytes serial write buffer, DMA based, ESP3D captured)
START OF MESSAGE 2 ========================================
PIN: PA0 (A0) M42 P0 CONTROLLER_FAN_PIN protected
PIN: PA1 (A1) M42 P1 FAN1_PIN protected
. E0_AUTO_FAN_PIN protected
PIN: PA2 (A2) M42 P2 FAN0_PIN protected
PIN: PA3 (A3) M42 P3 <unused/unknown> Input LOW
PIN: PA4 (A4) M42 P4 Input LOW
PIN: PA5 (A5) M42 P5 Alt Function: 5 - SPI1/SPI2
PIN: PA6 (A6) M42 P6 Alt Function: 5 - SPI1/SPI2
PIN: PA7 (A7) M42 P7 Alt Function: 5 - SPI1/SPI2
PIN: PA8 M42 P8 SERVO0_PIN Output LOW
PIN: PA9 M42 P9 Alt Function: 7 - USART1..3
PIN: PA10 M42 P10 Alt Function: 7 - USART1..3
PIN: PA11 M42 P11 Alt Function: 10 - OTG
PIN: PA12 M42 P12 Alt Function: 10 - OTG
PIN: PA13 M42 P13 Alt Function: 0 - system (misc. I/O)
PIN: PA14 M42 P14 X_MIN_PIN protected
. X_STOP_PIN protected
PIN: PA15 M42 P15 Y_MIN_PIN protected
. Y_STOP_PIN protected
PIN: PB0 (A8) M42 P16 HEATER_1_PIN Output LOW
PIN: PB1 (A9) M42 P17 HEATER_0_PIN protected
PIN: PB2 M42 P18 Output LOW
PIN: PB3 M42 P19 E0_SERIAL_TX_PIN Output HIGH
. E0_SERIAL_RX_PIN Output HIGH
PIN: PB4 M42 P20 E0_DIR_PIN protected
PIN: PB5 M42 P21 E0_STEP_PIN protected
PIN: PB6 M42 P22 E0_ENABLE_PIN protected
PIN: PB7 M42 P23 Y2_CS_PIN protected
PIN: PB8 M42 P24 I2C_SCL_PIN Alt Function: 4 - I2C1..3
PIN: PB9 M42 P25 I2C_SDA_PIN Alt Function: 4 - I2C1..3
PIN: PB10 M42 P26 HEATER_BED_PIN protected
PIN: PB11 M42 P27 Input HIGH
PIN: PB12 M42 P28 FIL_RUNOUT_PIN Input HIGH
PIN: PB13 M42 P29 Y2_MIN_PIN Input HIGH
. Y2_STOP_PIN Input HIGH
PIN: PB14 M42 P30 Alt Function: 12 - FSMC, SDIO, OTG
PIN: PB15 M42 P31 Alt Function: 12 - FSMC, SDIO, OTG
PIN: PC0 (A10) M42 P18 Analog in = 0 Input LOW
PIN: PC1 (A11) M42 P19 Input HIGH
PIN: PC2 (A12) M42 P20 Analog in = 0 Input LOW
PIN: PC3 (A13) M42 P21 Input HIGH
PIN: PC4 (A14) M42 P22 Input LOW
PIN: PC5 (A15) M42 P23 FREEZE_PIN protected
. Z_MIN_PIN protected
. Z_STOP_PIN protected
. Z_MIN_PROBE_PIN protected
PIN: PC6 M42 P38 Z2_DIR_PIN protected
PIN: PC7 M42 P39 Z2_STEP_PIN protected
PIN: PC8 M42 P40 Z2_ENABLE_PIN protected
PIN: PC9 M42 P41 SDSS Output HIGH
PIN: PC10 M42 P42 SD_SCK_PIN Alt Function: 6 - SPI3
PIN: PC11 M42 P43 SD_MISO_PIN Alt Function: 6 - SPI3
PIN: PC12 M42 P44 SD_MOSI_PIN Alt Function: 6 - SPI3
PIN: PC13 M42 P45 X_DIR_PIN protected
PIN: PC14 M42 P46 X_STEP_PIN protected
PIN: PC15 M42 P47 X_ENABLE_PIN protected
. Y_ENABLE_PIN protected
PIN: PD0 M42 P48 Z4_SERIAL_TX_PIN Output HIGH
. Z4_SERIAL_RX_PIN Output HIGH
PIN: PD1 M42 P49 Z4_DIR_PIN protected
PIN: PD2 M42 P50 Z4_STEP_PIN protected
PIN: PD3 M42 P51 Z4_ENABLE_PIN protected
PIN: PD4 M42 P52 Z_SERIAL_TX_PIN Output HIGH
. Z_SERIAL_RX_PIN Output HIGH
PIN: PD5 M42 P53 Z_DIR_PIN protected
PIN: PD6 M42 P54 Z_STEP_PIN protected
PIN: PD7 M42 P55 Z_ENABLE_PIN protected
PIN: PD8 M42 P56 Input HIGH
PIN: PD9 M42 P57 Input HIGH
PIN: PD10 M42 P58 Output LOW
PIN: PD11 M42 P59 Z3_SERIAL_TX_PIN Output HIGH
. Z3_SERIAL_RX_PIN Output HIGH
PIN: PD12 M42 P60 Z3_DIR_PIN protected
PIN: PD13 M42 P61 Z3_STEP_PIN protected
PIN: PD14 M42 P62 Z3_ENABLE_PIN protected
PIN: PD15 M42 P63 Z2_SERIAL_TX_PIN Output HIGH
. Z2_SERIAL_RX_PIN Output HIGH
PIN: PE0 M42 P64 Y2_DIR_PIN protected
PIN: PE1 M42 P65 Y2_STEP_PIN protected
PIN: PE2 M42 P66 Y2_ENABLE_PIN protected
PIN: PE3 M42 P67 Y_CS_PIN protected
PIN: PE4 M42 P68 Y_DIR_PIN protected
PIN: PE5 M42 P69 Y_STEP_PIN protected
PIN: PE6 M42 P70 X_CS_PIN protected
PIN: PE7 M42 P71 Output HIGH
PIN: PE8 M42 P72 Input HIGH
PIN: PE9 M42 P73 Input HIGH
PIN: PE10 M42 P74 Input HIGH
PIN: PE11 M42 P75 Output HIGH
PIN: PE12 M42 P76 TMC_SPI_SCK Output HIGH
PIN: PE13 M42 P77 TMC_SPI_MISO Input HIGH
PIN: PE14 M42 P78 TMC_SPI_MOSI Output LOW
PIN: PE15 M42 P79 Output HIGH
PIN: PH0 M42 P80 Input LOW
PIN: PH1 M42 P81 Input LOW
END OF MESSAGE 2 ========================================

(BTW: I previously tried this, but without the serial write buffering, both messages were incomplete. M503 still doesn't work, I'm note sure why).

@V1EngineeringInc
Copy link
Author

I emailed my Biqu rep. Maybe that will get some eyes on #2827. No promises, I am not that big of a purchaser from them.

Thank you both!

@kisslorand
Copy link
Contributor

I made more important changes to the hesitation guard resulting in even more stability improvement during print. The hesitation guard is no more static, it is dynamic now, it constantly adapts to the situation. (for ex. it adapts to the situation where in a very busy print job the user start pressing buttons, moving across menus, adjusting things; it adapts to external commands (ESP3D, terminal, etc) perturbing the print job and so on...)
The hesitation guard level is configurable at compilation time but after all the tests done (spy on communication between the TFT and MB with a HW sniffer, check buffers of MB with Pronterface, check variable values of the TFT's MCU with ST Debugger) I didn't felt the need to make it adjustable at runtime or by "config.ini" because at a fairly low level it gives enormous stability.
The tests were done on a cylinder without Arc support, at a very high resolution. At 100 mm/s speed (40 gcodes per second) I couldn't make the planner buffer to have one single empty slot, at 500mm/s (200 gcodes per second) I barely could make the planner buffer to have occasionally 1-3 empty buffers, at 1000 mm/s (400 gcodes per second) there were now and than a few empty planner buffer slots and very rarely I was able to make it completely empty and starving (max starvation time was 20ms).
To make it harder for the TFT, after each gcode a comment was introduced, just to make it sweat. :)
If even more stability is needed my humble opinion is that we're stretching the physical limits of the electronics involved.
It worth mentioning that on the motherboard side very modest buffer sizes are needed. In my tests planner buffer had 16 slots and receiving buffer was also 16 but it was more than needed, it would pass the tests with only 4.

Fun fact

  In my tests I raised the hesitation guard to a high level and I couldn't make the planner buffer to starve one single slot even at 1000 mm/s (400 gcodes per second).

What else?

Well, PR #2825 is also included.

OK but where are all these goodies?

The compiled FW files can be found in my repository.

@V1EngineeringInc
Copy link
Author

The compiled FW files can be found in my repository.

Why not make a PR here or show your code on your side, so someone can look through it and possibly do it here? Not tying to come off rude I am just curious.

@kisslorand
Copy link
Contributor

As simple as the question is I cannot give a simple answer. You know where to reach me if you are really curious.

@rondlh
Copy link

rondlh commented Aug 24, 2023

As simple as the question is I cannot give a simple answer. You know where to reach me if you are really curious.

There are 2 different issues here:

  1. A bug causing a clear hesitation of about 1 second in the middle of the print. I believe that bug was fixed with removing rx_ok from the guard in Serial_Get
  2. General performance issues which were quite minor in my experience, especially for the average user. I believe that was greatly improved with adding ADVANCED_OK which gives some "air" if the TFT would be distracted with other tasks for a second. In my view adding buffered serial write is the next biggest remaining thing to do. You mentioned that there are more fundamental issues, I'm not sure what you mean with this. Could you enlighten me? Resource management?

bigtreetech pushed a commit that referenced this issue Sep 26, 2023
* Added ADVANCED_OK support + #2761 bugfix
* added tx_slots parameter on config.ini file
Copy link

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked and limited conversation to collaborators Mar 25, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
question Further information is requested
Projects
None yet
Development

Successfully merging a pull request may close this issue.

10 participants