2020-07-29T17:26:44.791Z,1596043604.791 [CommandLine](IMPORTANT): got command restart logs 2020-07-29T17:27:08.849Z,1596043628.849 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-07-29T17:27:08.849Z,1596043628.849 [Default:CheckIn:C.Wait] Stopped 2020-07-29T17:27:08.849Z,1596043628.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-07-29T17:27:08.850Z,1596043628.850 [Default:CheckIn:D] Running Loop=1 2020-07-29T17:27:09.260Z,1596043629.260 [Default:CheckIn:D] Stopped 2020-07-29T17:27:09.260Z,1596043629.260 [Default:CheckIn:E] Running Loop=1 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.702462 min 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn:E] Stopped 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn] Stopped 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn](INFO): Running loop #2 2020-07-29T17:27:09.672Z,1596043629.672 [Default:CheckIn] Running Loop=2 2020-07-29T17:27:09.673Z,1596043629.673 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-07-29T17:27:09.673Z,1596043629.673 [Default:CheckIn:Read_GPS] Running Loop=1 2020-07-29T17:27:11.673Z,1596043631.673 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172623.00,A,3648.32455,N,12149.15060,W,29.294,89.74,290720,,,A*76 2020-07-29T17:27:11.676Z,1596043631.676 [NAL9602](INFO): GPS fix at 20200729T172623: (36.805409, -121.819177) 2020-07-29T17:27:11.684Z,1596043631.684 [Default:CheckIn:Read_GPS] Stopped 2020-07-29T17:27:11.685Z,1596043631.685 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-07-29T17:27:29.047Z,1596043649.047 [NAL9602](INFO): SBD MO Status=0, MOMSN=39077, MT Status=0, MTMSN=0 2020-07-29T17:27:29.047Z,1596043649.047 [NAL9602](INFO): No messages in MT queue 2020-07-29T17:27:48.439Z,1596043668.439 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200729T143408/Courier0027.lzma 2020-07-29T17:27:53.452Z,1596043673.452 [DataOverHttps](INFO): Moved sent file to Logs/20200729T143408/Courier0027.lzma.bak 2020-07-29T17:27:53.453Z,1596043673.453 [DataOverHttps](INFO): SBD MOMSN=12478083 2020-07-29T17:27:59.744Z,1596043679.744 [NAL9602](INFO): Not Powering down - fast GPS 2020-07-29T17:28:09.087Z,1596043689.087 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20200729T172644/Courier0000.lzma 2020-07-29T17:28:10.088Z,1596043690.088 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Courier0000.lzma.bak 2020-07-29T17:28:10.089Z,1596043690.089 [DataOverHttps](INFO): SBD MOMSN=12478085 2020-07-29T17:28:42.215Z,1596043722.215 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-07-29T17:29:30.234Z,1596043770.234 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20200729T143408/Express0028.lzma 2020-07-29T17:29:31.237Z,1596043771.237 [DataOverHttps](INFO): Moved sent file to Logs/20200729T143408/Express0028.lzma.bak 2020-07-29T17:29:31.237Z,1596043771.237 [DataOverHttps](INFO): SBD MOMSN=12478089 2020-07-29T17:29:46.855Z,1596043786.855 [DataOverHttps](INFO): Sending 394 bytes from file Logs/20200729T172644/Express0001.lzma 2020-07-29T17:29:47.856Z,1596043787.856 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0001.lzma.bak 2020-07-29T17:29:47.857Z,1596043787.857 [DataOverHttps](INFO): SBD MOMSN=12478093 2020-07-29T17:30:03.718Z,1596043803.718 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200729T172644/Express0004.lzma 2020-07-29T17:30:04.721Z,1596043804.721 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0004.lzma.bak 2020-07-29T17:30:04.721Z,1596043804.721 [DataOverHttps](INFO): SBD MOMSN=12478097 2020-07-29T17:30:06.238Z,1596043806.238 [Default:CheckIn:Read_Iridium] Stopped 2020-07-29T17:30:06.238Z,1596043806.238 [Default:CheckIn:C.Wait] Running Loop=1 2020-07-29T17:30:06.238Z,1596043806.238 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-07-29T17:35:06.810Z,1596044106.810 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-07-29T17:35:06.810Z,1596044106.810 [Default:CheckIn:C.Wait] Stopped 2020-07-29T17:35:06.811Z,1596044106.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-07-29T17:35:06.811Z,1596044106.811 [Default:CheckIn:D] Running Loop=1 2020-07-29T17:35:07.217Z,1596044107.217 [Default:CheckIn:D] Stopped 2020-07-29T17:35:07.217Z,1596044107.217 [Default:CheckIn:E] Running Loop=1 2020-07-29T17:35:07.626Z,1596044107.626 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.668416 min 2020-07-29T17:35:07.626Z,1596044107.626 [Default:CheckIn:E] Stopped 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn] Stopped 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn](INFO): Running loop #3 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn] Running Loop=3 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-07-29T17:35:07.627Z,1596044107.627 [Default:CheckIn:Read_GPS] Running Loop=1 2020-07-29T17:35:09.638Z,1596044109.638 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173421.00,A,3648.31975,N,12147.14177,W,0.389,206.02,290720,,,A*71 2020-07-29T17:35:09.640Z,1596044109.640 [NAL9602](INFO): GPS fix at 20200729T173421: (36.805329, -121.785696) 2020-07-29T17:35:09.649Z,1596044109.649 [Default:CheckIn:Read_GPS] Stopped 2020-07-29T17:35:09.649Z,1596044109.649 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-07-29T17:35:16.018Z,1596044116.018 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200729T172644/Courier0006.lzma 2020-07-29T17:35:17.021Z,1596044117.021 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Courier0006.lzma.bak 2020-07-29T17:35:17.021Z,1596044117.021 [DataOverHttps](INFO): SBD MOMSN=12478107 2020-07-29T17:35:34.290Z,1596044134.290 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20200729T172644/Express0007.lzma 2020-07-29T17:35:35.292Z,1596044135.292 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0007.lzma.bak 2020-07-29T17:35:35.293Z,1596044135.293 [DataOverHttps](INFO): SBD MOMSN=12478110 2020-07-29T17:35:36.766Z,1596044136.766 [Default:CheckIn:Read_Iridium] Stopped 2020-07-29T17:35:36.766Z,1596044136.766 [Default:CheckIn:C.Wait] Running Loop=1 2020-07-29T17:35:36.766Z,1596044136.766 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-07-29T17:35:55.741Z,1596044155.741 [NAL9602](INFO): SBD MO Status=0, MOMSN=39078, MT Status=0, MTMSN=0 2020-07-29T17:35:55.741Z,1596044155.741 [NAL9602](INFO): No messages in MT queue 2020-07-29T17:36:26.442Z,1596044186.442 [NAL9602](INFO): Not Powering down - fast GPS 2020-07-29T17:40:37.340Z,1596044437.340 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-07-29T17:40:37.341Z,1596044437.341 [Default:CheckIn:C.Wait] Stopped 2020-07-29T17:40:37.341Z,1596044437.341 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-07-29T17:40:37.341Z,1596044437.341 [Default:CheckIn:D] Running Loop=1 2020-07-29T17:40:37.749Z,1596044437.749 [Default:CheckIn:D] Stopped 2020-07-29T17:40:37.749Z,1596044437.749 [Default:CheckIn:E] Running Loop=1 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.177283 min 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn:E] Stopped 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn] Stopped 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn](INFO): Running loop #4 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn] Running Loop=4 2020-07-29T17:40:38.148Z,1596044438.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-07-29T17:40:38.149Z,1596044438.149 [Default:CheckIn:Read_GPS] Running Loop=1 2020-07-29T17:40:40.160Z,1596044440.160 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173951.00,A,3648.32132,N,12147.14378,W,0.136,206.02,290720,,,A*78 2020-07-29T17:40:40.162Z,1596044440.162 [NAL9602](INFO): GPS fix at 20200729T173951: (36.805355, -121.785730) 2020-07-29T17:40:40.171Z,1596044440.171 [Default:CheckIn:Read_GPS] Stopped 2020-07-29T17:40:40.171Z,1596044440.171 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-07-29T17:40:46.878Z,1596044446.878 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200729T172644/Courier0009.lzma 2020-07-29T17:40:47.881Z,1596044447.881 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Courier0009.lzma.bak 2020-07-29T17:40:47.881Z,1596044447.881 [DataOverHttps](INFO): SBD MOMSN=12478114 2020-07-29T17:41:01.985Z,1596044461.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=39079, MT Status=2, MTMSN=0 2020-07-29T17:41:01.985Z,1596044461.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-07-29T17:41:03.814Z,1596044463.814 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200729T172644/Express0010.lzma 2020-07-29T17:41:04.817Z,1596044464.817 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0010.lzma.bak 2020-07-29T17:41:04.817Z,1596044464.817 [DataOverHttps](INFO): SBD MOMSN=12478118 2020-07-29T17:41:06.454Z,1596044466.454 [Default:CheckIn:Read_Iridium] Stopped 2020-07-29T17:41:06.454Z,1596044466.454 [Default:CheckIn:C.Wait] Running Loop=1 2020-07-29T17:41:06.454Z,1596044466.454 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-07-29T17:41:26.618Z,1596044486.618 [NAL9602](INFO): SBD MO Status=2, MOMSN=39079, MT Status=2, MTMSN=0 2020-07-29T17:41:26.618Z,1596044486.618 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-07-29T17:41:37.935Z,1596044497.935 [NAL9602](INFO): SBD MO Status=0, MOMSN=39079, MT Status=0, MTMSN=0 2020-07-29T17:41:37.935Z,1596044497.935 [NAL9602](INFO): No messages in MT queue 2020-07-29T17:42:08.640Z,1596044528.640 [NAL9602](INFO): Not Powering down - fast GPS 2020-07-29T17:46:07.005Z,1596044767.005 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-07-29T17:46:07.005Z,1596044767.005 [Default:CheckIn:C.Wait] Stopped 2020-07-29T17:46:07.005Z,1596044767.005 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-07-29T17:46:07.006Z,1596044767.006 [Default:CheckIn:D] Running Loop=1 2020-07-29T17:46:07.418Z,1596044767.418 [Default:CheckIn:D] Stopped 2020-07-29T17:46:07.418Z,1596044767.418 [Default:CheckIn:E] Running Loop=1 2020-07-29T17:46:07.831Z,1596044767.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.671767 min 2020-07-29T17:46:07.831Z,1596044767.831 [Default:CheckIn:E] Stopped 2020-07-29T17:46:07.831Z,1596044767.831 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-07-29T17:46:07.831Z,1596044767.831 [Default:CheckIn] Stopped 2020-07-29T17:46:07.832Z,1596044767.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-07-29T17:46:07.832Z,1596044767.832 [Default:CheckIn](INFO): Running loop #5 2020-07-29T17:46:07.832Z,1596044767.832 [Default:CheckIn] Running Loop=5 2020-07-29T17:46:07.832Z,1596044767.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-07-29T17:46:07.832Z,1596044767.832 [Default:CheckIn:Read_GPS] Running Loop=1 2020-07-29T17:46:09.829Z,1596044769.829 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174521.00,A,3648.32137,N,12147.14274,W,0.078,192.72,290720,,,A*7E 2020-07-29T17:46:09.831Z,1596044769.831 [NAL9602](INFO): GPS fix at 20200729T174521: (36.805356, -121.785712) 2020-07-29T17:46:09.840Z,1596044769.840 [Default:CheckIn:Read_GPS] Stopped 2020-07-29T17:46:09.840Z,1596044769.840 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-07-29T17:46:16.558Z,1596044776.558 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200729T172644/Courier0012.lzma 2020-07-29T17:46:17.561Z,1596044777.561 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Courier0012.lzma.bak 2020-07-29T17:46:17.561Z,1596044777.561 [DataOverHttps](INFO): SBD MOMSN=12478132 2020-07-29T17:46:29.621Z,1596044789.621 [NAL9602](INFO): SBD MO Status=0, MOMSN=39080, MT Status=0, MTMSN=0 2020-07-29T17:46:29.622Z,1596044789.622 [NAL9602](INFO): No messages in MT queue 2020-07-29T17:46:33.214Z,1596044793.214 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200729T172644/Express0013.lzma 2020-07-29T17:46:34.217Z,1596044794.217 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0013.lzma.bak 2020-07-29T17:46:34.217Z,1596044794.217 [DataOverHttps](INFO): SBD MOMSN=12478135 2020-07-29T17:46:35.701Z,1596044795.701 [Default:CheckIn:Read_Iridium] Stopped 2020-07-29T17:46:35.701Z,1596044795.701 [Default:CheckIn:C.Wait] Running Loop=1 2020-07-29T17:46:35.701Z,1596044795.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-07-29T17:47:00.329Z,1596044820.329 [NAL9602](INFO): Not Powering down - fast GPS 2020-07-29T17:51:36.281Z,1596045096.281 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-07-29T17:51:36.282Z,1596045096.282 [Default:CheckIn:C.Wait] Stopped 2020-07-29T17:51:36.282Z,1596045096.282 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-07-29T17:51:36.282Z,1596045096.282 [Default:CheckIn:D] Running Loop=1 2020-07-29T17:51:36.698Z,1596045096.698 [Default:CheckIn:D] Stopped 2020-07-29T17:51:36.699Z,1596045096.699 [Default:CheckIn:E] Running Loop=1 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.159772 min 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn:E] Stopped 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn] Stopped 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-07-29T17:51:37.092Z,1596045097.092 [Default:CheckIn](INFO): Running loop #6 2020-07-29T17:51:37.093Z,1596045097.093 [Default:CheckIn] Running Loop=6 2020-07-29T17:51:37.093Z,1596045097.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-07-29T17:51:37.093Z,1596045097.093 [Default:CheckIn:Read_GPS] Running Loop=1 2020-07-29T17:51:39.101Z,1596045099.101 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175050.00,A,3648.18238,N,12147.16549,W,4.004,197.90,290720,,,D*70 2020-07-29T17:51:39.103Z,1596045099.103 [NAL9602](INFO): GPS fix at 20200729T175050: (36.803040, -121.786091) 2020-07-29T17:51:39.112Z,1596045099.112 [Default:CheckIn:Read_GPS] Stopped 2020-07-29T17:51:39.112Z,1596045099.112 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-07-29T17:51:48.066Z,1596045108.066 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200729T172644/Courier0015.lzma 2020-07-29T17:51:49.069Z,1596045109.069 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Courier0015.lzma.bak 2020-07-29T17:51:49.069Z,1596045109.069 [DataOverHttps](INFO): SBD MOMSN=12478140 2020-07-29T17:51:59.708Z,1596045119.708 [NAL9602](INFO): SBD MO Status=0, MOMSN=39081, MT Status=0, MTMSN=0 2020-07-29T17:51:59.708Z,1596045119.708 [NAL9602](INFO): No messages in MT queue 2020-07-29T17:52:04.556Z,1596045124.556 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-07-29T17:52:04.646Z,1596045124.646 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20200729T172644/Express0016.lzma 2020-07-29T17:52:05.648Z,1596045125.648 [DataOverHttps](INFO): Moved sent file to Logs/20200729T172644/Express0016.lzma.bak 2020-07-29T17:52:05.649Z,1596045125.649 [DataOverHttps](INFO): SBD MOMSN=12478143 2020-07-29T17:52:06.999Z,1596045126.999 [Default:CheckIn:Read_Iridium] Stopped 2020-07-29T17:52:06.999Z,1596045126.999 [Default:CheckIn:C.Wait] Running Loop=1 2020-07-29T17:52:06.999Z,1596045126.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-07-29T17:52:16.272Z,1596045136.272 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-07-29T17:52:27.179Z,1596045147.179 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-07-29T17:52:30.406Z,1