2022-08-31T14:05:33.064Z,1661954733.064 [NAL9602](INFO): Received command: restart logs 2022-08-31T14:05:33.081Z,1661954733.081 [CommandExec](IMPORTANT): got command restart logs 2022-08-31T14:05:43.531Z,1661954743.531 [NAL9602](INFO): SBD MO Status=1, MOMSN=44397, MT Status=0, MTMSN=0 2022-08-31T14:05:43.588Z,1661954743.588 [NAL9602](INFO): Sent 52 bytes from file Logs/20220831T134209/Courier0016.lzma 2022-08-31T14:05:43.588Z,1661954743.588 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:05:52.594Z,1661954752.594 [NAL9602](INFO): SBD MO Status=1, MOMSN=44398, MT Status=0, MTMSN=0 2022-08-31T14:05:52.648Z,1661954752.648 [NAL9602](INFO): Sent 119 bytes from file Logs/20220831T134209/Express0014.lzma 2022-08-31T14:05:52.648Z,1661954752.648 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:06:07.695Z,1661954767.695 [NAL9602](INFO): SBD MO Status=2, MOMSN=44399, MT Status=2, MTMSN=0 2022-08-31T14:06:07.696Z,1661954767.696 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T14:06:27.582Z,1661954787.582 [NAL9602](INFO): SBD MO Status=1, MOMSN=44399, MT Status=0, MTMSN=0 2022-08-31T14:06:27.636Z,1661954787.636 [NAL9602](INFO): Sent 108 bytes from file Logs/20220831T134209/Express0017.lzma 2022-08-31T14:06:27.636Z,1661954787.636 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:06:43.682Z,1661954803.682 [NAL9602](INFO): SBD MO Status=0, MOMSN=44400, MT Status=0, MTMSN=0 2022-08-31T14:06:56.759Z,1661954816.759 [NAL9602](INFO): SBD MO Status=1, MOMSN=44401, MT Status=0, MTMSN=0 2022-08-31T14:06:56.808Z,1661954816.808 [NAL9602](INFO): Sent 169 bytes from file Logs/20220831T140533/Courier0000.lzma 2022-08-31T14:06:56.808Z,1661954816.808 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:07:07.402Z,1661954827.402 [NAL9602](INFO): SBD MO Status=1, MOMSN=44402, MT Status=0, MTMSN=0 2022-08-31T14:07:07.464Z,1661954827.464 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0001.lzma 2022-08-31T14:07:07.464Z,1661954827.464 [NAL9602](INFO): Packets left to send: 1 2022-08-31T14:07:16.643Z,1661954836.643 [NAL9602](INFO): SBD MO Status=1, MOMSN=44403, MT Status=0, MTMSN=0 2022-08-31T14:07:16.700Z,1661954836.700 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T140533/Express0001.lzma 2022-08-31T14:07:16.700Z,1661954836.700 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:07:37.171Z,1661954857.171 [NAL9602](INFO): SBD MO Status=0, MOMSN=44404, MT Status=0, MTMSN=0 2022-08-31T14:07:37.249Z,1661954857.249 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T14:07:37.249Z,1661954857.249 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T14:07:37.249Z,1661954857.249 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:08:07.874Z,1661954887.874 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T14:12:09.068Z,1661955129.068 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T14:12:09.073Z,1661955129.073 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831141209.430441,06,714,22,0127,0150,194,02,02,01,02,-1,-01,-01,1,3,7,0,150,14.9,0.07,-100,2.93,-01,0.53,59,14500,4000*45 2022-08-31T14:12:37.763Z,1661955157.763 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T14:12:37.763Z,1661955157.763 [Default:CheckIn:C.Wait] Stopped 2022-08-31T14:12:37.764Z,1661955157.764 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:12:37.764Z,1661955157.764 [Default:CheckIn:D] Running Loop=1 2022-08-31T14:12:38.223Z,1661955158.223 [Default:CheckIn:D] Stopped 2022-08-31T14:12:38.227Z,1661955158.227 [Default:CheckIn:E] Running Loop=1 2022-08-31T14:12:38.614Z,1661955158.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.651137 min 2022-08-31T14:12:38.615Z,1661955158.615 [Default:CheckIn:E] Stopped 2022-08-31T14:12:38.615Z,1661955158.615 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T14:12:38.615Z,1661955158.615 [Default:CheckIn] Stopped 2022-08-31T14:12:38.615Z,1661955158.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T14:12:38.615Z,1661955158.615 [Default:CheckIn](INFO): Running loop #4 2022-08-31T14:12:38.631Z,1661955158.631 [Default:CheckIn] Running Loop=4 2022-08-31T14:12:38.631Z,1661955158.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T14:12:38.632Z,1661955158.632 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T14:12:40.605Z,1661955160.605 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141247.00,A,4015.14481,N,07115.18833,W,0.525,322.55,310822,,,A*79 2022-08-31T14:12:40.607Z,1661955160.607 [NAL9602](INFO): GPS fix at 20220831T141247: (40.252414, -71.253139) 2022-08-31T14:12:40.669Z,1661955160.669 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T14:12:40.669Z,1661955160.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T14:12:52.920Z,1661955172.920 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T14:12:53.334Z,1661955173.334 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831141251.434318,06,1325,25,0122,0150,208,02,02,01,02,4,-01,-01,2,3,1,0,150,2.0,-0.46,-100,3.46,-01,-3.80,62,14500,4000*6E 2022-08-31T14:12:54.943Z,1661955174.943 [NAL9602](INFO): SBD MO Status=1, MOMSN=44405, MT Status=0, MTMSN=0 2022-08-31T14:12:55.008Z,1661955175.008 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Courier0003.lzma 2022-08-31T14:12:55.008Z,1661955175.008 [NAL9602](INFO): Packets left to send: 1 2022-08-31T14:13:05.804Z,1661955185.804 [NAL9602](INFO): SBD MO Status=1, MOMSN=44406, MT Status=0, MTMSN=0 2022-08-31T14:13:05.852Z,1661955185.852 [NAL9602](INFO): Sent 39 bytes from file Logs/20220831T140533/Courier0003.lzma 2022-08-31T14:13:05.852Z,1661955185.852 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:13:16.400Z,1661955196.400 [NAL9602](INFO): SBD MO Status=1, MOMSN=44407, MT Status=0, MTMSN=0 2022-08-31T14:13:16.449Z,1661955196.449 [NAL9602](INFO): Sent 152 bytes from file Logs/20220831T140533/Express0004.lzma 2022-08-31T14:13:16.449Z,1661955196.449 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:13:27.142Z,1661955207.142 [NAL9602](INFO): SBD MO Status=0, MOMSN=44408, MT Status=0, MTMSN=0 2022-08-31T14:13:27.220Z,1661955207.220 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T14:13:27.220Z,1661955207.220 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T14:13:27.220Z,1661955207.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:13:57.869Z,1661955237.869 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T14:14:20.888Z,1661955260.888 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T14:14:20.894Z,1661955260.894 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831141421.442982,06,618,21,0109,0150,141,01,01,01,01,-1,-01,-01,1,3,5,0,150,28.1,0.06,-100,2.94,-01,-3.39,52,14500,4000*6D 2022-08-31T14:15:23.102Z,1661955323.102 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31 2022-08-31T14:15:23.107Z,1661955323.107 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831141523.422950,06,1295,25,0105,0150,208,01,01,01,01,-1,-01,-01,1,3,4,0,150,18.5,0.18,-100,2.82,-01,-2.50,62,14500,4000*52 2022-08-31T14:15:54.612Z,1661955354.612 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T14:16:32.582Z,1661955392.582 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:18:01.479Z,1661955481.479 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:18:27.746Z,1661955507.746 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T14:18:27.746Z,1661955507.746 [Default:CheckIn:C.Wait] Stopped 2022-08-31T14:18:27.746Z,1661955507.746 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:18:27.746Z,1661955507.746 [Default:CheckIn:D] Running Loop=1 2022-08-31T14:18:28.153Z,1661955508.153 [Default:CheckIn:D] Stopped 2022-08-31T14:18:28.153Z,1661955508.153 [Default:CheckIn:E] Running Loop=1 2022-08-31T14:18:28.594Z,1661955508.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.483313 min 2022-08-31T14:18:28.594Z,1661955508.594 [Default:CheckIn:E] Stopped 2022-08-31T14:18:28.595Z,1661955508.595 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T14:18:28.595Z,1661955508.595 [Default:CheckIn] Stopped 2022-08-31T14:18:28.595Z,1661955508.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T14:18:28.595Z,1661955508.595 [Default:CheckIn](INFO): Running loop #5 2022-08-31T14:18:28.595Z,1661955508.595 [Default:CheckIn] Running Loop=5 2022-08-31T14:18:28.599Z,1661955508.599 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T14:18:28.599Z,1661955508.599 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T14:18:30.550Z,1661955510.550 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141837.00,A,4015.15700,N,07115.24109,W,0.603,298.69,310822,,,A*78 2022-08-31T14:18:30.552Z,1661955510.552 [NAL9602](INFO): GPS fix at 20220831T141837: (40.252617, -71.254018) 2022-08-31T14:18:30.618Z,1661955510.618 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T14:18:30.618Z,1661955510.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T14:18:50.873Z,1661955530.873 [NAL9602](INFO): SBD MO Status=1, MOMSN=44409, MT Status=0, MTMSN=0 2022-08-31T14:18:50.932Z,1661955530.932 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0006.lzma 2022-08-31T14:18:50.932Z,1661955530.932 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:18:58.679Z,1661955538.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=44410, MT Status=0, MTMSN=0 2022-08-31T14:18:58.740Z,1661955538.740 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0007.lzma 2022-08-31T14:18:58.740Z,1661955538.740 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:19:01.418Z,1661955541.418 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T14:19:15.137Z,1661955555.137 [NAL9602](INFO): SBD MO Status=0, MOMSN=44411, MT Status=0, MTMSN=0 2022-08-31T14:19:15.216Z,1661955555.216 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T14:19:15.216Z,1661955555.216 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T14:19:15.216Z,1661955555.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:19:45.829Z,1661955585.829 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T14:24:15.732Z,1661955855.732 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T14:24:15.732Z,1661955855.732 [Default:CheckIn:C.Wait] Stopped 2022-08-31T14:24:15.732Z,1661955855.732 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:24:15.733Z,1661955855.733 [Default:CheckIn:D] Running Loop=1 2022-08-31T14:24:16.157Z,1661955856.157 [Default:CheckIn:D] Stopped 2022-08-31T14:24:16.158Z,1661955856.158 [Default:CheckIn:E] Running Loop=1 2022-08-31T14:24:16.582Z,1661955856.582 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.283390 min 2022-08-31T14:24:16.582Z,1661955856.582 [Default:CheckIn:E] Stopped 2022-08-31T14:24:16.583Z,1661955856.583 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T14:24:16.583Z,1661955856.583 [Default:CheckIn] Stopped 2022-08-31T14:24:16.583Z,1661955856.583 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T14:24:16.583Z,1661955856.583 [Default:CheckIn](INFO): Running loop #6 2022-08-31T14:24:16.583Z,1661955856.583 [Default:CheckIn] Running Loop=6 2022-08-31T14:24:16.587Z,1661955856.587 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T14:24:16.587Z,1661955856.587 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T14:24:18.549Z,1661955858.549 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142425.00,A,4015.16417,N,07115.26827,W,0.680,146.44,310822,,,A*71 2022-08-31T14:24:18.552Z,1661955858.552 [NAL9602](INFO): GPS fix at 20220831T142425: (40.252736, -71.254471) 2022-08-31T14:24:18.612Z,1661955858.612 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T14:24:18.612Z,1661955858.612 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T14:24:42.643Z,1661955882.643 [NAL9602](INFO): SBD MO Status=1, MOMSN=44412, MT Status=0, MTMSN=0 2022-08-31T14:24:42.696Z,1661955882.696 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0009.lzma 2022-08-31T14:24:42.696Z,1661955882.696 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:24:52.857Z,1661955892.857 [NAL9602](INFO): SBD MO Status=1, MOMSN=44413, MT Status=0, MTMSN=0 2022-08-31T14:24:52.912Z,1661955892.912 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0010.lzma 2022-08-31T14:24:52.912Z,1661955892.912 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:25:02.256Z,1661955902.256 [NAL9602](INFO): SBD MO Status=0, MOMSN=44414, MT Status=0, MTMSN=0 2022-08-31T14:25:02.388Z,1661955902.388 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T14:25:02.388Z,1661955902.388 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T14:25:02.388Z,1661955902.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:25:32.956Z,1661955932.956 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T14:30:02.832Z,1661956202.832 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T14:30:02.832Z,1661956202.832 [Default:CheckIn:C.Wait] Stopped 2022-08-31T14:30:02.832Z,1661956202.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:30:02.833Z,1661956202.833 [Default:CheckIn:D] Running Loop=1 2022-08-31T14:30:03.242Z,1661956203.242 [Default:CheckIn:D] Stopped 2022-08-31T14:30:03.242Z,1661956203.242 [Default:CheckIn:E] Running Loop=1 2022-08-31T14:30:03.657Z,1661956203.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.068132 min 2022-08-31T14:30:03.657Z,1661956203.657 [Default:CheckIn:E] Stopped 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn] Stopped 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn](INFO): Running loop #7 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn] Running Loop=7 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T14:30:03.658Z,1661956203.658 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T14:30:05.643Z,1661956205.643 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143012.00,A,4015.12528,N,07115.21964,W,0.039,157.49,310822,,,A*71 2022-08-31T14:30:05.645Z,1661956205.645 [NAL9602](INFO): GPS fix at 20220831T143012: (40.252088, -71.253661) 2022-08-31T14:30:05.656Z,1661956205.656 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T14:30:05.656Z,1661956205.656 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T14:30:19.543Z,1661956219.543 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=44415, MT Status=1, MTMSN=1686 2022-08-31T14:30:19.604Z,1661956219.604 [NAL9602](INFO): Sent 71 bytes from file Logs/20220831T140533/Courier0012.lzma 2022-08-31T14:30:19.604Z,1661956219.604 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:30:20.233Z,1661956220.233 [NAL9602](INFO): Received command: load Maintenance/ballast_and_trim.tl;set ballast_and_trim.MissionTimeout 60 min;set ballast_and_trim.Depth1 10 m;set ballast_and_trim.MinAltitude 3 m;set ballast_and_trim.MaxDepth 13 m;run 2022-08-31T14:30:20.324Z,1661956220.324 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T14:30:20.324Z,1661956220.324 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T14:30:20.324Z,1661956220.324 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Maintenance/ballast_and_trim.tx 2022-08-31T14:30:20.555Z,1661956220.555 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 90.000000 min 2022-08-31T14:30:20.558Z,1661956220.558 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool 2022-08-31T14:30:20.561Z,1661956220.561 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 35.000000 m 2022-08-31T14:30:20.576Z,1661956220.576 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m 2022-08-31T14:30:20.578Z,1661956220.578 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m 2022-08-31T14:30:20.585Z,1661956220.585 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSpeed = 1.000000 m/s 2022-08-31T14:30:20.589Z,1661956220.589 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthTimeout = 20.000000 min 2022-08-31T14:30:20.600Z,1661956220.600 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthRate = 0.400000 m/s 2022-08-31T14:30:20.602Z,1661956220.602 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachPitchLimit = 20.000000 arcdeg 2022-08-31T14:30:20.617Z,1661956220.617 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSettleTimePreDive = 0.000000 min 2022-08-31T14:30:20.621Z,1661956220.621 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min 2022-08-31T14:30:20.633Z,1661956220.633 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min 2022-08-31T14:30:20.640Z,1661956220.640 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min 2022-08-31T14:30:20.643Z,1661956220.643 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm 2022-08-31T14:30:20.654Z,1661956220.654 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc 2022-08-31T14:30:20.657Z,1661956220.657 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 % 2022-08-31T14:30:20.668Z,1661956220.668 [MissionManager](INFO): DefineArg ballast_and_trim.massDeadband = 0.250000 mm 2022-08-31T14:30:20.671Z,1661956220.671 [MissionManager](INFO): DefineArg ballast_and_trim.MinAltitude = 5.000000 m 2022-08-31T14:30:20.678Z,1661956220.678 [MissionManager](INFO): DefineArg ballast_and_trim.MaxDepth = 52.000000 m 2022-08-31T14:30:20.681Z,1661956220.681 [MissionManager](INFO): DefineArg ballast_and_trim.MinOffshore = 2.000000 km 2022-08-31T14:30:20.703Z,1661956220.703 [MissionManager](INFO): DefineArg ballast_and_trim.CheckDepths = 1.000000 bool 2022-08-31T14:30:20.704Z,1661956220.704 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml 2022-08-31T14:30:22.674Z,1661956222.674 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool 2022-08-31T14:30:22.694Z,1661956222.694 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min 2022-08-31T14:30:22.720Z,1661956222.720 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool 2022-08-31T14:30:22.723Z,1661956222.723 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool 2022-08-31T14:30:22.729Z,1661956222.729 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool 2022-08-31T14:30:22.749Z,1661956222.749 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool 2022-08-31T14:30:22.814Z,1661956222.814 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool 2022-08-31T14:30:22.825Z,1661956222.825 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count 2022-08-31T14:30:22.866Z,1661956222.866 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count 2022-08-31T14:30:22.902Z,1661956222.902 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 % 2022-08-31T14:30:22.925Z,1661956222.925 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool 2022-08-31T14:30:22.936Z,1661956222.936 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool 2022-08-31T14:30:22.938Z,1661956222.938 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool 2022-08-31T14:30:22.957Z,1661956222.957 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool 2022-08-31T14:30:22.968Z,1661956222.968 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2022-08-31T14:30:22.975Z,1661956222.975 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool 2022-08-31T14:30:22.979Z,1661956222.979 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool 2022-08-31T14:30:22.993Z,1661956222.993 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool 2022-08-31T14:30:23.009Z,1661956223.009 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 0 bool 2022-08-31T14:30:23.049Z,1661956223.049 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 1 bool 2022-08-31T14:30:23.057Z,1661956223.057 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool 2022-08-31T14:30:23.064Z,1661956223.064 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count 2022-08-31T14:30:23.101Z,1661956223.101 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count 2022-08-31T14:30:23.112Z,1661956223.112 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m 2022-08-31T14:30:23.115Z,1661956223.115 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m 2022-08-31T14:30:23.146Z,1661956223.146 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m 2022-08-31T14:30:23.198Z,1661956223.198 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l 2022-08-31T14:30:23.217Z,1661956223.217 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m 2022-08-31T14:30:23.232Z,1661956223.232 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC 2022-08-31T14:30:23.235Z,1661956223.235 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg 2022-08-31T14:30:23.250Z,1661956223.250 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg 2022-08-31T14:30:23.284Z,1661956223.284 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l 2022-08-31T14:30:23.297Z,1661956223.297 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m 2022-08-31T14:30:23.312Z,1661956223.312 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg 2022-08-31T14:30:23.328Z,1661956223.328 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg 2022-08-31T14:30:23.331Z,1661956223.331 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3 2022-08-31T14:30:23.354Z,1661956223.354 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m 2022-08-31T14:30:23.373Z,1661956223.373 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg 2022-08-31T14:30:23.384Z,1661956223.384 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg 2022-08-31T14:30:23.387Z,1661956223.387 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb 2022-08-31T14:30:23.402Z,1661956223.402 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m 2022-08-31T14:30:23.414Z,1661956223.414 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC 2022-08-31T14:30:23.430Z,1661956223.430 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg 2022-08-31T14:30:23.523Z,1661956223.523 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg 2022-08-31T14:30:23.526Z,1661956223.526 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m 2022-08-31T14:30:23.537Z,1661956223.537 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu 2022-08-31T14:30:23.545Z,1661956223.545 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m 2022-08-31T14:30:23.556Z,1661956223.556 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC 2022-08-31T14:30:23.559Z,1661956223.559 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg 2022-08-31T14:30:23.594Z,1661956223.594 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg 2022-08-31T14:30:23.609Z,1661956223.609 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l 2022-08-31T14:30:23.621Z,1661956223.621 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m 2022-08-31T14:30:23.636Z,1661956223.636 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg 2022-08-31T14:30:23.639Z,1661956223.639 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg 2022-08-31T14:30:23.680Z,1661956223.680 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m 2022-08-31T14:30:23.683Z,1661956223.683 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu 2022-08-31T14:30:23.702Z,1661956223.702 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m 2022-08-31T14:30:23.709Z,1661956223.709 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg 2022-08-31T14:30:23.720Z,1661956223.720 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg 2022-08-31T14:30:23.726Z,1661956223.726 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m 2022-08-31T14:30:23.729Z,1661956223.729 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu 2022-08-31T14:30:23.740Z,1661956223.740 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m 2022-08-31T14:30:23.743Z,1661956223.743 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg 2022-08-31T14:30:23.750Z,1661956223.750 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg 2022-08-31T14:30:23.762Z,1661956223.762 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m 2022-08-31T14:30:23.946Z,1661956223.946 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T14:30:24.001Z,1661956224.001 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T14:30:24.062Z,1661956224.062 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T14:30:24.108Z,1661956224.108 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T14:30:24.126Z,1661956224.126 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T14:30:24.149Z,1661956224.149 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T14:30:24.173Z,1661956224.173 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T14:30:24.248Z,1661956224.248 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T14:30:24.267Z,1661956224.267 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml 2022-08-31T14:30:24.431Z,1661956224.431 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.DiveInterval = 3.000000 h 2022-08-31T14:30:24.434Z,1661956224.434 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.WaitForPitchUp = 10.000000 min 2022-08-31T14:30:24.446Z,1661956224.446 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfacePitch = 20.000000 arcdeg 2022-08-31T14:30:24.454Z,1661956224.454 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceDepthRate = nan m/s 2022-08-31T14:30:24.461Z,1661956224.461 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceSpeed = 1.000000 m/s 2022-08-31T14:30:24.480Z,1661956224.480 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.GPSTimeout = 7.000000 min 2022-08-31T14:30:24.492Z,1661956224.492 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.CommsTimeout = 30.000000 min 2022-08-31T14:30:24.515Z,1661956224.515 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-08-31T14:30:24.565Z,1661956224.565 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml 2022-08-31T14:30:24.626Z,1661956224.626 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinAltitude = 5.000000 m 2022-08-31T14:30:24.642Z,1661956224.642 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MaxDepth = 200.000000 m 2022-08-31T14:30:24.649Z,1661956224.649 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinOffshore = 2000.000000 m 2022-08-31T14:30:24.650Z,1661956224.650 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2022-08-31T14:30:24.682Z,1661956224.682 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2022-08-31T14:30:24.724Z,1661956224.724 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2022-08-31T14:30:24.774Z,1661956224.774 [ballast_and_trim:CheckTargetDepths:CheckDepth1:B.Execute](DEBUG): Construct Execute. 2022-08-31T14:30:24.794Z,1661956224.794 [ballast_and_trim:CheckTargetDepths:CheckDepth2:B.Execute](DEBUG): Construct Execute. 2022-08-31T14:30:24.817Z,1661956224.817 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml 2022-08-31T14:30:25.072Z,1661956225.072 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m 2022-08-31T14:30:25.074Z,1661956225.074 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s 2022-08-31T14:30:25.086Z,1661956225.086 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s 2022-08-31T14:30:25.093Z,1661956225.093 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg 2022-08-31T14:30:25.112Z,1661956225.112 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min 2022-08-31T14:30:25.127Z,1661956225.127 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min 2022-08-31T14:30:25.130Z,1661956225.130 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min 2022-08-31T14:30:25.157Z,1661956225.157 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min 2022-08-31T14:30:25.165Z,1661956225.165 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min 2022-08-31T14:30:25.168Z,1661956225.168 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm 2022-08-31T14:30:25.171Z,1661956225.171 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc 2022-08-31T14:30:25.198Z,1661956225.198 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 % 2022-08-31T14:30:25.201Z,1661956225.201 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m 2022-08-31T14:30:25.213Z,1661956225.213 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm 2022-08-31T14:30:25.263Z,1661956225.263 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct. 2022-08-31T14:30:25.270Z,1661956225.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy. 2022-08-31T14:30:25.298Z,1661956225.298 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct. 2022-08-31T14:30:25.333Z,1661956225.333 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait. 2022-08-31T14:30:25.371Z,1661956225.371 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct. 2022-08-31T14:30:25.374Z,1661956225.374 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct. 2022-08-31T14:30:25.390Z,1661956225.390 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2022-08-31T14:30:25.418Z,1661956225.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct. 2022-08-31T14:30:25.421Z,1661956225.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct. 2022-08-31T14:30:25.449Z,1661956225.449 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait. 2022-08-31T14:30:25.475Z,1661956225.475 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim. 2022-08-31T14:30:25.532Z,1661956225.532 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband 2022-08-31T14:30:25.534Z,1661956225.534 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = reader:ballast_and_trim.ApproachSpeed 2022-08-31T14:30:25.535Z,1661956225.535 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = reader:ballast_and_trim.ApproachDepthRate 2022-08-31T14:30:25.537Z,1661956225.537 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = reader:ballast_and_trim.ApproachPitchLimit 2022-08-31T14:30:25.539Z,1661956225.539 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = reader:ballast_and_trim.ApproachSettleTimePreDive 2022-08-31T14:30:25.557Z,1661956225.557 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.ApproachDepthTimeout 2022-08-31T14:30:25.558Z,1661956225.558 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime 2022-08-31T14:30:25.560Z,1661956225.560 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout 2022-08-31T14:30:25.562Z,1661956225.562 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime 2022-08-31T14:30:25.580Z,1661956225.580 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound 2022-08-31T14:30:25.581Z,1661956225.581 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound 2022-08-31T14:30:25.591Z,1661956225.591 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence 2022-08-31T14:30:25.593Z,1661956225.593 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = reader:ballast_and_trim.massDeadband 2022-08-31T14:30:25.729Z,1661956225.729 [MissionManager](DEBUG): mission ballast_and_trim { arguments { MissionTimeout = 90 minute """ Maximum duration of mission """ SkipComms = false """ Skip communications at start of mission. """ Depth1 = 35 meter Depth2 = NaN meter DepthDeadband = 0.1 meter """ How much vertical drift from the specified depth is allowed durnig the mission. """ ApproachSpeed = 1 meter_per_second """ Enables vehicle thruster at the commanded speed to reach target depth (set to 0 m/s to drift). """ ApproachDepthTimeout = 20 minute """ Maximum wait time for the vehicle to reach the targeted depth. """ ApproachDepthRate = 0.4 meter_per_second """ Descent depth rate (Positive depth rate means going down). """ ApproachPitchLimit = 20 degree """ Max vehicle pitch (+/-) when decending from the surface. """ ApproachSettleTimePreDive = 0 minute """ Time duration for the vehicle to pump down the VBS *BEFORE* leaving the surface. """ SettleTime = 10 minute """ How long to wait after reaching target depth before starting ballast and trim. """ EstimationTimeout = 45 minute """ Timeout for ballast and trim estimation. """ MinEstimationTime = 10 minute """ Minimum time to run ballast and trim estimation before determining convergence (must be shorter than timeout). """ MassEstimationErrorBound = 0.25 millimeter """ Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). """ BuoyEstimationErrorBound = 15 cubic_centimeter """ Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). """ EstimationConfidence = 99.9 percent """ Confidence level that the estimator has reached the desired error range (larger values take longer to converge). """ massDeadband = 0.25 millimeter """ Degree of rounding in mass-shifter command output values. """ MinAltitude = 5 meter MaxDepth = 52 meter MinOffshore = 2 kilometer CheckDepths = 1 bool } timeout duration=MissionTimeout insert Insert/Science.xml insert id="NeedComms" Insert/NeedComms.xml assign in sequence NeedComms:DiveInterval = MissionTimeout insert Insert/StandardEnvelopes.xml assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore aggregate CheckTargetDepths { run in sequence break if ( not ( CheckDepths ) ) aggregate CheckDepth1 { run in sequence break if ( not ( Depth1 > MaxDepth ) ) syslog important "Aborting ballast and trim mission. Target depth Depth1 exceeds the mission's MaxDepth setting (review mission parameters)." behavior Guidance:Execute { run in sequence set command = "stop" } } aggregate CheckDepth2 { run in sequence break if ( not ( Depth2 > MaxDepth ) ) syslog important "Aborting ballast and trim mission. Target depth Depth2 exceeds the mission's MaxDepth setting (review mission parameters)." behavior Guidance:Execute { run in sequence set command = "stop" } } assign in sequence CheckDepths = 0 bool } aggregate StartingMission { run in sequence break if ( SkipComms ) # DO NOT REMOVE the syslog entry below. The MissionManager seems to ignore the value of SkipComms, does not evaluate the Break statement properly, and always calls NeedComms. Adding the syslog call somehow fixes it. syslog info "Checking for additional instructions before submerging." call id="StartingMission" refId="NeedComms" } aggregate RunBallastAndTrim { run in sequence insert Insert/BallastAndTrim.xml { redefineArg InsertDepthDeadband = DepthDeadband redefineArg InsertApproachSpeed = ApproachSpeed redefineArg InsertApproachDepthRate = ApproachDepthRate redefineArg InsertApproachPitchLimit = ApproachPitchLimit redefineArg InsertApproachSettleTimePreDive = ApproachSettleTimePreDive redefineArg InsertApproachDepthTimeout = ApproachDepthTimeout redefineArg InsertSettleTime = SettleTime redefineArg EstTimeout = EstimationTimeout redefineArg MinEstTime = MinEstimationTime redefineArg MassEstErrorBound = MassEstimationErrorBound redefineArg BuoyEstErrorBound = BuoyEstimationErrorBound redefineArg EstConfidence = EstimationConfidence redefineArg InsertMassDeadband = massDeadband } aggregate RunDepth1 { run in sequence break if ( isNaN ( Depth1 ) ) assign in sequence BallastAndTrim:InsertDepth = Depth1 call refId="BallastAndTrim" } aggregate RunDepth2 { run in sequence break if ( isNaN ( Depth2 ) ) assign in sequence BallastAndTrim:InsertDepth = Depth2 call refId="BallastAndTrim" } } call id="EndingMission" refId="NeedComms" } 2022-08-31T14:30:25.730Z,1661956225.730 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T14:30:36.762Z,1661956236.762 [CommandExec](IMPORTANT): got command set ballast_and_trim.MissionTimeout 60 minute 2022-08-31T14:30:36.763Z,1661956236.763 [CommandExec](IMPORTANT): got command set ballast_and_trim.Depth1 10 meter 2022-08-31T14:30:36.768Z,1661956236.768 [CommandExec](IMPORTANT): got command set ballast_and_trim.MinAltitude 3 meter 2022-08-31T14:30:36.769Z,1661956236.769 [CommandExec](IMPORTANT): got command set ballast_and_trim.MaxDepth 13 meter 2022-08-31T14:30:36.769Z,1661956236.769 [CommandExec](IMPORTANT): got command run 2022-08-31T14:30:36.793Z,1661956236.793 [CommandExec](IMPORTANT): Running 2022-08-31T14:30:37.151Z,1661956237.151 [Default] Stopped 2022-08-31T14:30:37.151Z,1661956237.151 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-31T14:30:37.152Z,1661956237.152 [Default:B.GoToSurface] Stopped 2022-08-31T14:30:37.152Z,1661956237.152 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T14:30:37.152Z,1661956237.152 [Default:CheckIn] Stopped 2022-08-31T14:30:37.152Z,1661956237.152 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T14:30:37.152Z,1661956237.152 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T14:30:37.152Z,1661956237.152 [MissionManager](IMPORTANT): Started mission ballast_and_trim 2022-08-31T14:30:37.152Z,1661956237.152 [ballast_and_trim] Running Loop=1 2022-08-31T14:30:37.152Z,1661956237.152 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:A] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:B] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:C] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:D] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:E] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:F] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:Read_Oil] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T14:30:37.153Z,1661956237.153 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T14:30:37.156Z,1661956237.156 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1 2022-08-31T14:30:37.156Z,1661956237.156 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport 2022-08-31T14:30:37.156Z,1661956237.156 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T14:30:37.156Z,1661956237.156 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T14:30:37.156Z,1661956237.156 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1 2022-08-31T14:30:37.157Z,1661956237.157 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3 2022-08-31T14:30:37.157Z,1661956237.157 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T14:30:37.157Z,1661956237.157 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T14:30:37.159Z,1661956237.159 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1 2022-08-31T14:30:37.159Z,1661956237.159 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil 2022-08-31T14:30:37.159Z,1661956237.159 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T14:30:37.160Z,1661956237.160 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T14:30:37.161Z,1661956237.161 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1 2022-08-31T14:30:37.161Z,1661956237.161 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport 2022-08-31T14:30:37.161Z,1661956237.161 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T14:30:37.161Z,1661956237.161 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T14:30:37.162Z,1661956237.162 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1 2022-08-31T14:30:37.162Z,1661956237.162 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM 2022-08-31T14:30:37.162Z,1661956237.162 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T14:30:37.162Z,1661956237.162 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T14:30:37.164Z,1661956237.164 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1 2022-08-31T14:30:37.164Z,1661956237.164 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity 2022-08-31T14:30:37.164Z,1661956237.164 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T14:30:37.164Z,1661956237.164 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T14:30:37.166Z,1661956237.166 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1 2022-08-31T14:30:37.166Z,1661956237.166 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport 2022-08-31T14:30:37.166Z,1661956237.166 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T14:30:37.166Z,1661956237.166 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T14:30:37.167Z,1661956237.167 [ballast_and_trim:Science:OceanCurrent] Running Loop=1 2022-08-31T14:30:37.167Z,1661956237.167 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent 2022-08-31T14:30:37.167Z,1661956237.167 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2022-08-31T14:30:37.167Z,1661956237.167 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator. 2022-08-31T14:30:37.167Z,1661956237.167 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::initialize ballast_and_trim:StandardEnvelopes 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2022-08-31T14:30:37.168Z,1661956237.168 [ballast_and_trim:C] Running Loop=1 2022-08-31T14:30:37.169Z,1661956237.169 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2022-08-31T14:30:37.169Z,1661956237.169 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2022-08-31T14:30:37.170Z,1661956237.170 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2022-08-31T14:30:37.170Z,1661956237.170 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2022-08-31T14:30:37.171Z,1661956237.171 [ballast_and_trim:C] Stopped 2022-08-31T14:30:37.171Z,1661956237.171 [ballast_and_trim:E] Running Loop=1 2022-08-31T14:30:37.172Z,1661956237.172 [ballast_and_trim:Science] Running Loop=1 2022-08-31T14:30:37.172Z,1661956237.172 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectSalinity] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectFDOM] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T14:30:37.173Z,1661956237.173 [ballast_and_trim:Science:HighestOilPeakReport] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectOil] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectNO3] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T14:30:37.174Z,1661956237.174 [ballast_and_trim:Science:HighestChlPeakReport] Stopped 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:PeakDetectChl] Stopped 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T14:30:37.175Z,1661956237.175 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2022-08-31T14:30:37.177Z,1661956237.177 [ballast_and_trim:Science:Read_Oil] Running Loop=1 2022-08-31T14:30:37.178Z,1661956237.178 [ballast_and_trim:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_petroleum_hydrocarbons_in_sea_water 2022-08-31T14:30:37.178Z,1661956237.178 [ballast_and_trim:Science:F] Stopped 2022-08-31T14:30:37.178Z,1661956237.178 [ballast_and_trim:Science:E] Stopped 2022-08-31T14:30:37.178Z,1661956237.178 [ballast_and_trim:Science:D] Stopped 2022-08-31T14:30:37.178Z,1661956237.178 [ballast_and_trim:Science:C] Running Loop=1 2022-08-31T14:30:37.183Z,1661956237.183 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2022-08-31T14:30:37.184Z,1661956237.184 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2022-08-31T14:30:37.184Z,1661956237.184 [ballast_and_trim:Science:B] Running Loop=1 2022-08-31T14:30:37.185Z,1661956237.185 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2022-08-31T14:30:37.185Z,1661956237.185 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2022-08-31T14:30:37.185Z,1661956237.185 [ballast_and_trim:Science:A] Stopped 2022-08-31T14:30:37.574Z,1661956237.574 [ballast_and_trim:E] Stopped 2022-08-31T14:30:37.574Z,1661956237.574 [ballast_and_trim:F] Running Loop=1 2022-08-31T14:30:37.949Z,1661956237.949 [ballast_and_trim:F] Stopped 2022-08-31T14:30:37.949Z,1661956237.949 [ballast_and_trim:G] Running Loop=1 2022-08-31T14:30:38.390Z,1661956238.390 [ballast_and_trim:G] Stopped 2022-08-31T14:30:38.390Z,1661956238.390 [ballast_and_trim:CheckTargetDepths] Running Loop=1 2022-08-31T14:30:38.390Z,1661956238.390 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths 2022-08-31T14:30:38.390Z,1661956238.390 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Running Loop=1 2022-08-31T14:30:38.391Z,1661956238.391 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2022-08-31T14:30:38.391Z,1661956238.391 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Running Loop=1 2022-08-31T14:30:38.782Z,1661956238.782 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Stopped 2022-08-31T14:30:38.782Z,1661956238.782 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2022-08-31T14:30:38.783Z,1661956238.783 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Stopped 2022-08-31T14:30:38.783Z,1661956238.783 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Running Loop=1 2022-08-31T14:30:38.783Z,1661956238.783 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2022-08-31T14:30:38.783Z,1661956238.783 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Running Loop=1 2022-08-31T14:30:39.162Z,1661956239.162 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Stopped 2022-08-31T14:30:39.162Z,1661956239.162 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2022-08-31T14:30:39.162Z,1661956239.162 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Stopped 2022-08-31T14:30:39.163Z,1661956239.163 [ballast_and_trim:CheckTargetDepths:C] Running Loop=1 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:CheckTargetDepths:C] Stopped 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:CheckTargetDepths](INFO): Completed ballast_and_trim:CheckTargetDepths 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:CheckTargetDepths] Stopped 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:StartingMission] Running Loop=1 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission 2022-08-31T14:30:39.622Z,1661956239.622 [ballast_and_trim:StartingMission:A] Running Loop=1 2022-08-31T14:30:39.984Z,1661956239.984 [ballast_and_trim:StartingMission:A](INFO): Checking for additional instructions before submerging. 2022-08-31T14:30:39.985Z,1661956239.985 [ballast_and_trim:StartingMission:A] Stopped 2022-08-31T14:30:39.985Z,1661956239.985 [ballast_and_trim:StartingMission:StartingMission] Running Loop=1 2022-08-31T14:30:39.985Z,1661956239.985 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission:StartingMission 2022-08-31T14:30:40.421Z,1661956240.421 [ballast_and_trim:NeedComms] Running Loop=1 2022-08-31T14:30:40.421Z,1661956240.421 [ballast_and_trim:NeedComms](DEBUG): Aggregate::initialize ballast_and_trim:NeedComms 2022-08-31T14:30:40.421Z,1661956240.421 [ballast_and_trim:NeedComms:B.GoToSurface] Running Loop=1 2022-08-31T14:30:40.421Z,1661956240.421 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T14:30:40.422Z,1661956240.422 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2022-08-31T14:30:40.422Z,1661956240.422 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2022-08-31T14:30:40.422Z,1661956240.422 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2022-08-31T14:30:40.423Z,1661956240.423 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T14:30:40.427Z,1661956240.427 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T14:30:40.428Z,1661956240.428 [ballast_and_trim:NeedComms:A] Running Loop=1 2022-08-31T14:30:40.429Z,1661956240.429 [ballast_and_trim:NeedComms:A](INFO): last time_fix was: 1661956212.000000 second since 1970/01/01T00:00:00Z 2022-08-31T14:30:40.429Z,1661956240.429 [ballast_and_trim:NeedComms:A] Stopped 2022-08-31T14:30:40.533Z,1661956240.533 [CTD_Seabird](ERROR): Failed to parse device response: 2022-08-31T14:30:40.791Z,1661956240.791 [ballast_and_trim:NeedComms:C] Running Loop=1 2022-08-31T14:30:41.180Z,1661956241.180 [NAL9602](INFO): SBD MO Status=1, MOMSN=44416, MT Status=0, MTMSN=0 2022-08-31T14:30:41.228Z,1661956241.228 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0013.lzma 2022-08-31T14:30:41.228Z,1661956241.228 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:30:41.509Z,1661956241.509 [ballast_and_trim:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-08-31T14:30:42.402Z,1661956242.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143048.00,A,4015.12152,N,07115.21302,W,0.972,123.50,310822,,,A*70 2022-08-31T14:30:42.405Z,1661956242.405 [NAL9602](INFO): GPS fix at 20220831T143048: (40.252025, -71.253550) 2022-08-31T14:30:42.484Z,1661956242.484 [ballast_and_trim:NeedComms:C] Stopped 2022-08-31T14:30:42.485Z,1661956242.485 [ballast_and_trim:NeedComms:D] Running Loop=1 2022-08-31T14:30:42.816Z,1661956242.816 [ballast_and_trim:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-08-31T14:31:05.729Z,1661956265.729 [NAL9602](INFO): SBD MO Status=1, MOMSN=44417, MT Status=0, MTMSN=0 2022-08-31T14:31:05.780Z,1661956265.780 [NAL9602](INFO): Sent 52 bytes from file Logs/20220831T140533/Courier0015.lzma 2022-08-31T14:31:05.780Z,1661956265.780 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:31:13.764Z,1661956273.764 [NAL9602](INFO): SBD MO Status=1, MOMSN=44418, MT Status=0, MTMSN=0 2022-08-31T14:31:13.812Z,1661956273.812 [NAL9602](INFO): Sent 71 bytes from file Logs/20220831T140533/Courier0018.lzma 2022-08-31T14:31:13.812Z,1661956273.812 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:31:22.536Z,1661956282.536 [NAL9602](INFO): SBD MO Status=1, MOMSN=44419, MT Status=0, MTMSN=0 2022-08-31T14:31:22.584Z,1661956282.584 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0016.lzma 2022-08-31T14:31:22.584Z,1661956282.584 [NAL9602](INFO): Packets left to send: 2 2022-08-31T14:31:32.849Z,1661956292.849 [NAL9602](INFO): SBD MO Status=1, MOMSN=44420, MT Status=0, MTMSN=0 2022-08-31T14:31:32.908Z,1661956292.908 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0016.lzma 2022-08-31T14:31:32.908Z,1661956292.908 [NAL9602](INFO): Packets left to send: 1 2022-08-31T14:31:45.565Z,1661956305.565 [NAL9602](INFO): SBD MO Status=1, MOMSN=44421, MT Status=0, MTMSN=0 2022-08-31T14:31:45.620Z,1661956305.620 [NAL9602](INFO): Sent 157 bytes from file Logs/20220831T140533/Express0016.lzma 2022-08-31T14:31:45.620Z,1661956305.620 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:31:57.459Z,1661956317.459 [NAL9602](INFO): SBD MO Status=1, MOMSN=44422, MT Status=0, MTMSN=0 2022-08-31T14:31:57.508Z,1661956317.508 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T140533/Express0019.lzma 2022-08-31T14:31:57.508Z,1661956317.508 [NAL9602](INFO): Packets left to send: 0 2022-08-31T14:32:13.439Z,1661956333.439 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout 2022-08-31T14:32:13.440Z,1661956333.440 [RDI_PathfinderUp] Communications Fault, FailCount= 1 2022-08-31T14:32:13.440Z,1661956333.440 [RDI_PathfinderUp](ERROR): Communications Fault 2022-08-31T14:32:13.490Z,1661956333.490 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp 2022-08-31T14:32:13.812Z,1661956333.812 [RDI_PathfinderUp](INFO): Powering down 2022-08-31T14:32:14.603Z,1661956334.603 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp 2022-08-31T14:32:14.603Z,1661956334.603 [RDI_PathfinderUp] No Fault, FailCount= 1 2022-08-31T14:32:14.951Z,1661956334.951 [NAL9602](INFO): SBD MO Status=0, MOMSN=44423, MT Status=0, MTMSN=0 2022-08-31T14:32:15.032Z,1661956335.032 [ballast_and_trim:NeedComms:D] Stopped 2022-08-31T14:32:15.033Z,1661956335.033 [ballast_and_trim:NeedComms:E] Running Loop=1 2022-08-31T14:32:15.370Z,1661956335.370 [ballast_and_trim:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-08-31T14:32:17.385Z,1661956337.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143223.00,A,4015.10994,N,07115.19926,W,0.719,107.47,310822,,,A*7B 2022-08-31T14:32:17.388Z,1661956337.388 [NAL9602](INFO): GPS fix at 20220831T143223: (40.251832, -71.253321) 2022-08-31T14:32:17.401Z,1661956337.401 [ballast_and_trim:NeedComms:E] Stopped 2022-08-31T14:32:17.401Z,1661956337.401 [ballast_and_trim:NeedComms](INFO): Completed ballast_and_trim:NeedComms 2022-08-31T14:32:17.401Z,1661956337.401 [ballast_and_trim:NeedComms] Stopped 2022-08-31T14:32:17.402Z,1661956337.402 [ballast_and_trim:NeedComms](DEBUG): Aggregate::uninitialize ballast_and_trim:NeedComms 2022-08-31T14:32:17.402Z,1661956337.402 [ballast_and_trim:NeedComms:B.GoToSurface] Stopped 2022-08-31T14:32:17.402Z,1661956337.402 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T14:32:17.821Z,1661956337.821 [ballast_and_trim:StartingMission:StartingMission](INFO): Completed ballast_and_trim:StartingMission:StartingMission 2022-08-31T14:32:17.821Z,1661956337.821 [ballast_and_trim:StartingMission:StartingMission] Stopped 2022-08-31T14:32:17.821Z,1661956337.821 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission:StartingMission 2022-08-31T14:32:17.821Z,1661956337.821 [ballast_and_trim:StartingMission](INFO): Completed ballast_and_trim:StartingMission 2022-08-31T14:32:17.821Z,1661956337.821 [ballast_and_trim:StartingMission] Stopped 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:RunBallastAndTrim] Running Loop=1 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Running Loop=1 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2022-08-31T14:32:17.822Z,1661956337.822 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Running Loop=1 2022-08-31T14:32:18.277Z,1661956338.277 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Stopped 2022-08-31T14:32:18.277Z,1661956338.277 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Running Loop=1 2022-08-31T14:32:18.277Z,1661956338.277 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2022-08-31T14:32:18.597Z,1661956338.597 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2022-08-31T14:32:18.598Z,1661956338.598 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 1.000000 m/s 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2022-08-31T14:32:18.617Z,1661956338.617 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize. 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize. 2022-08-31T14:32:18.618Z,1661956338.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1 2022-08-31T14:32:18.619Z,1661956338.619 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T14:32:18.623Z,1661956338.623 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1 2022-08-31T14:32:18.624Z,1661956338.624 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2022-08-31T14:32:18.624Z,1661956338.624 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2022-08-31T14:32:18.624Z,1661956338.624 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2022-08-31T14:32:18.624Z,1661956338.624 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2022-08-31T14:32:18.624Z,1661956338.624 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral. 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1 2022-08-31T14:32:19.029Z,1661956339.029 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1 2022-08-31T14:32:19.030Z,1661956339.030 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1 2022-08-31T14:32:19.030Z,1661956339.030 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1 2022-08-31T14:32:19.031Z,1661956339.031 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2022-08-31T14:32:19.416Z,1661956339.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting. 2022-08-31T14:32:19.416Z,1661956339.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped 2022-08-31T14:32:19.416Z,1661956339.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:32:19.416Z,1661956339.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T14:32:19.416Z,1661956339.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize. 2022-08-31T14:32:19.417Z,1661956339.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1 2022-08-31T14:32:19.823Z,1661956339.823 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2022-08-31T14:32:19.824Z,1661956339.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 10.000000 m 2022-08-31T14:32:19.824Z,1661956339.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped 2022-08-31T14:32:19.824Z,1661956339.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1 2022-08-31T14:32:19.824Z,1661956339.824 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize. 2022-08-31T14:32:26.899Z,1661956346.899 [ThrusterHE](FAULT): Could not get status:serial timeout 2022-08-31T14:32:33.166Z,1661956353.166 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:32:50.109Z,1661956370.109 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T14:33:22.462Z,1661956402.462 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:33:32.146Z,1661956412.146 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude 2022-08-31T14:34:13.154Z,1661956453.154 [ThrusterHE](FAULT): getSpeed error serial timeout 2022-08-31T14:34:13.154Z,1661956453.154 [ThrusterHE](FAULT): Thruster uart error: serial timeout 2022-08-31T14:34:13.154Z,1661956453.154 [ThrusterHE] Communications Fault, FailCount= 1 2022-08-31T14:34:13.154Z,1661956453.154 [ThrusterHE](ERROR): Communications Fault 2022-08-31T14:34:13.165Z,1661956453.165 [CBIT](ERROR): Communications Fault in component: ThrusterHE 2022-08-31T14:34:13.401Z,1661956453.401 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-08-31T14:34:13.401Z,1661956453.401 [ThrusterHE](INFO): Powering down 2022-08-31T14:34:14.294Z,1661956454.294 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-08-31T14:34:14.412Z,1661956454.412 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-08-31T14:34:14.416Z,1661956454.416 [CBIT](INFO): Clearing failed state for component ThrusterHE 2022-08-31T14:34:14.416Z,1661956454.416 [ThrusterHE] No Fault, FailCount= 1 2022-08-31T14:34:18.267Z,1661956458.267 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T14:35:32.547Z,1661956532.547 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:35:59.760Z,1661956559.760 [Radio_Surface](INFO): Powering down 2022-08-31T14:36:08.860Z,1661956568.860 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-08-31T14:36:12.547Z,1661956572.547 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T14:36:21.042Z,1661956581.042 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped 2022-08-31T14:36:21.043Z,1661956581.043 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T14:36:21.043Z,1661956581.043 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped 2022-08-31T14:36:21.043Z,1661956581.043 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T14:36:21.044Z,1661956581.044 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped 2022-08-31T14:36:21.044Z,1661956581.044 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize. 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped 2022-08-31T14:36:21.045Z,1661956581.045 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize. 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2022-08-31T14:36:21.046Z,1661956581.046 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize. 2022-08-31T14:36:21.047Z,1661956581.047 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 10.045513 m 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component. 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2022-08-31T14:36:21.453Z,1661956581.453 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2022-08-31T14:36:32.387Z,1661956592.387 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2022-08-31T14:36:32.387Z,1661956592.387 [RDI_Pathfinder] Communications Fault, FailCount= 1 2022-08-31T14:36:32.387Z,1661956592.387 [RDI_Pathfinder](ERROR): Communications Fault 2022-08-31T14:36:32.556Z,1661956592.556 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2022-08-31T14:36:32.808Z,1661956592.808 [RDI_Pathfinder](INFO): Powering down 2022-08-31T14:36:33.589Z,1661956593.589 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2022-08-31T14:36:33.589Z,1661956593.589 [RDI_Pathfinder] No Fault, FailCount= 1 2022-08-31T14:36:33.946Z,1661956593.946 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2022-08-31T14:37:52.397Z,1661956672.397 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T14:37:57.585Z,1661956677.585 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T14:38:07.347Z,1661956687.347 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:39:22.604Z,1661956762.604 [Radio_Surface](INFO): Powering up 2022-08-31T14:39:28.680Z,1661956768.680 [DataOverHttps](INFO): Radio surface powered ON. 2022-08-31T14:46:22.245Z,1661957182.245 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting. 2022-08-31T14:46:22.245Z,1661957182.245 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped 2022-08-31T14:46:22.245Z,1661957182.245 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T14:46:22.245Z,1661957182.245 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1 2022-08-31T14:46:22.618Z,1661957182.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 0.230240 m 2022-08-31T14:46:22.618Z,1661957182.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped 2022-08-31T14:46:22.618Z,1661957182.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1 2022-08-31T14:46:22.618Z,1661957182.618 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim. 2022-08-31T14:51:32.523Z,1661957492.523 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:53:58.363Z,1661957638.363 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T14:56:13.404Z,1661957773.404 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:56:38.381Z,1661957798.381 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T14:57:08.659Z,1661957828.659 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout 2022-08-31T14:57:08.660Z,1661957828.660 [RDI_PathfinderUp] Communications Fault, FailCount= 1 2022-08-31T14:57:08.660Z,1661957828.660 [RDI_PathfinderUp](ERROR): Communications Fault 2022-08-31T14:57:08.713Z,1661957828.713 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp 2022-08-31T14:57:09.100Z,1661957829.100 [RDI_PathfinderUp](INFO): Powering down 2022-08-31T14:57:09.916Z,1661957829.916 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp 2022-08-31T14:57:09.916Z,1661957829.916 [RDI_PathfinderUp] No Fault, FailCount= 1 2022-08-31T14:57:33.693Z,1661957853.693 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T14:57:44.607Z,1661957864.607 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T15:02:08.828Z,1661958128.828 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:07:34.046Z,1661958454.046 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T15:15:14.271Z,1661958914.271 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T15:15:26.367Z,1661958926.367 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T15:17:44.561Z,1661959064.561 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:17:54.441Z,1661959074.441 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T15:18:04.439Z,1661959084.439 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout 2022-08-31T15:18:04.439Z,1661959084.439 [RDI_PathfinderUp] Communications Fault, FailCount= 1 2022-08-31T15:18:04.439Z,1661959084.439 [RDI_PathfinderUp](ERROR): Communications Fault 2022-08-31T15:18:04.495Z,1661959084.495 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp 2022-08-31T15:18:04.812Z,1661959084.812 [RDI_PathfinderUp](INFO): Powering down 2022-08-31T15:18:05.589Z,1661959085.589 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp 2022-08-31T15:18:05.589Z,1661959085.589 [RDI_PathfinderUp] No Fault, FailCount= 1 2022-08-31T15:20:45.513Z,1661959245.513 [BPC1](ERROR): Battery stick #62 (s/n: 0138) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0. 2022-08-31T15:20:45.513Z,1661959245.513 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2022-08-31T15:20:45.516Z,1661959245.516 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2022-08-31T15:24:29.762Z,1661959469.762 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:25:48.587Z,1661959548.587 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T15:25:52.972Z,1661959552.972 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T15:26:39.868Z,1661959599.868 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:27:10.152Z,1661959630.152 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim](INFO): Timed out from 2022-08-31T14:30:37.2Z 2022-08-31T15:30:37.450Z,1661959837.450 [MissionManager](INFO): ballast_and_trim is completed. 2022-08-31T15:30:37.450Z,1661959837.450 [MissionManager](INFO): Uninitializing Mission ballast_and_trim 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim] Stopped 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim:Science] Stopped 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim:Science:B] Stopped 2022-08-31T15:30:37.450Z,1661959837.450 [ballast_and_trim:Science:C] Stopped 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:Science:Read_Oil] Stopped 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:Science:OceanCurrent] Stopped 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:Science:OceanCurrent:A.] Stopped 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:StandardEnvelopes] Stopped 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::uninitialize ballast_and_trim:StandardEnvelopes 2022-08-31T15:30:37.451Z,1661959837.451 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2022-08-31T15:30:37.455Z,1661959837.455 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2022-08-31T15:30:37.455Z,1661959837.455 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Stopped 2022-08-31T15:30:37.455Z,1661959837.455 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2022-08-31T15:30:37.456Z,1661959837.456 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped 2022-08-31T15:30:37.457Z,1661959837.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize. 2022-08-31T15:30:37.457Z,1661959837.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped 2022-08-31T15:30:37.457Z,1661959837.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped 2022-08-31T15:30:37.457Z,1661959837.457 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](FAULT): BallastAndTrim aborted prematurely - reporting best estimate. Estimation time: 44.24 minutes. 2022-08-31T15:30:37.458Z,1661959837.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 154.552032 +/- 0.000000 cc (conf. level 99.90%, sigma: 0.000000 cc). 2022-08-31T15:30:37.463Z,1661959837.463 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 9.623657 +/- 0.487339 mm (conf. level 99.90%, sigma: 1.249139 mm). 2022-08-31T15:30:37.464Z,1661959837.464 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim. 2022-08-31T15:30:37.464Z,1661959837.464 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Stopped 2022-08-31T15:30:37.464Z,1661959837.464 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2022-08-31T15:30:37.464Z,1661959837.464 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Stopped 2022-08-31T15:30:37.464Z,1661959837.464 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2022-08-31T15:30:37.839Z,1661959837.839 [MissionManager](IMPORTANT): Started mission Default 2022-08-31T15:30:37.840Z,1661959837.840 [Default] Running Loop=1 2022-08-31T15:30:37.840Z,1661959837.840 [Default](DEBUG): Aggregate::initialize Default 2022-08-31T15:30:37.840Z,1661959837.840 [Default:B.GoToSurface] Running Loop=1 2022-08-31T15:30:37.840Z,1661959837.840 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T15:30:37.840Z,1661959837.840 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-08-31T15:30:37.840Z,1661959837.840 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-08-31T15:30:37.841Z,1661959837.841 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-08-31T15:30:37.841Z,1661959837.841 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T15:30:37.841Z,1661959837.841 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T15:30:37.842Z,1661959837.842 [Default:A.Wait] Running Loop=1 2022-08-31T15:30:37.842Z,1661959837.842 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-08-31T15:30:51.157Z,1661959851.157 [Default:A.Wait](INFO): Done Waiting. 2022-08-31T15:30:51.157Z,1661959851.157 [Default:A.Wait] Stopped 2022-08-31T15:30:51.157Z,1661959851.157 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T15:30:51.565Z,1661959851.565 [Default:CheckIn] Running Loop=1 2022-08-31T15:30:51.566Z,1661959851.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T15:30:51.566Z,1661959851.566 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T15:30:53.571Z,1661959853.571 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153100.00,A,4014.75840,N,07114.69388,W,0.933,136.62,310822,,,A*79 2022-08-31T15:30:53.573Z,1661959853.573 [NAL9602](INFO): GPS fix at 20220831T153100: (40.245973, -71.244898) 2022-08-31T15:30:53.603Z,1661959853.603 [UniversalFixResidualReporter](INFO): Fix residual: 17.7 %DT, over the last 1989.1 m. Residual distance 351.5 m at bearing -31.3 degrees. Fix at (40.2460, -71.2449) with 967.2 m made good. 2022-08-31T15:30:53.605Z,1661959853.605 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T15:30:53.605Z,1661959853.605 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T15:31:37.043Z,1661959897.043 [NAL9602](INFO): SBD MO Status=2, MOMSN=44424, MT Status=2, MTMSN=0 2022-08-31T15:31:37.043Z,1661959897.043 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:31:58.319Z,1661959918.319 [NAL9602](INFO): SBD MO Status=1, MOMSN=44424, MT Status=0, MTMSN=0 2022-08-31T15:31:58.376Z,1661959918.376 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Courier0021.lzma 2022-08-31T15:31:58.376Z,1661959918.376 [NAL9602](INFO): Packets left to send: 1 2022-08-31T15:32:17.922Z,1661959937.922 [NAL9602](INFO): SBD MO Status=1, MOMSN=44425, MT Status=0, MTMSN=0 2022-08-31T15:32:17.980Z,1661959937.980 [NAL9602](INFO): Sent 84 bytes from file Logs/20220831T140533/Courier0021.lzma 2022-08-31T15:32:17.980Z,1661959937.980 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:32:28.931Z,1661959948.931 [NAL9602](INFO): SBD MO Status=1, MOMSN=44426, MT Status=0, MTMSN=0 2022-08-31T15:32:28.984Z,1661959948.984 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0022.lzma 2022-08-31T15:32:28.984Z,1661959948.984 [NAL9602](INFO): Packets left to send: 2 2022-08-31T15:32:42.724Z,1661959962.724 [NAL9602](INFO): SBD MO Status=1, MOMSN=44427, MT Status=0, MTMSN=0 2022-08-31T15:32:42.772Z,1661959962.772 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0022.lzma 2022-08-31T15:32:42.772Z,1661959962.772 [NAL9602](INFO): Packets left to send: 1 2022-08-31T15:32:57.228Z,1661959977.228 [NAL9602](INFO): SBD MO Status=2, MOMSN=44428, MT Status=2, MTMSN=0 2022-08-31T15:32:57.228Z,1661959977.228 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:33:22.808Z,1661960002.808 [NAL9602](INFO): SBD MO Status=2, MOMSN=44428, MT Status=2, MTMSN=0 2022-08-31T15:33:22.808Z,1661960002.808 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:33:55.579Z,1661960035.579 [NAL9602](INFO): SBD MO Status=2, MOMSN=44428, MT Status=2, MTMSN=0 2022-08-31T15:33:55.587Z,1661960035.587 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:34:20.601Z,1661960060.601 [NAL9602](INFO): SBD MO Status=2, MOMSN=44428, MT Status=2, MTMSN=0 2022-08-31T15:34:20.601Z,1661960060.601 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:34:45.731Z,1661960085.731 [NAL9602](INFO): SBD MO Status=1, MOMSN=44428, MT Status=0, MTMSN=0 2022-08-31T15:34:45.780Z,1661960085.780 [NAL9602](INFO): Sent 144 bytes from file Logs/20220831T140533/Express0022.lzma 2022-08-31T15:34:45.780Z,1661960085.780 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:35:01.040Z,1661960101.040 [NAL9602](INFO): SBD MO Status=2, MOMSN=44429, MT Status=2, MTMSN=0 2022-08-31T15:35:01.040Z,1661960101.040 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:35:19.957Z,1661960119.957 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T15:35:20.369Z,1661960120.369 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831153517.895244,06,1345,25,0099,0150,208,02,02,01,02,5,-01,-01,2,3,5,0,150,2.3,-2.74,-100,5.74,-01,-1.58,61,14500,4000*66 2022-08-31T15:35:20.371Z,1661960120.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=44429, MT Status=0, MTMSN=0 2022-08-31T15:35:20.456Z,1661960120.456 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T15:35:20.456Z,1661960120.456 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T15:35:20.456Z,1661960120.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T15:35:51.065Z,1661960151.065 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T15:37:35.375Z,1661960255.375 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:38:58.525Z,1661960338.525 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00 2022-08-31T15:38:58.529Z,1661960338.529 [Micromodem](INFO): Nmea in: $CACST,6,1,20220831153858.174791,06,574,21,0100,0150,134,01,01,01,01,6,-01,-01,2,3,1,0,150,-29.0,2.23,07,0.77,-01,-5.89,58,14500,4000*74 2022-08-31T15:40:21.021Z,1661960421.021 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T15:40:21.021Z,1661960421.021 [Default:CheckIn:C.Wait] Stopped 2022-08-31T15:40:21.021Z,1661960421.021 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T15:40:21.021Z,1661960421.021 [Default:CheckIn:D] Running Loop=1 2022-08-31T15:40:21.372Z,1661960421.372 [Default:CheckIn:D] Stopped 2022-08-31T15:40:21.372Z,1661960421.372 [Default:CheckIn:E] Running Loop=1 2022-08-31T15:40:21.755Z,1661960421.755 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.725526 min 2022-08-31T15:40:21.755Z,1661960421.755 [Default:CheckIn:E] Stopped 2022-08-31T15:40:21.755Z,1661960421.755 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T15:40:21.755Z,1661960421.755 [Default:CheckIn] Stopped 2022-08-31T15:40:21.755Z,1661960421.755 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T15:40:21.756Z,1661960421.756 [Default:CheckIn](INFO): Running loop #2 2022-08-31T15:40:21.756Z,1661960421.756 [Default:CheckIn] Running Loop=2 2022-08-31T15:40:21.756Z,1661960421.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T15:40:21.756Z,1661960421.756 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T15:40:23.771Z,1661960423.771 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154030.00,A,4014.68417,N,07114.59265,W,1.438,144.04,310822,,,A*7D 2022-08-31T15:40:23.774Z,1661960423.774 [NAL9602](INFO): GPS fix at 20220831T154030: (40.244736, -71.243211) 2022-08-31T15:40:23.785Z,1661960423.785 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T15:40:23.785Z,1661960423.785 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T15:40:45.119Z,1661960445.119 [NAL9602](INFO): SBD MO Status=1, MOMSN=44430, MT Status=0, MTMSN=0 2022-08-31T15:40:45.176Z,1661960445.176 [NAL9602](INFO): Sent 78 bytes from file Logs/20220831T140533/Courier0024.lzma 2022-08-31T15:40:45.176Z,1661960445.176 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:41:09.380Z,1661960469.380 [NAL9602](INFO): SBD MO Status=2, MOMSN=44431, MT Status=2, MTMSN=0 2022-08-31T15:41:09.381Z,1661960469.381 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:41:34.094Z,1661960494.094 [NAL9602](INFO): SBD MO Status=1, MOMSN=44431, MT Status=0, MTMSN=0 2022-08-31T15:41:34.144Z,1661960494.144 [NAL9602](INFO): Sent 118 bytes from file Logs/20220831T140533/Express0025.lzma 2022-08-31T15:41:34.144Z,1661960494.144 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:41:55.193Z,1661960515.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=44432, MT Status=2, MTMSN=0 2022-08-31T15:41:55.193Z,1661960515.193 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:42:19.523Z,1661960539.523 [NAL9602](INFO): SBD MO Status=2, MOMSN=44432, MT Status=2, MTMSN=0 2022-08-31T15:42:19.523Z,1661960539.523 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:42:25.887Z,1661960545.887 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T15:42:54.627Z,1661960574.627 [NAL9602](INFO): SBD MO Status=2, MOMSN=44432, MT Status=2, MTMSN=0 2022-08-31T15:42:54.627Z,1661960574.627 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:43:00.993Z,1661960580.993 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T15:43:28.165Z,1661960608.165 [NAL9602](INFO): SBD MO Status=0, MOMSN=44432, MT Status=0, MTMSN=0 2022-08-31T15:43:28.245Z,1661960608.245 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T15:43:28.245Z,1661960608.245 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T15:43:28.245Z,1661960608.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T15:43:58.861Z,1661960638.861 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T15:44:45.360Z,1661960685.360 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T15:48:28.745Z,1661960908.745 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T15:48:28.745Z,1661960908.745 [Default:CheckIn:C.Wait] Stopped 2022-08-31T15:48:28.745Z,1661960908.745 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T15:48:28.746Z,1661960908.746 [Default:CheckIn:D] Running Loop=1 2022-08-31T15:48:29.194Z,1661960909.194 [Default:CheckIn:D] Stopped 2022-08-31T15:48:29.194Z,1661960909.194 [Default:CheckIn:E] Running Loop=1 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.855906 min 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn:E] Stopped 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn] Stopped 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn](INFO): Running loop #3 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn] Running Loop=3 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T15:48:29.554Z,1661960909.554 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T15:48:31.572Z,1661960911.572 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154838.00,A,4014.61077,N,07114.50941,W,0.952,143.38,310822,,,A*7A 2022-08-31T15:48:31.574Z,1661960911.574 [NAL9602](INFO): GPS fix at 20220831T154838: (40.243513, -71.241823) 2022-08-31T15:48:31.585Z,1661960911.585 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T15:48:31.585Z,1661960911.585 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T15:49:04.548Z,1661960944.548 [NAL9602](INFO): SBD MO Status=2, MOMSN=44433, MT Status=2, MTMSN=0 2022-08-31T15:49:04.548Z,1661960944.548 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:49:26.723Z,1661960966.723 [NAL9602](INFO): SBD MO Status=2, MOMSN=44433, MT Status=2, MTMSN=0 2022-08-31T15:49:26.723Z,1661960966.723 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:49:27.557Z,1661960967.557 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-31T15:49:39.573Z,1661960979.573 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.025436 CHAN A1 (24V): 0.030453 CHAN A2 (12V): 0.011872 CHAN A3 (5V): 0.002587 CHAN B0 (3.3V): 0.002765 CHAN B1 (3.15aV): 0.002380 CHAN B2 (3.15bV): 0.002746 CHAN B3 (GND): -0.000809 OPEN: 0.006495 Full Scale: +/- 1 mA 2022-08-31T15:49:51.262Z,1661960991.262 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T15:49:53.268Z,1661960993.268 [NAL9602](INFO): SBD MO Status=2, MOMSN=44433, MT Status=2, MTMSN=0 2022-08-31T15:49:53.268Z,1661960993.268 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:50:10.880Z,1661961010.880 [NAL9602](INFO): SBD MO Status=1, MOMSN=44433, MT Status=0, MTMSN=0 2022-08-31T15:50:10.964Z,1661961010.964 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0027.lzma 2022-08-31T15:50:10.965Z,1661961010.965 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:50:30.668Z,1661961030.668 [NAL9602](INFO): SBD MO Status=2, MOMSN=44434, MT Status=2, MTMSN=0 2022-08-31T15:50:30.668Z,1661961030.668 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:50:41.272Z,1661961041.272 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T15:50:41.281Z,1661961041.281 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude 2022-08-31T15:50:58.625Z,1661961058.625 [NAL9602](INFO): SBD MO Status=2, MOMSN=44434, MT Status=2, MTMSN=0 2022-08-31T15:50:58.625Z,1661961058.625 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:51:11.214Z,1661961071.214 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items 2022-08-31T15:51:26.131Z,1661961086.131 [NAL9602](INFO): SBD MO Status=1, MOMSN=44434, MT Status=0, MTMSN=0 2022-08-31T15:51:26.188Z,1661961086.188 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0028.lzma 2022-08-31T15:51:26.188Z,1661961086.188 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:51:34.188Z,1661961094.188 [NAL9602](INFO): SBD MO Status=0, MOMSN=44435, MT Status=0, MTMSN=0 2022-08-31T15:51:34.276Z,1661961094.276 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T15:51:34.276Z,1661961094.276 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T15:51:34.276Z,1661961094.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T15:52:04.880Z,1661961124.880 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T15:56:34.764Z,1661961394.764 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T15:56:34.764Z,1661961394.764 [Default:CheckIn:C.Wait] Stopped 2022-08-31T15:56:34.764Z,1661961394.764 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T15:56:34.765Z,1661961394.765 [Default:CheckIn:D] Running Loop=1 2022-08-31T15:56:35.238Z,1661961395.238 [Default:CheckIn:D] Stopped 2022-08-31T15:56:35.238Z,1661961395.238 [Default:CheckIn:E] Running Loop=1 2022-08-31T15:56:35.588Z,1661961395.588 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.956628 min 2022-08-31T15:56:35.588Z,1661961395.588 [Default:CheckIn:E] Stopped 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn] Stopped 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn](INFO): Running loop #4 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn] Running Loop=4 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T15:56:35.589Z,1661961395.589 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T15:56:37.588Z,1661961397.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155644.00,A,4014.53736,N,07114.41412,W,0.253,150.27,310822,,,D*75 2022-08-31T15:56:37.590Z,1661961397.590 [NAL9602](INFO): GPS fix at 20220831T155644: (40.242289, -71.240235) 2022-08-31T15:56:37.617Z,1661961397.617 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T15:56:37.617Z,1661961397.617 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T15:56:55.916Z,1661961415.916 [NAL9602](INFO): SBD MO Status=1, MOMSN=44436, MT Status=0, MTMSN=0 2022-08-31T15:56:55.968Z,1661961415.968 [NAL9602](INFO): Sent 77 bytes from file Logs/20220831T140533/Courier0030.lzma 2022-08-31T15:56:55.968Z,1661961415.968 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:57:12.611Z,1661961432.611 [NAL9602](INFO): SBD MO Status=1, MOMSN=44437, MT Status=0, MTMSN=0 2022-08-31T15:57:12.667Z,1661961432.667 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0031.lzma 2022-08-31T15:57:12.667Z,1661961432.667 [NAL9602](INFO): Packets left to send: 1 2022-08-31T15:57:26.534Z,1661961446.534 [NAL9602](INFO): SBD MO Status=1, MOMSN=44438, MT Status=0, MTMSN=0 2022-08-31T15:57:26.584Z,1661961446.584 [NAL9602](INFO): Sent 133 bytes from file Logs/20220831T140533/Express0031.lzma 2022-08-31T15:57:26.584Z,1661961446.584 [NAL9602](INFO): Packets left to send: 0 2022-08-31T15:57:45.867Z,1661961465.867 [NAL9602](INFO): SBD MO Status=2, MOMSN=44439, MT Status=2, MTMSN=0 2022-08-31T15:57:45.868Z,1661961465.868 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-31T15:57:53.390Z,1661961473.390 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-31T15:58:10.528Z,1661961490.528 [NAL9602](INFO): SBD MO Status=0, MOMSN=44439, MT Status=0, MTMSN=0 2022-08-31T15:58:10.616Z,1661961490.616 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T15:58:10.616Z,1661961490.616 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T15:58:10.616Z,1661961490.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T15:58:41.233Z,1661961521.233 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T15:59:55.587Z,1661961595.587 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T16:03:11.123Z,1661961791.123 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:03:11.123Z,1661961791.123 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:03:11.123Z,1661961791.123 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:03:11.123Z,1661961791.123 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:03:11.573Z,1661961791.573 [Default:CheckIn:D] Stopped 2022-08-31T16:03:11.573Z,1661961791.573 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:03:11.940Z,1661961791.940 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.562217 min 2022-08-31T16:03:11.940Z,1661961791.940 [Default:CheckIn:E] Stopped 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn] Stopped 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn](INFO): Running loop #5 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn] Running Loop=5 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:03:11.941Z,1661961791.941 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:03:13.936Z,1661961793.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160320.00,A,4014.47474,N,07114.33402,W,2.333,139.82,310822,,,A*70 2022-08-31T16:03:13.938Z,1661961793.938 [NAL9602](INFO): GPS fix at 20220831T160320: (40.241246, -71.238900) 2022-08-31T16:03:13.950Z,1661961793.950 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:03:13.950Z,1661961793.950 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:03:27.855Z,1661961807.855 [NAL9602](INFO): SBD MO Status=1, MOMSN=44440, MT Status=0, MTMSN=0 2022-08-31T16:03:27.904Z,1661961807.904 [NAL9602](INFO): Sent 71 bytes from file Logs/20220831T140533/Courier0033.lzma 2022-08-31T16:03:27.904Z,1661961807.904 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:03:43.301Z,1661961823.301 [NAL9602](INFO): SBD MO Status=1, MOMSN=44441, MT Status=0, MTMSN=0 2022-08-31T16:03:43.351Z,1661961823.351 [NAL9602](INFO): Sent 119 bytes from file Logs/20220831T140533/Express0034.lzma 2022-08-31T16:03:43.351Z,1661961823.351 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:03:53.251Z,1661961833.251 [NAL9602](INFO): SBD MO Status=0, MOMSN=44442, MT Status=0, MTMSN=0 2022-08-31T16:03:53.376Z,1661961833.376 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:03:53.377Z,1661961833.377 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T16:03:53.377Z,1661961833.377 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:04:23.946Z,1661961863.946 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:08:53.842Z,1661962133.842 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:08:53.843Z,1661962133.843 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:08:53.843Z,1661962133.843 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:08:53.843Z,1661962133.843 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:08:54.254Z,1661962134.254 [Default:CheckIn:D] Stopped 2022-08-31T16:08:54.254Z,1661962134.254 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:08:54.658Z,1661962134.658 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.273572 min 2022-08-31T16:08:54.658Z,1661962134.658 [Default:CheckIn:E] Stopped 2022-08-31T16:08:54.658Z,1661962134.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:08:54.658Z,1661962134.658 [Default:CheckIn] Stopped 2022-08-31T16:08:54.658Z,1661962134.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:08:54.659Z,1661962134.659 [Default:CheckIn](INFO): Running loop #6 2022-08-31T16:08:54.659Z,1661962134.659 [Default:CheckIn] Running Loop=6 2022-08-31T16:08:54.659Z,1661962134.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:08:54.659Z,1661962134.659 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:08:56.647Z,1661962136.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160903.00,A,4014.41601,N,07114.26675,W,0.739,160.47,310822,,,A*72 2022-08-31T16:08:56.649Z,1661962136.649 [NAL9602](INFO): GPS fix at 20220831T160903: (40.240267, -71.237779) 2022-08-31T16:08:56.661Z,1661962136.661 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:08:56.661Z,1661962136.661 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:09:20.298Z,1661962160.298 [NAL9602](INFO): SBD MO Status=1, MOMSN=44443, MT Status=0, MTMSN=0 2022-08-31T16:09:20.352Z,1661962160.352 [NAL9602](INFO): Sent 79 bytes from file Logs/20220831T140533/Courier0036.lzma 2022-08-31T16:09:20.352Z,1661962160.352 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:09:31.322Z,1661962171.322 [NAL9602](INFO): SBD MO Status=1, MOMSN=44444, MT Status=0, MTMSN=0 2022-08-31T16:09:31.372Z,1661962171.372 [NAL9602](INFO): Sent 119 bytes from file Logs/20220831T140533/Express0037.lzma 2022-08-31T16:09:31.372Z,1661962171.372 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:09:43.035Z,1661962183.035 [NAL9602](INFO): SBD MO Status=0, MOMSN=44445, MT Status=0, MTMSN=0 2022-08-31T16:09:43.129Z,1661962183.129 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:09:43.129Z,1661962183.129 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T16:09:43.129Z,1661962183.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:10:13.725Z,1661962213.725 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:11:25.251Z,1661962285.251 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-08-31T16:13:26.471Z,1661962406.471 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items 2022-08-31T16:13:28.497Z,1661962408.497 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items 2022-08-31T16:14:40.386Z,1661962480.386 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T16:14:44.016Z,1661962484.016 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:14:44.016Z,1661962484.016 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:14:44.016Z,1661962484.016 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:14:44.016Z,1661962484.016 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:14:44.472Z,1661962484.472 [Default:CheckIn:D] Stopped 2022-08-31T16:14:44.472Z,1661962484.472 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:14:44.828Z,1661962484.828 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.110535 min 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn:E] Stopped 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn] Stopped 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn](INFO): Running loop #7 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn] Running Loop=7 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:14:44.829Z,1661962484.829 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:14:46.835Z,1661962486.835 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161453.00,A,4014.35749,N,07114.19719,W,0.661,146.63,310822,,,D*79 2022-08-31T16:14:46.837Z,1661962486.837 [NAL9602](INFO): GPS fix at 20220831T161453: (40.239292, -71.236620) 2022-08-31T16:14:46.866Z,1661962486.866 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:14:46.866Z,1661962486.866 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:14:50.497Z,1661962490.497 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-08-31T16:14:56.955Z,1661962496.955 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T16:15:12.504Z,1661962512.504 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T16:15:12.897Z,1661962512.897 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=44446, MT Status=1, MTMSN=1687 2022-08-31T16:15:12.960Z,1661962512.960 [NAL9602](INFO): Sent 79 bytes from file Logs/20220831T140533/Courier0039.lzma 2022-08-31T16:15:12.960Z,1661962512.960 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:15:13.600Z,1661962513.600 [NAL9602](INFO): Received command: load Maintenance/ballast_and_trim.tl;set ballast_and_trim.MassEstimationErrorBound 0.5 mm;set ballast_and_trim.BuoyEstimationErrorBound 25 cc;set ballast_and_trim.EstimationConfidence 98.0 %;run 2022-08-31T16:15:13.730Z,1661962513.730 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T16:15:13.740Z,1661962513.740 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T16:15:13.741Z,1661962513.741 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Maintenance/ballast_and_trim.tx 2022-08-31T16:15:13.880Z,1661962513.880 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 90.000000 min 2022-08-31T16:15:13.882Z,1661962513.882 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool 2022-08-31T16:15:13.885Z,1661962513.885 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 35.000000 m 2022-08-31T16:15:13.887Z,1661962513.887 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m 2022-08-31T16:15:13.889Z,1661962513.889 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m 2022-08-31T16:15:13.891Z,1661962513.891 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSpeed = 1.000000 m/s 2022-08-31T16:15:13.921Z,1661962513.921 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthTimeout = 20.000000 min 2022-08-31T16:15:13.928Z,1661962513.928 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthRate = 0.400000 m/s 2022-08-31T16:15:13.930Z,1661962513.930 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachPitchLimit = 20.000000 arcdeg 2022-08-31T16:15:13.936Z,1661962513.936 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSettleTimePreDive = 0.000000 min 2022-08-31T16:15:13.938Z,1661962513.938 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min 2022-08-31T16:15:13.941Z,1661962513.941 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min 2022-08-31T16:15:13.956Z,1661962513.956 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min 2022-08-31T16:15:13.958Z,1661962513.958 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm 2022-08-31T16:15:13.972Z,1661962513.972 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc 2022-08-31T16:15:13.974Z,1661962513.974 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 % 2022-08-31T16:15:13.981Z,1661962513.981 [MissionManager](INFO): DefineArg ballast_and_trim.massDeadband = 0.250000 mm 2022-08-31T16:15:13.983Z,1661962513.983 [MissionManager](INFO): DefineArg ballast_and_trim.MinAltitude = 5.000000 m 2022-08-31T16:15:13.993Z,1661962513.993 [MissionManager](INFO): DefineArg ballast_and_trim.MaxDepth = 52.000000 m 2022-08-31T16:15:13.000Z,1661962514.000 [MissionManager](INFO): DefineArg ballast_and_trim.MinOffshore = 2.000000 km 2022-08-31T16:15:14.002Z,1661962514.002 [MissionManager](INFO): DefineArg ballast_and_trim.CheckDepths = 1.000000 bool 2022-08-31T16:15:14.002Z,1661962514.002 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml 2022-08-31T16:15:14.398Z,1661962514.398 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool 2022-08-31T16:15:14.400Z,1661962514.400 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min 2022-08-31T16:15:14.402Z,1661962514.402 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool 2022-08-31T16:15:14.404Z,1661962514.404 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool 2022-08-31T16:15:14.406Z,1661962514.406 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool 2022-08-31T16:15:14.408Z,1661962514.408 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool 2022-08-31T16:15:14.410Z,1661962514.410 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool 2022-08-31T16:15:14.412Z,1661962514.412 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count 2022-08-31T16:15:14.414Z,1661962514.414 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count 2022-08-31T16:15:14.432Z,1661962514.432 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 % 2022-08-31T16:15:14.437Z,1661962514.437 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool 2022-08-31T16:15:14.438Z,1661962514.438 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool 2022-08-31T16:15:14.440Z,1661962514.440 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool 2022-08-31T16:15:14.442Z,1661962514.442 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool 2022-08-31T16:15:14.447Z,1661962514.447 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2022-08-31T16:15:14.454Z,1661962514.454 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool 2022-08-31T16:15:14.457Z,1661962514.457 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool 2022-08-31T16:15:14.468Z,1661962514.468 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool 2022-08-31T16:15:14.470Z,1661962514.470 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 0 bool 2022-08-31T16:15:14.477Z,1661962514.477 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 1 bool 2022-08-31T16:15:14.479Z,1661962514.479 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool 2022-08-31T16:15:14.529Z,1661962514.529 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count 2022-08-31T16:15:14.537Z,1661962514.537 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count 2022-08-31T16:15:14.545Z,1661962514.545 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m 2022-08-31T16:15:14.547Z,1661962514.547 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m 2022-08-31T16:15:14.570Z,1661962514.570 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m 2022-08-31T16:15:14.576Z,1661962514.576 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l 2022-08-31T16:15:14.578Z,1661962514.578 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m 2022-08-31T16:15:14.585Z,1661962514.585 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC 2022-08-31T16:15:14.607Z,1661962514.607 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg 2022-08-31T16:15:14.610Z,1661962514.610 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg 2022-08-31T16:15:14.620Z,1661962514.620 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l 2022-08-31T16:15:14.622Z,1661962514.622 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m 2022-08-31T16:15:14.633Z,1661962514.633 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg 2022-08-31T16:15:14.635Z,1661962514.635 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg 2022-08-31T16:15:14.649Z,1661962514.649 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3 2022-08-31T16:15:14.668Z,1661962514.668 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m 2022-08-31T16:15:14.670Z,1661962514.670 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg 2022-08-31T16:15:14.677Z,1661962514.677 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg 2022-08-31T16:15:14.679Z,1661962514.679 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb 2022-08-31T16:15:14.693Z,1661962514.693 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m 2022-08-31T16:15:14.700Z,1661962514.700 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC 2022-08-31T16:15:14.702Z,1661962514.702 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg 2022-08-31T16:15:14.708Z,1661962514.708 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg 2022-08-31T16:15:14.711Z,1661962514.711 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m 2022-08-31T16:15:14.717Z,1661962514.717 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu 2022-08-31T16:15:14.728Z,1661962514.728 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m 2022-08-31T16:15:14.731Z,1661962514.731 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC 2022-08-31T16:15:14.737Z,1661962514.737 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg 2022-08-31T16:15:14.744Z,1661962514.744 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg 2022-08-31T16:15:14.746Z,1661962514.746 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l 2022-08-31T16:15:14.752Z,1661962514.752 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m 2022-08-31T16:15:14.754Z,1661962514.754 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg 2022-08-31T16:15:14.761Z,1661962514.761 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg 2022-08-31T16:15:14.763Z,1661962514.763 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m 2022-08-31T16:15:14.770Z,1661962514.770 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu 2022-08-31T16:15:14.776Z,1661962514.776 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m 2022-08-31T16:15:14.778Z,1661962514.778 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg 2022-08-31T16:15:14.786Z,1661962514.786 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg 2022-08-31T16:15:14.793Z,1661962514.793 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m 2022-08-31T16:15:14.795Z,1661962514.795 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu 2022-08-31T16:15:14.802Z,1661962514.802 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m 2022-08-31T16:15:14.808Z,1661962514.808 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg 2022-08-31T16:15:14.810Z,1661962514.810 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg 2022-08-31T16:15:14.813Z,1661962514.813 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m 2022-08-31T16:15:14.850Z,1661962514.850 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T16:15:14.878Z,1661962514.878 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T16:15:14.972Z,1661962514.972 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T16:15:14.989Z,1661962514.989 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T16:15:15.012Z,1661962515.012 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T16:15:15.031Z,1661962515.031 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T16:15:15.061Z,1661962515.061 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2022-08-31T16:15:15.088Z,1661962515.088 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2022-08-31T16:15:15.102Z,1661962515.102 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml 2022-08-31T16:15:15.215Z,1661962515.215 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.DiveInterval = 3.000000 h 2022-08-31T16:15:15.233Z,1661962515.233 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.WaitForPitchUp = 10.000000 min 2022-08-31T16:15:15.257Z,1661962515.257 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfacePitch = 20.000000 arcdeg 2022-08-31T16:15:15.268Z,1661962515.268 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceDepthRate = nan m/s 2022-08-31T16:15:15.270Z,1661962515.270 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceSpeed = 1.000000 m/s 2022-08-31T16:15:15.288Z,1661962515.288 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.GPSTimeout = 7.000000 min 2022-08-31T16:15:15.290Z,1661962515.290 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.CommsTimeout = 30.000000 min 2022-08-31T16:15:15.347Z,1661962515.347 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-08-31T16:15:15.388Z,1661962515.388 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml 2022-08-31T16:15:15.417Z,1661962515.417 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinAltitude = 5.000000 m 2022-08-31T16:15:15.428Z,1661962515.428 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MaxDepth = 200.000000 m 2022-08-31T16:15:15.431Z,1661962515.431 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinOffshore = 2000.000000 m 2022-08-31T16:15:15.436Z,1661962515.436 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2022-08-31T16:15:15.445Z,1661962515.445 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2022-08-31T16:15:15.463Z,1661962515.463 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2022-08-31T16:15:15.491Z,1661962515.491 [ballast_and_trim:CheckTargetDepths:CheckDepth1:B.Execute](DEBUG): Construct Execute. 2022-08-31T16:15:15.499Z,1661962515.499 [ballast_and_trim:CheckTargetDepths:CheckDepth2:B.Execute](DEBUG): Construct Execute. 2022-08-31T16:15:15.511Z,1661962515.511 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml 2022-08-31T16:15:15.645Z,1661962515.645 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m 2022-08-31T16:15:15.648Z,1661962515.648 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s 2022-08-31T16:15:15.650Z,1661962515.650 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s 2022-08-31T16:15:15.652Z,1661962515.652 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg 2022-08-31T16:15:15.654Z,1661962515.654 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min 2022-08-31T16:15:15.657Z,1661962515.657 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min 2022-08-31T16:15:15.659Z,1661962515.659 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min 2022-08-31T16:15:15.661Z,1661962515.661 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min 2022-08-31T16:15:15.688Z,1661962515.688 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min 2022-08-31T16:15:15.690Z,1661962515.690 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm 2022-08-31T16:15:15.736Z,1661962515.736 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc 2022-08-31T16:15:15.738Z,1661962515.738 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 % 2022-08-31T16:15:15.745Z,1661962515.745 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m 2022-08-31T16:15:15.747Z,1661962515.747 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm 2022-08-31T16:15:15.805Z,1661962515.805 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct. 2022-08-31T16:15:15.815Z,1661962515.815 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy. 2022-08-31T16:15:15.818Z,1661962515.818 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct. 2022-08-31T16:15:15.845Z,1661962515.845 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait. 2022-08-31T16:15:15.852Z,1661962515.852 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct. 2022-08-31T16:15:15.855Z,1661962515.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct. 2022-08-31T16:15:15.869Z,1661962515.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2022-08-31T16:15:15.876Z,1661962515.876 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct. 2022-08-31T16:15:15.879Z,1661962515.879 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct. 2022-08-31T16:15:15.892Z,1661962515.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait. 2022-08-31T16:15:15.896Z,1661962515.896 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim. 2022-08-31T16:15:15.910Z,1661962515.910 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband 2022-08-31T16:15:15.911Z,1661962515.911 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = reader:ballast_and_trim.ApproachSpeed 2022-08-31T16:15:15.917Z,1661962515.917 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = reader:ballast_and_trim.ApproachDepthRate 2022-08-31T16:15:15.918Z,1661962515.918 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = reader:ballast_and_trim.ApproachPitchLimit 2022-08-31T16:15:15.924Z,1661962515.924 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = reader:ballast_and_trim.ApproachSettleTimePreDive 2022-08-31T16:15:15.925Z,1661962515.925 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.ApproachDepthTimeout 2022-08-31T16:15:15.926Z,1661962515.926 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime 2022-08-31T16:15:15.932Z,1661962515.932 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout 2022-08-31T16:15:15.933Z,1661962515.933 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime 2022-08-31T16:15:15.935Z,1661962515.935 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound 2022-08-31T16:15:15.940Z,1661962515.940 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound 2022-08-31T16:15:15.942Z,1661962515.942 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence 2022-08-31T16:15:15.947Z,1661962515.947 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = reader:ballast_and_trim.massDeadband 2022-08-31T16:15:16.027Z,1661962516.027 [MissionManager](DEBUG): mission ballast_and_trim { arguments { MissionTimeout = 90 minute """ Maximum duration of mission """ SkipComms = false """ Skip communications at start of mission. """ Depth1 = 35 meter Depth2 = NaN meter DepthDeadband = 0.1 meter """ How much vertical drift from the specified depth is allowed durnig the mission. """ ApproachSpeed = 1 meter_per_second """ Enables vehicle thruster at the commanded speed to reach target depth (set to 0 m/s to drift). """ ApproachDepthTimeout = 20 minute """ Maximum wait time for the vehicle to reach the targeted depth. """ ApproachDepthRate = 0.4 meter_per_second """ Descent depth rate (Positive depth rate means going down). """ ApproachPitchLimit = 20 degree """ Max vehicle pitch (+/-) when decending from the surface. """ ApproachSettleTimePreDive = 0 minute """ Time duration for the vehicle to pump down the VBS *BEFORE* leaving the surface. """ SettleTime = 10 minute """ How long to wait after reaching target depth before starting ballast and trim. """ EstimationTimeout = 45 minute """ Timeout for ballast and trim estimation. """ MinEstimationTime = 10 minute """ Minimum time to run ballast and trim estimation before determining convergence (must be shorter than timeout). """ MassEstimationErrorBound = 0.25 millimeter """ Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). """ BuoyEstimationErrorBound = 15 cubic_centimeter """ Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). """ EstimationConfidence = 99.9 percent """ Confidence level that the estimator has reached the desired error range (larger values take longer to converge). """ massDeadband = 0.25 millimeter """ Degree of rounding in mass-shifter command output values. """ MinAltitude = 5 meter MaxDepth = 52 meter MinOffshore = 2 kilometer CheckDepths = 1 bool } timeout duration=MissionTimeout insert Insert/Science.xml insert id="NeedComms" Insert/NeedComms.xml assign in sequence NeedComms:DiveInterval = MissionTimeout insert Insert/StandardEnvelopes.xml assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore aggregate CheckTargetDepths { run in sequence break if ( not ( CheckDepths ) ) aggregate CheckDepth1 { run in sequence break if ( not ( Depth1 > MaxDepth ) ) syslog important "Aborting ballast and trim mission. Target depth Depth1 exceeds the mission's MaxDepth setting (review mission parameters)." behavior Guidance:Execute { run in sequence set command = "stop" } } aggregate CheckDepth2 { run in sequence break if ( not ( Depth2 > MaxDepth ) ) syslog important "Aborting ballast and trim mission. Target depth Depth2 exceeds the mission's MaxDepth setting (review mission parameters)." behavior Guidance:Execute { run in sequence set command = "stop" } } assign in sequence CheckDepths = 0 bool } aggregate StartingMission { run in sequence break if ( SkipComms ) # DO NOT REMOVE the syslog entry below. The MissionManager seems to ignore the value of SkipComms, does not evaluate the Break statement properly, and always calls NeedComms. Adding the syslog call somehow fixes it. syslog info "Checking for additional instructions before submerging." call id="StartingMission" refId="NeedComms" } aggregate RunBallastAndTrim { run in sequence insert Insert/BallastAndTrim.xml { redefineArg InsertDepthDeadband = DepthDeadband redefineArg InsertApproachSpeed = ApproachSpeed redefineArg InsertApproachDepthRate = ApproachDepthRate redefineArg InsertApproachPitchLimit = ApproachPitchLimit redefineArg InsertApproachSettleTimePreDive = ApproachSettleTimePreDive redefineArg InsertApproachDepthTimeout = ApproachDepthTimeout redefineArg InsertSettleTime = SettleTime redefineArg EstTimeout = EstimationTimeout redefineArg MinEstTime = MinEstimationTime redefineArg MassEstErrorBound = MassEstimationErrorBound redefineArg BuoyEstErrorBound = BuoyEstimationErrorBound redefineArg EstConfidence = EstimationConfidence redefineArg InsertMassDeadband = massDeadband } aggregate RunDepth1 { run in sequence break if ( isNaN ( Depth1 ) ) assign in sequence BallastAndTrim:InsertDepth = Depth1 call refId="BallastAndTrim" } aggregate RunDepth2 { run in sequence break if ( isNaN ( Depth2 ) ) assign in sequence BallastAndTrim:InsertDepth = Depth2 call refId="BallastAndTrim" } } call id="EndingMission" refId="NeedComms" } 2022-08-31T16:15:16.028Z,1661962516.028 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.tl 2022-08-31T16:15:22.804Z,1661962522.804 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-08-31T16:15:27.657Z,1661962527.657 [CommandExec](IMPORTANT): got command set ballast_and_trim.MassEstimationErrorBound 0.5 millimeter 2022-08-31T16:15:27.658Z,1661962527.658 [CommandExec](IMPORTANT): got command set ballast_and_trim.BuoyEstimationErrorBound 25 cubic_centimeter 2022-08-31T16:15:27.659Z,1661962527.659 [CommandExec](IMPORTANT): got command set ballast_and_trim.EstimationConfidence 98.0 percent 2022-08-31T16:15:27.659Z,1661962527.659 [CommandExec](IMPORTANT): got command run 2022-08-31T16:15:27.661Z,1661962527.661 [CommandExec](IMPORTANT): Running 2022-08-31T16:15:27.768Z,1661962527.768 [Default] Stopped 2022-08-31T16:15:27.768Z,1661962527.768 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-31T16:15:27.768Z,1661962527.768 [Default:B.GoToSurface] Stopped 2022-08-31T16:15:27.768Z,1661962527.768 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T16:15:27.768Z,1661962527.768 [Default:CheckIn] Stopped 2022-08-31T16:15:27.769Z,1661962527.769 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:15:27.769Z,1661962527.769 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:15:27.769Z,1661962527.769 [MissionManager](IMPORTANT): Started mission ballast_and_trim 2022-08-31T16:15:27.769Z,1661962527.769 [ballast_and_trim] Running Loop=1 2022-08-31T16:15:27.769Z,1661962527.769 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim 2022-08-31T16:15:27.769Z,1661962527.769 [ballast_and_trim:Science] Running Loop=1 2022-08-31T16:15:27.769Z,1661962527.769 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:A] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:B] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:C] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:D] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:E] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:F] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:Read_Oil] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T16:15:27.770Z,1661962527.770 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T16:15:27.772Z,1661962527.772 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1 2022-08-31T16:15:27.772Z,1661962527.772 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport 2022-08-31T16:15:27.772Z,1661962527.772 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T16:15:27.772Z,1661962527.772 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T16:15:27.772Z,1661962527.772 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1 2022-08-31T16:15:27.773Z,1661962527.773 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3 2022-08-31T16:15:27.773Z,1661962527.773 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T16:15:27.773Z,1661962527.773 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T16:15:27.774Z,1661962527.774 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1 2022-08-31T16:15:27.774Z,1661962527.774 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil 2022-08-31T16:15:27.774Z,1661962527.774 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T16:15:27.774Z,1661962527.774 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T16:15:27.775Z,1661962527.775 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM 2022-08-31T16:15:27.776Z,1661962527.776 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T16:15:27.777Z,1661962527.777 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T16:15:27.778Z,1661962527.778 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1 2022-08-31T16:15:27.778Z,1661962527.778 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity 2022-08-31T16:15:27.778Z,1661962527.778 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1 2022-08-31T16:15:27.778Z,1661962527.778 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize. 2022-08-31T16:15:27.779Z,1661962527.779 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1 2022-08-31T16:15:27.779Z,1661962527.779 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:OceanCurrent] Running Loop=1 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator. 2022-08-31T16:15:27.780Z,1661962527.780 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::initialize ballast_and_trim:StandardEnvelopes 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2022-08-31T16:15:27.781Z,1661962527.781 [ballast_and_trim:C] Running Loop=1 2022-08-31T16:15:27.782Z,1661962527.782 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2022-08-31T16:15:27.782Z,1661962527.782 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2022-08-31T16:15:27.782Z,1661962527.782 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2022-08-31T16:15:27.783Z,1661962527.783 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2022-08-31T16:15:27.783Z,1661962527.783 [ballast_and_trim:C] Stopped 2022-08-31T16:15:27.783Z,1661962527.783 [ballast_and_trim:E] Running Loop=1 2022-08-31T16:15:27.784Z,1661962527.784 [ballast_and_trim:Science] Running Loop=1 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectSalinity] Stopped 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectFDOM] Stopped 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM 2022-08-31T16:15:27.785Z,1661962527.785 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:HighestOilPeakReport] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectOil] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectNO3] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2022-08-31T16:15:27.786Z,1661962527.786 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:HighestChlPeakReport] Stopped 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:PeakDetectChl] Stopped 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2022-08-31T16:15:27.787Z,1661962527.787 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:Read_Oil] Running Loop=1 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_petroleum_hydrocarbons_in_sea_water 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:F] Stopped 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:E] Stopped 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:D] Stopped 2022-08-31T16:15:27.789Z,1661962527.789 [ballast_and_trim:Science:C] Running Loop=1 2022-08-31T16:15:27.790Z,1661962527.790 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2022-08-31T16:15:27.790Z,1661962527.790 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2022-08-31T16:15:27.790Z,1661962527.790 [ballast_and_trim:Science:B] Running Loop=1 2022-08-31T16:15:27.791Z,1661962527.791 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2022-08-31T16:15:27.791Z,1661962527.791 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2022-08-31T16:15:27.792Z,1661962527.792 [ballast_and_trim:Science:A] Stopped 2022-08-31T16:15:28.197Z,1661962528.197 [ballast_and_trim:E] Stopped 2022-08-31T16:15:28.198Z,1661962528.198 [ballast_and_trim:F] Running Loop=1 2022-08-31T16:15:28.629Z,1661962528.629 [ballast_and_trim:F] Stopped 2022-08-31T16:15:28.629Z,1661962528.629 [ballast_and_trim:G] Running Loop=1 2022-08-31T16:15:28.975Z,1661962528.975 [ballast_and_trim:G] Stopped 2022-08-31T16:15:28.975Z,1661962528.975 [ballast_and_trim:CheckTargetDepths] Running Loop=1 2022-08-31T16:15:28.975Z,1661962528.975 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths 2022-08-31T16:15:28.975Z,1661962528.975 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Running Loop=1 2022-08-31T16:15:28.975Z,1661962528.975 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2022-08-31T16:15:28.995Z,1661962528.995 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Running Loop=1 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Stopped 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Stopped 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Running Loop=1 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2022-08-31T16:15:29.408Z,1661962529.408 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Running Loop=1 2022-08-31T16:15:29.786Z,1661962529.786 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Stopped 2022-08-31T16:15:29.786Z,1661962529.786 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2022-08-31T16:15:29.786Z,1661962529.786 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Stopped 2022-08-31T16:15:29.786Z,1661962529.786 [ballast_and_trim:CheckTargetDepths:C] Running Loop=1 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:CheckTargetDepths:C] Stopped 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:CheckTargetDepths](INFO): Completed ballast_and_trim:CheckTargetDepths 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:CheckTargetDepths] Stopped 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:StartingMission] Running Loop=1 2022-08-31T16:15:30.257Z,1661962530.257 [ballast_and_trim:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission 2022-08-31T16:15:30.258Z,1661962530.258 [ballast_and_trim:StartingMission:A] Running Loop=1 2022-08-31T16:15:30.649Z,1661962530.649 [ballast_and_trim:StartingMission:A](INFO): Checking for additional instructions before submerging. 2022-08-31T16:15:30.649Z,1661962530.649 [ballast_and_trim:StartingMission:A] Stopped 2022-08-31T16:15:30.649Z,1661962530.649 [ballast_and_trim:StartingMission:StartingMission] Running Loop=1 2022-08-31T16:15:30.649Z,1661962530.649 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission:StartingMission 2022-08-31T16:15:30.998Z,1661962530.998 [ballast_and_trim:NeedComms] Running Loop=1 2022-08-31T16:15:30.998Z,1661962530.998 [ballast_and_trim:NeedComms](DEBUG): Aggregate::initialize ballast_and_trim:NeedComms 2022-08-31T16:15:30.999Z,1661962530.999 [ballast_and_trim:NeedComms:B.GoToSurface] Running Loop=1 2022-08-31T16:15:30.999Z,1661962530.999 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T16:15:30.999Z,1661962530.999 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2022-08-31T16:15:30.000Z,1661962531.000 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2022-08-31T16:15:30.000Z,1661962531.000 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2022-08-31T16:15:31.000Z,1661962531.000 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T16:15:31.001Z,1661962531.001 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T16:15:31.001Z,1661962531.001 [ballast_and_trim:NeedComms:A] Running Loop=1 2022-08-31T16:15:31.002Z,1661962531.002 [ballast_and_trim:NeedComms:A](INFO): last time_fix was: 1661962493.000000 second since 1970/01/01T00:00:00Z 2022-08-31T16:15:31.002Z,1661962531.002 [ballast_and_trim:NeedComms:A] Stopped 2022-08-31T16:15:31.418Z,1661962531.418 [ballast_and_trim:NeedComms:C] Running Loop=1 2022-08-31T16:15:31.565Z,1661962531.565 [CTD_Seabird](ERROR): Failed to parse device response: 2022-08-31T16:15:31.824Z,1661962531.824 [ballast_and_trim:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-08-31T16:15:39.868Z,1661962539.868 [NAL9602](INFO): SBD MO Status=1, MOMSN=44447, MT Status=0, MTMSN=0 2022-08-31T16:15:39.920Z,1661962539.920 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0040.lzma 2022-08-31T16:15:39.920Z,1661962539.920 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:15:41.080Z,1661962541.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161547.00,A,4014.34757,N,07114.18666,W,0.778,133.20,310822,,,A*72 2022-08-31T16:15:41.082Z,1661962541.082 [NAL9602](INFO): GPS fix at 20220831T161547: (40.239126, -71.236444) 2022-08-31T16:15:41.112Z,1661962541.112 [ballast_and_trim:NeedComms:C] Stopped 2022-08-31T16:15:41.112Z,1661962541.112 [ballast_and_trim:NeedComms:D] Running Loop=1 2022-08-31T16:15:41.533Z,1661962541.533 [ballast_and_trim:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-08-31T16:15:43.518Z,1661962543.518 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T16:15:50.300Z,1661962550.300 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T16:15:52.319Z,1661962552.319 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T16:16:02.344Z,1661962562.344 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T16:16:05.156Z,1661962565.156 [NAL9602](INFO): SBD MO Status=1, MOMSN=44448, MT Status=0, MTMSN=0 2022-08-31T16:16:05.213Z,1661962565.213 [NAL9602](INFO): Sent 51 bytes from file Logs/20220831T140533/Courier0042.lzma 2022-08-31T16:16:05.213Z,1661962565.213 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:16:12.361Z,1661962572.361 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2022-08-31T16:16:12.361Z,1661962572.361 [RDI_Pathfinder] Communications Fault, FailCount= 1 2022-08-31T16:16:12.361Z,1661962572.361 [RDI_Pathfinder](ERROR): Communications Fault 2022-08-31T16:16:12.423Z,1661962572.423 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2022-08-31T16:16:12.800Z,1661962572.800 [RDI_Pathfinder](INFO): Powering down 2022-08-31T16:16:13.581Z,1661962573.581 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2022-08-31T16:16:13.581Z,1661962573.581 [RDI_Pathfinder] No Fault, FailCount= 1 2022-08-31T16:16:13.939Z,1661962573.939 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2022-08-31T16:16:28.897Z,1661962588.897 [NAL9602](INFO): SBD MO Status=1, MOMSN=44449, MT Status=0, MTMSN=0 2022-08-31T16:16:28.952Z,1661962588.952 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0045.lzma 2022-08-31T16:16:28.952Z,1661962588.952 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:16:44.435Z,1661962604.435 [NAL9602](INFO): SBD MO Status=1, MOMSN=44450, MT Status=0, MTMSN=0 2022-08-31T16:16:44.492Z,1661962604.492 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0043.lzma 2022-08-31T16:16:44.492Z,1661962604.492 [NAL9602](INFO): Packets left to send: 2 2022-08-31T16:17:01.181Z,1661962621.181 [NAL9602](INFO): SBD MO Status=1, MOMSN=44451, MT Status=0, MTMSN=0 2022-08-31T16:17:01.232Z,1661962621.232 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0043.lzma 2022-08-31T16:17:01.232Z,1661962621.232 [NAL9602](INFO): Packets left to send: 1 2022-08-31T16:17:12.018Z,1661962632.018 [NAL9602](INFO): SBD MO Status=1, MOMSN=44452, MT Status=0, MTMSN=0 2022-08-31T16:17:12.068Z,1661962632.068 [NAL9602](INFO): Sent 5 bytes from file Logs/20220831T140533/Express0043.lzma 2022-08-31T16:17:12.068Z,1661962632.068 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:17:21.372Z,1661962641.372 [NAL9602](INFO): SBD MO Status=1, MOMSN=44453, MT Status=0, MTMSN=0 2022-08-31T16:17:21.428Z,1661962641.428 [NAL9602](INFO): Sent 74 bytes from file Logs/20220831T140533/Express0046.lzma 2022-08-31T16:17:21.428Z,1661962641.428 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:17:34.075Z,1661962654.075 [NAL9602](INFO): SBD MO Status=0, MOMSN=44454, MT Status=0, MTMSN=0 2022-08-31T16:17:34.229Z,1661962654.229 [ballast_and_trim:NeedComms:D] Stopped 2022-08-31T16:17:34.229Z,1661962654.229 [ballast_and_trim:NeedComms:E] Running Loop=1 2022-08-31T16:17:34.446Z,1661962654.446 [ballast_and_trim:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-08-31T16:17:36.445Z,1661962656.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161743.00,A,4014.32637,N,07114.16364,W,2.469,154.91,310822,,,A*76 2022-08-31T16:17:36.447Z,1661962656.447 [NAL9602](INFO): GPS fix at 20220831T161743: (40.238773, -71.236061) 2022-08-31T16:17:36.498Z,1661962656.498 [ballast_and_trim:NeedComms:E] Stopped 2022-08-31T16:17:36.499Z,1661962656.499 [ballast_and_trim:NeedComms](INFO): Completed ballast_and_trim:NeedComms 2022-08-31T16:17:36.499Z,1661962656.499 [ballast_and_trim:NeedComms] Stopped 2022-08-31T16:17:36.499Z,1661962656.499 [ballast_and_trim:NeedComms](DEBUG): Aggregate::uninitialize ballast_and_trim:NeedComms 2022-08-31T16:17:36.499Z,1661962656.499 [ballast_and_trim:NeedComms:B.GoToSurface] Stopped 2022-08-31T16:17:36.504Z,1661962656.504 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T16:17:36.884Z,1661962656.884 [ballast_and_trim:StartingMission:StartingMission](INFO): Completed ballast_and_trim:StartingMission:StartingMission 2022-08-31T16:17:36.884Z,1661962656.884 [ballast_and_trim:StartingMission:StartingMission] Stopped 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission:StartingMission 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:StartingMission](INFO): Completed ballast_and_trim:StartingMission 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:StartingMission] Stopped 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:RunBallastAndTrim] Running Loop=1 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Running Loop=1 2022-08-31T16:17:36.885Z,1661962656.885 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2022-08-31T16:17:36.886Z,1661962656.886 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Running Loop=1 2022-08-31T16:17:37.273Z,1661962657.273 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Stopped 2022-08-31T16:17:37.273Z,1661962657.273 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Running Loop=1 2022-08-31T16:17:37.273Z,1661962657.273 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2022-08-31T16:17:37.700Z,1661962657.700 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1 2022-08-31T16:17:37.700Z,1661962657.700 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2022-08-31T16:17:37.700Z,1661962657.700 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2022-08-31T16:17:37.700Z,1661962657.700 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2022-08-31T16:17:37.701Z,1661962657.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2022-08-31T16:17:37.701Z,1661962657.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2022-08-31T16:17:37.701Z,1661962657.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2022-08-31T16:17:37.701Z,1661962657.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 1.000000 m/s 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2022-08-31T16:17:37.720Z,1661962657.720 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize. 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize. 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1 2022-08-31T16:17:37.721Z,1661962657.721 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T16:17:37.722Z,1661962657.722 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1 2022-08-31T16:17:37.722Z,1661962657.722 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2022-08-31T16:17:37.722Z,1661962657.722 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2022-08-31T16:17:37.722Z,1661962657.722 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2022-08-31T16:17:37.722Z,1661962657.722 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2022-08-31T16:17:37.723Z,1661962657.723 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2022-08-31T16:17:38.168Z,1661962658.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral. 2022-08-31T16:17:38.168Z,1661962658.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped 2022-08-31T16:17:38.168Z,1661962658.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1 2022-08-31T16:17:38.168Z,1661962658.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:17:38.168Z,1661962658.168 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1 2022-08-31T16:17:38.169Z,1661962658.169 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1 2022-08-31T16:17:38.169Z,1661962658.169 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1 2022-08-31T16:17:38.169Z,1661962658.169 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1 2022-08-31T16:17:38.169Z,1661962658.169 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting. 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1 2022-08-31T16:17:38.496Z,1661962658.496 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T16:17:38.497Z,1661962658.497 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2022-08-31T16:17:38.497Z,1661962658.497 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize. 2022-08-31T16:17:38.497Z,1661962658.497 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1 2022-08-31T16:17:38.906Z,1661962658.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2022-08-31T16:17:38.906Z,1661962658.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 35.000000 m 2022-08-31T16:17:38.906Z,1661962658.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped 2022-08-31T16:17:38.907Z,1661962658.907 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1 2022-08-31T16:17:38.907Z,1661962658.907 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize. 2022-08-31T16:18:09.229Z,1661962689.229 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:18:12.474Z,1661962692.474 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T16:20:51.882Z,1661962851.882 [CTD_Seabird](ERROR): Salinity reading out of range: 23.283226 psu 2022-08-31T16:21:28.096Z,1661962888.096 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-08-31T16:24:13.124Z,1661963053.124 [Radio_Surface](INFO): Powering down 2022-08-31T16:24:15.784Z,1661963055.784 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-08-31T16:26:50.898Z,1661963210.898 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped 2022-08-31T16:26:50.899Z,1661963210.899 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T16:26:50.899Z,1661963210.899 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped 2022-08-31T16:26:50.899Z,1661963210.899 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2022-08-31T16:26:50.899Z,1661963210.899 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped 2022-08-31T16:26:50.899Z,1661963210.899 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize. 2022-08-31T16:26:50.900Z,1661963210.900 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T16:26:50.900Z,1661963210.900 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped 2022-08-31T16:26:50.900Z,1661963210.900 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize. 2022-08-31T16:26:50.901Z,1661963210.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2022-08-31T16:26:50.902Z,1661963210.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize. 2022-08-31T16:26:50.902Z,1661963210.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1 2022-08-31T16:26:51.307Z,1661963211.307 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 35.056530 m 2022-08-31T16:26:51.307Z,1661963211.307 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped 2022-08-31T16:26:51.308Z,1661963211.308 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1 2022-08-31T16:26:51.308Z,1661963211.308 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:26:51.308Z,1661963211.308 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2022-08-31T16:26:51.308Z,1661963211.308 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2022-08-31T16:26:58.229Z,1661963218.229 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items 2022-08-31T16:27:00.669Z,1661963220.669 [CBIT](CRITICAL): STOP DEPTH REACHED. Terminating Mission. 2022-08-31T16:27:00.670Z,1661963220.670 [Supervisor](INFO): Stop Mission called by CBIT::checkDepth 2022-08-31T16:27:01.019Z,1661963221.019 [MissionManager](INFO): MissionManager is completed. 2022-08-31T16:27:01.019Z,1661963221.019 [MissionManager](INFO): Uninitializing Mission ballast_and_trim 2022-08-31T16:27:01.019Z,1661963221.019 [ballast_and_trim] Stopped 2022-08-31T16:27:01.019Z,1661963221.019 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim 2022-08-31T16:27:01.019Z,1661963221.019 [ballast_and_trim:Science] Stopped 2022-08-31T16:27:01.023Z,1661963221.023 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science 2022-08-31T16:27:01.023Z,1661963221.023 [ballast_and_trim:Science:B] Stopped 2022-08-31T16:27:01.023Z,1661963221.023 [ballast_and_trim:Science:C] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:Science:Read_Oil] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:Science:OceanCurrent] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:Science:OceanCurrent:A.] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::uninitialize ballast_and_trim:StandardEnvelopes 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2022-08-31T16:27:01.024Z,1661963221.024 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize. 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped 2022-08-31T16:27:01.025Z,1661963221.025 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped 2022-08-31T16:27:01.026Z,1661963221.026 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:27:01.026Z,1661963221.026 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Stopped 2022-08-31T16:27:01.026Z,1661963221.026 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2022-08-31T16:27:01.026Z,1661963221.026 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Stopped 2022-08-31T16:27:01.026Z,1661963221.026 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2022-08-31T16:27:01.193Z,1661963221.193 [CommandExec](FAULT): Scheduling is paused 2022-08-31T16:27:01.194Z,1661963221.194 [CBIT](INFO): Critical error at 20220831T162700 2022-08-31T16:27:01.406Z,1661963221.406 [MissionManager](IMPORTANT): Started mission Default 2022-08-31T16:27:01.406Z,1661963221.406 [Default] Running Loop=1 2022-08-31T16:27:01.406Z,1661963221.406 [Default](DEBUG): Aggregate::initialize Default 2022-08-31T16:27:01.406Z,1661963221.406 [Default:B.GoToSurface] Running Loop=1 2022-08-31T16:27:01.406Z,1661963221.406 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-31T16:27:01.407Z,1661963221.407 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-08-31T16:27:01.407Z,1661963221.407 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-08-31T16:27:01.407Z,1661963221.407 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-08-31T16:27:01.408Z,1661963221.408 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-31T16:27:01.408Z,1661963221.408 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-31T16:27:01.409Z,1661963221.409 [Default:A.Wait] Running Loop=1 2022-08-31T16:27:01.409Z,1661963221.409 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:27:01.777Z,1661963221.777 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -25.00 mm (1 active estimators). 2022-08-31T16:27:02.004Z,1661963222.004 [Radio_Surface](INFO): Powering up 2022-08-31T16:27:07.500Z,1661963227.500 [DataOverHttps](INFO): Radio surface powered ON. 2022-08-31T16:27:14.739Z,1661963234.739 [Default:A.Wait](INFO): Done Waiting. 2022-08-31T16:27:14.739Z,1661963234.739 [Default:A.Wait] Stopped 2022-08-31T16:27:14.739Z,1661963234.739 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:28:41.977Z,1661963321.977 [Default:CheckIn] Running Loop=1 2022-08-31T16:28:41.977Z,1661963321.977 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:28:41.977Z,1661963321.977 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:28:54.106Z,1661963334.106 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=44455, MT Status=1, MTMSN=1688 2022-08-31T16:28:54.106Z,1661963334.106 [NAL9602](INFO): Data available in MT queue 2022-08-31T16:28:54.652Z,1661963334.652 [NAL9602](INFO): Received command: get CTD_Seabird.loadAtStartup 2022-08-31T16:28:55.736Z,1661963335.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162902.00,A,4014.27495,N,07114.09284,W,0.933,204.98,310822,,,D*7B 2022-08-31T16:28:55.738Z,1661963335.738 [NAL9602](INFO): GPS fix at 20220831T162902: (40.237916, -71.234881) 2022-08-31T16:28:55.803Z,1661963335.803 [UniversalFixResidualReporter](INFO): Fix residual: 14.2 %DT, over the last 507.1 m. Residual distance 72.0 m at bearing -23.4 degrees. Fix at (40.2379, -71.2349) with 138.3 m made good. 2022-08-31T16:28:55.804Z,1661963335.804 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:28:55.804Z,1661963335.804 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:28:55.917Z,1661963335.917 [CommandExec](IMPORTANT): got command get CTD_Seabird.loadAtStartup 2022-08-31T16:28:55.918Z,1661963335.918 [CommandExec](IMPORTANT): CTD_Seabird.loadAtStartup 1 bool 2022-08-31T16:29:11.026Z,1661963351.026 [NAL9602](INFO): SBD MO Status=1, MOMSN=44456, MT Status=0, MTMSN=0 2022-08-31T16:29:11.080Z,1661963351.080 [NAL9602](INFO): Sent 164 bytes from file Logs/20220831T140533/Courier0048.lzma 2022-08-31T16:29:11.080Z,1661963351.080 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:29:28.936Z,1661963368.936 [NAL9602](INFO): SBD MO Status=1, MOMSN=44457, MT Status=0, MTMSN=0 2022-08-31T16:29:28.984Z,1661963368.984 [NAL9602](INFO): Sent 184 bytes from file Logs/20220831T140533/Express0049.lzma 2022-08-31T16:29:28.984Z,1661963368.984 [NAL9602](INFO): Packets left to send: 1 2022-08-31T16:29:33.482Z,1661963373.482 [BPC1](ERROR): BPC1B: No match for serial number FFFF in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2022-08-31T16:29:44.770Z,1661963384.770 [NAL9602](INFO): SBD MO Status=1, MOMSN=44458, MT Status=0, MTMSN=0 2022-08-31T16:29:44.832Z,1661963384.832 [NAL9602](INFO): Sent 126 bytes from file Logs/20220831T140533/Express0049.lzma 2022-08-31T16:29:44.832Z,1661963384.832 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:29:52.108Z,1661963392.108 [NAL9602](INFO): SBD MO Status=0, MOMSN=44459, MT Status=0, MTMSN=0 2022-08-31T16:30:02.422Z,1661963402.422 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error 2022-08-31T16:30:08.160Z,1661963408.160 [NAL9602](INFO): SBD MO Status=1, MOMSN=44460, MT Status=0, MTMSN=0 2022-08-31T16:30:08.208Z,1661963408.208 [NAL9602](INFO): Sent 52 bytes from file Logs/20220831T140533/Courier0051.lzma 2022-08-31T16:30:08.208Z,1661963408.208 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:30:19.412Z,1661963419.412 [NAL9602](INFO): SBD MO Status=1, MOMSN=44461, MT Status=0, MTMSN=0 2022-08-31T16:30:19.476Z,1661963419.476 [NAL9602](INFO): Sent 62 bytes from file Logs/20220831T140533/Express0052.lzma 2022-08-31T16:30:19.476Z,1661963419.476 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:30:33.143Z,1661963433.143 [NAL9602](INFO): SBD MO Status=0, MOMSN=44462, MT Status=0, MTMSN=0 2022-08-31T16:30:33.220Z,1661963433.220 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:30:33.220Z,1661963433.220 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T16:30:33.221Z,1661963433.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:31:03.830Z,1661963463.830 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:32:28.277Z,1661963548.277 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-08-31T16:33:18.385Z,1661963598.385 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-08-31T16:35:33.739Z,1661963733.739 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:35:33.739Z,1661963733.739 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:35:33.739Z,1661963733.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:35:33.739Z,1661963733.739 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:35:34.194Z,1661963734.194 [Default:CheckIn:D] Stopped 2022-08-31T16:35:34.194Z,1661963734.194 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.546455 min 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn:E] Stopped 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn] Stopped 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn](INFO): Running loop #2 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn] Running Loop=2 2022-08-31T16:35:34.537Z,1661963734.537 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:35:34.538Z,1661963734.538 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:35:36.527Z,1661963736.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163543.00,A,4014.19139,N,07114.01151,W,0.972,143.79,310822,,,A*71 2022-08-31T16:35:36.529Z,1661963736.529 [NAL9602](INFO): GPS fix at 20220831T163543: (40.236523, -71.233525) 2022-08-31T16:35:36.557Z,1661963736.557 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:35:36.557Z,1661963736.557 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:35:56.162Z,1661963756.162 [NAL9602](INFO): SBD MO Status=1, MOMSN=44463, MT Status=0, MTMSN=0 2022-08-31T16:35:56.212Z,1661963756.212 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0054.lzma 2022-08-31T16:35:56.212Z,1661963756.212 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:36:14.887Z,1661963774.887 [NAL9602](INFO): SBD MO Status=1, MOMSN=44464, MT Status=0, MTMSN=0 2022-08-31T16:36:14.936Z,1661963774.936 [NAL9602](INFO): Sent 119 bytes from file Logs/20220831T140533/Express0055.lzma 2022-08-31T16:36:14.936Z,1661963774.936 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:36:29.400Z,1661963789.400 [NAL9602](INFO): SBD MO Status=0, MOMSN=44465, MT Status=0, MTMSN=0 2022-08-31T16:36:29.481Z,1661963789.481 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:36:29.481Z,1661963789.481 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T16:36:29.481Z,1661963789.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:37:00.106Z,1661963820.106 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:38:48.436Z,1661963928.436 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items 2022-08-31T16:41:29.980Z,1661964089.980 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:41:29.980Z,1661964089.980 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:41:29.980Z,1661964089.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:41:29.980Z,1661964089.980 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:41:30.456Z,1661964090.456 [Default:CheckIn:D] Stopped 2022-08-31T16:41:30.456Z,1661964090.456 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:41:30.804Z,1661964090.804 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.484167 min 2022-08-31T16:41:30.804Z,1661964090.804 [Default:CheckIn:E] Stopped 2022-08-31T16:41:30.804Z,1661964090.804 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:41:30.805Z,1661964090.805 [Default:CheckIn] Stopped 2022-08-31T16:41:30.805Z,1661964090.805 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:41:30.806Z,1661964090.806 [Default:CheckIn](INFO): Running loop #3 2022-08-31T16:41:30.806Z,1661964090.806 [Default:CheckIn] Running Loop=3 2022-08-31T16:41:30.807Z,1661964090.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:41:30.807Z,1661964090.807 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:41:32.840Z,1661964092.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164139.00,A,4014.11892,N,07113.93418,W,0.700,148.37,310822,,,D*74 2022-08-31T16:41:32.842Z,1661964092.842 [NAL9602](INFO): GPS fix at 20220831T164139: (40.235315, -71.232236) 2022-08-31T16:41:32.864Z,1661964092.864 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:41:32.864Z,1661964092.864 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:41:52.912Z,1661964112.912 [NAL9602](INFO): SBD MO Status=1, MOMSN=44466, MT Status=0, MTMSN=0 2022-08-31T16:41:52.964Z,1661964112.964 [NAL9602](INFO): Sent 72 bytes from file Logs/20220831T140533/Courier0057.lzma 2022-08-31T16:41:52.964Z,1661964112.964 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:42:04.100Z,1661964124.100 [NAL9602](INFO): SBD MO Status=1, MOMSN=44467, MT Status=0, MTMSN=0 2022-08-31T16:42:04.148Z,1661964124.148 [NAL9602](INFO): Sent 120 bytes from file Logs/20220831T140533/Express0058.lzma 2022-08-31T16:42:04.148Z,1661964124.148 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:42:15.781Z,1661964135.781 [NAL9602](INFO): SBD MO Status=0, MOMSN=44468, MT Status=0, MTMSN=0 2022-08-31T16:42:15.880Z,1661964135.880 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:42:15.881Z,1661964135.881 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-31T16:42:15.881Z,1661964135.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-31T16:42:46.420Z,1661964166.420 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-31T16:47:16.366Z,1661964436.366 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-31T16:47:16.366Z,1661964436.366 [Default:CheckIn:C.Wait] Stopped 2022-08-31T16:47:16.367Z,1661964436.367 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-31T16:47:16.367Z,1661964436.367 [Default:CheckIn:D] Running Loop=1 2022-08-31T16:47:16.774Z,1661964436.774 [Default:CheckIn:D] Stopped 2022-08-31T16:47:16.774Z,1661964436.774 [Default:CheckIn:E] Running Loop=1 2022-08-31T16:47:17.130Z,1661964437.130 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.256134 min 2022-08-31T16:47:17.130Z,1661964437.130 [Default:CheckIn:E] Stopped 2022-08-31T16:47:17.130Z,1661964437.130 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-31T16:47:17.130Z,1661964437.130 [Default:CheckIn] Stopped 2022-08-31T16:47:17.130Z,1661964437.130 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:47:17.131Z,1661964437.131 [Default:CheckIn](INFO): Running loop #4 2022-08-31T16:47:17.131Z,1661964437.131 [Default:CheckIn] Running Loop=4 2022-08-31T16:47:17.131Z,1661964437.131 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-31T16:47:17.131Z,1661964437.131 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-31T16:47:19.129Z,1661964439.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164725.00,A,4014.04682,N,07113.85684,W,1.147,149.64,310822,,,D*77 2022-08-31T16:47:19.133Z,1661964439.133 [NAL9602](INFO): GPS fix at 20220831T164725: (40.234114, -71.230947) 2022-08-31T16:47:19.151Z,1661964439.151 [Default:CheckIn:Read_GPS] Stopped 2022-08-31T16:47:19.151Z,1661964439.151 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-31T16:47:31.998Z,1661964451.998 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=44469, MT Status=1, MTMSN=1689 2022-08-31T16:47:32.052Z,1661964452.052 [NAL9602](INFO): Sent 78 bytes from file Logs/20220831T140533/Courier0060.lzma 2022-08-31T16:47:32.052Z,1661964452.052 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:47:32.556Z,1661964452.556 [NAL9602](INFO): Received command: configSet CBIT.stopDepth 200 meter persist;configSet CBIT.abortDepth 250 meter persist 2022-08-31T16:47:33.023Z,1661964453.023 [CommandExec](IMPORTANT): got command configSet CBIT.stopDepth 200 meter persist 2022-08-31T16:47:33.026Z,1661964453.026 [CommandExec](IMPORTANT): got command configSet CBIT.abortDepth 250 meter persist 2022-08-31T16:47:53.884Z,1661964473.884 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=44470, MT Status=1, MTMSN=1690 2022-08-31T16:47:53.936Z,1661964473.936 [NAL9602](INFO): Sent 119 bytes from file Logs/20220831T140533/Express0061.lzma 2022-08-31T16:47:53.936Z,1661964473.936 [NAL9602](INFO): Packets left to send: 0 2022-08-31T16:47:54.400Z,1661964474.400 [NAL9602](INFO): Received command: restart app 2022-08-31T16:47:54.473Z,1661964474.473 [CommandExec](IMPORTANT): got command restart application 2022-08-31T16:47:55.476Z,1661964475.476 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:55.476Z,1661964475.476 [CommandExec](INFO): Uninitializing the command executive. 2022-08-31T16:47:55.476Z,1661964475.476 [CommandExec](INFO): Uninitializing the command scheduler. 2022-08-31T16:47:55.476Z,1661964475.476 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.539Z,1661964475.539 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-08-31T16:47:55.539Z,1661964475.539 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-08-31T16:47:55.540Z,1661964475.540 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.540Z,1661964475.540 [NavChartDb](INFO): Join timeout helper Thread ID is 9738 2022-08-31T16:47:55.760Z,1661964475.760 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:55.760Z,1661964475.760 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.767Z,1661964475.767 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2022-08-31T16:47:55.768Z,1661964475.768 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.768Z,1661964475.768 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 9739 2022-08-31T16:47:55.803Z,1661964475.803 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:55.804Z,1661964475.804 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.808Z,1661964475.808 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-08-31T16:47:55.808Z,1661964475.808 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:55.808Z,1661964475.808 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9740 2022-08-31T16:47:56.603Z,1661964476.603 [CTD_Seabird](INFO): Powering down 2022-08-31T16:47:56.615Z,1661964476.615 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:56.616Z,1661964476.616 [CTD_Seabird](INFO): Powering down 2022-08-31T16:47:56.628Z,1661964476.628 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:56.649Z,1661964476.649 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-08-31T16:47:56.649Z,1661964476.649 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:56.650Z,1661964476.650 [Radio_Surface](INFO): Join timeout helper Thread ID is 9741 2022-08-31T16:47:56.887Z,1661964476.887 [Radio_Surface](INFO): Powering down 2022-08-31T16:47:56.888Z,1661964476.888 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:56.889Z,1661964476.889 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:56.891Z,1661964476.891 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-08-31T16:47:56.892Z,1661964476.892 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:56.892Z,1661964476.892 [Onboard](INFO): Join timeout helper Thread ID is 9742 2022-08-31T16:47:58.796Z,1661964478.796 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:58.796Z,1661964478.796 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:58.816Z,1661964478.816 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-08-31T16:47:58.816Z,1661964478.816 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:58.817Z,1661964478.817 [DataOverHttps](INFO): Join timeout helper Thread ID is 9743 2022-08-31T16:47:59.676Z,1661964479.676 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:59.676Z,1661964479.676 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.697Z,1661964479.697 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-08-31T16:47:59.697Z,1661964479.697 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.697Z,1661964479.697 [logger](INFO): Join timeout helper Thread ID is 9744 2022-08-31T16:47:59.721Z,1661964479.721 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:59.721Z,1661964479.721 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.728Z,1661964479.728 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-08-31T16:47:59.728Z,1661964479.728 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.729Z,1661964479.729 [CommandLine](INFO): Join timeout helper Thread ID is 9745 2022-08-31T16:47:59.796Z,1661964479.796 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:47:59.796Z,1661964479.796 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.812Z,1661964479.812 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-08-31T16:47:59.812Z,1661964479.812 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.813Z,1661964479.813 [CommandExec](INFO): Join timeout helper Thread ID is 9746 2022-08-31T16:47:59.824Z,1661964479.824 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-08-31T16:47:59.824Z,1661964479.824 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:47:59.825Z,1661964479.825 [controlThread](INFO): Join timeout helper Thread ID is 9747 2022-08-31T16:48:00.558Z,1661964480.558 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-31T16:48:00.558Z,1661964480.558 [controlThread](DEBUG): Uninitializing ControlThread 2022-08-31T16:48:00.559Z,1661964480.559 [AHRS_M2](INFO): Powering down 2022-08-31T16:48:00.632Z,1661964480.632 [DDM](INFO): Powering down 2022-08-31T16:48:00.706Z,1661964480.706 [Micromodem](INFO): Powering down 2022-08-31T16:48:00.800Z,1661964480.800 [NAL9602](INFO): Powering down 2022-08-31T16:48:00.871Z,1661964480.871 [RDI_Pathfinder](INFO): Powering down 2022-08-31T16:48:00.943Z,1661964480.943 [RDI_PathfinderUp](INFO): Powering down 2022-08-31T16:48:00.945Z,1661964480.945 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-08-31T16:48:00.946Z,1661964480.946 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-08-31T16:48:00.946Z,1661964480.946 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-08-31T16:48:00.947Z,1661964480.947 [MissionManager](INFO): Uninitializing Mission Default 2022-08-31T16:48:00.947Z,1661964480.947 [Default] Stopped 2022-08-31T16:48:00.947Z,1661964480.947 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-31T16:48:00.947Z,1661964480.947 [Default:B.GoToSurface] Stopped 2022-08-31T16:48:00.948Z,1661964480.948 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-31T16:48:00.948Z,1661964480.948 [Default:CheckIn] Stopped 2022-08-31T16:48:00.948Z,1661964480.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-31T16:48:00.948Z,1661964480.948 [Default:CheckIn:Read_Iridium] Stopped 2022-08-31T16:48:00.950Z,1661964480.950 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-08-31T16:48:00.951Z,1661964480.951 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-08-31T16:48:00.951Z,1661964480.951 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-08-31T16:48:00.951Z,1661964480.951 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-08-31T16:48:00.952Z,1661964480.952 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-08-31T16:48:00.952Z,1661964480.952 [BuoyancyServo](INFO): Powering down 2022-08-31T16:48:00.963Z,1661964480.963 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-08-31T16:48:00.964Z,1661964480.964 [ElevatorServo](INFO): Powering down 2022-08-31T16:48:00.964Z,1661964480.964 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-08-31T16:48:00.965Z,1661964480.965 [MassServo](INFO): Powering down 2022-08-31T16:48:00.965Z,1661964480.965 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-08-31T16:48:00.965Z,1661964480.965 [RudderServo](INFO): Powering down 2022-08-31T16:48:00.966Z,1661964480.966 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-08-31T16:48:00.966Z,1661964480.966 [ThrusterHE](INFO): Powering down 2022-08-31T16:48:00.967Z,1661964480.967 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-08-31T16:48:00.968Z,1661964480.968 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-08-31T16:48:00.968Z,1661964480.968 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-08-31T16:48:00.968Z,1661964480.968 [CBIT](DEBUG): Powering off loads. 2022-08-31T16:48:00.979Z,1661964480.979 [CBIT](DEBUG): Disabling WDT. 2022-08-31T16:48:00.991Z,1661964480.991 [CBIT](DEBUG): Opening all GF detection circuits. 2022-08-31T16:48:00.992Z,1661964480.992 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:00.000Z,1661964481.000 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.004Z,1661964481.004 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.013Z,1661964481.013 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.103Z,1661964481.103 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.105Z,1661964481.105 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.165Z,1661964481.165 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-31T16:48:01.231Z,1661964481.231 [logger ThreadHandler](INFO): Thread cancelled.