micro-manager / pycro-manager

Python control of micro-manager for customized data acquisition
https://pycro-manager.readthedocs.io/en/latest/
BSD 3-Clause "New" or "Revised" License
162 stars 49 forks source link

Change GenericSLM Displayed Image during Acquisition #395

Closed tpeterson14 closed 6 months ago

tpeterson14 commented 2 years ago

I'm working with a structured illumination microscope and want to create acquisition events that allows me to capture multiple images at each z-position, and change the displayed image on a GenericSLM for each capture.

Here is some sample code:

from pycromanager import Core, Acquisition, multi_d_acquisition_events
import os

def hook(event):
    print(f'Event received at hook: {event}')
    return event

desktop = os.path.join(os.path.join(os.environ['USERPROFILE']), 'Desktop')
with Acquisition(directory=desktop,
    name='acquisition_test',
    pre_hardware_hook_fn=hook,
    show_display=True) as acq:  

    events = []
    events.append({'axes': {'z': 0, 'i_SIM': 0}, 'z': 0})
    events.append({'axes': {'z': 0, 'i_SIM': 1}, 'z': 0})
    events.append({'axes': {'z': 0, 'i_SIM': 2}, 'z': 0})
    events.append({'axes': {'z': 1, 'i_SIM': 0}, 'z': 10})
    events.append({'axes': {'z': 1, 'i_SIM': 1}, 'z': 10})
    events.append({'axes': {'z': 1, 'i_SIM': 2}, 'z': 10})

    acq.acquire(events)

My problem is that this only calls the hook function once for each z position:

Event received at hook: [{'axes': {'i_SIM': 0, 'z': 0}, 'z': 0, 'properties': []}, {'axes': {'i_SIM': 1, 'z': 0}, 'z': 0, 'properties': []}, {'axes': {'i_SIM': 2, 'z': 0}, 'z': 0, 'properties': []}]

Event received at hook: [{'axes': {'i_SIM': 0, 'z': 1}, 'z': 10, 'properties': []}, {'axes': {'i_SIM': 1, 'z': 1}, 'z': 10, 'properties': []}, {'axes': {'i_SIM': 2, 'z': 1}, 'z': 10, 'properties': []}] [Finished in 1.8s]

I see that all 3 events are pushed into the hook function, so I can't manually call to Core().set_slm_image() and Core().display_slm_image().

What is the best way to change the GenericSLM image for each unique [z, i_SIM] event during an Acquisition? Can the event "properties" key be used for this somehow without generating 10's-100's of numpy arrays during event generation?

tpeterson14 commented 2 years ago

After some further digging, it seems like it is hardware sequencing the camera acquisitions, even when I have "Camera-UseExposureSequences" set to No (this is the demo config).

If I change the event structure to something like

    events = []
    events.append({'axes': {'z': 0, 'i_SIM': 0}, 'z': 0})
    events.append({'axes': {'z': 0, 'i_SIM': 1}, 'z': 0.0001})
    events.append({'axes': {'z': 0, 'i_SIM': 2}, 'z': 0.0002})
    events.append({'axes': {'z': 1, 'i_SIM': 0}, 'z': 10})
    events.append({'axes': {'z': 1, 'i_SIM': 1}, 'z': 10.0001})
    events.append({'axes': {'z': 1, 'i_SIM': 2}, 'z': 10.0002})

then I get the desired output:

Event received at hook: {'axes': {'i_SIM': 0, 'z': 0}, 'z': 0, 'properties': []} Event received at hook: {'axes': {'i_SIM': 1, 'z': 0}, 'z': 0.0001, 'properties': []} Event received at hook: {'axes': {'i_SIM': 2, 'z': 0}, 'z': 0.0002, 'properties': []} Event received at hook: {'axes': {'i_SIM': 0, 'z': 1}, 'z': 10, 'properties': []} Event received at hook: {'axes': {'i_SIM': 1, 'z': 1}, 'z': 10.0001, 'properties': []} Event received at hook: {'axes': {'i_SIM': 2, 'z': 1}, 'z': 10.0002, 'properties': []}

So maybe a better question is: Is it possible to disable camera hardware sequencing when multiple events have the same z-position?

edit: formatting

henrypinkard commented 2 years ago

without generating 10's-100's of numpy arrays during event generation?

Could you explain a bit more what this means? Dont you have to create a bunch of numpy arrays in the hook to set the SIM patterns?

So maybe a better question is: Is it possible to disable camera hardware sequencing when multiple events have the same z-position?

Yes it certainly should be. This may be something that is not correctly implemented in the acquisition engine right now. @nicost , do you know what the correct way to check the camera if it is allowing sequences or not? Is it to use the isExposureSequencable function? Currently, this is only used as a check if different events have different exposures:

https://github.com/micro-manager/AcqEngJ/blob/fb96967aa5d0fecaf60182c18b458cd25f836ae1/src/main/java/org/micromanager/acqj/internal/Engine.java#L800

So maybe a better question is: Is it possible to disable camera hardware sequencing when multiple events have the same z-position?

Yes, two possibilities:

1) (A hacky way) Find some random unimportant property that isn't sequencable and change it in each event so they wont be merged into a sequence.

2) (Probably the correct way) Add in 'slm' to acquisition events so that this can just be called through the API and you wouldn't need to use hooks. Is there any reason this wouldn't work in your case if I added it (the thing about hundreds of numpy arrays)?

tpeterson14 commented 2 years ago

Thanks for the quick response Henry!

Dont you have to create a bunch of numpy arrays in the hook to set the SIM patterns?

This gets a little out of my depth, but my concern was memory. I'm thinking that if I have 200 z-positions, 7 SIM images at each z, and each numpy array is 480x640, that would mean generating a 480x640x1400 array if I understand correctly. That's ~3.2GB, which just froze up the control PC when I made a np.ones array with that size. Not sure if creating them one-by-one in the hook function is any different, though (if the memory is reclaimed between events?).

(I illuminate with one row of pixels per z-position -- we are doing structured light sheet microscopy, hence the need to create 7 unique images per z-position).

(Probably the correct way) Add in 'slm' to acquisition events so that this can just be called through the API and you wouldn't need to use hooks. Is there any reason this wouldn't work in your case if I added it (the thing about hundreds of numpy arrays)?

My only concern is memory (see above), which is why I like the idea of dynamically setting the SLM pattern for each event. But like I said this is not my area of expertise so maybe I'm not looking at things the right way.

(A hacky way) Find some random unimportant property that isn't sequencable and change it in each event so they wont be merged into a sequence.

I'm certainly not above using a hacky solution! I'm using a ThorlabsAPTStage, PCO camera, and GenericSLM, and tried varying a couple of properties with no luck ("Core-TimeoutMs" and "GenericSLM-MonochromeColor"). Any suggestions for properties that might work better?

henrypinkard commented 2 years ago

I'm certainly not above using a hacky solution! I'm using a ThorlabsAPTStage, PCO camera, and GenericSLM, and tried varying a couple of properties with no luck ("Core-TimeoutMs" and "GenericSLM-MonochromeColor"). Any suggestions for properties that might work better?

You could try adding in one of the demo devices to your configuration, and then changing its property. This would have the benefit of no weird side effects because no actual hardware

That's ~3.2GB, which just froze up the control PC when I made a np.ones array with that size. Not sure if creating them one-by-one in the hook function is any different, though (if the memory is reclaimed between events?).

Yes, memory is reclaimed, so I don't think this should cause a problem. Hacky solution should work for now.

I think the best way to solve this is to be able to pass a python generator function to acq.acquire, so that events can be dynamically generated as needed, and you wouldn't need to do them all at once. Something like

def event_maker():
   while #some condition:
        #create a new event
        yield event

Ultimately I think if you (or someone else) wanted this to go really fast, youd need to set up hardware triggering between SLM and camera, and then have the acquisition engine automatically dispatch sequences of SIM patterns at once (which would mean you cant use hooks)

tpeterson14 commented 2 years ago

You could try adding in one of the demo devices to your configuration, and then changing its property.

This worked perfectly! I added a Demo XY Stage and incremented its position by one each event, and the hook function processed each event independently:

with Acquisition(directory=desktop,
    name='acquisition_test',
    pre_hardware_hook_fn=hook,  
    show_display=True) as acq:  

        events = []
        events.append({'axes': {'z': 0, 'i_SIM': 0}, 'z': 1, 'x':1})
        events.append({'axes': {'z': 0, 'i_SIM': 1}, 'z': 1, 'x':2})
        events.append({'axes': {'z': 0, 'i_SIM': 2}, 'z': 1, 'x':3})
        events.append({'axes': {'z': 1, 'i_SIM': 0}, 'z': 5, 'x':4})
        events.append({'axes': {'z': 1, 'i_SIM': 1}, 'z': 5, 'x':5})
        events.append({'axes': {'z': 1, 'i_SIM': 2}, 'z': 5, 'x':6})
        acq.acquire(events)

Returns

Event received at hook: {'axes': {'i_SIM': 0, 'z': 0}, 'x': 1, 'z': 1, 'properties': []} Event received at hook: {'axes': {'i_SIM': 1, 'z': 0}, 'x': 2, 'z': 1, 'properties': []} Event received at hook: {'axes': {'i_SIM': 2, 'z': 0}, 'x': 3, 'z': 1, 'properties': []} Event received at hook: {'axes': {'i_SIM': 0, 'z': 1}, 'x': 4, 'z': 5, 'properties': []} Event received at hook: {'axes': {'i_SIM': 1, 'z': 1}, 'x': 5, 'z': 5, 'properties': []} Event received at hook: {'axes': {'i_SIM': 2, 'z': 1}, 'x': 6, 'z': 5, 'properties': []}

So even if it isn't the most efficient approach, your suggestion is a great workaround that lets me move forward with the experiment - thank you!

Ultimately I think if you (or someone else) wanted this to go really fast, youd need to set up hardware triggering between SLM and camera, and then have the acquisition engine automatically dispatch sequences of SIM patterns at once (which would mean you cant use hooks)

I'm a little rusty with generator functions, but I think as long as the SIM pattern could be created dynamically for each event based on other event parameters (i.e. i_SIM and z in my example above) during a sequence acquisition then that would probably work. But like I said, the quick fix you suggested above got me past the major roadblock -- I really appreciate your help!

henrypinkard commented 2 years ago

Awesome! I'll keep this issue open now to remind me to implement the better way, which I think would be helpful for other types of experiments too.

@marktsuchida , wondering if you also might know what the correct acquisition engine behavior is in this case. How do you check if the camera is allowing sequences or not? Is it to use the isExposureSequencable function? Currently, this is only used as a check if different events have different exposures:

https://github.com/micro-manager/AcqEngJ/blob/fb96967aa5d0fecaf60182c18b458cd25f836ae1/src/main/java/org/micromanager/acqj/internal/Engine.java#L800

nicost commented 2 years ago

I believe that all cameras have to implement sequencing (in whatever way they like). The operator can always disable sequencing by setting an interval higher than the exposure time. Or there could be a way to feed information into the acquisition engine that sequencing is not desired in this case.

marktsuchida commented 2 years ago

The isExposureSequenceable() function determines whether the camera can load a sequence of (different) exposure times, and run a hardware-timed acquisition using the sequence. This is a rare and advanced feature (some PVCAM cameras support it). The function has nothing to do with whether cameras allow regular (uniform exposure) sequence acquisition; the answer to that question is assumed to be yes.

(I believe the Clojure acqEngine uses the non-uniform exposure sequencing, if available, in the case where different channels have different exposure settings.)

The behavior in the Clojure acqEngine is that sequence acquisition is preferred unless either (1) some device change (XY, Z, or channel, or autofocus) cannot be sequenced in hardware or (2) the acquisition's time interval setting is greater than (or equal to, IIRC) the total exposure time of the time point. The way to disable hardware sequencing within a time series time point is typically to set the Z or channel device's EnableSequencing (or similarly named) property to No.

henrypinkard commented 2 years ago

Gotcha, thanks for the clarifications. I guess everything is set up as it should be then.

Or there could be a way to feed information into the acquisition engine that sequencing is not desired in this case.

Yes that makes sense. It would be redundant the properties to enable/disable sequencing in the other devices involved, but it would have the nice benefit of standardizing things. This seems in general to be something that confuses people

tpeterson14 commented 2 years ago

Hi Henry -- I had to change my lab PC (which included an upgrade to Win10 from Win7) and ran into a new problem this morning. The acquisition does not run if I have multiple events at the same z-position. For example, these events will run without a problem:

{'axes': {'z': 0, 'i_SIM': 0}, 'z': 3992.887, 'x': 0, 'exposure': 100}
{'axes': {'z': 1, 'i_SIM': 0}, 'z': 3997.9790000000003, 'x': 1, 'exposure': 100}
{'axes': {'z': 2, 'i_SIM': 0}, 'z': 4003.071, 'x': 2, 'exposure': 100}
{'axes': {'z': 3, 'i_SIM': 0}, 'z': 4008.163, 'x': 3, 'exposure': 100}

But if I send these events (capturing 3 SIM images at each plane), the acquisition popup window goes straight to saying "Finished" without capturing any events or throwing an error. To my knowledge, the hook function is never called (I put a print statement in there that doesn't print):

{'axes': {'z': 0, 'i_SIM': 0}, 'z': 3992.887, 'x': 0, 'exposure': 100}
{'axes': {'z': 0, 'i_SIM': 1}, 'z': 3992.887, 'x': 1, 'exposure': 100}
{'axes': {'z': 0, 'i_SIM': 2}, 'z': 3992.887, 'x': 2, 'exposure': 100}
{'axes': {'z': 1, 'i_SIM': 0}, 'z': 3997.9790000000003, 'x': 3, 'exposure': 100}
{'axes': {'z': 1, 'i_SIM': 1}, 'z': 3997.9790000000003, 'x': 4, 'exposure': 100}
{'axes': {'z': 1, 'i_SIM': 2}, 'z': 3997.9790000000003, 'x': 5, 'exposure': 100}
{'axes': {'z': 2, 'i_SIM': 0}, 'z': 4003.071, 'x': 6, 'exposure': 100}
{'axes': {'z': 2, 'i_SIM': 1}, 'z': 4003.071, 'x': 7, 'exposure': 100}
{'axes': {'z': 2, 'i_SIM': 2}, 'z': 4003.071, 'x': 8, 'exposure': 100}
{'axes': {'z': 3, 'i_SIM': 0}, 'z': 4008.163, 'x': 9, 'exposure': 100}
{'axes': {'z': 3, 'i_SIM': 1}, 'z': 4008.163, 'x': 10, 'exposure': 100}
{'axes': {'z': 3, 'i_SIM': 2}, 'z': 4008.163, 'x': 11, 'exposure': 100}

However, when I click to exit the acquisition window, it gives me the "Finish Current Acquisition" popup and asks if I want to finish the acquisition. That doesn't usually happen when the acquisition captures the images and reports "Finished".

I'm using the most current pycromanager (0.17.8) and the 20220523 nightly build of MM. Any ideas of what might be causing this?

henrypinkard commented 2 years ago

I looked into it, and it seems that this arises from an exception in controlling hardware. When I run your code with the demo config, its because the 'z' position is out of range. If you change those to 'z': 1.887 etc, it works as expected.

There is likely an exception printed to the micromanager core log that describes more specifically whats going on, and i just wrote some code that I will push tonight so that in future versions, this exception will be propagated over to the python console as well.

I assume your problem is specific to your hardware, and I suspect it may have to do with the acquisition engine trying to sequence hardware over the same position. If you add in successive time delays to your events 'min_start_time': 0.00001, 'min_start_time': 0.00002, etc, it will turn off auto-sequencing so you can test this

tpeterson14 commented 2 years ago

Thanks for the suggestion, I'll try that out tomorrow morning when the new version is pushed out.

I checked the hardware configuration wizard to verify the travel range of my z-stage and noticed that the property names are "Position Upper/Lower Limit (um)". The values are set as 0 to 12, but that should be in mm (or 0 to 12,000 microns) for my setup, and I can't enter a value greater than 12.

Do you think the unit discrepancy could be causing the problem here?

henrypinkard commented 2 years ago

Its certainly possible

tpeterson14 commented 2 years ago

I tried the new nightly build this morning and see the same problem with these events:

{'axes': {'z': 0, 'i_SIM': 0}, 'z': 0.0, 'x': 0, 'exposure': 9, 'min_start_time': 1e-05}
{'axes': {'z': 0, 'i_SIM': 1}, 'z': 0.0, 'x': 1, 'exposure': 9, 'min_start_time': 2e-05}
{'axes': {'z': 0, 'i_SIM': 2}, 'z': 0.0, 'x': 2, 'exposure': 9, 'min_start_time': 3.0000000000000004e-05}
{'axes': {'z': 1, 'i_SIM': 0}, 'z': 0.9985, 'x': 3, 'exposure': 9, 'min_start_time': 4e-05}
{'axes': {'z': 1, 'i_SIM': 1}, 'z': 0.9985, 'x': 4, 'exposure': 9, 'min_start_time': 5e-05}
{'axes': {'z': 1, 'i_SIM': 2}, 'z': 0.9985, 'x': 5, 'exposure': 9, 'min_start_time': 6.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 0}, 'z': 1.997, 'x': 6, 'exposure': 9, 'min_start_time': 7.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 1}, 'z': 1.997, 'x': 7, 'exposure': 9, 'min_start_time': 8e-05}
{'axes': {'z': 2, 'i_SIM': 2}, 'z': 1.997, 'x': 8, 'exposure': 9, 'min_start_time': 9e-05}
{'axes': {'z': 3, 'i_SIM': 0}, 'z': 2.9955000000000003, 'x': 9, 'exposure': 9, 'min_start_time': 0.0001}
{'axes': {'z': 3, 'i_SIM': 1}, 'z': 2.9955000000000003, 'x': 10, 'exposure': 9, 'min_start_time': 0.00011}
{'axes': {'z': 3, 'i_SIM': 2}, 'z': 2.9955000000000003, 'x': 11, 'exposure': 9, 'min_start_time': 0.00012000000000000002}
{'axes': {'z': 4, 'i_SIM': 0}, 'z': 3.994, 'x': 12, 'exposure': 9, 'min_start_time': 0.00013000000000000002}
{'axes': {'z': 4, 'i_SIM': 1}, 'z': 3.994, 'x': 13, 'exposure': 9, 'min_start_time': 0.00014000000000000001}
{'axes': {'z': 4, 'i_SIM': 2}, 'z': 3.994, 'x': 14, 'exposure': 9, 'min_start_time': 0.00015000000000000001}

Note that I also set the 'z' positions to be within 0-4 microns to eliminate travel range as a variable. These same events run without a problem in the demo configuration.

How would you recommend identifying the source of my hardware problem? I don't receive an error message in python, the script just continues on to the next step as if no problem occurred.

(Also, please let me know if you want to move this discussion somewhere else -- I don't want to muddy the waters of this issue thread too much.)

henrypinkard commented 2 years ago

Did you pip update as well? That is needed to see the error message in python. You should be able to see it in the micromanager core log either way though

henrypinkard commented 2 years ago

(Also, please let me know if you want to move this discussion somewhere else -- I don't want to muddy the waters of this issue thread too much.)

fine by me to just continue here

tpeterson14 commented 2 years ago

Ah, no (oops) -- after a pip update and running these events:

{'axes': {'z': 0, 'i_SIM': 0}, 'z': 0.0, 'x': 0, 'exposure': 9, 'min_start_time': 1e-05}
{'axes': {'z': 0, 'i_SIM': 1}, 'z': 0.0, 'x': 1, 'exposure': 9, 'min_start_time': 2e-05}
{'axes': {'z': 0, 'i_SIM': 2}, 'z': 0.0, 'x': 2, 'exposure': 9, 'min_start_time': 3.0000000000000004e-05}
{'axes': {'z': 1, 'i_SIM': 0}, 'z': 1.0028000000000001, 'x': 3, 'exposure': 9, 'min_start_time': 4e-05}
{'axes': {'z': 1, 'i_SIM': 1}, 'z': 1.0028000000000001, 'x': 4, 'exposure': 9, 'min_start_time': 5e-05}
{'axes': {'z': 1, 'i_SIM': 2}, 'z': 1.0028000000000001, 'x': 5, 'exposure': 9, 'min_start_time': 6.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 0}, 'z': 2.0056000000000003, 'x': 6, 'exposure': 9, 'min_start_time': 7.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 1}, 'z': 2.0056000000000003, 'x': 7, 'exposure': 9, 'min_start_time': 8e-05}
{'axes': {'z': 2, 'i_SIM': 2}, 'z': 2.0056000000000003, 'x': 8, 'exposure': 9, 'min_start_time': 9e-05}
{'axes': {'z': 3, 'i_SIM': 0}, 'z': 3.0084000000000004, 'x': 9, 'exposure': 9, 'min_start_time': 0.0001}
{'axes': {'z': 3, 'i_SIM': 1}, 'z': 3.0084000000000004, 'x': 10, 'exposure': 9, 'min_start_time': 0.00011}
{'axes': {'z': 3, 'i_SIM': 2}, 'z': 3.0084000000000004, 'x': 11, 'exposure': 9, 'min_start_time': 0.00012000000000000002}
{'axes': {'z': 4, 'i_SIM': 0}, 'z': 4.0112000000000005, 'x': 12, 'exposure': 9, 'min_start_time': 0.00013000000000000002}
{'axes': {'z': 4, 'i_SIM': 1}, 'z': 4.0112000000000005, 'x': 13, 'exposure': 9, 'min_start_time': 0.00014000000000000001}
{'axes': {'z': 4, 'i_SIM': 2}, 'z': 4.0112000000000005, 'x': 14, 'exposure': 9, 'min_start_time': 0.00015000000000000001}
{'axes': {'z': 5, 'i_SIM': 0}, 'z': 5.014000000000001, 'x': 15, 'exposure': 9, 'min_start_time': 0.00016}
{'axes': {'z': 5, 'i_SIM': 1}, 'z': 5.014000000000001, 'x': 16, 'exposure': 9, 'min_start_time': 0.00017}
{'axes': {'z': 5, 'i_SIM': 2}, 'z': 5.014000000000001, 'x': 17, 'exposure': 9, 'min_start_time': 0.00018}

...I see this error:

Traceback (most recent call last):
  File "C:\Users\tyler\OneDrive - University of Arizona\Images2\TestFullscreenImage_v2.py", line 217, in run_acquisition
    stack.run()    
  File "C:\Users\tyler\OneDrive - University of Arizona\Images2\MMZStack.py", line 213, in run
    acq.acquire(self.events)
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\acquisitions.py", line 371, in __exit__
    self.await_completion()
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\acquisitions.py", line 474, in await_completion
    self._remote_acq.check_for_exceptions()
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\bridge.py", line 489, in <lambda>
    ): instance._translate_call(signatures_list, args, static = _java_class == 'java.lang.Class')
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\bridge.py", line 612, in _translate_call
    recieved = self._socket.receive()
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\bridge.py", line 175, in receive
    self._check_exception(message)
  File "C:\Users\tyler\AppData\Local\Programs\Python\Python39\lib\site-packages\pycromanager\bridge.py", line 180, in _check_exception
    raise Exception(response["value"])
Exception: java.lang.RuntimeException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.lang.Exception: No device with label ""
org.micromanager.acqj.internal.Engine.lambda$submitEventIterator$4(Engine.java:176)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
java.util.concurrent.FutureTask.run(FutureTask.java:266)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)

I can only make this happen if I try to do multiple SLM patterns at a single z-position. Do you know how to find out what hardware the engine is trying to communicate with that would be labeled ""?

henrypinkard commented 2 years ago

Maybe there is a stack trace with more description in the micromanager core log?

tpeterson14 commented 2 years ago

I ran these events (which throw the same python error in my previous comment):

{'axes': {'z': 0, 'i_SIM': 0}, 'z': 0.0, 'x': 0, 'exposure': 9, 'min_start_time': 1e-05}
{'axes': {'z': 0, 'i_SIM': 1}, 'z': 0.0, 'x': 1, 'exposure': 9, 'min_start_time': 2e-05}
{'axes': {'z': 0, 'i_SIM': 2}, 'z': 0.0, 'x': 2, 'exposure': 9, 'min_start_time': 3.0000000000000004e-05}
{'axes': {'z': 1, 'i_SIM': 0}, 'z': 1.0028000000000001, 'x': 3, 'exposure': 9, 'min_start_time': 4e-05}
{'axes': {'z': 1, 'i_SIM': 1}, 'z': 1.0028000000000001, 'x': 4, 'exposure': 9, 'min_start_time': 5e-05}
{'axes': {'z': 1, 'i_SIM': 2}, 'z': 1.0028000000000001, 'x': 5, 'exposure': 9, 'min_start_time': 6.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 0}, 'z': 2.0056000000000003, 'x': 6, 'exposure': 9, 'min_start_time': 7.000000000000001e-05}
{'axes': {'z': 2, 'i_SIM': 1}, 'z': 2.0056000000000003, 'x': 7, 'exposure': 9, 'min_start_time': 8e-05}
{'axes': {'z': 2, 'i_SIM': 2}, 'z': 2.0056000000000003, 'x': 8, 'exposure': 9, 'min_start_time': 9e-05}
{'axes': {'z': 3, 'i_SIM': 0}, 'z': 3.0084000000000004, 'x': 9, 'exposure': 9, 'min_start_time': 0.0001}
{'axes': {'z': 3, 'i_SIM': 1}, 'z': 3.0084000000000004, 'x': 10, 'exposure': 9, 'min_start_time': 0.00011}
{'axes': {'z': 3, 'i_SIM': 2}, 'z': 3.0084000000000004, 'x': 11, 'exposure': 9, 'min_start_time': 0.00012000000000000002}
{'axes': {'z': 4, 'i_SIM': 0}, 'z': 4.0112000000000005, 'x': 12, 'exposure': 9, 'min_start_time': 0.00013000000000000002}
{'axes': {'z': 4, 'i_SIM': 1}, 'z': 4.0112000000000005, 'x': 13, 'exposure': 9, 'min_start_time': 0.00014000000000000001}
{'axes': {'z': 4, 'i_SIM': 2}, 'z': 4.0112000000000005, 'x': 14, 'exposure': 9, 'min_start_time': 0.00015000000000000001}
{'axes': {'z': 5, 'i_SIM': 0}, 'z': 5.014000000000001, 'x': 15, 'exposure': 9, 'min_start_time': 0.00016}
{'axes': {'z': 5, 'i_SIM': 1}, 'z': 5.014000000000001, 'x': 16, 'exposure': 9, 'min_start_time': 0.00017}
{'axes': {'z': 5, 'i_SIM': 2}, 'z': 5.014000000000001, 'x': 17, 'exposure': 9, 'min_start_time': 0.00018}

And this is the CoreLog file that was generated:

2022-05-26T11:00:41.353756 tid23568 [IFO,LogManager] Enabled primary log file C:\Program Files\Micro-Manager-2.0\CoreLogs\CoreLog20220526T110041_pid19416.txt
2022-05-26T11:00:41.353756 tid23568 [IFO,App] User: tyler
2022-05-26T11:00:41.354143 tid23568 [IFO,App] Host: DESKTOP-2N8U8J5
2022-05-26T11:00:41.354143 tid23568 [IFO,App] MM Studio version: 2.0.1 20220524
2022-05-26T11:00:41.354143 tid23568 [IFO,App] MMCore version 10.2.0
2022-05-26T11:00:41.354143 tid23568 [IFO,App] Device API version 70, Module API version 10
2022-05-26T11:00:41.354143 tid23568 [IFO,App] Operating System: Windows 10 (amd64) 10.0
2022-05-26T11:00:41.354143 tid23568 [IFO,App] JVM: Java HotSpot(TM) 64-Bit Server VM, version 1.8.0_152, 64-bit
2022-05-26T11:00:41.684688 tid22152 [IFO,App] Found plugin org.micromanager.display.inspector.internal.panels.intensity.IntensityInspectorPanelPlugin@3bcc49b3
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.inspector.internal.panels.metadata.SummaryMetadataInspectorPanelPlugin@48355643
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.inspector.internal.panels.metadata.PlaneMetadataInspectorPanelPlugin@3e86502
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.inspector.internal.panels.comments.CommentsInspectorPanelPlugin@4333681e
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.overlay.internal.overlays.PatternOverlayPlugin@3a4cefd8
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.inspector.internal.panels.overlays.OverlaysInspectorPanelPlugin@62e70317
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.overlay.internal.overlays.ScaleBarPlugin@366526da
2022-05-26T11:00:41.685684 tid22152 [IFO,App] Found plugin org.micromanager.display.overlay.internal.overlays.TimestampPlugin@2e9e3685
2022-05-26T11:00:41.686680 tid22152 [IFO,App] Found plugin org.micromanager.acquisition.internal.DefaultMDAPlugin@73f13ea1
2022-05-26T11:00:41.686680 tid22152 [IFO,App] Found plugin org.micromanager.display.internal.gearmenu.CopyToImageJItem@29d46473
2022-05-26T11:00:41.686680 tid22152 [IFO,App] Found plugin org.micromanager.display.internal.gearmenu.ExportImagesItem@3698c465
2022-05-26T11:00:41.686680 tid22152 [IFO,App] Found plugin org.micromanager.display.internal.gearmenu.LineProfileItem@69edf62d
2022-05-26T11:00:41.687675 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.AutofocusButtons@62ad68c0
2022-05-26T11:00:41.687675 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.CloseAllButton@daf89ff
2022-05-26T11:00:41.688671 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.ExposureTime@543bc834
2022-05-26T11:00:41.689666 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.LiveButton@35f08e1f
2022-05-26T11:00:41.690662 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.MDAButtons@75ad86b5
2022-05-26T11:00:41.690662 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.PresetButton@3fddfbc1
2022-05-26T11:00:41.690662 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.RefreshButton@26dc5aa1
2022-05-26T11:00:41.691658 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.SavedMDAButton@46bd5fb2
2022-05-26T11:00:41.691658 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.ScriptButton@7f364952
2022-05-26T11:00:41.692655 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.ShutterControl@535ac9c9
2022-05-26T11:00:41.692655 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.SnapButton@866d84b
2022-05-26T11:00:41.692655 tid22152 [IFO,App] Found plugin org.micromanager.quickaccess.internal.controls.TextLabel@df74c0f
2022-05-26T11:00:41.692655 tid22152 [IFO,App] Plugin loading took 761ms
2022-05-26T11:00:41.692655 tid23568 [IFO,App] Finished waiting for plugins to load
2022-05-26T11:00:43.769457 tid23568 [IFO,Core] Did unload all devices
2022-05-26T11:00:43.770453 tid23568 [IFO,Core] Did unload all devices
2022-05-26T11:00:43.842136 tid23568 [IFO,Core] Did load device GenericSLM from GenericSLM; label = GenericSLM
2022-05-26T11:00:43.848110 tid23568 [IFO,Core] Did load device pco_camera from PCO_Camera; label = pco_camera
2022-05-26T11:00:59.732648 tid23568 [IFO,Core] Did load device TDC001 from ThorlabsAPTStage; label = TDC001
2022-05-26T11:00:59.732648 tid23568 [IFO,dev:TDC001] Channel number set to 1
2022-05-26T11:00:59.732648 tid23568 [IFO,dev:TDC001] TDC001-83839440 minTravelUm_ set to 0 pfMinPos:0 pfMaxPos:500
2022-05-26T11:00:59.732648 tid23568 [IFO,dev:TDC001] TDC001-83839440 maxTravelUm_ set to 12000 pfMinPos:0 pfMaxPos:500
2022-05-26T11:01:01.056214 tid23568 [IFO,dev:TDC001] TDC001-83839440 Serial number set to 83839440
2022-05-26T11:01:01.056214 tid23568 [IFO,Core] Will initialize 3 devices
2022-05-26T11:01:01.056214 tid23568 [IFO,Core] Will initialize device GenericSLM
2022-05-26T11:01:05.910490 tid23568 [IFO,Core] Did initialize device GenericSLM
2022-05-26T11:01:05.910490 tid23568 [IFO,Core] Default SLM set to GenericSLM
2022-05-26T11:01:05.910490 tid23568 [IFO,Core] Will initialize device pco_camera
2022-05-26T11:01:05.910490 tid23568 [IFO,dev:pco_camera] pco.sdk device adapter - V3,0,0,146
2022-05-26T11:01:11.232468 tid23568 [IFO,dev:pco_camera] pco_generic. Try to Init!
2022-05-26T11:01:11.629721 tid23568 [IFO,Core] Did initialize device pco_camera
2022-05-26T11:01:11.630717 tid23568 [IFO,Core] Default camera set to pco_camera
2022-05-26T11:01:11.630717 tid23568 [IFO,Core] Will initialize device TDC001
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 InitHWDevice()
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 pfMaxAccn:5 pfMaxVel:2.6
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 pfMinPos:0 pfMaxPos:12 plUnits:1 pfPitch:1
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 szModel:TDC001 szSWVer:SW Version 2.0.5 szHWNotes:TDC001 DC Servo Drive
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 Channel number set to 1
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 minTravelUm_ set to 0 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 maxTravelUm_ set to 12000 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:11.630717 tid23568 [IFO,dev:TDC001] TDC001-83839440 Serial number set to 83839440
2022-05-26T11:01:11.635695 tid23568 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:11.635695 tid23568 [IFO,dev:TDC001] TDC001-83839440 all done
2022-05-26T11:01:11.635695 tid23568 [IFO,Core] Did initialize device TDC001
2022-05-26T11:01:11.635695 tid23568 [IFO,Core] Finished initializing 3 devices
2022-05-26T11:01:11.635695 tid23568 [IFO,Core] Default camera set to pco_camera
2022-05-26T11:01:11.635695 tid23568 [IFO,Core] Default stage set to TDC001
2022-05-26T11:01:11.636691 tid23568 [IFO,dev:TDC001] TDC001-83839440 Channel number set to 1
2022-05-26T11:01:11.636691 tid23568 [IFO,dev:TDC001] TDC001-83839440 minTravelUm_ set to 0 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:11.636691 tid23568 [IFO,dev:TDC001] TDC001-83839440 maxTravelUm_ set to 12000 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:11.636691 tid23568 [IFO,dev:TDC001] TDC001-83839440 Serial number set to 83839440
2022-05-26T11:01:11.651641 tid23568 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:11.652617 tid23568 [IFO,Core] Did update system state cache
2022-05-26T11:01:12.153414 tid23568 [IFO,App] EDTHangLogger: Started monitoring of EDT hangs
                                    [       ] [heartbeat timeout = 4500 ms, hang check interval = 1000 ms]
2022-05-26T11:01:12.617370 tid23568 [IFO,App] Rebuilding config group table
2022-05-26T11:01:12.617370 tid23568 [IFO,App] Finished rebuilding config group table
2022-05-26T11:01:12.633303 tid23568 [IFO,App] Startup script (C:\Program Files\Micro-Manager-2.0\MMStartup.bsh) not present
2022-05-26T11:01:12.633303 tid23568 [IFO,App] Updating GUI; config pad = true; from cache = false
2022-05-26T11:01:12.643256 tid23568 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:12.645248 tid23568 [IFO,dev:TDC001] TDC001-83839440 Channel number set to 1
2022-05-26T11:01:12.645248 tid23568 [IFO,dev:TDC001] TDC001-83839440 minTravelUm_ set to 0 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:12.645248 tid23568 [IFO,dev:TDC001] TDC001-83839440 maxTravelUm_ set to 12000 pfMinPos:0 pfMaxPos:12
2022-05-26T11:01:12.645248 tid23568 [IFO,dev:TDC001] TDC001-83839440 Serial number set to 83839440
2022-05-26T11:01:12.658190 tid23568 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:12.659186 tid23568 [IFO,Core] Did update system state cache
2022-05-26T11:01:12.662173 tid23568 [IFO,App] Rebuilding config group table
2022-05-26T11:01:12.662173 tid23568 [IFO,App] Finished rebuilding config group table
2022-05-26T11:01:12.662173 tid23568 [IFO,App] Finished updating GUI
2022-05-26T11:01:13.628695 tid23568 [IFO,App] Initialized ZMQ Server on port: 4827
2022-05-26T11:01:19.402237 tid30916 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:24.613097 tid30916 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T11:01:28.516377 tid30916 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:0 continuousFlag:1
2022-05-26T11:01:29.103386 tid30916 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:0
2022-05-26T11:01:32.364296 tid30916 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:0
2022-05-26T11:05:23.178786 tid23568 [IFO,App] EDTHangLogger: Stopping monitoring of EDT hangs
2022-05-26T11:05:23.178786 tid23568 [IFO,dev:TDC001] TDC001-83839440 Shutdown()
2022-05-26T11:05:27.704009 tid23568 [IFO,Core] Did unload all devices
2022-05-26T11:05:27.704009 tid23568 [IFO,Core] System reset
2022-05-26T11:05:27.744828 tid23568 [IFO,Core] Core session ended

For reference, here's the ending of the CoreLog when I only capture one image per z-position:

2022-05-26T10:44:43.553894 tid31800 [IFO,App] Initialized ZMQ Server on port: 4827
2022-05-26T10:45:18.782471 tid23328 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:0
2022-05-26T10:45:25.447017 tid23328 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:0
2022-05-26T10:45:32.292337 tid23328 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:5 continuousFlag:1
2022-05-26T10:45:33.197364 tid23328 [IFO,dev:TDC001] TDC001-83839440 GetPositionUm:5.01399
2022-05-26T10:45:37.943445 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:0 continuousFlag:1
2022-05-26T10:45:40.675585 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:1.0028 continuousFlag:1
2022-05-26T10:45:41.299141 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:2.0056 continuousFlag:1
2022-05-26T10:45:41.906429 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:3.0084 continuousFlag:1
2022-05-26T10:45:42.658067 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:4.0112 continuousFlag:1
2022-05-26T10:45:43.297444 tid32444 [IFO,dev:TDC001] TDC001-83839440 SetPositionUm:5.014 continuousFlag:1
2022-05-26T10:47:25.901637 tid31800 [IFO,App] EDTHangLogger: Stopping monitoring of EDT hangs
2022-05-26T10:47:25.902632 tid31800 [IFO,dev:TDC001] TDC001-83839440 Shutdown()
2022-05-26T10:47:28.574675 tid31800 [IFO,Core] Did unload all devices
2022-05-26T10:47:28.574675 tid31800 [IFO,Core] System reset
2022-05-26T10:47:28.610517 tid31800 [IFO,Core] Core session ended

It seems like it isn't sending the SetPositionUm call to TCD001 after the 0um position -- do you see anything actionable in this?

henrypinkard commented 2 years ago

Huh. Weird that it doesnt have a stack trace in there.

Maybe it is having an error when trying to set position, which causes the acq to abort. There might also be something useful if you turn on Acquistion(core_log_debug=True.

To test this, you could try making a new configuration where you replace that Z drive with the demo Z drive, but run the same events. This could reveal if it is specifically your z drive

tpeterson14 commented 2 years ago

Embarrassing fix incoming...

Turns out I forgot to re-add the DHub DemoXYStage to my new configuration on the new PC, which I use to force the acquisition to capture multiple images at each z-position. So that must have been the empty-string device that the engine was trying in vain to communicate with.

I would have thought that would cause the 1-capture-per-z acquisition to fail as well, since it's also present in those events, but I guess not.

henrypinkard commented 2 years ago

Happens to the best of us!

I've been meaning to add in an option to turn off sequencing so you don't need to use this hack.

Though If you could come up with a minimal example of this happening without having to use hardware, it would be great to be able to fix it or at at least add a more informative error