ipsod
commented
1 year ago Closed ipsod closed 1 year ago
ipsod
commented
1 year ago ipsod
commented
1 year ago 
bdring
commented
1 year ago TLDR;
Can you make the most simple example to repeat the problem?
Are you 100% sure you are waiting for an ok before sending a jog command? I notice Bf:0 in a few places.
ipsod
commented
1 year ago I'll try to make a simple example.
ipsod
commented
1 year ago Does 0x85 jog cancel do anything funny regarding the buffer and sending ok messages?
I typically queue up a serial-buffer-full of commands. Before those are planned, while they're just in the serial buffer, I may then send a 0x85 jog cancel, which I understand is processed by a different pipeline. What would happen to those jog commands in the serial buffer? Am I doing it wrong? Should I wait for ok between each message?
MitchBradley
commented
1 year ago The jog cancel character "jumps the queue", bypassing any partial line that has already advanced from the hardware FIFO to the line collection buffer.
You really should send jogs synchronously instead of queuing them up - and you should not send other, non-jog, commands until the job has been completed or canceled.
MitchBradley
commented
1 year ago jog cancel has no relation whatsoever to "ok". ok indicates that a complete line has been received, passed to the GCode parser, and interpreted without error. The result of that interpretation causes the indicated operation - perhaps motion - to be passed on to the planner, where it is aggregated with any previous motion.
The jog cancel character is recognized anywhere, even in the middle of a line, before the line is handed over to the GCode parser. It sends an event to the protocol state machine that results in the cancellation of motion that is already in progress - motion that is typically well past the planner queue. The feedback to the sender is in the form of status reports that show state changes, completely independent of and separate from the "ok" acknowledgement of the line-oriented GCode parser.
ipsod
commented
1 year ago Would this list of timestamps (in microseconds) and commands sent suffice to try and reproduce the error? This sequence is giving the error about half the time, for me. This is not a great jog sequence. It causes jerky motion from failing to keep the buffer queue full, but it brings out the error quickly in my experience, though I don't know where the problem lies, for sure.
ipsod
commented
1 year ago @MitchBradley Ok, thank you for the info. I'll try and modify my jog code to comply with that.
ipsod
commented
1 year ago TLDR;
Can you make the most simple example to repeat the problem?
Are you 100% sure you are waiting for an
okbefore sending a jog command? I noticeBf:0in a few places.
I've altered my sender to wait for "ok" before sending each subsequent command, and no longer get Bf:0 in my status, but still get the error described in the issue. Here's a cleaned up log that's easier to see what's happening in, and it shows that each command waits for a response.
ipsod
commented
1 year ago I've written a python script that induces this error (on my machine). It's not waiting for "ok" in any sense, but this is just replaying a captured session which did. Note that the error will likely be buried in further output, since the sending part isn't aware of the receiving part. You can find it in the output easily by searching for error:.
import serial as pyserial
import time
import multiprocessing
def connect(port="/dev/ttyUSB0", baudrate=115200, timeout=0.1):
serial = pyserial.Serial()
serial.port = port
serial.baudrate = baudrate
serial.timeout = timeout
serial.open()
if not serial.is_open:
raise Exception("could not connect to serial")
return serial
def timed_send(csv, conn: pyserial.Serial):
begin = time.time()
for timestamp, command in csv.items():
while time.time() - begin < (float(timestamp)/1e6):
pass
conn.write(command)
print(command)
def read_loop(conn: pyserial.Serial):
while True:
value = conn.readline().rstrip()
if value:
assert isinstance(value, bytes)
print(f"\t{value}")
if b'error:' in value:
raise Exception(value)
timestamps = {
'0001104424': b'\x18',
'0001104728': b'\x0c',
'0002111029': b'$ri=50\n',
'0002122378': b'$Alarm/Disable\n',
'0002133496': b'G10L20 X0Y0Z0\n',
'0002225694': b'$10=2\n',
'0002234257': b'\n$Bye\n',
'0003851715': b'$T\n',
'0003894207': b'\x85',
'0005971033': b'\x17',
'0005971358': b'\x0c',
'0005975080': b'\x17',
'0005975287': b'\x17',
'0006076116': b'\x0c',
'0006377325': b'\x17',
'0006482553': b'\x17',
'0006482840': b'\x0c',
'0007488691': b'\x18',
'0007488913': b'\x0c',
'0008497874': b'$ri=50\n',
'0008508713': b'$Alarm/Disable\n',
'0008527685': b'G10L20 X0Y0Z0\n',
'0008541794': b'$10=2\n',
'0008549644': b'$T\n',
'0008559413': b'$Commands/List\n',
'0008719920': b'$Settings/List\n',
'0008774405': b'$Settings/ListChanged\n',
'0008787879': b'$Alarms/List\n',
'0008822019': b'$Errors/List\n',
'0009009464': b'$Config/Dump\n',
'0009422404': b'$Alarm/Disable\n',
'0009430830': b'$j=g91x0.0002y0.00333z0.00333f2829.06345\n',
'0009442155': b'$j=g91x0.0004y0.00667z0.00667f2829.06345\n',
'0009452593': b'$j=g91x0.0006y0.01z0.01f2829.06345\n',
'0009462160': b'$j=g91x0.0008y0.01333z0.01333f2829.06345\n',
'0009472766': b'$j=g91x0.001y0.01667z0.01667f2829.06345\n',
'0009483306': b'$j=g91x0.0012y0.02z0.02f2829.06345\n',
'0009492657': b'$j=g91x0.0014y0.02333z0.02333f2829.06345\n',
'0009503597': b'$j=g91x0.0016y0.02667z0.02667f2829.06345\n',
'0009512853': b'$j=g91x0.0018y0.03z0.03f2829.06345\n',
'0009522771': b'$j=g91x0.002y0.03333z0.03333f2829.06345\n',
'0009532953': b'$j=g91x0.0022y0.03667z0.03667f2829.06345\n',
'0009543331': b'$j=g91x0.0024y0.04z0.04f2829.06345\n',
'0009553657': b'$j=g91x0.0026y0.04333z0.04333f2829.06345\n',
'0009566061': b'$j=g91x0.0028y0.04667z0.04667f2829.06345\n',
'0009577291': b'$j=g91x0.003y0.05z0.05f2829.06345\n',
'0009586751': b'$j=g91x0.0032y0.05333z0.05333f2829.06345\n',
'0009598614': b'$j=g91x0.0034y0.05667z0.05667f2829.06345\n',
'0009610146': b'$j=g91x0.0036y0.06z0.06f2829.06345\n',
'0009620304': b'$j=g91x0.0038y0.06333z0.06333f2829.06345\n',
'0009631838': b'$j=g91x0.004y0.06667z0.06667f2829.06345\n',
'0009643195': b'$j=g91x0.0042y0.07z0.07f2829.06345\n',
'0009653522': b'$j=g91x0.0044y0.07333z0.07333f2829.06345\n',
'0009666049': b'$j=g91x0.0046y0.07667z0.07667f2829.06345\n',
'0009675647': b'$j=g91x0.0048y0.08z0.08f2829.06345\n',
'0009684830': b'$j=g91x0.005y0.08333z0.08333f2829.06345\n',
'0009696591': b'$j=g91x0.0052y0.08667z0.08667f2829.06345\n',
'0009708508': b'$j=g91x0.0054y0.09z0.09f2829.06345\n',
'0009720386': b'$j=g91x0.0056y0.09333z0.09333f2829.06345\n',
'0009732658': b'$j=g91x0.0058y0.09667z0.09667f2829.06345\n',
'0009744235': b'$j=g91x0.006y0.1z0.1f2829.06345\n',
'0009753664': b'$j=g91x0.0062y0.10333z0.10333f2829.06345\n',
'0009766080': b'$j=g91x0.0064y0.10667z0.10667f2829.06345\n',
'0009777698': b'$j=g91x0.0066y0.11z0.11f2829.06345\n',
'0009787161': b'$j=g91x0.0068y0.11333z0.11333f2829.06345\n',
'0009798596': b'$j=g91x0.007y0.11667z0.11667f2829.06345\n',
'0009810307': b'$j=g91x0.0072y0.12z0.12f2829.06345\n',
'0009820800': b'$j=g91x0.0074y0.12333z0.12333f2829.06345\n',
'0009832646': b'$j=g91x0.0076y0.12667z0.12667f2829.06345\n',
'0009863908': b'\x85',
'0009868098': b'$j=g91x0.0002y0.00333z0.00333f2829.06345\n',
'0009930934': b'$j=g91x0.0004y0.00667z0.00667f2829.06345\n',
'0009941558': b'$j=g91x0.0006y0.01z0.01f2829.06345\n',
'0009951801': b'$j=g91x0.0008y0.01333z0.01333f2829.06345\n',
'0009962073': b'$j=g91x0.001y0.01667z0.01667f2829.06345\n',
'0009971877': b'$j=g91x0.0012y0.02z0.02f2829.06345\n',
'0009982339': b'$j=g91x0.0014y0.02333z0.02333f2829.06345\n',
'0009994157': b'$j=g91x0.0016y0.02667z0.02667f2829.06345\n',
'0010006050': b'$j=g91x0.0018y0.03z0.03f2829.06345\n',
'0010017547': b'$j=g91x0.002y0.03333z0.03333f2829.06345\n',
'0010027719': b'$j=g91x0.0022y0.03667z0.03667f2829.06345\n',
'0010039530': b'$j=g91x0.0024y0.04z0.04f2829.06345\n',
}
if __name__ == "__main__":
conn = connect()
proc = multiprocessing.Process(target=read_loop, args=[conn], daemon=True)
proc.start()
timed_send(timestamps, conn)The first Run message appears when the X value finally changes from 0.000 to 0.005. In the preceding jog commands, the X offset is smaller - sometimes much smaller - than the size of a machine step (.005). I will keep investigating, but I do not see the point of issuing jogs for less than a step size.
ipsod
commented
1 year ago The first Run message appears when the X value finally changes from 0.000 to 0.005. In the preceding jog commands, the X offset is smaller - sometimes much smaller - than the size of a machine step (.005). I will keep investigating, but I do not see the point of issuing jogs for less than a step size.
Well, the intent is to implement GRBL1.1 jogging with independent speeds on multiple axes, and these really short motions happen when a faster axis is running along with a slower axis. I'm not sure what sort of checks/whatever to implement to avoid that - I guess that all of the shorter motions will be grouped at the beginning/end of a motion, anyhow, so maybe I could just omit them without worrying about how it might effect the rest of the motion.
Are these short commands ignored entirely, or does 0.0025 + 0.0025 = 0.005? Likewise, is 1.0025 == 1.000? Also, is 0.005 machine step a universal constant, or is it specific to my configuration?
MitchBradley
commented
1 year ago 200 steps/mm = 0.005 mm/step
ipsod
commented
1 year ago I see. Below are the results of some experiments I did.
0.0025 + 0.0025 = 0.005
<Idle|WPos:0.195,2.705,2.705|Bf:15,128|FS:0,0>
$j=g91x0.0025f1000
ok
$j=g91x0.0025f1000
ok
<Jog|WPos:0.195,2.705,2.705|Bf:15,128|FS:0,0>
<Idle|WPos:0.200,2.705,2.705|Bf:15,128|FS:0,0>0.0005 * 10 = 0.005
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
<Jog|WPos:0.200,2.705,2.705|Bf:15,128|FS:0,0>
<Idle|WPos:0.205,2.705,2.705|Bf:15,128|FS:0,0>partial steps followed by a full step do not (always?) cause error
$j=g91x0.0005f1000
ok
$j=g91x0.0005f1000
ok
$j=g91x0.005f1000
ok
<Jog|WPos:0.205,2.705,2.705|Bf:15,128|FS:0,0>
<Idle|WPos:0.210,2.705,2.705|Bf:15,128|FS:0,0|WCO:0.000,0.000,0.000>Please let me know if there's anything further I can do to move this along.
MitchBradley
commented
1 year ago It is a multi-core synchronization problem. I am working on a fix.
ipsod
commented
1 year ago Great, thank you. Good hunting.
Controller Board
Makerbase Tiny Bee v1.0
Machine Description
fluidnc-v3.6.5-pre2 board only, no motors or switches
Input Circuits
No response
Configuration file
Startup Messages
User Interface Software
custom
What happened?
I'm using
$ri=50.I'm getting a error:8 ("Command requires idle state") when sending only jog commands. I send only jog commands, never a normal "gcode" command. I also observe that the status report says state is
run.This error often happens when I'm really spamming the jog keys in my sender. However, it sometimes also happens when doing what seems like a very simple motion (ie: jog forward, jog cancel, jog left).
Here is a log of what happened before/during the failure. Lines prepended with (python fstring)
{time.time()}<< SerialConn(...)are lines received from serial. Lines prepended with{time.time()}>>are sent to serial. Other lines are just contextual notes.Here is the rest of the log, after the error:
Other Information
I can generate some more error logs if you like. Let me know how else I can help.