2023-04-07T20:08:02.045Z,1680898082.045 [CommandExec](IMPORTANT): got command restart logs 2023-04-07T20:08:23.643Z,1680898103.643 [DVL_micro](ERROR): Failed to parse: :.99,+9999..99,+9999.99 2023-04-07T20:09:03.244Z,1680898143.244 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.243607 2023-04-07T20:09:29.093Z,1680898169.093 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:09:29.093Z,1680898169.093 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:09:29.093Z,1680898169.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:09:29.094Z,1680898169.094 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:09:29.508Z,1680898169.508 [Default:CheckIn:D] Stopped 2023-04-07T20:09:29.508Z,1680898169.508 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:09:29.904Z,1680898169.904 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.791246 min 2023-04-07T20:09:29.904Z,1680898169.904 [Default:CheckIn:E] Stopped 2023-04-07T20:09:29.904Z,1680898169.904 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:09:29.904Z,1680898169.904 [Default:CheckIn] Stopped 2023-04-07T20:09:29.904Z,1680898169.904 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:09:29.905Z,1680898169.905 [Default:CheckIn](INFO): Running loop #4 2023-04-07T20:09:29.905Z,1680898169.905 [Default:CheckIn] Running Loop=4 2023-04-07T20:09:29.905Z,1680898169.905 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:09:29.905Z,1680898169.905 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:09:31.915Z,1680898171.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200930.00,A,3641.45225,N,12157.53216,W,8.553,70.16,070423,,,A*4A 2023-04-07T20:09:31.917Z,1680898171.917 [NAL9602](INFO): GPS fix at 20230407T200930: (36.690871, -121.958869) 2023-04-07T20:09:31.928Z,1680898171.928 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:09:31.929Z,1680898171.929 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:10:56.724Z,1680898256.724 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002989 2023-04-07T20:11:04.127Z,1680898264.127 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230407T024717/Courier0178.lzma 2023-04-07T20:11:05.130Z,1680898265.130 [DataOverHttps](INFO): Moved sent file to Logs/20230407T024717/Courier0178.lzma.bak 2023-04-07T20:11:05.130Z,1680898265.130 [DataOverHttps](INFO): SBD MOMSN=18170581 2023-04-07T20:11:27.093Z,1680898287.093 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:11:31.544Z,1680898291.544 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-07T20:11:31.544Z,1680898291.544 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+110,1489.0,000 2023-04-07T20:12:20.284Z,1680898340.284 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.735435 2023-04-07T20:12:31.740Z,1680898351.740 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-04-07T20:12:31.746Z,1680898351.746 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 5. 2023-04-07T20:12:31.749Z,1680898351.749 [BPC1](INFO): Received data from all battery sticks. 2023-04-07T20:12:51.409Z,1680898371.409 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-07T20:13:14.157Z,1680898394.157 [DVL_micro](ERROR): Failed to parse: :WI,+00004,+00024,-00401,+00000,A 2023-04-07T20:13:26.548Z,1680898406.548 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-07T20:13:53.795Z,1680898433.795 [NAL9602](INFO): SBD MO Status=2, MOMSN=14795, MT Status=2, MTMSN=0 2023-04-07T20:13:53.795Z,1680898433.795 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-04-07T20:14:01.704Z,1680898441.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-07T20:14:23.236Z,1680898463.236 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002940 2023-04-07T20:14:34.250Z,1680898474.250 [DVL_micro](ERROR): only read 0 of 4 data items 2023-04-07T20:14:34.251Z,1680898474.251 [DVL_micro](ERROR): Failed to parse: :BI+0002,+00000,I 2023-04-07T20:14:34.253Z,1680898474.253 [NAL9602](INFO): SBD MO Status=2, MOMSN=14795, MT Status=2, MTMSN=0 2023-04-07T20:14:34.253Z,1680898474.253 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-04-07T20:14:47.684Z,1680898487.684 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20230407T200802/Courier0000.lzma 2023-04-07T20:14:48.686Z,1680898488.686 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0000.lzma.bak 2023-04-07T20:14:48.686Z,1680898488.686 [DataOverHttps](INFO): SBD MOMSN=18170596 2023-04-07T20:15:04.962Z,1680898504.962 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:15:15.611Z,1680898515.611 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230407T200802/Courier0003.lzma 2023-04-07T20:15:16.614Z,1680898516.614 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0003.lzma.bak 2023-04-07T20:15:16.615Z,1680898516.615 [DataOverHttps](INFO): SBD MOMSN=18170600 2023-04-07T20:15:47.736Z,1680898547.736 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-04-07T20:16:16.853Z,1680898576.853 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.238560 2023-04-07T20:16:43.316Z,1680898603.316 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002981 2023-04-07T20:16:44.382Z,1680898604.382 [NAL9602](INFO): SBD MO Status=2, MOMSN=14795, MT Status=2, MTMSN=0 2023-04-07T20:16:44.383Z,1680898604.383 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-04-07T20:16:55.703Z,1680898615.703 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230407T024717/Express0179.lzma 2023-04-07T20:16:56.706Z,1680898616.706 [DataOverHttps](INFO): Moved sent file to Logs/20230407T024717/Express0179.lzma.bak 2023-04-07T20:16:56.707Z,1680898616.707 [DataOverHttps](INFO): SBD MOMSN=18170602 2023-04-07T20:17:13.636Z,1680898633.636 [DataOverHttps](INFO): Sending 382 bytes from file Logs/20230407T200802/Express0001.lzma 2023-04-07T20:17:14.638Z,1680898634.638 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0001.lzma.bak 2023-04-07T20:17:14.638Z,1680898634.638 [DataOverHttps](INFO): SBD MOMSN=18170605 2023-04-07T20:17:15.104Z,1680898635.104 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:17:30.547Z,1680898650.547 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20230407T200802/Express0004.lzma 2023-04-07T20:17:31.549Z,1680898651.549 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0004.lzma.bak 2023-04-07T20:17:31.550Z,1680898651.550 [DataOverHttps](INFO): SBD MOMSN=18170609 2023-04-07T20:17:32.906Z,1680898652.906 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:17:32.906Z,1680898652.906 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:17:32.906Z,1680898652.906 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:18:10.469Z,1680898690.469 [DVL_micro](ERROR): Failed to parse:018,+00016,-00311,+00000,I 2023-04-07T20:20:39.573Z,1680898839.573 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-07T20:20:39.573Z,1680898839.573 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+11.,1489.0,000 2023-04-07T20:22:33.555Z,1680898953.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:22:33.555Z,1680898953.555 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:22:33.555Z,1680898953.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:22:33.555Z,1680898953.555 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:22:33.949Z,1680898953.949 [Default:CheckIn:D] Stopped 2023-04-07T20:22:33.949Z,1680898953.949 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:22:34.356Z,1680898954.356 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.865263 min 2023-04-07T20:22:34.356Z,1680898954.356 [Default:CheckIn:E] Stopped 2023-04-07T20:22:34.356Z,1680898954.356 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:22:34.356Z,1680898954.356 [Default:CheckIn] Stopped 2023-04-07T20:22:34.356Z,1680898954.356 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:22:34.357Z,1680898954.357 [Default:CheckIn](INFO): Running loop #5 2023-04-07T20:22:34.357Z,1680898954.357 [Default:CheckIn] Running Loop=5 2023-04-07T20:22:34.357Z,1680898954.357 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:22:34.357Z,1680898954.357 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:22:36.363Z,1680898956.363 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202235.00,A,3642.93581,N,12155.70612,W,10.263,53.81,070423,,,D*73 2023-04-07T20:22:36.365Z,1680898956.365 [NAL9602](INFO): GPS fix at 20230407T202235: (36.715597, -121.928435) 2023-04-07T20:22:36.377Z,1680898956.377 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:22:36.377Z,1680898956.377 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:22:44.415Z,1680898964.415 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230407T200802/Courier0006.lzma 2023-04-07T20:22:45.417Z,1680898965.417 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0006.lzma.bak 2023-04-07T20:22:45.418Z,1680898965.418 [DataOverHttps](INFO): SBD MOMSN=18170654 2023-04-07T20:23:01.436Z,1680898981.436 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230407T200802/Express0007.lzma 2023-04-07T20:23:02.437Z,1680898982.437 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0007.lzma.bak 2023-04-07T20:23:02.438Z,1680898982.438 [DataOverHttps](INFO): SBD MOMSN=18170657 2023-04-07T20:23:03.870Z,1680898983.870 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:23:03.870Z,1680898983.870 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:23:03.870Z,1680898983.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:23:16.787Z,1680898996.787 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-07T20:23:16.788Z,1680898996.788 [DVL_micro](ERROR): Failed to parse: :TS,0000000099.99 2023-04-07T20:23:21.611Z,1680899001.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=14795, MT Status=2, MTMSN=0 2023-04-07T20:23:21.612Z,1680899001.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-04-07T20:23:26.871Z,1680899006.871 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-07T20:23:26.871Z,1680899006.871 [DVL_micro](ERROR): Failed to parse: :TS,000000000000011.9,0000.0,1489.0,000 2023-04-07T20:24:57.030Z,1680899097.030 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+12.0,0000.0,1489.0,000 2023-04-07T20:27:38.633Z,1680899258.633 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-04-07T20:28:04.581Z,1680899284.581 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:28:04.581Z,1680899284.581 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:28:04.581Z,1680899284.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:28:04.582Z,1680899284.582 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:28:04.972Z,1680899284.972 [Default:CheckIn:D] Stopped 2023-04-07T20:28:04.972Z,1680899284.972 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:28:05.386Z,1680899285.386 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.382316 min 2023-04-07T20:28:05.386Z,1680899285.386 [Default:CheckIn:E] Stopped 2023-04-07T20:28:05.386Z,1680899285.386 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn] Stopped 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn](INFO): Running loop #6 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn] Running Loop=6 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:28:05.387Z,1680899285.387 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:28:07.385Z,1680899287.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202806.00,A,3643.50698,N,12154.88153,W,8.922,47.37,070423,,,D*47 2023-04-07T20:28:07.388Z,1680899287.388 [NAL9602](INFO): GPS fix at 20230407T202806: (36.725116, -121.914692) 2023-04-07T20:28:07.399Z,1680899287.399 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:28:07.399Z,1680899287.399 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:28:15.107Z,1680899295.107 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230407T200802/Courier0009.lzma 2023-04-07T20:28:16.109Z,1680899296.109 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0009.lzma.bak 2023-04-07T20:28:16.110Z,1680899296.110 [DataOverHttps](INFO): SBD MOMSN=18170660 2023-04-07T20:28:32.156Z,1680899312.156 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20230407T200802/Express0010.lzma 2023-04-07T20:28:33.158Z,1680899313.158 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0010.lzma.bak 2023-04-07T20:28:33.158Z,1680899313.158 [DataOverHttps](INFO): SBD MOMSN=18170663 2023-04-07T20:28:34.469Z,1680899314.469 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:28:34.469Z,1680899314.469 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:28:34.469Z,1680899314.469 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:28:39.705Z,1680899319.705 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:33:35.106Z,1680899615.106 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:33:35.106Z,1680899615.106 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:33:35.106Z,1680899615.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:33:35.106Z,1680899615.106 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:33:35.519Z,1680899615.519 [Default:CheckIn:D] Stopped 2023-04-07T20:33:35.519Z,1680899615.519 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:33:35.927Z,1680899615.927 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.891431 min 2023-04-07T20:33:35.927Z,1680899615.927 [Default:CheckIn:E] Stopped 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn] Stopped 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn](INFO): Running loop #7 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn] Running Loop=7 2023-04-07T20:33:35.928Z,1680899615.928 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:33:35.929Z,1680899615.929 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:33:37.926Z,1680899617.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203336.00,A,3644.07506,N,12154.04535,W,10.380,58.57,070423,,,D*7C 2023-04-07T20:33:37.928Z,1680899617.928 [NAL9602](INFO): GPS fix at 20230407T203336: (36.734584, -121.900756) 2023-04-07T20:33:37.965Z,1680899617.965 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:33:37.965Z,1680899617.965 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:33:48.919Z,1680899628.919 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230407T200802/Courier0012.lzma 2023-04-07T20:33:49.922Z,1680899629.922 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0012.lzma.bak 2023-04-07T20:33:49.922Z,1680899629.922 [DataOverHttps](INFO): SBD MOMSN=18170712 2023-04-07T20:34:08.742Z,1680899648.742 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-04-07T20:34:08.816Z,1680899648.816 [NAL9602](ERROR): received: +CSQ:0 OK795, 2, 0, 0, 0 OK 2023-04-07T20:34:09.659Z,1680899649.659 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230407T200802/Express0013.lzma 2023-04-07T20:34:10.661Z,1680899650.661 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0013.lzma.bak 2023-04-07T20:34:10.662Z,1680899650.662 [DataOverHttps](INFO): SBD MOMSN=18170715 2023-04-07T20:34:11.992Z,1680899651.992 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:34:11.993Z,1680899651.993 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:34:11.993Z,1680899651.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:36:47.530Z,1680899807.530 [NAL9602](INFO): SBD MO Status=2, MOMSN=14795, MT Status=2, MTMSN=0 2023-04-07T20:36:47.531Z,1680899807.531 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-04-07T20:38:32.656Z,1680899912.656 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-04-07T20:38:32.656Z,1680899912.656 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+12.6,0000.0,1489.0,,-00002,+00104,-00101,+00000,A 2023-04-07T20:38:39.921Z,1680899919.921 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-04-07T20:39:10.620Z,1680899950.620 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:39:12.651Z,1680899952.651 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:39:12.651Z,1680899952.651 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:39:12.651Z,1680899952.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:39:12.652Z,1680899952.652 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:39:13.060Z,1680899953.060 [Default:CheckIn:D] Stopped 2023-04-07T20:39:13.060Z,1680899953.060 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:39:13.471Z,1680899953.471 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.517114 min 2023-04-07T20:39:13.471Z,1680899953.471 [Default:CheckIn:E] Stopped 2023-04-07T20:39:13.471Z,1680899953.471 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn] Stopped 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn](INFO): Running loop #8 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn] Running Loop=8 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:39:13.472Z,1680899953.472 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:39:15.475Z,1680899955.475 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203914.00,A,3644.64770,N,12153.19382,W,9.525,55.19,070423,,,D*47 2023-04-07T20:39:15.477Z,1680899955.477 [NAL9602](INFO): GPS fix at 20230407T203914: (36.744128, -121.886564) 2023-04-07T20:39:15.510Z,1680899955.510 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:39:15.510Z,1680899955.510 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:39:23.419Z,1680899963.419 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230407T200802/Courier0015.lzma 2023-04-07T20:39:24.421Z,1680899964.421 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0015.lzma.bak 2023-04-07T20:39:24.422Z,1680899964.422 [DataOverHttps](INFO): SBD MOMSN=18170718 2023-04-07T20:39:41.452Z,1680899981.452 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230407T200802/Express0016.lzma 2023-04-07T20:39:42.454Z,1680899982.454 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0016.lzma.bak 2023-04-07T20:39:42.454Z,1680899982.454 [DataOverHttps](INFO): SBD MOMSN=18170721 2023-04-07T20:39:43.779Z,1680899983.779 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:39:43.779Z,1680899983.779 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:39:43.788Z,1680899983.788 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:39:46.193Z,1680899986.193 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-04-07T20:39:46.272Z,1680899986.272 [NAL9602](ERROR): received: +CSQ:0 OK795, 2, 0, 0, 0 OK 2023-04-07T20:41:17.959Z,1680900077.959 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+12.8,0000.0,1489.0,000 2023-04-07T20:42:14.526Z,1680900134.526 [DVL_micro](ERROR): only read 3 of 4 data items 2023-04-07T20:42:14.526Z,1680900134.526 [DVL_micro](ERROR): Failed to parse: :BI,00006,-00055,+00000,I 2023-04-07T20:44:17.774Z,1680900257.774 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-04-07T20:44:44.465Z,1680900284.465 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:44:44.465Z,1680900284.465 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:44:44.465Z,1680900284.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:44:44.466Z,1680900284.466 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:44:44.855Z,1680900284.855 [Default:CheckIn:D] Stopped 2023-04-07T20:44:44.874Z,1680900284.874 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:44:45.260Z,1680900285.260 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.047038 min 2023-04-07T20:44:45.260Z,1680900285.260 [Default:CheckIn:E] Stopped 2023-04-07T20:44:45.260Z,1680900285.260 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:44:45.260Z,1680900285.260 [Default:CheckIn] Stopped 2023-04-07T20:44:45.261Z,1680900285.261 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:44:45.261Z,1680900285.261 [Default:CheckIn](INFO): Running loop #9 2023-04-07T20:44:45.261Z,1680900285.261 [Default:CheckIn] Running Loop=9 2023-04-07T20:44:45.261Z,1680900285.261 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:44:45.261Z,1680900285.261 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:44:47.267Z,1680900287.267 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204446.00,A,3645.18057,N,12152.36519,W,10.166,62.69,070423,,,D*72 2023-04-07T20:44:47.269Z,1680900287.269 [NAL9602](INFO): GPS fix at 20230407T204446: (36.753009, -121.872753) 2023-04-07T20:44:47.281Z,1680900287.281 [Default:CheckIn:Read_GPS] Stopped 2023-04-07T20:44:47.281Z,1680900287.281 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-04-07T20:44:55.047Z,1680900295.047 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230407T200802/Courier0018.lzma 2023-04-07T20:44:56.050Z,1680900296.050 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Courier0018.lzma.bak 2023-04-07T20:44:56.050Z,1680900296.050 [DataOverHttps](INFO): SBD MOMSN=18170766 2023-04-07T20:45:12.828Z,1680900312.828 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20230407T200802/Express0019.lzma 2023-04-07T20:45:16.842Z,1680900316.842 [DataOverHttps](INFO): Moved sent file to Logs/20230407T200802/Express0019.lzma.bak 2023-04-07T20:45:16.842Z,1680900316.842 [DataOverHttps](INFO): SBD MOMSN=18170770 2023-04-07T20:45:18.003Z,1680900318.003 [Default:CheckIn:Read_Iridium] Stopped 2023-04-07T20:45:18.003Z,1680900318.003 [Default:CheckIn:C.Wait] Running Loop=1 2023-04-07T20:45:18.003Z,1680900318.003 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-04-07T20:45:19.989Z,1680900319.989 [NAL9602](INFO): Not Powering down - fast GPS 2023-04-07T20:50:18.634Z,1680900618.634 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-04-07T20:50:18.634Z,1680900618.634 [Default:CheckIn:C.Wait] Stopped 2023-04-07T20:50:18.634Z,1680900618.634 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-04-07T20:50:18.635Z,1680900618.635 [Default:CheckIn:D] Running Loop=1 2023-04-07T20:50:19.026Z,1680900619.026 [Default:CheckIn:D] Stopped 2023-04-07T20:50:19.027Z,1680900619.027 [Default:CheckIn:E] Running Loop=1 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.616553 min 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn:E] Stopped 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn] Stopped 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn](INFO): Running loop #10 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn] Running Loop=10 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-04-07T20:50:19.446Z,1680900619.446 [Default:CheckIn:Read_GPS] Running Loop=1 2023-04-07T20:50:21.442Z,1680900621.442 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205020.00,A,3645.70532,N,12151.54269,W,9.000,58.05,070423,