Realtime commands not always executed once planner buffer full.

[mrdunk]

Hi, cool project. Thanks for the work so far; It's been helpful while developing a GRBL control program.

I've got an issue though:
When i push enough commands to fill Grbl's planner buffer, realtime commands stop working. eg: "?" no longer triggers a status update.

My system:

duncan@lapdancer:~/Working/grbl-master/grbl/grbl-sim$ uname -a
Linux lapdancer 4.15.0-72-generic #81-Ubuntu SMP Tue Nov 26 12:20:02 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
duncan@lapdancer:~/Working/grbl-master/grbl/grbl-sim$ gcc -v
Using built-in specs.
COLLECT_GCC=gcc
COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/7/lto-wrapper
OFFLOAD_TARGET_NAMES=nvptx-none
OFFLOAD_TARGET_DEFAULT=1
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Ubuntu 7.4.0-1ubuntu1~18.04.1' --with-bugurl=file:///usr/share/doc/gcc-7/README.Bugs --enable-languages=c,ada,c++,go,brig,d,fortran,objc,obj-c++ --prefix=/usr --with-gcc-major-version-only --program-suffix=-7 --program-prefix=x86_64-linux-gnu- --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --libdir=/usr/lib --enable-nls --with-sysroot=/ --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --with-default-libstdcxx-abi=new --enable-gnu-unique-object --disable-vtable-verify --enable-libmpx --enable-plugin --enable-default-pie --with-system-zlib --with-target-system-zlib --enable-objc-gc=auto --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --enable-multilib --with-tune=generic --enable-offload-targets=nvptx-none --without-cuda-driver --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 7.4.0 (Ubuntu 7.4.0-1ubuntu1~18.04.1) 
duncan@lapdancer:~/Working/grbl-master/grbl/grbl-sim$ ./grbl_sim.exe 
# 
# Grbl 1.1h ['$' for help]
$I
# [VER:1.1h.20190830:]
# [OPT:V,15,128]
# ok

Steps to reproduce:

duncan@lapdancer:~/Working/grbl-master/grbl/grbl-sim$ ./grbl_sim.exe 
# 
# Grbl 1.1h ['$' for help]
G00 F10 X1000 G91
250000, 0, 0, 0.000000
# ok
#  <Run|MPos:0.004,0.000,0.000|FS:54,0|Pn:PXYZRHS|WCO:0.000,0.000,0.000>
G00 F10 X1000 G91
500000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
750000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
1000000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
1250000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
1500000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
1750000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
2000000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
2250000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
2500000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
2750000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
3000000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
3250000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
3500000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
3750000, 0, 0, 250000.000000
# ok
G00 F10 X1000 G91
#  <Run|MPos:0.304,0.000,0.000|FS:174,0|Pn:PXYZRHS|Ov:100,100,100>
# ?????????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
#  <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ?????????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
#  <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ?# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ??# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ?????????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# # <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# # <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ???????????????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# # <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ????????????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# # <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ??# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>
# ???????# <Run|MPos:0.388,0.000,0.000|FS:192,0|Pn:PXYZRHS>

You can see above me sending Gcode until i stop getting "ok" back. Ie, the planner buffer has filled.
After that, sometimes a "?" returns a status report but usually it does not.

I've dug around in the code for a day.
Grbl's ISR(SERIAL_RX) is definitely receiving the serial port data.
The following modifications can be used to prove this:
in ./grbl-sim/serial.c:

[...SNIP...]

extern volatile uint8_t serial_tx_buffer_head;
extern volatile uint8_t serial_tx_buffer_tail;
extern volatile uint8_t serial_rx_buffer_head;
extern volatile uint8_t serial_rx_buffer_tail;
extern volatile uint8_t sys_rt_exec_state;
void simulate_read_interrupt(){
  uint8_t char_in = platform_poll_stdin();
  if (char_in) {
	 UDR0 = char_in;
	 //EOF or CTRL-F to exit
	 if (UDR0 == EOF || UDR0 == 0xFF || UDR0 == 0x06 ) {
		sim.exit = exit_REQ;
	 }
	 //debugging
	 if (UDR0 == '%') { 
		printf("%ld %f\n",sim.masterclock,(double)sim.sim_time);
		printf("serial_tx_buffer_tail: %i    serial_tx_buffer_head: %i\n",
		    serial_tx_buffer_tail, serial_tx_buffer_head);
		printf("serial_rx_buffer_tail: %i    serial_rx_buffer_head: %i\n",
		    serial_rx_buffer_tail, serial_rx_buffer_head);
		printf("sys_rt_exec_state: 0x%x\n", sys_rt_exec_state);
	 }
	 interrupt_SERIAL_RX();
	
	 // The following line shows the  EXEC_STATUS_REPORT flag is always correctly set.
	 printf("sys_rt_exec_state: 0x%x\n", sys_rt_exec_state);
  }
}

uint8_t count = 0;
void simulate_serial(){
  simulate_write_interrupt();
  simulate_read_interrupt();
}

If you compile the above you'll see the serial_rx_buffer is still filling for all non realtime commands
and for realtime commands the flags are getting set in sys_rt_exec_state.

So since realtime commands work /before/ the planned buffer fills but not afterwards...
i presume Grbl is making more calls to protocol_execute_realtime() in the before case.
I can't seem to find where in Grbl code consuming data from serial_read() blocks once the planned buffer is full....

Any thoughts?