2022-06-08T18:56:09.684Z,1654714569.684 [DataOverHttps](INFO): Received command: restart logs 2022-06-08T18:56:09.737Z,1654714569.737 [CommandExec](IMPORTANT): got command restart logs 2022-06-08T18:56:52.494Z,1654714612.494 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T18:56:52.494Z,1654714612.494 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.99,+9999.99 2022-06-08T18:57:06.033Z,1654714626.033 [CommandExec](IMPORTANT): got command strobe off 2022-06-08T18:57:06.033Z,1654714626.033 [CommandExec](IMPORTANT): Deactivating strobe 2022-06-08T18:57:27.672Z,1654714647.672 [DVL_micro](ERROR): Failed to parse: :WI,+00389,+00118,-01300,+00000,A 2022-06-08T18:59:02.326Z,1654714742.326 [CommandExec](IMPORTANT): got command maintain clear 2022-06-08T18:59:02.686Z,1654714742.686 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-06-08T18:59:23.646Z,1654714763.646 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T18:59:23.647Z,1654714763.647 [Default:CheckIn:C.Wait] Stopped 2022-06-08T18:59:23.647Z,1654714763.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T18:59:23.648Z,1654714763.648 [Default:CheckIn:D] Running Loop=1 2022-06-08T18:59:24.054Z,1654714764.054 [Default:CheckIn:D] Stopped 2022-06-08T18:59:24.054Z,1654714764.054 [Default:CheckIn:E] Running Loop=1 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.458146 min 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn:E] Stopped 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn] Stopped 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn](INFO): Running loop #20 2022-06-08T18:59:24.465Z,1654714764.465 [Default:CheckIn] Running Loop=20 2022-06-08T18:59:24.466Z,1654714764.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T18:59:24.466Z,1654714764.466 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T18:59:26.454Z,1654714766.454 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185914.00,A,3424.88886,N,11949.73440,W,0.058,52.29,080622,,,D*41 2022-06-08T18:59:26.461Z,1654714766.461 [NAL9602](INFO): GPS fix at 20220608T185914: (34.414814, -119.828907) 2022-06-08T18:59:26.470Z,1654714766.470 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T18:59:26.470Z,1654714766.470 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T18:59:33.943Z,1654714773.943 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220608T170650/Courier0061.lzma 2022-06-08T18:59:34.946Z,1654714774.946 [DataOverHttps](INFO): Moved sent file to Logs/20220608T170650/Courier0061.lzma.bak 2022-06-08T18:59:34.946Z,1654714774.946 [DataOverHttps](INFO): SBD MOMSN=16872656 2022-06-08T18:59:51.440Z,1654714791.440 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20220608T185609/Courier0000.lzma 2022-06-08T18:59:52.442Z,1654714792.442 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0000.lzma.bak 2022-06-08T18:59:52.442Z,1654714792.442 [DataOverHttps](INFO): SBD MOMSN=16872661 2022-06-08T18:59:57.164Z,1654714797.164 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T18:59:57.244Z,1654714797.244 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:00:08.328Z,1654714808.328 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20220608T170650/Express0062.lzma 2022-06-08T19:00:09.330Z,1654714809.330 [DataOverHttps](INFO): Moved sent file to Logs/20220608T170650/Express0062.lzma.bak 2022-06-08T19:00:09.330Z,1654714809.330 [DataOverHttps](INFO): SBD MOMSN=16872669 2022-06-08T19:00:25.396Z,1654714825.396 [DataOverHttps](INFO): Sending 436 bytes from file Logs/20220608T185609/Express0001.lzma 2022-06-08T19:00:26.397Z,1654714826.397 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0001.lzma.bak 2022-06-08T19:00:26.398Z,1654714826.398 [DataOverHttps](INFO): SBD MOMSN=16872673 2022-06-08T19:00:45.744Z,1654714845.744 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220608T185609/Express0004.lzma 2022-06-08T19:00:46.746Z,1654714846.746 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0004.lzma.bak 2022-06-08T19:00:46.746Z,1654714846.746 [DataOverHttps](INFO): SBD MOMSN=16872680 2022-06-08T19:00:48.959Z,1654714848.959 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:00:48.959Z,1654714848.959 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:00:48.959Z,1654714848.959 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:02:02.860Z,1654714922.860 [CommandExec](IMPORTANT): got command failComponent 2022-06-08T19:02:02.861Z,1654714922.861 [CommandExec](IMPORTANT): Failed components: 2022-06-08T19:02:02.861Z,1654714922.861 [CommandExec](IMPORTANT): No failed Components. 2022-06-08T19:02:05.464Z,1654714925.464 [CommandExec](IMPORTANT): got command ibit 2022-06-08T19:02:05.693Z,1654714925.693 [IBIT](IMPORTANT): Beginning Initiated BIT 2022-06-08T19:02:05.694Z,1654714925.694 [IBIT](IMPORTANT): Beginning control surface checks. 2022-06-08T19:02:05.697Z,1654714925.697 [CBIT](IMPORTANT): Beginning ground fault scan 2022-06-08T19:02:07.697Z,1654714927.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=47223, MT Status=2, MTMSN=0 2022-06-08T19:02:07.698Z,1654714927.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-06-08T19:02:16.662Z,1654714936.662 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001885 CHAN A1 (24V): -0.014511 CHAN A2 (12V): -0.009021 CHAN A3 (5V): -0.014098 CHAN B0 (3.3V): -0.003665 CHAN B1 (3.15aV): -0.000637 CHAN B2 (3.15bV): -0.001514 CHAN B3 (GND): -0.001296 OPEN: 0.011000 Full Scale: +/- 1 mA 2022-06-08T19:02:20.698Z,1654714940.698 [IBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:14.423778 2022-06-08T19:02:20.698Z,1654714940.698 [IBIT](FAULT): Control surface position failure. 2022-06-08T19:02:27.536Z,1654714947.536 [ElevatorServo](FAULT): Overload Error 2022-06-08T19:02:27.536Z,1654714947.536 [ElevatorServo] Hardware Fault, FailCount= 1 2022-06-08T19:02:27.536Z,1654714947.536 [ElevatorServo](ERROR): Hardware Fault 2022-06-08T19:02:27.574Z,1654714947.574 [CBIT](ERROR): Hardware Fault in component: ElevatorServo 2022-06-08T19:02:27.946Z,1654714947.946 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-06-08T19:02:27.946Z,1654714947.946 [ElevatorServo](INFO): Powering down 2022-06-08T19:02:28.715Z,1654714948.715 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-06-08T19:02:28.833Z,1654714948.833 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-06-08T19:02:28.839Z,1654714948.839 [CBIT](INFO): Clearing failed state for component ElevatorServo 2022-06-08T19:02:28.839Z,1654714948.839 [ElevatorServo] No Fault, FailCount= 1 2022-06-08T19:02:34.424Z,1654714954.424 [ElevatorServo](FAULT): Overload Error 2022-06-08T19:02:34.424Z,1654714954.424 [ElevatorServo] Hardware Fault, FailCount= 2 2022-06-08T19:02:34.425Z,1654714954.425 [ElevatorServo](ERROR): Hardware Fault 2022-06-08T19:02:34.457Z,1654714954.457 [CBIT](ERROR): Hardware Fault in component: ElevatorServo 2022-06-08T19:02:34.830Z,1654714954.830 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-06-08T19:02:34.830Z,1654714954.830 [ElevatorServo](INFO): Powering down 2022-06-08T19:02:35.601Z,1654714955.601 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-06-08T19:02:35.717Z,1654714955.717 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-06-08T19:02:35.719Z,1654714955.719 [IBIT](FAULT): Could not read elevatorAngleReader_. 2022-06-08T19:02:35.719Z,1654714955.719 [IBIT](FAULT): Control surface position failure. 2022-06-08T19:02:35.722Z,1654714955.722 [CBIT](INFO): Clearing failed state for component ElevatorServo 2022-06-08T19:02:35.722Z,1654714955.722 [ElevatorServo] No Fault, FailCount= 2 2022-06-08T19:03:46.286Z,1654715026.286 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 1 Latitude: 34.414814 Longitude: -119.828903 2022-06-08T19:03:46.704Z,1654715026.704 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2022-06-08T19:03:47.090Z,1654715027.090 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2022-06-08T19:03:47.090Z,1654715027.090 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2022-06-08T19:03:47.090Z,1654715027.090 [IBIT](IMPORTANT): Pressure:9.533887 PSI 2022-06-08T19:03:47.091Z,1654715027.091 [IBIT](IMPORTANT): Humidity:19.808327 % 2022-06-08T19:03:47.489Z,1654715027.489 [IBIT](IMPORTANT): Vehicle Pitch:-2.914630 degrees 2022-06-08T19:03:47.490Z,1654715027.490 [IBIT](IMPORTANT): Vehicle Roll:2.937909 degrees 2022-06-08T19:03:47.490Z,1654715027.490 [IBIT](IMPORTANT): Vehicle Heading:185.864822 degrees 2022-06-08T19:03:47.923Z,1654715027.923 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2022-06-08T19:03:47.923Z,1654715027.923 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc 2022-06-08T19:03:47.924Z,1654715027.924 [IBIT](IMPORTANT): massDefault: 0.990000 cm 2022-06-08T19:03:47.924Z,1654715027.924 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2022-06-08T19:03:47.924Z,1654715027.924 [IBIT](IMPORTANT): abortDepth: 250.000000 m 2022-06-08T19:03:47.924Z,1654715027.924 [IBIT](IMPORTANT): IBIT FAILED 2022-06-08T19:04:00.430Z,1654715040.430 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-06-08T19:04:29.088Z,1654715069.088 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:04:59.794Z,1654715099.794 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:05:49.494Z,1654715149.494 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:05:49.494Z,1654715149.494 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:05:49.494Z,1654715149.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:05:49.494Z,1654715149.494 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:05:49.902Z,1654715149.902 [Default:CheckIn:D] Stopped 2022-06-08T19:05:49.902Z,1654715149.902 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:05:50.318Z,1654715150.318 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.888940 min 2022-06-08T19:05:50.318Z,1654715150.318 [Default:CheckIn:E] Stopped 2022-06-08T19:05:50.318Z,1654715150.318 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:05:50.318Z,1654715150.318 [Default:CheckIn] Stopped 2022-06-08T19:05:50.318Z,1654715150.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:05:50.319Z,1654715150.319 [Default:CheckIn](INFO): Running loop #21 2022-06-08T19:05:50.319Z,1654715150.319 [Default:CheckIn] Running Loop=21 2022-06-08T19:05:50.319Z,1654715150.319 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:05:50.319Z,1654715150.319 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:05:52.321Z,1654715152.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190540.00,A,3424.88775,N,11949.73428,W,0.039,52.29,080622,,,D*42 2022-06-08T19:05:52.324Z,1654715152.324 [NAL9602](INFO): GPS fix at 20220608T190540: (34.414796, -119.828905) 2022-06-08T19:05:52.361Z,1654715152.361 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:05:52.362Z,1654715152.362 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:05:55.962Z,1654715155.962 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+99999.99 2022-06-08T19:06:00.531Z,1654715160.531 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0006.lzma 2022-06-08T19:06:01.533Z,1654715161.533 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0006.lzma.bak 2022-06-08T19:06:01.534Z,1654715161.534 [DataOverHttps](INFO): SBD MOMSN=16872688 2022-06-08T19:06:17.345Z,1654715177.345 [DataOverHttps](INFO): Sending 999 bytes from file Logs/20220608T185609/Express0007.lzma 2022-06-08T19:06:18.346Z,1654715178.346 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0007.lzma.bak 2022-06-08T19:06:18.346Z,1654715178.346 [DataOverHttps](INFO): SBD MOMSN=16872691 2022-06-08T19:06:20.210Z,1654715180.210 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:06:20.210Z,1654715180.210 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:06:20.210Z,1654715180.210 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:06:23.026Z,1654715183.026 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T19:06:23.104Z,1654715183.104 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:10:54.132Z,1654715454.132 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:11:20.788Z,1654715480.788 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:11:20.788Z,1654715480.788 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:11:20.788Z,1654715480.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:11:20.788Z,1654715480.788 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:11:21.191Z,1654715481.191 [Default:CheckIn:D] Stopped 2022-06-08T19:11:21.192Z,1654715481.192 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:11:21.596Z,1654715481.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.410425 min 2022-06-08T19:11:21.596Z,1654715481.596 [Default:CheckIn:E] Stopped 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn] Stopped 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn](INFO): Running loop #22 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn] Running Loop=22 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:11:21.597Z,1654715481.597 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:11:23.617Z,1654715483.617 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191112.00,A,3424.88603,N,11949.73480,W,0.933,182.62,080622,,,A*77 2022-06-08T19:11:23.619Z,1654715483.619 [NAL9602](INFO): GPS fix at 20220608T191112: (34.414767, -119.828913) 2022-06-08T19:11:23.628Z,1654715483.628 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:11:23.629Z,1654715483.629 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:11:30.875Z,1654715490.875 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0009.lzma 2022-06-08T19:11:31.878Z,1654715491.878 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0009.lzma.bak 2022-06-08T19:11:31.878Z,1654715491.878 [DataOverHttps](INFO): SBD MOMSN=16872733 2022-06-08T19:11:47.760Z,1654715507.760 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220608T185609/Express0010.lzma 2022-06-08T19:11:48.762Z,1654715508.762 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0010.lzma.bak 2022-06-08T19:11:48.762Z,1654715508.762 [DataOverHttps](INFO): SBD MOMSN=16872736 2022-06-08T19:11:50.715Z,1654715510.715 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:11:50.715Z,1654715510.715 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:11:50.716Z,1654715510.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:11:56.361Z,1654715516.361 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:16:51.295Z,1654715811.295 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:16:51.295Z,1654715811.295 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:16:51.295Z,1654715811.295 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:16:51.295Z,1654715811.295 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:16:51.705Z,1654715811.705 [Default:CheckIn:D] Stopped 2022-06-08T19:16:51.705Z,1654715811.705 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.918978 min 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn:E] Stopped 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn] Stopped 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:16:52.096Z,1654715812.096 [Default:CheckIn](INFO): Running loop #23 2022-06-08T19:16:52.097Z,1654715812.097 [Default:CheckIn] Running Loop=23 2022-06-08T19:16:52.097Z,1654715812.097 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:16:52.097Z,1654715812.097 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:16:54.110Z,1654715814.110 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191642.00,A,3424.88543,N,11949.73419,W,0.175,182.62,080622,,,A*78 2022-06-08T19:16:54.112Z,1654715814.112 [NAL9602](INFO): GPS fix at 20220608T191642: (34.414757, -119.828903) 2022-06-08T19:16:54.121Z,1654715814.121 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:16:54.121Z,1654715814.121 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:17:01.343Z,1654715821.343 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0012.lzma 2022-06-08T19:17:02.346Z,1654715822.346 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0012.lzma.bak 2022-06-08T19:17:02.346Z,1654715822.346 [DataOverHttps](INFO): SBD MOMSN=16872746 2022-06-08T19:17:18.215Z,1654715838.215 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220608T185609/Express0013.lzma 2022-06-08T19:17:19.217Z,1654715839.217 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0013.lzma.bak 2022-06-08T19:17:19.218Z,1654715839.218 [DataOverHttps](INFO): SBD MOMSN=16872749 2022-06-08T19:17:20.799Z,1654715840.799 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:17:20.800Z,1654715840.800 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:17:20.800Z,1654715840.800 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:17:24.835Z,1654715844.835 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T19:17:24.912Z,1654715844.912 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:18:33.929Z,1654715913.929 [NAL9602](INFO): SBD MO Status=2, MOMSN=47223, MT Status=2, MTMSN=0 2022-06-08T19:18:33.929Z,1654715913.929 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-06-08T19:18:54.124Z,1654715934.124 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T19:18:54.124Z,1654715934.124 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2022-06-08T19:18:58.969Z,1654715938.969 [DVL_micro](ERROR): Failed to parse: :BI,+00005,-00080,-00655,+00000,I 2022-06-08T19:19:06.649Z,1654715946.649 [DVL_micro](ERROR): Failed to parse: :.99,+9999.99,+9999.99,+9999.99 2022-06-08T19:21:56.378Z,1654716116.378 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:22:07.285Z,1654716127.285 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-06-08T19:22:07.285Z,1654716127.285 [DropWeight] Hardware Fault, FailCount= 1 2022-06-08T19:22:07.285Z,1654716127.285 [DropWeight](ERROR): Hardware Fault 2022-06-08T19:22:07.310Z,1654716127.310 [CBIT](INFO): Critical error at 20220608T192207 2022-06-08T19:22:07.312Z,1654716127.312 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-06-08T19:22:07.313Z,1654716127.313 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-06-08T19:22:07.716Z,1654716127.716 [CBIT](INFO): Critical error at 20220608T192207 2022-06-08T19:22:21.431Z,1654716141.431 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:22:21.431Z,1654716141.431 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:22:21.461Z,1654716141.461 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:22:21.461Z,1654716141.461 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:22:21.832Z,1654716141.832 [Default:CheckIn:D] Stopped 2022-06-08T19:22:21.832Z,1654716141.832 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:22:22.247Z,1654716142.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.421094 min 2022-06-08T19:22:22.247Z,1654716142.247 [Default:CheckIn:E] Stopped 2022-06-08T19:22:22.247Z,1654716142.247 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:22:22.248Z,1654716142.248 [Default:CheckIn] Stopped 2022-06-08T19:22:22.248Z,1654716142.248 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:22:22.248Z,1654716142.248 [Default:CheckIn](INFO): Running loop #24 2022-06-08T19:22:22.248Z,1654716142.248 [Default:CheckIn] Running Loop=24 2022-06-08T19:22:22.249Z,1654716142.249 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:22:22.249Z,1654716142.249 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:22:24.293Z,1654716144.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192212.00,A,3425.03636,N,11949.73400,W,0.272,238.08,080622,,,A*7B 2022-06-08T19:22:24.314Z,1654716144.314 [NAL9602](INFO): GPS fix at 20220608T192212: (34.417273, -119.828900) 2022-06-08T19:22:24.398Z,1654716144.398 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:22:24.398Z,1654716144.398 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:22:31.379Z,1654716151.379 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20220608T185609/Courier0015.lzma 2022-06-08T19:22:32.381Z,1654716152.381 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0015.lzma.bak 2022-06-08T19:22:32.382Z,1654716152.382 [DataOverHttps](INFO): SBD MOMSN=16872765 2022-06-08T19:22:51.396Z,1654716171.396 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220608T185609/Express0016.lzma 2022-06-08T19:22:52.398Z,1654716172.398 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0016.lzma.bak 2022-06-08T19:22:52.398Z,1654716172.398 [DataOverHttps](INFO): SBD MOMSN=16872770 2022-06-08T19:22:54.812Z,1654716174.812 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:22:54.812Z,1654716174.812 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:22:54.812Z,1654716174.812 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:22:56.353Z,1654716176.353 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:27:55.327Z,1654716475.327 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:27:55.327Z,1654716475.327 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:27:55.328Z,1654716475.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:27:55.328Z,1654716475.328 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:27:55.743Z,1654716475.743 [Default:CheckIn:D] Stopped 2022-06-08T19:27:55.743Z,1654716475.743 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:27:56.139Z,1654716476.139 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.986296 min 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn:E] Stopped 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn] Stopped 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn](INFO): Running loop #25 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn] Running Loop=25 2022-06-08T19:27:56.140Z,1654716476.140 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:27:56.141Z,1654716476.141 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:27:58.174Z,1654716478.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192746.00,A,3426.12869,N,11948.55207,W,3.538,238.69,080622,,,A*71 2022-06-08T19:27:58.177Z,1654716478.177 [NAL9602](INFO): GPS fix at 20220608T192746: (34.435478, -119.809201) 2022-06-08T19:27:58.186Z,1654716478.186 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:27:58.186Z,1654716478.186 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:28:06.375Z,1654716486.375 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0018.lzma 2022-06-08T19:28:07.378Z,1654716487.378 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0018.lzma.bak 2022-06-08T19:28:07.378Z,1654716487.378 [DataOverHttps](INFO): SBD MOMSN=16872775 2022-06-08T19:28:23.203Z,1654716503.203 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20220608T185609/Express0019.lzma 2022-06-08T19:28:24.206Z,1654716504.206 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0019.lzma.bak 2022-06-08T19:28:24.206Z,1654716504.206 [DataOverHttps](INFO): SBD MOMSN=16872778 2022-06-08T19:28:26.034Z,1654716506.034 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:28:26.034Z,1654716506.034 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:28:26.034Z,1654716506.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:28:28.846Z,1654716508.846 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T19:28:28.920Z,1654716508.920 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:33:00.383Z,1654716780.383 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:33:26.631Z,1654716806.631 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:33:26.631Z,1654716806.631 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:33:26.631Z,1654716806.631 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:33:26.631Z,1654716806.631 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:33:27.036Z,1654716807.036 [Default:CheckIn:D] Stopped 2022-06-08T19:33:27.036Z,1654716807.036 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:33:27.438Z,1654716807.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.507845 min 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn:E] Stopped 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn] Stopped 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn](INFO): Running loop #26 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn] Running Loop=26 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:33:27.439Z,1654716807.439 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:33:29.446Z,1654716809.446 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193317.00,A,3426.12831,N,11948.55749,W,0.292,190.26,080622,,,A*7C 2022-06-08T19:33:29.448Z,1654716809.448 [NAL9602](INFO): GPS fix at 20220608T193317: (34.435472, -119.809292) 2022-06-08T19:33:29.457Z,1654716809.457 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:33:29.457Z,1654716809.457 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:33:37.123Z,1654716817.123 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220608T185609/Courier0021.lzma 2022-06-08T19:33:38.126Z,1654716818.126 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0021.lzma.bak 2022-06-08T19:33:38.126Z,1654716818.126 [DataOverHttps](INFO): SBD MOMSN=16872781 2022-06-08T19:33:57.683Z,1654716837.683 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220608T185609/Express0022.lzma 2022-06-08T19:33:58.686Z,1654716838.686 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0022.lzma.bak 2022-06-08T19:33:58.686Z,1654716838.686 [DataOverHttps](INFO): SBD MOMSN=16872784 2022-06-08T19:34:00.594Z,1654716840.594 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:34:00.594Z,1654716840.594 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:34:00.594Z,1654716840.594 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:34:02.201Z,1654716842.201 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:35:12.514Z,1654716912.514 [DVL_micro](ERROR): Failed to parse: :SA,+04.61,+02.30,177.5 2022-06-08T19:35:14.923Z,1654716914.923 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T19:35:14.923Z,1654716914.923 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-06-08T19:35:17.346Z,1654716917.346 [DVL_micro](ERROR): No DVL communication! Re-initializing 2022-06-08T19:35:17.347Z,1654716917.347 [DVL_micro] Communications Fault, FailCount= 1 2022-06-08T19:35:17.347Z,1654716917.347 [DVL_micro](ERROR): Communications Fault 2022-06-08T19:35:17.399Z,1654716917.399 [CBIT](ERROR): Communications Fault in component: DVL_micro 2022-06-08T19:35:17.820Z,1654716917.820 [DVL_micro](INFO): Powering down 2022-06-08T19:35:18.583Z,1654716918.583 [CBIT](INFO): Clearing failed state for component DVL_micro 2022-06-08T19:35:18.583Z,1654716918.583 [DVL_micro] No Fault, FailCount= 1 2022-06-08T19:37:07.679Z,1654717027.679 [CBIT](INFO): Clearing failed state for component DropWeight 2022-06-08T19:37:07.684Z,1654717027.684 [DropWeight] No Fault, FailCount= 1 2022-06-08T19:39:01.177Z,1654717141.177 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:39:01.178Z,1654717141.178 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:39:01.178Z,1654717141.178 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:39:01.178Z,1654717141.178 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:39:01.576Z,1654717141.576 [Default:CheckIn:D] Stopped 2022-06-08T19:39:01.576Z,1654717141.576 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.083496 min 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn:E] Stopped 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn] Stopped 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn](INFO): Running loop #27 2022-06-08T19:39:01.980Z,1654717141.980 [Default:CheckIn] Running Loop=27 2022-06-08T19:39:01.981Z,1654717141.981 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:39:01.981Z,1654717141.981 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:39:03.995Z,1654717143.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193852.00,A,3426.12639,N,11948.55580,W,0.097,190.26,080622,,,A*70 2022-06-08T19:39:03.998Z,1654717143.998 [NAL9602](INFO): GPS fix at 20220608T193852: (34.435440, -119.809263) 2022-06-08T19:39:04.007Z,1654717144.007 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:39:04.007Z,1654717144.007 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:39:11.807Z,1654717151.807 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0024.lzma 2022-06-08T19:39:12.810Z,1654717152.810 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0024.lzma.bak 2022-06-08T19:39:12.810Z,1654717152.810 [DataOverHttps](INFO): SBD MOMSN=16872789 2022-06-08T19:39:28.611Z,1654717168.611 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220608T185609/Express0025.lzma 2022-06-08T19:39:29.614Z,1654717169.614 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0025.lzma.bak 2022-06-08T19:39:29.614Z,1654717169.614 [DataOverHttps](INFO): SBD MOMSN=16872792 2022-06-08T19:39:31.484Z,1654717171.484 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:39:31.484Z,1654717171.484 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:39:31.485Z,1654717171.485 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:39:34.712Z,1654717174.712 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T19:39:34.792Z,1654717174.792 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:39:54.908Z,1654717194.908 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T19:39:54.908Z,1654717194.908 [DVL_micro](ERROR): Failed to parse: :BI,-00130,-00060,-0000,I 2022-06-08T19:43:20.946Z,1654717400.946 [DVL_micro](ERROR): only read 2 of 4 data items 2022-06-08T19:43:20.946Z,1654717400.946 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2022-06-08T19:44:06.184Z,1654717446.184 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:44:32.053Z,1654717472.053 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:44:32.053Z,1654717472.053 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:44:32.053Z,1654717472.053 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:44:32.053Z,1654717472.053 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:44:32.452Z,1654717472.452 [Default:CheckIn:D] Stopped 2022-06-08T19:44:32.452Z,1654717472.452 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:44:32.865Z,1654717472.865 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.598096 min 2022-06-08T19:44:32.865Z,1654717472.865 [Default:CheckIn:E] Stopped 2022-06-08T19:44:32.865Z,1654717472.865 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn] Stopped 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn](INFO): Running loop #28 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn] Running Loop=28 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:44:32.866Z,1654717472.866 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:44:34.869Z,1654717474.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194423.00,A,3426.12644,N,11948.56843,W,0.272,117.82,080622,,,A*7E 2022-06-08T19:44:34.872Z,1654717474.872 [NAL9602](INFO): GPS fix at 20220608T194423: (34.435441, -119.809474) 2022-06-08T19:44:34.881Z,1654717474.881 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:44:34.881Z,1654717474.881 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:44:42.283Z,1654717482.283 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0027.lzma 2022-06-08T19:44:42.967Z,1654717482.967 [DVL_micro](ERROR): Failed to parse: :R99,+9999.999,+9999.99 2022-06-08T19:44:43.286Z,1654717483.286 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0027.lzma.bak 2022-06-08T19:44:43.286Z,1654717483.286 [DataOverHttps](INFO): SBD MOMSN=16872795 2022-06-08T19:45:03.160Z,1654717503.160 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20220608T185609/Express0028.lzma 2022-06-08T19:45:04.162Z,1654717504.162 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0028.lzma.bak 2022-06-08T19:45:04.162Z,1654717504.162 [DataOverHttps](INFO): SBD MOMSN=16872798 2022-06-08T19:45:06.054Z,1654717506.054 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:45:06.054Z,1654717506.054 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:45:06.054Z,1654717506.054 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:45:07.275Z,1654717507.275 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:49:08.084Z,1654717748.084 [DVL_micro](ERROR): Failed to parse: :BI,-00010,-0304,+00000,I 2022-06-08T19:49:23.025Z,1654717763.025 [DVL_micro](ERROR): Failed to parse: :SA,+04.55,+02.22,177.6 2022-06-08T19:50:06.664Z,1654717806.664 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:50:06.664Z,1654717806.664 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:50:06.664Z,1654717806.664 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:50:06.664Z,1654717806.664 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:50:07.072Z,1654717807.072 [Default:CheckIn:D] Stopped 2022-06-08T19:50:07.073Z,1654717807.073 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:50:07.483Z,1654717807.483 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 159.175114 min 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn:E] Stopped 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn] Stopped 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn](INFO): Running loop #29 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn] Running Loop=29 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:50:07.484Z,1654717807.484 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:50:09.485Z,1654717809.485 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194957.00,A,3426.12568,N,11948.55636,W,0.311,117.82,080622,,,A*76 2022-06-08T19:50:09.499Z,1654717809.499 [NAL9602](INFO): GPS fix at 20220608T194957: (34.435428, -119.809273) 2022-06-08T19:50:09.508Z,1654717809.508 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:50:09.508Z,1654717809.508 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:50:17.143Z,1654717817.143 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220608T185609/Courier0030.lzma 2022-06-08T19:50:18.146Z,1654717818.146 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0030.lzma.bak 2022-06-08T19:50:18.146Z,1654717818.146 [DataOverHttps](INFO): SBD MOMSN=16872935 2022-06-08T19:50:34.071Z,1654717834.071 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220608T185609/Express0031.lzma 2022-06-08T19:50:35.074Z,1654717835.074 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0031.lzma.bak 2022-06-08T19:50:35.074Z,1654717835.074 [DataOverHttps](INFO): SBD MOMSN=16872938 2022-06-08T19:50:36.973Z,1654717836.973 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:50:36.973Z,1654717836.973 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:50:36.973Z,1654717836.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:50:40.194Z,1654717840.194 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T19:50:40.276Z,1654717840.276 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T19:52:28.870Z,1654717948.870 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-06-08T19:52:28.870Z,1654717948.870 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+21.7,0000.0,1489.0,000 2022-06-08T19:53:10.899Z,1654717990.899 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T19:53:10.904Z,1654717990.904 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999..99 2022-06-08T19:55:12.144Z,1654718112.144 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T19:55:37.610Z,1654718137.610 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T19:55:37.610Z,1654718137.610 [Default:CheckIn:C.Wait] Stopped 2022-06-08T19:55:37.610Z,1654718137.610 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T19:55:37.610Z,1654718137.610 [Default:CheckIn:D] Running Loop=1 2022-06-08T19:55:38.008Z,1654718138.008 [Default:CheckIn:D] Stopped 2022-06-08T19:55:38.008Z,1654718138.008 [Default:CheckIn:E] Running Loop=1 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.690706 min 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn:E] Stopped 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn] Stopped 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn](INFO): Running loop #30 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn] Running Loop=30 2022-06-08T19:55:38.418Z,1654718138.418 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T19:55:38.419Z,1654718138.419 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T19:55:40.432Z,1654718140.432 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195528.00,A,3426.12280,N,11948.56102,W,0.991,117.82,080622,,,A*73 2022-06-08T19:55:40.435Z,1654718140.435 [NAL9602](INFO): GPS fix at 20220608T195528: (34.435380, -119.809350) 2022-06-08T19:55:40.444Z,1654718140.444 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T19:55:40.444Z,1654718140.444 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T19:55:50.803Z,1654718150.803 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0033.lzma 2022-06-08T19:55:51.806Z,1654718151.806 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0033.lzma.bak 2022-06-08T19:55:51.806Z,1654718151.806 [DataOverHttps](INFO): SBD MOMSN=16872962 2022-06-08T19:56:04.737Z,1654718164.737 [DVL_micro](ERROR): only read 1 of 4 data items 2022-06-08T19:56:04.738Z,1654718164.738 [DVL_micro](ERROR): Failed to parse: :BI,-00066-00284,+00000,I 2022-06-08T19:56:08.761Z,1654718168.761 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220608T185609/Express0034.lzma 2022-06-08T19:56:09.758Z,1654718169.758 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0034.lzma.bak 2022-06-08T19:56:09.758Z,1654718169.758 [DataOverHttps](INFO): SBD MOMSN=16872966 2022-06-08T19:56:11.611Z,1654718171.611 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T19:56:11.611Z,1654718171.611 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T19:56:11.611Z,1654718171.611 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T19:56:13.213Z,1654718173.213 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T19:56:56.897Z,1654718216.897 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-06-08T19:56:56.897Z,1654718216.897 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.9,089.0,000 2022-06-08T19:58:41.189Z,1654718321.189 [DVL_micro](ERROR): only read 0 of 4 data items 2022-06-08T19:58:41.189Z,1654718321.189 [DVL_micro](ERROR): Failed to parse: :RD,++9999.99,+9999.99,+9999.99 2022-06-08T20:01:12.030Z,1654718472.030 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:01:12.030Z,1654718472.030 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:01:12.030Z,1654718472.030 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:01:12.030Z,1654718472.030 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:01:12.430Z,1654718472.430 [Default:CheckIn:D] Stopped 2022-06-08T20:01:12.430Z,1654718472.430 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:01:12.838Z,1654718472.838 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.264404 min 2022-06-08T20:01:12.838Z,1654718472.838 [Default:CheckIn:E] Stopped 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn] Stopped 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn](INFO): Running loop #31 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn] Running Loop=31 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:01:12.839Z,1654718472.839 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:01:14.847Z,1654718474.847 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200103.00,A,3426.12471,N,11948.55801,W,0.272,117.82,080622,,,A*76 2022-06-08T20:01:14.849Z,1654718474.849 [NAL9602](INFO): GPS fix at 20220608T200103: (34.435412, -119.809300) 2022-06-08T20:01:14.859Z,1654718474.859 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:01:14.859Z,1654718474.859 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:01:22.023Z,1654718482.023 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0036.lzma 2022-06-08T20:01:23.026Z,1654718483.026 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0036.lzma.bak 2022-06-08T20:01:23.026Z,1654718483.026 [DataOverHttps](INFO): SBD MOMSN=16873001 2022-06-08T20:01:39.071Z,1654718499.071 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220608T185609/Express0037.lzma 2022-06-08T20:01:40.074Z,1654718500.074 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0037.lzma.bak 2022-06-08T20:01:40.074Z,1654718500.074 [DataOverHttps](INFO): SBD MOMSN=16873004 2022-06-08T20:01:41.927Z,1654718501.927 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T20:01:41.927Z,1654718501.927 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T20:01:41.927Z,1654718501.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T20:01:45.621Z,1654718505.621 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T20:01:45.696Z,1654718505.696 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T20:02:15.122Z,1654718535.122 [DVL_micro](ERROR): Failed to parse: :SA,+04.26,+04.28,182.7 2022-06-08T20:03:47.343Z,1654718627.343 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-06-08T20:03:47.343Z,1654718627.343 [DVL_micro](ERROR): Failed to parse: :TS,000000000000002.4,0000.0,1489.0,000 2022-06-08T20:06:16.928Z,1654718776.928 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T20:06:42.385Z,1654718802.385 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:06:42.385Z,1654718802.385 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:06:42.386Z,1654718802.386 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:06:42.386Z,1654718802.386 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:06:42.788Z,1654718802.788 [Default:CheckIn:D] Stopped 2022-06-08T20:06:42.789Z,1654718802.789 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.770378 min 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn:E] Stopped 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn] Stopped 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:06:43.209Z,1654718803.209 [Default:CheckIn](INFO): Running loop #32 2022-06-08T20:06:43.210Z,1654718803.210 [Default:CheckIn] Running Loop=32 2022-06-08T20:06:43.210Z,1654718803.210 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:06:43.210Z,1654718803.210 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:06:45.202Z,1654718805.202 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200633.00,A,3426.11661,N,11948.58319,W,2.819,110.14,080622,,,A*70 2022-06-08T20:06:45.204Z,1654718805.204 [NAL9602](INFO): GPS fix at 20220608T200633: (34.435277, -119.809720) 2022-06-08T20:06:45.257Z,1654718805.257 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:06:45.257Z,1654718805.257 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:06:46.518Z,1654718806.518 [DVL_micro](ERROR): Failed to parse: :WI,+00057,+00193,-00085,+00000,A 2022-06-08T20:06:55.035Z,1654718815.035 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220608T185609/Courier0039.lzma 2022-06-08T20:06:56.038Z,1654718816.038 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0039.lzma.bak 2022-06-08T20:06:56.038Z,1654718816.038 [DataOverHttps](INFO): SBD MOMSN=16873036 2022-06-08T20:07:09.159Z,1654718829.159 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-06-08T20:07:09.159Z,1654718829.159 [DropWeight] Hardware Fault, FailCount= 1 2022-06-08T20:07:09.159Z,1654718829.159 [DropWeight](ERROR): Hardware Fault 2022-06-08T20:07:09.227Z,1654718829.227 [CBIT](INFO): Critical error at 20220608T200709 2022-06-08T20:07:09.238Z,1654718829.238 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-06-08T20:07:09.239Z,1654718829.239 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-06-08T20:07:09.619Z,1654718829.619 [CBIT](INFO): Critical error at 20220608T200709 2022-06-08T20:07:11.948Z,1654718831.948 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20220608T185609/Express0040.lzma 2022-06-08T20:07:12.966Z,1654718832.966 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0040.lzma.bak 2022-06-08T20:07:12.966Z,1654718832.966 [DataOverHttps](INFO): SBD MOMSN=16873041 2022-06-08T20:07:14.826Z,1654718834.826 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T20:07:14.826Z,1654718834.826 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T20:07:14.826Z,1654718834.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T20:07:17.237Z,1654718837.237 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T20:12:15.572Z,1654719135.572 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:12:15.572Z,1654719135.572 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:12:15.572Z,1654719135.572 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:12:15.572Z,1654719135.572 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:12:15.974Z,1654719135.974 [Default:CheckIn:D] Stopped 2022-06-08T20:12:15.974Z,1654719135.974 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:12:16.390Z,1654719136.390 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.323470 min 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn:E] Stopped 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn] Stopped 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn](INFO): Running loop #33 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn] Running Loop=33 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:12:16.391Z,1654719136.391 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:12:18.391Z,1654719138.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201206.00,A,3426.30603,N,11950.64614,W,55.905,261.42,080622,,,A*42 2022-06-08T20:12:18.393Z,1654719138.393 [NAL9602](INFO): GPS fix at 20220608T201206: (34.438434, -119.844102) 2022-06-08T20:12:18.403Z,1654719138.403 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:12:18.403Z,1654719138.403 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:12:26.619Z,1654719146.619 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20220608T185609/Courier0042.lzma 2022-06-08T20:12:27.622Z,1654719147.622 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0042.lzma.bak 2022-06-08T20:12:27.622Z,1654719147.622 [DataOverHttps](INFO): SBD MOMSN=16873074 2022-06-08T20:12:43.768Z,1654719163.768 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220608T185609/Express0043.lzma 2022-06-08T20:12:44.770Z,1654719164.770 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0043.lzma.bak 2022-06-08T20:12:44.770Z,1654719164.770 [DataOverHttps](INFO): SBD MOMSN=16873082 2022-06-08T20:12:47.184Z,1654719167.184 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T20:12:47.184Z,1654719167.184 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T20:12:47.184Z,1654719167.184 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T20:12:49.134Z,1654719169.134 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T20:12:49.232Z,1654719169.232 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T20:14:04.302Z,1654719244.302 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-06-08T20:14:04.302Z,1654719244.302 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489:WI,-00004,-00001,-00023,+00000,A 2022-06-08T20:17:20.244Z,1654719440.244 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T20:17:47.726Z,1654719467.726 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:17:47.726Z,1654719467.726 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:17:47.726Z,1654719467.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:17:47.726Z,1654719467.726 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:17:48.127Z,1654719468.127 [Default:CheckIn:D] Stopped 2022-06-08T20:17:48.127Z,1654719468.127 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:17:48.537Z,1654719468.537 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.859359 min 2022-06-08T20:17:48.537Z,1654719468.537 [Default:CheckIn:E] Stopped 2022-06-08T20:17:48.537Z,1654719468.537 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:17:48.537Z,1654719468.537 [Default:CheckIn] Stopped 2022-06-08T20:17:48.537Z,1654719468.537 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:17:48.538Z,1654719468.538 [Default:CheckIn](INFO): Running loop #34 2022-06-08T20:17:48.538Z,1654719468.538 [Default:CheckIn] Running Loop=34 2022-06-08T20:17:48.538Z,1654719468.538 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:17:48.538Z,1654719468.538 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:17:50.547Z,1654719470.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201739.00,A,3426.85554,N,11957.55772,W,69.317,312.85,080622,,,A*48 2022-06-08T20:17:50.549Z,1654719470.549 [NAL9602](INFO): GPS fix at 20220608T201739: (34.447592, -119.959295) 2022-06-08T20:17:50.558Z,1654719470.558 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:17:50.558Z,1654719470.558 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:18:01.046Z,1654719481.046 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0045.lzma 2022-06-08T20:18:01.802Z,1654719481.802 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0045.lzma.bak 2022-06-08T20:18:01.802Z,1654719481.802 [DataOverHttps](INFO): SBD MOMSN=16873152 2022-06-08T20:18:20.544Z,1654719500.544 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20220608T185609/Express0046.lzma 2022-06-08T20:18:21.546Z,1654719501.546 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0046.lzma.bak 2022-06-08T20:18:21.546Z,1654719501.546 [DataOverHttps](INFO): SBD MOMSN=16873159 2022-06-08T20:18:23.313Z,1654719503.313 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T20:18:23.323Z,1654719503.323 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T20:18:23.323Z,1654719503.323 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T20:18:23.323Z,1654719503.323 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T20:22:09.213Z,1654719729.213 [CBIT](INFO): Clearing failed state for component DropWeight 2022-06-08T20:22:09.214Z,1654719729.214 [DropWeight] No Fault, FailCount= 1 2022-06-08T20:23:23.948Z,1654719803.948 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:23:23.948Z,1654719803.948 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:23:23.948Z,1654719803.948 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:23:23.948Z,1654719803.948 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:23:24.332Z,1654719804.332 [Default:CheckIn:D] Stopped 2022-06-08T20:23:24.332Z,1654719804.332 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:23:24.742Z,1654719804.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.462777 min 2022-06-08T20:23:24.742Z,1654719804.742 [Default:CheckIn:E] Stopped 2022-06-08T20:23:24.742Z,1654719804.742 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:23:24.742Z,1654719804.742 [Default:CheckIn] Stopped 2022-06-08T20:23:24.742Z,1654719804.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:23:24.743Z,1654719804.743 [Default:CheckIn](INFO): Running loop #35 2022-06-08T20:23:24.743Z,1654719804.743 [Default:CheckIn] Running Loop=35 2022-06-08T20:23:24.743Z,1654719804.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:23:24.743Z,1654719804.743 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:23:26.756Z,1654719806.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202315.00,A,3427.75946,N,12004.62815,W,65.527,237.66,080622,,,A*44 2022-06-08T20:23:26.759Z,1654719806.759 [NAL9602](INFO): GPS fix at 20220608T202315: (34.462658, -120.077136) 2022-06-08T20:23:26.767Z,1654719806.767 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:23:26.767Z,1654719806.767 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:23:57.456Z,1654719837.456 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-06-08T20:23:57.540Z,1654719837.540 [NAL9602](ERROR): received: +CSQ:0 OK223, 2, 0, 0, 0 OK 2022-06-08T20:24:14.407Z,1654719854.407 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220608T185609/Courier0048.lzma 2022-06-08T20:24:15.410Z,1654719855.410 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0048.lzma.bak 2022-06-08T20:24:15.410Z,1654719855.410 [DataOverHttps](INFO): SBD MOMSN=16873179 2022-06-08T20:24:35.391Z,1654719875.391 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220608T185609/Express0049.lzma 2022-06-08T20:24:36.394Z,1654719876.394 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Express0049.lzma.bak 2022-06-08T20:24:36.394Z,1654719876.394 [DataOverHttps](INFO): SBD MOMSN=16873182 2022-06-08T20:24:38.348Z,1654719878.348 [Default:CheckIn:Read_Iridium] Stopped 2022-06-08T20:24:38.348Z,1654719878.348 [Default:CheckIn:C.Wait] Running Loop=1 2022-06-08T20:24:38.348Z,1654719878.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-06-08T20:28:29.512Z,1654720109.512 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-06-08T20:28:33.151Z,1654720113.151 [DVL_micro](ERROR): only read 3 of 4 data items 2022-06-08T20:28:33.152Z,1654720113.152 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2022-06-08T20:29:00.268Z,1654720140.268 [NAL9602](INFO): Not Powering down - fast GPS 2022-06-08T20:29:39.050Z,1654720179.050 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-06-08T20:29:39.051Z,1654720179.051 [Default:CheckIn:C.Wait] Stopped 2022-06-08T20:29:39.051Z,1654720179.051 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-06-08T20:29:39.051Z,1654720179.051 [Default:CheckIn:D] Running Loop=1 2022-06-08T20:29:39.462Z,1654720179.462 [Default:CheckIn:D] Stopped 2022-06-08T20:29:39.462Z,1654720179.462 [Default:CheckIn:E] Running Loop=1 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 198.714941 min 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn:E] Stopped 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn] Stopped 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn](INFO): Running loop #36 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn] Running Loop=36 2022-06-08T20:29:39.857Z,1654720179.857 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-06-08T20:29:39.858Z,1654720179.858 [Default:CheckIn:Read_GPS] Running Loop=1 2022-06-08T20:29:41.871Z,1654720181.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202930.00,A,3428.40894,N,12012.60404,W,65.002,269.72,080622,,,A*4B 2022-06-08T20:29:41.874Z,1654720181.874 [NAL9602](INFO): GPS fix at 20220608T202930: (34.473482, -120.210067) 2022-06-08T20:29:41.884Z,1654720181.884 [Default:CheckIn:Read_GPS] Stopped 2022-06-08T20:29:41.885Z,1654720181.885 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-06-08T20:29:51.667Z,1654720191.667 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220608T185609/Courier0051.lzma 2022-06-08T20:29:52.670Z,1654720192.670 [DataOverHttps](INFO): Moved sent file to Logs/20220608T185609/Courier0051.lzma.bak 2022-06-08T20:29:52.670Z,1654720192.670 [DataOverHttps](INFO): SBD MOMSN=16873248 2022-06-08T20:30:10.168Z,1654