line mode protocol overflows when sending data without any delays

[talpadk]

Hi

I have written a small python script to send g-code data to the g2core but are getting what seems to be overflow errors in the g2core:
{“er”:{“fb”:100.26,”st”:28,”msg”:”Failed to get planner buffer – mp_get_write_buffer()”}}
{“er”:{“fb”:100.26,”st”:36,”msg”:”Failed to get planner buffer – aline()”}}

I have previously asked for help on:
https://www.synthetos.com/topics/g2core-line-mode-protocol-question/
As a probable cause would be that I simply have misunderstood the protocol, but was suggested to log an issue here.
(Basically one is allowed to have up to 4 unacknowledged commands)

I'm seeing the "bug" on an Arduino Due running the latest edge branch (SHA: af26ad8)

The python script provoking the "bug" is available here:
https://github.com/talpadk/g2coregui
(SHA: d73f999ca678c198a34cbd5875be0df71663b5fc)

I have attached the g-code / nc file I'm attempting to send
test3.txt

When I send the file without any delay I get the output inserted at the bottom.
The format starts with a timestamp followed by the "buffer state" before the line is received or send
The "buffer state" 'is number_of_unacked_send / max_number_of_unacked_allowed'
followed by direction indication and then the data received or send.

If I introduce a 0.5 second delay in the code the file is send just fine, but that is probably g-code content specific and besides goes against the idea of keeping the g2core buffer semi full at all times.

I'm expecting that the g2core is supposed to stop sending me {"r" when it has filled all its planner buffers and suspend parsing of g-code data in the serial input buffers.
But it seems to keep on "requesting" more data until it fatally runs out of planner buffers.

Any help / suggestions would be appreciated.
Regards Visti Andresen

talpa@Hermes g2coregui [master] $ ./g2coreAutoSender.py
Copy the file to send to: 'autosend.nc' when done it will be deleted!!!
Ctrl+C to stop
10:09:38:934 0/4 <- {"r":{"fv":0.99,"fb":100.26,"fbs":"100.26","fbc":"settings_test.h","hp":3,"hv":0,"id":"0084-e739-18c6-294","msg":"SYSTEM READY"},"f":[1,0,1]}
New file detected
10:09:50:078 0/4 -> {"gc":"G1 X10 F1000"}
10:09:50:078 1/4 -> {"gc":"G1 X0"}
10:09:50:078 2/4 -> {"gc":"G1 X10"}
10:09:50:078 3/4 -> {"gc":"G1 X0"}
10:09:50:089 4/4 <- {"r":{},"f":[1,0,23]}
10:09:50:089 3/4 <- {"r":{},"f":[1,0,16]}
10:09:50:089 2/4 <- {"r":{},"f":[1,0,17]}
10:09:50:089 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:089 0/4 -> {"gc":"G1 X10"}
10:09:50:099 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:099 0/4 -> {"gc":"G1 X0"}
10:09:50:109 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:109 0/4 -> {"gc":"G1 X10"}
10:09:50:120 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:120 0/4 -> {"gc":"G1 X0"}
10:09:50:130 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:130 0/4 -> {"gc":"G1 X10"}
10:09:50:141 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:141 0/4 -> {"gc":"G1 X0"}
10:09:50:151 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:151 0/4 -> {"gc":"G1 X10"}
10:09:50:161 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:162 0/4 -> {"gc":"G1 X0"}
10:09:50:172 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:172 0/4 -> {"gc":"G1 X10"}
10:09:50:182 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:182 0/4 -> {"gc":"G1 X0"}
10:09:50:192 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:192 0/4 -> {"gc":"G1 X10"}
10:09:50:203 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:203 0/4 -> {"gc":"G1 X0"}
10:09:50:213 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:213 0/4 -> {"gc":"G1 X10"}
10:09:50:224 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:224 0/4 -> {"gc":"G1 X0"}
10:09:50:234 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:235 0/4 -> {"gc":"G1 X10"}
10:09:50:245 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:245 0/4 -> {"gc":"G1 X0"}
10:09:50:256 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:256 0/4 -> {"gc":"G1 X10"}
10:09:50:266 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:267 0/4 -> {"gc":"G1 X0"}
10:09:50:277 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:277 0/4 -> {"gc":"G1 X10"}
10:09:50:288 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:288 0/4 -> {"gc":"G1 X0"}
10:09:50:298 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:298 0/4 -> {"gc":"G1 X10"}
10:09:50:309 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:309 0/4 -> {"gc":"G1 X0"}
10:09:50:320 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:320 0/4 -> {"gc":"G1 X10"}
10:09:50:330 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:330 0/4 <- {"sr":{"line":0,"posx":0,"posy":0,"posz":0,"feed":0,"vel":0,"momo":0,"stat":5}}
10:09:50:331 0/4 -> {"gc":"G1 X0"}
10:09:50:341 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:341 0/4 -> {"gc":"G1 X10"}
10:09:50:351 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:352 0/4 -> {"gc":"G1 X0"}
10:09:50:362 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:362 0/4 -> {"gc":"G1 X10"}
10:09:50:373 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:373 0/4 -> {"gc":"G1 X0"}
10:09:50:383 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:383 0/4 -> {"gc":"G1 X10"}
10:09:50:394 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:394 0/4 -> {"gc":"G1 X0"}
10:09:50:404 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:404 0/4 -> {"gc":"G1 X10"}
10:09:50:415 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:415 0/4 -> {"gc":"G1 X0"}
10:09:50:425 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:426 0/4 -> {"gc":"G1 X10"}
10:09:50:436 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:436 0/4 -> {"gc":"G1 X0"}
10:09:50:447 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:447 0/4 -> {"gc":"G1 X10"}
10:09:50:457 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:458 0/4 -> {"gc":"G1 X0"}
10:09:50:468 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:468 0/4 -> {"gc":"G1 X10"}
10:09:50:479 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:479 0/4 -> {"gc":"G1 X0"}
10:09:50:489 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:490 0/4 -> {"gc":"G1 X10"}
10:09:50:500 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:500 0/4 -> {"gc":"G1 X0"}
10:09:50:511 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:511 0/4 -> {"gc":"G1 X10"}
10:09:50:521 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:521 0/4 -> {"gc":"G1 X0"}
10:09:50:532 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:532 0/4 -> {"gc":"G1 X10"}
10:09:50:542 1/4 <- {"r":{},"f":[1,0,17]}
10:09:50:542 0/4 -> {"gc":"G1 X0"}
10:09:50:553 1/4 <- {"r":{},"f":[1,0,16]}
10:09:50:553 0/4 -> {"gc":"G1 X10"}
10:09:50:563 1/4 <- {"er":{"fb":100.26,"st":28,"msg":"Failed to get planner buffer - mp_get_write_buffer()"}}
10:09:50:563 1/4 <- {"er":{"fb":100.26,"st":36,"msg":"Failed to get planner buffer - aline()"}}
10:09:50:563 1/4 <- {"r":{},"f":[1,36,17]}
10:09:50:564 0/4 -> {"gc":"G1 X0"}
10:09:50:574 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:574 0/4 -> {"gc":"G1 X10"}
10:09:50:584 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:584 0/4 <- {"sr":{"stat":13}}
10:09:50:584 0/4 -> {"gc":"G1 X0"}
10:09:50:595 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:595 0/4 -> {"gc":"G1 X10"}
10:09:50:605 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:605 0/4 -> {"gc":"G1 X0"}
10:09:50:616 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:616 0/4 -> {"gc":"G1 X10"}
10:09:50:626 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:626 0/4 -> {"gc":"G1 X0"}
10:09:50:637 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:637 0/4 -> {"gc":"G1 X10"}
10:09:50:647 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:648 0/4 -> {"gc":"G1 X0"}
10:09:50:658 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:658 0/4 -> {"gc":"G1 X10"}
10:09:50:669 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:669 0/4 -> {"gc":"G1 X0"}
10:09:50:679 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:679 0/4 -> {"gc":"G1 X10"}
10:09:50:690 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:690 0/4 -> {"gc":"G1 X0"}
10:09:50:700 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:700 0/4 -> {"gc":"G1 X10"}
10:09:50:711 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:711 0/4 -> {"gc":"G1 X0"}
10:09:50:721 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:722 0/4 -> {"gc":"G1 X10"}
10:09:50:732 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:732 0/4 -> {"gc":"G1 X0"}
10:09:50:743 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:743 0/4 -> {"gc":"G1 X10"}
10:09:50:753 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:754 0/4 -> {"gc":"G1 X0"}
10:09:50:764 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:764 0/4 -> {"gc":"G1 X10"}
10:09:50:775 1/4 <- {"r":{},"f":[1,206,17]}
10:09:50:775 0/4 -> {"gc":"G1 X0"}
10:09:50:786 1/4 <- {"r":{},"f":[1,206,16]}
10:09:50:786 0/4 -> {"gc":"G1 X10"}
10:09:50:796 1/4 <- {"r":{},"f":[1,206,17]}
Done sending

[talpadk]

While reading https://github.com/synthetos/g2/wiki/g2core-Communications specifically:

If the motion buffer is full, however, there is no room for new moves to be stored, so g2core will stop reading and parsing data lines until room is made in the motion buffer. It will continue to read control lines in any case.

it hit me that the g2core might mistake {"gc": line as control line.

Indeed if I don't wrap the g-code in json the g2core works like expected without any delays and with multiple bursts enabled too.

P.S. also the first

{"r":{"fv":0.99,"fb":100.26,"fbs":"100.26","fbc":"settings_test.h","hp":3,"hv":0,"id":"0084-e739-18c6-294","msg":"SYSTEM READY"},"f":[1,0,1]}

Could also be seen as problematic as it is an {"r" response without any "cause"
(I'm already limiting my counter to prevent this, but it is not part of the specification)

[giseburt]

You are correct. The {"gc":...} JSON is not intended to be used externally except in rare conditions. JSON is seen as "control" before the contents are parsed. Due to how we separate control from data in the incoming buffer it would require duplicating part of the JSON parser (and the related performance impact) to identify different types of JSON, so for now we simply consider it all control. There are essentially three times something gets executed: 1) immediately - if it starts with any of {!%~ and a couple of control characters (^D, for example) 2) when the gcode is being parsed - this is all gcode not in the next group. For JSON to run here you wrap it in a M100.1 active comment, like this: M100.1 ({zfr:200}) 3) M100 active comments is queued and executed when the motion before it is done, synchronized with motion, M101 active comments are waits and will pause motion after it until the true/false value in the comment matches the actual value. I gotta check out g2coregui. It sounds cool. Note that we have identified a bug in some versions of Pyserial that causes it to return a partial line and then hold on to the rest of the line an indeterminate amount of time.

…

On Tue, Jul 25, 2017 at 4:12 AM Visti Andresen ***@***.***> wrote: While reading https://github.com/synthetos/g2/wiki/g2core-Communications specifically: If the motion buffer is full, however, there is no room for new moves to be stored, so g2core will stop reading and parsing data lines until room is made in the motion buffer. It will continue to read control lines in any case. it hit me that the *g2core might mistake {"gc": line as control line.* Indeed if I don't wrap the g-code in json the g2core works like expected without any delays and with multiple bursts enabled too. P.S. also the first {"r":{"fv":0.99,"fb":100.26,"fbs":"100.26","fbc":"settings_test.h","hp":3,"hv":0,"id":"0084-e739-18c6-294","msg":"SYSTEM READY"},"f":[1,0,1]} Could also be seen as problematic as it is an {"r" response without any "cause" (I'm already limiting my counter to prevent this, but it is not part of the specification) — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#287 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAXj0aw6GQLFBu4zk1ENIdEX5bntAFcqks5sRbFugaJpZM4OiO0Y> .

[talpadk]

I'm considering updating the wiki pages with notices that one should not send g-code using json.
(If no one objects)

g2coregui isn't much to behold quite yet

[giseburt]

No objections here. Much appreciated.

…

On Tue, Jul 25, 2017 at 12:02 PM Visti Andresen ***@***.***> wrote: I'm considering updating the wiki pages with notices that one should not send g-code using json. (If no one objects) g2coregui isn't much to behold quite yet — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#287 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAXj0VuRpq35_g5piLY39wpgliBRVirzks5sRh-_gaJpZM4OiO0Y> .

[talpadk]

I'm closing this issue as the behaviour can be described as a design decision.

Also I'm done updating the wiki to prevent others from having to experiencing this issue.