is this with debug logging? i wonder if data/a response is sent that we don’t parse correctly
i’ll try to replicate the error with debug logging, i thought it was on but i don’t think it was. part of the problem is it doesn’t halt consistently on one command, so i’ll have to try and wait it out and see if it does it again.
after more testing, finding that this may be an error with jupyter notebook interaction of some sort, as the error did not occur on the same and longer protocols when using a python script rather than a notebook
2 Likes
very odd, thanks for sharing
@mackenzie I’m running into a similar problem now, getting a timeout error during a long step. This one happened on the 4th dispense
TimeoutError: Timeout while waiting for response to command C0DSid0058dm2 2 2 2 2 2 2 2tm1 1 1 1 1 1 1 1xp03156 02796 03066 02526 03426 02796 02976 02616yp1365 1005 1005 1455 0825 1455 0915 1365zx1974 1974 1974 1974 1974 1974 1974 1974lp2421 2421 2421 2421 2421 2421 2421 2421zl1974 1974 1974 1974 1974 1974 1974 1974po0100 0100 0100 0100 0100 0100 0100 0100ip0000 0000 0000 0000 0000 0000 0000 0000it0 0 0 0 0 0 0 0fp0000 0000 0000 0000 0000 0000 0000 0000zu0032 0032 0032 0032 0032 0032 0032 0032zr06180 06180 06180 06180 06180 06180 06180 06180th2450te2450dv00707 01020 01020 01020 01241 01241 01241 01461ds1200 1200 1200 1200 1200 1200 1200 1200ss0050 0050 0050 0050 0050 0050 0050 0050rv000 000 000 000 000 000 000 000ta050 050 050 050 050 050 050 050ba0000 0000 0000 0000 0000 0000 0000 0000lm0 0 0 0 0 0 0 0dj00zo000 000 000 000 000 000 000 000ll1 1 1 1 1 1 1 1lv1 1 1 1 1 1 1 1de0020 0020 0020 0020 0020 0020 0020 0020wt00 00 00 00 00 00 00 00mv00000 00000 00000 00000 00000 00000 00000 00000mc00 00 00 00 00 00 00 00mp000 000 000 000 000 000 000 000ms0010 0010 0010 0010 0010 0010 0010 0010mh0000 0000 0000 0000 0000 0000 0000 0000gi000 000 000 000 000 000 000 000gj0gk0.
Were you able to figure this out for jupyter notebooks? And what does it look like when you have it running in a python script?
Hi all, I’m encountering the same error (on the same machine as @Mackenzie) when using a Python script. I added some error handling to just retry the dispense/aspirate it times out on, but noticed something strange: when the retry occurs seemingly successfully, it actually dispenses twice.
Any thoughts on what might be going wrong? It seems like the dispense is actually happening despite the timeout error.
Not sure if you are still wondering about this, but I just ran everything in my Jupyter notebook within an async function. This seems to run faster too 
Hi @agar,
Could you please share with us some code that causes the error to troubleshoot what might be going on?
yes, if the command is sent and received by the machine, it’s executed. we wait 2 minutes, but you can increase this:
Hi there, so I actually increased the timeout to 20 minutes and am still having the TimeoutError issue. Since the command is executed, would the best practice just be to catch TimeoutErrors and wait indefinitely?
The issue is that upon TimeoutError the Hamilton will just stop in the middle of the protocol, forcing me to manually restart at unnatural midpoints in protocol. I’d like to set it and forget it for >>>2 hours.
Hi!! Thank you so much for the help. Here’s the current way I’m handling errors. This results in the multiple executions. I replaced my calls to lh.aspirate and lh.dispense with these.
async def safe_dispense(lh, resource, vols, offsets, max_attempts, text_log_file):
for attempt in range(max_attempts):
try:
set_volume_tracking(True)
return await lh.dispense(resource, vols=vols, offsets=offsets)
except TimeoutError:
with open(text_log_file, "a") as f:
f.write(f"Dispense timed out (attempt {attempt+1}), retrying…\n")
print(f"Dispense timed out (attempt {attempt+1}), retrying…")
if attempt == 0:
with open(text_log_file, "a") as f:
f.write(f"Turning off volume tracking…\n")
print(f"Turning off volume tracking…")
set_volume_tracking(False)
with open(text_log_file, "a") as f:
f.write(f"Failed to dispense after {max_attempts} attempts\n")
raise RuntimeError(f"Failed to dispense after {max_attempts} attempts")
async def safe_aspirate(lh, resource, vols, offsets, max_attempts, text_log_file):
for attempt in range(max_attempts):
try:
set_volume_tracking(True)
return await lh.aspirate(resource, vols=vols, offsets=offsets)
except TimeoutError:
with open(text_log_file, "a") as f:
f.write(f"Aspirate timed out (attempt {attempt+1}), retrying…\n")
print(f"Aspirate timed out (attempt {attempt+1}), retrying…")
if attempt == 0:
with open(text_log_file, "a") as f:
f.write(f"Turning off volume tracking…\n")
print(f"Turning off volume tracking…")
set_volume_tracking(False)
with open(text_log_file, "a") as f:
f.write(f"Failed to aspirate after {max_attempts} attempts\n")
raise RuntimeError(f"Failed to aspirate after {max_attempts} attempts")
~we still don’t know the original call that is causing the timeout~
nvm mackenzie shared the firmware command
1 Like
Calls to lh.aspirate or lh.dispense trigger the timeout. It’s after an arbitrary amount of time and on arbitrary of the many calls to these I have in the protocol.
Here are several examples of firmware commands that trigger this
C0DSid1157dm2 2&tm1 0&xp01911 00000&yp0928 0000&zx2189 2189&lp2411 2411&zl2189 2189&po0100 0100&ip0000 0000&it0 0&fp0000 0000&zu0032 0032&zr06180 06180&th2450te2450dv00392 00392&ds1200 1200&ss0050 0050&rv000 000&ta000 000&ba0000 0000&lm0 0&dj00zo000 000&ll1 1&lv1 1&de0100 0100&wt00 00&mv00000 00000&mc00 00&mp000 000&ms0500 0500&mh0000 0000&gi000 000&gj0gk0
C0ASid0295at0 0&tm1 0&xp09464 00000&yp4982 0000&th2450te2450lp2197 2197&ch000 000&zl1902 1902&po0100 0100&zu0032 0032&zr06180 06180&zx1902 1902&ip0000 0000&it0 0&fp0000 0000&av07975 07975&as1000 1000&ta000 000&ba0000 0000&oa000 000&lm0 0&ll1 1&lv1 1&zo000 000&ld00 00&de1000 1000&wt00 00&mv00000 00000&mc00 00&mp000 000&ms0500 0500&mh0000 0000&gi000 000&gj0gk0lk0 0&ik0000 0000&sd0500 0500&se0500 0500&sz0300 0300&io0000 0000&il00000 00000&in0000 0000&
C0DSid0087dm2 2&tm1 0&xp01371 00000&yp4858 0000&zx2119 2119&lp2341 2341&zl2119 2119&po0100 0100&ip0000 0000&it0 0&fp0000 0000&zu0032 0032&zr06180 06180&th2450te2450dv02255 02255&ds1200 1200&ss0050 0050&rv000 000&ta000 000&ba0000 0000&lm0 0&dj00zo000 000&ll1 1&lv1 1&de0100 0100&wt00 00&mv00000 00000&mc00 00&mp000 000&ms0500 0500&mh0000 0000&gi000 000&gj0gk0
Thanks for the quick follow up!
(I am a new user so limited to 3 replies to the same topic. Re: firmware log it might take me a while to get that. I’ll see if I can set up a toy experiment. Is there any way you can get this from the firmware commands?)
could you share a full firmware log?
made using for example the io layer: aP Validation Against Log File Example — PyLabRobot documentation
i am curious if the machine sends a response that we don’t parse correctly or if there is no response at all
i upgraded your account trust level
just the last couple of commands in the log would be sufficient.
but it should be incredibly easy to just run the setup code and the line that causes the problem
thanks for the trust level upgrade!
One issue is that the errors do not always occur on the same command, nor at the same time. You can see that the firmware commands it fails on vary too.
1 Like
as an update on this, I can run a toy protocol today to generate the validation log, but am not confident that I can induce the timeout error since it happens on different lines and firmware commands.
I’ll set up capture for the next real protocols to generate logs for firmware commands failing. Is there anything I can do to solve this in the meantime?
Thank you all for the timely and hands-on help!
edit: seems like the opposite problem is happening here - action errors out, but happens in real life liquid handler dispense (lh.dispense) removes liquid from tracker even if action fails · Issue #427 · PyLabRobot/pylabrobot · GitHub
2 Likes
@agar, I believe I can explain this execution duplication:
When you sent a command to the STAR it is executing it and during that time is “closing its incoming commands ears”.
During this time we’re just waiting for a confirmation from the machine for the duration specified in the STAR_backend.read_timout attribute.
If your command does take longer than read_timeout, let’s say default 120 sec, you will receive a firmware “listening”/reading error, aka the TimeOutError… BUT this error does not interrupt the ongoing operation!
That means the dispense is actually happening!
Your error handling just sees the error created by the reading and then triggers a second dispense.
I’m actually surprised this 2nd dispense doesn’t raise an error itself!?
Because the channel piston should have moved down, and shouldn’t have enough downwards movement space anymore after the first dispense. I would have expected you to see sth like a NotEnoughLiquid error during the 2nd dispense attempt (IF you don’t perform a multi-dispense here?).
But that error wouldn’t be caught by your except logic which only catches TimeOutError.
My recommendation: do not use TimeOutError handling, it becomes very messy very quickly, but focus on figuring out with us why you get that TimeOutError in the first place.
Could you please share some code as how you set up your machine?
I’m particularly interested in how you extend the STAR_Backend.read_timeout.
If you are pressed on time, I can think of an ad-hoc workaround… But it’s complex and ain’t pretty:
Assumptions
Your aim: dispense volume X into a container (simple)
Problem: TimeOutError means you are not sure whether the dispense has occurred
Quick & dirty solution: modify your error handling → if you get a TimeOutError you want to first check whether the transfer has actually occurred!
Use cll_probing on any channel that raised the error to detect the liquid height in that container.
Convert liquid height to volume using PLR’s volume from height function (NB: doesn’t exist for all PLR-integrated containers yet, but does for all I’ve integrated, I believe).
Is the volume you just measured ± 10% of what you said to dispense?
Yes → dispense worked, move on
No → dispense didn’t work, repeat
…I’d recommend not to do this and instead focusing on figuring out what causes the TimeOutError
1 Like
I do indeed get this error. Sometimes it doesn’t trigger the error immediately bc performing multi-dispense, but yes I get it by the end of the multi-dispense set. Initially — before I realized it was still dispensing when timing out — I assumed the error was spurious.
Here it is!
BACKEND = STAR()
DECK = STARDeck()
lh = LiquidHandler(backend=BACKEND, deck=DECK)
SKIP_CORE96_HEAD = True # For broken core96 head
# [... add resources ...]
# --- Setup the system ---
lh.backend.read_timeout = 20*60
# --- Enable resource tracking ---
set_tip_tracking(True)
set_volume_tracking(True)
await lh.setup(skip_core96_head=skip_core96_head)
Thank you for the quick and dirty solution! The assumptions are slightly off (tho I think should still be applicable for my situation). I am trying to do a multi-dispense, and the chief problem with TimeOutError is actually that it disrupts and fails a long, complex protocol. The problem is the failure in the middle of the protocol. It’s very nontrivial to “start where I left off” and increases the room for error.