2021-07-21T17:54:57.478Z,1626890097.478 [CommandLine](IMPORTANT): got command restart logs
2021-07-21T17:56:09.628Z,1626890169.628 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T17:56:09.628Z,1626890169.628 [Default:CheckIn:C.Wait] Stopped
2021-07-21T17:56:09.628Z,1626890169.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T17:56:09.629Z,1626890169.629 [Default:CheckIn:D] Running Loop=1
2021-07-21T17:56:10.040Z,1626890170.040 [Default:CheckIn:D] Stopped
2021-07-21T17:56:10.040Z,1626890170.040 [Default:CheckIn:E] Running Loop=1
2021-07-21T17:56:10.445Z,1626890170.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.919984 min 
2021-07-21T17:56:10.449Z,1626890170.449 [Default:CheckIn:E] Stopped
2021-07-21T17:56:10.449Z,1626890170.449 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T17:56:10.449Z,1626890170.449 [Default:CheckIn] Stopped
2021-07-21T17:56:10.449Z,1626890170.449 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T17:56:10.450Z,1626890170.450 [Default:CheckIn](INFO): Running loop #2
2021-07-21T17:56:10.450Z,1626890170.450 [Default:CheckIn] Running Loop=2
2021-07-21T17:56:10.450Z,1626890170.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T17:56:10.450Z,1626890170.450 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T17:56:12.444Z,1626890172.444 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175602.00,A,3648.16604,N,12147.28321,W,0.097,0.00,210721,,,D*70
2021-07-21T17:56:12.447Z,1626890172.447 [NAL9602](INFO): GPS fix at 20210721T175602: (36.802767, -121.788054)
2021-07-21T17:56:12.457Z,1626890172.457 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T17:56:12.458Z,1626890172.458 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T17:56:21.508Z,1626890181.508 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210721T171344/Courier0016.lzma
2021-07-21T17:56:22.511Z,1626890182.511 [DataOverHttps](INFO): Moved sent file to Logs/20210721T171344/Courier0016.lzma.bak
2021-07-21T17:56:22.511Z,1626890182.511 [DataOverHttps](INFO): SBD MOMSN=15751530
2021-07-21T17:56:44.305Z,1626890204.305 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210721T175457/Courier0000.lzma
2021-07-21T17:56:45.347Z,1626890205.347 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0000.lzma.bak
2021-07-21T17:56:45.347Z,1626890205.347 [DataOverHttps](INFO): SBD MOMSN=15751532
2021-07-21T17:57:05.997Z,1626890225.997 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20210721T171344/Express0017.lzma
2021-07-21T17:57:06.999Z,1626890226.999 [DataOverHttps](INFO): Moved sent file to Logs/20210721T171344/Express0017.lzma.bak
2021-07-21T17:57:06.999Z,1626890226.999 [DataOverHttps](INFO): SBD MOMSN=15751536
2021-07-21T17:57:14.788Z,1626890234.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=28499, MT Status=2, MTMSN=0
2021-07-21T17:57:14.788Z,1626890234.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T17:57:24.833Z,1626890244.833 [DataOverHttps](INFO): Sending 383 bytes from file Logs/20210721T175457/Express0001.lzma
2021-07-21T17:57:25.835Z,1626890245.835 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0001.lzma.bak
2021-07-21T17:57:25.835Z,1626890245.835 [DataOverHttps](INFO): SBD MOMSN=15751539
2021-07-21T17:57:40.644Z,1626890260.644 [NAL9602](INFO): SBD MO Status=2, MOMSN=28499, MT Status=2, MTMSN=0
2021-07-21T17:57:40.644Z,1626890260.644 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T17:57:43.575Z,1626890263.575 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210721T175457/Express0004.lzma
2021-07-21T17:57:44.575Z,1626890264.575 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0004.lzma.bak
2021-07-21T17:57:44.575Z,1626890264.575 [DataOverHttps](INFO): SBD MOMSN=15751543
2021-07-21T17:57:47.937Z,1626890267.937 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T17:57:47.938Z,1626890267.938 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T17:57:47.938Z,1626890267.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T17:57:56.400Z,1626890276.400 [NAL9602](INFO): SBD MO Status=2, MOMSN=28499, MT Status=2, MTMSN=0
2021-07-21T17:57:56.400Z,1626890276.400 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T17:58:41.300Z,1626890321.300 [NAL9602](INFO): SBD MO Status=2, MOMSN=28499, MT Status=2, MTMSN=0
2021-07-21T17:58:41.300Z,1626890321.300 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T17:59:06.762Z,1626890346.762 [NAL9602](INFO): SBD MO Status=2, MOMSN=28499, MT Status=2, MTMSN=0
2021-07-21T17:59:06.762Z,1626890346.762 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T17:59:44.332Z,1626890384.332 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=28499, MT Status=1, MTMSN=2606
2021-07-21T17:59:44.332Z,1626890384.332 [NAL9602](INFO): Data available in MT queue
2021-07-21T17:59:44.822Z,1626890384.822 [NAL9602](INFO): Received command:strobe off
2021-07-21T17:59:44.829Z,1626890384.829 [CommandLine](IMPORTANT): got command strobe off
2021-07-21T17:59:44.829Z,1626890384.829 [CommandLine](IMPORTANT): Deactivating strobe
2021-07-21T18:00:15.435Z,1626890415.435 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:02:48.725Z,1626890568.725 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T18:02:48.725Z,1626890568.725 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:02:48.725Z,1626890568.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:02:48.726Z,1626890568.726 [Default:CheckIn:D] Running Loop=1
2021-07-21T18:02:49.112Z,1626890569.112 [Default:CheckIn:D] Stopped
2021-07-21T18:02:49.113Z,1626890569.113 [Default:CheckIn:E] Running Loop=1
2021-07-21T18:02:49.513Z,1626890569.513 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.571193 min 
2021-07-21T18:02:49.513Z,1626890569.513 [Default:CheckIn:E] Stopped
2021-07-21T18:02:49.513Z,1626890569.513 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn] Stopped
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn](INFO): Running loop #3
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn] Running Loop=3
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T18:02:49.514Z,1626890569.514 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T18:02:51.524Z,1626890571.524 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180241.00,A,3648.16225,N,12147.28227,W,0.564,0.00,210721,,,D*70
2021-07-21T18:02:51.527Z,1626890571.527 [NAL9602](INFO): GPS fix at 20210721T180241: (36.802704, -121.788038)
2021-07-21T18:02:51.574Z,1626890571.574 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T18:02:51.574Z,1626890571.574 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T18:03:00.168Z,1626890580.168 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210721T175457/Courier0006.lzma
2021-07-21T18:03:01.171Z,1626890581.171 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0006.lzma.bak
2021-07-21T18:03:01.171Z,1626890581.171 [DataOverHttps](INFO): SBD MOMSN=15751554
2021-07-21T18:03:18.938Z,1626890598.938 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20210721T175457/Express0007.lzma
2021-07-21T18:03:19.939Z,1626890599.939 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0007.lzma.bak
2021-07-21T18:03:19.939Z,1626890599.939 [DataOverHttps](INFO): SBD MOMSN=15751557
2021-07-21T18:03:23.097Z,1626890603.097 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T18:03:23.097Z,1626890603.097 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T18:03:23.097Z,1626890603.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T18:04:56.420Z,1626890696.420 [NAL9602](INFO): SBD MO Status=2, MOMSN=28500, MT Status=2, MTMSN=0
2021-07-21T18:04:56.420Z,1626890696.420 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:05:14.192Z,1626890714.192 [NAL9602](INFO): SBD MO Status=2, MOMSN=28500, MT Status=2, MTMSN=0
2021-07-21T18:05:14.192Z,1626890714.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:05:48.935Z,1626890748.935 [NAL9602](INFO): SBD MO Status=2, MOMSN=28500, MT Status=2, MTMSN=0
2021-07-21T18:05:48.936Z,1626890748.936 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:06:18.832Z,1626890778.832 [NAL9602](INFO): SBD MO Status=2, MOMSN=28500, MT Status=2, MTMSN=0
2021-07-21T18:06:18.832Z,1626890778.832 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:06:39.063Z,1626890799.063 [NAL9602](INFO): SBD MO Status=1, MOMSN=28500, MT Status=0, MTMSN=0
2021-07-21T18:06:39.063Z,1626890799.063 [NAL9602](INFO): No messages in MT queue
2021-07-21T18:07:09.798Z,1626890829.798 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:08:23.740Z,1626890903.740 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T18:08:23.740Z,1626890903.740 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:08:23.740Z,1626890903.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:08:23.740Z,1626890903.740 [Default:CheckIn:D] Running Loop=1
2021-07-21T18:08:24.149Z,1626890904.149 [Default:CheckIn:D] Stopped
2021-07-21T18:08:24.149Z,1626890904.149 [Default:CheckIn:E] Running Loop=1
2021-07-21T18:08:24.558Z,1626890904.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.155133 min 
2021-07-21T18:08:24.558Z,1626890904.558 [Default:CheckIn:E] Stopped
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn] Stopped
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn](INFO): Running loop #4
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn] Running Loop=4
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T18:08:24.559Z,1626890904.559 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T18:08:26.560Z,1626890906.560 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180816.00,A,3648.16378,N,12147.28436,W,0.214,0.00,210721,,,D*77
2021-07-21T18:08:26.562Z,1626890906.562 [NAL9602](INFO): GPS fix at 20210721T180816: (36.802730, -121.788073)
2021-07-21T18:08:26.609Z,1626890906.609 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T18:08:26.609Z,1626890906.609 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T18:08:39.333Z,1626890919.333 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210721T175457/Courier0009.lzma
2021-07-21T18:08:40.335Z,1626890920.335 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0009.lzma.bak
2021-07-21T18:08:40.335Z,1626890920.335 [DataOverHttps](INFO): SBD MOMSN=15751569
2021-07-21T18:09:03.761Z,1626890943.761 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210721T175457/Express0010.lzma
2021-07-21T18:09:04.763Z,1626890944.763 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0010.lzma.bak
2021-07-21T18:09:04.763Z,1626890944.763 [DataOverHttps](INFO): SBD MOMSN=15751574
2021-07-21T18:09:07.833Z,1626890947.833 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T18:09:07.833Z,1626890947.833 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T18:09:07.833Z,1626890947.833 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T18:11:27.731Z,1626891087.731 [CommandLine](IMPORTANT): got command show best depth
2021-07-21T18:11:27.731Z,1626891087.731 [CommandLine](IMPORTANT): depth best is Depth_Keller.depth
2021-07-21T18:13:29.220Z,1626891209.220 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-21T18:13:59.930Z,1626891239.930 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:14:08.427Z,1626891248.427 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T18:14:08.428Z,1626891248.428 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:14:08.428Z,1626891248.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:14:08.428Z,1626891248.428 [Default:CheckIn:D] Running Loop=1
2021-07-21T18:14:08.821Z,1626891248.821 [Default:CheckIn:D] Stopped
2021-07-21T18:14:08.821Z,1626891248.821 [Default:CheckIn:E] Running Loop=1
2021-07-21T18:14:09.229Z,1626891249.229 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.899664 min 
2021-07-21T18:14:09.229Z,1626891249.229 [Default:CheckIn:E] Stopped
2021-07-21T18:14:09.229Z,1626891249.229 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T18:14:09.229Z,1626891249.229 [Default:CheckIn] Stopped
2021-07-21T18:14:09.230Z,1626891249.230 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:14:09.230Z,1626891249.230 [Default:CheckIn](INFO): Running loop #5
2021-07-21T18:14:09.230Z,1626891249.230 [Default:CheckIn] Running Loop=5
2021-07-21T18:14:09.230Z,1626891249.230 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T18:14:09.230Z,1626891249.230 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T18:14:11.238Z,1626891251.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181401.00,A,3648.16487,N,12147.28175,W,0.078,47.99,210721,,,D*42
2021-07-21T18:14:11.240Z,1626891251.240 [NAL9602](INFO): GPS fix at 20210721T181401: (36.802748, -121.788029)
2021-07-21T18:14:11.251Z,1626891251.251 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T18:14:11.252Z,1626891251.252 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T18:14:19.841Z,1626891259.841 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210721T175457/Courier0012.lzma
2021-07-21T18:14:20.843Z,1626891260.843 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0012.lzma.bak
2021-07-21T18:14:20.843Z,1626891260.843 [DataOverHttps](INFO): SBD MOMSN=15751577
2021-07-21T18:14:42.039Z,1626891282.039 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-07-21T18:14:42.121Z,1626891282.121 [NAL9602](ERROR): received: 
+CSQ:0

OK500, 0, 0, 0, 0

OK
2021-07-21T18:14:46.157Z,1626891286.157 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20210721T175457/Express0013.lzma
2021-07-21T18:14:47.159Z,1626891287.159 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0013.lzma.bak
2021-07-21T18:14:47.159Z,1626891287.159 [DataOverHttps](INFO): SBD MOMSN=15751580
2021-07-21T18:14:52.221Z,1626891292.221 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T18:14:52.221Z,1626891292.221 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T18:14:52.221Z,1626891292.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T18:14:57.420Z,1626891297.420 [NAL9602](INFO): SBD MO Status=2, MOMSN=28501, MT Status=2, MTMSN=0
2021-07-21T18:14:57.420Z,1626891297.420 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:15:17.624Z,1626891317.624 [NAL9602](INFO): SBD MO Status=1, MOMSN=28501, MT Status=0, MTMSN=0
2021-07-21T18:15:17.624Z,1626891317.624 [NAL9602](INFO): No messages in MT queue
2021-07-21T18:15:48.329Z,1626891348.329 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:19:52.876Z,1626891592.876 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T18:19:52.876Z,1626891592.876 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:19:52.876Z,1626891592.876 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:19:52.877Z,1626891592.877 [Default:CheckIn:D] Running Loop=1
2021-07-21T18:19:53.288Z,1626891593.288 [Default:CheckIn:D] Stopped
2021-07-21T18:19:53.288Z,1626891593.288 [Default:CheckIn:E] Running Loop=1
2021-07-21T18:19:53.681Z,1626891593.681 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.640784 min 
2021-07-21T18:19:53.681Z,1626891593.681 [Default:CheckIn:E] Stopped
2021-07-21T18:19:53.681Z,1626891593.681 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T18:19:53.681Z,1626891593.681 [Default:CheckIn] Stopped
2021-07-21T18:19:53.682Z,1626891593.682 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:19:53.682Z,1626891593.682 [Default:CheckIn](INFO): Running loop #6
2021-07-21T18:19:53.682Z,1626891593.682 [Default:CheckIn] Running Loop=6
2021-07-21T18:19:53.682Z,1626891593.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T18:19:53.682Z,1626891593.682 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T18:19:55.688Z,1626891595.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181945.00,A,3648.16401,N,12147.28449,W,0.175,47.99,210721,,,D*47
2021-07-21T18:19:55.691Z,1626891595.691 [NAL9602](INFO): GPS fix at 20210721T181945: (36.802734, -121.788075)
2021-07-21T18:19:55.702Z,1626891595.702 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T18:19:55.702Z,1626891595.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T18:20:03.704Z,1626891603.704 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210721T175457/Courier0015.lzma
2021-07-21T18:20:04.707Z,1626891604.707 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0015.lzma.bak
2021-07-21T18:20:04.707Z,1626891604.707 [DataOverHttps](INFO): SBD MOMSN=15751598
2021-07-21T18:20:22.677Z,1626891622.677 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210721T175457/Express0016.lzma
2021-07-21T18:20:23.679Z,1626891623.679 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0016.lzma.bak
2021-07-21T18:20:23.679Z,1626891623.679 [DataOverHttps](INFO): SBD MOMSN=15751601
2021-07-21T18:20:26.840Z,1626891626.840 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T18:20:26.840Z,1626891626.840 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T18:20:26.840Z,1626891626.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T18:22:47.180Z,1626891767.180 [NAL9602](INFO): SBD MO Status=2, MOMSN=28502, MT Status=2, MTMSN=0
2021-07-21T18:22:47.180Z,1626891767.180 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:23:03.336Z,1626891783.336 [NAL9602](INFO): SBD MO Status=2, MOMSN=28502, MT Status=2, MTMSN=0
2021-07-21T18:23:03.336Z,1626891783.336 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-21T18:23:19.896Z,1626891799.896 [NAL9602](INFO): SBD MO Status=1, MOMSN=28502, MT Status=0, MTMSN=0
2021-07-21T18:23:19.896Z,1626891799.896 [NAL9602](INFO): No messages in MT queue
2021-07-21T18:23:50.664Z,1626891830.664 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:25:01.305Z,1626891901.305 [CommandLine](IMPORTANT): got command show variable limiLo
2021-07-21T18:25:13.040Z,1626891913.040 [CommandLine](IMPORTANT): got command show variable limitL
2021-07-21T18:25:13.094Z,1626891913.094 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitLoCC (cubic_centimeter)
2021-07-21T18:25:13.105Z,1626891913.105 [CommandLine](IMPORTANT): BuoyancyServo.limitLo (count)
2021-07-21T18:25:13.106Z,1626891913.106 [CommandLine](IMPORTANT): DockingServo.limitLo (count)
2021-07-21T18:25:13.108Z,1626891913.108 [CommandLine](IMPORTANT): ElevatorServo.limitLo (count)
2021-07-21T18:25:13.109Z,1626891913.109 [CommandLine](IMPORTANT): MassServo.limitLo (count)
2021-07-21T18:25:13.110Z,1626891913.110 [CommandLine](IMPORTANT): RudderServo.limitLo (count)
2021-07-21T18:25:24.867Z,1626891924.867 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyLimitLoCC
2021-07-21T18:25:24.868Z,1626891924.868 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitLoCC 30.000000 cc
2021-07-21T18:25:27.613Z,1626891927.613 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-21T18:25:27.614Z,1626891927.614 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:25:27.614Z,1626891927.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:25:27.614Z,1626891927.614 [Default:CheckIn:D] Running Loop=1
2021-07-21T18:25:27.996Z,1626891927.996 [Default:CheckIn:D] Stopped
2021-07-21T18:25:27.996Z,1626891927.996 [Default:CheckIn:E] Running Loop=1
2021-07-21T18:25:28.400Z,1626891928.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.219255 min 
2021-07-21T18:25:28.400Z,1626891928.400 [Default:CheckIn:E] Stopped
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn] Stopped
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn](INFO): Running loop #7
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn] Running Loop=7
2021-07-21T18:25:28.401Z,1626891928.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-21T18:25:28.402Z,1626891928.402 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-21T18:25:30.407Z,1626891930.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182520.00,A,3648.16340,N,12147.28462,W,0.292,47.99,210721,,,D*4A
2021-07-21T18:25:30.409Z,1626891930.409 [NAL9602](INFO): GPS fix at 20210721T182520: (36.802723, -121.788077)
2021-07-21T18:25:30.420Z,1626891930.420 [Default:CheckIn:Read_GPS] Stopped
2021-07-21T18:25:30.421Z,1626891930.421 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-21T18:25:32.424Z,1626891932.424 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyLimitHiCC
2021-07-21T18:25:32.424Z,1626891932.424 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitHiCC 955.000000 cc
2021-07-21T18:25:39.037Z,1626891939.037 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210721T175457/Courier0018.lzma
2021-07-21T18:25:40.039Z,1626891940.039 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Courier0018.lzma.bak
2021-07-21T18:25:40.039Z,1626891940.039 [DataOverHttps](INFO): SBD MOMSN=15751605
2021-07-21T18:25:56.272Z,1626891956.272 [NAL9602](INFO): SBD MO Status=1, MOMSN=28503, MT Status=0, MTMSN=0
2021-07-21T18:25:56.272Z,1626891956.272 [NAL9602](INFO): No messages in MT queue
2021-07-21T18:25:57.845Z,1626891957.845 [DataOverHttps](INFO): Sending 315 bytes from file Logs/20210721T175457/Express0019.lzma
2021-07-21T18:25:58.847Z,1626891958.847 [DataOverHttps](INFO): Moved sent file to Logs/20210721T175457/Express0019.lzma.bak
2021-07-21T18:25:58.847Z,1626891958.847 [DataOverHttps](INFO): SBD MOMSN=15751611
2021-07-21T18:26:01.935Z,1626891961.935 [Default:CheckIn:Read_Iridium] Stopped
2021-07-21T18:26:01.935Z,1626891961.935 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-21T18:26:01.935Z,1626891961.935 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-21T18:26:26.966Z,1626891986.966 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-21T18:27:52.222Z,1626892072.222 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-07-21T18:27:52.225Z,1626892072.225 [BPC1](INFO): Received data from all battery sticks.
2021-07-21T18:28:51.910Z,1626892131.910 [DataOverHttps](IMPORTANT): SBD MTMSN=20210721T182841
2021-07-21T18:28:59.301Z,1626892139.301 [DataOverHttps](INFO): Received command:restart app
2021-07-21T18:28:59.344Z,1626892139.344 [CommandLine](IMPORTANT): got command restart application
2021-07-21T18:29:00.349Z,1626892140.349 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-07-21T18:29:00.349Z,1626892140.349 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:00.350Z,1626892140.350 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.461Z,1626892140.461 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-07-21T18:29:00.461Z,1626892140.461 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.462Z,1626892140.462 [CommandLine](INFO): Join timeout helper Thread ID is 1576
2021-07-21T18:29:00.462Z,1626892140.462 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-07-21T18:29:00.462Z,1626892140.462 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.463Z,1626892140.463 [NavChartDb](INFO): Join timeout helper Thread ID is 1577
2021-07-21T18:29:00.849Z,1626892140.849 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:00.849Z,1626892140.849 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.869Z,1626892140.869 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-07-21T18:29:00.869Z,1626892140.869 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.869Z,1626892140.869 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1578
2021-07-21T18:29:00.909Z,1626892140.909 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:00.910Z,1626892140.910 [WetLabsBB2FL](INFO): Powering down
2021-07-21T18:29:00.910Z,1626892140.910 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.914Z,1626892140.914 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-07-21T18:29:00.914Z,1626892140.914 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:00.914Z,1626892140.914 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1579
2021-07-21T18:29:01.473Z,1626892141.473 [CTD_Seabird](INFO): Powering down
2021-07-21T18:29:01.485Z,1626892141.485 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:01.485Z,1626892141.485 [CTD_Seabird](INFO): Powering down
2021-07-21T18:29:01.497Z,1626892141.497 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:01.509Z,1626892141.509 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-07-21T18:29:01.509Z,1626892141.509 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:01.509Z,1626892141.509 [Radio_Surface](INFO): Join timeout helper Thread ID is 1580
2021-07-21T18:29:01.633Z,1626892141.633 [Radio_Surface](INFO): Powering down
2021-07-21T18:29:01.634Z,1626892141.634 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:01.634Z,1626892141.634 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:01.650Z,1626892141.650 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-07-21T18:29:01.650Z,1626892141.650 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:01.650Z,1626892141.650 [Onboard](INFO): Join timeout helper Thread ID is 1581
2021-07-21T18:29:02.309Z,1626892142.309 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-07-21T18:29:03.414Z,1626892143.414 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:03.414Z,1626892143.414 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:03.430Z,1626892143.430 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-07-21T18:29:03.430Z,1626892143.430 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:03.430Z,1626892143.430 [DataOverHttps](INFO): Join timeout helper Thread ID is 1582
2021-07-21T18:29:04.318Z,1626892144.318 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:04.318Z,1626892144.318 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.338Z,1626892144.338 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-07-21T18:29:04.338Z,1626892144.338 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.338Z,1626892144.338 [logger](INFO): Join timeout helper Thread ID is 1583
2021-07-21T18:29:04.353Z,1626892144.353 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:04.353Z,1626892144.353 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.358Z,1626892144.358 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-07-21T18:29:04.358Z,1626892144.358 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.358Z,1626892144.358 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-07-21T18:29:04.358Z,1626892144.358 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.358Z,1626892144.358 [controlThread](INFO): Join timeout helper Thread ID is 1584
2021-07-21T18:29:04.525Z,1626892144.525 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-21T18:29:04.525Z,1626892144.525 [controlThread](DEBUG): Uninitializing ControlThread
2021-07-21T18:29:04.526Z,1626892144.526 [AHRS_M2](INFO): Powering down
2021-07-21T18:29:04.599Z,1626892144.599 [NAL9602](INFO): Powering down
2021-07-21T18:29:04.603Z,1626892144.603 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-07-21T18:29:04.605Z,1626892144.605 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-07-21T18:29:04.605Z,1626892144.605 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-07-21T18:29:04.606Z,1626892144.606 [MissionManager](INFO): Uninitializing Mission Default
2021-07-21T18:29:04.606Z,1626892144.606 [Default] Stopped
2021-07-21T18:29:04.606Z,1626892144.606 [Default](DEBUG): Aggregate::uninitialize Default
2021-07-21T18:29:04.606Z,1626892144.606 [Default:B.GoToSurface] Stopped
2021-07-21T18:29:04.606Z,1626892144.606 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-21T18:29:04.606Z,1626892144.606 [Default:CheckIn] Stopped
2021-07-21T18:29:04.606Z,1626892144.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-21T18:29:04.607Z,1626892144.607 [Default:CheckIn:C.Wait] Stopped
2021-07-21T18:29:04.607Z,1626892144.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-21T18:29:04.610Z,1626892144.610 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-07-21T18:29:04.610Z,1626892144.610 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-07-21T18:29:04.611Z,1626892144.611 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-07-21T18:29:04.611Z,1626892144.611 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-07-21T18:29:04.611Z,1626892144.611 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-07-21T18:29:04.611Z,1626892144.611 [BuoyancyServo](INFO): Powering down
2021-07-21T18:29:04.625Z,1626892144.625 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-07-21T18:29:04.625Z,1626892144.625 [ElevatorServo](INFO): Powering down
2021-07-21T18:29:04.626Z,1626892144.626 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-07-21T18:29:04.626Z,1626892144.626 [MassServo](INFO): Powering down
2021-07-21T18:29:04.627Z,1626892144.627 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-07-21T18:29:04.627Z,1626892144.627 [RudderServo](INFO): Powering down
2021-07-21T18:29:04.628Z,1626892144.628 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-07-21T18:29:04.628Z,1626892144.628 [ThrusterServo](INFO): Powering down
2021-07-21T18:29:04.629Z,1626892144.629 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-07-21T18:29:04.630Z,1626892144.630 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-07-21T18:29:04.630Z,1626892144.630 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-07-21T18:29:04.630Z,1626892144.630 [CBIT](DEBUG): Powering off loads.
2021-07-21T18:29:04.641Z,1626892144.641 [CBIT](DEBUG): Disabling WDT.
2021-07-21T18:29:04.653Z,1626892144.653 [CBIT](DEBUG): Opening all GF detection circuits.
2021-07-21T18:29:04.654Z,1626892144.654 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.693Z,1626892144.693 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.696Z,1626892144.696 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.702Z,1626892144.702 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.774Z,1626892144.774 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.778Z,1626892144.778 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.817Z,1626892144.817 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-21T18:29:04.892Z,1626892144.892 [logger ThreadHandler](INFO): Thread cancelled.