MarlinFirmware / Marlin

Marlin is an optimized firmware for RepRap 3D printers based on the Arduino platform. Many commercial 3D printers come with Marlin installed. Check with your vendor if you need source code for your specific machine.
https://marlinfw.org
GNU General Public License v3.0
16.29k stars 19.24k forks source link

[BUG] Marlin fails to send OK with space in planner buffer until buffer is empty #16894

Closed CRCinAU closed 4 years ago

CRCinAU commented 4 years ago

Bug Description

When printing slowly (ie Luke's flow calibration test cube), there are times when OctoPrint is sending data to the printer, but the printer doesn't respond with OK until the planner buffer becomes empty. Once this happens, data flows correctly again - until the next failure to reply.

It seems that in this mode, maybe marlin should send back BUSY if it won't accept more data, but as the temperature autoreport is sent every 2 seconds, the pause between OK's was approx 60 seconds.

My Configurations

Octoprint log ``` Recv: ok N1644 P58 B63 Send: N1645 G1 X108.5 Y127.3 E480.88219*89 Recv: ok N1645 P57 B63 Send: N1646 G0 F830.5 X107.7 Y127.3*93 Recv: ok N1646 P56 B63 Send: N1647 M73 P88 R4*21 Recv: ok N1647 P56 B63 Send: N1648 G0 F300 X107.7 Y127.3 Z14*63 Recv: ok N1648 P55 B63 Send: N1649 G0 F5400 X108.1 Y126.9*113 Recv: ok N1649 P54 B63 Send: N1650 M117 L=68/74 ETC 3m44s*26 Recv: ok N1650 P54 B63 Send: N1651 G1 F2400 E478.88219*49 Recv: ok N1651 P53 B63 Send: N1652 G1 F2400 E480.88219*53 Recv: ok N1652 P52 B63 Send: N1653 G1 F922.8 X126.9 Y126.9 E481.57001*20 Recv: ok N1653 P51 B63 Send: N1654 G1 X126.9 Y108.1 E482.25783*85 Recv: ok N1654 P50 B63 Send: N1655 G1 X108.1 Y108.1 E482.94565*80 Recv: ok N1655 P49 B63 Send: N1656 G1 X108.1 Y126.1 E483.6042*101 Recv: ok N1656 P48 B63 Send: N1657 G0 F830.5 X108.1 Y126.9*95 Recv: ok N1657 P47 B63 Send: N1658 G0 F5400 X107.7 Y127.3*115 Recv: ok N1658 P46 B63 Send: N1659 G1 F922.8 X107.7 Y107.7 E484.32128*18 Recv: ok N1659 P45 B63 Send: N1660 G1 X127.3 Y107.7 E485.03837*83 Recv: ok N1660 P44 B63 Send: N1661 G1 X127.3 Y127.3 E485.75546*94 Recv: ok N1661 P43 B63 Send: N1662 G1 X108.5 Y127.3 E486.44328*89 Recv: ok N1662 P42 B63 Send: N1663 G0 F830.5 X107.7 Y127.3*90 Recv: ok N1663 P41 B63 Send: N1664 M73 P88 R4*20 Recv: ok N1664 P41 B63 Send: N1665 G0 F300 X107.7 Y127.3 Z14.2*44 Recv: ok N1665 P40 B63 Send: N1666 G0 F5400 X108.1 Y126.9*124 Recv: ok N1666 P39 B63 Send: N1667 M117 L=69/74 ETC 3m34s*24 Recv: ok N1667 P39 B63 Send: N1668 G1 F2400 E484.44328*59 Recv: ok N1668 P38 B63 Send: N1669 G1 F2400 E486.44328*56 Recv: T:249.92 /250.00 B:99.93 /100.00 @:89 B@:73 Recv: T:249.76 /250.00 B:100.00 /100.00 @:93 B@:69 Recv: T:250.20 /250.00 B:99.96 /100.00 @:82 B@:72 Recv: T:250.00 /250.00 B:100.04 /100.00 @:87 B@:67 Recv: T:250.00 /250.00 B:99.99 /100.00 @:87 B@:70 Recv: T:250.30 /250.00 B:99.98 /100.00 @:80 B@:71 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Send: N1670 G1 F922.8 X126.9 Y126.9 E487.1311*34 Recv: T:250.00 /250.00 B:100.06 /100.00 @:88 B@:67 Recv: T:250.20 /250.00 B:100.08 /100.00 @:83 B@:66 Recv: T:249.84 /250.00 B:99.90 /100.00 @:92 B@:75 Recv: T:250.00 /250.00 B:100.06 /100.00 @:88 B@:66 Recv: T:249.76 /250.00 B:99.97 /100.00 @:94 B@:71 Recv: T:250.00 /250.00 B:99.97 /100.00 @:88 B@:71 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Recv: T:249.92 /250.00 B:99.90 /100.00 @:91 B@:75 Recv: T:250.10 /250.00 B:99.97 /100.00 @:86 B@:71 Recv: T:249.84 /250.00 B:100.00 /100.00 @:92 B@:69 Recv: T:250.00 /250.00 B:100.00 /100.00 @:88 B@:69 Recv: T:250.20 /250.00 B:100.02 /100.00 @:83 B@:68 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Recv: T:250.10 /250.00 B:99.97 /100.00 @:85 B@:71 Recv: T:249.84 /250.00 B:100.07 /100.00 @:92 B@:66 Recv: T:249.76 /250.00 B:100.02 /100.00 @:93 B@:68 Recv: T:249.76 /250.00 B:99.97 /100.00 @:93 B@:71 Recv: T:250.00 /250.00 B:100.06 /100.00 @:87 B@:66 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Recv: T:250.20 /250.00 B:100.08 /100.00 @:82 B@:64 Recv: T:250.10 /250.00 B:100.07 /100.00 @:85 B@:65 Recv: T:249.92 /250.00 B:100.02 /100.00 @:89 B@:67 Recv: T:249.84 /250.00 B:100.00 /100.00 @:92 B@:68 Recv: T:250.20 /250.00 B:100.02 /100.00 @:82 B@:67 Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves. Recv: T:249.92 /250.00 B:99.96 /100.00 @:89 B@:71 Recv: T:250.10 /250.00 B:99.93 /100.00 @:85 B@:72 Recv: T:249.92 /250.00 B:99.97 /100.00 @:90 B@:70 Recv: T:250.20 /250.00 B:99.97 /100.00 @:82 B@:70 Recv: ok N1669 P126 B62 Send: N1671 G1 X126.9 Y108.1 E487.81892*86 Recv: ok N1670 P125 B63 Send: N1672 G1 X108.1 Y108.1 E488.50674*84 Recv: ok N1671 P124 B63 Send: N1673 G1 X108.1 Y126.1 E489.16529*81 Recv: ok N1672 P123 B63 Recv: ok N1673 P122 B63 Send: N1674 G0 F830.5 X108.1 Y126.9*94 Recv: ok N1674 P121 B63 Send: N1675 G0 F5400 X107.7 Y127.3*124 Recv: ok N1675 P120 B63 Send: N1676 G1 F922.8 X107.7 Y107.7 E489.88238*17 Recv: ok N1676 P119 B63 Send: N1677 G1 X127.3 Y107.7 E490.59947*88 Recv: ok N1677 P118 B63 Send: N1678 G1 X127.3 Y127.3 E491.31656*81 Recv: ok N1678 P117 B63 Send: N1679 G1 X108.5 Y127.3 E492.00438*80 Recv: ok N1679 P116 B63 Send: N1680 G0 F830.5 X107.7 Y127.3*87 Recv: ok N1680 P115 B63 Send: N1681 G0 F300 X107.7 Y127.3 Z14.4*32 Recv: T:250.20 /250.00 B:99.93 /100.00 @:82 B@:73 Recv: ok N1681 P115 B63 Send: N1682 G0 F5400 X108.1 Y126.9*118 Recv: ok N1682 P114 B63 Send: N1683 M117 L=70/74 ETC 3m22s*29 Recv: ok N1683 P114 B63 Send: N1684 M73 P91 R4*18 Recv: ok N1684 P114 B63 Send: N1685 M105*29 Recv: ok T:249.76 /250.00 B:99.90 /100.00 @:94 B@:75 Send: N1686 G1 F2400 E490.00438*56 Recv: ok N1686 P113 B63 Send: N1687 G1 F2400 E492.00438*59 Recv: ok N1687 P112 B63 Send: N1688 G1 F922.8 X126.9 Y126.9 E492.69219*22 Recv: ok N1688 P111 B63 Send: N1689 G1 X126.9 Y108.1 E493.38001*84 Recv: ok N1689 P110 B63 Send: N1690 G1 X108.1 Y108.1 E494.06783*95 Recv: ok N1690 P109 B63 Send: N1691 G1 X108.1 Y126.1 E494.72638*80 Recv: ok N1691 P108 B63 Send: N1692 G0 F830.5 X108.1 Y126.9*86 Recv: ok N1692 P107 B63 Send: N1693 G0 F5400 X107.7 Y127.3*116 Recv: ok N1693 P106 B63 Send: N1694 G1 F922.8 X107.7 Y107.7 E495.44347*25 Recv: ok N1694 P105 B63 Send: N1695 G1 X127.3 Y107.7 E496.16056*80 Recv: ok N1695 P104 B63 Send: N1696 G1 X127.3 Y127.3 E496.87765*90 Recv: ok N1696 P103 B63 Send: N1697 G1 X108.5 Y127.3 E497.56547*95 Recv: ok N1697 P102 B63 Send: N1698 G0 F830.5 X107.7 Y127.3*94 Recv: ok N1698 P101 B63 Send: N1699 G0 F300 X107.7 Y127.3 Z14.6*43 Recv: ok N1699 P100 B63 Send: N1700 M117 L=71/74 ETC 3m19s*30 Recv: ok N1700 P100 B63 Send: N1701 G0 F5400 X108.1 Y126.9*124 Recv: ok N1701 P99 B63 Send: N1702 G1 F2400 E495.56547*58 Recv: ok N1702 P98 B63 Send: N1703 G1 F2400 E497.56547*57 Recv: ok N1703 P97 B63 Send: N1704 M73 P92 R3*31 Recv: ok N1704 P97 B63 Send: N1705 G1 F922.8 X126.9 Y126.9 E498.25329*18 Recv: ok N1705 P96 B63 Send: N1706 G1 X126.9 Y108.1 E498.94111*95 Recv: ok N1706 P95 B63 Send: N1707 G1 X108.1 Y108.1 E499.62893*81 Recv: ok N1707 P94 B63 Send: N1708 G1 X108.1 Y126.1 E500.28748*84 Recv: ok N1708 P93 B63 Send: N1709 G0 F830.5 X108.1 Y126.9*85 Recv: ok N1709 P92 B63 Send: N1710 G0 F5400 X107.7 Y127.3*126 Recv: ok N1710 P91 B63 Send: N1711 G1 F922.8 X107.7 Y107.7 E501.00457*31 Recv: ok N1711 P90 B63 Send: N1712 G1 X127.3 Y107.7 E501.72166*81 Recv: ok N1712 P89 B63 Send: N1713 G1 X127.3 Y127.3 E502.43874*93 Recv: ok N1713 P88 B63 Send: N1714 G1 X108.5 Y127.3 E503.12656*90 Recv: ok N1714 P87 B63 Send: N1715 G0 F830.5 X107.7 Y127.3*90 Recv: ok N1715 P86 B63 Send: N1716 G0 F300 X107.7 Y127.3 Z14.8*35 Recv: ok N1716 P85 B63 Send: N1717 G0 F5400 X108.1 Y126.9*123 Recv: ok N1717 P84 B63 Send: N1718 M117 L=72/74 ETC 3m5s*41 Recv: ok N1718 P84 B63 Send: N1719 M73 P92 R3*19 Recv: ok N1719 P84 B63 Send: N1720 G1 F2400 E501.12656*53 Recv: ok N1720 P83 B63 Send: N1721 G1 F2400 E503.12656*54 Recv: ok N1721 P82 B63 Send: N1722 G1 F922.8 X126.9 Y126.9 E503.81438*29 Recv: ok N1722 P81 B63 Send: N1723 G1 X126.9 Y108.1 E504.5022*101 Recv: ok N1723 P80 B63 Send: N1724 G1 X108.1 Y108.1 E505.19002*88 Recv: ok N1724 P79 B63 Send: N1725 G1 X108.1 Y126.1 E505.84857*89 Recv: ok N1725 P78 B63 Send: N1726 G0 F830.5 X108.1 Y126.9*88 Recv: ok N1726 P77 B63 Send: N1727 G0 F5400 X107.7 Y127.3*122 Recv: ok N1727 P76 B63 Send: N1728 G1 F922.8 X107.7 Y107.7 E506.56566*18 Recv: ok N1728 P75 B63 Send: N1729 G1 X127.3 Y107.7 E507.28275*81 Recv: ok N1729 P74 B63 Send: N1730 G1 X127.3 Y127.3 E507.99984*80 Recv: ok N1730 P73 B63 Send: N1731 G1 X108.5 Y127.3 E508.68766*89 Recv: ok N1731 P72 B63 Send: N1732 G0 F830.5 X107.7 Y127.3*95 Recv: ok N1732 P71 B63 Send: N1733 G0 F300 X107.7 Y127.3 Z15*51 Recv: ok N1733 P70 B63 Send: N1734 G0 F5400 X108.1 Y126.9*122 Recv: ok N1734 P69 B63 Send: N1735 M117 L=73/74 ETC 2m56s*16 Recv: ok N1735 P69 B63 Send: N1736 G1 F2400 E506.68766*58 Recv: ok N1736 P68 B63 Send: N1737 M73 P95 R3*24 Recv: ok N1737 P68 B63 Send: N1738 G1 F2400 E508.68766*58 Recv: ok N1738 P67 B63 Send: N1739 G1 F922.8 X126.9 Y126.9 E509.37548*22 Recv: ok N1739 P66 B63 Send: N1740 G1 X126.9 Y108.1 E510.0633*102 Recv: ok N1740 P65 B63 Send: N1741 G1 X108.1 Y108.1 E510.75112*85 Recv: ok N1741 P64 B63 Send: N1742 G1 X108.1 Y126.1 E511.40967*87 Recv: ok N1742 P63 B63 Send: N1743 G0 F830.5 X108.1 Y126.9*91 Recv: ok N1743 P62 B63 Send: N1744 G0 F5400 X107.7 Y127.3*127 Recv: ok N1744 P61 B63 Send: N1745 G1 F922.8 X107.7 Y107.7 E512.12676*30 Recv: ok N1745 P60 B63 Send: N1746 G1 X127.3 Y107.7 E512.84385*84 Recv: ok N1746 P59 B63 Send: N1747 G1 X127.3 Y127.3 E513.56093*89 Recv: ok N1747 P58 B63 Send: N1748 G1 X107.7 Y127.3 E514.27802*81 Recv: ok N1748 P57 B63 Changing monitoring state from "Printing" to "Finishing" Send: N1749 G1 F2400 E512.27802*49 Recv: ok N1749 P56 B63 Send: N1750 M140 S0*86 Recv: ok N1750 P56 B63 Send: N1751 G91*35 Recv: ok N1751 P56 B63 Send: N1752 G1 E-2 F2700*0 Recv: ok N1752 P55 B63 Send: N1753 M117 L=74/74 ETC 2m45s*21 Recv: ok N1753 P55 B63 Send: N1754 G1 E-2 Z0.2 F2400*83 Recv: ok N1754 P54 B63 Send: N1755 G1 X5 Y5 F3000*122 Recv: ok N1755 P53 B63 Send: N1756 M73 P95 R3*31 Recv: ok N1756 P53 B63 Send: N1757 G1 Z15*98 Recv: ok N1757 P52 B63 Send: N1758 G90*43 Recv: ok N1758 P52 B63 Send: N1759 G1 X0 Y110*19 Recv: ok N1759 P51 B63 Send: N1760 M106 S0*87 Recv: ok N1760 P51 B63 Send: N1761 M104 S0*84 Recv: ok N1761 P51 B63 Send: N1762 M140 S0*87 Recv: ok N1762 P51 B63 Send: N1763 M84 X Y E*72 Recv: T:250.10 /0.00 B:99.90 /0.00 @:0 B@:0 Recv: T:249.92 /0.00 B:99.86 /0.00 @:0 B@:0 Recv: T:248.97 /0.00 B:99.83 /0.00 @:0 B@:0 Recv: T:247.78 /0.00 B:99.54 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:246.11 /0.00 B:99.02 /0.00 @:0 B@:0 Recv: T:243.57 /0.00 B:98.82 /0.00 @:0 B@:0 Recv: T:240.87 /0.00 B:98.72 /0.00 @:0 B@:0 Recv: T:238.37 /0.00 B:98.35 /0.00 @:0 B@:0 Recv: T:235.49 /0.00 B:98.04 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:232.55 /0.00 B:97.71 /0.00 @:0 B@:0 Recv: T:229.31 /0.00 B:97.42 /0.00 @:0 B@:0 Recv: T:226.56 /0.00 B:96.86 /0.00 @:0 B@:0 Recv: T:223.39 /0.00 B:96.62 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:220.00 /0.00 B:96.55 /0.00 @:0 B@:0 Recv: T:217.34 /0.00 B:95.82 /0.00 @:0 B@:0 Recv: T:214.51 /0.00 B:95.64 /0.00 @:0 B@:0 Recv: T:211.39 /0.00 B:95.54 /0.00 @:0 B@:0 Recv: T:208.47 /0.00 B:95.46 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:205.41 /0.00 B:94.88 /0.00 @:0 B@:0 Recv: T:202.16 /0.00 B:94.59 /0.00 @:0 B@:0 Recv: T:199.02 /0.00 B:94.46 /0.00 @:0 B@:0 Recv: T:196.60 /0.00 B:94.41 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:193.75 /0.00 B:94.15 /0.00 @:0 B@:0 Recv: T:191.18 /0.00 B:93.93 /0.00 @:0 B@:0 Recv: T:188.92 /0.00 B:93.79 /0.00 @:0 B@:0 Recv: T:185.79 /0.00 B:93.58 /0.00 @:0 B@:0 Recv: T:183.55 /0.00 B:93.51 /0.00 @:0 B@:0 Recv: echo:busy: processing Recv: T:181.13 /0.00 B:93.51 /0.00 @:0 B@:0 Recv: ok N1763 P127 B62 Send: N1764 M82*45 Recv: ok N1764 P127 B63 Send: N1765 M104 S0*80 Recv: ok N1765 P127 B63 Send: N1766 M73 P95 R3*28 Recv: ok N1766 P127 B63 Send: N1767 M117 L=74/74 ETC*31 Recv: ok N1767 P127 B63 Send: N1768 M400*31 Recv: ok N1768 P127 B63 Changing monitoring state from "Finishing" to "Operational" Send: M73 P100 R0 Recv: ok P127 B63 Recv: T:178.49 /0.00 B:93.51 /0.00 @:0 B@:0 Recv: T:176.48 /0.00 B:93.51 /0.00 @:0 B@:0 Recv: T:174.09 /0.00 B:93.36 /0.00 @:0 B@:0 Recv: T:171.87 /0.00 B:92.64 /0.00 @:0 B@:0 ```
thinkyhead commented 4 years ago

I have been looking into how this could occur. I notice that the host keepalive messages and the ok messages both got suspended, but the temperature auto-report did continue. This is particularly strange, because the temperature auto-report and the host keepalive both emanate from calls to idle(). Therefore, whatever was suspending and calling idle() could not have been a g-code handler, because g-codes set the busy status.

It looks like CardReader::printingHasFinished is one potential culprit. It gets triggered as soon as an SD card job file has finished reading, and if you have a very large buffer this is long before the buffer gets emptied. printingHasFinished does a planner.synchronize which will call idle in a loop without setting the busy status.

So what we really want to do is have a two-stage job completion, where we put off closing the file and completing the print job until the g-code buffer has first been emptied. It means re-writing a bit of the print completion code, but I believe I know what needs to be done.

CRCinAU commented 4 years ago

Here's an interesting question - as this was via USB, would it matter about SD card stuff? Or is that how it does buffering?

thinkyhead commented 4 years ago

Ah, right. For a print over USB there will be no such behavior. So, I will have to look deeper!

CRCinAU commented 4 years ago

For what its worth, I see this with a smaller buffer as well:

Send: N143539 G1 X139.489 Y167.214 E2635.07366*100
Recv: ok N143539 P0 B31
Send: N143540 G1 X139.489 Y167.592 E2635.08749*101
Recv: ok N143540 P0 B31
Send: N143541 G1 X139.489 Y167.857 E2635.09718*101
Recv: ok N143541 P0 B31
Send: N143542 G1 X135.276 Y179.671 E2635.55607*111
Recv: ok N143542 P0 B30
Send: N143543 G1 X134.963 Y179.852 E2635.5693*87
Recv:  T:250.20 /250.00 B:100.02 /100.00 @:67 B@:59
Recv: ok N143543 P30 B31
Send: N143544 G1 X134.666 Y180.023 E2635.58184*107
Recv: ok N143544 P29 B31
Send: N143545 G1 X134.503 Y180.118 E2635.58874*101
Recv: ok N143545 P28 B31
Send: N143546 G1 X134.206 Y180.29 E2635.6013*101
Recv: ok N143546 P27 B31

and

Send: N145207 G0 X96.717 Y184.995*43
Recv: ok N145207 P0 B31
Send: N145208 G0 X97.97 Y183.164*27
Recv: ok N145208 P0 B30
Send: N145209 G0 X98.105 Y182.627*46
Recv:  T:250.10 /250.00 B:100.03 /100.00 @:69 B@:59
Recv:  T:249.92 /250.00 B:100.16 /100.00 @:71 B@:52
Recv: ok N145209 P30 B31
Send: N145210 G0 X97.983 Y182.055*44
Recv: ok N145210 P29 B31
Send: N145211 G0 X97.594 Y181.506*39
Recv: ok N145211 P28 B31

You can see the P buffer only start to fill again once its empty after the temp autoreport.

CRCinAU commented 4 years ago

Ok - I think I might have discovered something.....

I have a TFT35 v2 connected to the onboard TFT connector. I'm pretty sure this just acts as a serial port - and it sends commands to get status etc while the print is going on. If I unplug this screen (therefore we only get the USB serial data), then things don't pause after a T: line on USB.

I believe this may be a result of commands also coming in via the TFT port on from the screen.

Does this assist in the thought process of what's causing it?

edit: What I'm seeing with the screen unplugged:

Send: N150132 G0 X151.984 Y178.418*31
Recv: ok N150132 P0 B31
Send: N150133 G0 X151.999 Y101.768*24
Recv: ok N150133 P0 B31
Send: N150134 G0 X150.88 Y101.504*47
Recv: ok N150134 P0 B31
Send: N150135 G0 X128.574 Y101.22*38
Recv:  T:250.40 /250.00 B:100.07 /100.00 @:65 B@:56
Recv: ok N150135 P0 B31
Send: N150136 G1 F2400 E3069.10453*12
Recv: ok N150136 P0 B31
Send: N150137 G1 X128.574 Y101.02 E3069.11184*93
Recv: ok N150137 P2 B31
Send: N150138 G1 X128.581 Y98.803 E3069.19295*91
Recv: ok N150138 P1 B31
Send: N150139 G1 X128.616 Y98.585 E3069.20103*82
Recv: ok N150139 P0 B31
Send: N150140 G1 X128.682 Y98.408 E3069.20794*93
Recv: ok N150140 P0 B31
thinkyhead commented 4 years ago

You can try using M111 S3 to have Marlin echo back everything it gets from the host, including the serial TFT. But, it might only echo back to the TFT that sent it. If this is the case, that echo can be tweaked to go to all serial out.

I suspect it must be sending some command that invokes M400 or planner.synchronize.

CRCinAU commented 4 years ago

I believe the commands (not 100% sure - but believe!) is to retrieve the position, as it updates the X Y Z on the screen, as well as the command to get the current temps (as it doesn't do an auto-report).

M114 (get current position) seems to be called: https://github.com/bigtreetech/BIGTREETECH-TouchScreenFirmware/blob/605a921564f6df46638bcd79f20d16c2146740ad/TFT/src/User/Menu/StatusScreen.c#L295

M105 to get temperatures: https://github.com/bigtreetech/BIGTREETECH-TouchScreenFirmware/blob/92ee173ebb86442b77d8e5eb738f1d1309790fd0/TFT/src/User/Menu/Heat.c#L276

CRCinAU commented 4 years ago

It's interesting that since I unplugged the TFT, the blotches that I was seeing on my print (2h left out of 5h) seem to have disappeared - which means they're caused by the small pause when the P buffer empties.

I was racking my brain to figure out what was causing this - hence the first try with a P buffer size of 128... However now we know the cause, what do we do to fix it? :)

thinkyhead commented 4 years ago

That's it, then! The screen firmware is not compatible with Marlin. The M114 command necessarily invokes a planner.synchronize() because the current position needs to correspond to the stepper positions, and they will be out of sync if the command isn't synchronized.

If the LCD firmware can be altered, then we could do something for it. The other alternative is to alter M114 so that it "fakes" the stepper positions by calculating them (kinematics included) from the cartesian current position and displaying the calculated rather than true current stepper values.

CRCinAU commented 4 years ago

Hmmm... Many thoughts.... I wonder if its correct for M114 to just report the position as per where it is right now - without syncing the planner - ie where it would be after everything in the P buffer has been executed?

If the P buffer is empty, it wouldn't matter - but if the P buffer contains things, then what M114 reports could only be correct AFTER the buffer has been emptied. Should it return sooner, but with the position as per when the command is executed - and not after the P buffer is empty?

What would be the drawback for this?

Hmmmm

Failing that, I assume currently there is no way to subscribe to position updates on a timer - like there is for temperature reporting...

Also, we can change the firmware in the LCD - as its just published on their github page: https://github.com/bigtreetech/BIGTREETECH-TouchScreenFirmware/

thinkyhead commented 4 years ago

These are never in sync when the machine is in motion.

thinkyhead commented 4 years ago

The simplest thing to do is to add a custom command (or extra flag for M114) that tells it to skip synchronize and only report the simple XYZ (optional E) position, for something like an LCD and then update the LCD firmware.

CRCinAU commented 4 years ago

I think that might be the better option - as it doesn't make sense to always skip the sync.

As the S parameter is usually used for values, would it be better to use M114 D1 = Enable dirty report?

This way the position can be reported for random updates, but it doesn't have to be accurate, and a dirty report of where it kinda is will probably be good enough.

I can then build a firmware that replaces all M114 commands with M114 D1 in the firmware to see if this fixes the problem in this - and in the TFT issues page I just linked.

edit: Scratch that - D is already used:

[D<|>] | Detailed information (requires M114_DETAIL)

thinkyhead commented 4 years ago
CRCinAU commented 4 years ago

Yeah - I believe the E parameter is for their 'smart filament sensor' thing... Does that also call planner.synchronize()? If so, that would cause the same issue...

Ah, I see the code:

void GcodeSuite::M114() {

  #if ENABLED(M114_DETAIL)
    if (parser.seen('D')) {
      report_current_position_detail();
      return;
    }
    if (parser.seen('E')) {
      SERIAL_ECHOLNPAIR("Count E:", stepper.position(E_AXIS));
      return;
    }
  #endif

  planner.synchronize();
  report_current_position();
}

This also means that M114 E won't work unless M114_DETAIL is defined? Should E be outside of that #if?

I would assume we could have the following outside the M114_DETAIL define?

if ( parser.seen('S') ) {
    report_current_position();
    return;
}
thinkyhead commented 4 years ago

Here's the context for synchronize: 34ff0c3 / #6039 / #6037

guruathwal commented 4 years ago

The TFT sends the M114 command when it is on Status Menu or when it is on Move Menu to display the correct nozzle position, setting the TFT to any other menu will stop the M114 command.

The synchronize part can be avoided if Marlin can respond to M114 with the approximate position details from G-code it is processing and not re-calculating during printing.

Another way can be to send a confirmation message from marlin to all connected serial devices that a print has started which will be helpful to stop sending commands from idle hosts during prints and display a Print in progress with printing progress/status. About a month ago I open a PR https://github.com/MarlinFirmware/Marlin/pull/16682 to auto report the Z position while printing from Onboard sd-card to avoid sending M114 from TFT for the update but it was closed with the reason being that it was getting mixed up and M114 command is good enough. After that, I dropped the idea of displaying the Z height on the TFT when printing through Onboard sd-card as I did not want to poll M114 every few seconds to update the position.

Although I did not dig deep enough to check if https://github.com/MarlinFirmware/Marlin/pull/16682 will also trigger the synchronize part.

CRCinAU commented 4 years ago

Yeah - it causes big quality issues when the P buffer becomes empty - hence it certainly needs a non-blocking mode. I chose U to indicate that it is reported in the unsync'ed state.

This way, the TFT can change to call M114 U and get a 'good enough' position without having to wait for sync - therefore causing the buffer to empty and a blob to form.

guruathwal commented 4 years ago

@CRCinAU the U option will be helpful but the host will also need to know when to send M114 and when to send M114 U. There should also be some status message from Marlin to inform the hosts that a print is in progress through another host. Alternatively, it can be possible to report the unsynced position on M114 when the Print Timer is running and report the synced position when idle.

CRCinAU commented 4 years ago

@thinkyhead Theres an idea.... If the print timer is running, should it skip the planner.synchronize() instead of adding a new parameter to do this?

hfog commented 4 years ago

The problem is that if the print is running from another source such as Octoprint, the TFT may have no idea that a print is running.

CRCinAU commented 4 years ago

Yeah - I've just tested that proposed patch - but it seems that there is still a call to planner.synchronize() somewhere... It makes me wonder if the print_job_timer is scoped to each serial interface instead of global...

It builds ok, but I still see the buffer empty when the TFT sends an M114.

I can see @thinkyhead is working on stuff at the moment - which look like much more drastic changes that for the moment I won't pretend to understand - but I'm guessing will be much more complete than my feeble attempt :grin:

guruathwal commented 4 years ago

just saw #17032 by @thinkyhead addressing the M114 synchronization issue.

thinkyhead commented 4 years ago

Theres an idea.... If the print timer is running, should it skip the planner.synchronize() instead of adding a new parameter to do this?

Well, what you more or less end up with there is that it will only synchronize when it doesn't much matter. So I just took the approach of removing the synchronize entirely, but made M114 still return the same values that it would if you waited. The position returned during movement will be ahead of the actual position.

guruathwal commented 4 years ago

@thinkyhead

  • The E parameter reports E separately (or alone) for the benefit of BTT, since they submitted that change.

The E parameter should also be changed to report the length of filament in MM instead of the total step count because the TFT firmware converts the steps in MM based on the extruder's steps per MM specified in the configuration of the TFT firmware. This will give an inaccurate reading when someone uses precompiled TFT firmware with an extruder with different steps per MM

CRCinAU commented 4 years ago

Ah - I figured out what was wrong with my build.... the scripts I use run a git reset --hard - so it was removing the patch after compiling the first binary :)

However, instead of testing my patch again, I've rolled a number of firmwares with @thinkyhead changes in the PR and will give it a test when I get to sit down and do a print again.

I haven't done any special changes to any Configuration.h or Configuration_adv.h files - so if I understand the code correctly, an M114 will return without the sync now by default.

CRCinAU commented 4 years ago

@thinkyhead - I've done some test prints using your PR code on top of bugfix-2.0.x.

I can confirm that the P buffer does not decrease now when the TFT issues an M114 command.

+1 from me.

denis-itskovich commented 4 years ago

@CRCinAU Were you eventually be able to solve this somehow?

CRCinAU commented 4 years ago

@CRCinAU Were you eventually be able to solve this somehow?

Yep - grab the latest bugfix-2.0.x. The default M114 behaviour has changed to resolve that problem.

github-actions[bot] commented 4 years ago

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.