2022-03-17T19:47:02.528Z,1647546422.528 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220316T151851/Express0091.lzma 2022-03-17T19:47:02.531Z,1647546422.531 [DataOverHttps](INFO): Received command: restart logs 2022-03-17T19:47:02.533Z,1647546422.533 [CommandExec](IMPORTANT): got command restart logs 2022-03-17T19:47:03.924Z,1647546423.924 [DataOverHttps](INFO): Moved sent file to Logs/20220316T151851/Express0091.lzma.bak 2022-03-17T19:47:03.929Z,1647546423.929 [DataOverHttps](INFO): SBD MOMSN=16577081 2022-03-17T19:47:15.091Z,1647546435.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=18277, MT Status=0, MTMSN=0 2022-03-17T19:47:15.091Z,1647546435.091 [NAL9602](INFO): No messages in MT queue 2022-03-17T19:47:22.912Z,1647546442.912 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220316T151851/Courier0093.lzma 2022-03-17T19:47:23.915Z,1647546443.915 [DataOverHttps](INFO): Moved sent file to Logs/20220316T151851/Courier0093.lzma.bak 2022-03-17T19:47:23.915Z,1647546443.915 [DataOverHttps](INFO): SBD MOMSN=16577088 2022-03-17T19:47:41.220Z,1647546461.220 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220316T151851/Express0094.lzma 2022-03-17T19:47:42.223Z,1647546462.223 [DataOverHttps](INFO): Moved sent file to Logs/20220316T151851/Express0094.lzma.bak 2022-03-17T19:47:42.223Z,1647546462.223 [DataOverHttps](INFO): SBD MOMSN=16577090 2022-03-17T19:47:43.403Z,1647546463.403 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T19:47:43.403Z,1647546463.403 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T19:47:43.403Z,1647546463.403 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T19:47:45.793Z,1647546465.793 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T19:48:49.849Z,1647546529.849 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2022-03-17T19:48:51.857Z,1647546531.857 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.931362 2022-03-17T19:49:06.697Z,1647546546.697 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003129 2022-03-17T19:52:43.968Z,1647546763.968 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T19:52:43.968Z,1647546763.968 [Default:CheckIn:C.Wait] Stopped 2022-03-17T19:52:43.968Z,1647546763.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T19:52:43.968Z,1647546763.968 [Default:CheckIn:D] Running Loop=1 2022-03-17T19:52:44.385Z,1647546764.385 [Default:CheckIn:D] Stopped 2022-03-17T19:52:44.385Z,1647546764.385 [Default:CheckIn:E] Running Loop=1 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.765851 min 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn:E] Stopped 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn] Stopped 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn](INFO): Running loop #6 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn] Running Loop=6 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T19:52:44.781Z,1647546764.781 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T19:52:46.791Z,1647546766.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195246.00,A,3648.67081,N,12149.54834,W,0.952,70.99,170322,,,D*48 2022-03-17T19:52:46.794Z,1647546766.794 [NAL9602](INFO): GPS fix at 20220317T195246: (36.811180, -121.825806) 2022-03-17T19:52:46.805Z,1647546766.805 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T19:52:46.805Z,1647546766.805 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T19:52:57.357Z,1647546777.357 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20220317T194702/Courier0003.lzma 2022-03-17T19:52:58.350Z,1647546778.350 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0003.lzma.bak 2022-03-17T19:52:58.350Z,1647546778.350 [DataOverHttps](INFO): SBD MOMSN=16577105 2022-03-17T19:53:11.835Z,1647546791.835 [NAL9602](INFO): SBD MO Status=1, MOMSN=18278, MT Status=0, MTMSN=0 2022-03-17T19:53:11.836Z,1647546791.836 [NAL9602](INFO): No messages in MT queue 2022-03-17T19:53:14.737Z,1647546794.737 [DataOverHttps](INFO): Sending 382 bytes from file Logs/20220317T194702/Express0004.lzma 2022-03-17T19:53:15.738Z,1647546795.738 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0004.lzma.bak 2022-03-17T19:53:15.738Z,1647546795.738 [DataOverHttps](INFO): SBD MOMSN=16577109 2022-03-17T19:53:17.134Z,1647546797.134 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T19:53:17.134Z,1647546797.134 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T19:53:17.134Z,1647546797.134 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T19:53:42.542Z,1647546822.542 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T19:58:17.714Z,1647547097.714 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T19:58:17.714Z,1647547097.714 [Default:CheckIn:C.Wait] Stopped 2022-03-17T19:58:17.714Z,1647547097.714 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T19:58:17.714Z,1647547097.714 [Default:CheckIn:D] Running Loop=1 2022-03-17T19:58:18.105Z,1647547098.105 [Default:CheckIn:D] Stopped 2022-03-17T19:58:18.105Z,1647547098.105 [Default:CheckIn:E] Running Loop=1 2022-03-17T19:58:18.508Z,1647547098.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.327865 min 2022-03-17T19:58:18.508Z,1647547098.508 [Default:CheckIn:E] Stopped 2022-03-17T19:58:18.508Z,1647547098.508 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T19:58:18.508Z,1647547098.508 [Default:CheckIn] Stopped 2022-03-17T19:58:18.508Z,1647547098.508 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T19:58:18.509Z,1647547098.509 [Default:CheckIn](INFO): Running loop #7 2022-03-17T19:58:18.509Z,1647547098.509 [Default:CheckIn] Running Loop=7 2022-03-17T19:58:18.509Z,1647547098.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T19:58:18.509Z,1647547098.509 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T19:58:20.517Z,1647547100.517 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195819.00,A,3648.45074,N,12148.87991,W,27.272,116.86,170322,,,A*45 2022-03-17T19:58:20.519Z,1647547100.519 [NAL9602](INFO): GPS fix at 20220317T195819: (36.807512, -121.814665) 2022-03-17T19:58:20.530Z,1647547100.530 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T19:58:20.530Z,1647547100.530 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T19:58:28.600Z,1647547108.600 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220317T194702/Courier0006.lzma 2022-03-17T19:58:29.602Z,1647547109.602 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0006.lzma.bak 2022-03-17T19:58:29.603Z,1647547109.603 [DataOverHttps](INFO): SBD MOMSN=16577137 2022-03-17T19:58:38.693Z,1647547118.693 [NAL9602](INFO): SBD MO Status=1, MOMSN=18279, MT Status=0, MTMSN=0 2022-03-17T19:58:38.693Z,1647547118.693 [NAL9602](INFO): No messages in MT queue 2022-03-17T19:58:45.856Z,1647547125.856 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220317T194702/Express0007.lzma 2022-03-17T19:58:46.858Z,1647547126.858 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0007.lzma.bak 2022-03-17T19:58:46.858Z,1647547126.858 [DataOverHttps](INFO): SBD MOMSN=16577142 2022-03-17T19:58:48.403Z,1647547128.403 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T19:58:48.404Z,1647547128.404 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T19:58:48.404Z,1647547128.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T19:59:09.402Z,1647547149.402 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:03:49.099Z,1647547429.099 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:03:49.099Z,1647547429.099 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:03:49.099Z,1647547429.099 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:03:49.099Z,1647547429.099 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:03:49.489Z,1647547429.489 [Default:CheckIn:D] Stopped 2022-03-17T20:03:49.489Z,1647547429.489 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.850932 min 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn:E] Stopped 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn] Stopped 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:03:49.877Z,1647547429.877 [Default:CheckIn](INFO): Running loop #8 2022-03-17T20:03:49.878Z,1647547429.878 [Default:CheckIn] Running Loop=8 2022-03-17T20:03:49.878Z,1647547429.878 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:03:49.878Z,1647547429.878 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:03:51.872Z,1647547431.872 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200351.00,A,3648.24083,N,12147.84926,W,0.797,90.61,170322,,,A*4F 2022-03-17T20:03:51.874Z,1647547431.874 [NAL9602](INFO): GPS fix at 20220317T200351: (36.804014, -121.797488) 2022-03-17T20:03:51.889Z,1647547431.889 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:03:51.889Z,1647547431.889 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:03:59.528Z,1647547439.528 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0009.lzma 2022-03-17T20:04:00.531Z,1647547440.531 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0009.lzma.bak 2022-03-17T20:04:00.531Z,1647547440.531 [DataOverHttps](INFO): SBD MOMSN=16577156 2022-03-17T20:04:20.429Z,1647547460.429 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220317T194702/Express0010.lzma 2022-03-17T20:04:21.430Z,1647547461.430 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0010.lzma.bak 2022-03-17T20:04:21.430Z,1647547461.430 [DataOverHttps](INFO): SBD MOMSN=16577162 2022-03-17T20:04:22.662Z,1647547462.662 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:04:22.662Z,1647547462.662 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:04:22.662Z,1647547462.662 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:04:44.059Z,1647547484.059 [NAL9602](INFO): SBD MO Status=1, MOMSN=18280, MT Status=0, MTMSN=0 2022-03-17T20:04:44.059Z,1647547484.059 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:05:14.770Z,1647547514.770 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:09:23.251Z,1647547763.251 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:09:23.251Z,1647547763.251 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:09:23.251Z,1647547763.251 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:09:23.252Z,1647547763.252 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:09:23.640Z,1647547763.640 [Default:CheckIn:D] Stopped 2022-03-17T20:09:23.640Z,1647547763.640 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.420101 min 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn:E] Stopped 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn] Stopped 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:09:24.057Z,1647547764.057 [Default:CheckIn](INFO): Running loop #9 2022-03-17T20:09:24.058Z,1647547764.058 [Default:CheckIn] Running Loop=9 2022-03-17T20:09:24.058Z,1647547764.058 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:09:24.058Z,1647547764.058 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:09:26.052Z,1647547766.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200925.00,A,3648.21475,N,12147.82020,W,0.816,192.19,170322,,,A*7D 2022-03-17T20:09:26.054Z,1647547766.054 [NAL9602](INFO): GPS fix at 20220317T200925: (36.803579, -121.797003) 2022-03-17T20:09:26.065Z,1647547766.065 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:09:26.065Z,1647547766.065 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:09:33.644Z,1647547773.644 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0012.lzma 2022-03-17T20:09:34.646Z,1647547774.646 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0012.lzma.bak 2022-03-17T20:09:34.646Z,1647547774.646 [DataOverHttps](INFO): SBD MOMSN=16577176 2022-03-17T20:09:51.124Z,1647547791.124 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220317T194702/Express0013.lzma 2022-03-17T20:09:52.126Z,1647547792.126 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0013.lzma.bak 2022-03-17T20:09:52.126Z,1647547792.126 [DataOverHttps](INFO): SBD MOMSN=16577180 2022-03-17T20:09:53.537Z,1647547793.537 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:09:53.537Z,1647547793.537 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:09:53.537Z,1647547793.537 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:09:53.927Z,1647547793.927 [NAL9602](INFO): SBD MO Status=1, MOMSN=18281, MT Status=0, MTMSN=0 2022-03-17T20:09:53.928Z,1647547793.928 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:10:24.693Z,1647547824.693 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:11:21.998Z,1647547881.998 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2022-03-17T20:11:21.000Z,1647547882.000 [BPC1](INFO): Received data from all battery sticks. 2022-03-17T20:12:55.332Z,1647547975.332 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-03-17T20:14:54.116Z,1647548094.116 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:14:54.117Z,1647548094.117 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:14:54.117Z,1647548094.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:14:54.117Z,1647548094.117 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:14:54.512Z,1647548094.512 [Default:CheckIn:D] Stopped 2022-03-17T20:14:54.512Z,1647548094.512 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:14:54.911Z,1647548094.911 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.934639 min 2022-03-17T20:14:54.911Z,1647548094.911 [Default:CheckIn:E] Stopped 2022-03-17T20:14:54.911Z,1647548094.911 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:14:54.911Z,1647548094.911 [Default:CheckIn] Stopped 2022-03-17T20:14:54.911Z,1647548094.911 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:14:54.912Z,1647548094.912 [Default:CheckIn](INFO): Running loop #10 2022-03-17T20:14:54.912Z,1647548094.912 [Default:CheckIn] Running Loop=10 2022-03-17T20:14:54.912Z,1647548094.912 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:14:54.912Z,1647548094.912 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:14:56.927Z,1647548096.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201456.00,A,3648.17798,N,12147.76086,W,1.341,170.46,170322,,,A*79 2022-03-17T20:14:56.938Z,1647548096.938 [NAL9602](INFO): GPS fix at 20220317T201456: (36.802966, -121.796014) 2022-03-17T20:14:56.949Z,1647548096.949 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:14:56.949Z,1647548096.949 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:15:05.112Z,1647548105.112 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20220317T194702/Courier0015.lzma 2022-03-17T20:15:06.114Z,1647548106.114 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0015.lzma.bak 2022-03-17T20:15:06.114Z,1647548106.114 [DataOverHttps](INFO): SBD MOMSN=16577197 2022-03-17T20:15:09.455Z,1647548109.455 [NAL9602](INFO): SBD MO Status=1, MOMSN=18282, MT Status=0, MTMSN=0 2022-03-17T20:15:09.456Z,1647548109.456 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:15:22.545Z,1647548122.545 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0016.lzma 2022-03-17T20:15:23.546Z,1647548123.546 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0016.lzma.bak 2022-03-17T20:15:23.546Z,1647548123.546 [DataOverHttps](INFO): SBD MOMSN=16577200 2022-03-17T20:15:24.813Z,1647548124.813 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:15:24.813Z,1647548124.813 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:15:24.813Z,1647548124.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:15:40.156Z,1647548140.156 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:20:25.441Z,1647548425.441 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:20:25.441Z,1647548425.441 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:20:25.441Z,1647548425.441 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:20:25.442Z,1647548425.442 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:20:25.791Z,1647548425.791 [Default:CheckIn:D] Stopped 2022-03-17T20:20:25.792Z,1647548425.792 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.455969 min 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn:E] Stopped 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn] Stopped 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn](INFO): Running loop #11 2022-03-17T20:20:26.205Z,1647548426.205 [Default:CheckIn] Running Loop=11 2022-03-17T20:20:26.206Z,1647548426.206 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:20:26.206Z,1647548426.206 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:20:28.204Z,1647548428.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202027.00,A,3648.43489,N,12147.32306,W,3.363,44.84,170322,,,D*4E 2022-03-17T20:20:28.206Z,1647548428.206 [NAL9602](INFO): GPS fix at 20220317T202027: (36.807248, -121.788718) 2022-03-17T20:20:28.217Z,1647548428.217 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:20:28.217Z,1647548428.217 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:20:35.472Z,1647548435.472 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0018.lzma 2022-03-17T20:20:36.474Z,1647548436.474 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0018.lzma.bak 2022-03-17T20:20:36.475Z,1647548436.475 [DataOverHttps](INFO): SBD MOMSN=16577212 2022-03-17T20:20:52.837Z,1647548452.837 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20220317T194702/Express0019.lzma 2022-03-17T20:20:53.838Z,1647548453.838 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0019.lzma.bak 2022-03-17T20:20:53.839Z,1647548453.839 [DataOverHttps](INFO): SBD MOMSN=16577215 2022-03-17T20:20:55.463Z,1647548455.463 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:20:55.463Z,1647548455.463 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:20:55.463Z,1647548455.463 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:21:17.205Z,1647548477.205 [NAL9602](INFO): SBD MO Status=1, MOMSN=18283, MT Status=0, MTMSN=0 2022-03-17T20:21:17.206Z,1647548477.206 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:21:47.906Z,1647548507.906 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:25:55.981Z,1647548755.981 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:25:55.981Z,1647548755.981 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:25:55.981Z,1647548755.981 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:25:55.981Z,1647548755.981 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:25:56.380Z,1647548756.380 [Default:CheckIn:D] Stopped 2022-03-17T20:25:56.380Z,1647548756.380 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:25:56.778Z,1647548756.778 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.965771 min 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn:E] Stopped 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn] Stopped 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn](INFO): Running loop #12 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn] Running Loop=12 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:25:56.779Z,1647548756.779 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:25:58.795Z,1647548758.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202558.00,A,3648.27668,N,12147.13975,W,3.577,195.26,170322,,,D*77 2022-03-17T20:25:58.807Z,1647548758.807 [NAL9602](INFO): GPS fix at 20220317T202558: (36.804611, -121.785663) 2022-03-17T20:25:58.817Z,1647548758.817 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:25:58.818Z,1647548758.818 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:26:06.304Z,1647548766.304 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0021.lzma 2022-03-17T20:26:07.306Z,1647548767.306 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0021.lzma.bak 2022-03-17T20:26:07.307Z,1647548767.307 [DataOverHttps](INFO): SBD MOMSN=16577234 2022-03-17T20:26:16.168Z,1647548776.168 [NAL9602](INFO): SBD MO Status=1, MOMSN=18284, MT Status=0, MTMSN=0 2022-03-17T20:26:16.168Z,1647548776.168 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:26:23.684Z,1647548783.684 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0022.lzma 2022-03-17T20:26:24.686Z,1647548784.686 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0022.lzma.bak 2022-03-17T20:26:24.687Z,1647548784.687 [DataOverHttps](INFO): SBD MOMSN=16577237 2022-03-17T20:26:26.272Z,1647548786.272 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:26:26.272Z,1647548786.272 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:26:26.272Z,1647548786.272 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:26:46.870Z,1647548806.870 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:31:26.861Z,1647549086.861 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:31:26.861Z,1647549086.861 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:31:26.861Z,1647549086.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:31:26.861Z,1647549086.861 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:31:27.284Z,1647549087.284 [Default:CheckIn:D] Stopped 2022-03-17T20:31:27.284Z,1647549087.284 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.480835 min 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn:E] Stopped 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn] Stopped 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn](INFO): Running loop #13 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn] Running Loop=13 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:31:27.662Z,1647549087.662 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:31:29.670Z,1647549089.670 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203128.00,A,3648.14968,N,12147.22161,W,0.058,211.82,170322,,,D*7F 2022-03-17T20:31:29.672Z,1647549089.672 [NAL9602](INFO): GPS fix at 20220317T203128: (36.802495, -121.787027) 2022-03-17T20:31:29.683Z,1647549089.683 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:31:29.683Z,1647549089.683 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:31:37.412Z,1647549097.412 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0024.lzma 2022-03-17T20:31:38.414Z,1647549098.414 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0024.lzma.bak 2022-03-17T20:31:38.415Z,1647549098.415 [DataOverHttps](INFO): SBD MOMSN=16577247 2022-03-17T20:31:44.615Z,1647549104.615 [NAL9602](INFO): SBD MO Status=1, MOMSN=18285, MT Status=0, MTMSN=0 2022-03-17T20:31:44.615Z,1647549104.615 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:31:54.668Z,1647549114.668 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0025.lzma 2022-03-17T20:31:55.670Z,1647549115.670 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0025.lzma.bak 2022-03-17T20:31:55.671Z,1647549115.671 [DataOverHttps](INFO): SBD MOMSN=16577250 2022-03-17T20:31:57.199Z,1647549117.199 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:31:57.199Z,1647549117.199 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:31:57.199Z,1647549117.199 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:32:15.322Z,1647549135.322 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:36:57.740Z,1647549417.740 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:36:57.741Z,1647549417.741 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:36:57.741Z,1647549417.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:36:57.741Z,1647549417.741 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:36:58.155Z,1647549418.155 [Default:CheckIn:D] Stopped 2022-03-17T20:36:58.155Z,1647549418.155 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:36:58.546Z,1647549418.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.995353 min 2022-03-17T20:36:58.546Z,1647549418.546 [Default:CheckIn:E] Stopped 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn] Stopped 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn](INFO): Running loop #14 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn] Running Loop=14 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:36:58.547Z,1647549418.547 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:37:00.558Z,1647549420.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203659.00,A,3648.14244,N,12147.22922,W,0.000,231.89,170322,,,D*70 2022-03-17T20:37:00.560Z,1647549420.560 [NAL9602](INFO): GPS fix at 20220317T203659: (36.802374, -121.787154) 2022-03-17T20:37:00.570Z,1647549420.570 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:37:00.571Z,1647549420.571 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:37:08.160Z,1647549428.160 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0027.lzma 2022-03-17T20:37:09.163Z,1647549429.163 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0027.lzma.bak 2022-03-17T20:37:09.163Z,1647549429.163 [DataOverHttps](INFO): SBD MOMSN=16577275 2022-03-17T20:37:25.532Z,1647549445.532 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0028.lzma 2022-03-17T20:37:26.535Z,1647549446.535 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0028.lzma.bak 2022-03-17T20:37:26.535Z,1647549446.535 [DataOverHttps](INFO): SBD MOMSN=16577278 2022-03-17T20:37:28.051Z,1647549448.051 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:37:28.051Z,1647549448.051 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:37:28.052Z,1647549448.052 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:37:29.243Z,1647549449.243 [NAL9602](INFO): SBD MO Status=2, MOMSN=18286, MT Status=2, MTMSN=0 2022-03-17T20:37:29.244Z,1647549449.244 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T20:38:21.375Z,1647549501.375 [NAL9602](INFO): SBD MO Status=2, MOMSN=18286, MT Status=2, MTMSN=0 2022-03-17T20:38:21.375Z,1647549501.375 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T20:38:58.938Z,1647549538.938 [NAL9602](INFO): SBD MO Status=1, MOMSN=18286, MT Status=0, MTMSN=0 2022-03-17T20:38:58.938Z,1647549538.938 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:39:29.639Z,1647549569.639 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:42:28.624Z,1647549748.624 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:42:28.624Z,1647549748.624 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:42:28.624Z,1647549748.624 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:42:28.624Z,1647549748.624 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:42:29.043Z,1647549749.043 [Default:CheckIn:D] Stopped 2022-03-17T20:42:29.043Z,1647549749.043 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:42:29.452Z,1647549749.452 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.510156 min 2022-03-17T20:42:29.452Z,1647549749.452 [Default:CheckIn:E] Stopped 2022-03-17T20:42:29.452Z,1647549749.452 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:42:29.452Z,1647549749.452 [Default:CheckIn] Stopped 2022-03-17T20:42:29.453Z,1647549749.453 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:42:29.453Z,1647549749.453 [Default:CheckIn](INFO): Running loop #15 2022-03-17T20:42:29.453Z,1647549749.453 [Default:CheckIn] Running Loop=15 2022-03-17T20:42:29.453Z,1647549749.453 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:42:29.453Z,1647549749.453 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:42:31.443Z,1647549751.443 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204230.00,A,3648.14233,N,12147.23027,W,0.019,231.89,170322,,,D*79 2022-03-17T20:42:31.446Z,1647549751.446 [NAL9602](INFO): GPS fix at 20220317T204230: (36.802372, -121.787171) 2022-03-17T20:42:31.533Z,1647549751.533 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:42:31.533Z,1647549751.533 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:42:39.062Z,1647549759.062 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0030.lzma 2022-03-17T20:42:40.059Z,1647549760.059 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0030.lzma.bak 2022-03-17T20:42:40.059Z,1647549760.059 [DataOverHttps](INFO): SBD MOMSN=16577288 2022-03-17T20:42:53.659Z,1647549773.659 [NAL9602](INFO): SBD MO Status=1, MOMSN=18287, MT Status=0, MTMSN=0 2022-03-17T20:42:53.659Z,1647549773.659 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:42:56.428Z,1647549776.428 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0031.lzma 2022-03-17T20:42:57.430Z,1647549777.430 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0031.lzma.bak 2022-03-17T20:42:57.430Z,1647549777.430 [DataOverHttps](INFO): SBD MOMSN=16577291 2022-03-17T20:42:58.932Z,1647549778.932 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:42:58.932Z,1647549778.932 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:42:58.933Z,1647549778.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:43:24.359Z,1647549804.359 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:47:59.497Z,1647550079.497 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:47:59.497Z,1647550079.497 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:47:59.497Z,1647550079.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:47:59.497Z,1647550079.497 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:47:59.904Z,1647550079.904 [Default:CheckIn:D] Stopped 2022-03-17T20:47:59.904Z,1647550079.904 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.024512 min 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn:E] Stopped 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn] Stopped 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn](INFO): Running loop #16 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn] Running Loop=16 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:48:00.305Z,1647550080.305 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:48:02.316Z,1647550082.316 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204801.00,A,3648.14214,N,12147.23079,W,0.000,231.89,170322,,,D*77 2022-03-17T20:48:02.318Z,1647550082.318 [NAL9602](INFO): GPS fix at 20220317T204801: (36.802369, -121.787180) 2022-03-17T20:48:02.349Z,1647550082.349 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:48:02.350Z,1647550082.350 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:48:10.284Z,1647550090.284 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0033.lzma 2022-03-17T20:48:11.286Z,1647550091.286 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0033.lzma.bak 2022-03-17T20:48:11.287Z,1647550091.287 [DataOverHttps](INFO): SBD MOMSN=16577309 2022-03-17T20:48:27.664Z,1647550107.664 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0034.lzma 2022-03-17T20:48:28.666Z,1647550108.666 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0034.lzma.bak 2022-03-17T20:48:28.667Z,1647550108.667 [DataOverHttps](INFO): SBD MOMSN=16577312 2022-03-17T20:48:29.787Z,1647550109.787 [NAL9602](INFO): SBD MO Status=1, MOMSN=18288, MT Status=0, MTMSN=0 2022-03-17T20:48:29.787Z,1647550109.787 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:48:30.198Z,1647550110.198 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:48:30.198Z,1647550110.198 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:48:30.198Z,1647550110.198 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:49:00.493Z,1647550140.493 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:51:34.054Z,1647550294.054 [CBIT](IMPORTANT): Beginning ground fault scan 2022-03-17T20:51:44.944Z,1647550304.944 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.009965 CHAN A1 (24V): 0.000351 CHAN A2 (12V): -0.007514 CHAN A3 (5V): -0.002846 CHAN B0 (3.3V): 0.000057 CHAN B1 (3.15aV): 0.000422 CHAN B2 (3.15bV): -0.000282 CHAN B3 (GND): 0.002289 OPEN: 0.005452 Full Scale: +/- 1 mA 2022-03-17T20:53:30.776Z,1647550410.776 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:53:30.776Z,1647550410.776 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:53:30.777Z,1647550410.777 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:53:30.777Z,1647550410.777 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:53:31.205Z,1647550411.205 [Default:CheckIn:D] Stopped 2022-03-17T20:53:31.205Z,1647550411.205 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:53:31.602Z,1647550411.602 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.546200 min 2022-03-17T20:53:31.602Z,1647550411.602 [Default:CheckIn:E] Stopped 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn] Stopped 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn](INFO): Running loop #17 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn] Running Loop=17 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:53:31.603Z,1647550411.603 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:53:33.600Z,1647550413.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205332.00,A,3648.14095,N,12147.23021,W,0.019,231.89,170322,,,D*73 2022-03-17T20:53:33.602Z,1647550413.602 [NAL9602](INFO): GPS fix at 20220317T205332: (36.802349, -121.787170) 2022-03-17T20:53:33.613Z,1647550413.613 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:53:33.613Z,1647550413.613 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:53:41.192Z,1647550421.192 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0036.lzma 2022-03-17T20:53:42.194Z,1647550422.194 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0036.lzma.bak 2022-03-17T20:53:42.195Z,1647550422.195 [DataOverHttps](INFO): SBD MOMSN=16577324 2022-03-17T20:53:53.821Z,1647550433.821 [NAL9602](INFO): SBD MO Status=2, MOMSN=18289, MT Status=2, MTMSN=0 2022-03-17T20:53:53.821Z,1647550433.821 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T20:53:58.593Z,1647550438.593 [DataOverHttps](INFO): Sending 331 bytes from file Logs/20220317T194702/Express0037.lzma 2022-03-17T20:53:59.595Z,1647550439.595 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0037.lzma.bak 2022-03-17T20:53:59.595Z,1647550439.595 [DataOverHttps](INFO): SBD MOMSN=16577327 2022-03-17T20:54:01.149Z,1647550441.149 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:54:01.149Z,1647550441.149 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:54:01.149Z,1647550441.149 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:54:04.703Z,1647550444.703 [NAL9602](INFO): SBD MO Status=1, MOMSN=18289, MT Status=0, MTMSN=0 2022-03-17T20:54:04.703Z,1647550444.703 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:54:35.410Z,1647550475.410 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T20:59:01.659Z,1647550741.659 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T20:59:01.659Z,1647550741.659 [Default:CheckIn:C.Wait] Stopped 2022-03-17T20:59:01.659Z,1647550741.659 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T20:59:01.659Z,1647550741.659 [Default:CheckIn:D] Running Loop=1 2022-03-17T20:59:02.072Z,1647550742.072 [Default:CheckIn:D] Stopped 2022-03-17T20:59:02.072Z,1647550742.072 [Default:CheckIn:E] Running Loop=1 2022-03-17T20:59:02.481Z,1647550742.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.060645 min 2022-03-17T20:59:02.481Z,1647550742.481 [Default:CheckIn:E] Stopped 2022-03-17T20:59:02.481Z,1647550742.481 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T20:59:02.481Z,1647550742.481 [Default:CheckIn] Stopped 2022-03-17T20:59:02.481Z,1647550742.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T20:59:02.482Z,1647550742.482 [Default:CheckIn](INFO): Running loop #18 2022-03-17T20:59:02.482Z,1647550742.482 [Default:CheckIn] Running Loop=18 2022-03-17T20:59:02.482Z,1647550742.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T20:59:02.482Z,1647550742.482 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T20:59:04.480Z,1647550744.480 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205903.00,A,3648.16906,N,12147.27893,W,0.311,229.16,170322,,,D*7B 2022-03-17T20:59:04.482Z,1647550744.482 [NAL9602](INFO): GPS fix at 20220317T205903: (36.802818, -121.787982) 2022-03-17T20:59:04.517Z,1647550744.517 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T20:59:04.518Z,1647550744.518 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T20:59:12.456Z,1647550752.456 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0039.lzma 2022-03-17T20:59:13.458Z,1647550753.458 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0039.lzma.bak 2022-03-17T20:59:13.459Z,1647550753.459 [DataOverHttps](INFO): SBD MOMSN=16577347 2022-03-17T20:59:25.100Z,1647550765.100 [NAL9602](INFO): SBD MO Status=1, MOMSN=18290, MT Status=0, MTMSN=0 2022-03-17T20:59:25.100Z,1647550765.100 [NAL9602](INFO): No messages in MT queue 2022-03-17T20:59:29.820Z,1647550769.820 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220317T194702/Express0040.lzma 2022-03-17T20:59:30.822Z,1647550770.822 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0040.lzma.bak 2022-03-17T20:59:30.823Z,1647550770.823 [DataOverHttps](INFO): SBD MOMSN=16577350 2022-03-17T20:59:32.455Z,1647550772.455 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T20:59:32.455Z,1647550772.455 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T20:59:32.455Z,1647550772.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T20:59:55.790Z,1647550795.790 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:04:32.943Z,1647551072.943 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:04:32.943Z,1647551072.943 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:04:32.944Z,1647551072.944 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:04:32.944Z,1647551072.944 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:04:33.392Z,1647551073.392 [Default:CheckIn:D] Stopped 2022-03-17T21:04:33.392Z,1647551073.392 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:04:33.753Z,1647551073.753 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.582642 min 2022-03-17T21:04:33.753Z,1647551073.753 [Default:CheckIn:E] Stopped 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn] Stopped 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn](INFO): Running loop #19 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn] Running Loop=19 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:04:33.754Z,1647551073.754 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:04:35.763Z,1647551075.763 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210435.00,A,3648.17103,N,12147.27836,W,0.214,229.16,170322,,,D*70 2022-03-17T21:04:35.767Z,1647551075.767 [NAL9602](INFO): GPS fix at 20220317T210435: (36.802850, -121.787973) 2022-03-17T21:04:35.798Z,1647551075.798 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:04:35.798Z,1647551075.798 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:04:43.480Z,1647551083.480 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0042.lzma 2022-03-17T21:04:44.482Z,1647551084.482 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0042.lzma.bak 2022-03-17T21:04:44.483Z,1647551084.483 [DataOverHttps](INFO): SBD MOMSN=16577362 2022-03-17T21:05:00.740Z,1647551100.740 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0043.lzma 2022-03-17T21:05:01.742Z,1647551101.742 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0043.lzma.bak 2022-03-17T21:05:01.743Z,1647551101.743 [DataOverHttps](INFO): SBD MOMSN=16577365 2022-03-17T21:05:03.266Z,1647551103.266 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:05:03.266Z,1647551103.266 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:05:03.266Z,1647551103.266 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:05:54.946Z,1647551154.946 [NAL9602](INFO): SBD MO Status=1, MOMSN=18291, MT Status=0, MTMSN=0 2022-03-17T21:05:54.946Z,1647551154.946 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:06:25.650Z,1647551185.650 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:10:03.836Z,1647551403.836 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:10:03.836Z,1647551403.836 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:10:03.836Z,1647551403.836 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:10:03.841Z,1647551403.841 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:10:04.227Z,1647551404.227 [Default:CheckIn:D] Stopped 2022-03-17T21:10:04.228Z,1647551404.228 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:10:04.628Z,1647551404.628 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.096566 min 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn:E] Stopped 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn] Stopped 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn](INFO): Running loop #20 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn] Running Loop=20 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:10:04.629Z,1647551404.629 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:10:06.642Z,1647551406.642 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211005.00,A,3648.17529,N,12147.27678,W,0.136,229.16,170322,,,A*78 2022-03-17T21:10:06.644Z,1647551406.644 [NAL9602](INFO): GPS fix at 20220317T211005: (36.802921, -121.787946) 2022-03-17T21:10:06.655Z,1647551406.655 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:10:06.655Z,1647551406.655 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:10:15.026Z,1647551415.026 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0045.lzma 2022-03-17T21:10:16.026Z,1647551416.026 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0045.lzma.bak 2022-03-17T21:10:16.027Z,1647551416.027 [DataOverHttps](INFO): SBD MOMSN=16577384 2022-03-17T21:10:32.412Z,1647551432.412 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0046.lzma 2022-03-17T21:10:33.414Z,1647551433.414 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0046.lzma.bak 2022-03-17T21:10:33.415Z,1647551433.415 [DataOverHttps](INFO): SBD MOMSN=16577387 2022-03-17T21:10:34.111Z,1647551434.111 [NAL9602](INFO): SBD MO Status=1, MOMSN=18292, MT Status=0, MTMSN=0 2022-03-17T21:10:34.111Z,1647551434.111 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:10:34.937Z,1647551434.937 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:10:34.937Z,1647551434.937 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:10:34.937Z,1647551434.937 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:11:04.814Z,1647551464.814 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:15:35.541Z,1647551735.541 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:15:35.541Z,1647551735.541 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:15:35.541Z,1647551735.541 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:15:35.542Z,1647551735.542 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:15:35.933Z,1647551735.933 [Default:CheckIn:D] Stopped 2022-03-17T21:15:35.933Z,1647551735.933 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.624992 min 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn:E] Stopped 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn] Stopped 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn](INFO): Running loop #21 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn] Running Loop=21 2022-03-17T21:15:36.350Z,1647551736.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:15:36.351Z,1647551736.351 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:15:38.364Z,1647551738.364 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211537.00,A,3648.17594,N,12147.27708,W,0.292,229.16,170322,,,A*71 2022-03-17T21:15:38.366Z,1647551738.366 [NAL9602](INFO): GPS fix at 20220317T211537: (36.802932, -121.787951) 2022-03-17T21:15:38.393Z,1647551738.393 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:15:38.393Z,1647551738.393 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:15:46.384Z,1647551746.384 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0048.lzma 2022-03-17T21:15:47.386Z,1647551747.386 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0048.lzma.bak 2022-03-17T21:15:47.387Z,1647551747.387 [DataOverHttps](INFO): SBD MOMSN=16577397 2022-03-17T21:15:50.867Z,1647551750.867 [NAL9602](INFO): SBD MO Status=1, MOMSN=18293, MT Status=0, MTMSN=0 2022-03-17T21:15:50.867Z,1647551750.867 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:16:04.276Z,1647551764.276 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0049.lzma 2022-03-17T21:16:05.278Z,1647551765.278 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0049.lzma.bak 2022-03-17T21:16:05.279Z,1647551765.279 [DataOverHttps](INFO): SBD MOMSN=16577400 2022-03-17T21:16:06.649Z,1647551766.649 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:16:06.649Z,1647551766.649 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:16:06.649Z,1647551766.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:16:21.566Z,1647551781.566 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:18:49.435Z,1647551929.435 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-03-17T21:18:49.437Z,1647551929.437 [BPC1](INFO): Received data from all battery sticks. 2022-03-17T21:21:07.228Z,1647552067.228 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:21:07.228Z,1647552067.228 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:21:07.228Z,1647552067.228 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:21:07.228Z,1647552067.228 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:21:07.617Z,1647552067.617 [Default:CheckIn:D] Stopped 2022-03-17T21:21:07.617Z,1647552067.617 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:21:08.034Z,1647552068.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.153060 min 2022-03-17T21:21:08.034Z,1647552068.034 [Default:CheckIn:E] Stopped 2022-03-17T21:21:08.034Z,1647552068.034 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:21:08.034Z,1647552068.034 [Default:CheckIn] Stopped 2022-03-17T21:21:08.034Z,1647552068.034 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:21:08.035Z,1647552068.035 [Default:CheckIn](INFO): Running loop #22 2022-03-17T21:21:08.035Z,1647552068.035 [Default:CheckIn] Running Loop=22 2022-03-17T21:21:08.035Z,1647552068.035 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:21:08.035Z,1647552068.035 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:21:10.028Z,1647552070.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212109.00,A,3648.17672,N,12147.27930,W,0.253,0.00,170322,,,A*76 2022-03-17T21:21:10.030Z,1647552070.030 [NAL9602](INFO): GPS fix at 20220317T212109: (36.802945, -121.787988) 2022-03-17T21:21:10.041Z,1647552070.041 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:21:10.041Z,1647552070.041 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:21:17.760Z,1647552077.760 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220317T194702/Courier0051.lzma 2022-03-17T21:21:18.762Z,1647552078.762 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0051.lzma.bak 2022-03-17T21:21:18.763Z,1647552078.763 [DataOverHttps](INFO): SBD MOMSN=16577418 2022-03-17T21:21:35.372Z,1647552095.372 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0052.lzma 2022-03-17T21:21:36.375Z,1647552096.375 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0052.lzma.bak 2022-03-17T21:21:36.375Z,1647552096.375 [DataOverHttps](INFO): SBD MOMSN=16577421 2022-03-17T21:21:37.919Z,1647552097.919 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:21:37.919Z,1647552097.919 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:21:37.919Z,1647552097.919 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:24:46.573Z,1647552286.573 [NAL9602](INFO): SBD MO Status=1, MOMSN=18294, MT Status=0, MTMSN=0 2022-03-17T21:24:46.573Z,1647552286.573 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:25:17.274Z,1647552317.274 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:26:38.487Z,1647552398.487 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:26:38.487Z,1647552398.487 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:26:38.488Z,1647552398.488 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:26:38.488Z,1647552398.488 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:26:38.892Z,1647552398.892 [Default:CheckIn:D] Stopped 2022-03-17T21:26:38.892Z,1647552398.892 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:26:39.316Z,1647552399.316 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.674308 min 2022-03-17T21:26:39.316Z,1647552399.316 [Default:CheckIn:E] Stopped 2022-03-17T21:26:39.316Z,1647552399.316 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn] Stopped 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn](INFO): Running loop #23 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn] Running Loop=23 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:26:39.317Z,1647552399.317 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:26:41.304Z,1647552401.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212640.00,A,3648.17654,N,12147.27696,W,0.117,9.46,170322,,,A*73 2022-03-17T21:26:41.306Z,1647552401.306 [NAL9602](INFO): GPS fix at 20220317T212640: (36.802942, -121.787949) 2022-03-17T21:26:41.353Z,1647552401.353 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:26:41.353Z,1647552401.353 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:26:49.312Z,1647552409.312 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0054.lzma 2022-03-17T21:26:50.315Z,1647552410.315 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0054.lzma.bak 2022-03-17T21:26:50.315Z,1647552410.315 [DataOverHttps](INFO): SBD MOMSN=16577432 2022-03-17T21:26:56.260Z,1647552416.260 [NAL9602](INFO): SBD MO Status=1, MOMSN=18295, MT Status=0, MTMSN=0 2022-03-17T21:26:56.260Z,1647552416.260 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:27:06.653Z,1647552426.653 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0055.lzma 2022-03-17T21:27:07.655Z,1647552427.655 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0055.lzma.bak 2022-03-17T21:27:07.655Z,1647552427.655 [DataOverHttps](INFO): SBD MOMSN=16577438 2022-03-17T21:27:09.219Z,1647552429.219 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:27:09.219Z,1647552429.219 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:27:09.219Z,1647552429.219 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:27:26.958Z,1647552446.958 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:32:09.768Z,1647552729.768 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:32:09.768Z,1647552729.768 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:32:09.768Z,1647552729.768 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:32:09.768Z,1647552729.768 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:32:10.172Z,1647552730.172 [Default:CheckIn:D] Stopped 2022-03-17T21:32:10.172Z,1647552730.172 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:32:10.573Z,1647552730.573 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.195638 min 2022-03-17T21:32:10.573Z,1647552730.573 [Default:CheckIn:E] Stopped 2022-03-17T21:32:10.573Z,1647552730.573 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:32:10.573Z,1647552730.573 [Default:CheckIn] Stopped 2022-03-17T21:32:10.573Z,1647552730.573 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:32:10.574Z,1647552730.574 [Default:CheckIn](INFO): Running loop #24 2022-03-17T21:32:10.574Z,1647552730.574 [Default:CheckIn] Running Loop=24 2022-03-17T21:32:10.574Z,1647552730.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:32:10.574Z,1647552730.574 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:32:12.587Z,1647552732.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213211.00,A,3648.17450,N,12147.28073,W,0.117,352.55,170322,,,A*79 2022-03-17T21:32:12.590Z,1647552732.590 [NAL9602](INFO): GPS fix at 20220317T213211: (36.802908, -121.788012) 2022-03-17T21:32:12.618Z,1647552732.618 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:32:12.618Z,1647552732.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:32:20.736Z,1647552740.736 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220317T194702/Courier0057.lzma 2022-03-17T21:32:21.739Z,1647552741.739 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0057.lzma.bak 2022-03-17T21:32:21.739Z,1647552741.739 [DataOverHttps](INFO): SBD MOMSN=16577458 2022-03-17T21:32:37.960Z,1647552757.960 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220317T194702/Express0058.lzma 2022-03-17T21:32:38.962Z,1647552758.962 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0058.lzma.bak 2022-03-17T21:32:38.963Z,1647552758.963 [DataOverHttps](INFO): SBD MOMSN=16577461 2022-03-17T21:32:40.479Z,1647552760.479 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:32:40.480Z,1647552760.480 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:32:40.480Z,1647552760.480 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:33:51.571Z,1647552831.571 [NAL9602](INFO): SBD MO Status=1, MOMSN=18296, MT Status=0, MTMSN=0 2022-03-17T21:33:51.571Z,1647552831.571 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:34:22.278Z,1647552862.278 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:37:41.109Z,1647553061.109 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:37:41.109Z,1647553061.109 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:37:41.109Z,1647553061.109 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:37:41.109Z,1647553061.109 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:37:41.484Z,1647553061.484 [Default:CheckIn:D] Stopped 2022-03-17T21:37:41.484Z,1647553061.484 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.717505 min 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn:E] Stopped 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn] Stopped 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn](INFO): Running loop #25 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn] Running Loop=25 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:37:41.886Z,1647553061.886 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:37:43.879Z,1647553063.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213743.00,A,3648.17363,N,12147.27826,W,0.194,344.59,170322,,,A*7B 2022-03-17T21:37:43.882Z,1647553063.882 [NAL9602](INFO): GPS fix at 20220317T213743: (36.802894, -121.787971) 2022-03-17T21:37:43.893Z,1647553063.893 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:37:43.893Z,1647553063.893 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:37:51.540Z,1647553071.540 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0060.lzma 2022-03-17T21:37:52.542Z,1647553072.542 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0060.lzma.bak 2022-03-17T21:37:52.543Z,1647553072.543 [DataOverHttps](INFO): SBD MOMSN=16577474 2022-03-17T21:38:08.985Z,1647553088.985 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220317T194702/Express0061.lzma 2022-03-17T21:38:09.993Z,1647553089.993 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0061.lzma.bak 2022-03-17T21:38:09.993Z,1647553089.993 [DataOverHttps](INFO): SBD MOMSN=16577477 2022-03-17T21:38:11.401Z,1647553091.401 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:38:11.401Z,1647553091.401 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:38:11.401Z,1647553091.401 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:42:46.472Z,1647553366.472 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T21:43:11.940Z,1647553391.940 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:43:11.940Z,1647553391.940 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:43:11.940Z,1647553391.940 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:43:11.941Z,1647553391.941 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:43:12.351Z,1647553392.351 [Default:CheckIn:D] Stopped 2022-03-17T21:43:12.351Z,1647553392.351 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:43:12.742Z,1647553392.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.231966 min 2022-03-17T21:43:12.742Z,1647553392.742 [Default:CheckIn:E] Stopped 2022-03-17T21:43:12.742Z,1647553392.742 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn] Stopped 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn](INFO): Running loop #26 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn] Running Loop=26 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:43:12.743Z,1647553392.743 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:43:14.755Z,1647553394.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214314.00,A,3648.17095,N,12147.27967,W,0.019,344.59,170322,,,A*70 2022-03-17T21:43:14.758Z,1647553394.758 [NAL9602](INFO): GPS fix at 20220317T214314: (36.802849, -121.787994) 2022-03-17T21:43:14.768Z,1647553394.768 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:43:14.768Z,1647553394.768 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:43:22.736Z,1647553402.736 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0063.lzma 2022-03-17T21:43:23.738Z,1647553403.738 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0063.lzma.bak 2022-03-17T21:43:23.739Z,1647553403.739 [DataOverHttps](INFO): SBD MOMSN=16577492 2022-03-17T21:43:40.308Z,1647553420.308 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20220317T194702/Express0064.lzma 2022-03-17T21:43:41.311Z,1647553421.311 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0064.lzma.bak 2022-03-17T21:43:41.311Z,1647553421.311 [DataOverHttps](INFO): SBD MOMSN=16577495 2022-03-17T21:43:42.649Z,1647553422.649 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:43:42.649Z,1647553422.649 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:43:42.649Z,1647553422.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:43:47.478Z,1647553427.478 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:48:43.247Z,1647553723.247 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:48:43.247Z,1647553723.247 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:48:43.247Z,1647553723.247 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:48:43.247Z,1647553723.247 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:48:43.628Z,1647553723.628 [Default:CheckIn:D] Stopped 2022-03-17T21:48:43.628Z,1647553723.628 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.753239 min 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn:E] Stopped 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn] Stopped 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn](INFO): Running loop #27 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn] Running Loop=27 2022-03-17T21:48:44.033Z,1647553724.033 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:48:44.034Z,1647553724.034 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:48:46.040Z,1647553726.040 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214845.00,A,3648.17417,N,12147.27960,W,0.039,344.59,170322,,,A*74 2022-03-17T21:48:46.043Z,1647553726.043 [NAL9602](INFO): GPS fix at 20220317T214845: (36.802903, -121.787993) 2022-03-17T21:48:46.054Z,1647553726.054 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:48:46.054Z,1647553726.054 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:48:53.752Z,1647553733.752 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0066.lzma 2022-03-17T21:48:54.754Z,1647553734.754 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0066.lzma.bak 2022-03-17T21:48:54.754Z,1647553734.754 [DataOverHttps](INFO): SBD MOMSN=16577510 2022-03-17T21:49:11.042Z,1647553751.042 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0067.lzma 2022-03-17T21:49:12.039Z,1647553752.039 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0067.lzma.bak 2022-03-17T21:49:12.039Z,1647553752.039 [DataOverHttps](INFO): SBD MOMSN=16577517 2022-03-17T21:49:13.534Z,1647553753.534 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:49:13.534Z,1647553753.534 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:49:13.534Z,1647553753.534 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:52:43.995Z,1647553963.995 [NAL9602](INFO): SBD MO Status=1, MOMSN=18297, MT Status=0, MTMSN=0 2022-03-17T21:52:43.995Z,1647553963.995 [NAL9602](INFO): No messages in MT queue 2022-03-17T21:53:14.702Z,1647553994.702 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T21:54:14.100Z,1647554054.100 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:54:14.100Z,1647554054.100 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:54:14.100Z,1647554054.100 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:54:14.100Z,1647554054.100 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:54:14.504Z,1647554054.504 [Default:CheckIn:D] Stopped 2022-03-17T21:54:14.504Z,1647554054.504 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:54:14.905Z,1647554054.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.267839 min 2022-03-17T21:54:14.905Z,1647554054.905 [Default:CheckIn:E] Stopped 2022-03-17T21:54:14.905Z,1647554054.905 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:54:14.905Z,1647554054.905 [Default:CheckIn] Stopped 2022-03-17T21:54:14.905Z,1647554054.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:54:14.906Z,1647554054.906 [Default:CheckIn](INFO): Running loop #28 2022-03-17T21:54:14.906Z,1647554054.906 [Default:CheckIn] Running Loop=28 2022-03-17T21:54:14.906Z,1647554054.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:54:14.906Z,1647554054.906 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:54:16.920Z,1647554056.920 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215416.00,A,3648.17217,N,12147.27633,W,0.058,344.59,170322,,,A*77 2022-03-17T21:54:16.922Z,1647554056.922 [NAL9602](INFO): GPS fix at 20220317T215416: (36.802869, -121.787939) 2022-03-17T21:54:16.953Z,1647554056.953 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:54:16.953Z,1647554056.953 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:54:24.948Z,1647554064.948 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0069.lzma 2022-03-17T21:54:25.950Z,1647554065.950 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0069.lzma.bak 2022-03-17T21:54:25.951Z,1647554065.951 [DataOverHttps](INFO): SBD MOMSN=16577528 2022-03-17T21:54:42.320Z,1647554082.320 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0070.lzma 2022-03-17T21:54:43.323Z,1647554083.323 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0070.lzma.bak 2022-03-17T21:54:43.323Z,1647554083.323 [DataOverHttps](INFO): SBD MOMSN=16577531 2022-03-17T21:54:44.813Z,1647554084.813 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T21:54:44.813Z,1647554084.813 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T21:54:44.813Z,1647554084.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T21:54:58.127Z,1647554098.127 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T21:54:58.127Z,1647554098.127 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T21:59:19.508Z,1647554359.508 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T21:59:45.420Z,1647554385.420 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T21:59:45.420Z,1647554385.420 [Default:CheckIn:C.Wait] Stopped 2022-03-17T21:59:45.420Z,1647554385.420 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T21:59:45.420Z,1647554385.420 [Default:CheckIn:D] Running Loop=1 2022-03-17T21:59:45.784Z,1647554385.784 [Default:CheckIn:D] Stopped 2022-03-17T21:59:45.784Z,1647554385.784 [Default:CheckIn:E] Running Loop=1 2022-03-17T21:59:46.182Z,1647554386.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.789176 min 2022-03-17T21:59:46.182Z,1647554386.182 [Default:CheckIn:E] Stopped 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn] Stopped 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn](INFO): Running loop #29 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn] Running Loop=29 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T21:59:46.183Z,1647554386.183 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T21:59:48.195Z,1647554388.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215947.00,A,3648.17548,N,12147.27615,W,0.078,344.59,170322,,,A*75 2022-03-17T21:59:48.198Z,1647554388.198 [NAL9602](INFO): GPS fix at 20220317T215947: (36.802925, -121.787936) 2022-03-17T21:59:48.208Z,1647554388.208 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T21:59:48.209Z,1647554388.209 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T21:59:56.312Z,1647554396.312 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0072.lzma 2022-03-17T21:59:57.314Z,1647554397.314 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0072.lzma.bak 2022-03-17T21:59:57.315Z,1647554397.315 [DataOverHttps](INFO): SBD MOMSN=16577546 2022-03-17T22:00:13.976Z,1647554413.976 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0073.lzma 2022-03-17T22:00:14.979Z,1647554414.979 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0073.lzma.bak 2022-03-17T22:00:14.979Z,1647554414.979 [DataOverHttps](INFO): SBD MOMSN=16577549 2022-03-17T22:00:16.497Z,1647554416.497 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:00:16.497Z,1647554416.497 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:00:16.497Z,1647554416.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:00:20.518Z,1647554420.518 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:00:33.451Z,1647554433.451 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-03-17T22:05:17.130Z,1647554717.130 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:05:17.130Z,1647554717.130 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:05:17.130Z,1647554717.130 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:05:17.131Z,1647554717.131 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:05:17.487Z,1647554717.487 [Default:CheckIn:D] Stopped 2022-03-17T22:05:17.487Z,1647554717.487 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.317562 min 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn:E] Stopped 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn] Stopped 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn](INFO): Running loop #30 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn] Running Loop=30 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:05:17.893Z,1647554717.893 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:05:19.904Z,1647554719.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220519.00,A,3648.18100,N,12147.27278,W,0.097,0.00,170322,,,A*72 2022-03-17T22:05:19.906Z,1647554719.906 [NAL9602](INFO): GPS fix at 20220317T220519: (36.803017, -121.787880) 2022-03-17T22:05:19.917Z,1647554719.917 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:05:19.918Z,1647554719.918 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:05:27.552Z,1647554727.552 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220317T194702/Courier0075.lzma 2022-03-17T22:05:28.554Z,1647554728.554 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0075.lzma.bak 2022-03-17T22:05:28.555Z,1647554728.555 [DataOverHttps](INFO): SBD MOMSN=16577560 2022-03-17T22:05:45.124Z,1647554745.124 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0076.lzma 2022-03-17T22:05:46.127Z,1647554746.127 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0076.lzma.bak 2022-03-17T22:05:46.127Z,1647554746.127 [DataOverHttps](INFO): SBD MOMSN=16577563 2022-03-17T22:05:47.481Z,1647554747.481 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:05:47.481Z,1647554747.481 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:05:47.481Z,1647554747.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:05:50.606Z,1647554750.606 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T22:05:50.689Z,1647554750.689 [NAL9602](ERROR): received: +CSQ:0 OK298, 2, 0, 0, 0 OK 2022-03-17T22:10:22.544Z,1647555022.544 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T22:10:48.021Z,1647555048.021 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:10:48.021Z,1647555048.021 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:10:48.021Z,1647555048.021 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:10:48.021Z,1647555048.021 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:10:48.411Z,1647555048.411 [Default:CheckIn:D] Stopped 2022-03-17T22:10:48.411Z,1647555048.411 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.832959 min 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn:E] Stopped 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn] Stopped 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn](INFO): Running loop #31 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn] Running Loop=31 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:10:48.822Z,1647555048.822 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:10:50.826Z,1647555050.826 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221050.00,A,3648.17485,N,12147.27527,W,0.117,0.00,170322,,,A*78 2022-03-17T22:10:50.828Z,1647555050.828 [NAL9602](INFO): GPS fix at 20220317T221050: (36.802914, -121.787921) 2022-03-17T22:10:50.854Z,1647555050.854 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:10:50.854Z,1647555050.854 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:10:58.192Z,1647555058.192 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0078.lzma 2022-03-17T22:10:59.194Z,1647555059.194 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0078.lzma.bak 2022-03-17T22:10:59.195Z,1647555059.195 [DataOverHttps](INFO): SBD MOMSN=16577580 2022-03-17T22:11:15.568Z,1647555075.568 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220317T194702/Express0079.lzma 2022-03-17T22:11:16.571Z,1647555076.571 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0079.lzma.bak 2022-03-17T22:11:16.571Z,1647555076.571 [DataOverHttps](INFO): SBD MOMSN=16577583 2022-03-17T22:11:17.947Z,1647555077.947 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:11:17.948Z,1647555077.948 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:11:17.948Z,1647555077.948 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:11:23.582Z,1647555083.582 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:14:01.178Z,1647555241.178 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-03-17T22:16:18.546Z,1647555378.546 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:16:18.546Z,1647555378.546 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:16:18.546Z,1647555378.546 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:16:18.547Z,1647555378.547 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:16:18.956Z,1647555378.956 [Default:CheckIn:D] Stopped 2022-03-17T22:16:18.956Z,1647555378.956 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:16:19.383Z,1647555379.383 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 174.342041 min 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn:E] Stopped 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn] Stopped 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn](INFO): Running loop #32 2022-03-17T22:16:19.384Z,1647555379.384 [Default:CheckIn] Running Loop=32 2022-03-17T22:16:19.385Z,1647555379.385 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:16:19.385Z,1647555379.385 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:16:21.373Z,1647555381.373 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221620.00,A,3648.17232,N,12147.28413,W,0.253,0.00,170322,,,A*79 2022-03-17T22:16:21.376Z,1647555381.376 [NAL9602](INFO): GPS fix at 20220317T221620: (36.802872, -121.788069) 2022-03-17T22:16:21.407Z,1647555381.407 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:16:21.407Z,1647555381.407 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:16:29.808Z,1647555389.808 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0081.lzma 2022-03-17T22:16:30.811Z,1647555390.811 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0081.lzma.bak 2022-03-17T22:16:30.811Z,1647555390.811 [DataOverHttps](INFO): SBD MOMSN=16577594 2022-03-17T22:16:47.124Z,1647555407.124 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0082.lzma 2022-03-17T22:16:48.127Z,1647555408.127 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0082.lzma.bak 2022-03-17T22:16:48.128Z,1647555408.128 [DataOverHttps](INFO): SBD MOMSN=16577597 2022-03-17T22:16:49.664Z,1647555409.664 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:16:49.664Z,1647555409.664 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:16:49.664Z,1647555409.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:16:52.070Z,1647555412.070 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T22:16:52.145Z,1647555412.145 [NAL9602](ERROR): received: +CSQ:0 OK298, 2, 0, 0, 0 OK 2022-03-17T22:20:59.374Z,1647555659.374 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T22:20:59.374Z,1647555659.374 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:21:23.622Z,1647555683.622 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T22:21:50.297Z,1647555710.297 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:21:50.298Z,1647555710.298 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:21:50.298Z,1647555710.298 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:21:50.298Z,1647555710.298 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:21:50.700Z,1647555710.700 [Default:CheckIn:D] Stopped 2022-03-17T22:21:50.700Z,1647555710.700 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:21:51.134Z,1647555711.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 179.871110 min 2022-03-17T22:21:51.134Z,1647555711.134 [Default:CheckIn:E] Stopped 2022-03-17T22:21:51.134Z,1647555711.134 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn] Stopped 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn](INFO): Running loop #33 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn] Running Loop=33 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:21:51.135Z,1647555711.135 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:21:53.113Z,1647555713.113 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222152.00,A,3648.17133,N,12147.28191,W,0.078,0.00,170322,,,A*7E 2022-03-17T22:21:53.115Z,1647555713.115 [NAL9602](INFO): GPS fix at 20220317T222152: (36.802855, -121.788032) 2022-03-17T22:21:53.162Z,1647555713.162 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:21:53.162Z,1647555713.162 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:22:02.484Z,1647555722.484 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0084.lzma 2022-03-17T22:22:03.487Z,1647555723.487 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0084.lzma.bak 2022-03-17T22:22:03.487Z,1647555723.487 [DataOverHttps](INFO): SBD MOMSN=16577613 2022-03-17T22:22:23.296Z,1647555743.296 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0085.lzma 2022-03-17T22:22:24.299Z,1647555744.299 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0085.lzma.bak 2022-03-17T22:22:24.299Z,1647555744.299 [DataOverHttps](INFO): SBD MOMSN=16577616 2022-03-17T22:22:25.463Z,1647555745.463 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:22:25.504Z,1647555745.504 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:22:25.504Z,1647555745.504 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:22:25.504Z,1647555745.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:25:17.562Z,1647555917.562 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-03-17T22:26:17.844Z,1647555977.844 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-03-17T22:26:17.847Z,1647555977.847 [BPC1](INFO): Received data from all battery sticks. 2022-03-17T22:27:26.124Z,1647556046.124 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:27:26.124Z,1647556046.124 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:27:26.124Z,1647556046.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:27:26.124Z,1647556046.124 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:27:26.540Z,1647556046.540 [Default:CheckIn:D] Stopped 2022-03-17T22:27:26.540Z,1647556046.540 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:27:26.936Z,1647556046.936 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.468441 min 2022-03-17T22:27:26.936Z,1647556046.936 [Default:CheckIn:E] Stopped 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn] Stopped 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn](INFO): Running loop #34 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn] Running Loop=34 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:27:26.937Z,1647556046.937 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:27:28.947Z,1647556048.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222728.00,A,3648.17504,N,12147.27879,W,0.039,0.00,170322,,,A*70 2022-03-17T22:27:28.950Z,1647556048.950 [NAL9602](INFO): GPS fix at 20220317T222728: (36.802917, -121.787980) 2022-03-17T22:27:28.961Z,1647556048.961 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:27:28.961Z,1647556048.961 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:27:36.704Z,1647556056.704 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20220317T194702/Courier0087.lzma 2022-03-17T22:27:37.707Z,1647556057.707 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0087.lzma.bak 2022-03-17T22:27:37.707Z,1647556057.707 [DataOverHttps](INFO): SBD MOMSN=16577627 2022-03-17T22:27:54.292Z,1647556074.292 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220317T194702/Express0088.lzma 2022-03-17T22:27:55.295Z,1647556075.295 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0088.lzma.bak 2022-03-17T22:27:55.295Z,1647556075.295 [DataOverHttps](INFO): SBD MOMSN=16577630 2022-03-17T22:27:56.864Z,1647556076.864 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:27:56.864Z,1647556076.864 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:27:56.869Z,1647556076.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:27:59.646Z,1647556079.646 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T22:27:59.729Z,1647556079.729 [NAL9602](ERROR): received: +CSQ:0 OK298, 2, 0, 0, 0 OK 2022-03-17T22:30:04.914Z,1647556204.914 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T22:30:04.914Z,1647556204.914 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:32:24.299Z,1647556344.299 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T22:32:24.299Z,1647556344.299 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:32:31.572Z,1647556351.572 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T22:32:57.456Z,1647556377.456 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:32:57.457Z,1647556377.457 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:32:57.457Z,1647556377.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:32:57.457Z,1647556377.457 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:32:57.857Z,1647556377.857 [Default:CheckIn:D] Stopped 2022-03-17T22:32:57.857Z,1647556377.857 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:32:58.245Z,1647556378.245 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 190.990397 min 2022-03-17T22:32:58.245Z,1647556378.245 [Default:CheckIn:E] Stopped 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn] Stopped 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn](INFO): Running loop #35 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn] Running Loop=35 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:32:58.246Z,1647556378.246 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:33:00.263Z,1647556380.263 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223259.00,A,3648.17402,N,12147.27626,W,0.058,0.00,170322,,,A*76 2022-03-17T22:33:00.266Z,1647556380.266 [NAL9602](INFO): GPS fix at 20220317T223259: (36.802900, -121.787938) 2022-03-17T22:33:00.276Z,1647556380.276 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:33:00.276Z,1647556380.276 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:33:08.416Z,1647556388.416 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220317T194702/Courier0090.lzma 2022-03-17T22:33:09.419Z,1647556389.419 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0090.lzma.bak 2022-03-17T22:33:09.419Z,1647556389.419 [DataOverHttps](INFO): SBD MOMSN=16577645 2022-03-17T22:33:26.000Z,1647556406.000 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220317T194702/Express0091.lzma 2022-03-17T22:33:27.003Z,1647556407.003 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0091.lzma.bak 2022-03-17T22:33:27.003Z,1647556407.003 [DataOverHttps](INFO): SBD MOMSN=16577648 2022-03-17T22:33:28.548Z,1647556408.548 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:33:28.548Z,1647556408.548 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:33:28.548Z,1647556408.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:33:32.570Z,1647556412.570 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:38:29.228Z,1647556709.228 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:38:29.229Z,1647556709.229 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:38:29.229Z,1647556709.229 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:38:29.230Z,1647556709.230 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:38:29.616Z,1647556709.616 [Default:CheckIn:D] Stopped 2022-03-17T22:38:29.616Z,1647556709.616 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:38:30.013Z,1647556710.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 196.519710 min 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn:E] Stopped 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn] Stopped 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn](INFO): Running loop #36 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn] Running Loop=36 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:38:30.014Z,1647556710.014 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:38:32.018Z,1647556712.018 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223831.00,A,3648.16982,N,12147.27891,W,0.117,0.00,170322,,,A*7E 2022-03-17T22:38:32.021Z,1647556712.021 [NAL9602](INFO): GPS fix at 20220317T223831: (36.802830, -121.787982) 2022-03-17T22:38:32.031Z,1647556712.031 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:38:32.032Z,1647556712.032 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:38:39.988Z,1647556719.988 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0093.lzma 2022-03-17T22:38:40.991Z,1647556720.991 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0093.lzma.bak 2022-03-17T22:38:40.991Z,1647556720.991 [DataOverHttps](INFO): SBD MOMSN=16577660 2022-03-17T22:38:57.492Z,1647556737.492 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0094.lzma 2022-03-17T22:38:58.496Z,1647556738.496 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0094.lzma.bak 2022-03-17T22:38:58.496Z,1647556738.496 [DataOverHttps](INFO): SBD MOMSN=16577663 2022-03-17T22:38:59.916Z,1647556739.916 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:38:59.916Z,1647556739.916 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:38:59.916Z,1647556739.916 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:39:02.722Z,1647556742.722 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T22:39:02.797Z,1647556742.797 [NAL9602](ERROR): received: +CSQ:0 OK298, 2, 0, 0, 0 OK 2022-03-17T22:40:15.133Z,1647556815.133 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-03-17T22:41:11.193Z,1647556871.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T22:41:11.193Z,1647556871.193 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:41:37.093Z,1647556897.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=18298, MT Status=2, MTMSN=0 2022-03-17T22:41:37.094Z,1647556897.094 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:42:16.702Z,1647556936.702 [NAL9602](INFO): SBD MO Status=1, MOMSN=18298, MT Status=0, MTMSN=0 2022-03-17T22:42:16.702Z,1647556936.702 [NAL9602](INFO): No messages in MT queue 2022-03-17T22:42:47.446Z,1647556967.446 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:44:00.558Z,1647557040.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:44:00.558Z,1647557040.558 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:44:00.559Z,1647557040.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:44:00.559Z,1647557040.559 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:44:00.950Z,1647557040.950 [Default:CheckIn:D] Stopped 2022-03-17T22:44:00.950Z,1647557040.950 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:44:01.413Z,1647557041.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.041943 min 2022-03-17T22:44:01.413Z,1647557041.413 [Default:CheckIn:E] Stopped 2022-03-17T22:44:01.413Z,1647557041.413 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:44:01.413Z,1647557041.413 [Default:CheckIn] Stopped 2022-03-17T22:44:01.413Z,1647557041.413 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:44:01.414Z,1647557041.414 [Default:CheckIn](INFO): Running loop #37 2022-03-17T22:44:01.414Z,1647557041.414 [Default:CheckIn] Running Loop=37 2022-03-17T22:44:01.414Z,1647557041.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:44:01.414Z,1647557041.414 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:44:03.365Z,1647557043.365 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224402.00,A,3648.17618,N,12147.27746,W,0.039,0.00,170322,,,A*70 2022-03-17T22:44:03.367Z,1647557043.367 [NAL9602](INFO): GPS fix at 20220317T224402: (36.802936, -121.787958) 2022-03-17T22:44:03.435Z,1647557043.435 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:44:03.435Z,1647557043.435 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:44:14.628Z,1647557054.628 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0096.lzma 2022-03-17T22:44:15.632Z,1647557055.632 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0096.lzma.bak 2022-03-17T22:44:15.633Z,1647557055.633 [DataOverHttps](INFO): SBD MOMSN=16577679 2022-03-17T22:44:31.820Z,1647557071.820 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0097.lzma 2022-03-17T22:44:32.823Z,1647557072.823 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0097.lzma.bak 2022-03-17T22:44:32.823Z,1647557072.823 [DataOverHttps](INFO): SBD MOMSN=16577683 2022-03-17T22:44:34.102Z,1647557074.102 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:44:34.102Z,1647557074.102 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:44:34.102Z,1647557074.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:48:56.698Z,1647557336.698 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T22:48:56.698Z,1647557336.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:49:05.584Z,1647557345.584 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T22:49:34.696Z,1647557374.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:49:34.696Z,1647557374.696 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:49:34.696Z,1647557374.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:49:34.696Z,1647557374.696 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:49:35.134Z,1647557375.134 [Default:CheckIn:D] Stopped 2022-03-17T22:49:35.134Z,1647557375.134 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:49:35.496Z,1647557375.496 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 207.611670 min 2022-03-17T22:49:35.496Z,1647557375.496 [Default:CheckIn:E] Stopped 2022-03-17T22:49:35.496Z,1647557375.496 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:49:35.496Z,1647557375.496 [Default:CheckIn] Stopped 2022-03-17T22:49:35.496Z,1647557375.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:49:35.497Z,1647557375.497 [Default:CheckIn](INFO): Running loop #38 2022-03-17T22:49:35.497Z,1647557375.497 [Default:CheckIn] Running Loop=38 2022-03-17T22:49:35.497Z,1647557375.497 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:49:35.497Z,1647557375.497 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:49:37.516Z,1647557377.516 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224936.00,A,3648.17513,N,12147.28126,W,0.175,0.00,170322,,,A*74 2022-03-17T22:49:37.557Z,1647557377.557 [NAL9602](INFO): GPS fix at 20220317T224936: (36.802919, -121.788021) 2022-03-17T22:49:37.611Z,1647557377.611 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:49:37.612Z,1647557377.612 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:49:39.122Z,1647557379.122 [NAL9602](FAULT): LCB fault: Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated. 2022-03-17T22:49:39.123Z,1647557379.122 [NAL9602] Hardware Fault, FailCount= 1 2022-03-17T22:49:39.123Z,1647557379.123 [NAL9602](ERROR): Hardware Fault 2022-03-17T22:49:39.196Z,1647557379.196 [CBIT](ERROR): Hardware Fault in component: NAL9602 2022-03-17T22:49:39.523Z,1647557379.523 [NAL9602](INFO): Powering down 2022-03-17T22:49:40.347Z,1647557380.347 [CBIT](INFO): Clearing failed state for component NAL9602 2022-03-17T22:49:40.347Z,1647557380.347 [NAL9602] No Fault, FailCount= 1 2022-03-17T22:49:45.672Z,1647557385.672 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0099.lzma 2022-03-17T22:49:46.675Z,1647557386.675 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0099.lzma.bak 2022-03-17T22:49:46.675Z,1647557386.675 [DataOverHttps](INFO): SBD MOMSN=16577692 2022-03-17T22:50:04.697Z,1647557404.697 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220317T194702/Express0100.lzma 2022-03-17T22:50:05.699Z,1647557405.699 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0100.lzma.bak 2022-03-17T22:50:05.699Z,1647557405.699 [DataOverHttps](INFO): SBD MOMSN=16577695 2022-03-17T22:50:07.110Z,1647557407.110 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:50:07.110Z,1647557407.110 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:50:07.110Z,1647557407.110 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:50:09.894Z,1647557409.894 [NAL9602](INFO): Powering up NAL9602 2022-03-17T22:50:20.777Z,1647557420.777 [NAL9602](INFO): NAL9602 initialized 2022-03-17T22:50:43.431Z,1647557443.431 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-03-17T22:50:51.883Z,1647557451.883 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T22:55:07.635Z,1647557707.635 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T22:55:07.635Z,1647557707.635 [Default:CheckIn:C.Wait] Stopped 2022-03-17T22:55:07.636Z,1647557707.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T22:55:07.636Z,1647557707.636 [Default:CheckIn:D] Running Loop=1 2022-03-17T22:55:08.037Z,1647557708.037 [Default:CheckIn:D] Stopped 2022-03-17T22:55:08.037Z,1647557708.037 [Default:CheckIn:E] Running Loop=1 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 213.160059 min 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn:E] Stopped 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn] Stopped 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn](INFO): Running loop #39 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn] Running Loop=39 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T22:55:08.445Z,1647557708.445 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T22:55:10.452Z,1647557710.452 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225509.00,A,3648.17897,N,12147.28049,W,0.447,107.48,170322,,,A*72 2022-03-17T22:55:10.454Z,1647557710.454 [NAL9602](INFO): GPS fix at 20220317T225509: (36.802983, -121.788008) 2022-03-17T22:55:10.483Z,1647557710.483 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T22:55:10.483Z,1647557710.483 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T22:55:18.172Z,1647557718.172 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0102.lzma 2022-03-17T22:55:19.175Z,1647557719.175 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0102.lzma.bak 2022-03-17T22:55:19.175Z,1647557719.175 [DataOverHttps](INFO): SBD MOMSN=16577717 2022-03-17T22:55:35.572Z,1647557735.572 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20220317T194702/Express0103.lzma 2022-03-17T22:55:36.575Z,1647557736.575 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0103.lzma.bak 2022-03-17T22:55:36.575Z,1647557736.575 [DataOverHttps](INFO): SBD MOMSN=16577720 2022-03-17T22:55:37.968Z,1647557737.968 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T22:55:37.968Z,1647557737.968 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T22:55:37.968Z,1647557737.968 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T22:58:03.419Z,1647557883.419 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T22:58:03.419Z,1647557883.419 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:59:23.008Z,1647557963.008 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T22:59:23.009Z,1647557963.009 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T22:59:48.863Z,1647557988.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T22:59:48.863Z,1647557988.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T23:00:12.298Z,1647558012.298 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:00:38.572Z,1647558038.572 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:00:38.572Z,1647558038.572 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:00:38.573Z,1647558038.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:00:38.573Z,1647558038.573 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:00:38.976Z,1647558038.976 [Default:CheckIn:D] Stopped 2022-03-17T23:00:38.976Z,1647558038.976 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 218.675700 min 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn:E] Stopped 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn] Stopped 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn](INFO): Running loop #40 2022-03-17T23:00:39.402Z,1647558039.402 [Default:CheckIn] Running Loop=40 2022-03-17T23:00:39.403Z,1647558039.403 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:00:39.403Z,1647558039.403 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:00:41.388Z,1647558041.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230040.00,A,3648.17651,N,12147.27880,W,0.583,151.95,170322,,,A*72 2022-03-17T23:00:41.390Z,1647558041.390 [NAL9602](INFO): GPS fix at 20220317T230040: (36.802942, -121.787980) 2022-03-17T23:00:41.439Z,1647558041.439 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:00:41.439Z,1647558041.439 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:00:49.164Z,1647558049.164 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0105.lzma 2022-03-17T23:00:50.167Z,1647558050.167 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0105.lzma.bak 2022-03-17T23:00:50.167Z,1647558050.167 [DataOverHttps](INFO): SBD MOMSN=16577731 2022-03-17T23:01:06.396Z,1647558066.396 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220317T194702/Express0106.lzma 2022-03-17T23:01:07.395Z,1647558067.395 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0106.lzma.bak 2022-03-17T23:01:07.395Z,1647558067.395 [DataOverHttps](INFO): SBD MOMSN=16577734 2022-03-17T23:01:08.874Z,1647558068.874 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:01:08.874Z,1647558068.874 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:01:08.874Z,1647558068.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:01:13.302Z,1647558073.302 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:06:09.509Z,1647558369.509 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:06:09.509Z,1647558369.509 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:06:09.509Z,1647558369.509 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:06:09.509Z,1647558369.509 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:06:09.870Z,1647558369.870 [Default:CheckIn:D] Stopped 2022-03-17T23:06:09.870Z,1647558369.870 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:06:10.272Z,1647558370.272 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 224.190609 min 2022-03-17T23:06:10.272Z,1647558370.272 [Default:CheckIn:E] Stopped 2022-03-17T23:06:10.272Z,1647558370.272 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:06:10.272Z,1647558370.272 [Default:CheckIn] Stopped 2022-03-17T23:06:10.272Z,1647558370.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:06:10.277Z,1647558370.277 [Default:CheckIn](INFO): Running loop #41 2022-03-17T23:06:10.277Z,1647558370.277 [Default:CheckIn] Running Loop=41 2022-03-17T23:06:10.277Z,1647558370.277 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:06:10.277Z,1647558370.277 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:06:12.268Z,1647558372.268 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230611.00,A,3648.17469,N,12147.27923,W,0.253,121.41,170322,,,A*75 2022-03-17T23:06:12.270Z,1647558372.270 [NAL9602](INFO): GPS fix at 20220317T230611: (36.802912, -121.787987) 2022-03-17T23:06:12.281Z,1647558372.281 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:06:12.281Z,1647558372.281 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:06:23.688Z,1647558383.688 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0108.lzma 2022-03-17T23:06:24.691Z,1647558384.691 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0108.lzma.bak 2022-03-17T23:06:24.691Z,1647558384.691 [DataOverHttps](INFO): SBD MOMSN=16577750 2022-03-17T23:06:41.160Z,1647558401.160 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0109.lzma 2022-03-17T23:06:42.163Z,1647558402.163 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0109.lzma.bak 2022-03-17T23:06:42.163Z,1647558402.163 [DataOverHttps](INFO): SBD MOMSN=16577753 2022-03-17T23:06:43.093Z,1647558403.093 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T23:06:43.182Z,1647558403.182 [NAL9602](ERROR): received: +CSQ:1 OK299, 2, 0, 0, 0 OK 2022-03-17T23:06:43.515Z,1647558403.515 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:06:43.521Z,1647558403.521 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:06:43.521Z,1647558403.521 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:09:31.135Z,1647558571.135 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T23:09:31.135Z,1647558571.135 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T23:11:14.563Z,1647558674.563 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:11:44.058Z,1647558704.058 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:11:44.058Z,1647558704.058 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:11:44.058Z,1647558704.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:11:44.059Z,1647558704.059 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:11:44.465Z,1647558704.465 [Default:CheckIn:D] Stopped 2022-03-17T23:11:44.465Z,1647558704.465 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:11:44.870Z,1647558704.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 229.767204 min 2022-03-17T23:11:44.870Z,1647558704.870 [Default:CheckIn:E] Stopped 2022-03-17T23:11:44.870Z,1647558704.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn] Stopped 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn](INFO): Running loop #42 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn] Running Loop=42 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:11:44.871Z,1647558704.871 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:11:45.266Z,1647558705.266 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:11:46.879Z,1647558706.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231146.00,A,3648.17563,N,12147.27753,W,0.039,12.12,170322,,,A*4A 2022-03-17T23:11:46.882Z,1647558706.882 [NAL9602](INFO): GPS fix at 20220317T231146: (36.802927, -121.787959) 2022-03-17T23:11:46.893Z,1647558706.893 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:11:46.893Z,1647558706.893 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:11:55.383Z,1647558715.383 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0111.lzma 2022-03-17T23:11:56.383Z,1647558716.383 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0111.lzma.bak 2022-03-17T23:11:56.383Z,1647558716.383 [DataOverHttps](INFO): SBD MOMSN=16577763 2022-03-17T23:12:17.635Z,1647558737.635 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T23:12:17.712Z,1647558737.712 [NAL9602](ERROR): received: +CSQ:0 OK299, 2, 0, 0, 0 OK 2022-03-17T23:12:17.992Z,1647558737.992 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220317T194702/Express0112.lzma 2022-03-17T23:12:18.995Z,1647558738.995 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0112.lzma.bak 2022-03-17T23:12:18.995Z,1647558738.995 [DataOverHttps](INFO): SBD MOMSN=16577766 2022-03-17T23:12:20.478Z,1647558740.478 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:12:20.478Z,1647558740.478 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:12:20.478Z,1647558740.478 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:16:49.535Z,1647559009.535 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:17:20.239Z,1647559040.239 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:17:21.093Z,1647559041.093 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:17:21.093Z,1647559041.093 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:17:21.093Z,1647559041.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:17:21.094Z,1647559041.094 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:17:21.478Z,1647559041.478 [Default:CheckIn:D] Stopped 2022-03-17T23:17:21.478Z,1647559041.478 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:17:21.870Z,1647559041.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 235.384082 min 2022-03-17T23:17:21.870Z,1647559041.870 [Default:CheckIn:E] Stopped 2022-03-17T23:17:21.870Z,1647559041.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:17:21.870Z,1647559041.870 [Default:CheckIn] Stopped 2022-03-17T23:17:21.871Z,1647559041.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:17:21.871Z,1647559041.871 [Default:CheckIn](INFO): Running loop #43 2022-03-17T23:17:21.871Z,1647559041.871 [Default:CheckIn] Running Loop=43 2022-03-17T23:17:21.871Z,1647559041.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:17:21.871Z,1647559041.871 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:17:23.871Z,1647559043.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231723.00,A,3648.18563,N,12147.27749,W,0.311,12.12,170322,,,A*42 2022-03-17T23:17:23.875Z,1647559043.875 [NAL9602](INFO): GPS fix at 20220317T231723: (36.803094, -121.787958) 2022-03-17T23:17:23.886Z,1647559043.886 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:17:23.886Z,1647559043.886 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:17:31.016Z,1647559051.016 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0114.lzma 2022-03-17T23:17:32.019Z,1647559052.019 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0114.lzma.bak 2022-03-17T23:17:32.019Z,1647559052.019 [DataOverHttps](INFO): SBD MOMSN=16577783 2022-03-17T23:17:48.221Z,1647559068.221 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0115.lzma 2022-03-17T23:17:49.219Z,1647559069.219 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0115.lzma.bak 2022-03-17T23:17:49.219Z,1647559069.219 [DataOverHttps](INFO): SBD MOMSN=16577786 2022-03-17T23:17:50.677Z,1647559070.677 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:17:50.677Z,1647559070.677 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:17:50.677Z,1647559070.677 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:17:54.294Z,1647559074.294 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T23:17:54.374Z,1647559074.374 [NAL9602](ERROR): received: +CSQ:0 OK299, 2, 0, 0, 0 OK 2022-03-17T23:18:33.141Z,1647559113.141 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-03-17T23:22:26.258Z,1647559346.258 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:22:51.337Z,1647559371.337 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:22:51.337Z,1647559371.337 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:22:51.337Z,1647559371.337 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:22:51.337Z,1647559371.337 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:22:51.732Z,1647559371.732 [Default:CheckIn:D] Stopped 2022-03-17T23:22:51.732Z,1647559371.732 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:22:52.124Z,1647559372.124 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 240.888314 min 2022-03-17T23:22:52.124Z,1647559372.124 [Default:CheckIn:E] Stopped 2022-03-17T23:22:52.124Z,1647559372.124 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn] Stopped 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn](INFO): Running loop #44 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn] Running Loop=44 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:22:52.125Z,1647559372.125 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:22:54.136Z,1647559374.136 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232253.00,A,3648.17057,N,12147.27278,W,0.175,291.80,170322,,,A*7B 2022-03-17T23:22:54.138Z,1647559374.138 [NAL9602](INFO): GPS fix at 20220317T232253: (36.802843, -121.787880) 2022-03-17T23:22:54.149Z,1647559374.149 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:22:54.149Z,1647559374.149 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:23:02.196Z,1647559382.196 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0117.lzma 2022-03-17T23:23:03.199Z,1647559383.199 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0117.lzma.bak 2022-03-17T23:23:03.199Z,1647559383.199 [DataOverHttps](INFO): SBD MOMSN=16577799 2022-03-17T23:23:19.465Z,1647559399.465 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0118.lzma 2022-03-17T23:23:20.467Z,1647559400.467 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0118.lzma.bak 2022-03-17T23:23:20.467Z,1647559400.467 [DataOverHttps](INFO): SBD MOMSN=16577805 2022-03-17T23:23:22.029Z,1647559402.029 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:23:22.029Z,1647559402.029 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:23:22.029Z,1647559402.029 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:23:26.458Z,1647559406.458 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:28:22.633Z,1647559702.633 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:28:22.633Z,1647559702.633 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:28:22.633Z,1647559702.633 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:28:22.633Z,1647559702.633 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:28:23.019Z,1647559703.019 [Default:CheckIn:D] Stopped 2022-03-17T23:28:23.019Z,1647559703.019 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:28:23.444Z,1647559703.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 246.409749 min 2022-03-17T23:28:23.444Z,1647559703.444 [Default:CheckIn:E] Stopped 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn] Stopped 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn](INFO): Running loop #45 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn] Running Loop=45 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:28:23.445Z,1647559703.445 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:28:25.446Z,1647559705.446 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232824.00,A,3648.15942,N,12147.27545,W,0.758,291.80,170322,,,A*7E 2022-03-17T23:28:25.448Z,1647559705.448 [NAL9602](INFO): GPS fix at 20220317T232824: (36.802657, -121.787924) 2022-03-17T23:28:25.479Z,1647559705.479 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:28:25.479Z,1647559705.479 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:28:33.132Z,1647559713.132 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0120.lzma 2022-03-17T23:28:34.135Z,1647559714.135 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0120.lzma.bak 2022-03-17T23:28:34.135Z,1647559714.135 [DataOverHttps](INFO): SBD MOMSN=16577815 2022-03-17T23:28:50.494Z,1647559730.494 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T23:28:50.494Z,1647559730.494 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T23:28:50.589Z,1647559730.589 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0121.lzma 2022-03-17T23:28:51.591Z,1647559731.591 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0121.lzma.bak 2022-03-17T23:28:51.591Z,1647559731.591 [DataOverHttps](INFO): SBD MOMSN=16577818 2022-03-17T23:28:52.941Z,1647559732.941 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:28:52.941Z,1647559732.941 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:28:52.942Z,1647559732.942 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:29:33.719Z,1647559773.719 [NAL9602](INFO): SBD MO Status=2, MOMSN=18299, MT Status=2, MTMSN=0 2022-03-17T23:29:33.719Z,1647559773.719 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-03-17T23:33:27.328Z,1647560007.328 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:33:49.167Z,1647560029.167 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-03-17T23:33:49.170Z,1647560029.170 [BPC1](INFO): Received data from all battery sticks. 2022-03-17T23:33:53.603Z,1647560033.603 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:33:53.603Z,1647560033.603 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:33:53.604Z,1647560033.604 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:33:53.604Z,1647560033.604 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:33:54.008Z,1647560034.008 [Default:CheckIn:D] Stopped 2022-03-17T23:33:54.008Z,1647560034.008 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:33:54.425Z,1647560034.425 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 251.926237 min 2022-03-17T23:33:54.425Z,1647560034.425 [Default:CheckIn:E] Stopped 2022-03-17T23:33:54.425Z,1647560034.425 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:33:54.425Z,1647560034.425 [Default:CheckIn] Stopped 2022-03-17T23:33:54.425Z,1647560034.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:33:54.426Z,1647560034.426 [Default:CheckIn](INFO): Running loop #46 2022-03-17T23:33:54.426Z,1647560034.426 [Default:CheckIn] Running Loop=46 2022-03-17T23:33:54.426Z,1647560034.426 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:33:54.426Z,1647560034.426 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:33:56.424Z,1647560036.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233355.00,A,3648.16537,N,12147.28073,W,0.097,178.85,170322,,,A*75 2022-03-17T23:33:56.426Z,1647560036.426 [NAL9602](INFO): GPS fix at 20220317T233355: (36.802756, -121.788012) 2022-03-17T23:33:56.437Z,1647560036.437 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:33:56.437Z,1647560036.437 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:34:06.888Z,1647560046.888 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20220317T194702/Courier0123.lzma 2022-03-17T23:34:07.891Z,1647560047.891 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0123.lzma.bak 2022-03-17T23:34:07.891Z,1647560047.891 [DataOverHttps](INFO): SBD MOMSN=16577834 2022-03-17T23:34:25.240Z,1647560065.240 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220317T194702/Express0124.lzma 2022-03-17T23:34:26.245Z,1647560066.245 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0124.lzma.bak 2022-03-17T23:34:26.245Z,1647560066.245 [DataOverHttps](INFO): SBD MOMSN=16577837 2022-03-17T23:34:27.604Z,1647560067.604 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:34:27.605Z,1647560067.605 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:34:27.605Z,1647560067.605 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:34:28.381Z,1647560068.381 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:39:28.234Z,1647560368.234 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:39:28.234Z,1647560368.234 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:39:28.234Z,1647560368.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:39:28.235Z,1647560368.235 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:39:28.638Z,1647560368.638 [Default:CheckIn:D] Stopped 2022-03-17T23:39:28.639Z,1647560368.639 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:39:29.058Z,1647560369.058 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 257.503418 min 2022-03-17T23:39:29.058Z,1647560369.058 [Default:CheckIn:E] Stopped 2022-03-17T23:39:29.059Z,1647560369.059 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:39:29.059Z,1647560369.059 [Default:CheckIn] Stopped 2022-03-17T23:39:29.059Z,1647560369.059 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:39:29.060Z,1647560369.060 [Default:CheckIn](INFO): Running loop #47 2022-03-17T23:39:29.060Z,1647560369.060 [Default:CheckIn] Running Loop=47 2022-03-17T23:39:29.061Z,1647560369.061 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:39:29.061Z,1647560369.061 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:39:31.101Z,1647560371.101 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233930.00,A,3648.16861,N,12147.27996,W,0.330,278.30,170322,,,A*7C 2022-03-17T23:39:31.108Z,1647560371.108 [NAL9602](INFO): GPS fix at 20220317T233930: (36.802810, -121.787999) 2022-03-17T23:39:31.152Z,1647560371.152 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:39:31.152Z,1647560371.152 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:39:38.700Z,1647560378.700 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0126.lzma 2022-03-17T23:39:39.704Z,1647560379.704 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0126.lzma.bak 2022-03-17T23:39:39.704Z,1647560379.704 [DataOverHttps](INFO): SBD MOMSN=16577847 2022-03-17T23:39:56.000Z,1647560396.000 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220317T194702/Express0127.lzma 2022-03-17T23:39:57.003Z,1647560397.003 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0127.lzma.bak 2022-03-17T23:39:57.003Z,1647560397.003 [DataOverHttps](INFO): SBD MOMSN=16577850 2022-03-17T23:39:58.532Z,1647560398.532 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:39:58.532Z,1647560398.532 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:39:58.532Z,1647560398.532 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:40:01.758Z,1647560401.758 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T23:40:01.837Z,1647560401.837 [NAL9602](ERROR): received: +CSQ:0 OK299, 2, 0, 0, 0 OK 2022-03-17T23:44:33.302Z,1647560673.302 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:44:59.191Z,1647560699.191 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:44:59.192Z,1647560699.192 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:44:59.192Z,1647560699.192 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:44:59.192Z,1647560699.192 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:44:59.583Z,1647560699.583 [Default:CheckIn:D] Stopped 2022-03-17T23:44:59.583Z,1647560699.583 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 263.019157 min 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn:E] Stopped 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn] Stopped 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn](INFO): Running loop #48 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn] Running Loop=48 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:44:59.975Z,1647560699.975 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:45:01.987Z,1647560701.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234501.00,A,3648.16143,N,12147.28005,W,0.097,283.16,170322,,,A*7E 2022-03-17T23:45:01.989Z,1647560701.989 [NAL9602](INFO): GPS fix at 20220317T234501: (36.802690, -121.788001) 2022-03-17T23:45:02.000Z,1647560702.000 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:45:02.000Z,1647560702.000 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:45:10.948Z,1647560710.948 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0129.lzma 2022-03-17T23:45:11.951Z,1647560711.951 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0129.lzma.bak 2022-03-17T23:45:11.951Z,1647560711.951 [DataOverHttps](INFO): SBD MOMSN=16577873 2022-03-17T23:45:28.153Z,1647560728.153 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0130.lzma 2022-03-17T23:45:29.155Z,1647560729.155 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0130.lzma.bak 2022-03-17T23:45:29.155Z,1647560729.155 [DataOverHttps](INFO): SBD MOMSN=16577877 2022-03-17T23:45:30.692Z,1647560730.692 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:45:30.692Z,1647560730.692 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:45:30.692Z,1647560730.692 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:45:34.306Z,1647560734.306 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-17T23:49:41.160Z,1647560981.160 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2022-03-17T23:50:31.281Z,1647561031.281 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:50:31.281Z,1647561031.281 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:50:31.281Z,1647561031.281 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:50:31.281Z,1647561031.281 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:50:31.659Z,1647561031.659 [Default:CheckIn:D] Stopped 2022-03-17T23:50:31.659Z,1647561031.659 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 268.553760 min 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn:E] Stopped 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn] Stopped 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn](INFO): Running loop #49 2022-03-17T23:50:32.092Z,1647561032.092 [Default:CheckIn] Running Loop=49 2022-03-17T23:50:32.093Z,1647561032.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:50:32.093Z,1647561032.093 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:50:34.076Z,1647561034.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235033.00,A,3648.16712,N,12147.28152,W,0.058,234.63,170322,,,A*77 2022-03-17T23:50:34.078Z,1647561034.078 [NAL9602](INFO): GPS fix at 20220317T235033: (36.802785, -121.788025) 2022-03-17T23:50:34.128Z,1647561034.128 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:50:34.128Z,1647561034.128 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:50:42.660Z,1647561042.660 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0132.lzma 2022-03-17T23:50:43.663Z,1647561043.663 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0132.lzma.bak 2022-03-17T23:50:43.663Z,1647561043.663 [DataOverHttps](INFO): SBD MOMSN=16577881 2022-03-17T23:50:59.888Z,1647561059.888 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0133.lzma 2022-03-17T23:51:00.891Z,1647561060.891 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0133.lzma.bak 2022-03-17T23:51:00.891Z,1647561060.891 [DataOverHttps](INFO): SBD MOMSN=16577884 2022-03-17T23:51:02.391Z,1647561062.391 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:51:02.391Z,1647561062.391 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:51:02.391Z,1647561062.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:51:04.778Z,1647561064.778 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-17T23:51:04.861Z,1647561064.861 [NAL9602](ERROR): received: +CSQ:0 OK299, 2, 0, 0, 0 OK 2022-03-17T23:55:36.326Z,1647561336.326 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-17T23:56:03.011Z,1647561363.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-17T23:56:03.011Z,1647561363.011 [Default:CheckIn:C.Wait] Stopped 2022-03-17T23:56:03.011Z,1647561363.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-17T23:56:03.011Z,1647561363.011 [Default:CheckIn:D] Running Loop=1 2022-03-17T23:56:03.408Z,1647561363.408 [Default:CheckIn:D] Stopped 2022-03-17T23:56:03.409Z,1647561363.409 [Default:CheckIn:E] Running Loop=1 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 274.082910 min 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn:E] Stopped 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn] Stopped 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-17T23:56:03.813Z,1647561363.813 [Default:CheckIn](INFO): Running loop #50 2022-03-17T23:56:03.814Z,1647561363.814 [Default:CheckIn] Running Loop=50 2022-03-17T23:56:03.814Z,1647561363.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-17T23:56:03.814Z,1647561363.814 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-17T23:56:05.817Z,1647561365.817 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235605.00,A,3648.16786,N,12147.28050,W,0.117,234.63,170322,,,A*70 2022-03-17T23:56:05.820Z,1647561365.820 [NAL9602](INFO): GPS fix at 20220317T235605: (36.802798, -121.788008) 2022-03-17T23:56:05.867Z,1647561365.867 [Default:CheckIn:Read_GPS] Stopped 2022-03-17T23:56:05.867Z,1647561365.867 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-17T23:56:13.628Z,1647561373.628 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0135.lzma 2022-03-17T23:56:14.631Z,1647561374.631 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0135.lzma.bak 2022-03-17T23:56:14.631Z,1647561374.631 [DataOverHttps](INFO): SBD MOMSN=16577893 2022-03-17T23:56:30.832Z,1647561390.832 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0136.lzma 2022-03-17T23:56:31.835Z,1647561391.835 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0136.lzma.bak 2022-03-17T23:56:31.835Z,1647561391.835 [DataOverHttps](INFO): SBD MOMSN=16577896 2022-03-17T23:56:33.369Z,1647561393.369 [Default:CheckIn:Read_Iridium] Stopped 2022-03-17T23:56:33.369Z,1647561393.369 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-17T23:56:33.369Z,1647561393.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-17T23:56:38.606Z,1647561398.606 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-18T00:01:33.928Z,1647561693.928 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-18T00:01:33.928Z,1647561693.928 [Default:CheckIn:C.Wait] Stopped 2022-03-18T00:01:33.928Z,1647561693.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-18T00:01:33.930Z,1647561693.930 [Default:CheckIn:D] Running Loop=1 2022-03-18T00:01:34.360Z,1647561694.360 [Default:CheckIn:D] Stopped 2022-03-18T00:01:34.360Z,1647561694.360 [Default:CheckIn:E] Running Loop=1 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 279.598763 min 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn:E] Stopped 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn] Stopped 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn](INFO): Running loop #51 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn] Running Loop=51 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-18T00:01:34.741Z,1647561694.741 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-18T00:01:36.756Z,1647561696.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000136.00,A,3648.16645,N,12147.28260,W,0.097,0.00,180322,,,A*7A 2022-03-18T00:01:36.758Z,1647561696.758 [NAL9602](INFO): GPS fix at 20220318T000136: (36.802774, -121.788043) 2022-03-18T00:01:36.769Z,1647561696.769 [Default:CheckIn:Read_GPS] Stopped 2022-03-18T00:01:36.769Z,1647561696.769 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-18T00:01:44.824Z,1647561704.824 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20220317T194702/Courier0138.lzma 2022-03-18T00:01:45.827Z,1647561705.827 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0138.lzma.bak 2022-03-18T00:01:45.827Z,1647561705.827 [DataOverHttps](INFO): SBD MOMSN=16577900 2022-03-18T00:02:03.093Z,1647561723.093 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0139.lzma 2022-03-18T00:02:04.087Z,1647561724.087 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0139.lzma.bak 2022-03-18T00:02:04.087Z,1647561724.087 [DataOverHttps](INFO): SBD MOMSN=16577903 2022-03-18T00:02:05.472Z,1647561725.472 [Default:CheckIn:Read_Iridium] Stopped 2022-03-18T00:02:05.472Z,1647561725.472 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-18T00:02:05.472Z,1647561725.472 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-18T00:06:39.417Z,1647561999.417 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-18T00:07:06.113Z,1647562026.113 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-18T00:07:06.113Z,1647562026.113 [Default:CheckIn:C.Wait] Stopped 2022-03-18T00:07:06.113Z,1647562026.113 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-18T00:07:06.114Z,1647562026.114 [Default:CheckIn:D] Running Loop=1 2022-03-18T00:07:06.497Z,1647562026.497 [Default:CheckIn:D] Stopped 2022-03-18T00:07:06.497Z,1647562026.497 [Default:CheckIn:E] Running Loop=1 2022-03-18T00:07:06.900Z,1647562026.900 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 285.134408 min 2022-03-18T00:07:06.900Z,1647562026.900 [Default:CheckIn:E] Stopped 2022-03-18T00:07:06.900Z,1647562026.900 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-18T00:07:06.900Z,1647562026.900 [Default:CheckIn] Stopped 2022-03-18T00:07:06.901Z,1647562026.901 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-18T00:07:06.901Z,1647562026.901 [Default:CheckIn](INFO): Running loop #52 2022-03-18T00:07:06.901Z,1647562026.901 [Default:CheckIn] Running Loop=52 2022-03-18T00:07:06.901Z,1647562026.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-18T00:07:06.901Z,1647562026.901 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-18T00:07:08.908Z,1647562028.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000708.00,A,3648.16729,N,12147.27989,W,0.039,119.65,180322,,,A*77 2022-03-18T00:07:08.918Z,1647562028.918 [NAL9602](INFO): GPS fix at 20220318T000708: (36.802788, -121.787998) 2022-03-18T00:07:08.933Z,1647562028.933 [Default:CheckIn:Read_GPS] Stopped 2022-03-18T00:07:08.933Z,1647562028.933 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-18T00:07:16.268Z,1647562036.268 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220317T194702/Courier0141.lzma 2022-03-18T00:07:17.271Z,1647562037.271 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0141.lzma.bak 2022-03-18T00:07:17.271Z,1647562037.271 [DataOverHttps](INFO): SBD MOMSN=16577912 2022-03-18T00:07:33.561Z,1647562053.561 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220317T194702/Express0142.lzma 2022-03-18T00:07:34.563Z,1647562054.563 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0142.lzma.bak 2022-03-18T00:07:34.563Z,1647562054.563 [DataOverHttps](INFO): SBD MOMSN=16577915 2022-03-18T00:07:36.054Z,1647562056.054 [Default:CheckIn:Read_Iridium] Stopped 2022-03-18T00:07:36.054Z,1647562056.054 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-18T00:07:36.054Z,1647562056.054 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-18T00:07:41.634Z,1647562061.634 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-18T00:12:36.647Z,1647562356.647 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-18T00:12:36.647Z,1647562356.647 [Default:CheckIn:C.Wait] Stopped 2022-03-18T00:12:36.647Z,1647562356.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-18T00:12:36.648Z,1647562356.648 [Default:CheckIn:D] Running Loop=1 2022-03-18T00:12:37.069Z,1647562357.069 [Default:CheckIn:D] Stopped 2022-03-18T00:12:37.070Z,1647562357.070 [Default:CheckIn:E] Running Loop=1 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 290.643945 min 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn:E] Stopped 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn] Stopped 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn](INFO): Running loop #53 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn] Running Loop=53 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-18T00:12:37.450Z,1647562357.450 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-18T00:12:39.456Z,1647562359.456 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001238.00,A,3648.16202,N,12147.28286,W,0.369,209.90,180322,,,A*79 2022-03-18T00:12:39.458Z,1647562359.458 [NAL9602](INFO): GPS fix at 20220318T001238: (36.802700, -121.788048) 2022-03-18T00:12:39.469Z,1647562359.469 [Default:CheckIn:Read_GPS] Stopped 2022-03-18T00:12:39.469Z,1647562359.469 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-18T00:12:47.128Z,1647562367.128 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0144.lzma 2022-03-18T00:12:48.131Z,1647562368.131 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0144.lzma.bak 2022-03-18T00:12:48.131Z,1647562368.131 [DataOverHttps](INFO): SBD MOMSN=16577919 2022-03-18T00:13:04.461Z,1647562384.461 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220317T194702/Express0145.lzma 2022-03-18T00:13:05.464Z,1647562385.464 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0145.lzma.bak 2022-03-18T00:13:05.464Z,1647562385.464 [DataOverHttps](INFO): SBD MOMSN=16577922 2022-03-18T00:13:06.945Z,1647562386.945 [Default:CheckIn:Read_Iridium] Stopped 2022-03-18T00:13:06.945Z,1647562386.945 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-18T00:13:06.945Z,1647562386.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-18T00:13:10.163Z,1647562390.163 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-03-18T00:13:10.237Z,1647562390.237 [NAL9602](ERROR): received: +CSQ:0 OK299, 2, 0, 0, 0 OK 2022-03-18T00:13:32.043Z,1647562412.043 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-03-18T00:17:41.304Z,1647562661.304 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-03-18T00:18:07.594Z,1647562687.594 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-03-18T00:18:07.594Z,1647562687.594 [Default:CheckIn:C.Wait] Stopped 2022-03-18T00:18:07.594Z,1647562687.594 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-18T00:18:07.594Z,1647562687.594 [Default:CheckIn:D] Running Loop=1 2022-03-18T00:18:08.036Z,1647562688.036 [Default:CheckIn:D] Stopped 2022-03-18T00:18:08.036Z,1647562688.036 [Default:CheckIn:E] Running Loop=1 2022-03-18T00:18:08.409Z,1647562688.409 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 296.160026 min 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn:E] Stopped 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn] Stopped 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn](INFO): Running loop #54 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn] Running Loop=54 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-03-18T00:18:08.410Z,1647562688.410 [Default:CheckIn:Read_GPS] Running Loop=1 2022-03-18T00:18:10.399Z,1647562690.399 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001809.00,A,3648.16454,N,12147.27482,W,0.544,198.40,180322,,,A*76 2022-03-18T00:18:10.402Z,1647562690.402 [NAL9602](INFO): GPS fix at 20220318T001809: (36.802742, -121.787914) 2022-03-18T00:18:10.433Z,1647562690.433 [Default:CheckIn:Read_GPS] Stopped 2022-03-18T00:18:10.433Z,1647562690.433 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-03-18T00:18:17.636Z,1647562697.636 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220317T194702/Courier0147.lzma 2022-03-18T00:18:18.639Z,1647562698.639 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Courier0147.lzma.bak 2022-03-18T00:18:18.639Z,1647562698.639 [DataOverHttps](INFO): SBD MOMSN=16577932 2022-03-18T00:18:34.932Z,1647562714.932 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220317T194702/Express0148.lzma 2022-03-18T00:18:35.936Z,1647562715.936 [DataOverHttps](INFO): Moved sent file to Logs/20220317T194702/Express0148.lzma.bak 2022-03-18T00:18:35.936Z,1647562715.936 [DataOverHttps](INFO): SBD MOMSN=16577935 2022-03-18T00:18:37.480Z,1647562717.480 [Default:CheckIn:Read_Iridium] Stopped 2022-03-18T00:18:37.480Z,1647562717.480 [Default:CheckIn:C.Wait] Running Loop=1 2022-03-18T00:18:37.480Z,1647562717.480 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-03-18T00:18:42.314Z,1647562722.314 [NAL9602](INFO): Not Powering down - fast GPS 2022-03-18T00:19:37.141Z,1647562777.141 [CommandExec](IMPORTANT): got command quit 2022-03-18T00:19:38.149Z,1647562778.149 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:38.149Z,1647562778.149 [CommandExec](INFO): Uninitializing the command executive. 2022-03-18T00:19:38.149Z,1647562778.149 [CommandExec](INFO): Uninitializing the command scheduler. 2022-03-18T00:19:38.150Z,1647562778.150 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.221Z,1647562778.221 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-03-18T00:19:38.221Z,1647562778.221 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-03-18T00:19:38.221Z,1647562778.221 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.222Z,1647562778.222 [NavChartDb](INFO): Join timeout helper Thread ID is 1371 2022-03-18T00:19:38.309Z,1647562778.309 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:38.309Z,1647562778.309 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.321Z,1647562778.321 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2022-03-18T00:19:38.321Z,1647562778.321 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.321Z,1647562778.321 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 1372 2022-03-18T00:19:38.689Z,1647562778.689 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:38.689Z,1647562778.689 [WetLabsUBAT](INFO): Powering down 2022-03-18T00:19:38.690Z,1647562778.690 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.692Z,1647562778.692 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-03-18T00:19:38.693Z,1647562778.693 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.693Z,1647562778.693 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1373 2022-03-18T00:19:38.869Z,1647562778.869 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:38.869Z,1647562778.869 [WetLabsBB2FL](INFO): Powering down 2022-03-18T00:19:38.870Z,1647562778.870 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.873Z,1647562778.873 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-03-18T00:19:38.873Z,1647562778.873 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:38.873Z,1647562778.873 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1374 2022-03-18T00:19:39.509Z,1647562779.509 [CTD_Seabird](INFO): Powering down 2022-03-18T00:19:39.523Z,1647562779.523 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:39.532Z,1647562779.532 [CTD_Seabird](INFO): Powering down 2022-03-18T00:19:39.545Z,1647562779.545 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.560Z,1647562779.560 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-03-18T00:19:39.561Z,1647562779.561 [DAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.561Z,1647562779.561 [DAT](INFO): Join timeout helper Thread ID is 1375 2022-03-18T00:19:39.705Z,1647562779.705 [DAT](INFO): Powering down 2022-03-18T00:19:39.777Z,1647562779.777 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:39.777Z,1647562779.777 [DAT](INFO): Powering down 2022-03-18T00:19:39.778Z,1647562779.778 [DAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.793Z,1647562779.793 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-03-18T00:19:39.793Z,1647562779.793 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.794Z,1647562779.794 [Radio_Surface](INFO): Join timeout helper Thread ID is 1376 2022-03-18T00:19:39.853Z,1647562779.853 [Radio_Surface](INFO): Powering down 2022-03-18T00:19:39.853Z,1647562779.853 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:39.854Z,1647562779.854 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.861Z,1647562779.861 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-03-18T00:19:39.861Z,1647562779.861 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:39.862Z,1647562779.862 [Onboard](INFO): Join timeout helper Thread ID is 1377 2022-03-18T00:19:40.513Z,1647562780.513 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-03-18T00:19:42.621Z,1647562782.621 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:42.621Z,1647562782.621 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:42.629Z,1647562782.629 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-03-18T00:19:42.629Z,1647562782.629 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:42.630Z,1647562782.630 [DataOverHttps](INFO): Join timeout helper Thread ID is 1378 2022-03-18T00:19:43.525Z,1647562783.525 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:43.525Z,1647562783.525 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.537Z,1647562783.537 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-03-18T00:19:43.537Z,1647562783.537 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.538Z,1647562783.538 [BackseatComponent](INFO): Join timeout helper Thread ID is 1379 2022-03-18T00:19:43.554Z,1647562783.554 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:43.555Z,1647562783.555 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.557Z,1647562783.557 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-03-18T00:19:43.558Z,1647562783.558 [logger ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.558Z,1647562783.558 [logger](INFO): Join timeout helper Thread ID is 1380 2022-03-18T00:19:43.595Z,1647562783.595 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:43.596Z,1647562783.596 [logger ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.605Z,1647562783.605 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-03-18T00:19:43.605Z,1647562783.605 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.606Z,1647562783.606 [CommandLine](INFO): Join timeout helper Thread ID is 1381 2022-03-18T00:19:43.637Z,1647562783.637 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:43.637Z,1647562783.637 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.645Z,1647562783.645 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-03-18T00:19:43.645Z,1647562783.645 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.646Z,1647562783.646 [CommandExec](INFO): Join timeout helper Thread ID is 1382 2022-03-18T00:19:43.647Z,1647562783.647 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-03-18T00:19:43.647Z,1647562783.647 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.647Z,1647562783.647 [controlThread](INFO): Join timeout helper Thread ID is 1383 2022-03-18T00:19:43.705Z,1647562783.705 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-03-18T00:19:43.705Z,1647562783.705 [controlThread](DEBUG): Uninitializing ControlThread 2022-03-18T00:19:43.706Z,1647562783.706 [AHRS_M2](INFO): Powering down 2022-03-18T00:19:43.782Z,1647562783.782 [NAL9602](INFO): Powering down 2022-03-18T00:19:43.853Z,1647562783.853 [RDI_Pathfinder](INFO): Powering down 2022-03-18T00:19:43.854Z,1647562783.854 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-03-18T00:19:43.855Z,1647562783.855 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-03-18T00:19:43.855Z,1647562783.855 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-03-18T00:19:43.856Z,1647562783.856 [MissionManager](INFO): Uninitializing Mission Default 2022-03-18T00:19:43.856Z,1647562783.856 [Default] Stopped 2022-03-18T00:19:43.856Z,1647562783.856 [Default](DEBUG): Aggregate::uninitialize Default 2022-03-18T00:19:43.856Z,1647562783.856 [Default:B.GoToSurface] Stopped 2022-03-18T00:19:43.856Z,1647562783.856 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-03-18T00:19:43.857Z,1647562783.857 [Default:CheckIn] Stopped 2022-03-18T00:19:43.857Z,1647562783.857 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-03-18T00:19:43.857Z,1647562783.857 [Default:CheckIn:C.Wait] Stopped 2022-03-18T00:19:43.857Z,1647562783.857 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-03-18T00:19:43.859Z,1647562783.859 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-03-18T00:19:43.860Z,1647562783.860 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-03-18T00:19:43.860Z,1647562783.860 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-03-18T00:19:43.860Z,1647562783.860 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-03-18T00:19:43.861Z,1647562783.861 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-03-18T00:19:43.861Z,1647562783.861 [BuoyancyServo](INFO): Powering down 2022-03-18T00:19:43.873Z,1647562783.873 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-03-18T00:19:43.873Z,1647562783.873 [ElevatorServo](INFO): Powering down 2022-03-18T00:19:43.874Z,1647562783.874 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-03-18T00:19:43.874Z,1647562783.874 [MassServo](INFO): Powering down 2022-03-18T00:19:43.875Z,1647562783.875 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-03-18T00:19:43.875Z,1647562783.875 [RudderServo](INFO): Powering down 2022-03-18T00:19:43.876Z,1647562783.876 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-03-18T00:19:43.876Z,1647562783.876 [ThrusterServo](INFO): Powering down 2022-03-18T00:19:43.877Z,1647562783.877 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-03-18T00:19:43.878Z,1647562783.878 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-03-18T00:19:43.878Z,1647562783.878 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-03-18T00:19:43.878Z,1647562783.878 [CBIT](DEBUG): Powering off loads. 2022-03-18T00:19:43.892Z,1647562783.892 [CBIT](DEBUG): Disabling WDT. 2022-03-18T00:19:43.905Z,1647562783.905 [CBIT](DEBUG): Opening all GF detection circuits. 2022-03-18T00:19:43.906Z,1647562783.906 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.978Z,1647562783.978 [DAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.985Z,1647562783.985 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.987Z,1647562783.987 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:43.993Z,1647562783.993 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.036Z,1647562784.036 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.094Z,1647562784.094 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.095Z,1647562784.095 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.099Z,1647562784.099 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.107Z,1647562784.107 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-03-18T00:19:44.207Z,1647562784.207 [logger ThreadHandler](INFO): Thread cancelled.