2021-04-28T22:57:03.085Z,1619650623.085 [CommandLine](IMPORTANT): got command restart logs 2021-04-28T22:58:07.895Z,1619650687.895 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T22:58:07.895Z,1619650687.895 [Default:CheckIn:C.Wait] Stopped 2021-04-28T22:58:07.895Z,1619650687.895 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T22:58:07.896Z,1619650687.896 [Default:CheckIn:D] Running Loop=1 2021-04-28T22:58:08.321Z,1619650688.321 [Default:CheckIn:D] Stopped 2021-04-28T22:58:08.321Z,1619650688.321 [Default:CheckIn:E] Running Loop=1 2021-04-28T22:58:08.711Z,1619650688.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.221893 min 2021-04-28T22:58:08.711Z,1619650688.711 [Default:CheckIn:E] Stopped 2021-04-28T22:58:08.711Z,1619650688.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T22:58:08.711Z,1619650688.711 [Default:CheckIn] Stopped 2021-04-28T22:58:08.712Z,1619650688.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T22:58:08.712Z,1619650688.712 [Default:CheckIn](INFO): Running loop #3 2021-04-28T22:58:08.712Z,1619650688.712 [Default:CheckIn] Running Loop=3 2021-04-28T22:58:08.712Z,1619650688.712 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T22:58:08.712Z,1619650688.712 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T22:58:10.714Z,1619650690.714 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225809.00,A,3648.16178,N,12147.28655,W,0.855,350.91,280421,,,A*7E 2021-04-28T22:58:10.716Z,1619650690.716 [NAL9602](INFO): GPS fix at 20210428T225809: (36.802696, -121.788109) 2021-04-28T22:58:10.744Z,1619650690.744 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T22:58:10.744Z,1619650690.744 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T22:58:19.519Z,1619650699.519 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210428T220141/Courier0028.lzma 2021-04-28T22:58:20.521Z,1619650700.521 [DataOverHttps](INFO): Moved sent file to Logs/20210428T220141/Courier0028.lzma.bak 2021-04-28T22:58:20.521Z,1619650700.521 [DataOverHttps](INFO): SBD MOMSN=15607697 2021-04-28T22:58:41.271Z,1619650721.271 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210428T225703/Courier0000.lzma 2021-04-28T22:58:41.460Z,1619650721.460 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-28T22:58:41.539Z,1619650721.539 [NAL9602](ERROR): received: +CSQ:0 OK620, 2, 0, 0, 0 OK 2021-04-28T22:58:42.273Z,1619650722.273 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0000.lzma.bak 2021-04-28T22:58:42.273Z,1619650722.273 [DataOverHttps](INFO): SBD MOMSN=15607699 2021-04-28T22:58:58.699Z,1619650738.699 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210428T220141/Express0029.lzma 2021-04-28T22:58:59.702Z,1619650739.702 [DataOverHttps](INFO): Moved sent file to Logs/20210428T220141/Express0029.lzma.bak 2021-04-28T22:58:59.702Z,1619650739.702 [DataOverHttps](INFO): SBD MOMSN=15607703 2021-04-28T22:59:16.503Z,1619650756.503 [DataOverHttps](INFO): Sending 379 bytes from file Logs/20210428T225703/Express0001.lzma 2021-04-28T22:59:17.505Z,1619650757.505 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0001.lzma.bak 2021-04-28T22:59:17.505Z,1619650757.505 [DataOverHttps](INFO): SBD MOMSN=15607705 2021-04-28T22:59:19.487Z,1619650759.487 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T22:59:19.487Z,1619650759.487 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T22:59:19.487Z,1619650759.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:01:54.208Z,1619650914.208 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-28T23:01:54.208Z,1619650914.208 [DropWeight] No Fault, FailCount= 1 2021-04-28T23:02:04.265Z,1619650924.265 [NAL9602](INFO): SBD MO Status=2, MOMSN=14620, MT Status=2, MTMSN=0 2021-04-28T23:02:04.265Z,1619650924.265 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:03:13.404Z,1619650993.404 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-28T23:03:44.137Z,1619651024.137 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:04:20.089Z,1619651060.089 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:04:20.090Z,1619651060.090 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:04:20.090Z,1619651060.090 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:04:20.090Z,1619651060.090 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:04:20.473Z,1619651060.473 [Default:CheckIn:D] Stopped 2021-04-28T23:04:20.473Z,1619651060.473 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:04:20.937Z,1619651060.937 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.424430 min 2021-04-28T23:04:20.937Z,1619651060.937 [Default:CheckIn:E] Stopped 2021-04-28T23:04:20.937Z,1619651060.937 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:04:20.937Z,1619651060.937 [Default:CheckIn] Stopped 2021-04-28T23:04:20.937Z,1619651060.937 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:04:20.938Z,1619651060.938 [Default:CheckIn](INFO): Running loop #4 2021-04-28T23:04:20.938Z,1619651060.938 [Default:CheckIn] Running Loop=4 2021-04-28T23:04:20.938Z,1619651060.938 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:04:20.938Z,1619651060.938 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:04:22.896Z,1619651062.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230422.00,A,3648.16715,N,12147.28218,W,0.544,10.12,280421,,,A*4E 2021-04-28T23:04:22.898Z,1619651062.898 [NAL9602](INFO): GPS fix at 20210428T230422: (36.802786, -121.788036) 2021-04-28T23:04:22.984Z,1619651062.984 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:04:22.984Z,1619651062.984 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:04:31.659Z,1619651071.659 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0003.lzma 2021-04-28T23:04:32.663Z,1619651072.663 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0003.lzma.bak 2021-04-28T23:04:32.663Z,1619651072.663 [DataOverHttps](INFO): SBD MOMSN=15607715 2021-04-28T23:04:49.093Z,1619651089.093 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20210428T225703/Express0004.lzma 2021-04-28T23:04:50.092Z,1619651090.092 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0004.lzma.bak 2021-04-28T23:04:50.092Z,1619651090.092 [DataOverHttps](INFO): SBD MOMSN=15607718 2021-04-28T23:04:52.007Z,1619651092.007 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:04:52.007Z,1619651092.007 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:04:52.007Z,1619651092.007 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:04:53.593Z,1619651093.593 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-28T23:04:53.667Z,1619651093.667 [NAL9602](ERROR): received: +CSQ:0 OK620, 2, 0, 0, 0 OK 2021-04-28T23:09:25.491Z,1619651365.491 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-28T23:09:52.586Z,1619651392.586 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:09:52.587Z,1619651392.587 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:09:52.587Z,1619651392.587 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:09:52.588Z,1619651392.588 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:09:52.994Z,1619651392.994 [Default:CheckIn:D] Stopped 2021-04-28T23:09:52.994Z,1619651392.994 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.966451 min 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn:E] Stopped 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn] Stopped 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn](INFO): Running loop #5 2021-04-28T23:09:53.394Z,1619651393.394 [Default:CheckIn] Running Loop=5 2021-04-28T23:09:53.395Z,1619651393.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:09:53.395Z,1619651393.395 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:09:55.386Z,1619651395.386 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230954.00,A,3648.16126,N,12147.28481,W,0.097,10.12,280421,,,A*49 2021-04-28T23:09:55.388Z,1619651395.388 [NAL9602](INFO): GPS fix at 20210428T230954: (36.802688, -121.788080) 2021-04-28T23:09:55.400Z,1619651395.400 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:09:55.400Z,1619651395.400 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:10:03.917Z,1619651403.917 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0006.lzma 2021-04-28T23:10:04.045Z,1619651404.045 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0006.lzma.bak 2021-04-28T23:10:04.045Z,1619651404.045 [DataOverHttps](INFO): SBD MOMSN=15607722 2021-04-28T23:10:23.267Z,1619651423.267 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20210428T225703/Express0007.lzma 2021-04-28T23:10:24.269Z,1619651424.269 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0007.lzma.bak 2021-04-28T23:10:24.269Z,1619651424.269 [DataOverHttps](INFO): SBD MOMSN=15607725 2021-04-28T23:10:26.654Z,1619651426.654 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:10:26.655Z,1619651426.655 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:10:26.655Z,1619651426.655 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:10:27.017Z,1619651427.017 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:15:27.159Z,1619651727.159 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:15:27.159Z,1619651727.159 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:15:27.159Z,1619651727.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:15:27.163Z,1619651727.163 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:15:27.630Z,1619651727.630 [Default:CheckIn:D] Stopped 2021-04-28T23:15:27.630Z,1619651727.630 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.543717 min 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn:E] Stopped 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn] Stopped 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:15:27.991Z,1619651727.991 [Default:CheckIn](INFO): Running loop #6 2021-04-28T23:15:27.992Z,1619651727.992 [Default:CheckIn] Running Loop=6 2021-04-28T23:15:27.992Z,1619651727.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:15:27.992Z,1619651727.992 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:15:29.957Z,1619651729.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231529.00,A,3648.16736,N,12147.28058,W,0.136,233.28,280421,,,A*79 2021-04-28T23:15:29.960Z,1619651729.960 [NAL9602](INFO): GPS fix at 20210428T231529: (36.802789, -121.788010) 2021-04-28T23:15:29.971Z,1619651729.971 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:15:29.971Z,1619651729.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:15:38.740Z,1619651738.740 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0009.lzma 2021-04-28T23:15:39.145Z,1619651739.145 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0009.lzma.bak 2021-04-28T23:15:39.145Z,1619651739.145 [DataOverHttps](INFO): SBD MOMSN=15607736 2021-04-28T23:15:55.527Z,1619651755.527 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210428T225703/Express0010.lzma 2021-04-28T23:15:56.529Z,1619651756.529 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0010.lzma.bak 2021-04-28T23:15:56.529Z,1619651756.529 [DataOverHttps](INFO): SBD MOMSN=15607739 2021-04-28T23:15:58.280Z,1619651758.280 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:15:58.280Z,1619651758.280 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:15:58.280Z,1619651758.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:16:00.754Z,1619651760.754 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-28T23:16:00.827Z,1619651760.827 [NAL9602](ERROR): received: +CSQ:0 OK620, 2, 0, 0, 0 OK 2021-04-28T23:16:45.136Z,1619651805.136 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2021-04-28T23:16:45.138Z,1619651805.138 [BPC1](INFO): Received data from all battery sticks. 2021-04-28T23:19:47.414Z,1619651987.414 [NAL9602](INFO): SBD MO Status=2, MOMSN=14620, MT Status=2, MTMSN=0 2021-04-28T23:19:47.414Z,1619651987.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:20:05.165Z,1619652005.165 [NAL9602](INFO): SBD MO Status=0, MOMSN=14620, MT Status=0, MTMSN=0 2021-04-28T23:20:05.165Z,1619652005.165 [NAL9602](INFO): No messages in MT queue 2021-04-28T23:20:35.873Z,1619652035.873 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:20:58.908Z,1619652058.908 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:20:58.908Z,1619652058.908 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:20:58.908Z,1619652058.908 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:20:58.908Z,1619652058.908 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:20:59.309Z,1619652059.309 [Default:CheckIn:D] Stopped 2021-04-28T23:20:59.309Z,1619652059.309 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:20:59.734Z,1619652059.734 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.071698 min 2021-04-28T23:20:59.734Z,1619652059.734 [Default:CheckIn:E] Stopped 2021-04-28T23:20:59.734Z,1619652059.734 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:20:59.734Z,1619652059.734 [Default:CheckIn] Stopped 2021-04-28T23:20:59.734Z,1619652059.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:20:59.735Z,1619652059.735 [Default:CheckIn](INFO): Running loop #7 2021-04-28T23:20:59.735Z,1619652059.735 [Default:CheckIn] Running Loop=7 2021-04-28T23:20:59.735Z,1619652059.735 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:20:59.735Z,1619652059.735 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:21:01.726Z,1619652061.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232101.00,A,3648.16416,N,12147.28580,W,0.292,233.28,280421,,,A*78 2021-04-28T23:21:01.728Z,1619652061.728 [NAL9602](INFO): GPS fix at 20210428T232101: (36.802736, -121.788097) 2021-04-28T23:21:01.780Z,1619652061.780 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:21:01.780Z,1619652061.780 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:21:09.747Z,1619652069.747 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210428T225703/Courier0012.lzma 2021-04-28T23:21:10.749Z,1619652070.749 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0012.lzma.bak 2021-04-28T23:21:10.749Z,1619652070.749 [DataOverHttps](INFO): SBD MOMSN=15607742 2021-04-28T23:21:27.963Z,1619652087.963 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0013.lzma 2021-04-28T23:21:28.965Z,1619652088.965 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0013.lzma.bak 2021-04-28T23:21:28.965Z,1619652088.965 [DataOverHttps](INFO): SBD MOMSN=15607745 2021-04-28T23:21:30.840Z,1619652090.840 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:21:30.840Z,1619652090.840 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:21:30.840Z,1619652090.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:21:45.354Z,1619652105.354 [NAL9602](INFO): SBD MO Status=2, MOMSN=14621, MT Status=2, MTMSN=0 2021-04-28T23:21:45.354Z,1619652105.354 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:22:47.182Z,1619652167.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=14621, MT Status=2, MTMSN=0 2021-04-28T23:22:47.182Z,1619652167.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:26:04.405Z,1619652364.405 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-28T23:26:31.573Z,1619652391.573 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:26:31.573Z,1619652391.573 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:26:31.573Z,1619652391.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:26:31.573Z,1619652391.573 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:26:31.938Z,1619652391.938 [Default:CheckIn:D] Stopped 2021-04-28T23:26:31.938Z,1619652391.938 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:26:32.400Z,1619652392.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.615507 min 2021-04-28T23:26:32.400Z,1619652392.400 [Default:CheckIn:E] Stopped 2021-04-28T23:26:32.400Z,1619652392.400 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:26:32.400Z,1619652392.400 [Default:CheckIn] Stopped 2021-04-28T23:26:32.401Z,1619652392.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:26:32.401Z,1619652392.401 [Default:CheckIn](INFO): Running loop #8 2021-04-28T23:26:32.401Z,1619652392.401 [Default:CheckIn] Running Loop=8 2021-04-28T23:26:32.401Z,1619652392.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:26:32.401Z,1619652392.401 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:26:34.372Z,1619652394.372 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232633.00,A,3648.16672,N,12147.28239,W,0.389,210.23,280421,,,A*7A 2021-04-28T23:26:34.377Z,1619652394.377 [NAL9602](INFO): GPS fix at 20210428T232633: (36.802779, -121.788040) 2021-04-28T23:26:34.482Z,1619652394.482 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:26:34.482Z,1619652394.482 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:26:45.239Z,1619652405.239 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0015.lzma 2021-04-28T23:26:46.241Z,1619652406.241 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0015.lzma.bak 2021-04-28T23:26:46.241Z,1619652406.241 [DataOverHttps](INFO): SBD MOMSN=15607755 2021-04-28T23:27:02.663Z,1619652422.663 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210428T225703/Express0016.lzma 2021-04-28T23:27:03.665Z,1619652423.665 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0016.lzma.bak 2021-04-28T23:27:03.665Z,1619652423.665 [DataOverHttps](INFO): SBD MOMSN=15607758 2021-04-28T23:27:05.496Z,1619652425.496 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:27:05.496Z,1619652425.496 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:27:05.496Z,1619652425.496 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:27:06.284Z,1619652426.284 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:31:55.612Z,1619652715.612 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-28T23:31:55.612Z,1619652715.612 [DropWeight] Hardware Fault, FailCount= 1 2021-04-28T23:31:55.612Z,1619652715.612 [DropWeight](ERROR): Hardware Fault 2021-04-28T23:31:55.702Z,1619652715.702 [CBIT](INFO): Critical error at 20210428T233155 2021-04-28T23:31:55.713Z,1619652715.713 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-28T23:31:55.713Z,1619652715.713 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-28T23:31:56.108Z,1619652716.108 [CBIT](INFO): Critical error at 20210428T233155 2021-04-28T23:32:06.164Z,1619652726.164 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:32:06.164Z,1619652726.164 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:32:06.164Z,1619652726.164 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:32:06.165Z,1619652726.165 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:32:06.558Z,1619652726.558 [Default:CheckIn:D] Stopped 2021-04-28T23:32:06.558Z,1619652726.558 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.192200 min 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn:E] Stopped 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn] Stopped 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn](INFO): Running loop #9 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn] Running Loop=9 2021-04-28T23:32:06.940Z,1619652726.940 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:32:06.941Z,1619652726.941 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:32:08.945Z,1619652728.945 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233208.00,A,3648.16635,N,12147.28306,W,0.117,243.12,280421,,,A*78 2021-04-28T23:32:08.948Z,1619652728.948 [NAL9602](INFO): GPS fix at 20210428T233208: (36.802773, -121.788051) 2021-04-28T23:32:08.960Z,1619652728.960 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:32:08.960Z,1619652728.960 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:32:16.947Z,1619652736.947 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20210428T225703/Courier0018.lzma 2021-04-28T23:32:17.950Z,1619652737.950 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0018.lzma.bak 2021-04-28T23:32:17.950Z,1619652737.950 [DataOverHttps](INFO): SBD MOMSN=15607762 2021-04-28T23:32:39.376Z,1619652759.376 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-28T23:32:39.455Z,1619652759.455 [NAL9602](ERROR): received: +CSQ:0 OK621, 2, 0, 0, 0 OK 2021-04-28T23:32:41.619Z,1619652761.619 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0019.lzma 2021-04-28T23:32:42.621Z,1619652762.621 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0019.lzma.bak 2021-04-28T23:32:42.621Z,1619652762.621 [DataOverHttps](INFO): SBD MOMSN=15607767 2021-04-28T23:32:44.738Z,1619652764.738 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:32:44.738Z,1619652764.738 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:32:44.738Z,1619652764.738 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:36:41.446Z,1619653001.446 [NAL9602](INFO): SBD MO Status=2, MOMSN=14621, MT Status=2, MTMSN=0 2021-04-28T23:36:41.446Z,1619653001.446 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:37:11.340Z,1619653031.340 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-28T23:37:42.064Z,1619653062.064 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:37:45.309Z,1619653065.309 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:37:45.309Z,1619653065.309 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:37:45.309Z,1619653065.309 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:37:45.310Z,1619653065.310 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:37:45.699Z,1619653065.699 [Default:CheckIn:D] Stopped 2021-04-28T23:37:45.699Z,1619653065.699 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:37:46.148Z,1619653066.148 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.844865 min 2021-04-28T23:37:46.148Z,1619653066.148 [Default:CheckIn:E] Stopped 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn] Stopped 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn](INFO): Running loop #10 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn] Running Loop=10 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:37:46.149Z,1619653066.149 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:37:48.130Z,1619653068.130 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233747.00,A,3648.16507,N,12147.28092,W,0.117,243.12,280421,,,A*7A 2021-04-28T23:37:48.156Z,1619653068.156 [NAL9602](INFO): GPS fix at 20210428T233747: (36.802751, -121.788015) 2021-04-28T23:37:48.202Z,1619653068.202 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:37:48.202Z,1619653068.202 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:37:55.803Z,1619653075.803 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0021.lzma 2021-04-28T23:37:56.801Z,1619653076.801 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0021.lzma.bak 2021-04-28T23:37:56.801Z,1619653076.801 [DataOverHttps](INFO): SBD MOMSN=15607777 2021-04-28T23:38:13.671Z,1619653093.671 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210428T225703/Express0022.lzma 2021-04-28T23:38:14.673Z,1619653094.673 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0022.lzma.bak 2021-04-28T23:38:14.673Z,1619653094.673 [DataOverHttps](INFO): SBD MOMSN=15607780 2021-04-28T23:38:16.408Z,1619653096.408 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:38:16.408Z,1619653096.408 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:38:16.408Z,1619653096.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:38:18.828Z,1619653098.828 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-28T23:38:18.907Z,1619653098.907 [NAL9602](ERROR): received: +CSQ:0 OK621, 2, 0, 0, 0 OK 2021-04-28T23:38:52.006Z,1619653132.006 [NAL9602](INFO): SBD MO Status=2, MOMSN=14621, MT Status=2, MTMSN=0 2021-04-28T23:38:52.006Z,1619653132.006 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-28T23:39:04.123Z,1619653144.123 [NAL9602](INFO): SBD MO Status=0, MOMSN=14621, MT Status=0, MTMSN=0 2021-04-28T23:39:04.124Z,1619653144.124 [NAL9602](INFO): No messages in MT queue 2021-04-28T23:39:34.828Z,1619653174.828 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:43:17.115Z,1619653397.115 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:43:17.115Z,1619653397.115 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:43:17.115Z,1619653397.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:43:17.116Z,1619653397.116 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:43:17.514Z,1619653397.514 [Default:CheckIn:D] Stopped 2021-04-28T23:43:17.515Z,1619653397.515 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:43:17.953Z,1619653397.953 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.375122 min 2021-04-28T23:43:17.953Z,1619653397.953 [Default:CheckIn:E] Stopped 2021-04-28T23:43:17.953Z,1619653397.953 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:43:17.953Z,1619653397.953 [Default:CheckIn] Stopped 2021-04-28T23:43:17.953Z,1619653397.953 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:43:17.954Z,1619653397.954 [Default:CheckIn](INFO): Running loop #11 2021-04-28T23:43:17.954Z,1619653397.954 [Default:CheckIn] Running Loop=11 2021-04-28T23:43:17.954Z,1619653397.954 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:43:17.954Z,1619653397.954 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:43:19.931Z,1619653399.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234319.00,A,3648.16390,N,12147.27992,W,0.156,243.12,280421,,,A*79 2021-04-28T23:43:19.933Z,1619653399.933 [NAL9602](INFO): GPS fix at 20210428T234319: (36.802732, -121.787999) 2021-04-28T23:43:19.985Z,1619653399.985 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:43:19.985Z,1619653399.985 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:43:27.547Z,1619653407.547 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0024.lzma 2021-04-28T23:43:29.140Z,1619653409.140 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0024.lzma.bak 2021-04-28T23:43:29.141Z,1619653409.141 [DataOverHttps](INFO): SBD MOMSN=15607785 2021-04-28T23:43:42.170Z,1619653422.170 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2021-04-28T23:43:44.951Z,1619653424.951 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210428T225703/Express0025.lzma 2021-04-28T23:43:45.953Z,1619653425.953 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0025.lzma.bak 2021-04-28T23:43:45.953Z,1619653425.953 [DataOverHttps](INFO): SBD MOMSN=15607788 2021-04-28T23:43:47.826Z,1619653427.826 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:43:47.826Z,1619653427.826 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:43:47.826Z,1619653427.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:44:52.142Z,1619653492.142 [NAL9602](INFO): SBD MO Status=0, MOMSN=14622, MT Status=0, MTMSN=0 2021-04-28T23:44:52.142Z,1619653492.142 [NAL9602](INFO): No messages in MT queue 2021-04-28T23:45:22.848Z,1619653522.848 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:46:55.832Z,1619653615.832 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-28T23:46:55.832Z,1619653615.832 [DropWeight] No Fault, FailCount= 1 2021-04-28T23:48:48.538Z,1619653728.538 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:48:48.538Z,1619653728.538 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:48:48.538Z,1619653728.538 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:48:48.538Z,1619653728.538 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:48:48.939Z,1619653728.939 [Default:CheckIn:D] Stopped 2021-04-28T23:48:48.939Z,1619653728.939 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.898531 min 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn:E] Stopped 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn] Stopped 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn](INFO): Running loop #12 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn] Running Loop=12 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:48:49.354Z,1619653729.354 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:48:51.338Z,1619653731.338 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234850.00,A,3648.16464,N,12147.28062,W,0.097,0.00,280421,,,A*70 2021-04-28T23:48:51.340Z,1619653731.340 [NAL9602](INFO): GPS fix at 20210428T234850: (36.802744, -121.788010) 2021-04-28T23:48:51.369Z,1619653731.369 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:48:51.369Z,1619653731.369 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:48:59.383Z,1619653739.383 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0027.lzma 2021-04-28T23:49:00.385Z,1619653740.385 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0027.lzma.bak 2021-04-28T23:49:00.385Z,1619653740.385 [DataOverHttps](INFO): SBD MOMSN=15607799 2021-04-28T23:49:02.647Z,1619653742.647 [NAL9602](INFO): SBD MO Status=0, MOMSN=14623, MT Status=0, MTMSN=0 2021-04-28T23:49:02.647Z,1619653742.647 [NAL9602](INFO): No messages in MT queue 2021-04-28T23:49:16.715Z,1619653756.715 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0028.lzma 2021-04-28T23:49:17.717Z,1619653757.717 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0028.lzma.bak 2021-04-28T23:49:17.717Z,1619653757.717 [DataOverHttps](INFO): SBD MOMSN=15607802 2021-04-28T23:49:20.059Z,1619653760.059 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:49:20.059Z,1619653760.059 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:49:20.061Z,1619653760.061 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:49:33.348Z,1619653773.348 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:50:07.408Z,1619653807.408 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2021-04-28T23:54:20.731Z,1619654060.731 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:54:20.731Z,1619654060.731 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:54:20.731Z,1619654060.731 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:54:20.735Z,1619654060.735 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:54:21.168Z,1619654061.168 [Default:CheckIn:D] Stopped 2021-04-28T23:54:21.168Z,1619654061.168 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:54:21.519Z,1619654061.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.436011 min 2021-04-28T23:54:21.519Z,1619654061.519 [Default:CheckIn:E] Stopped 2021-04-28T23:54:21.519Z,1619654061.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:54:21.523Z,1619654061.523 [Default:CheckIn] Stopped 2021-04-28T23:54:21.523Z,1619654061.523 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:54:21.524Z,1619654061.524 [Default:CheckIn](INFO): Running loop #13 2021-04-28T23:54:21.524Z,1619654061.524 [Default:CheckIn] Running Loop=13 2021-04-28T23:54:21.524Z,1619654061.524 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:54:21.524Z,1619654061.524 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-28T23:54:23.530Z,1619654063.530 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235422.00,A,3648.16327,N,12147.27996,W,0.078,0.00,280421,,,A*74 2021-04-28T23:54:23.533Z,1619654063.533 [NAL9602](INFO): GPS fix at 20210428T235422: (36.802721, -121.787999) 2021-04-28T23:54:23.593Z,1619654063.593 [Default:CheckIn:Read_GPS] Stopped 2021-04-28T23:54:23.593Z,1619654063.593 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-28T23:54:35.715Z,1619654075.715 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0030.lzma 2021-04-28T23:54:36.717Z,1619654076.717 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0030.lzma.bak 2021-04-28T23:54:36.717Z,1619654076.717 [DataOverHttps](INFO): SBD MOMSN=15607806 2021-04-28T23:54:37.813Z,1619654077.813 [NAL9602](INFO): SBD MO Status=0, MOMSN=14624, MT Status=0, MTMSN=0 2021-04-28T23:54:37.813Z,1619654077.813 [NAL9602](INFO): No messages in MT queue 2021-04-28T23:54:55.615Z,1619654095.615 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20210428T225703/Express0031.lzma 2021-04-28T23:54:56.621Z,1619654096.621 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0031.lzma.bak 2021-04-28T23:54:56.622Z,1619654096.622 [DataOverHttps](INFO): SBD MOMSN=15607809 2021-04-28T23:54:58.412Z,1619654098.412 [Default:CheckIn:Read_Iridium] Stopped 2021-04-28T23:54:58.412Z,1619654098.412 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-28T23:54:58.412Z,1619654098.412 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-28T23:55:08.478Z,1619654108.478 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-28T23:59:59.036Z,1619654399.036 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-28T23:59:59.036Z,1619654399.036 [Default:CheckIn:C.Wait] Stopped 2021-04-28T23:59:59.036Z,1619654399.036 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-28T23:59:59.036Z,1619654399.036 [Default:CheckIn:D] Running Loop=1 2021-04-28T23:59:59.403Z,1619654399.403 [Default:CheckIn:D] Stopped 2021-04-28T23:59:59.403Z,1619654399.403 [Default:CheckIn:E] Running Loop=1 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.073267 min 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn:E] Stopped 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn] Stopped 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn](INFO): Running loop #14 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn] Running Loop=14 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-28T23:59:59.801Z,1619654399.801 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:00:01.815Z,1619654401.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000001.00,A,3648.16573,N,12147.28166,W,0.330,0.00,290421,,,A*74 2021-04-29T00:00:01.817Z,1619654401.817 [NAL9602](INFO): GPS fix at 20210429T000001: (36.802762, -121.788028) 2021-04-29T00:00:01.829Z,1619654401.829 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:00:01.829Z,1619654401.829 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:00:09.479Z,1619654409.479 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0033.lzma 2021-04-29T00:00:10.481Z,1619654410.481 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0033.lzma.bak 2021-04-29T00:00:10.481Z,1619654410.481 [DataOverHttps](INFO): SBD MOMSN=15607821 2021-04-29T00:00:30.497Z,1619654430.497 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20210428T225703/Express0034.lzma 2021-04-29T00:00:31.497Z,1619654431.497 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0034.lzma.bak 2021-04-29T00:00:31.497Z,1619654431.497 [DataOverHttps](INFO): SBD MOMSN=15607824 2021-04-29T00:00:33.944Z,1619654433.944 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:00:33.945Z,1619654433.945 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:00:33.945Z,1619654433.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:02:59.322Z,1619654579.322 [NAL9602](INFO): SBD MO Status=0, MOMSN=14625, MT Status=0, MTMSN=0 2021-04-29T00:02:59.322Z,1619654579.322 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:03:30.024Z,1619654610.024 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:05:34.561Z,1619654734.561 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:05:34.561Z,1619654734.561 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:05:34.561Z,1619654734.561 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:05:34.562Z,1619654734.562 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:05:34.990Z,1619654734.990 [Default:CheckIn:D] Stopped 2021-04-29T00:05:34.990Z,1619654734.990 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:05:35.352Z,1619654735.352 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.666382 min 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn:E] Stopped 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn] Stopped 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn](INFO): Running loop #15 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn] Running Loop=15 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:05:35.353Z,1619654735.353 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:05:37.343Z,1619654737.343 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000536.00,A,3648.16139,N,12147.28223,W,0.097,0.00,290421,,,A*73 2021-04-29T00:05:37.346Z,1619654737.346 [NAL9602](INFO): GPS fix at 20210429T000536: (36.802690, -121.788037) 2021-04-29T00:05:37.386Z,1619654737.386 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:05:37.387Z,1619654737.387 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:05:38.354Z,1619654738.354 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0036.lzma 2021-04-29T00:05:38.913Z,1619654738.913 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0036.lzma.bak 2021-04-29T00:05:38.913Z,1619654738.913 [DataOverHttps](INFO): SBD MOMSN=15607828 2021-04-29T00:05:55.323Z,1619654755.323 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0037.lzma 2021-04-29T00:05:56.325Z,1619654756.325 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0037.lzma.bak 2021-04-29T00:05:56.325Z,1619654756.325 [DataOverHttps](INFO): SBD MOMSN=15607831 2021-04-29T00:05:58.058Z,1619654758.058 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:05:58.058Z,1619654758.058 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:05:58.058Z,1619654758.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:06:08.955Z,1619654768.955 [NAL9602](INFO): SBD MO Status=2, MOMSN=14626, MT Status=2, MTMSN=0 2021-04-29T00:06:08.955Z,1619654768.955 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:06:36.014Z,1619654796.014 [NAL9602](INFO): SBD MO Status=0, MOMSN=14626, MT Status=0, MTMSN=0 2021-04-29T00:06:36.014Z,1619654796.014 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:07:06.713Z,1619654826.713 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:10:58.731Z,1619655058.731 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:10:58.731Z,1619655058.731 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:10:58.731Z,1619655058.731 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:10:58.732Z,1619655058.732 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:10:59.105Z,1619655059.105 [Default:CheckIn:D] Stopped 2021-04-29T00:10:59.105Z,1619655059.105 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:10:59.526Z,1619655059.526 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.068302 min 2021-04-29T00:10:59.526Z,1619655059.526 [Default:CheckIn:E] Stopped 2021-04-29T00:10:59.526Z,1619655059.526 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn] Stopped 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn](INFO): Running loop #16 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn] Running Loop=16 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:10:59.527Z,1619655059.527 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:11:01.514Z,1619655061.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001100.00,A,3648.16342,N,12147.28254,W,0.078,0.00,290421,,,A*7C 2021-04-29T00:11:01.516Z,1619655061.516 [NAL9602](INFO): GPS fix at 20210429T001100: (36.802724, -121.788042) 2021-04-29T00:11:01.573Z,1619655061.573 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:11:01.573Z,1619655061.573 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:11:08.922Z,1619655068.922 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0039.lzma 2021-04-29T00:11:09.925Z,1619655069.925 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0039.lzma.bak 2021-04-29T00:11:09.925Z,1619655069.925 [DataOverHttps](INFO): SBD MOMSN=15607841 2021-04-29T00:11:26.251Z,1619655086.251 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210428T225703/Express0040.lzma 2021-04-29T00:11:27.253Z,1619655087.253 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0040.lzma.bak 2021-04-29T00:11:27.253Z,1619655087.253 [DataOverHttps](INFO): SBD MOMSN=15607844 2021-04-29T00:11:29.092Z,1619655089.092 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:11:29.092Z,1619655089.092 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:11:29.092Z,1619655089.092 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:12:02.598Z,1619655122.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=14627, MT Status=2, MTMSN=0 2021-04-29T00:12:02.598Z,1619655122.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:12:20.370Z,1619655140.370 [NAL9602](INFO): SBD MO Status=2, MOMSN=14627, MT Status=2, MTMSN=0 2021-04-29T00:12:20.370Z,1619655140.370 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:13:05.222Z,1619655185.222 [NAL9602](INFO): SBD MO Status=0, MOMSN=14627, MT Status=0, MTMSN=0 2021-04-29T00:13:05.222Z,1619655185.222 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:13:35.925Z,1619655215.925 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:16:29.777Z,1619655389.777 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:16:29.777Z,1619655389.777 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:16:29.777Z,1619655389.777 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:16:29.777Z,1619655389.777 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:16:30.167Z,1619655390.167 [Default:CheckIn:D] Stopped 2021-04-29T00:16:30.167Z,1619655390.167 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:16:30.603Z,1619655390.603 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.586003 min 2021-04-29T00:16:30.631Z,1619655390.631 [Default:CheckIn:E] Stopped 2021-04-29T00:16:30.631Z,1619655390.631 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:16:30.631Z,1619655390.631 [Default:CheckIn] Stopped 2021-04-29T00:16:30.632Z,1619655390.632 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:16:30.632Z,1619655390.632 [Default:CheckIn](INFO): Running loop #17 2021-04-29T00:16:30.632Z,1619655390.632 [Default:CheckIn] Running Loop=17 2021-04-29T00:16:30.632Z,1619655390.632 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:16:30.632Z,1619655390.632 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:16:32.580Z,1619655392.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001631.00,A,3648.16115,N,12147.28589,W,0.661,254.99,290421,,,A*73 2021-04-29T00:16:32.583Z,1619655392.583 [NAL9602](INFO): GPS fix at 20210429T001631: (36.802686, -121.788098) 2021-04-29T00:16:32.677Z,1619655392.677 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:16:32.677Z,1619655392.677 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:16:42.270Z,1619655402.270 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0042.lzma 2021-04-29T00:16:43.273Z,1619655403.273 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0042.lzma.bak 2021-04-29T00:16:43.273Z,1619655403.273 [DataOverHttps](INFO): SBD MOMSN=15607850 2021-04-29T00:16:57.272Z,1619655417.272 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-29T00:16:57.272Z,1619655417.272 [DropWeight] Hardware Fault, FailCount= 1 2021-04-29T00:16:57.272Z,1619655417.272 [DropWeight](ERROR): Hardware Fault 2021-04-29T00:16:57.355Z,1619655417.355 [CBIT](INFO): Critical error at 20210429T001657 2021-04-29T00:16:57.362Z,1619655417.362 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-29T00:16:57.362Z,1619655417.362 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-29T00:16:57.761Z,1619655417.761 [CBIT](INFO): Critical error at 20210429T001657 2021-04-29T00:17:00.223Z,1619655420.223 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0043.lzma 2021-04-29T00:17:01.225Z,1619655421.225 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0043.lzma.bak 2021-04-29T00:17:01.225Z,1619655421.225 [DataOverHttps](INFO): SBD MOMSN=15607857 2021-04-29T00:17:02.999Z,1619655422.999 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:17:02.999Z,1619655422.999 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:17:02.999Z,1619655422.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:17:06.150Z,1619655426.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=14628, MT Status=2, MTMSN=0 2021-04-29T00:17:06.150Z,1619655426.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:17:21.914Z,1619655441.914 [NAL9602](INFO): SBD MO Status=0, MOMSN=14628, MT Status=0, MTMSN=0 2021-04-29T00:17:21.914Z,1619655441.914 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:17:52.628Z,1619655472.628 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:22:03.776Z,1619655723.776 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:22:03.776Z,1619655723.776 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:22:03.777Z,1619655723.777 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:22:03.777Z,1619655723.777 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:22:04.135Z,1619655724.135 [Default:CheckIn:D] Stopped 2021-04-29T00:22:04.135Z,1619655724.135 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:22:04.522Z,1619655724.522 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.151864 min 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn:E] Stopped 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn] Stopped 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn](INFO): Running loop #18 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn] Running Loop=18 2021-04-29T00:22:04.523Z,1619655724.523 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:22:04.524Z,1619655724.524 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:22:04.939Z,1619655724.939 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2021-04-29T00:22:06.539Z,1619655726.539 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002205.00,A,3648.16357,N,12147.28743,W,0.136,254.99,290421,,,A*76 2021-04-29T00:22:06.542Z,1619655726.542 [NAL9602](INFO): GPS fix at 20210429T002205: (36.802726, -121.788124) 2021-04-29T00:22:06.553Z,1619655726.553 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:22:06.553Z,1619655726.553 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:22:14.291Z,1619655734.291 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20210428T225703/Courier0045.lzma 2021-04-29T00:22:15.293Z,1619655735.293 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0045.lzma.bak 2021-04-29T00:22:15.293Z,1619655735.293 [DataOverHttps](INFO): SBD MOMSN=15607861 2021-04-29T00:22:39.899Z,1619655759.899 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0046.lzma 2021-04-29T00:22:40.901Z,1619655760.901 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0046.lzma.bak 2021-04-29T00:22:40.902Z,1619655760.902 [DataOverHttps](INFO): SBD MOMSN=15607867 2021-04-29T00:22:43.078Z,1619655763.078 [NAL9602](INFO): SBD MO Status=2, MOMSN=14629, MT Status=2, MTMSN=0 2021-04-29T00:22:43.078Z,1619655763.078 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:22:43.920Z,1619655763.920 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:22:43.921Z,1619655763.921 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:22:43.921Z,1619655763.921 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:23:08.530Z,1619655788.530 [NAL9602](INFO): SBD MO Status=0, MOMSN=14629, MT Status=0, MTMSN=0 2021-04-29T00:23:08.531Z,1619655788.531 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:23:39.242Z,1619655819.242 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:24:09.581Z,1619655849.581 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6. 2021-04-29T00:24:09.591Z,1619655849.591 [BPC1](INFO): Received data from all battery sticks. 2021-04-29T00:27:44.574Z,1619656064.574 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:27:44.574Z,1619656064.574 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:27:44.574Z,1619656064.574 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:27:44.574Z,1619656064.574 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:27:45.006Z,1619656065.006 [Default:CheckIn:D] Stopped 2021-04-29T00:27:45.006Z,1619656065.006 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:27:45.387Z,1619656065.387 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.833317 min 2021-04-29T00:27:45.387Z,1619656065.387 [Default:CheckIn:E] Stopped 2021-04-29T00:27:45.418Z,1619656065.418 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:27:45.418Z,1619656065.418 [Default:CheckIn] Stopped 2021-04-29T00:27:45.418Z,1619656065.418 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:27:45.419Z,1619656065.419 [Default:CheckIn](INFO): Running loop #19 2021-04-29T00:27:45.419Z,1619656065.419 [Default:CheckIn] Running Loop=19 2021-04-29T00:27:45.419Z,1619656065.419 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:27:45.419Z,1619656065.419 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:27:47.394Z,1619656067.394 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002746.00,A,3648.16517,N,12147.28385,W,0.486,0.00,290421,,,A*75 2021-04-29T00:27:47.397Z,1619656067.397 [NAL9602](INFO): GPS fix at 20210429T002746: (36.802753, -121.788064) 2021-04-29T00:27:47.415Z,1619656067.415 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:27:47.415Z,1619656067.415 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:27:55.070Z,1619656075.070 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210428T225703/Courier0048.lzma 2021-04-29T00:27:56.073Z,1619656076.073 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0048.lzma.bak 2021-04-29T00:27:56.073Z,1619656076.073 [DataOverHttps](INFO): SBD MOMSN=15607877 2021-04-29T00:28:13.267Z,1619656093.267 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0049.lzma 2021-04-29T00:28:14.269Z,1619656094.269 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0049.lzma.bak 2021-04-29T00:28:14.269Z,1619656094.269 [DataOverHttps](INFO): SBD MOMSN=15607880 2021-04-29T00:28:16.095Z,1619656096.095 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:28:16.095Z,1619656096.095 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:28:16.096Z,1619656096.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:30:50.882Z,1619656250.882 [NAL9602](INFO): SBD MO Status=0, MOMSN=14630, MT Status=0, MTMSN=0 2021-04-29T00:30:50.882Z,1619656250.882 [NAL9602](INFO): No messages in MT queue 2021-04-29T00:31:21.581Z,1619656281.581 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:31:57.594Z,1619656317.594 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-29T00:31:57.594Z,1619656317.594 [DropWeight] No Fault, FailCount= 1 2021-04-29T00:33:16.822Z,1619656396.822 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:33:16.823Z,1619656396.823 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:33:16.823Z,1619656396.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:33:16.823Z,1619656396.823 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:33:17.219Z,1619656397.219 [Default:CheckIn:D] Stopped 2021-04-29T00:33:17.219Z,1619656397.219 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:33:17.615Z,1619656397.615 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.370199 min 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn:E] Stopped 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn] Stopped 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn](INFO): Running loop #20 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn] Running Loop=20 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:33:17.616Z,1619656397.616 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:33:19.626Z,1619656399.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003318.00,A,3648.16460,N,12147.28734,W,0.078,0.00,290421,,,A*71 2021-04-29T00:33:19.629Z,1619656399.629 [NAL9602](INFO): GPS fix at 20210429T003318: (36.802743, -121.788122) 2021-04-29T00:33:19.640Z,1619656399.640 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:33:19.640Z,1619656399.640 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:33:27.651Z,1619656407.651 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0051.lzma 2021-04-29T00:33:28.653Z,1619656408.653 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0051.lzma.bak 2021-04-29T00:33:28.653Z,1619656408.653 [DataOverHttps](INFO): SBD MOMSN=15607884 2021-04-29T00:33:42.246Z,1619656422.246 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T00:33:42.246Z,1619656422.246 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:33:45.699Z,1619656425.699 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0052.lzma 2021-04-29T00:33:46.701Z,1619656426.701 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0052.lzma.bak 2021-04-29T00:33:46.701Z,1619656426.701 [DataOverHttps](INFO): SBD MOMSN=15607887 2021-04-29T00:33:48.756Z,1619656428.756 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:33:48.757Z,1619656428.757 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:33:48.757Z,1619656428.757 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:35:05.468Z,1619656505.468 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T00:35:05.468Z,1619656505.468 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:38:22.284Z,1619656702.284 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T00:38:49.371Z,1619656729.371 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:38:49.371Z,1619656729.371 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:38:49.371Z,1619656729.371 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:38:49.372Z,1619656729.372 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:38:49.792Z,1619656729.792 [Default:CheckIn:D] Stopped 2021-04-29T00:38:49.792Z,1619656729.792 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.913078 min 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn:E] Stopped 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn] Stopped 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn](INFO): Running loop #21 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn] Running Loop=21 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:38:50.176Z,1619656730.176 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:38:52.182Z,1619656732.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003851.00,A,3648.16214,N,12147.28517,W,0.408,0.00,290421,,,A*72 2021-04-29T00:38:52.184Z,1619656732.184 [NAL9602](INFO): GPS fix at 20210429T003851: (36.802702, -121.788086) 2021-04-29T00:38:52.200Z,1619656732.200 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:38:52.200Z,1619656732.200 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:39:00.122Z,1619656740.122 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210428T225703/Courier0054.lzma 2021-04-29T00:39:01.125Z,1619656741.125 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0054.lzma.bak 2021-04-29T00:39:01.125Z,1619656741.125 [DataOverHttps](INFO): SBD MOMSN=15607897 2021-04-29T00:39:17.543Z,1619656757.543 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210428T225703/Express0055.lzma 2021-04-29T00:39:18.889Z,1619656758.889 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0055.lzma.bak 2021-04-29T00:39:18.889Z,1619656758.889 [DataOverHttps](INFO): SBD MOMSN=15607900 2021-04-29T00:39:20.143Z,1619656760.143 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:39:20.143Z,1619656760.143 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:39:20.143Z,1619656760.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:39:24.500Z,1619656764.500 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:44:20.778Z,1619657060.778 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:44:20.778Z,1619657060.778 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:44:20.778Z,1619657060.778 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:44:20.778Z,1619657060.778 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:44:21.148Z,1619657061.148 [Default:CheckIn:D] Stopped 2021-04-29T00:44:21.148Z,1619657061.148 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.435677 min 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn:E] Stopped 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn] Stopped 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:44:21.607Z,1619657061.607 [Default:CheckIn](INFO): Running loop #22 2021-04-29T00:44:21.608Z,1619657061.608 [Default:CheckIn] Running Loop=22 2021-04-29T00:44:21.608Z,1619657061.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:44:21.608Z,1619657061.608 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:44:23.574Z,1619657063.574 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004422.00,A,3648.16499,N,12147.28674,W,0.350,0.00,290421,,,A*72 2021-04-29T00:44:23.581Z,1619657063.581 [NAL9602](INFO): GPS fix at 20210429T004422: (36.802750, -121.788112) 2021-04-29T00:44:23.665Z,1619657063.665 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:44:23.665Z,1619657063.665 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:44:35.128Z,1619657075.128 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0057.lzma 2021-04-29T00:44:36.130Z,1619657076.130 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0057.lzma.bak 2021-04-29T00:44:36.130Z,1619657076.130 [DataOverHttps](INFO): SBD MOMSN=15607904 2021-04-29T00:44:54.102Z,1619657094.102 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T00:44:54.183Z,1619657094.183 [NAL9602](ERROR): received: +CSQ:0 OK631, 2, 0, 0, 0 OK 2021-04-29T00:44:54.559Z,1619657094.559 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0058.lzma 2021-04-29T00:44:55.561Z,1619657095.561 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0058.lzma.bak 2021-04-29T00:44:55.561Z,1619657095.561 [DataOverHttps](INFO): SBD MOMSN=15607908 2021-04-29T00:44:57.392Z,1619657097.392 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:44:57.392Z,1619657097.392 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:44:57.392Z,1619657097.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:49:25.250Z,1619657365.250 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T00:49:55.941Z,1619657395.941 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:49:58.001Z,1619657398.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:49:58.001Z,1619657398.001 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:49:58.001Z,1619657398.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:49:58.001Z,1619657398.001 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:49:58.378Z,1619657398.378 [Default:CheckIn:D] Stopped 2021-04-29T00:49:58.378Z,1619657398.378 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:49:58.806Z,1619657398.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.056177 min 2021-04-29T00:49:58.806Z,1619657398.806 [Default:CheckIn:E] Stopped 2021-04-29T00:49:58.806Z,1619657398.806 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:49:58.806Z,1619657398.806 [Default:CheckIn] Stopped 2021-04-29T00:49:58.807Z,1619657398.806 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:49:58.807Z,1619657398.807 [Default:CheckIn](INFO): Running loop #23 2021-04-29T00:49:58.807Z,1619657398.807 [Default:CheckIn] Running Loop=23 2021-04-29T00:49:58.807Z,1619657398.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:49:58.807Z,1619657398.807 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:50:00.794Z,1619657400.794 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005000.00,A,3648.16571,N,12147.28611,W,0.330,343.70,290421,,,A*76 2021-04-29T00:50:00.797Z,1619657400.797 [NAL9602](INFO): GPS fix at 20210429T005000: (36.802762, -121.788102) 2021-04-29T00:50:00.849Z,1619657400.849 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:50:00.849Z,1619657400.849 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:50:08.331Z,1619657408.331 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0060.lzma 2021-04-29T00:50:09.333Z,1619657409.333 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0060.lzma.bak 2021-04-29T00:50:09.333Z,1619657409.333 [DataOverHttps](INFO): SBD MOMSN=15607919 2021-04-29T00:50:28.847Z,1619657428.847 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210428T225703/Express0061.lzma 2021-04-29T00:50:29.852Z,1619657429.852 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0061.lzma.bak 2021-04-29T00:50:29.852Z,1619657429.852 [DataOverHttps](INFO): SBD MOMSN=15607922 2021-04-29T00:50:31.598Z,1619657431.598 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T00:50:31.671Z,1619657431.671 [NAL9602](ERROR): received: +CSQ:0 OK631, 2, 0, 0, 0 OK 2021-04-29T00:50:32.162Z,1619657432.162 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:50:32.162Z,1619657432.162 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:50:32.162Z,1619657432.162 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:51:35.954Z,1619657495.954 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T00:51:35.954Z,1619657495.954 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T00:55:03.257Z,1619657703.257 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T00:55:32.845Z,1619657732.845 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T00:55:32.845Z,1619657732.845 [Default:CheckIn:C.Wait] Stopped 2021-04-29T00:55:32.845Z,1619657732.845 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T00:55:32.845Z,1619657732.845 [Default:CheckIn:D] Running Loop=1 2021-04-29T00:55:33.191Z,1619657733.191 [Default:CheckIn:D] Stopped 2021-04-29T00:55:33.191Z,1619657733.191 [Default:CheckIn:E] Running Loop=1 2021-04-29T00:55:33.599Z,1619657733.599 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.636328 min 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn:E] Stopped 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn] Stopped 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn](INFO): Running loop #24 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn] Running Loop=24 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T00:55:33.600Z,1619657733.600 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T00:55:33.968Z,1619657733.968 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T00:55:35.582Z,1619657735.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005534.00,A,3648.16501,N,12147.28234,W,0.078,343.70,290421,,,A*7F 2021-04-29T00:55:35.588Z,1619657735.588 [NAL9602](INFO): GPS fix at 20210429T005534: (36.802750, -121.788039) 2021-04-29T00:55:35.647Z,1619657735.647 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T00:55:35.647Z,1619657735.647 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T00:55:37.151Z,1619657737.151 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0063.lzma 2021-04-29T00:55:37.750Z,1619657737.750 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0063.lzma.bak 2021-04-29T00:55:37.750Z,1619657737.750 [DataOverHttps](INFO): SBD MOMSN=15607926 2021-04-29T00:55:53.795Z,1619657753.795 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210428T225703/Express0064.lzma 2021-04-29T00:55:54.797Z,1619657754.797 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0064.lzma.bak 2021-04-29T00:55:54.797Z,1619657754.797 [DataOverHttps](INFO): SBD MOMSN=15607929 2021-04-29T00:55:56.634Z,1619657756.634 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T00:55:56.634Z,1619657756.634 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T00:55:56.634Z,1619657756.634 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T00:56:06.281Z,1619657766.281 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T00:56:06.359Z,1619657766.359 [NAL9602](ERROR): received: +CSQ:0 OK631, 2, 0, 0, 0 OK 2021-04-29T01:00:37.452Z,1619658037.452 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T01:00:57.251Z,1619658057.251 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:00:57.251Z,1619658057.251 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:00:57.251Z,1619658057.251 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:00:57.252Z,1619658057.252 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:00:57.655Z,1619658057.655 [Default:CheckIn:D] Stopped 2021-04-29T01:00:57.655Z,1619658057.655 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:00:58.075Z,1619658058.075 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 134.044132 min 2021-04-29T01:00:58.075Z,1619658058.075 [Default:CheckIn:E] Stopped 2021-04-29T01:00:58.075Z,1619658058.075 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:00:58.075Z,1619658058.075 [Default:CheckIn] Stopped 2021-04-29T01:00:58.075Z,1619658058.075 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:00:58.076Z,1619658058.076 [Default:CheckIn](INFO): Running loop #25 2021-04-29T01:00:58.076Z,1619658058.076 [Default:CheckIn] Running Loop=25 2021-04-29T01:00:58.076Z,1619658058.076 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:00:58.076Z,1619658058.076 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:01:00.064Z,1619658060.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010059.00,A,3648.16663,N,12147.28529,W,0.175,343.70,290421,,,A*75 2021-04-29T01:01:00.066Z,1619658060.066 [NAL9602](INFO): GPS fix at 20210429T010059: (36.802777, -121.788088) 2021-04-29T01:01:00.119Z,1619658060.119 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:01:00.119Z,1619658060.119 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:01:07.731Z,1619658067.731 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0066.lzma 2021-04-29T01:01:08.733Z,1619658068.733 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0066.lzma.bak 2021-04-29T01:01:08.733Z,1619658068.733 [DataOverHttps](INFO): SBD MOMSN=15607939 2021-04-29T01:01:25.035Z,1619658085.035 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210428T225703/Express0067.lzma 2021-04-29T01:01:26.037Z,1619658086.037 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0067.lzma.bak 2021-04-29T01:01:26.037Z,1619658086.037 [DataOverHttps](INFO): SBD MOMSN=15607942 2021-04-29T01:01:27.963Z,1619658087.963 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:01:27.963Z,1619658087.963 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:01:27.963Z,1619658087.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:01:32.384Z,1619658092.384 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:01:59.048Z,1619658119.048 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-29T01:01:59.048Z,1619658119.048 [DropWeight] Hardware Fault, FailCount= 1 2021-04-29T01:01:59.048Z,1619658119.048 [DropWeight](ERROR): Hardware Fault 2021-04-29T01:01:59.137Z,1619658119.137 [CBIT](INFO): Critical error at 20210429T010159 2021-04-29T01:01:59.145Z,1619658119.145 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-29T01:01:59.145Z,1619658119.145 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-29T01:01:59.470Z,1619658119.470 [CBIT](INFO): Critical error at 20210429T010159 2021-04-29T01:06:28.696Z,1619658388.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:06:28.696Z,1619658388.696 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:06:28.697Z,1619658388.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:06:28.697Z,1619658388.697 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:06:29.080Z,1619658389.080 [Default:CheckIn:D] Stopped 2021-04-29T01:06:29.080Z,1619658389.080 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.567887 min 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn:E] Stopped 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn] Stopped 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn](INFO): Running loop #26 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn] Running Loop=26 2021-04-29T01:06:29.456Z,1619658389.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:06:29.457Z,1619658389.457 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:06:31.452Z,1619658391.452 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010630.00,A,3648.16121,N,12147.28672,W,0.156,0.00,290421,,,A*72 2021-04-29T01:06:31.454Z,1619658391.454 [NAL9602](INFO): GPS fix at 20210429T010630: (36.802687, -121.788112) 2021-04-29T01:06:31.470Z,1619658391.470 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:06:31.470Z,1619658391.470 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:06:41.723Z,1619658401.723 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20210428T225703/Courier0069.lzma 2021-04-29T01:06:42.725Z,1619658402.725 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0069.lzma.bak 2021-04-29T01:06:42.725Z,1619658402.725 [DataOverHttps](INFO): SBD MOMSN=15607946 2021-04-29T01:06:59.133Z,1619658419.133 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0070.lzma 2021-04-29T01:07:00.134Z,1619658420.134 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0070.lzma.bak 2021-04-29T01:07:00.138Z,1619658420.138 [DataOverHttps](INFO): SBD MOMSN=15607951 2021-04-29T01:07:01.820Z,1619658421.820 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:07:01.820Z,1619658421.820 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:07:01.820Z,1619658421.820 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:07:02.224Z,1619658422.224 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T01:07:02.303Z,1619658422.303 [NAL9602](ERROR): received: +CSQ:0 OK631, 2, 0, 0, 0 OK 2021-04-29T01:07:45.454Z,1619658465.454 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T01:07:45.454Z,1619658465.454 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:10:41.673Z,1619658641.673 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2021-04-29T01:11:33.348Z,1619658693.348 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T01:12:02.447Z,1619658722.447 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:12:02.447Z,1619658722.447 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:12:02.447Z,1619658722.447 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:12:02.448Z,1619658722.448 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:12:02.872Z,1619658722.872 [Default:CheckIn:D] Stopped 2021-04-29T01:12:02.872Z,1619658722.872 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:12:03.256Z,1619658723.256 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 145.131087 min 2021-04-29T01:12:03.256Z,1619658723.256 [Default:CheckIn:E] Stopped 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn] Stopped 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn](INFO): Running loop #27 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn] Running Loop=27 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:12:03.257Z,1619658723.257 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:12:05.266Z,1619658725.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,011204.00,A,3648.16540,N,12147.28251,W,0.078,0.00,290421,,,A*7B 2021-04-29T01:12:05.268Z,1619658725.268 [NAL9602](INFO): GPS fix at 20210429T011204: (36.802757, -121.788042) 2021-04-29T01:12:05.280Z,1619658725.280 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:12:05.280Z,1619658725.280 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:12:12.687Z,1619658732.687 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0072.lzma 2021-04-29T01:12:13.689Z,1619658733.689 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0072.lzma.bak 2021-04-29T01:12:13.689Z,1619658733.689 [DataOverHttps](INFO): SBD MOMSN=15607960 2021-04-29T01:12:36.823Z,1619658756.823 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210428T225703/Express0073.lzma 2021-04-29T01:12:37.288Z,1619658757.288 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:12:37.825Z,1619658757.825 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0073.lzma.bak 2021-04-29T01:12:37.826Z,1619658757.826 [DataOverHttps](INFO): SBD MOMSN=15607963 2021-04-29T01:12:40.236Z,1619658760.236 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:12:40.236Z,1619658760.236 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:12:40.237Z,1619658760.237 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:16:59.218Z,1619659019.218 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-29T01:16:59.218Z,1619659019.218 [DropWeight] No Fault, FailCount= 1 2021-04-29T01:17:40.863Z,1619659060.863 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:17:40.863Z,1619659060.863 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:17:40.863Z,1619659060.863 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:17:40.867Z,1619659060.867 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:17:41.224Z,1619659061.224 [Default:CheckIn:D] Stopped 2021-04-29T01:17:41.224Z,1619659061.224 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:17:41.646Z,1619659061.646 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.770280 min 2021-04-29T01:17:41.646Z,1619659061.646 [Default:CheckIn:E] Stopped 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn] Stopped 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn](INFO): Running loop #28 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn] Running Loop=28 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:17:41.647Z,1619659061.647 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:17:43.625Z,1619659063.625 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,011742.00,A,3648.16192,N,12147.28146,W,0.175,0.00,290421,,,D*7B 2021-04-29T01:17:43.627Z,1619659063.627 [NAL9602](INFO): GPS fix at 20210429T011742: (36.802699, -121.788024) 2021-04-29T01:17:43.682Z,1619659063.682 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:17:43.682Z,1619659063.682 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:17:50.991Z,1619659070.991 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0075.lzma 2021-04-29T01:17:51.993Z,1619659071.993 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0075.lzma.bak 2021-04-29T01:17:51.993Z,1619659071.993 [DataOverHttps](INFO): SBD MOMSN=15607967 2021-04-29T01:18:09.132Z,1619659089.132 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0076.lzma 2021-04-29T01:18:10.249Z,1619659090.249 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0076.lzma.bak 2021-04-29T01:18:10.249Z,1619659090.249 [DataOverHttps](INFO): SBD MOMSN=15607970 2021-04-29T01:18:11.972Z,1619659091.972 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:18:11.972Z,1619659091.972 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:18:11.972Z,1619659091.972 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:18:14.320Z,1619659094.320 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T01:18:14.403Z,1619659094.403 [NAL9602](ERROR): received: +CSQ:0 OK631, 2, 0, 0, 0 OK 2021-04-29T01:22:45.493Z,1619659365.493 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T01:23:12.559Z,1619659392.559 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:23:12.559Z,1619659392.559 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:23:12.559Z,1619659392.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:23:12.559Z,1619659392.559 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:23:12.982Z,1619659392.982 [Default:CheckIn:D] Stopped 2021-04-29T01:23:12.982Z,1619659392.982 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:23:13.372Z,1619659393.372 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 156.299577 min 2021-04-29T01:23:13.372Z,1619659393.372 [Default:CheckIn:E] Stopped 2021-04-29T01:23:13.372Z,1619659393.372 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:23:13.372Z,1619659393.372 [Default:CheckIn] Stopped 2021-04-29T01:23:13.372Z,1619659393.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:23:13.373Z,1619659393.373 [Default:CheckIn](INFO): Running loop #29 2021-04-29T01:23:13.373Z,1619659393.373 [Default:CheckIn] Running Loop=29 2021-04-29T01:23:13.373Z,1619659393.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:23:13.373Z,1619659393.373 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:23:15.376Z,1619659395.376 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,012314.00,A,3648.16456,N,12147.28009,W,0.097,305.86,290421,,,D*7D 2021-04-29T01:23:15.378Z,1619659395.378 [NAL9602](INFO): GPS fix at 20210429T012314: (36.802743, -121.788002) 2021-04-29T01:23:15.414Z,1619659395.414 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:23:15.414Z,1619659395.414 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:23:23.599Z,1619659403.599 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0078.lzma 2021-04-29T01:23:24.601Z,1619659404.601 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0078.lzma.bak 2021-04-29T01:23:24.601Z,1619659404.601 [DataOverHttps](INFO): SBD MOMSN=15607981 2021-04-29T01:23:41.496Z,1619659421.496 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210428T225703/Express0079.lzma 2021-04-29T01:23:42.497Z,1619659422.497 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0079.lzma.bak 2021-04-29T01:23:42.497Z,1619659422.497 [DataOverHttps](INFO): SBD MOMSN=15607984 2021-04-29T01:23:44.090Z,1619659424.090 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:23:44.091Z,1619659424.091 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:23:44.091Z,1619659424.091 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:23:47.696Z,1619659427.696 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:28:44.559Z,1619659724.559 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:28:44.560Z,1619659724.560 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:28:44.560Z,1619659724.560 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:28:44.560Z,1619659724.560 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:28:44.960Z,1619659724.960 [Default:CheckIn:D] Stopped 2021-04-29T01:28:44.960Z,1619659724.960 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:28:45.348Z,1619659725.348 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.832552 min 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn:E] Stopped 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn] Stopped 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn](INFO): Running loop #30 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn] Running Loop=30 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:28:45.349Z,1619659725.349 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:28:47.382Z,1619659727.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,012846.00,A,3648.16190,N,12147.28538,W,0.292,11.49,290421,,,D*4B 2021-04-29T01:28:47.386Z,1619659727.386 [NAL9602](INFO): GPS fix at 20210429T012846: (36.802698, -121.788090) 2021-04-29T01:28:47.398Z,1619659727.398 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:28:47.398Z,1619659727.398 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:28:55.235Z,1619659735.235 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0081.lzma 2021-04-29T01:28:56.237Z,1619659736.237 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0081.lzma.bak 2021-04-29T01:28:56.238Z,1619659736.238 [DataOverHttps](INFO): SBD MOMSN=15607988 2021-04-29T01:29:13.191Z,1619659753.191 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0082.lzma 2021-04-29T01:29:14.194Z,1619659754.194 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0082.lzma.bak 2021-04-29T01:29:14.194Z,1619659754.194 [DataOverHttps](INFO): SBD MOMSN=15607991 2021-04-29T01:29:16.086Z,1619659756.086 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:29:16.087Z,1619659756.087 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:29:16.087Z,1619659756.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:31:38.726Z,1619659898.726 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-29T01:31:38.729Z,1619659898.729 [BPC1](INFO): Received data from all battery sticks. 2021-04-29T01:31:58.928Z,1619659918.928 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T01:31:58.928Z,1619659918.928 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:32:24.824Z,1619659944.824 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T01:32:24.824Z,1619659944.824 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:33:49.270Z,1619660029.270 [NAL9602](INFO): SBD MO Status=2, MOMSN=14631, MT Status=2, MTMSN=0 2021-04-29T01:33:49.270Z,1619660029.270 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:33:49.677Z,1619660029.677 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T01:34:16.760Z,1619660056.760 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:34:16.760Z,1619660056.760 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:34:16.760Z,1619660056.760 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:34:16.760Z,1619660056.760 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:34:17.230Z,1619660057.230 [Default:CheckIn:D] Stopped 2021-04-29T01:34:17.230Z,1619660057.230 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.370378 min 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn:E] Stopped 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn] Stopped 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn](INFO): Running loop #31 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn] Running Loop=31 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:34:17.605Z,1619660057.605 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:34:19.570Z,1619660059.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,013418.00,A,3648.16428,N,12147.28310,W,0.214,325.37,290421,,,D*74 2021-04-29T01:34:19.572Z,1619660059.572 [NAL9602](INFO): GPS fix at 20210429T013418: (36.802738, -121.788052) 2021-04-29T01:34:19.592Z,1619660059.592 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:34:19.593Z,1619660059.593 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:34:31.951Z,1619660071.951 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210428T225703/Courier0084.lzma 2021-04-29T01:34:32.953Z,1619660072.953 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0084.lzma.bak 2021-04-29T01:34:32.954Z,1619660072.954 [DataOverHttps](INFO): SBD MOMSN=15608000 2021-04-29T01:34:51.605Z,1619660091.605 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:34:53.959Z,1619660093.959 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210428T225703/Express0085.lzma 2021-04-29T01:34:54.961Z,1619660094.961 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0085.lzma.bak 2021-04-29T01:34:54.961Z,1619660094.961 [DataOverHttps](INFO): SBD MOMSN=15608003 2021-04-29T01:34:56.463Z,1619660096.463 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:34:56.463Z,1619660096.463 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:34:56.464Z,1619660096.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:39:57.156Z,1619660397.156 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:39:57.156Z,1619660397.156 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:39:57.157Z,1619660397.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:39:57.157Z,1619660397.157 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:39:57.552Z,1619660397.552 [Default:CheckIn:D] Stopped 2021-04-29T01:39:57.552Z,1619660397.552 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.042415 min 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn:E] Stopped 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn] Stopped 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn](INFO): Running loop #32 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn] Running Loop=32 2021-04-29T01:39:57.992Z,1619660397.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:39:57.993Z,1619660397.993 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:39:59.969Z,1619660399.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,013959.00,A,3648.16412,N,12147.28018,W,0.272,325.37,290421,,,D*7E 2021-04-29T01:39:59.975Z,1619660399.975 [NAL9602](INFO): GPS fix at 20210429T013959: (36.802735, -121.788003) 2021-04-29T01:40:00.034Z,1619660400.034 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:40:00.034Z,1619660400.034 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:40:07.710Z,1619660407.710 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0087.lzma 2021-04-29T01:40:08.713Z,1619660408.713 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0087.lzma.bak 2021-04-29T01:40:08.713Z,1619660408.713 [DataOverHttps](INFO): SBD MOMSN=15608007 2021-04-29T01:40:32.747Z,1619660432.747 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0088.lzma 2021-04-29T01:40:33.753Z,1619660433.753 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0088.lzma.bak 2021-04-29T01:40:33.754Z,1619660433.754 [DataOverHttps](INFO): SBD MOMSN=15608013 2021-04-29T01:40:36.500Z,1619660436.500 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:40:36.501Z,1619660436.501 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:40:36.501Z,1619660436.501 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:41:07.166Z,1619660467.166 [NAL9602](INFO): SBD MO Status=0, MOMSN=14631, MT Status=0, MTMSN=0 2021-04-29T01:41:07.166Z,1619660467.166 [NAL9602](INFO): No messages in MT queue 2021-04-29T01:41:37.865Z,1619660497.865 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:45:37.185Z,1619660737.185 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:45:37.186Z,1619660737.186 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:45:37.186Z,1619660737.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:45:37.186Z,1619660737.186 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:45:37.585Z,1619660737.585 [Default:CheckIn:D] Stopped 2021-04-29T01:45:37.585Z,1619660737.585 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:45:38.014Z,1619660738.014 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 178.709635 min 2021-04-29T01:45:38.014Z,1619660738.014 [Default:CheckIn:E] Stopped 2021-04-29T01:45:38.015Z,1619660738.015 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:45:38.015Z,1619660738.015 [Default:CheckIn] Stopped 2021-04-29T01:45:38.015Z,1619660738.015 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:45:38.019Z,1619660738.019 [Default:CheckIn](INFO): Running loop #33 2021-04-29T01:45:38.019Z,1619660738.019 [Default:CheckIn] Running Loop=33 2021-04-29T01:45:38.019Z,1619660738.019 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:45:38.019Z,1619660738.019 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:45:39.972Z,1619660739.972 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,014539.00,A,3648.16368,N,12147.28141,W,0.311,325.37,290421,,,D*70 2021-04-29T01:45:39.974Z,1619660739.974 [NAL9602](INFO): GPS fix at 20210429T014539: (36.802728, -121.788023) 2021-04-29T01:45:40.031Z,1619660740.031 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:45:40.031Z,1619660740.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:45:40.878Z,1619660740.878 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0090.lzma 2021-04-29T01:45:41.449Z,1619660741.449 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0090.lzma.bak 2021-04-29T01:45:41.449Z,1619660741.449 [DataOverHttps](INFO): SBD MOMSN=15608021 2021-04-29T01:45:57.895Z,1619660757.895 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0091.lzma 2021-04-29T01:45:58.897Z,1619660758.897 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0091.lzma.bak 2021-04-29T01:45:58.897Z,1619660758.897 [DataOverHttps](INFO): SBD MOMSN=15608024 2021-04-29T01:46:00.675Z,1619660760.675 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:46:00.675Z,1619660760.675 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:46:00.676Z,1619660760.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:47:00.452Z,1619660820.452 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-29T01:47:00.452Z,1619660820.452 [DropWeight] Hardware Fault, FailCount= 1 2021-04-29T01:47:00.452Z,1619660820.452 [DropWeight](ERROR): Hardware Fault 2021-04-29T01:47:00.534Z,1619660820.534 [CBIT](INFO): Critical error at 20210429T014700 2021-04-29T01:47:00.540Z,1619660820.540 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-29T01:47:00.541Z,1619660820.541 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-29T01:47:00.879Z,1619660820.879 [CBIT](INFO): Critical error at 20210429T014700 2021-04-29T01:48:14.790Z,1619660894.790 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:48:14.791Z,1619660894.791 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:48:49.238Z,1619660929.238 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:48:49.238Z,1619660929.238 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:49:07.018Z,1619660947.018 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:49:07.018Z,1619660947.018 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:49:24.380Z,1619660964.380 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:49:24.380Z,1619660964.380 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:49:37.310Z,1619660977.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:49:37.310Z,1619660977.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:50:33.474Z,1619661033.474 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:50:33.474Z,1619661033.474 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:50:42.384Z,1619661042.384 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T01:51:01.363Z,1619661061.363 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:51:01.363Z,1619661061.363 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:51:01.363Z,1619661061.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:51:01.364Z,1619661061.364 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:51:01.781Z,1619661061.781 [Default:CheckIn:D] Stopped 2021-04-29T01:51:01.781Z,1619661061.781 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 184.112891 min 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn:E] Stopped 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn] Stopped 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn](INFO): Running loop #34 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn] Running Loop=34 2021-04-29T01:51:02.177Z,1619661062.177 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:51:02.178Z,1619661062.178 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:51:04.175Z,1619661064.175 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,015103.00,A,3648.16670,N,12147.28920,W,0.156,0.00,290421,,,D*7E 2021-04-29T01:51:04.178Z,1619661064.178 [NAL9602](INFO): GPS fix at 20210429T015103: (36.802778, -121.788153) 2021-04-29T01:51:04.189Z,1619661064.189 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:51:04.190Z,1619661064.190 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:51:11.975Z,1619661071.975 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210428T225703/Courier0093.lzma 2021-04-29T01:51:12.977Z,1619661072.977 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0093.lzma.bak 2021-04-29T01:51:12.978Z,1619661072.978 [DataOverHttps](INFO): SBD MOMSN=15608033 2021-04-29T01:51:29.327Z,1619661089.327 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210428T225703/Express0094.lzma 2021-04-29T01:51:30.330Z,1619661090.330 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0094.lzma.bak 2021-04-29T01:51:30.330Z,1619661090.330 [DataOverHttps](INFO): SBD MOMSN=15608038 2021-04-29T01:51:32.087Z,1619661092.087 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:51:32.087Z,1619661092.087 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:51:32.087Z,1619661092.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:51:36.496Z,1619661096.496 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T01:56:32.790Z,1619661392.790 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T01:56:32.791Z,1619661392.791 [Default:CheckIn:C.Wait] Stopped 2021-04-29T01:56:32.791Z,1619661392.791 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T01:56:32.791Z,1619661392.791 [Default:CheckIn:D] Running Loop=1 2021-04-29T01:56:33.144Z,1619661393.144 [Default:CheckIn:D] Stopped 2021-04-29T01:56:33.144Z,1619661393.144 [Default:CheckIn:E] Running Loop=1 2021-04-29T01:56:33.616Z,1619661393.616 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.635612 min 2021-04-29T01:56:33.616Z,1619661393.616 [Default:CheckIn:E] Stopped 2021-04-29T01:56:33.616Z,1619661393.616 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn] Stopped 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn](INFO): Running loop #35 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn] Running Loop=35 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T01:56:33.617Z,1619661393.617 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T01:56:35.566Z,1619661395.566 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,015634.00,A,3648.16411,N,12147.28500,W,0.194,0.00,290421,,,A*7D 2021-04-29T01:56:35.577Z,1619661395.577 [NAL9602](INFO): GPS fix at 20210429T015634: (36.802735, -121.788083) 2021-04-29T01:56:35.639Z,1619661395.639 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T01:56:35.639Z,1619661395.639 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T01:56:44.375Z,1619661404.375 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0096.lzma 2021-04-29T01:56:45.377Z,1619661405.377 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0096.lzma.bak 2021-04-29T01:56:45.377Z,1619661405.377 [DataOverHttps](INFO): SBD MOMSN=15608042 2021-04-29T01:57:01.743Z,1619661421.743 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0097.lzma 2021-04-29T01:57:02.745Z,1619661422.745 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0097.lzma.bak 2021-04-29T01:57:02.745Z,1619661422.745 [DataOverHttps](INFO): SBD MOMSN=15608045 2021-04-29T01:57:04.674Z,1619661424.674 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T01:57:04.674Z,1619661424.674 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T01:57:04.674Z,1619661424.674 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T01:57:06.256Z,1619661426.256 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T01:57:06.335Z,1619661426.335 [NAL9602](ERROR): received: +CSQ:0 OK632, 2, 0, 0, 0 OK 2021-04-29T01:58:37.638Z,1619661517.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:58:37.638Z,1619661517.638 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:58:54.621Z,1619661534.621 [NAL9602](INFO): SBD MO Status=2, MOMSN=14632, MT Status=2, MTMSN=0 2021-04-29T01:58:54.621Z,1619661534.621 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T01:59:03.909Z,1619661543.909 [NAL9602](INFO): SBD MO Status=0, MOMSN=14632, MT Status=0, MTMSN=0 2021-04-29T01:59:03.910Z,1619661543.910 [NAL9602](INFO): No messages in MT queue 2021-04-29T01:59:34.608Z,1619661574.608 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:01:44.333Z,1619661704.333 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2021-04-29T02:02:00.503Z,1619661720.503 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-29T02:02:00.503Z,1619661720.503 [DropWeight] No Fault, FailCount= 1 2021-04-29T02:02:05.322Z,1619661725.322 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:02:05.322Z,1619661725.322 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:02:05.322Z,1619661725.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:02:05.323Z,1619661725.323 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:02:05.752Z,1619661725.752 [Default:CheckIn:D] Stopped 2021-04-29T02:02:05.752Z,1619661725.752 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 195.179085 min 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn:E] Stopped 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn] Stopped 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn](INFO): Running loop #36 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn] Running Loop=36 2021-04-29T02:02:06.153Z,1619661726.153 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:02:06.154Z,1619661726.154 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:02:08.142Z,1619661728.142 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,020207.00,A,3648.16272,N,12147.28608,W,0.603,0.00,290421,,,A*7E 2021-04-29T02:02:08.144Z,1619661728.144 [NAL9602](INFO): GPS fix at 20210429T020207: (36.802712, -121.788101) 2021-04-29T02:02:08.184Z,1619661728.184 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:02:08.184Z,1619661728.184 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:02:15.787Z,1619661735.787 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0099.lzma 2021-04-29T02:02:16.789Z,1619661736.789 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0099.lzma.bak 2021-04-29T02:02:16.789Z,1619661736.789 [DataOverHttps](INFO): SBD MOMSN=15608056 2021-04-29T02:02:36.544Z,1619661756.544 [NAL9602](INFO): SBD MO Status=2, MOMSN=14633, MT Status=2, MTMSN=0 2021-04-29T02:02:36.544Z,1619661756.544 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:02:41.535Z,1619661761.535 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210428T225703/Express0100.lzma 2021-04-29T02:02:42.538Z,1619661762.538 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0100.lzma.bak 2021-04-29T02:02:42.538Z,1619661762.538 [DataOverHttps](INFO): SBD MOMSN=15608059 2021-04-29T02:02:44.316Z,1619661764.316 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:02:44.316Z,1619661764.316 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:02:44.317Z,1619661764.317 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:04:48.311Z,1619661888.311 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2021-04-29T02:06:49.974Z,1619662009.974 [NAL9602](INFO): SBD MO Status=0, MOMSN=14633, MT Status=0, MTMSN=0 2021-04-29T02:06:49.974Z,1619662009.974 [NAL9602](INFO): No messages in MT queue 2021-04-29T02:07:20.674Z,1619662040.674 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:07:44.925Z,1619662064.925 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:07:44.925Z,1619662064.925 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:07:44.925Z,1619662064.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:07:44.926Z,1619662064.926 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:07:45.365Z,1619662065.365 [Default:CheckIn:D] Stopped 2021-04-29T02:07:45.365Z,1619662065.365 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 200.839307 min 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn:E] Stopped 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn] Stopped 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:07:45.758Z,1619662065.758 [Default:CheckIn](INFO): Running loop #37 2021-04-29T02:07:45.759Z,1619662065.759 [Default:CheckIn] Running Loop=37 2021-04-29T02:07:45.759Z,1619662065.759 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:07:45.759Z,1619662065.759 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:07:47.753Z,1619662067.753 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,020747.00,A,3648.16562,N,12147.28563,W,0.272,125.25,290421,,,A*74 2021-04-29T02:07:47.761Z,1619662067.761 [NAL9602](INFO): GPS fix at 20210429T020747: (36.802760, -121.788094) 2021-04-29T02:07:47.781Z,1619662067.781 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:07:47.781Z,1619662067.781 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:07:55.935Z,1619662075.935 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0102.lzma 2021-04-29T02:07:56.937Z,1619662076.937 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0102.lzma.bak 2021-04-29T02:07:56.938Z,1619662076.938 [DataOverHttps](INFO): SBD MOMSN=15608063 2021-04-29T02:08:14.363Z,1619662094.363 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0103.lzma 2021-04-29T02:08:14.501Z,1619662094.501 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0103.lzma.bak 2021-04-29T02:08:14.501Z,1619662094.501 [DataOverHttps](INFO): SBD MOMSN=15608066 2021-04-29T02:08:16.026Z,1619662096.026 [NAL9602](INFO): SBD MO Status=2, MOMSN=14634, MT Status=2, MTMSN=0 2021-04-29T02:08:16.026Z,1619662096.026 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:08:16.460Z,1619662096.460 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:08:16.460Z,1619662096.460 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:08:16.460Z,1619662096.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:08:33.873Z,1619662113.873 [NAL9602](INFO): SBD MO Status=0, MOMSN=14634, MT Status=0, MTMSN=0 2021-04-29T02:08:33.873Z,1619662113.873 [NAL9602](INFO): No messages in MT queue 2021-04-29T02:09:04.584Z,1619662144.584 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:13:17.184Z,1619662397.184 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:13:17.184Z,1619662397.184 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:13:17.184Z,1619662397.184 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:13:17.185Z,1619662397.185 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:13:17.632Z,1619662397.632 [Default:CheckIn:D] Stopped 2021-04-29T02:13:17.632Z,1619662397.632 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:13:17.996Z,1619662397.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 206.377083 min 2021-04-29T02:13:17.996Z,1619662397.996 [Default:CheckIn:E] Stopped 2021-04-29T02:13:17.996Z,1619662397.996 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:13:17.996Z,1619662397.996 [Default:CheckIn] Stopped 2021-04-29T02:13:17.997Z,1619662397.997 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:13:17.997Z,1619662397.997 [Default:CheckIn](INFO): Running loop #38 2021-04-29T02:13:17.997Z,1619662397.997 [Default:CheckIn] Running Loop=38 2021-04-29T02:13:17.997Z,1619662397.997 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:13:17.997Z,1619662397.997 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:13:20.006Z,1619662400.006 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,021319.00,A,3648.16467,N,12147.28743,W,0.564,125.25,290421,,,A*7E 2021-04-29T02:13:20.013Z,1619662400.013 [NAL9602](INFO): GPS fix at 20210429T021319: (36.802745, -121.788124) 2021-04-29T02:13:20.025Z,1619662400.025 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:13:20.025Z,1619662400.025 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:13:27.335Z,1619662407.335 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0105.lzma 2021-04-29T02:13:28.337Z,1619662408.337 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0105.lzma.bak 2021-04-29T02:13:28.337Z,1619662408.337 [DataOverHttps](INFO): SBD MOMSN=15608076 2021-04-29T02:13:45.423Z,1619662425.423 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210428T225703/Express0106.lzma 2021-04-29T02:13:46.426Z,1619662426.426 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0106.lzma.bak 2021-04-29T02:13:46.426Z,1619662426.426 [DataOverHttps](INFO): SBD MOMSN=15608079 2021-04-29T02:13:48.328Z,1619662428.328 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:13:48.328Z,1619662428.328 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:13:48.329Z,1619662428.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:15:35.842Z,1619662535.842 [NAL9602](INFO): SBD MO Status=2, MOMSN=14635, MT Status=2, MTMSN=0 2021-04-29T02:15:35.842Z,1619662535.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:15:50.815Z,1619662550.815 [NAL9602](INFO): SBD MO Status=0, MOMSN=14635, MT Status=0, MTMSN=0 2021-04-29T02:15:50.816Z,1619662550.816 [NAL9602](INFO): No messages in MT queue 2021-04-29T02:16:21.496Z,1619662581.496 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:18:48.978Z,1619662728.978 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:18:48.978Z,1619662728.978 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:18:48.978Z,1619662728.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:18:48.978Z,1619662728.978 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:18:49.396Z,1619662729.396 [Default:CheckIn:D] Stopped 2021-04-29T02:18:49.396Z,1619662729.396 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 211.906478 min 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn:E] Stopped 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn] Stopped 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn](INFO): Running loop #39 2021-04-29T02:18:49.825Z,1619662729.825 [Default:CheckIn] Running Loop=39 2021-04-29T02:18:49.826Z,1619662729.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:18:49.826Z,1619662729.826 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:18:51.795Z,1619662731.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,021851.00,A,3648.16518,N,12147.28880,W,1.069,0.00,290421,,,A*78 2021-04-29T02:18:51.797Z,1619662731.797 [NAL9602](INFO): GPS fix at 20210429T021851: (36.802753, -121.788147) 2021-04-29T02:18:51.828Z,1619662731.828 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:18:51.828Z,1619662731.828 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:18:59.850Z,1619662739.850 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0108.lzma 2021-04-29T02:19:00.853Z,1619662740.853 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0108.lzma.bak 2021-04-29T02:19:00.854Z,1619662740.854 [DataOverHttps](INFO): SBD MOMSN=15608083 2021-04-29T02:19:17.231Z,1619662757.231 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0109.lzma 2021-04-29T02:19:18.235Z,1619662758.235 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0109.lzma.bak 2021-04-29T02:19:18.236Z,1619662758.236 [DataOverHttps](INFO): SBD MOMSN=15608086 2021-04-29T02:19:20.128Z,1619662760.128 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:19:20.128Z,1619662760.128 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:19:20.128Z,1619662760.128 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:19:22.090Z,1619662762.090 [NAL9602](INFO): SBD MO Status=2, MOMSN=14636, MT Status=2, MTMSN=0 2021-04-29T02:19:22.090Z,1619662762.090 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:20:05.719Z,1619662805.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=14636, MT Status=0, MTMSN=0 2021-04-29T02:20:05.720Z,1619662805.720 [NAL9602](INFO): No messages in MT queue 2021-04-29T02:20:36.440Z,1619662836.440 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:24:20.769Z,1619663060.769 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:24:20.769Z,1619663060.769 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:24:20.769Z,1619663060.769 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:24:20.769Z,1619663060.769 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:24:21.153Z,1619663061.153 [Default:CheckIn:D] Stopped 2021-04-29T02:24:21.153Z,1619663061.153 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:24:21.611Z,1619663061.611 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 217.435758 min 2021-04-29T02:24:21.611Z,1619663061.611 [Default:CheckIn:E] Stopped 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn] Stopped 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn](INFO): Running loop #40 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn] Running Loop=40 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:24:21.612Z,1619663061.612 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:24:23.570Z,1619663063.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,022422.00,A,3648.16528,N,12147.28799,W,0.233,0.00,290421,,,A*7B 2021-04-29T02:24:23.573Z,1619663063.573 [NAL9602](INFO): GPS fix at 20210429T022422: (36.802755, -121.788133) 2021-04-29T02:24:23.653Z,1619663063.653 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:24:23.653Z,1619663063.653 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:24:35.449Z,1619663075.449 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0111.lzma 2021-04-29T02:24:36.445Z,1619663076.445 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0111.lzma.bak 2021-04-29T02:24:36.445Z,1619663076.445 [DataOverHttps](INFO): SBD MOMSN=15608096 2021-04-29T02:24:54.435Z,1619663094.435 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210428T225703/Express0112.lzma 2021-04-29T02:24:55.437Z,1619663095.437 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0112.lzma.bak 2021-04-29T02:24:55.438Z,1619663095.438 [DataOverHttps](INFO): SBD MOMSN=15608099 2021-04-29T02:24:57.158Z,1619663097.158 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:24:57.158Z,1619663097.158 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:24:57.158Z,1619663097.158 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:25:21.770Z,1619663121.770 [NAL9602](INFO): SBD MO Status=2, MOMSN=14637, MT Status=2, MTMSN=0 2021-04-29T02:25:21.770Z,1619663121.770 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:25:43.586Z,1619663143.586 [NAL9602](INFO): SBD MO Status=0, MOMSN=14637, MT Status=0, MTMSN=0 2021-04-29T02:25:43.586Z,1619663143.586 [NAL9602](INFO): No messages in MT queue 2021-04-29T02:26:14.282Z,1619663174.282 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:28:25.623Z,1619663305.623 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2021-04-29T02:29:57.753Z,1619663397.753 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:29:57.753Z,1619663397.753 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:29:57.753Z,1619663397.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:29:57.754Z,1619663397.754 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:29:58.143Z,1619663398.143 [Default:CheckIn:D] Stopped 2021-04-29T02:29:58.143Z,1619663398.143 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 223.052262 min 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn:E] Stopped 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn] Stopped 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:29:58.555Z,1619663398.555 [Default:CheckIn](INFO): Running loop #41 2021-04-29T02:29:58.556Z,1619663398.556 [Default:CheckIn] Running Loop=41 2021-04-29T02:29:58.556Z,1619663398.556 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:29:58.556Z,1619663398.556 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:30:00.558Z,1619663400.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,022959.00,A,3648.16370,N,12147.28492,W,0.097,0.00,290421,,,A*75 2021-04-29T02:30:00.560Z,1619663400.560 [NAL9602](INFO): GPS fix at 20210429T022959: (36.802728, -121.788082) 2021-04-29T02:30:00.673Z,1619663400.673 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:30:00.673Z,1619663400.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:30:07.823Z,1619663407.823 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0114.lzma 2021-04-29T02:30:08.825Z,1619663408.825 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0114.lzma.bak 2021-04-29T02:30:08.825Z,1619663408.825 [DataOverHttps](INFO): SBD MOMSN=15608103 2021-04-29T02:30:28.855Z,1619663428.855 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210428T225703/Express0115.lzma 2021-04-29T02:30:29.857Z,1619663429.857 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0115.lzma.bak 2021-04-29T02:30:29.858Z,1619663429.858 [DataOverHttps](INFO): SBD MOMSN=15608106 2021-04-29T02:30:32.334Z,1619663432.334 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:30:32.334Z,1619663432.334 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:30:32.334Z,1619663432.334 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:32:01.980Z,1619663521.980 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-29T02:32:01.980Z,1619663521.980 [DropWeight] Hardware Fault, FailCount= 1 2021-04-29T02:32:01.980Z,1619663521.980 [DropWeight](ERROR): Hardware Fault 2021-04-29T02:32:01.000Z,1619663522.000 [CBIT](INFO): Critical error at 20210429T023201 2021-04-29T02:32:02.002Z,1619663522.002 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-29T02:32:02.002Z,1619663522.002 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-29T02:32:02.462Z,1619663522.462 [CBIT](INFO): Critical error at 20210429T023202 2021-04-29T02:34:21.594Z,1619663661.594 [NAL9602](INFO): SBD MO Status=2, MOMSN=14638, MT Status=2, MTMSN=0 2021-04-29T02:34:21.594Z,1619663661.594 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:34:38.841Z,1619663678.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=14638, MT Status=2, MTMSN=0 2021-04-29T02:34:38.842Z,1619663678.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:35:02.352Z,1619663702.352 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T02:35:32.976Z,1619663732.976 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:35:33.004Z,1619663733.004 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:35:33.004Z,1619663733.004 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:35:33.004Z,1619663733.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:35:33.005Z,1619663733.005 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:35:33.403Z,1619663733.403 [Default:CheckIn:D] Stopped 2021-04-29T02:35:33.403Z,1619663733.403 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:35:33.841Z,1619663733.841 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 228.639860 min 2021-04-29T02:35:33.841Z,1619663733.841 [Default:CheckIn:E] Stopped 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn] Stopped 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn](INFO): Running loop #42 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn] Running Loop=42 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:35:33.842Z,1619663733.842 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:35:35.806Z,1619663735.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,023535.00,A,3648.16474,N,12147.28161,W,0.156,0.00,290421,,,A*74 2021-04-29T02:35:35.808Z,1619663735.808 [NAL9602](INFO): GPS fix at 20210429T023535: (36.802746, -121.788027) 2021-04-29T02:35:35.884Z,1619663735.884 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:35:35.885Z,1619663735.885 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:35:37.332Z,1619663737.332 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20210428T225703/Courier0117.lzma 2021-04-29T02:35:37.917Z,1619663737.917 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0117.lzma.bak 2021-04-29T02:35:37.917Z,1619663737.917 [DataOverHttps](INFO): SBD MOMSN=15608116 2021-04-29T02:35:54.767Z,1619663754.767 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210428T225703/Express0118.lzma 2021-04-29T02:35:55.777Z,1619663755.777 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0118.lzma.bak 2021-04-29T02:35:55.777Z,1619663755.777 [DataOverHttps](INFO): SBD MOMSN=15608121 2021-04-29T02:35:57.743Z,1619663757.743 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:35:57.743Z,1619663757.743 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:35:57.743Z,1619663757.743 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:36:06.651Z,1619663766.651 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-29T02:36:06.723Z,1619663766.723 [NAL9602](ERROR): received: +CSQ:0 OK638, 2, 0, 0, 0 OK 2021-04-29T02:36:47.418Z,1619663807.418 [NAL9602](INFO): SBD MO Status=2, MOMSN=14638, MT Status=2, MTMSN=0 2021-04-29T02:36:47.418Z,1619663807.418 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:38:47.332Z,1619663927.332 [NAL9602](INFO): SBD MO Status=2, MOMSN=14638, MT Status=2, MTMSN=0 2021-04-29T02:38:47.332Z,1619663927.332 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:39:05.136Z,1619663945.136 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2021-04-29T02:39:05.138Z,1619663945.138 [BPC1](INFO): Received data from all battery sticks. 2021-04-29T02:40:38.433Z,1619664038.433 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T02:40:58.241Z,1619664058.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:40:58.241Z,1619664058.241 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:40:58.241Z,1619664058.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:40:58.241Z,1619664058.241 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:40:58.683Z,1619664058.683 [Default:CheckIn:D] Stopped 2021-04-29T02:40:58.684Z,1619664058.684 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:40:59.059Z,1619664059.059 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 234.061279 min 2021-04-29T02:40:59.059Z,1619664059.059 [Default:CheckIn:E] Stopped 2021-04-29T02:40:59.059Z,1619664059.059 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:40:59.059Z,1619664059.059 [Default:CheckIn] Stopped 2021-04-29T02:40:59.060Z,1619664059.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:40:59.060Z,1619664059.060 [Default:CheckIn](INFO): Running loop #43 2021-04-29T02:40:59.060Z,1619664059.060 [Default:CheckIn] Running Loop=43 2021-04-29T02:40:59.060Z,1619664059.060 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:40:59.060Z,1619664059.060 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:41:01.059Z,1619664061.059 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,024100.00,A,3648.16342,N,12147.28528,W,0.039,134.36,290421,,,A*71 2021-04-29T02:41:01.062Z,1619664061.062 [NAL9602](INFO): GPS fix at 20210429T024100: (36.802724, -121.788088) 2021-04-29T02:41:01.098Z,1619664061.098 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:41:01.098Z,1619664061.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:41:09.167Z,1619664069.167 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210428T225703/Courier0120.lzma 2021-04-29T02:41:10.169Z,1619664070.169 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0120.lzma.bak 2021-04-29T02:41:10.169Z,1619664070.169 [DataOverHttps](INFO): SBD MOMSN=15608125 2021-04-29T02:41:26.535Z,1619664086.535 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210428T225703/Express0121.lzma 2021-04-29T02:41:27.537Z,1619664087.537 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0121.lzma.bak 2021-04-29T02:41:27.538Z,1619664087.538 [DataOverHttps](INFO): SBD MOMSN=15608128 2021-04-29T02:41:29.358Z,1619664089.358 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:41:29.358Z,1619664089.358 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:41:29.358Z,1619664089.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:41:33.380Z,1619664093.380 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:46:30.134Z,1619664390.134 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:46:30.134Z,1619664390.134 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:46:30.135Z,1619664390.135 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:46:30.135Z,1619664390.135 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:46:30.504Z,1619664390.504 [Default:CheckIn:D] Stopped 2021-04-29T02:46:30.504Z,1619664390.504 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 239.591618 min 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn:E] Stopped 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn] Stopped 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:46:30.881Z,1619664390.881 [Default:CheckIn](INFO): Running loop #44 2021-04-29T02:46:30.882Z,1619664390.882 [Default:CheckIn] Running Loop=44 2021-04-29T02:46:30.882Z,1619664390.882 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:46:30.882Z,1619664390.882 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:46:32.890Z,1619664392.890 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,024632.00,A,3648.16390,N,12147.28433,W,0.330,134.36,290421,,,D*7C 2021-04-29T02:46:32.892Z,1619664392.892 [NAL9602](INFO): GPS fix at 20210429T024632: (36.802732, -121.788072) 2021-04-29T02:46:32.937Z,1619664392.937 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:46:32.937Z,1619664392.937 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:46:43.578Z,1619664403.578 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0123.lzma 2021-04-29T02:46:44.581Z,1619664404.581 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0123.lzma.bak 2021-04-29T02:46:44.581Z,1619664404.581 [DataOverHttps](INFO): SBD MOMSN=15608138 2021-04-29T02:47:01.061Z,1619664421.061 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210428T225703/Express0124.lzma 2021-04-29T02:47:02.030Z,1619664422.030 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-29T02:47:02.030Z,1619664422.030 [DropWeight] No Fault, FailCount= 1 2021-04-29T02:47:02.062Z,1619664422.062 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0124.lzma.bak 2021-04-29T02:47:02.062Z,1619664422.062 [DataOverHttps](INFO): SBD MOMSN=15608141 2021-04-29T02:47:03.651Z,1619664423.651 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:47:03.652Z,1619664423.652 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:47:03.652Z,1619664423.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:47:31.087Z,1619664451.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=14638, MT Status=2, MTMSN=0 2021-04-29T02:47:31.088Z,1619664451.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-29T02:51:35.593Z,1619664695.593 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T02:52:04.286Z,1619664724.286 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:52:04.286Z,1619664724.286 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:52:04.286Z,1619664724.286 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:52:04.286Z,1619664724.286 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:52:04.682Z,1619664724.682 [Default:CheckIn:D] Stopped 2021-04-29T02:52:04.682Z,1619664724.682 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 245.161247 min 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn:E] Stopped 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn] Stopped 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn](INFO): Running loop #45 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn] Running Loop=45 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:52:05.108Z,1619664725.108 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:52:07.091Z,1619664727.091 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,025206.00,A,3648.16487,N,12147.28381,W,0.214,134.36,290421,,,D*76 2021-04-29T02:52:07.093Z,1619664727.093 [NAL9602](INFO): GPS fix at 20210429T025206: (36.802748, -121.788064) 2021-04-29T02:52:07.123Z,1619664727.123 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:52:07.123Z,1619664727.123 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:52:15.550Z,1619664735.550 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0126.lzma 2021-04-29T02:52:16.553Z,1619664736.553 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0126.lzma.bak 2021-04-29T02:52:16.554Z,1619664736.554 [DataOverHttps](INFO): SBD MOMSN=15608144 2021-04-29T02:52:39.156Z,1619664759.156 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-29T02:52:40.800Z,1619664760.800 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210428T225703/Express0127.lzma 2021-04-29T02:52:41.801Z,1619664761.801 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0127.lzma.bak 2021-04-29T02:52:41.802Z,1619664761.802 [DataOverHttps](INFO): SBD MOMSN=15608147 2021-04-29T02:52:43.630Z,1619664763.630 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:52:43.631Z,1619664763.631 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:52:43.631Z,1619664763.631 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T02:57:44.292Z,1619665064.292 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T02:57:44.292Z,1619665064.292 [Default:CheckIn:C.Wait] Stopped 2021-04-29T02:57:44.292Z,1619665064.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T02:57:44.292Z,1619665064.292 [Default:CheckIn:D] Running Loop=1 2021-04-29T02:57:44.672Z,1619665064.672 [Default:CheckIn:D] Stopped 2021-04-29T02:57:44.672Z,1619665064.672 [Default:CheckIn:E] Running Loop=1 2021-04-29T02:57:45.112Z,1619665065.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 250.827751 min 2021-04-29T02:57:45.112Z,1619665065.112 [Default:CheckIn:E] Stopped 2021-04-29T02:57:45.112Z,1619665065.112 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T02:57:45.112Z,1619665065.112 [Default:CheckIn] Stopped 2021-04-29T02:57:45.113Z,1619665065.113 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T02:57:45.113Z,1619665065.113 [Default:CheckIn](INFO): Running loop #46 2021-04-29T02:57:45.113Z,1619665065.113 [Default:CheckIn] Running Loop=46 2021-04-29T02:57:45.113Z,1619665065.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T02:57:45.113Z,1619665065.113 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T02:57:47.099Z,1619665067.099 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,025746.00,A,3648.16544,N,12147.28419,W,0.136,0.00,290421,,,D*7F 2021-04-29T02:57:47.101Z,1619665067.101 [NAL9602](INFO): GPS fix at 20210429T025746: (36.802757, -121.788070) 2021-04-29T02:57:47.155Z,1619665067.155 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T02:57:47.155Z,1619665067.155 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T02:57:54.718Z,1619665074.718 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210428T225703/Courier0129.lzma 2021-04-29T02:57:55.721Z,1619665075.721 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0129.lzma.bak 2021-04-29T02:57:55.722Z,1619665075.722 [DataOverHttps](INFO): SBD MOMSN=15608157 2021-04-29T02:58:12.114Z,1619665092.114 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210428T225703/Express0130.lzma 2021-04-29T02:58:13.113Z,1619665093.113 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Express0130.lzma.bak 2021-04-29T02:58:13.114Z,1619665093.114 [DataOverHttps](INFO): SBD MOMSN=15608160 2021-04-29T02:58:14.991Z,1619665094.991 [Default:CheckIn:Read_Iridium] Stopped 2021-04-29T02:58:14.991Z,1619665094.991 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-29T02:58:14.991Z,1619665094.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-29T03:02:49.428Z,1619665369.428 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-29T03:03:15.697Z,1619665395.697 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-29T03:03:15.697Z,1619665395.697 [Default:CheckIn:C.Wait] Stopped 2021-04-29T03:03:15.697Z,1619665395.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-29T03:03:15.697Z,1619665395.697 [Default:CheckIn:D] Running Loop=1 2021-04-29T03:03:16.118Z,1619665396.118 [Default:CheckIn:D] Stopped 2021-04-29T03:03:16.118Z,1619665396.118 [Default:CheckIn:E] Running Loop=1 2021-04-29T03:03:16.512Z,1619665396.512 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 256.351839 min 2021-04-29T03:03:16.512Z,1619665396.512 [Default:CheckIn:E] Stopped 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn] Stopped 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn](INFO): Running loop #47 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn] Running Loop=47 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-29T03:03:16.513Z,1619665396.513 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-29T03:03:18.518Z,1619665398.518 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,030317.00,A,3648.16327,N,12147.28328,W,0.136,42.44,290421,,,A*4E 2021-04-29T03:03:18.521Z,1619665398.521 [NAL9602](INFO): GPS fix at 20210429T030317: (36.802721, -121.788055) 2021-04-29T03:03:18.549Z,1619665398.549 [Default:CheckIn:Read_GPS] Stopped 2021-04-29T03:03:18.549Z,1619665398.549 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-29T03:03:26.275Z,1619665406.275 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210428T225703/Courier0132.lzma 2021-04-29T03:03:27.277Z,1619665407.277 [DataOverHttps](INFO): Moved sent file to Logs/20210428T225703/Courier0132.lzma.bak 2021-04-29T03:03:27.278Z,1619665407.278 [DataOverHttps](INFO): SBD MOMSN=15608163 2021-04-29T03:03:43.619Z,161966