NSLS-II / Bug-Reports

Unified issue-tracker for bugs in the data acquisition, management, and analysis software at NSLS-II
BSD 3-Clause "New" or "Revised" License
2 stars 5 forks source link

Another instance of function not executing at it is defined in memory. #165

Closed ambarb closed 7 years ago

ambarb commented 7 years ago

@tacaswell @danielballan This is the 2nd or 3rd time that I have seen this behavior at the endstation. This has also happened with .ipynb with functions defined in a cell. Please advise me on how to avoid this situation (alternatively, I will quit python seesions before defining a function.)

FYI @cmazzoli @wen-hu

I defined a function (without print or sleep on the second two lines). I realized that I needed to change a value because the sample is different for the sz. After I corrected the sz, nothing new happened (that is sz did not move). I then added a print statement and a bp.sleep(). The print statement did not happen and the bp.sleep() typo did not generate an error. The function just simply did the scan. The function is defined in memory to perform a print sz position, sleep, and then move sz. Restart of bsui corrected this issue. I would like to know what I am doing to make this happen to me so often.

In [341]: RE(FS_O(516))
^CA 'deferred pause' has been requested. The RunEngine will pause at the next checkpoint. To pause immediately, hit Ctrl+C again in the next 10 seconds.
Deferred pause acknowledged. Continuing to checkpoint.
^C
Your RunEngine is entering a paused state. These are your options for changing
the state of the RunEngine:

RE.resume()    Resume the plan.
RE.abort()     Perform cleanup, then kill plan. Mark exit_stats='aborted'.
RE.stop()      Perform cleanup, then kill plan. Mark exit_status='success'.
RE.halt()      Emergency Stop: Do not perform cleanup --- just stop.

Pausing...
Out[341]: []

In [342]: RE.abort()
Aborting: running cleanup and marking exit_status as 'abort'...

In [343]: 

Here is where i realized i needed to correct the sz conditional statement. I did so. I later realized that delta, theta and gamma did not move.

Below, sz is at 0.83 so i should move sz -0.3 relataive. It does not. Then I added a print statement to see if it would print the position. It does not. It also does not catch the typo in the sleep line.

In [343]: %run -i scan_defs.py

In [344]: %run -i scan_defs.py

In [345]: FS_refO??
Signature: FS_refO(en=0)
Source:   
def FS_refO(en=0):
    print(sz.readback.value)
    bs.sleep(1)
    sz_pos = sz.readback.value
    if sz_pos > 0.53:
        print('Moving sample out of the beam from sz = ',sz.readback.value, 'for O Kedge reference')
        yield from bp.rel_set(sz,-0.3,wait=False)
    print('Moving detector, sample theta, and to TiO2 target (531eV).')
    caput('XF:23ID1-ES{Diag:1-Ax:Y}Mtr.VAL',-97)
    if fccd in gs.DETS:
        gs.DETS.remove(fccd)
        gs.TABLE_COLS = ['sclr_ch2','sclr_ch3']; gs.PLOT_Y = 'sclr_ch2'
    yield from mv(theta,0, delta, 40, gamma, 30)
    if en !=0:
        yield from mv(pgm_en, en)
    yield from dscan(pgm_en,-6,6,24)
    print('Scan finished. Positions of sample and detector motor will not move back. ')
File:      ~/Users/2017_02_May/scan_defs.py
Type:      function

In [346]: RE(FS_O(516))
Transient Scan ID: 75398 @ 2017/03/02 14:31:35
Persistent Unique Scan ID: '806f6fbf-45e7-4320-8e91-ada377ca7e2f'
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1486: UserWarning: ca.get_timevars('XF:23ID1-OP{Mono}Enrgy-SP') timed out after 5.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
+-----------+------------+------------+---------------------+------------------------+-------------------+------------+-------------------+------------+
|   seq_num |       time |     energy | pgm_energy_setpoint | pgm_energy_stop_signal | fccd_stats4_total |     temp_b | fccd_stats3_total |   sclr_ch3 |
+-----------+------------+------------+---------------------+------------------------+-------------------+------------+-------------------+------------+
|         1 | 14:32:38.1 |    495.051 |             509.400 |                      0 |          -2766502 |     32.208 |            -17451 |        141 |
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1248: UserWarning: ca.get('XF:23ID1-OP{Mono-Ax:GrtP}Mtr.TDIR') timed out after 1.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
|         2 | 14:32:43.6 |    509.369 |             509.579 |                      0 |          -2435827 |     32.207 |             -3583 |        141 |
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1248: UserWarning: ca.get('XF:23ID1-OP{Mono-Ax:GrtP}Mtr.HLS') timed out after 1.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
|         3 | 14:32:50.4 |    509.538 |             509.759 |                      0 |          -2664061 |     32.206 |            -30605 |        141 |
|         4 | 14:32:58.4 |    509.754 |             509.938 |                      0 |          -2409881 |     32.204 |            -10974 |        142 |
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1248: UserWarning: ca.get('XF:23ID1-OP{Mono-Ax:GrtP}Mtr.LLS') timed out after 1.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
|         5 | 14:33:03.5 |    509.994 |             510.118 |                      0 |          -1904163 |     32.203 |              8645 |        141 |
|         6 | 14:33:11.4 |    510.048 |             510.297 |                      0 |          -2240472 |     32.203 |             -6155 |        141 |
|         7 | 14:33:16.0 |    510.255 |             510.477 |                      0 |          -1617910 |     32.205 |              6503 |        141 |
|         8 | 14:33:24.0 |    510.508 |             510.656 |                      0 |          -1629540 |     32.205 |             13747 |        141 |
|         9 | 14:33:29.2 |    510.644 |             510.836 |                      0 |          -1028991 |     32.203 |             27089 |        141 |
|        10 | 14:33:37.2 |    510.846 |             511.015 |                      0 |          -2760816 |     32.207 |            -22826 |        143 |
|        11 | 14:33:42.5 |    511.039 |             511.195 |                      0 |          -2442726 |     32.208 |            -28165 |        141 |
|        12 | 14:33:50.0 |    511.443 |             511.374 |                      0 |          -1882084 |     32.205 |              4439 |        141 |
|        13 | 14:33:59.4 |    511.559 |             511.554 |                      0 |          -2073761 |     32.206 |             -8269 |        141 |
|        14 | 14:34:06.8 |    511.759 |             511.733 |                      0 |          -1727430 |     32.204 |             -4626 |        143 |
|        15 | 14:34:16.4 |    511.943 |             511.913 |                      0 |          -1917442 |     32.204 |              1569 |        142 |
|        16 | 14:34:23.9 |    512.071 |             512.092 |                      0 |          -2615417 |     32.203 |            -18226 |        142 |
|        17 | 14:34:33.8 |    512.256 |             512.272 |                      0 |          -1066066 |     32.205 |             12434 |        141 |
|        18 | 14:34:41.8 |    512.466 |             512.451 |                      0 |           -993216 |     32.204 |             13569 |        142 |
|        19 | 14:34:51.0 |    512.545 |             512.631 |                      0 |          -2610628 |     32.207 |            -13834 |        141 |
|        20 | 14:34:58.6 |    512.898 |             512.810 |                      0 |           -895097 |     32.209 |             19632 |        141 |
|        21 | 14:35:08.2 |    512.997 |             512.990 |                      0 |          -1420527 |     32.204 |             14048 |        141 |
|        22 | 14:35:15.8 |    513.155 |             513.169 |                      0 |          -2417265 |     32.203 |            -10306 |        142 |
|        23 | 14:35:25.8 |    513.401 |             513.349 |                      0 |          -1480974 |     32.203 |              3192 |        141 |
|        24 | 14:35:33.2 |    513.516 |             513.528 |                      0 |           -689106 |     32.208 |             25603 |        142 |
|        25 | 14:35:42.4 |    513.630 |             513.708 |                      0 |          -1290303 |     32.207 |             17439 |        141 |
|        26 | 14:35:50.0 |    513.918 |             513.887 |                      0 |          -1501357 |     32.205 |             14173 |        140 |
|        27 | 14:35:59.4 |    514.046 |             514.067 |                      0 |          -1550378 |     32.208 |             22007 |        142 |
|        28 | 14:36:07.0 |    514.270 |             514.246 |                      0 |          -2117540 |     32.206 |            -18811 |        142 |
|        29 | 14:36:16.4 |    514.491 |             514.426 |                      0 |          -2090053 |     32.203 |             -8015 |        143 |
|        30 | 14:36:24.0 |    514.640 |             514.605 |                      0 |          -1798767 |     32.203 |            -15458 |        143 |
|        31 | 14:36:33.5 |    514.701 |             514.785 |                      0 |           -643854 |     32.201 |             26886 |        141 |
|        32 | 14:36:41.2 |    514.889 |             514.964 |                      0 |           -881419 |     32.205 |             25893 |        141 |
|        33 | 14:36:51.2 |    515.127 |             515.144 |                      0 |          -1714905 |     32.206 |             20791 |        141 |
|        34 | 14:36:59.2 |    515.335 |             515.323 |                      0 |          -1831476 |     32.203 |             -4376 |        141 |
|        35 | 14:37:08.6 |    515.516 |             515.503 |                      0 |          -2373871 |     32.206 |            -12975 |        141 |
|        36 | 14:37:16.4 |    515.725 |             515.682 |                      0 |          -1751818 |     32.206 |              8888 |        141 |
|        37 | 14:37:25.8 |    515.827 |             515.862 |                      0 |          -1348162 |     32.209 |              8540 |        142 |
|        38 | 14:37:34.8 |    516.134 |             516.041 |                      0 |          -2035874 |     32.212 |              2333 |        140 |
|        39 | 14:37:44.4 |    516.218 |             516.221 |                      0 |           -319583 |     32.206 |             24112 |        140 |
|        40 | 14:37:52.4 |    516.362 |             516.400 |                      0 |          -1749562 |     32.204 |             -7318 |        140 |
|        41 | 14:38:01.8 |    516.612 |             516.579 |                      0 |           -850986 |     32.202 |             15263 |        140 |
|        42 | 14:38:09.5 |    516.707 |             516.759 |                      0 |          -2117893 |     32.202 |             11291 |        140 |
|        43 | 14:38:18.8 |    516.970 |             516.938 |                      0 |          -1519901 |     32.207 |             46229 |        140 |
|        44 | 14:38:26.4 |    517.099 |             517.118 |                      0 |          -1673497 |     32.205 |              3674 |        140 |
^CA 'deferred pause' has been requested. The RunEngine will pause at the next checkpoint. To pause immediately, hit Ctrl+C again in the next 10 seconds.
Deferred pause acknowledged. Continuing to checkpoint.
^C|        45 | 14:38:35.9 |    517.179 |             517.297 |                      0 |          -1160769 |     32.204 |              6624 |        140 |

Your RunEngine is entering a paused state. These are your options for changing
the state of the RunEngine:

RE.resume()    Resume the plan.
RE.abort()     Perform cleanup, then kill plan. Mark exit_stats='aborted'.
RE.stop()      Perform cleanup, then kill plan. Mark exit_status='success'.
RE.halt()      Emergency Stop: Do not perform cleanup --- just stop.

Pausing...
Out[346]: ['806f6fbf-45e7-4320-8e91-ada377ca7e2f']

In [347]: RE.abort()
Aborting: running cleanup and marking exit_status as 'abort'...

In [348]: print(sz.readback.value)
0.8290014236900652

In [349]: FS_refO??
Signature: FS_refO(en=0)
Source:   
def FS_refO(en=0):
    print(sz.readback.value)
    bs.sleep(1)
    sz_pos = sz.readback.value
    if sz_pos > 0.53:
        print('Moving sample out of the beam from sz = ',sz.readback.value, 'for O Kedge reference')
        yield from bp.rel_set(sz,-0.3,wait=False)
    print('Moving detector, sample theta, and to TiO2 target (531eV).')
    caput('XF:23ID1-ES{Diag:1-Ax:Y}Mtr.VAL',-97)
    if fccd in gs.DETS:
        gs.DETS.remove(fccd)
        gs.TABLE_COLS = ['sclr_ch2','sclr_ch3']; gs.PLOT_Y = 'sclr_ch2'
    yield from mv(theta,0, delta, 40, gamma, 30)
    if en !=0:
        yield from mv(pgm_en, en)
    yield from dscan(pgm_en,-6,6,24)
    print('Scan finished. Positions of sample and detector motor will not move back. ')
File:      ~/Users/2017_02_May/scan_defs.py
Type:      function

exit bsui session and restart seemed to fixed (and correctly found my typo on third line of function definition after printing the sz position.

In [9]: %run -i scan_defs.py

In [10]: RE(FS_refO(516))
0.8290014236900652
name 'bs' is not defined
---------------------------------------------------------------------------

Below that bs was not defined and I corrected the typo.. Line 12 shows successful update of definition.

NameError: name 'bs' is not defined

In [11]: %run -i scan_defs.py

In [12]: RE(FS_refO(516))
0.8290014236900652
Moving sample out of the beam from sz =  0.8290014236900652 for O Kedge reference
Moving detector, sample theta, and to TiO2 target (531eV).
Transient Scan ID: 75399 @ 2017/03/02 15:01:11
Persistent Unique Scan ID: 'b18c391c-7b7a-4a0e-99b6-606119824373'
+-----------+------------+------------+---------------------+------------------------+
|   seq_num |       time |     energy | pgm_energy_setpoint | pgm_energy_stop_signal |
+-----------+------------+------------+---------------------+------------------------+
|         1 | 15:01:22.6 |    510.021 |             509.998 |                      0 |
|         2 | 15:01:32.0 |    510.427 |             510.498 |                      0 |
|         3 | 15:01:41.7 |    511.021 |             510.998 |                      0 |
|         4 | 15:01:50.9 |    511.497 |             511.498 |                      0 |
|         5 | 15:02:00.7 |    512.000 |             511.998 |                      0 |
|         6 | 15:02:10.0 |    512.502 |             512.498 |                      0 |
|         7 | 15:02:19.8 |    512.990 |             512.998 |                      0 |
|         8 | 15:02:29.1 |    513.518 |             513.498 |                      0 |
|         9 | 15:02:38.4 |    514.016 |             513.998 |                      0 |
|        10 | 15:02:47.8 |    514.462 |             514.498 |                      0 |
^CA 'deferred pause' has been requested. The RunEngine will pause at the next checkpoint. To pause immediately, hit Ctrl+C again in the next 10 seconds.
Deferred pause acknowledged. Continuing to checkpoint.
^C
Your RunEngine is entering a paused state. These are your options for changing
the state of the RunEngine:

RE.resume()    Resume the plan.
RE.abort()     Perform cleanup, then kill plan. Mark exit_stats='aborted'.
RE.stop()      Perform cleanup, then kill plan. Mark exit_status='success'.
RE.halt()      Emergency Stop: Do not perform cleanup --- just stop.

Pausing...
Out[12]: ['b18c391c-7b7a-4a0e-99b6-606119824373']

In [13]: RE.abort()
Aborting: running cleanup and marking exit_status as 'abort'...
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1486: UserWarning: ca.get_timevars('XF:23ID1-OP{Mono}Enrgy-SP') timed out after 5.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
/opt/conda_envs/collection-17Q1.0/lib/python3.5/site-packages/epics/ca.py:1486: UserWarning: ca.get_timevars('XF:23ID1-OP{Mono}Cmd:Stop-Cmd') timed out after 5.00 seconds.
  warnings.warn(msg % (name(chid), timeout))
name 'bs' is not defined
---------------------------------------------------------------------------
FailedStatus                              Traceback (most recent call last)
/home/xf23id1/Users/2017_02_May/scan_defs.py in <module>()
danielballan commented 7 years ago

I think I see the problem. You are editing a function named FS_refO but (sometimes) you are running a completely different function named FS_O. Is that the whole problem?

ambarb commented 7 years ago

ugh yes. As you can see, we are tired. I reversed search and was not paying close attention. Should have been obvious with the number of points.

cowanml commented 7 years ago

On Thu, 2 Mar 2017, ambarb wrote:

ugh yes. As you can see, we are tired. I reversed search and was not paying close attention. Should have been obvious with the number of points.

On other occasions you may have hit the issue where the docstring gets updated but not the def if you reimport but not reload?

%autoreload can be nice -matt


foo.py

def lala(): "lala prints woof" print "woo"

In [1]: import foo

In [2]: foo.lala?? Type: function String Form:<function lala at 0x1a31230> File: /tmp/blarf/foo.py Definition: foo.lala() Source: def lala(): "lala prints woof" print "woo"

In [3]: foo.lala() woo


edited foo.py

def lala(): "lala prints woof!" print "woot"

In [4]: import foo

In [5]: foo.lala?? Type: function String Form:<function lala at 0x1a31230> File: /tmp/blarf/foo.py Definition: foo.lala() Source: def lala(): "lala prints woof!" print "woot"

In [6]: foo.lala() woo

In [7]: reload(foo) Out[7]: <module 'foo' from 'foo.py'>

In [8]: foo.lala?? Type: function String Form:<function lala at 0x1a312a8> File: /tmp/blarf/foo.py Definition: foo.lala() Source: def lala(): "lala prints woof!" print "woot"

In [9]: foo.lala() woot