2021-12-07T18:36:00.830Z,1638902160.830 [DataOverHttps](INFO): Received command: restart logs
2021-12-07T18:36:00.832Z,1638902160.832 [CommandExec](IMPORTANT): got command restart logs
2021-12-07T18:36:13.792Z,1638902173.792 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T18:36:59.868Z,1638902219.868 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-12-07T18:39:31.133Z,1638902371.133 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-07T18:39:37.511Z,1638902377.511 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-12-07T18:39:37.514Z,1638902377.514 [BPC1](INFO): Received data from all battery sticks.
2021-12-07T18:40:43.782Z,1638902443.782 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T18:40:43.782Z,1638902443.782 [Default:CheckIn:C.Wait] Stopped
2021-12-07T18:40:43.783Z,1638902443.783 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T18:40:43.783Z,1638902443.783 [Default:CheckIn:D] Running Loop=1
2021-12-07T18:40:44.177Z,1638902444.177 [Default:CheckIn:D] Stopped
2021-12-07T18:40:44.177Z,1638902444.177 [Default:CheckIn:E] Running Loop=1
2021-12-07T18:40:44.560Z,1638902444.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.165356 min 
2021-12-07T18:40:44.560Z,1638902444.560 [Default:CheckIn:E] Stopped
2021-12-07T18:40:44.560Z,1638902444.560 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T18:40:44.560Z,1638902444.560 [Default:CheckIn] Stopped
2021-12-07T18:40:44.560Z,1638902444.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T18:40:44.561Z,1638902444.561 [Default:CheckIn](INFO): Running loop #6
2021-12-07T18:40:44.561Z,1638902444.561 [Default:CheckIn] Running Loop=6
2021-12-07T18:40:44.561Z,1638902444.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T18:40:44.561Z,1638902444.561 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T18:40:46.574Z,1638902446.574 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184045.00,A,3637.25363,N,12154.04308,W,2.721,181.41,071221,,,A*70
2021-12-07T18:40:46.577Z,1638902446.577 [NAL9602](INFO): GPS fix at 20211207T184045: (36.620894, -121.900718)
2021-12-07T18:40:46.589Z,1638902446.589 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T18:40:46.589Z,1638902446.589 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T18:40:54.242Z,1638902454.242 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211207T172333/Courier0039.lzma
2021-12-07T18:40:55.244Z,1638902455.244 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0039.lzma.bak
2021-12-07T18:40:55.245Z,1638902455.245 [DataOverHttps](INFO): SBD MOMSN=16335202
2021-12-07T18:41:03.133Z,1638902463.133 [NAL9602](INFO): SBD MO Status=0, MOMSN=17860, MT Status=0, MTMSN=0
2021-12-07T18:41:03.134Z,1638902463.134 [NAL9602](INFO): No messages in MT queue
2021-12-07T18:41:15.643Z,1638902475.643 [DataOverHttps](INFO): Sending 309 bytes from file Logs/20211207T183600/Courier0000.lzma
2021-12-07T18:41:16.644Z,1638902476.644 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0000.lzma.bak
2021-12-07T18:41:16.645Z,1638902476.645 [DataOverHttps](INFO): SBD MOMSN=16335206
2021-12-07T18:41:33.155Z,1638902493.155 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20211207T172333/Express0040.lzma
2021-12-07T18:41:33.844Z,1638902493.844 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T18:41:34.157Z,1638902494.157 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0040.lzma.bak
2021-12-07T18:41:34.157Z,1638902494.157 [DataOverHttps](INFO): SBD MOMSN=16335210
2021-12-07T18:42:05.279Z,1638902525.279 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T18:42:34.407Z,1638902554.407 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251266
2021-12-07T18:43:05.531Z,1638902585.531 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T18:43:14.905Z,1638902594.905 [NAL9602](INFO): SBD MO Status=2, MOMSN=17861, MT Status=2, MTMSN=0
2021-12-07T18:43:14.905Z,1638902594.905 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T18:43:40.683Z,1638902620.683 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T18:43:52.223Z,1638902632.223 [NAL9602](INFO): SBD MO Status=2, MOMSN=17861, MT Status=2, MTMSN=0
2021-12-07T18:43:52.224Z,1638902632.224 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T18:44:15.831Z,1638902655.831 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T18:44:31.507Z,1638902671.507 [NAL9602](INFO): SBD MO Status=1, MOMSN=17861, MT Status=0, MTMSN=0
2021-12-07T18:44:31.567Z,1638902671.567 [NAL9602](INFO): Sent 332 bytes from file Logs/20211207T183600/Express0001.lzma
2021-12-07T18:44:31.567Z,1638902671.567 [NAL9602](INFO): Packets left to send: 1
2021-12-07T18:44:36.152Z,1638902676.152 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003292
2021-12-07T18:44:42.865Z,1638902682.865 [NAL9602](INFO): SBD MO Status=1, MOMSN=17862, MT Status=0, MTMSN=0
2021-12-07T18:44:42.919Z,1638902682.919 [NAL9602](INFO): Sent 66 bytes from file Logs/20211207T183600/Express0001.lzma
2021-12-07T18:44:42.919Z,1638902682.919 [NAL9602](INFO): Packets left to send: 0
2021-12-07T18:45:07.271Z,1638902707.271 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T18:45:13.572Z,1638902713.572 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T18:45:14.946Z,1638902714.946 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20211207T183600/Express0004.lzma
2021-12-07T18:45:15.949Z,1638902715.949 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0004.lzma.bak
2021-12-07T18:45:15.949Z,1638902715.949 [DataOverHttps](INFO): SBD MOMSN=16335214
2021-12-07T18:45:17.228Z,1638902717.228 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T18:45:17.229Z,1638902717.229 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T18:45:17.229Z,1638902717.229 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T18:50:17.892Z,1638903017.892 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T18:50:17.893Z,1638903017.893 [Default:CheckIn:C.Wait] Stopped
2021-12-07T18:50:17.893Z,1638903017.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T18:50:17.893Z,1638903017.893 [Default:CheckIn:D] Running Loop=1
2021-12-07T18:50:18.273Z,1638903018.273 [Default:CheckIn:D] Stopped
2021-12-07T18:50:18.273Z,1638903018.273 [Default:CheckIn:E] Running Loop=1
2021-12-07T18:50:18.674Z,1638903018.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.733618 min 
2021-12-07T18:50:18.674Z,1638903018.674 [Default:CheckIn:E] Stopped
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn] Stopped
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn](INFO): Running loop #7
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn] Running Loop=7
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T18:50:18.683Z,1638903018.683 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T18:50:20.679Z,1638903020.679 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185019.00,A,3638.96082,N,12152.99799,W,20.663,22.61,071221,,,D*75
2021-12-07T18:50:20.681Z,1638903020.681 [NAL9602](INFO): GPS fix at 20211207T185019: (36.649347, -121.883300)
2021-12-07T18:50:20.702Z,1638903020.702 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T18:50:20.702Z,1638903020.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T18:50:31.322Z,1638903031.322 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0006.lzma
2021-12-07T18:50:32.324Z,1638903032.324 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0006.lzma.bak
2021-12-07T18:50:32.325Z,1638903032.325 [DataOverHttps](INFO): SBD MOMSN=16335223
2021-12-07T18:50:46.645Z,1638903046.645 [NAL9602](INFO): SBD MO Status=0, MOMSN=17863, MT Status=0, MTMSN=0
2021-12-07T18:50:46.645Z,1638903046.645 [NAL9602](INFO): No messages in MT queue
2021-12-07T18:50:48.796Z,1638903048.796 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T183600/Express0007.lzma
2021-12-07T18:50:49.796Z,1638903049.796 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0007.lzma.bak
2021-12-07T18:50:49.797Z,1638903049.797 [DataOverHttps](INFO): SBD MOMSN=16335226
2021-12-07T18:50:51.084Z,1638903051.084 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T18:50:51.085Z,1638903051.085 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T18:50:51.085Z,1638903051.085 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T18:51:17.329Z,1638903077.329 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T18:55:51.688Z,1638903351.688 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T18:55:51.688Z,1638903351.688 [Default:CheckIn:C.Wait] Stopped
2021-12-07T18:55:51.688Z,1638903351.688 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T18:55:51.689Z,1638903351.689 [Default:CheckIn:D] Running Loop=1
2021-12-07T18:55:52.060Z,1638903352.060 [Default:CheckIn:D] Stopped
2021-12-07T18:55:52.060Z,1638903352.060 [Default:CheckIn:E] Running Loop=1
2021-12-07T18:55:52.468Z,1638903352.468 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.296737 min 
2021-12-07T18:55:52.468Z,1638903352.468 [Default:CheckIn:E] Stopped
2021-12-07T18:55:52.468Z,1638903352.468 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T18:55:52.468Z,1638903352.468 [Default:CheckIn] Stopped
2021-12-07T18:55:52.468Z,1638903352.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T18:55:52.469Z,1638903352.469 [Default:CheckIn](INFO): Running loop #8
2021-12-07T18:55:52.469Z,1638903352.469 [Default:CheckIn] Running Loop=8
2021-12-07T18:55:52.469Z,1638903352.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T18:55:52.469Z,1638903352.469 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T18:55:54.476Z,1638903354.476 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185553.00,A,3640.69102,N,12151.95218,W,20.469,30.39,071221,,,D*7D
2021-12-07T18:55:54.478Z,1638903354.478 [NAL9602](INFO): GPS fix at 20211207T185553: (36.678184, -121.865870)
2021-12-07T18:55:54.491Z,1638903354.491 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T18:55:54.491Z,1638903354.491 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T18:56:02.322Z,1638903362.322 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0009.lzma
2021-12-07T18:56:03.324Z,1638903363.324 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0009.lzma.bak
2021-12-07T18:56:03.325Z,1638903363.325 [DataOverHttps](INFO): SBD MOMSN=16335232
2021-12-07T18:56:08.617Z,1638903368.617 [NAL9602](INFO): SBD MO Status=0, MOMSN=17864, MT Status=0, MTMSN=0
2021-12-07T18:56:08.618Z,1638903368.618 [NAL9602](INFO): No messages in MT queue
2021-12-07T18:56:21.135Z,1638903381.135 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T183600/Express0010.lzma
2021-12-07T18:56:22.137Z,1638903382.137 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0010.lzma.bak
2021-12-07T18:56:22.137Z,1638903382.137 [DataOverHttps](INFO): SBD MOMSN=16335235
2021-12-07T18:56:23.227Z,1638903383.227 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T18:56:23.227Z,1638903383.227 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T18:56:23.227Z,1638903383.227 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T18:56:39.368Z,1638903399.368 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:01:23.852Z,1638903683.852 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:01:23.852Z,1638903683.852 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:01:23.852Z,1638903683.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:01:23.852Z,1638903683.852 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:01:24.213Z,1638903684.213 [Default:CheckIn:D] Stopped
2021-12-07T19:01:24.213Z,1638903684.213 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:01:24.632Z,1638903684.632 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.832621 min 
2021-12-07T19:01:24.632Z,1638903684.632 [Default:CheckIn:E] Stopped
2021-12-07T19:01:24.632Z,1638903684.632 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn] Stopped
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn](INFO): Running loop #9
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn] Running Loop=9
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:01:24.633Z,1638903684.633 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:01:26.634Z,1638903686.634 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190125.00,A,3642.38002,N,12150.90363,W,20.352,27.71,071221,,,D*77
2021-12-07T19:01:26.637Z,1638903686.637 [NAL9602](INFO): GPS fix at 20211207T190125: (36.706334, -121.848394)
2021-12-07T19:01:26.670Z,1638903686.670 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:01:26.670Z,1638903686.670 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:01:33.970Z,1638903693.970 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0012.lzma
2021-12-07T19:01:34.973Z,1638903694.973 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0012.lzma.bak
2021-12-07T19:01:34.973Z,1638903694.973 [DataOverHttps](INFO): SBD MOMSN=16335240
2021-12-07T19:01:51.279Z,1638903711.279 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T183600/Express0013.lzma
2021-12-07T19:01:52.281Z,1638903712.281 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0013.lzma.bak
2021-12-07T19:01:52.281Z,1638903712.281 [DataOverHttps](INFO): SBD MOMSN=16335243
2021-12-07T19:01:52.485Z,1638903712.485 [NAL9602](INFO): SBD MO Status=0, MOMSN=17865, MT Status=0, MTMSN=0
2021-12-07T19:01:52.485Z,1638903712.485 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:01:53.339Z,1638903713.339 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:01:53.339Z,1638903713.339 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:01:53.339Z,1638903713.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:02:23.197Z,1638903743.197 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:06:53.944Z,1638904013.944 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:06:53.944Z,1638904013.944 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:06:53.944Z,1638904013.944 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:06:53.945Z,1638904013.945 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:06:54.349Z,1638904014.349 [Default:CheckIn:D] Stopped
2021-12-07T19:06:54.349Z,1638904014.349 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:06:54.761Z,1638904014.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.334880 min 
2021-12-07T19:06:54.761Z,1638904014.761 [Default:CheckIn:E] Stopped
2021-12-07T19:06:54.761Z,1638904014.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:06:54.761Z,1638904014.761 [Default:CheckIn] Stopped
2021-12-07T19:06:54.761Z,1638904014.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:06:54.762Z,1638904014.762 [Default:CheckIn](INFO): Running loop #10
2021-12-07T19:06:54.762Z,1638904014.762 [Default:CheckIn] Running Loop=10
2021-12-07T19:06:54.762Z,1638904014.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:06:54.762Z,1638904014.762 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:06:56.766Z,1638904016.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190655.00,A,3644.09617,N,12149.97312,W,19.127,24.40,071221,,,D*73
2021-12-07T19:06:56.768Z,1638904016.768 [NAL9602](INFO): GPS fix at 20211207T190655: (36.734936, -121.832885)
2021-12-07T19:06:56.804Z,1638904016.804 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:06:56.804Z,1638904016.804 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:07:04.898Z,1638904024.898 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0015.lzma
2021-12-07T19:07:05.900Z,1638904025.900 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0015.lzma.bak
2021-12-07T19:07:05.900Z,1638904025.900 [DataOverHttps](INFO): SBD MOMSN=16335262
2021-12-07T19:07:13.731Z,1638904033.731 [NAL9602](INFO): SBD MO Status=0, MOMSN=17866, MT Status=0, MTMSN=0
2021-12-07T19:07:13.731Z,1638904033.731 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:07:22.329Z,1638904042.329 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T183600/Express0016.lzma
2021-12-07T19:07:23.328Z,1638904043.328 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0016.lzma.bak
2021-12-07T19:07:23.329Z,1638904043.329 [DataOverHttps](INFO): SBD MOMSN=16335265
2021-12-07T19:07:24.652Z,1638904044.652 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:07:24.652Z,1638904044.652 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:07:24.653Z,1638904044.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:07:44.432Z,1638904064.432 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:10:17.807Z,1638904217.807 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:10:28.851Z,1638904228.851 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.259369
2021-12-07T19:11:25.771Z,1638904285.771 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003296
2021-12-07T19:12:25.260Z,1638904345.260 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:12:25.260Z,1638904345.260 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:12:25.260Z,1638904345.260 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:12:25.260Z,1638904345.260 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:12:25.738Z,1638904345.738 [Default:CheckIn:D] Stopped
2021-12-07T19:12:25.739Z,1638904345.739 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:12:26.046Z,1638904346.046 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.858044 min 
2021-12-07T19:12:26.046Z,1638904346.046 [Default:CheckIn:E] Stopped
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn] Stopped
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn](INFO): Running loop #11
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn] Running Loop=11
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:12:26.047Z,1638904346.047 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:12:28.054Z,1638904348.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191227.00,A,3645.89458,N,12148.97858,W,21.927,27.10,071221,,,D*72
2021-12-07T19:12:28.056Z,1638904348.056 [NAL9602](INFO): GPS fix at 20211207T191227: (36.764910, -121.816310)
2021-12-07T19:12:28.096Z,1638904348.096 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:12:28.096Z,1638904348.096 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:12:36.110Z,1638904356.110 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211207T183600/Courier0018.lzma
2021-12-07T19:12:37.112Z,1638904357.112 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0018.lzma.bak
2021-12-07T19:12:37.113Z,1638904357.113 [DataOverHttps](INFO): SBD MOMSN=16335311
2021-12-07T19:12:41.786Z,1638904361.786 [NAL9602](INFO): SBD MO Status=0, MOMSN=17867, MT Status=0, MTMSN=0
2021-12-07T19:12:41.786Z,1638904361.786 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:12:53.751Z,1638904373.751 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20211207T183600/Express0019.lzma
2021-12-07T19:12:54.752Z,1638904374.752 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0019.lzma.bak
2021-12-07T19:12:54.753Z,1638904374.753 [DataOverHttps](INFO): SBD MOMSN=16335314
2021-12-07T19:12:55.939Z,1638904375.939 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:12:55.939Z,1638904375.939 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:12:55.939Z,1638904375.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:13:12.492Z,1638904392.492 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:14:01.499Z,1638904441.499 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:14:03.507Z,1638904443.507 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.255337
2021-12-07T19:14:36.639Z,1638904476.639 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:15:11.779Z,1638904511.779 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:15:46.935Z,1638904546.935 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:16:22.075Z,1638904582.075 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:16:57.215Z,1638904617.215 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:17:32.355Z,1638904652.355 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:17:56.516Z,1638904676.516 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:17:56.516Z,1638904676.516 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:17:56.516Z,1638904676.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:17:56.516Z,1638904676.516 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:17:56.936Z,1638904676.936 [Default:CheckIn:D] Stopped
2021-12-07T19:17:56.936Z,1638904676.936 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.378003 min 
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn:E] Stopped
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn] Stopped
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn](INFO): Running loop #12
2021-12-07T19:17:57.337Z,1638904677.337 [Default:CheckIn] Running Loop=12
2021-12-07T19:17:57.338Z,1638904677.338 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:17:57.338Z,1638904677.338 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:17:59.339Z,1638904679.339 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191758.00,A,3647.56120,N,12148.30511,W,22.665,6.78,071221,,,D*4F
2021-12-07T19:17:59.341Z,1638904679.341 [NAL9602](INFO): GPS fix at 20211207T191758: (36.792687, -121.805085)
2021-12-07T19:17:59.354Z,1638904679.354 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:17:59.354Z,1638904679.354 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:18:07.495Z,1638904687.495 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-12-07T19:18:29.175Z,1638904709.175 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003245
2021-12-07T19:18:29.718Z,1638904709.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=17868, MT Status=2, MTMSN=0
2021-12-07T19:18:29.718Z,1638904709.718 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:18:37.118Z,1638904717.118 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0021.lzma
2021-12-07T19:18:38.120Z,1638904718.120 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0021.lzma.bak
2021-12-07T19:18:38.121Z,1638904718.121 [DataOverHttps](INFO): SBD MOMSN=16335422
2021-12-07T19:18:54.407Z,1638904734.407 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20211207T183600/Express0022.lzma
2021-12-07T19:18:55.410Z,1638904735.410 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0022.lzma.bak
2021-12-07T19:18:55.410Z,1638904735.410 [DataOverHttps](INFO): SBD MOMSN=16335425
2021-12-07T19:18:56.451Z,1638904736.451 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:18:56.452Z,1638904736.452 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:18:56.452Z,1638904736.452 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:19:00.421Z,1638904740.421 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:23:56.983Z,1638905036.983 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:23:56.983Z,1638905036.983 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:23:56.983Z,1638905036.983 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:23:56.984Z,1638905036.984 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:23:57.380Z,1638905037.380 [Default:CheckIn:D] Stopped
2021-12-07T19:23:57.380Z,1638905037.380 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.385392 min 
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn:E] Stopped
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn] Stopped
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn](INFO): Running loop #13
2021-12-07T19:23:57.837Z,1638905037.837 [Default:CheckIn] Running Loop=13
2021-12-07T19:23:57.838Z,1638905037.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:23:57.838Z,1638905037.838 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:23:59.794Z,1638905039.794 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192359.00,A,3648.40492,N,12147.12373,W,4.840,182.79,071221,,,D*71
2021-12-07T19:23:59.796Z,1638905039.796 [NAL9602](INFO): GPS fix at 20211207T192359: (36.806749, -121.785396)
2021-12-07T19:23:59.851Z,1638905039.851 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:23:59.851Z,1638905039.851 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:24:08.246Z,1638905048.246 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0024.lzma
2021-12-07T19:24:09.248Z,1638905049.248 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0024.lzma.bak
2021-12-07T19:24:09.249Z,1638905049.249 [DataOverHttps](INFO): SBD MOMSN=16335446
2021-12-07T19:24:13.533Z,1638905053.533 [NAL9602](INFO): SBD MO Status=1, MOMSN=17868, MT Status=0, MTMSN=0
2021-12-07T19:24:13.534Z,1638905053.534 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:24:29.051Z,1638905069.051 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T183600/Express0025.lzma
2021-12-07T19:24:30.055Z,1638905070.055 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0025.lzma.bak
2021-12-07T19:24:30.056Z,1638905070.056 [DataOverHttps](INFO): SBD MOMSN=16335449
2021-12-07T19:24:31.408Z,1638905071.408 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:24:31.409Z,1638905071.409 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:24:31.409Z,1638905071.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:24:44.312Z,1638905084.312 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:29:32.044Z,1638905372.044 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:29:32.044Z,1638905372.044 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:29:32.044Z,1638905372.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:29:32.044Z,1638905372.044 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:29:32.447Z,1638905372.447 [Default:CheckIn:D] Stopped
2021-12-07T19:29:32.447Z,1638905372.447 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:29:32.849Z,1638905372.849 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.969857 min 
2021-12-07T19:29:32.849Z,1638905372.849 [Default:CheckIn:E] Stopped
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn] Stopped
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn](INFO): Running loop #14
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn] Running Loop=14
2021-12-07T19:29:32.850Z,1638905372.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:29:32.851Z,1638905372.851 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:29:34.866Z,1638905374.866 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192934.00,A,3648.12067,N,12147.23219,W,0.039,281.53,071221,,,D*7C
2021-12-07T19:29:34.868Z,1638905374.868 [NAL9602](INFO): GPS fix at 20211207T192934: (36.802011, -121.787203)
2021-12-07T19:29:34.910Z,1638905374.910 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:29:34.910Z,1638905374.910 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:29:42.466Z,1638905382.466 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0027.lzma
2021-12-07T19:29:43.472Z,1638905383.472 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0027.lzma.bak
2021-12-07T19:29:43.472Z,1638905383.472 [DataOverHttps](INFO): SBD MOMSN=16335456
2021-12-07T19:30:00.191Z,1638905400.191 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T183600/Express0028.lzma
2021-12-07T19:30:01.193Z,1638905401.193 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0028.lzma.bak
2021-12-07T19:30:01.193Z,1638905401.193 [DataOverHttps](INFO): SBD MOMSN=16335459
2021-12-07T19:30:02.368Z,1638905402.368 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:30:02.368Z,1638905402.368 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:30:02.368Z,1638905402.368 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:30:34.246Z,1638905434.246 [NAL9602](INFO): SBD MO Status=1, MOMSN=17869, MT Status=0, MTMSN=0
2021-12-07T19:30:34.246Z,1638905434.246 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:31:04.948Z,1638905464.948 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:34:57.708Z,1638905697.708 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-12-07T19:35:02.959Z,1638905702.959 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:35:02.959Z,1638905702.959 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:35:02.960Z,1638905702.960 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:35:02.961Z,1638905702.961 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:35:03.374Z,1638905703.374 [Default:CheckIn:D] Stopped
2021-12-07T19:35:03.374Z,1638905703.374 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:35:03.796Z,1638905703.796 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.485303 min 
2021-12-07T19:35:03.796Z,1638905703.796 [Default:CheckIn:E] Stopped
2021-12-07T19:35:03.796Z,1638905703.796 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:35:03.796Z,1638905703.796 [Default:CheckIn] Stopped
2021-12-07T19:35:03.797Z,1638905703.797 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:35:03.797Z,1638905703.797 [Default:CheckIn](INFO): Running loop #15
2021-12-07T19:35:03.797Z,1638905703.797 [Default:CheckIn] Running Loop=15
2021-12-07T19:35:03.797Z,1638905703.797 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:35:03.797Z,1638905703.797 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:35:05.789Z,1638905705.789 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193504.00,A,3648.12121,N,12147.23113,W,0.078,281.53,071221,,,A*78
2021-12-07T19:35:05.791Z,1638905705.791 [NAL9602](INFO): GPS fix at 20211207T193504: (36.802020, -121.787186)
2021-12-07T19:35:05.824Z,1638905705.824 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:35:05.824Z,1638905705.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:35:13.306Z,1638905713.306 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20211207T183600/Courier0030.lzma
2021-12-07T19:35:14.317Z,1638905714.317 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0030.lzma.bak
2021-12-07T19:35:14.317Z,1638905714.317 [DataOverHttps](INFO): SBD MOMSN=16335464
2021-12-07T19:35:28.808Z,1638905728.808 [NAL9602](INFO): SBD MO Status=2, MOMSN=17870, MT Status=2, MTMSN=0
2021-12-07T19:35:28.808Z,1638905728.808 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:35:30.883Z,1638905730.883 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20211207T183600/Express0031.lzma
2021-12-07T19:35:31.885Z,1638905731.885 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0031.lzma.bak
2021-12-07T19:35:31.885Z,1638905731.885 [DataOverHttps](INFO): SBD MOMSN=16335467
2021-12-07T19:35:33.276Z,1638905733.276 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:35:33.276Z,1638905733.276 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:35:33.276Z,1638905733.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:36:11.626Z,1638905771.626 [NAL9602](INFO): SBD MO Status=1, MOMSN=17870, MT Status=0, MTMSN=0
2021-12-07T19:36:11.626Z,1638905771.626 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:36:42.324Z,1638905802.324 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:40:33.884Z,1638906033.884 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:40:33.884Z,1638906033.884 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:40:33.884Z,1638906033.884 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:40:33.884Z,1638906033.884 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:40:34.264Z,1638906034.264 [Default:CheckIn:D] Stopped
2021-12-07T19:40:34.264Z,1638906034.264 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:40:34.674Z,1638906034.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.000138 min 
2021-12-07T19:40:34.674Z,1638906034.674 [Default:CheckIn:E] Stopped
2021-12-07T19:40:34.674Z,1638906034.674 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:40:34.674Z,1638906034.674 [Default:CheckIn] Stopped
2021-12-07T19:40:34.675Z,1638906034.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:40:34.675Z,1638906034.675 [Default:CheckIn](INFO): Running loop #16
2021-12-07T19:40:34.675Z,1638906034.675 [Default:CheckIn] Running Loop=16
2021-12-07T19:40:34.675Z,1638906034.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:40:34.675Z,1638906034.675 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:40:36.678Z,1638906036.678 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194035.00,A,3648.11983,N,12147.23328,W,0.019,3.80,071221,,,D*75
2021-12-07T19:40:36.680Z,1638906036.680 [NAL9602](INFO): GPS fix at 20211207T194035: (36.801997, -121.787221)
2021-12-07T19:40:36.715Z,1638906036.715 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:40:36.715Z,1638906036.715 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:40:44.878Z,1638906044.878 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0033.lzma
2021-12-07T19:40:45.880Z,1638906045.880 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0033.lzma.bak
2021-12-07T19:40:45.881Z,1638906045.881 [DataOverHttps](INFO): SBD MOMSN=16335489
2021-12-07T19:41:02.591Z,1638906062.591 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T183600/Express0034.lzma
2021-12-07T19:41:03.592Z,1638906063.592 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0034.lzma.bak
2021-12-07T19:41:03.593Z,1638906063.593 [DataOverHttps](INFO): SBD MOMSN=16335493
2021-12-07T19:41:04.985Z,1638906064.985 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:41:04.985Z,1638906064.985 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:41:04.985Z,1638906064.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:41:17.890Z,1638906077.890 [NAL9602](INFO): SBD MO Status=2, MOMSN=17871, MT Status=2, MTMSN=0
2021-12-07T19:41:17.890Z,1638906077.890 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:41:36.887Z,1638906096.887 [NAL9602](INFO): SBD MO Status=2, MOMSN=17871, MT Status=2, MTMSN=0
2021-12-07T19:41:36.888Z,1638906096.888 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:41:45.361Z,1638906105.361 [NAL9602](INFO): SBD MO Status=1, MOMSN=17871, MT Status=0, MTMSN=0
2021-12-07T19:41:45.361Z,1638906105.361 [NAL9602](INFO): No messages in MT queue
2021-12-07T19:42:16.068Z,1638906136.068 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:45:01.968Z,1638906301.968 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2021-12-07T19:46:05.408Z,1638906365.408 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:46:05.408Z,1638906365.408 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:46:05.408Z,1638906365.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:46:05.408Z,1638906365.408 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:46:05.843Z,1638906365.843 [Default:CheckIn:D] Stopped
2021-12-07T19:46:05.843Z,1638906365.843 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:46:06.203Z,1638906366.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.526457 min 
2021-12-07T19:46:06.203Z,1638906366.203 [Default:CheckIn:E] Stopped
2021-12-07T19:46:06.203Z,1638906366.203 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:46:06.203Z,1638906366.203 [Default:CheckIn] Stopped
2021-12-07T19:46:06.204Z,1638906366.204 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:46:06.204Z,1638906366.204 [Default:CheckIn](INFO): Running loop #17
2021-12-07T19:46:06.204Z,1638906366.204 [Default:CheckIn] Running Loop=17
2021-12-07T19:46:06.204Z,1638906366.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:46:06.204Z,1638906366.204 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:46:08.220Z,1638906368.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194607.00,A,3648.15065,N,12147.25322,W,2.857,3.82,071221,,,D*79
2021-12-07T19:46:08.222Z,1638906368.222 [NAL9602](INFO): GPS fix at 20211207T194607: (36.802511, -121.787554)
2021-12-07T19:46:08.234Z,1638906368.234 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:46:08.234Z,1638906368.234 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:46:18.402Z,1638906378.402 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T183600/Courier0036.lzma
2021-12-07T19:46:19.407Z,1638906379.407 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0036.lzma.bak
2021-12-07T19:46:19.407Z,1638906379.407 [DataOverHttps](INFO): SBD MOMSN=16335500
2021-12-07T19:46:32.145Z,1638906392.145 [NAL9602](INFO): SBD MO Status=2, MOMSN=17872, MT Status=2, MTMSN=0
2021-12-07T19:46:32.146Z,1638906392.146 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:46:38.739Z,1638906398.739 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211207T183600/Express0037.lzma
2021-12-07T19:46:39.741Z,1638906399.741 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0037.lzma.bak
2021-12-07T19:46:39.741Z,1638906399.741 [DataOverHttps](INFO): SBD MOMSN=16335503
2021-12-07T19:46:41.045Z,1638906401.045 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:46:41.046Z,1638906401.046 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:46:41.046Z,1638906401.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:47:04.076Z,1638906424.076 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-12-07T19:47:04.079Z,1638906424.079 [BPC1](INFO): Received data from all battery sticks.
2021-12-07T19:47:08.913Z,1638906428.913 [NAL9602](INFO): SBD MO Status=2, MOMSN=17872, MT Status=2, MTMSN=0
2021-12-07T19:47:08.914Z,1638906428.914 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-12-07T19:51:10.584Z,1638906670.584 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-07T19:51:41.288Z,1638906701.288 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:51:41.756Z,1638906701.756 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:51:41.756Z,1638906701.756 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:51:41.756Z,1638906701.756 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:51:41.757Z,1638906701.757 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:51:42.105Z,1638906702.105 [Default:CheckIn:D] Stopped
2021-12-07T19:51:42.105Z,1638906702.105 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:51:42.519Z,1638906702.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.130819 min 
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn:E] Stopped
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn] Stopped
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn](INFO): Running loop #18
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn] Running Loop=18
2021-12-07T19:51:42.520Z,1638906702.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:51:42.521Z,1638906702.521 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:51:44.527Z,1638906704.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195143.00,A,3648.16490,N,12147.27908,W,0.641,29.30,071221,,,D*48
2021-12-07T19:51:44.530Z,1638906704.530 [NAL9602](INFO): GPS fix at 20211207T195143: (36.802748, -121.787985)
2021-12-07T19:51:44.570Z,1638906704.570 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:51:44.570Z,1638906704.570 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:51:45.341Z,1638906705.341 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:51:45.341Z,1638906705.341 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:51:45.341Z,1638906705.341 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T19:56:45.924Z,1638907005.924 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T19:56:45.924Z,1638907005.924 [Default:CheckIn:C.Wait] Stopped
2021-12-07T19:56:45.924Z,1638907005.924 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T19:56:45.924Z,1638907005.924 [Default:CheckIn:D] Running Loop=1
2021-12-07T19:56:46.312Z,1638907006.312 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-07T19:56:46.342Z,1638907006.342 [Default:CheckIn:D] Stopped
2021-12-07T19:56:46.343Z,1638907006.343 [Default:CheckIn:E] Running Loop=1
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.201440 min 
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn:E] Stopped
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn] Stopped
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn](INFO): Running loop #19
2021-12-07T19:56:46.725Z,1638907006.725 [Default:CheckIn] Running Loop=19
2021-12-07T19:56:46.726Z,1638907006.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T19:56:46.726Z,1638907006.726 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T19:56:48.734Z,1638907008.734 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195647.00,A,3648.16535,N,12147.27901,W,0.428,102.50,071221,,,A*7A
2021-12-07T19:56:48.736Z,1638907008.736 [NAL9602](INFO): GPS fix at 20211207T195647: (36.802756, -121.787983)
2021-12-07T19:56:48.749Z,1638907008.749 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T19:56:48.749Z,1638907008.749 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T19:56:56.554Z,1638907016.554 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20211207T183600/Courier0039.lzma
2021-12-07T19:56:57.557Z,1638907017.557 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0039.lzma.bak
2021-12-07T19:56:57.557Z,1638907017.557 [DataOverHttps](INFO): SBD MOMSN=16335510
2021-12-07T19:57:13.926Z,1638907033.926 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T183600/Courier0042.lzma
2021-12-07T19:57:14.928Z,1638907034.928 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0042.lzma.bak
2021-12-07T19:57:14.929Z,1638907034.929 [DataOverHttps](INFO): SBD MOMSN=16335513
2021-12-07T19:57:21.489Z,1638907041.489 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T19:57:31.476Z,1638907051.476 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20211207T183600/Express0040.lzma
2021-12-07T19:57:32.469Z,1638907052.469 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0040.lzma.bak
2021-12-07T19:57:32.469Z,1638907052.469 [DataOverHttps](INFO): SBD MOMSN=16335516
2021-12-07T19:57:48.633Z,1638907068.633 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20211207T183600/Express0043.lzma
2021-12-07T19:57:49.633Z,1638907069.633 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0043.lzma.bak
2021-12-07T19:57:49.633Z,1638907069.633 [DataOverHttps](INFO): SBD MOMSN=16335521
2021-12-07T19:57:50.961Z,1638907070.961 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T19:57:50.962Z,1638907070.962 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T19:57:50.963Z,1638907070.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T20:02:51.629Z,1638907371.629 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T20:02:51.629Z,1638907371.629 [Default:CheckIn:C.Wait] Stopped
2021-12-07T20:02:51.629Z,1638907371.629 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T20:02:51.630Z,1638907371.630 [Default:CheckIn:D] Running Loop=1
2021-12-07T20:02:51.999Z,1638907371.999 [Default:CheckIn:D] Stopped
2021-12-07T20:02:51.999Z,1638907371.999 [Default:CheckIn:E] Running Loop=1
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.295728 min 
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn:E] Stopped
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn] Stopped
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn](INFO): Running loop #20
2021-12-07T20:02:52.410Z,1638907372.410 [Default:CheckIn] Running Loop=20
2021-12-07T20:02:52.411Z,1638907372.411 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T20:02:52.411Z,1638907372.411 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T20:02:54.410Z,1638907374.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200253.00,A,3648.16937,N,12147.28091,W,0.078,102.50,071221,,,A*74
2021-12-07T20:02:54.412Z,1638907374.412 [NAL9602](INFO): GPS fix at 20211207T200253: (36.802823, -121.788015)
2021-12-07T20:02:54.425Z,1638907374.425 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T20:02:54.425Z,1638907374.425 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T20:03:02.434Z,1638907382.434 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T183600/Courier0045.lzma
2021-12-07T20:03:03.440Z,1638907383.440 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0045.lzma.bak
2021-12-07T20:03:03.440Z,1638907383.440 [DataOverHttps](INFO): SBD MOMSN=16335526
2021-12-07T20:03:19.855Z,1638907399.855 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211207T183600/Express0046.lzma
2021-12-07T20:03:20.857Z,1638907400.857 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0046.lzma.bak
2021-12-07T20:03:20.857Z,1638907400.857 [DataOverHttps](INFO): SBD MOMSN=16335529
2021-12-07T20:03:21.926Z,1638907401.926 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T20:03:21.939Z,1638907401.939 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T20:03:21.939Z,1638907401.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T20:03:25.108Z,1638907405.108 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-12-07T20:03:25.183Z,1638907405.183 [NAL9602](ERROR): received: 
+CSQ:0

OK872, 2, 0, 0, 0

OK
2021-12-07T20:07:56.680Z,1638907676.680 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-07T20:08:22.565Z,1638907702.565 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-07T20:08:22.566Z,1638907702.566 [Default:CheckIn:C.Wait] Stopped
2021-12-07T20:08:22.566Z,1638907702.566 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T20:08:22.566Z,1638907702.566 [Default:CheckIn:D] Running Loop=1
2021-12-07T20:08:22.968Z,1638907702.968 [Default:CheckIn:D] Stopped
2021-12-07T20:08:22.968Z,1638907702.968 [Default:CheckIn:E] Running Loop=1
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.811873 min 
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn:E] Stopped
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn] Stopped
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn](INFO): Running loop #21
2021-12-07T20:08:23.361Z,1638907703.361 [Default:CheckIn] Running Loop=21
2021-12-07T20:08:23.362Z,1638907703.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-07T20:08:23.362Z,1638907703.362 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-07T20:08:25.370Z,1638907705.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200824.00,A,3648.16472,N,12147.28575,W,1.361,148.83,071221,,,A*77
2021-12-07T20:08:25.373Z,1638907705.373 [NAL9602](INFO): GPS fix at 20211207T200824: (36.802745, -121.788096)
2021-12-07T20:08:25.385Z,1638907705.385 [Default:CheckIn:Read_GPS] Stopped
2021-12-07T20:08:25.385Z,1638907705.385 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-07T20:08:33.674Z,1638907713.674 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T183600/Courier0048.lzma
2021-12-07T20:08:34.677Z,1638907714.677 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Courier0048.lzma.bak
2021-12-07T20:08:34.677Z,1638907714.677 [DataOverHttps](INFO): SBD MOMSN=16335582
2021-12-07T20:08:50.991Z,1638907730.991 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20211207T183600/Express0049.lzma
2021-12-07T20:08:51.993Z,1638907731.993 [DataOverHttps](INFO): Moved sent file to Logs/20211207T183600/Express0049.lzma.bak
2021-12-07T20:08:51.993Z,1638907731.993 [DataOverHttps](INFO): SBD MOMSN=16335585
2021-12-07T20:08:53.264Z,1638907733.264 [Default:CheckIn:Read_Iridium] Stopped
2021-12-07T20:08:53.264Z,1638907733.264 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-07T20:08:53.264Z,1638907733.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-07T20:08:57.684Z,1638907737.684 [NAL9602](INFO): Not Powering down - fast GPS
2021-12-07T20:11:36.866Z,1638907896.866 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2021-12-07T20:11:36.866Z,1638907896.866 [DropWeight] Hardware Fault, FailCount= 1
2021-12-07T20:11:36.866Z,1638907896.866 [DropWeight](ERROR): Hardware Fault
2021-12-07T20:11:36.887Z,1638907896.887 [CommandExec](FAULT): Scheduling is paused
2021-12-07T20:11:36.888Z,1638907896.888 [CBIT](INFO): Critical error at 20211207T201136
2021-12-07T20:11:36.888Z,1638907896.888 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-12-07T20:11:36.890Z,1638907896.890 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-12-07T20:11:36.891Z,1638907896.891 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-12-07T20:11:37.312Z,1638907897.312 [CBIT](INFO): Critical error at 20211207T201136
2021-12-07T20:13:30.447Z,1638908010.447 [CommandExec](IMPORTANT): got command help
2021-12-07T20:13:36.983Z,1638908016.983 [CommandExec](IMPORTANT): got command quit
2021-12-07T20:13:37.988Z,1638908017.988 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:37.989Z,1638908017.989 [CommandExec](INFO): Uninitializing the command executive.
2021-12-07T20:13:37.989Z,1638908017.989 [CommandExec](INFO): Uninitializing the command scheduler.
2021-12-07T20:13:37.990Z,1638908017.990 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.083Z,1638908018.083 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-12-07T20:13:38.083Z,1638908018.083 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-12-07T20:13:38.083Z,1638908018.083 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.084Z,1638908018.084 [NavChartDb](INFO): Join timeout helper Thread ID is 2576
2021-12-07T20:13:38.215Z,1638908018.215 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:38.215Z,1638908018.215 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.219Z,1638908018.219 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2021-12-07T20:13:38.219Z,1638908018.219 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.219Z,1638908018.219 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 2577
2021-12-07T20:13:38.247Z,1638908018.247 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:38.247Z,1638908018.247 [WetLabsUBAT](INFO): Powering down
2021-12-07T20:13:38.248Z,1638908018.248 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.259Z,1638908018.259 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-12-07T20:13:38.259Z,1638908018.259 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.259Z,1638908018.259 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2578
2021-12-07T20:13:38.659Z,1638908018.659 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:38.659Z,1638908018.659 [WetLabsBB2FL](INFO): Powering down
2021-12-07T20:13:38.660Z,1638908018.660 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.671Z,1638908018.671 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-12-07T20:13:38.671Z,1638908018.671 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:38.671Z,1638908018.671 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2579
2021-12-07T20:13:39.559Z,1638908019.559 [CTD_Seabird](INFO): Powering down
2021-12-07T20:13:39.571Z,1638908019.571 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:39.571Z,1638908019.571 [CTD_Seabird](INFO): Powering down
2021-12-07T20:13:39.591Z,1638908019.591 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:39.598Z,1638908019.598 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-12-07T20:13:39.598Z,1638908019.598 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:39.598Z,1638908019.598 [Radio_Surface](INFO): Join timeout helper Thread ID is 2580
2021-12-07T20:13:39.867Z,1638908019.867 [Radio_Surface](INFO): Powering down
2021-12-07T20:13:39.868Z,1638908019.868 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:39.868Z,1638908019.868 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:39.880Z,1638908019.880 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-12-07T20:13:39.880Z,1638908019.880 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:39.880Z,1638908019.880 [Onboard](INFO): Join timeout helper Thread ID is 2581
2021-12-07T20:13:44.499Z,1638908024.499 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:44.499Z,1638908024.499 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:44.519Z,1638908024.519 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-12-07T20:13:44.520Z,1638908024.520 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:44.520Z,1638908024.520 [DataOverHttps](INFO): Join timeout helper Thread ID is 2582
2021-12-07T20:13:45.279Z,1638908025.279 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:45.282Z,1638908025.282 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.295Z,1638908025.295 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-12-07T20:13:45.295Z,1638908025.295 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.296Z,1638908025.296 [BackseatComponent](INFO): Join timeout helper Thread ID is 2583
2021-12-07T20:13:45.436Z,1638908025.436 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:45.437Z,1638908025.437 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.449Z,1638908025.449 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-12-07T20:13:45.449Z,1638908025.449 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.450Z,1638908025.450 [logger](INFO): Join timeout helper Thread ID is 2584
2021-12-07T20:13:45.495Z,1638908025.495 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:45.496Z,1638908025.496 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.501Z,1638908025.501 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-12-07T20:13:45.501Z,1638908025.501 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.502Z,1638908025.502 [CommandLine](INFO): Join timeout helper Thread ID is 2585
2021-12-07T20:13:45.583Z,1638908025.583 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:45.583Z,1638908025.583 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.603Z,1638908025.603 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-12-07T20:13:45.603Z,1638908025.603 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.604Z,1638908025.604 [CommandExec](INFO): Join timeout helper Thread ID is 2586
2021-12-07T20:13:45.605Z,1638908025.605 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-12-07T20:13:45.605Z,1638908025.605 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:45.605Z,1638908025.605 [controlThread](INFO): Join timeout helper Thread ID is 2587
2021-12-07T20:13:45.719Z,1638908025.719 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-07T20:13:45.719Z,1638908025.719 [controlThread](DEBUG): Uninitializing ControlThread
2021-12-07T20:13:45.720Z,1638908025.720 [AHRS_M2](INFO): Powering down
2021-12-07T20:13:45.791Z,1638908025.791 [NAL9602](INFO): Powering down
2021-12-07T20:13:45.863Z,1638908025.863 [RDI_Pathfinder](INFO): Powering down
2021-12-07T20:13:45.864Z,1638908025.864 [DAT](INFO): Powering down
2021-12-07T20:13:45.935Z,1638908025.935 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-12-07T20:13:45.936Z,1638908025.936 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-12-07T20:13:45.937Z,1638908025.937 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-12-07T20:13:45.937Z,1638908025.937 [MissionManager](INFO): Uninitializing Mission Default
2021-12-07T20:13:45.938Z,1638908025.938 [Default] Stopped
2021-12-07T20:13:45.938Z,1638908025.938 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-07T20:13:45.938Z,1638908025.938 [Default:B.GoToSurface] Stopped
2021-12-07T20:13:45.938Z,1638908025.938 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-07T20:13:45.938Z,1638908025.938 [Default:CheckIn] Stopped
2021-12-07T20:13:45.938Z,1638908025.938 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-07T20:13:45.938Z,1638908025.938 [Default:CheckIn:C.Wait] Stopped
2021-12-07T20:13:45.938Z,1638908025.938 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-07T20:13:45.941Z,1638908025.941 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-12-07T20:13:45.942Z,1638908025.942 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-12-07T20:13:45.942Z,1638908025.942 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-12-07T20:13:45.942Z,1638908025.942 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-12-07T20:13:45.943Z,1638908025.943 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-12-07T20:13:45.943Z,1638908025.943 [BuoyancyServo](INFO): Powering down
2021-12-07T20:13:45.955Z,1638908025.955 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-12-07T20:13:45.955Z,1638908025.955 [ElevatorServo](INFO): Powering down
2021-12-07T20:13:45.956Z,1638908025.956 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-12-07T20:13:45.956Z,1638908025.956 [MassServo](INFO): Powering down
2021-12-07T20:13:45.957Z,1638908025.957 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-07T20:13:45.957Z,1638908025.957 [RudderServo](INFO): Powering down
2021-12-07T20:13:45.958Z,1638908025.958 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-12-07T20:13:45.958Z,1638908025.958 [ThrusterServo](INFO): Powering down
2021-12-07T20:13:45.959Z,1638908025.959 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-12-07T20:13:45.959Z,1638908025.959 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-12-07T20:13:45.960Z,1638908025.960 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-12-07T20:13:45.960Z,1638908025.960 [CBIT](DEBUG): Powering off loads.
2021-12-07T20:13:45.970Z,1638908025.970 [CBIT](DEBUG): Disabling WDT.
2021-12-07T20:13:45.982Z,1638908025.982 [CBIT](DEBUG): Opening all GF detection circuits.
2021-12-07T20:13:45.984Z,1638908025.984 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.050Z,1638908026.050 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.053Z,1638908026.053 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.059Z,1638908026.059 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.104Z,1638908026.104 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.159Z,1638908026.159 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.161Z,1638908026.161 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.165Z,1638908026.165 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.172Z,1638908026.172 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-07T20:13:46.263Z,1638908026.263 [logger ThreadHandler](INFO): Thread cancelled.