# Murfey logs
```
(mc-feedback) [slg25752@ws466 murfey]$ murfey.server --feedback -e devrmq
[09/02/22 12:50:54] INFO Starting Murfey RabbitMQ thread __init__.py:150
INFO Starting Murfey server version 0.5.10 for beamline m12, listening on 0.0.0.0:8000 __init__.py:154
INFO Started server process [3336154] server.py:82
INFO Waiting for application startup. on.py:45
INFO Application startup complete. on.py:59
INFO Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit) server.py:215
/scratch/slg25752/python-murfey/src/murfey/server/ispyb.py:178: SAWarning: relationship 'BLSession.BeamCalendar1' will copy column BeamCalendar.beamCalendarId to column BLSession.beamCalendarId, which conflicts with relationship(s): 'BLSession.BeamCalendar' (copies BeamCalendar.beamCalendarId to BLSession.beamCalendarId). If this is not the intention, consider if these relationships should be linked with back_populates, or if viewonly=True should be applied to one or more if they are read-only. For the less common case that foreign key constraints are partially overlapping, the orm.foreign() annotation can be used to isolate the columns that should be written towards. To silence this warning, add the parameter 'overlaps="BeamCalendar"' to the 'BLSession.BeamCalendar1' relationship. (Background on this error at: https://sqlalche.me/e/14/qzyx)
db.query(BLSession)
[09/02/22 12:50:57] INFO ('127.0.0.1', 33610) - "WebSocket /ws/test/21" [accepted] websockets_impl.py:218
INFO connection open server.py:641
INFO Sending 'Client 21 joined' websocket.py:35
INFO State attribute 'Client 21' set to 'joined' websocket.py:50
INFO Starting Websocket connection __init__.py:205
INFO Opened connection websocket.py:145
INFO Received message: '{"message": "state-full", "state": {}}' websocket.py:105
INFO Received message: 'Client 21 joined' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "Client 21", "value": "joined"}' websocket.py:105
INFO Murfey 0.5.10 on Python 3.9.9 entering main loop __init__.py:297
[09/02/22 12:51:07] INFO RSync thread starting for <RSyncer /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input → /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4 (ready) rsync.py:99
INFO RSync thread starting rsync.py:121
INFO Analyser thread starting for <murfey.client.analyser.Analyser object at 0x7fb5f289e4c0> analyser.py:162
INFO Analyser thread started analyser.py:70
[09/02/22 12:51:47] INFO File extension determined: .mrc analyser.py:40
INFO Context found successfully: detector analyser.py:88
INFO New tilt series found: 66 context.py:198
[09/02/22 12:51:48] INFO Preparing to transfer 1 files rsync.py:143
[09/02/22 12:52:03] INFO Context found successfully: detector, /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_14_005[6.00]_Fractions.xml analyser.py:116
INFO New tilt series found: 41 context.py:198
INFO The following tilt series are considered complete: ['41', '66'] context.py:273
INFO File 'Position_66_015[-21.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
INFO Completed transfer of 1 files rsync.py:155
INFO Preparing to transfer 4 files rsync.py:143
INFO File 'Position_14_005[6.00]_Fractions.xml' successfully transferred (10656 bytes) app.py:501
INFO File 'Position_17_009[12.00]_Fractions.xml' successfully transferred (10654 bytes) app.py:501
INFO File 'Position_29_015[-21.00]_Fractions.xml' successfully transferred (10653 bytes) app.py:501
[09/02/22 12:52:07] INFO File 'Position_41_010[15.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
INFO Completed transfer of 4 files rsync.py:155
[09/02/22 12:52:26] INFO New tilt series found: 43 context.py:198
INFO The following tilt series are considered complete: ['43'] context.py:273
INFO Preparing to transfer 6 files rsync.py:143
[09/02/22 12:52:32] INFO Registering data collection group on microscope m12 main.py:378
[09/02/22 12:52:33] INFO Created DataCollectionGroup 7854121 ispyb.py:56
INFO Received message: '{"message": "state-update", "attribute": "data_collection_group_id", "value": 7854121}' websocket.py:105
INFO Starting data collection on microscope m12 main.py:403
INFO Starting data collection on microscope m12 main.py:403
INFO Created DataCollection 8842906 ispyb.py:78
INFO Starting data collection on microscope m12 main.py:403
[09/02/22 12:52:34] INFO Created DataCollection 8842907 ispyb.py:78
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"66": 8842906}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '66'} main.py:442
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '66'} main.py:442
INFO Created DataCollection 8842908 ispyb.py:78
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"66": 8842906, "41": 8842907}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '41'} main.py:442
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146569 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '41'} main.py:442
INFO Creating database entries... ispyb.py:100
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"66": 8842906, "41": 8842907, "43": 8842908}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '43'} main.py:442
INFO All done. Processing job 12146570 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Creating database entries... ispyb.py:100
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '43'} main.py:442
INFO All done. Processing job 12146571 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146569}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276933}}' websocket.py:105
INFO Creating database entries... ispyb.py:100
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146570}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276934}}' websocket.py:105
INFO All done. Processing job 12146572 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146573 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146574 created ispyb.py:103
INFO Sending Zocalo message {'recipes': ['em-tomo-preprocess'], 'parameters': {'dcid': 8842906, 'autoproc_program_id': 91276933, 'movie': main.py:262
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/Position_66_015[-21.00]_Fractions.mrc', 'mrc_out':
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/MotionCorr/Position_66_015[-21.00]_Fractions_motion_corrected.mrc', 'pix_size': 1.2076827,
'output_image': '/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/CTF/Position_66_015[-21.00]_Fractions_ctf.mrc', 'image_number': 1,
'microscope': 'm12', 'mc_uuid': 2, 'movie_uuid': 1}}
INFO Updating program None with status None ispyb.py:126
INFO Sending 'Pre-processing requested for Position_66_015[-21.00]_Fractions.mrc' websocket.py:35
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146570, "41": 12146571}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276934, "41": 91276935}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146570, "41": 12146572}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276934, "41": 91276936}}' websocket.py:105
INFO Sending Zocalo message {'recipes': ['em-tomo-preprocess'], 'parameters': {'dcid': 8842907, 'autoproc_program_id': 91276935, 'movie': main.py:262
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/Position_41_010[15.00]_Fractions.mrc', 'mrc_out':
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/MotionCorr/Position_41_010[15.00]_Fractions_motion_corrected.mrc', 'pix_size': 1.2076827,
'output_image': '/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/CTF/Position_41_010[15.00]_Fractions_ctf.mrc', 'image_number': 2,
'microscope': 'm12', 'mc_uuid': 4, 'movie_uuid': 3}}
INFO Sending 'Pre-processing requested for Position_41_010[15.00]_Fractions.mrc' websocket.py:35
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146570, "41": 12146572, "43": 12146573}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276934, "41": 91276936, "43": 91276937}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"66": 12146570, "41": 12146572, "43": 12146574}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"66": 91276934, "41": 91276936, "43": 91276938}}' websocket.py:105
INFO Received message: 'Pre-processing requested for Position_66_015[-21.00]_Fractions.mrc' websocket.py:105
INFO Received message: 'Pre-processing requested for Position_41_010[15.00]_Fractions.mrc' websocket.py:105
[09/02/22 12:52:43] INFO New tilt series found: 55 context.py:198
INFO The following tilt series are considered complete: ['55'] context.py:273
[09/02/22 12:53:00] INFO Tilt series 55 was previously thought complete but now /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_55_031[-45.00]_Fractions.mrc has been context.py:193
seen
[09/02/22 12:53:16] INFO New tilt series found: 59 context.py:198
INFO The following tilt series are considered complete: ['55'] context.py:273
[09/02/22 12:53:19] INFO File 'Position_22.mrc' successfully transferred (1241543424 bytes) app.py:501
INFO File 'Position_28_004[-6.00]_Fractions.xml' successfully transferred (10655 bytes) app.py:501
INFO File 'Position_33.mdoc' successfully transferred (25634 bytes) app.py:501
[09/02/22 12:53:34] INFO New tilt series found: 10 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 12:53:36] INFO File 'Position_43_005[6.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
INFO File 'Position_70_018[27.00]_Fractions.xml' successfully transferred (10649 bytes) app.py:501
[09/02/22 12:53:39] INFO File 'Position_87_019[-27.00]_Fractions.xml' successfully transferred (10652 bytes) app.py:501
INFO Completed transfer of 6 files rsync.py:155
INFO Preparing to transfer 11 files rsync.py:143
INFO File 'Position_10_012[-18.00]_Fractions.xml' successfully transferred (10648 bytes) app.py:501
[09/02/22 12:53:53] INFO File 'Position_10_034[51.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
INFO File 'Position_22_024[-36.00]_Fractions.xml' successfully transferred (10650 bytes) app.py:501
INFO File 'Position_25_026[39.00]_Fractions.xml' successfully transferred (10655 bytes) app.py:501
[09/02/22 12:54:10] INFO New tilt series found: 20 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
INFO Tilt series 66 was previously thought complete but now /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_66_034[51.00]_Fractions.mrc has been context.py:193
seen
INFO The following tilt series are considered complete: ['66'] context.py:273
[09/02/22 12:54:46] INFO Waiting for ongoing transfers to complete... rsync.py:106
INFO New tilt series found: 17 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 12:54:54] INFO File 'Position_4.mrc' successfully transferred (1241543424 bytes) app.py:501
INFO File 'Position_44_021[30.00]_Fractions.xml' successfully transferred (10653 bytes) app.py:501
INFO File 'Position_45.mdoc' successfully transferred (25644 bytes) app.py:501
[09/02/22 12:55:07] INFO New tilt series found: 2 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 12:55:08] INFO File 'Position_55_031[-45.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
[09/02/22 12:55:28] INFO New tilt series found: 88 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 12:55:29] INFO File 'Position_55_034[51.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
[09/02/22 12:55:40] INFO File 'Position_59_028[-42.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
[09/02/22 12:55:43] INFO File 'Position_81_016[-24.00]_Fractions.xml' successfully transferred (10655 bytes) app.py:501
INFO Completed transfer of 11 files rsync.py:155
[09/02/22 12:55:47] INFO Preparing to transfer 7 files rsync.py:143
INFO New tilt series found: 71 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 12:55:54] INFO File 'Position_17_012[-18.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:501
INFO File 'Position_18.mdoc' successfully transferred (25636 bytes) app.py:501
^C INFO Shutting down server.py:261
INFO Disconnecting Client 21 websocket.py:82
INFO State attribute 'Client 21' removed websocket.py:54
INFO connection closed server.py:259
INFO Waiting for application shutdown. on.py:64
INFO Application shutdown complete. on.py:75
INFO Finished server process [3336154] server.py:92
INFO Server shutting down
```
Part 2 (file disappeared when I cleared the directory)
```
(mc-feedback) [slg25752@ws466 murfey]$ murfey.server --feedback -e devrmq
[09/02/22 14:44:38] INFO Starting Murfey RabbitMQ thread __init__.py:150
INFO Starting Murfey server version 0.5.11 for beamline m12, listening on 0.0.0.0:8000 __init__.py:154
INFO Started server process [3426288] server.py:82
INFO Waiting for application startup. on.py:45
INFO Application startup complete. on.py:59
INFO Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit) server.py:215
/scratch/slg25752/python-murfey/src/murfey/server/ispyb.py:178: SAWarning: relationship 'BLSession.BeamCalendar1' will copy column BeamCalendar.beamCalendarId to column BLSession.beamCalendarId, which conflicts with relationship(s): 'BLSession.BeamCalendar' (copies BeamCalendar.beamCalendarId to BLSession.beamCalendarId). If this is not the intention, consider if these relationships should be linked with back_populates, or if viewonly=True should be applied to one or more if they are read-only. For the less common case that foreign key constraints are partially overlapping, the orm.foreign() annotation can be used to isolate the columns that should be written towards. To silence this warning, add the parameter 'overlaps="BeamCalendar"' to the 'BLSession.BeamCalendar1' relationship. (Background on this error at: https://sqlalche.me/e/14/qzyx)
db.query(BLSession)
[09/02/22 14:44:41] INFO ('127.0.0.1', 37346) - "WebSocket /ws/test/84" [accepted] websockets_impl.py:218
INFO connection open server.py:641
INFO Sending 'Client 84 joined' websocket.py:35
INFO State attribute 'Client 84' set to 'joined' websocket.py:51
INFO Starting Websocket connection __init__.py:205
INFO Opened connection websocket.py:145
INFO Received message: '{"message": "state-full", "state": {}}' websocket.py:105
INFO Received message: 'Client 84 joined' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "Client 84", "value": "joined"}' websocket.py:105
INFO Murfey 0.5.11 on Python 3.9.9 entering main loop __init__.py:297
[09/02/22 14:44:44] INFO RSync thread starting for <RSyncer /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input → /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4 (ready) rsync.py:99
INFO RSync thread starting rsync.py:121
INFO Analyser thread starting for <murfey.client.analyser.Analyser object at 0x7f9126e98100> analyser.py:162
INFO Analyser thread started analyser.py:70
[09/02/22 14:45:40] INFO File extension determined: .mrc analyser.py:40
INFO Context found successfully: detector, /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_41_010[15.00]_Fractions.mrc analyser.py:116
INFO New tilt series found: 41 context.py:198
INFO Context found successfully: detector, /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_66_015[-21.00]_Fractions.mrc analyser.py:116
INFO New tilt series found: 66 context.py:198
INFO The following tilt series are considered complete: ['66', '41'] context.py:273
INFO Preparing to transfer 5 files rsync.py:143
INFO File 'Position_14_005[6.00]_Fractions.xml' successfully transferred (10656 bytes) app.py:509
INFO File 'Position_17_009[12.00]_Fractions.xml' successfully transferred (10654 bytes) app.py:509
INFO File 'Position_29_015[-21.00]_Fractions.xml' successfully transferred (10653 bytes) app.py:509
[09/02/22 14:45:41] INFO File 'Position_41_010[15.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:509
[09/02/22 14:46:02] INFO File 'Position_66_015[-21.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:509
INFO Completed transfer of 5 files rsync.py:155
INFO Context found successfully: detector, /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_22.mrc analyser.py:116
INFO Context found successfully: detector, /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_28_004[-6.00]_Fractions.xml analyser.py:116
INFO New tilt series found: 43 context.py:198
INFO The following tilt series are considered complete: ['43'] context.py:273
INFO Preparing to transfer 6 files rsync.py:143
[09/02/22 14:46:10] INFO Registering data collection group on microscope m12 main.py:378
INFO Created DataCollectionGroup 7854128 ispyb.py:56
INFO Received message: '{"message": "state-update", "attribute": "data_collection_group_id", "value": 7854128}' websocket.py:105
INFO Starting data collection on microscope m12 main.py:403
INFO Starting data collection on microscope m12 main.py:403
INFO Created DataCollection 8842915 ispyb.py:78
INFO Starting data collection on microscope m12 main.py:403
INFO Created DataCollection 8842916 ispyb.py:78
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"41": 8842915}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '41'} main.py:442
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '41'} main.py:442
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"41": 8842915, "66": 8842916}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '66'} main.py:442
[09/02/22 14:46:11] INFO Created DataCollection 8842917 ispyb.py:78
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '66'} main.py:442
INFO Received message: '{"message": "state-update", "attribute": "data_collection_ids", "value": {"41": 8842915, "66": 8842916, "43": 8842917}}' websocket.py:105
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-preprocess', 'tag': '43'} main.py:442
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146587 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Send processing registration message to murfey_feedback: {'recipe': 'em-tomo-align', 'tag': '43'} main.py:442
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146588 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146587}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276951}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146588}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276952}}' websocket.py:105
INFO Creating database entries... ispyb.py:100
INFO Sending Zocalo message {'recipes': ['em-tomo-preprocess'], 'parameters': {'dcid': 8842915, 'autoproc_program_id': 91276951, 'movie': main.py:262
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/Position_41_010[15.00]_Fractions.mrc', 'mrc_out':
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/MotionCorr/Position_41_010[15.00]_Fractions_motion_corrected.mrc', 'pix_size': 1.2076827,
'output_image': '/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/CTF/Position_41_010[15.00]_Fractions_ctf.mrc', 'image_number': 1,
'microscope': 'm12', 'mc_uuid': 2, 'movie_uuid': 1}}
INFO All done. Processing job 12146589 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Sending 'Pre-processing requested for Position_41_010[15.00]_Fractions.mrc' websocket.py:35
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146588, "66": 12146589}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276952, "66": 91276953}}' websocket.py:105
INFO Received message: 'Pre-processing requested for Position_41_010[15.00]_Fractions.mrc' websocket.py:105
INFO Creating database entries... ispyb.py:100
[09/02/22 14:46:12] INFO All done. Processing job 12146590 created ispyb.py:103
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146588, "66": 12146590}}' websocket.py:105
INFO Updating program None with status None ispyb.py:126
INFO Creating database entries... ispyb.py:100
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276952, "66": 91276954}}' websocket.py:105
INFO Sending Zocalo message {'recipes': ['em-tomo-preprocess'], 'parameters': {'dcid': 8842916, 'autoproc_program_id': 91276953, 'movie': main.py:262
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/Position_66_015[-21.00]_Fractions.mrc', 'mrc_out':
'/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/MotionCorr/Position_66_015[-21.00]_Fractions_motion_corrected.mrc', 'pix_size': 1.2076827,
'output_image': '/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/cm31111-4/processed/CTF/Position_66_015[-21.00]_Fractions_ctf.mrc', 'image_number': 2,
'microscope': 'm12', 'mc_uuid': 4, 'movie_uuid': 3}}
INFO All done. Processing job 12146591 created ispyb.py:103
INFO Updating program None with status None ispyb.py:126
INFO Sending 'Pre-processing requested for Position_66_015[-21.00]_Fractions.mrc' websocket.py:35
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146588, "66": 12146590, "43": 12146591}}' websocket.py:105
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276952, "66": 91276954, "43": 91276955}}' websocket.py:105
INFO Received message: 'Pre-processing requested for Position_66_015[-21.00]_Fractions.mrc' websocket.py:105
INFO Creating database entries... ispyb.py:100
INFO All done. Processing job 12146592 created ispyb.py:103
INFO Received message: '{"message": "state-update", "attribute": "processing_job_ids", "value": {"41": 12146588, "66": 12146590, "43": 12146592}}' websocket.py:105
INFO Updating program None with status None ispyb.py:126
INFO Received message: '{"message": "state-update", "attribute": "autoproc_program_ids", "value": {"41": 91276952, "66": 91276954, "43": 91276956}}' websocket.py:105
[09/02/22 14:46:22] INFO New tilt series found: 55 context.py:198
INFO The following tilt series are considered complete: ['55'] context.py:273
[09/02/22 14:46:41] INFO Tilt series 55 was previously thought complete but now /dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_55_031[-45.00]_Fractions.mrc has been context.py:193
seen
[09/02/22 14:46:53] INFO File 'Position_22.mrc' successfully transferred (1241543424 bytes) app.py:509
INFO File 'Position_28_004[-6.00]_Fractions.xml' successfully transferred (10655 bytes) app.py:509
INFO File 'Position_33.mdoc' successfully transferred (25634 bytes) app.py:509
[09/02/22 14:46:58] INFO New tilt series found: 59 context.py:198
INFO The following tilt series are considered complete: ['55'] context.py:273
[09/02/22 14:46:59] INFO Waiting for ongoing transfers to complete... rsync.py:106
[09/02/22 14:47:01] INFO File 'Position_43_005[6.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:509
INFO File 'Position_70_018[27.00]_Fractions.xml' successfully transferred (10649 bytes) app.py:509
[09/02/22 14:47:04] INFO File 'Position_87_019[-27.00]_Fractions.xml' successfully transferred (10652 bytes) app.py:509
INFO Completed transfer of 6 files rsync.py:155
INFO Preparing to transfer 10 files rsync.py:143
INFO File 'Position_10_012[-18.00]_Fractions.xml' successfully transferred (10648 bytes) app.py:509
INFO File 'Position_22_024[-36.00]_Fractions.xml' successfully transferred (10650 bytes) app.py:509
INFO File 'Position_25_026[39.00]_Fractions.xml' successfully transferred (10655 bytes) app.py:509
[09/02/22 14:47:13] INFO New tilt series found: 10 context.py:198
INFO The following tilt series are considered complete: [] context.py:273
[09/02/22 14:47:24] INFO File 'Position_4.mrc' successfully transferred (1241543424 bytes) app.py:509
INFO File 'Position_44_021[30.00]_Fractions.xml' successfully transferred (10653 bytes) app.py:509
INFO File 'Position_45.mdoc' successfully transferred (25644 bytes) app.py:509
[09/02/22 14:47:29] INFO File 'Position_55_031[-45.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:509
[09/02/22 14:47:35] ERROR file has vanished: "/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_59_028[-42.00]_Fractions.mrc" rsync.py:255
[09/02/22 14:47:39] INFO File 'Position_55_034[51.00]_Fractions.mrc' successfully transferred (335554560 bytes) app.py:509
ERROR file has vanished: "/dls/ebic/data/staff-scratch/AnnaH/murfey_demo/input/Position_81_016[-24.00]_Fractions.xml" rsync.py:255
ERROR rsync warning: some files vanished before they could be transferred (code 24) at main.c(1189) [sender=3.1.3] rsync.py:255
WARNING Failed to transfer file 'Position_81_016[-24.00]_Fractions.xml' app.py:513
WARNING Failed to transfer file 'Position_59_028[-42.00]_Fractions.mrc' app.py:513
WARNING rsync process finished with return code 24 rsync.py:303
INFO Completed transfer of 10 files rsync.py:155
INFO Waiting 1 seconds before next rsync attempt rsync.py:166
[09/02/22 14:47:40] INFO RSync thread finished rsync.py:169
^C[09/02/22 14:47:45] INFO Shutting down server.py:261
INFO Disconnecting Client 84 websocket.py:83
INFO State attribute 'Client 84' removed websocket.py:55
INFO connection closed server.py:259
INFO Waiting for application shutdown. on.py:64
INFO Application shutdown complete. on.py:75
INFO Finished server process [3426288] server.py:92
INFO Server shutting down
```