2025-03-13T16:29:27.310Z,1741883367.310 [CommandExec](IMPORTANT): got command restart logs 2025-03-13T16:30:47.211Z,1741883447.211 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T163046 2025-03-13T16:30:57.941Z,1741883457.941 [DataOverHttps](INFO): Received command: maintain control verticalControl.elevatorAngleAction -10 degree 2025-03-13T16:31:00.211Z,1741883460.211 [CommandExec](IMPORTANT): got command maintain control VerticalControl.elevatorAngleAction -10 degree 2025-03-13T16:31:00.215Z,1741883460.215 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.elevatorAngleAction" handled in the control thread. 2025-03-13T16:31:00.446Z,1741883460.446 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.elevatorAngleAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,Reporter,LogSplitter, 2025-03-13T16:31:26.507Z,1741883486.507 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T163126 2025-03-13T16:31:58.085Z,1741883518.085 [DataOverHttps](INFO): Received command: configSet verticalControl.massDefault -30 mm persist 2025-03-13T16:31:58.512Z,1741883518.512 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault -30 millimeter persist 2025-03-13T16:31:59.086Z,1741883519.086 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-03-13T16:32:18.691Z,1741883538.691 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T163218 2025-03-13T16:32:55.969Z,1741883575.969 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T16:32:55.969Z,1741883575.969 [Default:CheckIn:C.Wait] Stopped 2025-03-13T16:32:55.969Z,1741883575.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T16:32:55.969Z,1741883575.969 [Default:CheckIn:D] Running Loop=1 2025-03-13T16:32:56.371Z,1741883576.371 [Default:CheckIn:D] Stopped 2025-03-13T16:32:56.371Z,1741883576.371 [Default:CheckIn:E] Running Loop=1 2025-03-13T16:32:56.775Z,1741883576.775 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.451420 min 2025-03-13T16:32:56.775Z,1741883576.775 [Default:CheckIn:E] Stopped 2025-03-13T16:32:56.775Z,1741883576.775 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T16:32:56.775Z,1741883576.775 [Default:CheckIn] Stopped 2025-03-13T16:32:56.775Z,1741883576.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T16:32:56.776Z,1741883576.776 [Default:CheckIn](INFO): Running loop #3 2025-03-13T16:32:56.776Z,1741883576.776 [Default:CheckIn] Running Loop=3 2025-03-13T16:32:56.776Z,1741883576.776 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T16:32:56.776Z,1741883576.776 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T16:33:03.309Z,1741883583.309 [DataOverHttps](INFO): Received command: configSet verticalControl.massDefault -30 mm persist 2025-03-13T16:33:03.746Z,1741883583.746 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault -30 millimeter persist 2025-03-13T16:34:36.558Z,1741883676.558 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T16:34:38.190Z,1741883678.190 [NAL9602](INFO): SBD MO Status=2, MOMSN=62625, MT Status=2, MTMSN=0 2025-03-13T16:34:38.190Z,1741883678.190 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:34:42.216Z,1741883682.216 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T16:35:27.485Z,1741883727.485 [NAL9602](INFO): SBD MO Status=0, MOMSN=62625, MT Status=0, MTMSN=0 2025-03-13T16:35:27.485Z,1741883727.485 [NAL9602](INFO): No messages in MT queue 2025-03-13T16:35:28.298Z,1741883728.298 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-13T16:35:28.299Z,1741883728.299 [NAL9602] Data Fault, FailCount= 1 2025-03-13T16:35:28.299Z,1741883728.299 [NAL9602](ERROR): Data Fault 2025-03-13T16:35:28.396Z,1741883728.396 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-13T16:35:28.706Z,1741883728.706 [NAL9602](INFO): Powering down 2025-03-13T16:35:29.682Z,1741883729.682 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-13T16:35:29.682Z,1741883729.682 [NAL9602] No Fault, FailCount= 1 2025-03-13T16:35:59.113Z,1741883759.113 [NAL9602](INFO): Powering up NAL9602 2025-03-13T16:36:10.318Z,1741883770.318 [NAL9602](INFO): NAL9602 initialized 2025-03-13T16:37:09.294Z,1741883829.294 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:37:23.433Z,1741883843.433 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:37:36.764Z,1741883856.764 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:37:50.096Z,1741883870.096 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:37:56.981Z,1741883876.981 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T16:32:56.8Z 2025-03-13T16:37:56.981Z,1741883876.981 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T16:37:56.982Z,1741883876.982 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T16:38:03.430Z,1741883883.430 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:38:05.485Z,1741883885.485 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250313T010454/Courier0241.lzma 2025-03-13T16:38:06.487Z,1741883886.487 [DataOverHttps](INFO): Moved sent file to Logs/20250313T010454/Courier0241.lzma.bak 2025-03-13T16:38:06.487Z,1741883886.487 [DataOverHttps](INFO): SBD MOMSN=24223629 2025-03-13T16:38:16.762Z,1741883896.762 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:38:26.061Z,1741883906.061 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250313T162927/Courier0000.lzma 2025-03-13T16:38:27.063Z,1741883907.063 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0000.lzma.bak 2025-03-13T16:38:27.063Z,1741883907.063 [DataOverHttps](INFO): SBD MOMSN=24223631 2025-03-13T16:38:27.746Z,1741883907.746 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T16:38:30.158Z,1741883910.158 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:38:43.895Z,1741883923.895 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:38:58.069Z,1741883938.069 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:39:11.806Z,1741883951.806 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:39:18.269Z,1741883958.269 [DataOverHttps](INFO): Sending 107 bytes from file Logs/20250313T010454/Express0242.lzma 2025-03-13T16:39:19.271Z,1741883959.271 [DataOverHttps](INFO): Moved sent file to Logs/20250313T010454/Express0242.lzma.bak 2025-03-13T16:39:19.271Z,1741883959.271 [DataOverHttps](INFO): SBD MOMSN=24223634 2025-03-13T16:39:25.541Z,1741883965.541 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:39:36.315Z,1741883976.315 [DataOverHttps](INFO): Sending 584 bytes from file Logs/20250313T162927/Express0001.lzma 2025-03-13T16:39:37.315Z,1741883977.315 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0001.lzma.bak 2025-03-13T16:39:37.315Z,1741883977.315 [DataOverHttps](INFO): SBD MOMSN=24223637 2025-03-13T16:39:40.106Z,1741883980.106 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.648596 decibar, -0.643805 m 2025-03-13T16:40:07.605Z,1741884007.605 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250313T162927/Express0004.lzma 2025-03-13T16:40:08.607Z,1741884008.607 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0004.lzma.bak 2025-03-13T16:40:08.607Z,1741884008.607 [DataOverHttps](INFO): SBD MOMSN=24223648 2025-03-13T16:40:10.004Z,1741884010.004 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T16:40:10.005Z,1741884010.005 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T16:40:10.007Z,1741884010.007 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T16:45:10.635Z,1741884310.635 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T16:45:10.635Z,1741884310.635 [Default:CheckIn:C.Wait] Stopped 2025-03-13T16:45:10.635Z,1741884310.635 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T16:45:10.636Z,1741884310.636 [Default:CheckIn:D] Running Loop=1 2025-03-13T16:45:11.082Z,1741884311.082 [Default:CheckIn:D] Stopped 2025-03-13T16:45:11.083Z,1741884311.083 [Default:CheckIn:E] Running Loop=1 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.696617 min 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn:E] Stopped 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn] Stopped 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T16:45:11.430Z,1741884311.430 [Default:CheckIn](INFO): Running loop #4 2025-03-13T16:45:11.431Z,1741884311.431 [Default:CheckIn] Running Loop=4 2025-03-13T16:45:11.431Z,1741884311.431 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T16:45:11.431Z,1741884311.431 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T16:45:18.845Z,1741884318.845 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:45:37.288Z,1741884337.288 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:45:37.288Z,1741884337.288 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:45:49.977Z,1741884349.977 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:46:15.244Z,1741884375.244 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:46:15.244Z,1741884375.244 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:46:21.121Z,1741884381.121 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:46:31.403Z,1741884391.403 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-03-13T16:46:45.557Z,1741884405.557 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:46:52.285Z,1741884412.285 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:46:53.628Z,1741884413.628 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:46:53.629Z,1741884413.629 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:46:56.302Z,1741884416.302 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.799423 2025-03-13T16:46:59.680Z,1741884419.680 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:47:12.212Z,1741884432.212 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:47:25.949Z,1741884445.949 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:47:40.093Z,1741884460.093 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:47:53.054Z,1741884473.054 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003338 2025-03-13T16:47:53.428Z,1741884473.428 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:48:06.364Z,1741884486.364 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:48:07.189Z,1741884487.189 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:48:07.190Z,1741884487.190 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:48:19.686Z,1741884499.686 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:48:31.395Z,1741884511.395 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:48:31.395Z,1741884511.395 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:48:33.017Z,1741884513.017 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:48:45.956Z,1741884525.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:48:45.956Z,1741884525.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:48:46.745Z,1741884526.745 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:48:55.605Z,1741884535.605 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-03-13T16:49:00.881Z,1741884540.881 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:49:02.500Z,1741884542.500 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:49:02.500Z,1741884542.500 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:49:24.725Z,1741884564.725 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:49:24.725Z,1741884564.725 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:49:52.000Z,1741884593.000 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:49:53.000Z,1741884593.000 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:49:57.865Z,1741884597.865 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:50:11.605Z,1741884611.605 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T16:45:11.4Z 2025-03-13T16:50:11.605Z,1741884611.605 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T16:50:11.605Z,1741884611.605 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T16:50:15.630Z,1741884615.630 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-13T16:50:28.989Z,1741884628.989 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:50:46.346Z,1741884646.346 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T16:51:00.114Z,1741884660.114 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:51:09.150Z,1741884669.150 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.579819 2025-03-13T16:51:31.643Z,1741884691.643 [NAL9602](INFO): SBD MO Status=2, MOMSN=62626, MT Status=2, MTMSN=0 2025-03-13T16:51:31.644Z,1741884691.644 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:51:40.282Z,1741884700.282 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:52:11.417Z,1741884731.417 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T16:52:43.113Z,1741884763.113 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-03-13T16:52:56.152Z,1741884776.152 [NAL9602](INFO): SBD MO Status=1, MOMSN=62626, MT Status=0, MTMSN=0 2025-03-13T16:52:56.210Z,1741884776.210 [NAL9602](INFO): Sent 39 bytes from file Logs/20250313T162927/Courier0006.lzma 2025-03-13T16:52:56.210Z,1741884776.210 [NAL9602](INFO): Packets left to send: 0 2025-03-13T16:53:04.292Z,1741884784.292 [NAL9602](INFO): SBD MO Status=1, MOMSN=62627, MT Status=0, MTMSN=0 2025-03-13T16:53:04.345Z,1741884784.345 [NAL9602](INFO): Sent 130 bytes from file Logs/20250313T162927/Express0007.lzma 2025-03-13T16:53:04.345Z,1741884784.345 [NAL9602](INFO): Packets left to send: 0 2025-03-13T16:53:19.638Z,1741884799.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=62628, MT Status=2, MTMSN=0 2025-03-13T16:53:19.638Z,1741884799.638 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T16:53:29.850Z,1741884809.850 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003303 2025-03-13T16:53:31.370Z,1741884811.370 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T16:53:31.370Z,1741884811.370 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T16:53:31.370Z,1741884811.370 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T16:53:45.501Z,1741884825.501 [NAL9602](INFO): SBD MO Status=0, MOMSN=62628, MT Status=0, MTMSN=0 2025-03-13T16:54:16.204Z,1741884856.204 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T16:56:18.611Z,1741884978.611 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:56:32.346Z,1741884992.346 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:56:46.487Z,1741885006.487 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:56:59.817Z,1741885019.817 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:57:13.149Z,1741885033.149 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:57:26.481Z,1741885046.481 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:57:40.220Z,1741885060.220 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:57:54.762Z,1741885074.762 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:58:08.901Z,1741885088.901 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:58:22.234Z,1741885102.234 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:58:31.944Z,1741885111.944 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T16:58:31.944Z,1741885111.944 [Default:CheckIn:C.Wait] Stopped 2025-03-13T16:58:31.944Z,1741885111.944 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T16:58:31.944Z,1741885111.944 [Default:CheckIn:D] Running Loop=1 2025-03-13T16:58:32.354Z,1741885112.354 [Default:CheckIn:D] Stopped 2025-03-13T16:58:32.354Z,1741885112.354 [Default:CheckIn:E] Running Loop=1 2025-03-13T16:58:32.770Z,1741885112.770 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.051143 min 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn:E] Stopped 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn] Stopped 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn](INFO): Running loop #5 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn] Running Loop=5 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T16:58:32.771Z,1741885112.771 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T16:58:34.362Z,1741885114.362 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-13T16:58:34.363Z,1741885114.363 [NAL9602] Data Fault, FailCount= 2 2025-03-13T16:58:34.363Z,1741885114.363 [NAL9602](ERROR): Data Fault 2025-03-13T16:58:34.415Z,1741885114.415 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-13T16:58:34.759Z,1741885114.759 [NAL9602](INFO): Powering down 2025-03-13T16:58:35.618Z,1741885115.618 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-13T16:58:35.618Z,1741885115.618 [NAL9602] No Fault, FailCount= 2 2025-03-13T16:58:36.025Z,1741885116.025 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T16:59:05.060Z,1741885145.060 [NAL9602](INFO): Powering up NAL9602 2025-03-13T16:59:15.966Z,1741885155.966 [NAL9602](INFO): NAL9602 initialized 2025-03-13T16:59:59.600Z,1741885199.600 [NAL9602](INFO): SBD MO Status=2, MOMSN=62629, MT Status=2, MTMSN=0 2025-03-13T16:59:59.600Z,1741885199.600 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:00:20.218Z,1741885220.218 [NAL9602](INFO): SBD MO Status=2, MOMSN=62629, MT Status=2, MTMSN=0 2025-03-13T17:00:20.219Z,1741885220.219 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:00:52.120Z,1741885252.120 [NAL9602](INFO): SBD MO Status=2, MOMSN=62629, MT Status=2, MTMSN=0 2025-03-13T17:00:52.120Z,1741885252.120 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:01:04.250Z,1741885264.250 [NAL9602](INFO): SBD MO Status=2, MOMSN=62629, MT Status=2, MTMSN=0 2025-03-13T17:01:04.250Z,1741885264.250 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:01:22.015Z,1741885282.015 [NAL9602](INFO): SBD MO Status=2, MOMSN=62629, MT Status=2, MTMSN=0 2025-03-13T17:01:22.016Z,1741885282.016 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:01:48.688Z,1741885308.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=62629, MT Status=0, MTMSN=0 2025-03-13T17:01:48.688Z,1741885308.688 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:03:09.935Z,1741885389.935 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4. 2025-03-13T17:03:09.938Z,1741885389.938 [BPC1](FAULT): Failed to receive data from 7 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 32, 33, 36, 37, 50, 51, 54. 2025-03-13T17:03:32.986Z,1741885412.986 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T16:58:32.8Z 2025-03-13T17:03:32.986Z,1741885412.986 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:03:32.987Z,1741885412.987 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:03:43.881Z,1741885423.881 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250313T162927/Courier0009.lzma 2025-03-13T17:03:44.883Z,1741885424.883 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0009.lzma.bak 2025-03-13T17:03:44.883Z,1741885424.883 [DataOverHttps](INFO): SBD MOMSN=24223776 2025-03-13T17:04:02.121Z,1741885442.121 [DataOverHttps](INFO): Sending 334 bytes from file Logs/20250313T162927/Express0010.lzma 2025-03-13T17:04:03.123Z,1741885443.123 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0010.lzma.bak 2025-03-13T17:04:03.123Z,1741885443.123 [DataOverHttps](INFO): SBD MOMSN=24223787 2025-03-13T17:04:03.686Z,1741885443.686 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:04:04.515Z,1741885444.515 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:04:04.515Z,1741885444.515 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:04:04.515Z,1741885444.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:09:05.088Z,1741885745.088 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:09:05.088Z,1741885745.088 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:09:05.089Z,1741885745.089 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:09:05.089Z,1741885745.089 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:09:05.497Z,1741885745.497 [Default:CheckIn:D] Stopped 2025-03-13T17:09:05.497Z,1741885745.497 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:09:05.889Z,1741885745.889 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.603455 min 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn:E] Stopped 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn] Stopped 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn](INFO): Running loop #6 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn] Running Loop=6 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:09:05.890Z,1741885745.890 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:09:38.608Z,1741885778.608 [NAL9602](INFO): SBD MO Status=0, MOMSN=62630, MT Status=0, MTMSN=0 2025-03-13T17:09:38.608Z,1741885778.608 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:09:39.412Z,1741885779.412 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-13T17:09:39.412Z,1741885779.412 [NAL9602] Data Fault, FailCount= 1 2025-03-13T17:09:39.412Z,1741885779.412 [NAL9602](ERROR): Data Fault 2025-03-13T17:09:39.433Z,1741885779.433 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-13T17:09:39.818Z,1741885779.818 [NAL9602](INFO): Powering down 2025-03-13T17:09:40.650Z,1741885780.650 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-13T17:09:40.650Z,1741885780.650 [NAL9602] No Fault, FailCount= 1 2025-03-13T17:10:10.116Z,1741885810.116 [NAL9602](INFO): Powering up NAL9602 2025-03-13T17:10:21.119Z,1741885821.119 [NAL9602](INFO): NAL9602 initialized 2025-03-13T17:14:06.106Z,1741886046.106 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T17:09:05.9Z 2025-03-13T17:14:06.106Z,1741886046.106 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:14:06.106Z,1741886046.106 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:14:13.140Z,1741886053.140 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250313T162927/Courier0012.lzma 2025-03-13T17:14:14.143Z,1741886054.143 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0012.lzma.bak 2025-03-13T17:14:14.143Z,1741886054.143 [DataOverHttps](INFO): SBD MOMSN=24223825 2025-03-13T17:14:33.781Z,1741886073.781 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250313T162927/Express0013.lzma 2025-03-13T17:14:34.783Z,1741886074.783 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0013.lzma.bak 2025-03-13T17:14:34.783Z,1741886074.783 [DataOverHttps](INFO): SBD MOMSN=24223827 2025-03-13T17:14:36.079Z,1741886076.079 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:14:36.080Z,1741886076.080 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:14:36.080Z,1741886076.080 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:14:36.858Z,1741886076.858 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:18:11.785Z,1741886291.785 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:18:25.112Z,1741886305.112 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:18:38.445Z,1741886318.445 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:18:51.818Z,1741886331.818 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:19:05.108Z,1741886345.108 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:19:18.440Z,1741886358.440 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:19:31.777Z,1741886371.777 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:19:36.642Z,1741886376.642 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:19:36.642Z,1741886376.642 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:19:36.642Z,1741886376.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:19:36.642Z,1741886376.642 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:19:37.059Z,1741886377.059 [Default:CheckIn:D] Stopped 2025-03-13T17:19:37.059Z,1741886377.059 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:19:37.449Z,1741886377.449 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.129561 min 2025-03-13T17:19:37.449Z,1741886377.449 [Default:CheckIn:E] Stopped 2025-03-13T17:19:37.449Z,1741886377.449 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn] Stopped 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn](INFO): Running loop #7 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn] Running Loop=7 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:19:37.450Z,1741886377.450 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:19:45.104Z,1741886385.104 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:19:58.843Z,1741886398.843 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:20:05.722Z,1741886405.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=62631, MT Status=2, MTMSN=0 2025-03-13T17:20:05.722Z,1741886405.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:20:12.173Z,1741886412.173 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:20:23.920Z,1741886423.920 [NAL9602](INFO): SBD MO Status=0, MOMSN=62631, MT Status=0, MTMSN=0 2025-03-13T17:20:23.920Z,1741886423.920 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:20:24.727Z,1741886424.727 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-13T17:20:24.727Z,1741886424.727 [NAL9602] Data Fault, FailCount= 1 2025-03-13T17:20:24.727Z,1741886424.727 [NAL9602](ERROR): Data Fault 2025-03-13T17:20:24.756Z,1741886424.756 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-13T17:20:25.175Z,1741886425.175 [NAL9602](INFO): Powering down 2025-03-13T17:20:25.533Z,1741886425.533 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:20:26.018Z,1741886426.018 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-13T17:20:26.018Z,1741886426.018 [NAL9602] No Fault, FailCount= 1 2025-03-13T17:20:55.460Z,1741886455.460 [NAL9602](INFO): Powering up NAL9602 2025-03-13T17:21:06.356Z,1741886466.356 [NAL9602](INFO): NAL9602 initialized 2025-03-13T17:24:37.858Z,1741886677.858 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T17:19:37.5Z 2025-03-13T17:24:37.858Z,1741886677.858 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:24:37.858Z,1741886677.858 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:24:45.517Z,1741886685.517 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250313T162927/Courier0015.lzma 2025-03-13T17:24:46.519Z,1741886686.519 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0015.lzma.bak 2025-03-13T17:24:46.519Z,1741886686.519 [DataOverHttps](INFO): SBD MOMSN=24223857 2025-03-13T17:25:06.161Z,1741886706.161 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20250313T162927/Express0016.lzma 2025-03-13T17:25:07.163Z,1741886707.163 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0016.lzma.bak 2025-03-13T17:25:07.163Z,1741886707.163 [DataOverHttps](INFO): SBD MOMSN=24223862 2025-03-13T17:25:08.602Z,1741886708.602 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:25:08.603Z,1741886708.603 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:25:08.603Z,1741886708.603 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:25:10.210Z,1741886710.210 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:27:43.380Z,1741886863.380 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:27:57.064Z,1741886877.064 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:28:11.191Z,1741886891.191 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:28:24.933Z,1741886904.933 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:28:38.265Z,1741886918.265 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:28:52.023Z,1741886932.023 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:29:05.758Z,1741886945.758 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:29:19.492Z,1741886959.492 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:29:33.633Z,1741886973.633 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:29:46.965Z,1741886986.965 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:30:00.702Z,1741887000.702 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:30:09.205Z,1741887009.205 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:30:09.205Z,1741887009.205 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:30:09.205Z,1741887009.205 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:30:09.206Z,1741887009.206 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:30:09.623Z,1741887009.623 [Default:CheckIn:D] Stopped 2025-03-13T17:30:09.623Z,1741887009.623 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.672298 min 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn:E] Stopped 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn] Stopped 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn](INFO): Running loop #8 2025-03-13T17:30:10.007Z,1741887010.007 [Default:CheckIn] Running Loop=8 2025-03-13T17:30:10.008Z,1741887010.008 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:30:10.008Z,1741887010.008 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:30:12.019Z,1741887012.019 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173011.00,A,3658.01424,N,12200.09252,W,0.875,0.00,130325,,,A*73 2025-03-13T17:30:12.022Z,1741887012.022 [NAL9602](INFO): GPS fix at 20250313T173011: (36.966904, -122.001542) 2025-03-13T17:30:12.034Z,1741887012.034 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:30:12.034Z,1741887012.034 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:30:22.065Z,1741887022.065 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20250313T162927/Courier0018.lzma 2025-03-13T17:30:23.067Z,1741887023.067 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0018.lzma.bak 2025-03-13T17:30:23.067Z,1741887023.067 [DataOverHttps](INFO): SBD MOMSN=24223889 2025-03-13T17:30:26.604Z,1741887026.604 [NAL9602](INFO): SBD MO Status=0, MOMSN=62632, MT Status=0, MTMSN=0 2025-03-13T17:30:26.604Z,1741887026.604 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:30:40.830Z,1741887040.830 [DataOverHttps](INFO): Sending 311 bytes from file Logs/20250313T162927/Express0019.lzma 2025-03-13T17:30:41.831Z,1741887041.831 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0019.lzma.bak 2025-03-13T17:30:41.831Z,1741887041.831 [DataOverHttps](INFO): SBD MOMSN=24223892 2025-03-13T17:30:43.182Z,1741887043.182 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:30:43.182Z,1741887043.182 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:30:43.183Z,1741887043.183 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:30:57.314Z,1741887057.314 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:35:44.001Z,1741887344.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:35:44.001Z,1741887344.001 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:35:44.001Z,1741887344.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:35:44.001Z,1741887344.001 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:35:44.406Z,1741887344.406 [Default:CheckIn:D] Stopped 2025-03-13T17:35:44.406Z,1741887344.406 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.252010 min 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn:E] Stopped 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn] Stopped 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn](INFO): Running loop #9 2025-03-13T17:35:44.801Z,1741887344.801 [Default:CheckIn] Running Loop=9 2025-03-13T17:35:44.802Z,1741887344.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:35:44.802Z,1741887344.802 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:36:46.664Z,1741887406.664 [NAL9602](INFO): SBD MO Status=2, MOMSN=62633, MT Status=2, MTMSN=0 2025-03-13T17:36:46.665Z,1741887406.665 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:37:12.559Z,1741887432.559 [NAL9602](INFO): SBD MO Status=2, MOMSN=62633, MT Status=2, MTMSN=0 2025-03-13T17:37:12.560Z,1741887432.560 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-03-13T17:37:27.498Z,1741887447.498 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:37:42.042Z,1741887462.042 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:37:53.380Z,1741887473.380 [NAL9602](INFO): SBD MO Status=0, MOMSN=62633, MT Status=0, MTMSN=0 2025-03-13T17:37:53.380Z,1741887473.380 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:37:54.572Z,1741887474.572 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173754.00,A,3658.88370,N,12159.37589,W,16.989,6.34,130325,,,A*45 2025-03-13T17:37:54.575Z,1741887474.575 [NAL9602](INFO): GPS fix at 20250313T173754: (36.981395, -121.989598) 2025-03-13T17:37:54.626Z,1741887474.626 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:37:54.627Z,1741887474.627 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:37:55.519Z,1741887475.519 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:37:57.616Z,1741887477.616 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0021.lzma 2025-03-13T17:37:58.331Z,1741887478.331 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0021.lzma.bak 2025-03-13T17:37:58.331Z,1741887478.331 [DataOverHttps](INFO): SBD MOMSN=24223916 2025-03-13T17:38:09.641Z,1741887489.641 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:38:17.365Z,1741887497.365 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250313T162927/Express0022.lzma 2025-03-13T17:38:18.367Z,1741887498.367 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0022.lzma.bak 2025-03-13T17:38:18.367Z,1741887498.367 [DataOverHttps](INFO): SBD MOMSN=24223920 2025-03-13T17:38:19.879Z,1741887499.879 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:38:19.880Z,1741887499.880 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:38:19.880Z,1741887499.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:38:23.405Z,1741887503.405 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:38:27.082Z,1741887507.082 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:38:37.982Z,1741887517.982 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:38:52.533Z,1741887532.533 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:39:07.095Z,1741887547.095 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:39:13.222Z,1741887553.222 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-03-13T17:39:20.449Z,1741887560.449 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:39:34.162Z,1741887574.162 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:39:34.166Z,1741887574.166 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-03-13T17:39:40.221Z,1741887580.221 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-03-13T17:40:35.574Z,1741887635.574 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-03-13T17:41:41.423Z,1741887701.423 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-03-13T17:43:20.425Z,1741887800.425 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:43:20.425Z,1741887800.425 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:43:20.425Z,1741887800.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:43:20.426Z,1741887800.426 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:43:20.837Z,1741887800.837 [Default:CheckIn:D] Stopped 2025-03-13T17:43:20.837Z,1741887800.837 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:43:21.241Z,1741887801.241 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.859188 min 2025-03-13T17:43:21.241Z,1741887801.241 [Default:CheckIn:E] Stopped 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn] Stopped 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn](INFO): Running loop #10 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn] Running Loop=10 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:43:21.242Z,1741887801.242 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:43:23.252Z,1741887803.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174322.00,A,3659.02771,N,12155.89847,W,54.739,95.52,130325,,,A*7E 2025-03-13T17:43:23.263Z,1741887803.263 [NAL9602](INFO): GPS fix at 20250313T174322: (36.983795, -121.931641) 2025-03-13T17:43:23.275Z,1741887803.275 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:43:23.275Z,1741887803.275 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:43:30.665Z,1741887810.665 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250313T162927/Courier0024.lzma 2025-03-13T17:43:31.667Z,1741887811.667 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0024.lzma.bak 2025-03-13T17:43:31.667Z,1741887811.667 [DataOverHttps](INFO): SBD MOMSN=24223941 2025-03-13T17:43:36.176Z,1741887816.176 [NAL9602](INFO): SBD MO Status=0, MOMSN=62634, MT Status=0, MTMSN=0 2025-03-13T17:43:36.176Z,1741887816.176 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:43:47.565Z,1741887827.565 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250313T162927/Express0025.lzma 2025-03-13T17:43:48.567Z,1741887828.567 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0025.lzma.bak 2025-03-13T17:43:48.567Z,1741887828.567 [DataOverHttps](INFO): SBD MOMSN=24223944 2025-03-13T17:43:49.927Z,1741887829.927 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:43:49.927Z,1741887829.927 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:43:49.927Z,1741887829.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:44:06.882Z,1741887846.882 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:44:11.721Z,1741887851.721 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4. 2025-03-13T17:44:11.725Z,1741887851.725 [BPC1](FAULT): Failed to receive data from 7 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 32, 33, 36, 37, 50, 51, 54. 2025-03-13T17:45:52.370Z,1741887952.370 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T17:48:50.581Z,1741888130.581 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:48:50.581Z,1741888130.581 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:48:50.581Z,1741888130.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:48:50.582Z,1741888130.582 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:48:50.984Z,1741888130.984 [Default:CheckIn:D] Stopped 2025-03-13T17:48:50.984Z,1741888130.984 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:48:51.413Z,1741888131.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.361646 min 2025-03-13T17:48:51.414Z,1741888131.414 [Default:CheckIn:E] Stopped 2025-03-13T17:48:51.415Z,1741888131.415 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:48:51.415Z,1741888131.415 [Default:CheckIn] Stopped 2025-03-13T17:48:51.416Z,1741888131.416 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:48:51.417Z,1741888131.417 [Default:CheckIn](INFO): Running loop #11 2025-03-13T17:48:51.417Z,1741888131.417 [Default:CheckIn] Running Loop=11 2025-03-13T17:48:51.429Z,1741888131.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:48:51.430Z,1741888131.430 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:48:53.409Z,1741888133.409 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174853.00,A,3656.62142,N,12150.58594,W,52.289,129.57,130325,,,A*4D 2025-03-13T17:48:53.411Z,1741888133.411 [NAL9602](INFO): GPS fix at 20250313T174853: (36.943690, -121.843099) 2025-03-13T17:48:53.458Z,1741888133.458 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:48:53.458Z,1741888133.458 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:49:00.905Z,1741888140.905 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20250313T162927/Courier0027.lzma 2025-03-13T17:49:01.907Z,1741888141.907 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0027.lzma.bak 2025-03-13T17:49:01.907Z,1741888141.907 [DataOverHttps](INFO): SBD MOMSN=24223970 2025-03-13T17:49:09.664Z,1741888149.664 [NAL9602](INFO): SBD MO Status=0, MOMSN=62635, MT Status=0, MTMSN=0 2025-03-13T17:49:09.664Z,1741888149.664 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:49:17.762Z,1741888157.762 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20250313T162927/Express0028.lzma 2025-03-13T17:49:18.763Z,1741888158.763 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0028.lzma.bak 2025-03-13T17:49:18.763Z,1741888158.763 [DataOverHttps](INFO): SBD MOMSN=24223974 2025-03-13T17:49:20.182Z,1741888160.182 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:49:20.182Z,1741888160.182 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:49:20.182Z,1741888160.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:49:40.366Z,1741888180.366 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:49:57.878Z,1741888197.878 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T174957 2025-03-13T17:50:05.393Z,1741888205.393 [DataOverHttps](INFO): Received command: gfscan 2025-03-13T17:50:05.454Z,1741888205.454 [CommandExec](IMPORTANT): got command gfscan 2025-03-13T17:50:05.842Z,1741888205.842 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-13T17:50:10.290Z,1741888210.290 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002047 CHAN A1 (24V): 0.000583 CHAN A2 (12V): -0.001941 CHAN A3 (5V): -0.001162 CHAN B0 (3.3V): -0.000139 CHAN B1 (3.15aV): -0.000119 CHAN B2 (3.15bV): -0.000507 CHAN B3 (GND): -0.000007 OPEN: -0.000682 Full Scale: +/- 1 mA 2025-03-13T17:50:40.107Z,1741888240.107 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T175039 2025-03-13T17:50:47.577Z,1741888247.577 [DataOverHttps](INFO): Received command: maintain clear 2025-03-13T17:50:47.631Z,1741888247.631 [CommandExec](IMPORTANT): got command maintain clear 2025-03-13T17:50:47.898Z,1741888247.898 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,Reporter,LogSplitter, 2025-03-13T17:50:48.578Z,1741888248.578 [DataOverHttps](IMPORTANT): SBD MTMSN=20250313T175048 2025-03-13T17:50:59.881Z,1741888259.881 [DataOverHttps](INFO): Received command: report clear 2025-03-13T17:50:59.958Z,1741888259.958 [CommandExec](IMPORTANT): got command report clear 2025-03-13T17:54:20.850Z,1741888460.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T17:54:20.850Z,1741888460.850 [Default:CheckIn:C.Wait] Stopped 2025-03-13T17:54:20.850Z,1741888460.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T17:54:20.850Z,1741888460.850 [Default:CheckIn:D] Running Loop=1 2025-03-13T17:54:21.270Z,1741888461.270 [Default:CheckIn:D] Stopped 2025-03-13T17:54:21.271Z,1741888461.271 [Default:CheckIn:E] Running Loop=1 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.866414 min 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn:E] Stopped 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn] Stopped 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn](INFO): Running loop #12 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn] Running Loop=12 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T17:54:21.654Z,1741888461.654 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T17:54:23.656Z,1741888463.656 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175423.00,A,3653.56409,N,12146.43286,W,55.477,169.52,130325,,,A*47 2025-03-13T17:54:23.658Z,1741888463.658 [NAL9602](INFO): GPS fix at 20250313T175423: (36.892735, -121.773881) 2025-03-13T17:54:23.705Z,1741888463.705 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T17:54:23.705Z,1741888463.705 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T17:54:31.137Z,1741888471.137 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250313T162927/Courier0030.lzma 2025-03-13T17:54:32.139Z,1741888472.139 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0030.lzma.bak 2025-03-13T17:54:32.139Z,1741888472.139 [DataOverHttps](INFO): SBD MOMSN=24224003 2025-03-13T17:54:37.948Z,1741888477.948 [NAL9602](INFO): SBD MO Status=0, MOMSN=62636, MT Status=0, MTMSN=0 2025-03-13T17:54:37.948Z,1741888477.948 [NAL9602](INFO): No messages in MT queue 2025-03-13T17:54:48.878Z,1741888488.878 [DataOverHttps](INFO): Sending 464 bytes from file Logs/20250313T162927/Express0031.lzma 2025-03-13T17:54:49.879Z,1741888489.879 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0031.lzma.bak 2025-03-13T17:54:49.879Z,1741888489.879 [DataOverHttps](INFO): SBD MOMSN=24224006 2025-03-13T17:55:08.689Z,1741888508.689 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20250313T162927/Express0032.lzma 2025-03-13T17:55:08.692Z,1741888508.692 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T17:55:09.691Z,1741888509.691 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0032.lzma.bak 2025-03-13T17:55:09.691Z,1741888509.691 [DataOverHttps](INFO): SBD MOMSN=24224029 2025-03-13T17:55:11.121Z,1741888511.121 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T17:55:11.122Z,1741888511.122 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T17:55:11.122Z,1741888511.122 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T17:56:40.081Z,1741888600.081 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T17:56:45.672Z,1741888605.672 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T17:59:12.486Z,1741888752.486 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:59:26.170Z,1741888766.170 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:59:39.498Z,1741888779.498 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T17:59:52.829Z,1741888792.829 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:00:06.161Z,1741888806.161 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:00:11.842Z,1741888811.842 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:00:11.842Z,1741888811.842 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:00:11.842Z,1741888811.842 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:00:11.842Z,1741888811.842 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:00:12.233Z,1741888812.233 [Default:CheckIn:D] Stopped 2025-03-13T18:00:12.233Z,1741888812.233 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:00:12.637Z,1741888812.637 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.715788 min 2025-03-13T18:00:12.637Z,1741888812.637 [Default:CheckIn:E] Stopped 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn] Stopped 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn](INFO): Running loop #13 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn] Running Loop=13 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:00:12.638Z,1741888812.638 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:00:14.658Z,1741888814.658 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180014.00,A,3648.66404,N,12147.11303,W,45.486,163.60,130325,,,A*47 2025-03-13T18:00:14.660Z,1741888814.660 [NAL9602](INFO): GPS fix at 20250313T180014: (36.811067, -121.785217) 2025-03-13T18:00:14.670Z,1741888814.670 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:00:14.671Z,1741888814.671 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:00:20.340Z,1741888820.340 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:00:28.937Z,1741888828.937 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0035.lzma 2025-03-13T18:00:29.939Z,1741888829.939 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0035.lzma.bak 2025-03-13T18:00:29.939Z,1741888829.939 [DataOverHttps](INFO): SBD MOMSN=24224078 2025-03-13T18:00:33.753Z,1741888833.753 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:00:44.264Z,1741888844.264 [NAL9602](INFO): SBD MO Status=0, MOMSN=62637, MT Status=0, MTMSN=0 2025-03-13T18:00:44.264Z,1741888844.264 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:00:46.230Z,1741888846.230 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20250313T162927/Express0037.lzma 2025-03-13T18:00:46.681Z,1741888846.681 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:00:47.231Z,1741888847.231 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0037.lzma.bak 2025-03-13T18:00:47.231Z,1741888847.231 [DataOverHttps](INFO): SBD MOMSN=24224099 2025-03-13T18:00:48.754Z,1741888848.754 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:00:48.755Z,1741888848.755 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:00:48.755Z,1741888848.755 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:00:59.666Z,1741888859.666 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:01:12.997Z,1741888872.997 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:01:15.023Z,1741888875.023 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:01:26.329Z,1741888886.329 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T18:05:49.393Z,1741889149.393 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:05:49.393Z,1741889149.393 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:05:49.393Z,1741889149.393 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:05:49.394Z,1741889149.394 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:05:49.804Z,1741889149.804 [Default:CheckIn:D] Stopped 2025-03-13T18:05:49.804Z,1741889149.804 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.341976 min 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn:E] Stopped 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn] Stopped 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:05:50.267Z,1741889150.267 [Default:CheckIn](INFO): Running loop #14 2025-03-13T18:05:50.268Z,1741889150.268 [Default:CheckIn] Running Loop=14 2025-03-13T18:05:50.268Z,1741889150.268 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:05:50.268Z,1741889150.268 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:05:52.217Z,1741889152.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180551.00,A,3648.15974,N,12147.28151,W,1.089,342.65,130325,,,A*7D 2025-03-13T18:05:52.219Z,1741889152.219 [NAL9602](INFO): GPS fix at 20250313T180551: (36.802662, -121.788025) 2025-03-13T18:05:52.249Z,1741889152.249 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:05:52.249Z,1741889152.249 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:06:00.393Z,1741889160.393 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0039.lzma 2025-03-13T18:06:01.395Z,1741889161.395 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0039.lzma.bak 2025-03-13T18:06:01.395Z,1741889161.395 [DataOverHttps](INFO): SBD MOMSN=24224155 2025-03-13T18:06:08.785Z,1741889168.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=62638, MT Status=0, MTMSN=0 2025-03-13T18:06:08.785Z,1741889168.785 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:06:18.217Z,1741889178.217 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250313T162927/Express0040.lzma 2025-03-13T18:06:19.219Z,1741889179.219 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0040.lzma.bak 2025-03-13T18:06:19.219Z,1741889179.219 [DataOverHttps](INFO): SBD MOMSN=24224158 2025-03-13T18:06:20.538Z,1741889180.538 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:06:20.538Z,1741889180.538 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:06:20.538Z,1741889180.538 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:06:39.534Z,1741889199.534 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:08:39.560Z,1741889319.560 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 5. 2025-03-13T18:08:39.587Z,1741889319.587 [BPC1](INFO): Received data from all battery sticks. 2025-03-13T18:11:21.318Z,1741889481.318 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:11:21.318Z,1741889481.318 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:11:21.318Z,1741889481.318 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:11:21.319Z,1741889481.319 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:11:21.574Z,1741889481.574 [Default:CheckIn:D] Stopped 2025-03-13T18:11:21.574Z,1741889481.574 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.871468 min 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn:E] Stopped 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn] Stopped 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn](INFO): Running loop #15 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn] Running Loop=15 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:11:21.990Z,1741889481.990 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:11:23.992Z,1741889483.992 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181123.00,A,3648.15043,N,12147.22767,W,0.505,5.43,130325,,,A*7D 2025-03-13T18:11:23.994Z,1741889483.994 [NAL9602](INFO): GPS fix at 20250313T181123: (36.802507, -121.787128) 2025-03-13T18:11:24.027Z,1741889484.027 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:11:24.027Z,1741889484.027 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:11:31.693Z,1741889491.693 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250313T162927/Courier0042.lzma 2025-03-13T18:11:32.695Z,1741889492.695 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0042.lzma.bak 2025-03-13T18:11:32.695Z,1741889492.695 [DataOverHttps](INFO): SBD MOMSN=24224178 2025-03-13T18:11:48.763Z,1741889508.763 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250313T162927/Express0043.lzma 2025-03-13T18:11:49.759Z,1741889509.759 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0043.lzma.bak 2025-03-13T18:11:49.759Z,1741889509.759 [DataOverHttps](INFO): SBD MOMSN=24224182 2025-03-13T18:11:51.072Z,1741889511.072 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:11:51.073Z,1741889511.073 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:11:51.073Z,1741889511.073 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:12:01.218Z,1741889521.218 [NAL9602](INFO): SBD MO Status=0, MOMSN=62639, MT Status=0, MTMSN=0 2025-03-13T18:12:01.219Z,1741889521.219 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:12:31.886Z,1741889551.886 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:16:51.719Z,1741889811.719 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:16:51.719Z,1741889811.719 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:16:51.719Z,1741889811.719 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:16:51.719Z,1741889811.719 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:16:52.094Z,1741889812.094 [Default:CheckIn:D] Stopped 2025-03-13T18:16:52.094Z,1741889812.094 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:16:52.498Z,1741889812.498 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.380143 min 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn:E] Stopped 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn] Stopped 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn](INFO): Running loop #16 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn] Running Loop=16 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:16:52.499Z,1741889812.499 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:16:54.496Z,1741889814.496 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181654.00,A,3648.15676,N,12147.21707,W,0.408,5.43,130325,,,A*73 2025-03-13T18:16:54.499Z,1741889814.499 [NAL9602](INFO): GPS fix at 20250313T181654: (36.802613, -121.786951) 2025-03-13T18:16:54.509Z,1741889814.509 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:16:54.510Z,1741889814.510 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:17:02.630Z,1741889822.630 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0045.lzma 2025-03-13T18:17:03.631Z,1741889823.631 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0045.lzma.bak 2025-03-13T18:17:03.632Z,1741889823.632 [DataOverHttps](INFO): SBD MOMSN=24224200 2025-03-13T18:17:16.312Z,1741889836.312 [NAL9602](INFO): SBD MO Status=0, MOMSN=62640, MT Status=0, MTMSN=0 2025-03-13T18:17:16.312Z,1741889836.312 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:17:19.657Z,1741889839.657 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250313T162927/Express0046.lzma 2025-03-13T18:17:20.659Z,1741889840.659 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0046.lzma.bak 2025-03-13T18:17:20.659Z,1741889840.659 [DataOverHttps](INFO): SBD MOMSN=24224203 2025-03-13T18:17:21.994Z,1741889841.994 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:17:21.994Z,1741889841.994 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:17:21.994Z,1741889841.994 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:17:47.014Z,1741889867.014 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:22:22.572Z,1741890142.572 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:22:22.573Z,1741890142.573 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:22:22.573Z,1741890142.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:22:22.585Z,1741890142.585 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:22:22.969Z,1741890142.969 [Default:CheckIn:D] Stopped 2025-03-13T18:22:22.969Z,1741890142.969 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.894718 min 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn:E] Stopped 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn] Stopped 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:22:23.381Z,1741890143.381 [Default:CheckIn](INFO): Running loop #17 2025-03-13T18:22:23.382Z,1741890143.382 [Default:CheckIn] Running Loop=17 2025-03-13T18:22:23.382Z,1741890143.382 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:22:23.382Z,1741890143.382 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:22:25.385Z,1741890145.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182225.00,A,3648.17115,N,12147.28349,W,1.536,298.93,130325,,,A*73 2025-03-13T18:22:25.387Z,1741890145.387 [NAL9602](INFO): GPS fix at 20250313T182225: (36.802853, -121.788058) 2025-03-13T18:22:25.415Z,1741890145.415 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:22:25.415Z,1741890145.415 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:22:36.681Z,1741890156.681 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0048.lzma 2025-03-13T18:22:38.687Z,1741890158.687 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0048.lzma.bak 2025-03-13T18:22:38.687Z,1741890158.687 [DataOverHttps](INFO): SBD MOMSN=24224228 2025-03-13T18:23:08.941Z,1741890188.941 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250313T162927/Express0049.lzma 2025-03-13T18:23:10.947Z,1741890190.947 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0049.lzma.bak 2025-03-13T18:23:10.947Z,1741890190.947 [DataOverHttps](INFO): SBD MOMSN=24224231 2025-03-13T18:23:12.265Z,1741890192.265 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:23:12.265Z,1741890192.265 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:23:12.265Z,1741890192.265 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:24:41.964Z,1741890281.964 [NAL9602](INFO): SBD MO Status=0, MOMSN=62641, MT Status=0, MTMSN=0 2025-03-13T18:24:41.964Z,1741890281.964 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:25:12.723Z,1741890312.723 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:28:13.015Z,1741890493.015 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:28:13.015Z,1741890493.015 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:28:13.016Z,1741890493.016 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:28:13.016Z,1741890493.016 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:28:13.429Z,1741890493.429 [Default:CheckIn:D] Stopped 2025-03-13T18:28:13.429Z,1741890493.429 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:28:13.826Z,1741890493.826 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.735726 min 2025-03-13T18:28:13.826Z,1741890493.826 [Default:CheckIn:E] Stopped 2025-03-13T18:28:13.826Z,1741890493.826 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:28:13.826Z,1741890493.826 [Default:CheckIn] Stopped 2025-03-13T18:28:13.826Z,1741890493.826 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:28:13.827Z,1741890493.827 [Default:CheckIn](INFO): Running loop #18 2025-03-13T18:28:13.827Z,1741890493.827 [Default:CheckIn] Running Loop=18 2025-03-13T18:28:13.827Z,1741890493.827 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:28:13.827Z,1741890493.827 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:28:15.840Z,1741890495.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182815.00,A,3648.16874,N,12147.27083,W,0.292,205.10,130325,,,A*78 2025-03-13T18:28:15.842Z,1741890495.842 [NAL9602](INFO): GPS fix at 20250313T182815: (36.802812, -121.787847) 2025-03-13T18:28:15.853Z,1741890495.853 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:28:15.853Z,1741890495.853 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:28:26.553Z,1741890506.553 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0051.lzma 2025-03-13T18:28:27.555Z,1741890507.555 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0051.lzma.bak 2025-03-13T18:28:27.555Z,1741890507.555 [DataOverHttps](INFO): SBD MOMSN=24224251 2025-03-13T18:28:37.697Z,1741890517.697 [NAL9602](INFO): SBD MO Status=0, MOMSN=62642, MT Status=0, MTMSN=0 2025-03-13T18:28:37.697Z,1741890517.697 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:28:44.133Z,1741890524.133 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250313T162927/Express0052.lzma 2025-03-13T18:28:45.135Z,1741890525.135 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0052.lzma.bak 2025-03-13T18:28:45.135Z,1741890525.135 [DataOverHttps](INFO): SBD MOMSN=24224260 2025-03-13T18:28:46.614Z,1741890526.614 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:28:46.614Z,1741890526.614 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:28:46.614Z,1741890526.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:29:08.458Z,1741890548.458 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:33:47.385Z,1741890827.385 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:33:47.385Z,1741890827.385 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:33:47.385Z,1741890827.385 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:33:47.385Z,1741890827.385 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:33:47.788Z,1741890827.788 [Default:CheckIn:D] Stopped 2025-03-13T18:33:47.788Z,1741890827.788 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.308382 min 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn:E] Stopped 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn] Stopped 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn](INFO): Running loop #19 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn] Running Loop=19 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:33:48.202Z,1741890828.202 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:33:50.204Z,1741890830.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183349.00,A,3648.18048,N,12147.27314,W,0.194,103.17,130325,,,A*78 2025-03-13T18:33:50.206Z,1741890830.206 [NAL9602](INFO): GPS fix at 20250313T183349: (36.803008, -121.787886) 2025-03-13T18:33:50.240Z,1741890830.240 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:33:50.240Z,1741890830.240 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:34:01.433Z,1741890841.433 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0054.lzma 2025-03-13T18:34:03.439Z,1741890843.439 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0054.lzma.bak 2025-03-13T18:34:03.439Z,1741890843.439 [DataOverHttps](INFO): SBD MOMSN=24224279 2025-03-13T18:34:14.448Z,1741890854.448 [NAL9602](INFO): SBD MO Status=0, MOMSN=62643, MT Status=0, MTMSN=0 2025-03-13T18:34:14.448Z,1741890854.448 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:34:22.965Z,1741890862.965 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250313T162927/Express0055.lzma 2025-03-13T18:34:23.967Z,1741890863.967 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0055.lzma.bak 2025-03-13T18:34:23.967Z,1741890863.967 [DataOverHttps](INFO): SBD MOMSN=24224282 2025-03-13T18:34:25.402Z,1741890865.402 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:34:25.402Z,1741890865.402 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:34:25.402Z,1741890865.402 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:34:45.231Z,1741890885.231 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:35:57.544Z,1741890957.544 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-03-13T18:35:57.544Z,1741890957.544 [DropWeight] Hardware Fault, FailCount= 1 2025-03-13T18:35:57.545Z,1741890957.545 [DropWeight](ERROR): Hardware Fault 2025-03-13T18:35:57.562Z,1741890957.562 [CommandExec](FAULT): Scheduling is paused 2025-03-13T18:35:57.563Z,1741890957.563 [CBIT](INFO): Critical error at 20250313T183557 2025-03-13T18:35:57.566Z,1741890957.566 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-03-13T18:35:57.566Z,1741890957.566 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-03-13T18:35:57.982Z,1741890957.982 [CBIT](INFO): Critical error at 20250313T183557 2025-03-13T18:37:55.524Z,1741891075.524 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.537288 decibar, -0.533325 m 2025-03-13T18:39:26.021Z,1741891166.021 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:39:26.021Z,1741891166.021 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:39:26.021Z,1741891166.021 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:39:26.022Z,1741891166.022 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:39:26.438Z,1741891166.438 [Default:CheckIn:D] Stopped 2025-03-13T18:39:26.438Z,1741891166.438 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:39:26.830Z,1741891166.830 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.952539 min 2025-03-13T18:39:26.830Z,1741891166.830 [Default:CheckIn:E] Stopped 2025-03-13T18:39:26.830Z,1741891166.830 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn] Stopped 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn](INFO): Running loop #20 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn] Running Loop=20 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:39:26.831Z,1741891166.831 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:39:28.844Z,1741891168.844 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183928.00,A,3648.18334,N,12147.27939,W,0.564,189.50,130325,,,A*72 2025-03-13T18:39:28.846Z,1741891168.846 [NAL9602](INFO): GPS fix at 20250313T183928: (36.803056, -121.787990) 2025-03-13T18:39:28.857Z,1741891168.857 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:39:28.857Z,1741891168.857 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:39:36.017Z,1741891176.017 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20250313T162927/Courier0057.lzma 2025-03-13T18:39:37.019Z,1741891177.019 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0057.lzma.bak 2025-03-13T18:39:37.019Z,1741891177.019 [DataOverHttps](INFO): SBD MOMSN=24224299 2025-03-13T18:39:53.145Z,1741891193.145 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250313T162927/Express0058.lzma 2025-03-13T18:39:54.148Z,1741891194.148 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0058.lzma.bak 2025-03-13T18:39:54.149Z,1741891194.149 [DataOverHttps](INFO): SBD MOMSN=24224304 2025-03-13T18:39:55.521Z,1741891195.521 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:39:55.521Z,1741891195.521 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:39:55.521Z,1741891195.521 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:41:26.393Z,1741891286.393 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:41:57.533Z,1741891317.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:42:28.657Z,1741891348.657 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:42:59.781Z,1741891379.781 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:44:18.504Z,1741891458.504 [NAL9602](INFO): SBD MO Status=0, MOMSN=62644, MT Status=0, MTMSN=0 2025-03-13T18:44:18.505Z,1741891458.505 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:44:49.212Z,1741891489.212 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:44:56.088Z,1741891496.088 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:44:56.088Z,1741891496.088 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:44:56.088Z,1741891496.088 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:44:56.088Z,1741891496.088 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:44:56.498Z,1741891496.498 [Default:CheckIn:D] Stopped 2025-03-13T18:44:56.498Z,1741891496.498 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:44:56.915Z,1741891496.915 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.453532 min 2025-03-13T18:44:56.915Z,1741891496.915 [Default:CheckIn:E] Stopped 2025-03-13T18:44:56.915Z,1741891496.915 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:44:56.915Z,1741891496.915 [Default:CheckIn] Stopped 2025-03-13T18:44:56.916Z,1741891496.916 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:44:56.916Z,1741891496.916 [Default:CheckIn](INFO): Running loop #21 2025-03-13T18:44:56.916Z,1741891496.916 [Default:CheckIn] Running Loop=21 2025-03-13T18:44:56.916Z,1741891496.916 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:44:56.916Z,1741891496.916 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:44:58.908Z,1741891498.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184458.00,A,3648.17573,N,12147.27716,W,0.894,191.29,130325,,,A*73 2025-03-13T18:44:58.910Z,1741891498.910 [NAL9602](INFO): GPS fix at 20250313T184458: (36.802929, -121.787953) 2025-03-13T18:44:58.950Z,1741891498.950 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:44:58.950Z,1741891498.950 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:45:06.101Z,1741891506.101 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250313T162927/Courier0060.lzma 2025-03-13T18:45:07.103Z,1741891507.103 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0060.lzma.bak 2025-03-13T18:45:07.103Z,1741891507.103 [DataOverHttps](INFO): SBD MOMSN=24224339 2025-03-13T18:45:16.277Z,1741891516.277 [NAL9602](INFO): SBD MO Status=0, MOMSN=62645, MT Status=0, MTMSN=0 2025-03-13T18:45:16.277Z,1741891516.277 [NAL9602](INFO): No messages in MT queue 2025-03-13T18:45:23.201Z,1741891523.201 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250313T162927/Express0061.lzma 2025-03-13T18:45:24.203Z,1741891524.203 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0061.lzma.bak 2025-03-13T18:45:24.203Z,1741891524.203 [DataOverHttps](INFO): SBD MOMSN=24224342 2025-03-13T18:45:25.582Z,1741891525.582 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T18:45:25.582Z,1741891525.582 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T18:45:25.582Z,1741891525.582 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T18:45:46.979Z,1741891546.979 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T18:47:27.245Z,1741891647.245 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:47:58.370Z,1741891678.370 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:48:29.501Z,1741891709.501 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:49:00.654Z,1741891740.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:49:31.778Z,1741891771.778 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:49:34.790Z,1741891774.790 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.755493 2025-03-13T18:50:26.166Z,1741891826.166 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T18:50:26.166Z,1741891826.166 [Default:CheckIn:C.Wait] Stopped 2025-03-13T18:50:26.166Z,1741891826.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T18:50:26.166Z,1741891826.166 [Default:CheckIn:D] Running Loop=1 2025-03-13T18:50:26.560Z,1741891826.560 [Default:CheckIn:D] Stopped 2025-03-13T18:50:26.560Z,1741891826.560 [Default:CheckIn:E] Running Loop=1 2025-03-13T18:50:26.968Z,1741891826.968 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.954574 min 2025-03-13T18:50:26.968Z,1741891826.968 [Default:CheckIn:E] Stopped 2025-03-13T18:50:26.968Z,1741891826.968 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn] Stopped 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn](INFO): Running loop #22 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn] Running Loop=22 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T18:50:26.969Z,1741891826.969 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T18:50:33.021Z,1741891833.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:50:57.722Z,1741891857.722 [CBIT](INFO): Clearing failed state for component DropWeight 2025-03-13T18:50:57.722Z,1741891857.722 [DropWeight] No Fault, FailCount= 1 2025-03-13T18:51:04.145Z,1741891864.145 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:51:35.273Z,1741891895.273 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:52:06.397Z,1741891926.397 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:52:37.535Z,1741891957.535 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:53:08.657Z,1741891988.657 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:53:39.781Z,1741892019.781 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:54:10.905Z,1741892050.905 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:54:42.041Z,1741892082.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:55:13.165Z,1741892113.165 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:55:27.165Z,1741892127.165 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-03-13T18:50:26.0Z 2025-03-13T18:55:27.166Z,1741892127.166 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T18:55:27.166Z,1741892127.166 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-03-13T18:55:30.772Z,1741892130.772 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-13T18:55:44.293Z,1741892144.293 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:56:15.417Z,1741892175.417 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:56:46.542Z,1741892206.542 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:57:17.665Z,1741892237.665 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:57:48.789Z,1741892268.789 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:58:19.913Z,1741892299.913 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:58:51.041Z,1741892331.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:59:22.165Z,1741892362.165 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T18:59:53.309Z,1741892393.309 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:00:24.442Z,1741892424.442 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:00:50.066Z,1741892450.066 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002987 2025-03-13T19:01:18.717Z,1741892478.717 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250313T162927/Courier0063.lzma 2025-03-13T19:01:19.719Z,1741892479.719 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Courier0063.lzma.bak 2025-03-13T19:01:19.719Z,1741892479.719 [DataOverHttps](INFO): SBD MOMSN=24224494 2025-03-13T19:01:22.247Z,1741892482.247 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T19:02:23.037Z,1741892543.037 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:02:54.161Z,1741892574.161 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:03:25.293Z,1741892605.293 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:03:56.418Z,1741892636.418 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:04:20.514Z,1741892660.514 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.795776 2025-03-13T19:04:51.645Z,1741892691.645 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:05:07.887Z,1741892707.887 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-13T19:05:12.368Z,1741892712.368 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002042 CHAN A1 (24V): 0.000516 CHAN A2 (12V): -0.002215 CHAN A3 (5V): -0.001619 CHAN B0 (3.3V): -0.000177 CHAN B1 (3.15aV): -0.000225 CHAN B2 (3.15bV): -0.000257 CHAN B3 (GND): 0.000009 OPEN: -0.000295 Full Scale: +/- 1 mA 2025-03-13T19:05:22.777Z,1741892722.777 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:05:53.905Z,1741892753.905 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:06:25.029Z,1741892785.029 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:06:56.166Z,1741892816.166 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:07:27.297Z,1741892847.297 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:07:58.421Z,1741892878.421 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:08:29.545Z,1741892909.545 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:09:00.669Z,1741892940.669 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:09:31.809Z,1741892971.809 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:10:02.953Z,1741893002.953 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:10:34.077Z,1741893034.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:11:05.209Z,1741893065.209 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:11:08.078Z,1741893068.078 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T19:11:13.723Z,1741893073.723 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-03-13T19:11:36.333Z,1741893096.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:12:01.387Z,1741893121.387 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-03-13T19:12:07.465Z,1741893127.465 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:12:38.589Z,1741893158.589 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:13:09.715Z,1741893189.715 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:13:39.558Z,1741893219.558 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:13:40.837Z,1741893220.837 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:13:53.294Z,1741893233.294 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:14:06.625Z,1741893246.625 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:14:11.969Z,1741893251.969 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:14:20.374Z,1741893260.374 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:14:33.705Z,1741893273.705 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:14:43.101Z,1741893283.101 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:14:47.039Z,1741893287.039 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:15:00.774Z,1741893300.774 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:15:14.269Z,1741893314.269 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:15:14.912Z,1741893314.912 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:15:27.857Z,1741893327.857 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:15:41.197Z,1741893341.197 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:15:45.401Z,1741893345.401 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:15:54.120Z,1741893354.120 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:16:16.525Z,1741893376.525 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:16:47.654Z,1741893407.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:17:18.777Z,1741893438.777 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:17:49.905Z,1741893469.905 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:18:21.041Z,1741893501.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:18:52.165Z,1741893532.165 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:19:23.289Z,1741893563.289 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:19:54.441Z,1741893594.441 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:20:25.565Z,1741893625.565 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:20:56.693Z,1741893656.693 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:20:59.222Z,1741893659.222 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-03-13T19:20:59.222Z,1741893659.222 [DropWeight] Hardware Fault, FailCount= 1 2025-03-13T19:20:59.222Z,1741893659.222 [DropWeight](ERROR): Hardware Fault 2025-03-13T19:20:59.274Z,1741893659.274 [CBIT](INFO): Critical error at 20250313T192059 2025-03-13T19:20:59.276Z,1741893659.276 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-03-13T19:20:59.277Z,1741893659.277 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-03-13T19:20:59.671Z,1741893659.671 [CBIT](INFO): Critical error at 20250313T192059 2025-03-13T19:21:27.821Z,1741893687.821 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:21:58.945Z,1741893718.945 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-03-13T19:22:27.922Z,1741893747.922 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003465 2025-03-13T19:22:35.821Z,1741893755.821 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20250313T162927/Express0064.lzma 2025-03-13T19:22:36.823Z,1741893756.823 [DataOverHttps](INFO): Moved sent file to Logs/20250313T162927/Express0064.lzma.bak 2025-03-13T19:22:36.823Z,1741893756.823 [DataOverHttps](INFO): SBD MOMSN=24224660 2025-03-13T19:22:38.337Z,1741893758.337 [Default:CheckIn:Read_Iridium] Stopped 2025-03-13T19:22:38.338Z,1741893758.338 [Default:CheckIn:C.Wait] Running Loop=1 2025-03-13T19:22:38.338Z,1741893758.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-03-13T19:23:01.686Z,1741893781.686 [NAL9602](INFO): Not Powering down - fast GPS 2025-03-13T19:23:18.658Z,1741893798.658 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:23:32.397Z,1741893812.397 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:23:46.524Z,1741893826.524 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:24:00.261Z,1741893840.261 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:24:13.593Z,1741893853.593 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:24:27.329Z,1741893867.329 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:24:40.660Z,1741893880.660 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:24:54.801Z,1741893894.801 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:25:08.133Z,1741893908.133 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:25:18.295Z,1741893918.295 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-03-13T19:25:21.869Z,1741893921.869 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:25:35.201Z,1741893935.201 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-03-13T19:26:20.754Z,1741893980.754 [CommandExec](IMPORTANT): got command failComponent 2025-03-13T19:26:20.754Z,1741893980.754 [CommandExec](IMPORTANT): Failed components: 2025-03-13T19:26:20.754Z,1741893980.754 [CommandExec](IMPORTANT): DropWeight: Hardware Fault 2025-03-13T19:26:24.738Z,1741893984.738 [CommandExec](IMPORTANT): got command gfscan 2025-03-13T19:26:24.923Z,1741893984.923 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-13T19:26:29.442Z,1741893989.442 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002136 CHAN A1 (24V): 0.000475 CHAN A2 (12V): -0.001661 CHAN A3 (5V): -0.001619 CHAN B0 (3.3V): 0.000622 CHAN B1 (3.15aV): 0.000072 CHAN B2 (3.15bV): 0.000027 CHAN B3 (GND): -0.000035 OPEN: -0.000704 Full Scale: +/- 1 mA 2025-03-13T19:27:38.840Z,1741894058.840 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-03-13T19:27:38.840Z,1741894058.840 [Default:CheckIn:C.Wait] Stopped 2025-03-13T19:27:38.840Z,1741894058.840 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-03-13T19:27:38.841Z,1741894058.841 [Default:CheckIn:D] Running Loop=1 2025-03-13T19:27:39.248Z,1741894059.248 [Default:CheckIn:D] Stopped 2025-03-13T19:27:39.248Z,1741894059.248 [Default:CheckIn:E] Running Loop=1 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 196.166048 min 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn:E] Stopped 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn] Stopped 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn](INFO): Running loop #23 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn] Running Loop=23 2025-03-13T19:27:39.648Z,1741894059.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-13T19:27:39.649Z,1741894059.649 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-13T19:27:41.271Z,1741894061.271 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-03-13T19:27:41.271Z,1741894061.271 [NAL9602] Data Fault, FailCount= 1 2025-03-13T19:27:41.271Z,1741894061.271 [NAL9602](ERROR): Data Fault 2025-03-13T19:27:41.291Z,1741894061.291 [CBIT](ERROR): Data Fault in component: NAL9602 2025-03-13T19:27:41.656Z,1741894061.656 [NAL9602](INFO): Powering down 2025-03-13T19:27:42.488Z,1741894062.488 [CBIT](INFO): Clearing failed state for component NAL9602 2025-03-13T19:27:42.489Z,1741894062.489 [NAL9602] No Fault, FailCount= 1 2025-03-13T19:28:11.955Z,1741894091.955 [NAL9602](INFO): Powering up NAL9602 2025-03-13T19:28:22.871Z,1741894102.871 [NAL9602](INFO): NAL9602 initialized 2025-03-13T19:30:01.162Z,1741894201.162 [CommandExec](IMPORTANT): got command quit 2025-03-13T19:30:02.165Z,1741894202.165 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:02.165Z,1741894202.165 [CommandExec](INFO): Uninitializing the command executive. 2025-03-13T19:30:02.165Z,1741894202.165 [CommandExec](INFO): Uninitializing the command scheduler. 2025-03-13T19:30:02.166Z,1741894202.166 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.329Z,1741894202.329 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-03-13T19:30:02.329Z,1741894202.329 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-03-13T19:30:02.329Z,1741894202.329 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.330Z,1741894202.330 [NavChartDb](INFO): Join timeout helper Thread ID is 9094 2025-03-13T19:30:02.413Z,1741894202.413 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:02.414Z,1741894202.414 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.417Z,1741894202.417 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-03-13T19:30:02.417Z,1741894202.417 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.418Z,1741894202.418 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9095 2025-03-13T19:30:02.861Z,1741894202.861 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:02.862Z,1741894202.862 [WetLabsBB2FL](INFO): Powering down 2025-03-13T19:30:02.862Z,1741894202.862 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.881Z,1741894202.881 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-03-13T19:30:02.881Z,1741894202.881 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:02.881Z,1741894202.881 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9096 2025-03-13T19:30:03.161Z,1741894203.161 [CTD_Seabird](INFO): Powering down 2025-03-13T19:30:03.173Z,1741894203.173 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:03.173Z,1741894203.173 [CTD_Seabird](INFO): Powering down 2025-03-13T19:30:03.185Z,1741894203.185 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.193Z,1741894203.193 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-03-13T19:30:03.193Z,1741894203.193 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.193Z,1741894203.193 [Radio_Surface](INFO): Join timeout helper Thread ID is 9097 2025-03-13T19:30:03.257Z,1741894203.257 [Radio_Surface](INFO): Powering down 2025-03-13T19:30:03.258Z,1741894203.258 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:03.258Z,1741894203.258 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.277Z,1741894203.277 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-03-13T19:30:03.277Z,1741894203.277 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.277Z,1741894203.277 [Onboard](INFO): Join timeout helper Thread ID is 9098 2025-03-13T19:30:03.569Z,1741894203.569 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:03.569Z,1741894203.569 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.592Z,1741894203.592 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-03-13T19:30:03.592Z,1741894203.592 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.592Z,1741894203.592 [DataOverHttps](INFO): Join timeout helper Thread ID is 9099 2025-03-13T19:30:03.957Z,1741894203.957 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:03.957Z,1741894203.957 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.966Z,1741894203.966 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-03-13T19:30:03.966Z,1741894203.966 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:03.966Z,1741894203.966 [DAT](INFO): Join timeout helper Thread ID is 9100 2025-03-13T19:30:04.097Z,1741894204.097 [DAT](INFO): Powering down 2025-03-13T19:30:04.170Z,1741894204.170 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:04.170Z,1741894204.170 [DAT](INFO): Powering down 2025-03-13T19:30:04.171Z,1741894204.171 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.186Z,1741894204.186 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-03-13T19:30:04.186Z,1741894204.186 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.186Z,1741894204.186 [logger](INFO): Join timeout helper Thread ID is 9101 2025-03-13T19:30:04.209Z,1741894204.209 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:04.210Z,1741894204.210 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.226Z,1741894204.226 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-03-13T19:30:04.226Z,1741894204.226 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.226Z,1741894204.226 [CommandLine](INFO): Join timeout helper Thread ID is 9102 2025-03-13T19:30:04.245Z,1741894204.245 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:04.246Z,1741894204.246 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.266Z,1741894204.266 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-03-13T19:30:04.266Z,1741894204.266 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.266Z,1741894204.266 [CommandExec](INFO): Join timeout helper Thread ID is 9103 2025-03-13T19:30:04.267Z,1741894204.267 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-03-13T19:30:04.267Z,1741894204.267 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.268Z,1741894204.268 [controlThread](INFO): Join timeout helper Thread ID is 9104 2025-03-13T19:30:04.269Z,1741894204.269 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-13T19:30:04.270Z,1741894204.270 [controlThread](DEBUG): Uninitializing ControlThread 2025-03-13T19:30:04.270Z,1741894204.270 [AHRS_M2](INFO): Powering down 2025-03-13T19:30:04.342Z,1741894204.342 [NAL9602](INFO): Powering down 2025-03-13T19:30:04.343Z,1741894204.343 [Sonardyne_Nano](INFO): Powering down 2025-03-13T19:30:04.463Z,1741894204.463 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-03-13T19:30:04.463Z,1741894204.463 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-03-13T19:30:04.464Z,1741894204.464 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-03-13T19:30:04.464Z,1741894204.464 [MissionManager](INFO): Uninitializing Mission Default 2025-03-13T19:30:04.464Z,1741894204.464 [Default] Stopped 2025-03-13T19:30:04.465Z,1741894204.464 [Default](DEBUG): Aggregate::uninitialize Default 2025-03-13T19:30:04.465Z,1741894204.465 [Default:B.GoToSurface] Stopped 2025-03-13T19:30:04.465Z,1741894204.465 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-13T19:30:04.465Z,1741894204.465 [Default:CheckIn] Stopped 2025-03-13T19:30:04.465Z,1741894204.465 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-13T19:30:04.465Z,1741894204.465 [Default:CheckIn:Read_GPS] Stopped 2025-03-13T19:30:04.468Z,1741894204.468 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-03-13T19:30:04.468Z,1741894204.468 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-03-13T19:30:04.469Z,1741894204.469 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-03-13T19:30:04.469Z,1741894204.469 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-03-13T19:30:04.470Z,1741894204.470 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-03-13T19:30:04.470Z,1741894204.470 [BuoyancyServo](INFO): Powering down 2025-03-13T19:30:04.481Z,1741894204.481 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-03-13T19:30:04.481Z,1741894204.481 [ElevatorServo](INFO): Powering down 2025-03-13T19:30:04.482Z,1741894204.482 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-03-13T19:30:04.482Z,1741894204.482 [MassServo](INFO): Powering down 2025-03-13T19:30:04.483Z,1741894204.483 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-03-13T19:30:04.483Z,1741894204.483 [RudderServo](INFO): Powering down 2025-03-13T19:30:04.484Z,1741894204.484 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-03-13T19:30:04.484Z,1741894204.484 [ThrusterHE](INFO): Powering down 2025-03-13T19:30:04.485Z,1741894204.485 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-03-13T19:30:04.485Z,1741894204.485 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-03-13T19:30:04.486Z,1741894204.486 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-03-13T19:30:04.486Z,1741894204.486 [CBIT](DEBUG): Powering off loads. 2025-03-13T19:30:04.497Z,1741894204.497 [CBIT](DEBUG): Disabling WDT. 2025-03-13T19:30:04.509Z,1741894204.509 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-13T19:30:04.509Z,1741894204.509 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-13T19:30:04.510Z,1741894204.510 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.572Z,1741894204.572 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.575Z,1741894204.575 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.581Z,1741894204.581 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.588Z,1741894204.588 [DAT ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.662Z,1741894204.662 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.667Z,1741894204.667 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.691Z,1741894204.691 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-13T19:30:04.691Z,1741894204.691 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-13T19:30:04.712Z,1741894204.712 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-13T19:30:04.811Z,1741894204.811 [logger ThreadHandler](INFO): Thread cancelled.