2021-08-19T14:50:07.373Z,1629384607.373 [CommandLine](IMPORTANT): got command restart logs 2021-08-19T14:52:12.158Z,1629384732.158 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T14:52:12.159Z,1629384732.159 [Default:CheckIn:C.Wait] Stopped 2021-08-19T14:52:12.159Z,1629384732.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T14:52:12.162Z,1629384732.162 [Default:CheckIn:D] Running Loop=1 2021-08-19T14:52:12.567Z,1629384732.567 [Default:CheckIn:D] Stopped 2021-08-19T14:52:12.568Z,1629384732.568 [Default:CheckIn:E] Running Loop=1 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.654776 min 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn:E] Stopped 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn] Stopped 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn](INFO): Running loop #3 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn] Running Loop=3 2021-08-19T14:52:12.989Z,1629384732.989 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T14:52:12.990Z,1629384732.990 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T14:52:14.983Z,1629384734.983 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145207.00,A,4244.92630,N,08614.93531,W,0.700,165.10,190821,,,D*75 2021-08-19T14:52:14.986Z,1629384734.986 [NAL9602](INFO): GPS fix at 20210819T145207: (42.748772, -86.248922) 2021-08-19T14:52:15.015Z,1629384735.015 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T14:52:15.020Z,1629384735.020 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T14:52:33.562Z,1629384753.562 [NAL9602](INFO): SBD MO Status=0, MOMSN=46874, MT Status=0, MTMSN=0 2021-08-19T14:52:33.562Z,1629384753.562 [NAL9602](INFO): No messages in MT queue 2021-08-19T14:52:55.055Z,1629384775.055 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210819T122057/Courier0031.lzma 2021-08-19T14:52:56.058Z,1629384776.058 [DataOverHttps](INFO): Moved sent file to Logs/20210819T122057/Courier0031.lzma.bak 2021-08-19T14:52:56.058Z,1629384776.058 [DataOverHttps](INFO): SBD MOMSN=15895408 2021-08-19T14:53:04.264Z,1629384784.264 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T14:53:30.529Z,1629384810.529 [DVL_micro](ERROR): Failed to parse: 04,-00001,+00036,+00000,I 2021-08-19T14:53:35.784Z,1629384815.784 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T14:53:35.784Z,1629384815.784 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0000.0,1489.0,0-00268,+00085,+00155,+00000,A 2021-08-19T14:53:40.626Z,1629384820.626 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T14:53:40.627Z,1629384820.627 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+23.7,0000.0,10 2021-08-19T14:53:52.416Z,1629384832.416 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210819T145007/Courier0000.lzma 2021-08-19T14:53:53.417Z,1629384833.417 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0000.lzma.bak 2021-08-19T14:53:53.418Z,1629384833.418 [DataOverHttps](INFO): SBD MOMSN=15895410 2021-08-19T14:54:46.665Z,1629384886.665 [DataOverHttps](IMPORTANT): SBD MTMSN=20210819T145439 2021-08-19T14:54:54.716Z,1629384894.716 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20210819T122057/Express0032.lzma 2021-08-19T14:54:54.718Z,1629384894.718 [DataOverHttps](INFO): Received command:strobe off 2021-08-19T14:54:54.721Z,1629384894.721 [CommandLine](IMPORTANT): got command strobe off 2021-08-19T14:54:54.721Z,1629384894.721 [CommandLine](IMPORTANT): Deactivating strobe 2021-08-19T14:54:56.011Z,1629384896.011 [DataOverHttps](INFO): Moved sent file to Logs/20210819T122057/Express0032.lzma.bak 2021-08-19T14:54:56.011Z,1629384896.011 [DataOverHttps](INFO): SBD MOMSN=15895417 2021-08-19T14:55:11.471Z,1629384911.471 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210819T145007/Courier0006.lzma 2021-08-19T14:55:12.474Z,1629384912.474 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0006.lzma.bak 2021-08-19T14:55:12.474Z,1629384912.474 [DataOverHttps](INFO): SBD MOMSN=15895422 2021-08-19T14:55:29.604Z,1629384929.604 [DataOverHttps](INFO): Sending 391 bytes from file Logs/20210819T145007/Express0001.lzma 2021-08-19T14:55:30.606Z,1629384930.606 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0001.lzma.bak 2021-08-19T14:55:30.606Z,1629384930.606 [DataOverHttps](INFO): SBD MOMSN=15895424 2021-08-19T14:55:51.319Z,1629384951.319 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210819T145007/Express0004.lzma 2021-08-19T14:55:52.322Z,1629384952.322 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0004.lzma.bak 2021-08-19T14:55:52.322Z,1629384952.322 [DataOverHttps](INFO): SBD MOMSN=15895428 2021-08-19T14:56:09.468Z,1629384969.468 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20210819T145007/Express0007.lzma 2021-08-19T14:56:10.470Z,1629384970.470 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0007.lzma.bak 2021-08-19T14:56:10.470Z,1629384970.470 [DataOverHttps](INFO): SBD MOMSN=15895430 2021-08-19T14:56:13.085Z,1629384973.085 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T14:56:13.085Z,1629384973.085 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T14:56:13.085Z,1629384973.085 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:01:13.699Z,1629385273.699 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:01:13.699Z,1629385273.699 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:01:13.699Z,1629385273.699 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:01:13.699Z,1629385273.699 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:01:14.113Z,1629385274.113 [Default:CheckIn:D] Stopped 2021-08-19T15:01:14.113Z,1629385274.113 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:01:14.505Z,1629385274.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.680540 min 2021-08-19T15:01:14.505Z,1629385274.505 [Default:CheckIn:E] Stopped 2021-08-19T15:01:14.505Z,1629385274.505 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn] Stopped 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn](INFO): Running loop #4 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn] Running Loop=4 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:01:14.506Z,1629385274.506 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:01:16.520Z,1629385276.520 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150109.00,A,4244.82722,N,08614.92160,W,0.972,177.03,190821,,,D*74 2021-08-19T15:01:16.522Z,1629385276.522 [NAL9602](INFO): GPS fix at 20210819T150109: (42.747120, -86.248693) 2021-08-19T15:01:16.532Z,1629385276.532 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:01:16.532Z,1629385276.532 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:01:28.475Z,1629385288.475 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0009.lzma 2021-08-19T15:01:29.478Z,1629385289.478 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0009.lzma.bak 2021-08-19T15:01:29.478Z,1629385289.478 [DataOverHttps](INFO): SBD MOMSN=15895441 2021-08-19T15:01:40.001Z,1629385300.001 [NAL9602](INFO): SBD MO Status=2, MOMSN=46875, MT Status=2, MTMSN=0 2021-08-19T15:01:40.002Z,1629385300.002 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:01:49.560Z,1629385309.560 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0010.lzma 2021-08-19T15:01:50.562Z,1629385310.562 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0010.lzma.bak 2021-08-19T15:01:50.562Z,1629385310.562 [DataOverHttps](INFO): SBD MOMSN=15895444 2021-08-19T15:01:52.992Z,1629385312.992 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:01:52.993Z,1629385312.993 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:01:52.993Z,1629385312.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:01:56.206Z,1629385316.206 [NAL9602](INFO): SBD MO Status=0, MOMSN=46875, MT Status=0, MTMSN=0 2021-08-19T15:01:56.206Z,1629385316.206 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:02:26.912Z,1629385346.912 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:02:51.100Z,1629385371.100 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.539089 2021-08-19T15:03:01.445Z,1629385381.445 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003452 2021-08-19T15:04:32.521Z,1629385472.521 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.663441 2021-08-19T15:05:26.748Z,1629385526.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:05:57.888Z,1629385557.888 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:06:29.020Z,1629385589.020 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:06:53.571Z,1629385613.571 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:06:53.571Z,1629385613.571 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:06:53.571Z,1629385613.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:06:53.571Z,1629385613.571 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:06:53.968Z,1629385613.968 [Default:CheckIn:D] Stopped 2021-08-19T15:06:53.968Z,1629385613.968 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:06:54.362Z,1629385614.362 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.344792 min 2021-08-19T15:06:54.362Z,1629385614.362 [Default:CheckIn:E] Stopped 2021-08-19T15:06:54.362Z,1629385614.362 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:06:54.362Z,1629385614.362 [Default:CheckIn] Stopped 2021-08-19T15:06:54.362Z,1629385614.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:06:54.363Z,1629385614.363 [Default:CheckIn](INFO): Running loop #5 2021-08-19T15:06:54.363Z,1629385614.363 [Default:CheckIn] Running Loop=5 2021-08-19T15:06:54.363Z,1629385614.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:06:54.363Z,1629385614.363 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:06:56.380Z,1629385616.380 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150649.00,A,4244.76807,N,08614.90694,W,0.700,169.48,190821,,,D*71 2021-08-19T15:06:56.382Z,1629385616.382 [NAL9602](INFO): GPS fix at 20210819T150649: (42.746134, -86.248449) 2021-08-19T15:06:56.391Z,1629385616.391 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:06:56.391Z,1629385616.391 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:07:00.144Z,1629385620.144 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:07:20.295Z,1629385640.295 [NAL9602](INFO): SBD MO Status=1, MOMSN=46876, MT Status=0, MTMSN=0 2021-08-19T15:07:20.352Z,1629385640.352 [NAL9602](INFO): Sent 72 bytes from file Logs/20210819T145007/Courier0012.lzma 2021-08-19T15:07:20.352Z,1629385640.352 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:07:27.277Z,1629385647.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=46877, MT Status=0, MTMSN=0 2021-08-19T15:07:27.324Z,1629385647.324 [NAL9602](INFO): Sent 142 bytes from file Logs/20210819T145007/Express0013.lzma 2021-08-19T15:07:27.324Z,1629385647.324 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:07:28.910Z,1629385648.910 [DVL_micro](ERROR): Failed to parse: :SA,-01.71,+28.37,097.5 2021-08-19T15:07:31.268Z,1629385651.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:07:31.286Z,1629385651.286 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-19T15:07:31.286Z,1629385651.286 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+9999.99,+9999.99 2021-08-19T15:07:34.111Z,1629385654.111 [NAL9602](INFO): SBD MO Status=0, MOMSN=46878, MT Status=0, MTMSN=0 2021-08-19T15:07:34.203Z,1629385654.203 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:07:34.204Z,1629385654.204 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:07:34.204Z,1629385654.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:08:04.824Z,1629385684.824 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:08:33.692Z,1629385713.692 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:09:04.816Z,1629385744.816 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:09:32.104Z,1629385772.104 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-19T15:09:32.105Z,1629385772.105 [DVL_micro](ERROR): Failed to parse: :BI,- 2021-08-19T15:09:35.940Z,1629385775.940 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:10:07.064Z,1629385807.064 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:10:38.188Z,1629385838.188 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:11:07.737Z,1629385867.737 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003479 2021-08-19T15:12:10.352Z,1629385930.352 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2021-08-19T15:12:19.705Z,1629385939.705 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=62.611530 2021-08-19T15:12:34.770Z,1629385954.770 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:12:34.770Z,1629385954.770 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:12:34.770Z,1629385954.770 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:12:34.770Z,1629385954.770 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:12:35.170Z,1629385955.170 [Default:CheckIn:D] Stopped 2021-08-19T15:12:35.170Z,1629385955.170 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:12:35.592Z,1629385955.592 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.031488 min 2021-08-19T15:12:35.592Z,1629385955.592 [Default:CheckIn:E] Stopped 2021-08-19T15:12:35.592Z,1629385955.592 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:12:35.592Z,1629385955.592 [Default:CheckIn] Stopped 2021-08-19T15:12:35.592Z,1629385955.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:12:35.593Z,1629385955.593 [Default:CheckIn](INFO): Running loop #6 2021-08-19T15:12:35.593Z,1629385955.593 [Default:CheckIn] Running Loop=6 2021-08-19T15:12:35.593Z,1629385955.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:12:35.593Z,1629385955.593 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:12:37.600Z,1629385957.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151230.00,A,4244.70393,N,08614.88779,W,0.661,164.19,190821,,,D*7E 2021-08-19T15:12:37.602Z,1629385957.602 [NAL9602](INFO): GPS fix at 20210819T151230: (42.745066, -86.248130) 2021-08-19T15:12:37.611Z,1629385957.611 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:12:37.612Z,1629385957.612 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:13:07.407Z,1629385987.407 [NAL9602](INFO): SBD MO Status=2, MOMSN=46879, MT Status=2, MTMSN=0 2021-08-19T15:13:07.408Z,1629385987.408 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:13:33.577Z,1629386013.577 [NAL9602](INFO): SBD MO Status=1, MOMSN=46879, MT Status=0, MTMSN=0 2021-08-19T15:13:33.624Z,1629386013.624 [NAL9602](INFO): Sent 72 bytes from file Logs/20210819T145007/Courier0015.lzma 2021-08-19T15:13:33.625Z,1629386013.625 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:13:55.068Z,1629386035.068 [NAL9602](INFO): SBD MO Status=2, MOMSN=46880, MT Status=2, MTMSN=0 2021-08-19T15:13:55.068Z,1629386035.068 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:14:00.203Z,1629386040.203 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005289 2021-08-19T15:14:14.596Z,1629386054.596 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0016.lzma 2021-08-19T15:14:15.598Z,1629386055.598 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0016.lzma.bak 2021-08-19T15:14:15.598Z,1629386055.598 [DataOverHttps](INFO): SBD MOMSN=15895460 2021-08-19T15:14:15.659Z,1629386055.659 [NAL9602](INFO): SBD MO Status=1, MOMSN=46880, MT Status=0, MTMSN=0 2021-08-19T15:14:15.708Z,1629386055.708 [NAL9602](INFO): Sent 143 bytes from file Logs/20210819T145007/Express0016.lzma 2021-08-19T15:14:15.708Z,1629386055.708 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:14:18.090Z,1629386058.090 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:14:18.090Z,1629386058.090 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:14:18.090Z,1629386058.090 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:14:46.366Z,1629386086.366 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:16:01.975Z,1629386161.975 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+26.0,0000.0,1489.0,000 2021-08-19T15:17:11.605Z,1629386231.605 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.243507 2021-08-19T15:18:05.820Z,1629386285.820 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:18:10.019Z,1629386290.019 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-19T15:18:36.948Z,1629386316.948 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:19:08.072Z,1629386348.072 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:19:18.713Z,1629386358.713 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:19:18.713Z,1629386358.713 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:19:18.713Z,1629386358.713 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:19:18.713Z,1629386358.713 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:19:19.130Z,1629386359.130 [Default:CheckIn:D] Stopped 2021-08-19T15:19:19.130Z,1629386359.130 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:19:19.518Z,1629386359.518 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.764148 min 2021-08-19T15:19:19.518Z,1629386359.518 [Default:CheckIn:E] Stopped 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn] Stopped 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn](INFO): Running loop #7 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn] Running Loop=7 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:19:19.519Z,1629386359.519 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:19:21.529Z,1629386361.529 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151914.00,A,4246.37230,N,08612.90287,W,6.356,84.29,190821,,,D*4A 2021-08-19T15:19:21.531Z,1629386361.531 [NAL9602](INFO): GPS fix at 20210819T151914: (42.772872, -86.215048) 2021-08-19T15:19:21.541Z,1629386361.541 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:19:21.541Z,1629386361.541 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:19:39.218Z,1629386379.218 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:19:40.039Z,1629386380.039 [NAL9602](INFO): SBD MO Status=1, MOMSN=46881, MT Status=0, MTMSN=0 2021-08-19T15:19:40.096Z,1629386380.096 [NAL9602](INFO): Sent 71 bytes from file Logs/20210819T145007/Courier0018.lzma 2021-08-19T15:19:40.096Z,1629386380.096 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:19:50.050Z,1629386390.050 [NAL9602](INFO): SBD MO Status=1, MOMSN=46882, MT Status=0, MTMSN=0 2021-08-19T15:19:50.104Z,1629386390.104 [NAL9602](INFO): Sent 144 bytes from file Logs/20210819T145007/Express0019.lzma 2021-08-19T15:19:50.104Z,1629386390.104 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:19:58.277Z,1629386398.277 [NAL9602](INFO): SBD MO Status=0, MOMSN=46883, MT Status=0, MTMSN=0 2021-08-19T15:19:58.360Z,1629386398.360 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:19:58.360Z,1629386398.360 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:19:58.360Z,1629386398.360 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:20:28.980Z,1629386428.980 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:20:36.145Z,1629386436.145 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003460 2021-08-19T15:21:42.772Z,1629386502.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:21:51.808Z,1629386511.808 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247189 2021-08-19T15:22:44.026Z,1629386564.026 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:23:15.156Z,1629386595.156 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:23:46.296Z,1629386626.296 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:24:17.432Z,1629386657.432 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:24:48.556Z,1629386688.556 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:24:58.892Z,1629386698.892 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:24:58.892Z,1629386698.892 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:24:58.893Z,1629386698.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:24:58.893Z,1629386698.893 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:24:59.290Z,1629386699.290 [Default:CheckIn:D] Stopped 2021-08-19T15:24:59.290Z,1629386699.290 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:24:59.704Z,1629386699.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.433484 min 2021-08-19T15:24:59.704Z,1629386699.704 [Default:CheckIn:E] Stopped 2021-08-19T15:24:59.704Z,1629386699.704 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:24:59.704Z,1629386699.704 [Default:CheckIn] Stopped 2021-08-19T15:24:59.704Z,1629386699.704 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:24:59.705Z,1629386699.705 [Default:CheckIn](INFO): Running loop #8 2021-08-19T15:24:59.705Z,1629386699.705 [Default:CheckIn] Running Loop=8 2021-08-19T15:24:59.705Z,1629386699.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:24:59.705Z,1629386699.705 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:25:01.706Z,1629386701.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152454.00,A,4246.29308,N,08612.20285,W,5.598,75.86,190821,,,D*40 2021-08-19T15:25:01.709Z,1629386701.709 [NAL9602](INFO): GPS fix at 20210819T152454: (42.771551, -86.203381) 2021-08-19T15:25:01.718Z,1629386701.718 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:25:01.718Z,1629386701.718 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:25:19.680Z,1629386719.680 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:25:24.678Z,1629386724.678 [NAL9602](INFO): SBD MO Status=2, MOMSN=46884, MT Status=2, MTMSN=0 2021-08-19T15:25:24.678Z,1629386724.678 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:25:44.507Z,1629386744.507 [NAL9602](INFO): SBD MO Status=1, MOMSN=46884, MT Status=0, MTMSN=0 2021-08-19T15:25:44.556Z,1629386744.556 [NAL9602](INFO): Sent 72 bytes from file Logs/20210819T145007/Courier0021.lzma 2021-08-19T15:25:44.556Z,1629386744.556 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:25:50.804Z,1629386750.804 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:25:52.377Z,1629386752.377 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T15:25:52.378Z,1629386752.378 [DVL_micro](ERROR): Failed to parse: :BI,-00204,-00104,+0014,I 2021-08-19T15:25:56.422Z,1629386756.422 [NAL9602](INFO): SBD MO Status=2, MOMSN=46885, MT Status=2, MTMSN=0 2021-08-19T15:25:56.422Z,1629386756.422 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:25:57.223Z,1629386757.223 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T15:25:57.223Z,1629386757.223 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.51489.0,000 2021-08-19T15:26:17.890Z,1629386777.890 [NAL9602](INFO): SBD MO Status=1, MOMSN=46885, MT Status=0, MTMSN=0 2021-08-19T15:26:17.948Z,1629386777.948 [NAL9602](INFO): Sent 143 bytes from file Logs/20210819T145007/Express0022.lzma 2021-08-19T15:26:17.948Z,1629386777.948 [NAL9602](INFO): Packets left to send: 0 2021-08-19T15:26:21.928Z,1629386781.928 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:26:25.938Z,1629386785.938 [NAL9602](INFO): SBD MO Status=0, MOMSN=46886, MT Status=0, MTMSN=0 2021-08-19T15:26:26.016Z,1629386786.016 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:26:26.017Z,1629386786.017 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:26:26.017Z,1629386786.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:26:53.052Z,1629386813.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:26:56.628Z,1629386816.628 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:27:24.176Z,1629386844.176 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T15:27:42.965Z,1629386862.965 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003410 2021-08-19T15:31:26.520Z,1629387086.520 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:31:26.520Z,1629387086.520 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:31:26.520Z,1629387086.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:31:26.521Z,1629387086.521 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:31:26.934Z,1629387086.934 [Default:CheckIn:D] Stopped 2021-08-19T15:31:26.934Z,1629387086.934 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.894210 min 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn:E] Stopped 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn] Stopped 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn](INFO): Running loop #9 2021-08-19T15:31:27.332Z,1629387087.332 [Default:CheckIn] Running Loop=9 2021-08-19T15:31:27.333Z,1629387087.333 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:31:27.333Z,1629387087.333 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:31:29.337Z,1629387089.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153122.00,A,4246.64744,N,08611.38081,W,6.667,47.84,190821,,,D*4F 2021-08-19T15:31:29.340Z,1629387089.340 [NAL9602](INFO): GPS fix at 20210819T153122: (42.777457, -86.189680) 2021-08-19T15:31:29.354Z,1629387089.354 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:31:29.354Z,1629387089.354 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:31:35.783Z,1629387095.783 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0024.lzma 2021-08-19T15:31:36.786Z,1629387096.786 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0024.lzma.bak 2021-08-19T15:31:36.786Z,1629387096.786 [DataOverHttps](INFO): SBD MOMSN=15895491 2021-08-19T15:31:42.739Z,1629387102.739 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-19T15:31:42.739Z,1629387102.739 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2021-08-19T15:31:47.664Z,1629387107.664 [DVL_micro](ERROR): only read 1 of 4 data items 2021-08-19T15:31:47.665Z,1629387107.665 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,,+9999.99,+9999.99 2021-08-19T15:31:57.260Z,1629387117.260 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0025.lzma 2021-08-19T15:31:58.262Z,1629387118.262 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0025.lzma.bak 2021-08-19T15:31:58.262Z,1629387118.262 [DataOverHttps](INFO): SBD MOMSN=15895494 2021-08-19T15:32:01.360Z,1629387121.360 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:32:01.361Z,1629387121.361 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:32:01.361Z,1629387121.361 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:32:01.726Z,1629387121.726 [NAL9602](INFO): SBD MO Status=2, MOMSN=46887, MT Status=2, MTMSN=0 2021-08-19T15:32:01.726Z,1629387121.726 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:32:12.250Z,1629387132.250 [NAL9602](INFO): SBD MO Status=0, MOMSN=46887, MT Status=0, MTMSN=0 2021-08-19T15:32:12.250Z,1629387132.250 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:32:42.957Z,1629387162.957 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:33:18.562Z,1629387198.562 [DVL_micro](ERROR): Failed to parse: :BI,-00166,+00189,+00150,+00000,I 2021-08-19T15:36:03.030Z,1629387363.030 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 384 2021-08-19T15:36:03.033Z,1629387363.033 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2021-08-19T15:37:02.035Z,1629387422.035 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:37:02.035Z,1629387422.035 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:37:02.035Z,1629387422.035 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:37:02.035Z,1629387422.035 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:37:02.422Z,1629387422.422 [Default:CheckIn:D] Stopped 2021-08-19T15:37:02.422Z,1629387422.422 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:37:02.823Z,1629387422.823 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.485677 min 2021-08-19T15:37:02.823Z,1629387422.823 [Default:CheckIn:E] Stopped 2021-08-19T15:37:02.823Z,1629387422.823 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:37:02.823Z,1629387422.823 [Default:CheckIn] Stopped 2021-08-19T15:37:02.823Z,1629387422.823 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:37:02.824Z,1629387422.824 [Default:CheckIn](INFO): Running loop #10 2021-08-19T15:37:02.824Z,1629387422.824 [Default:CheckIn] Running Loop=10 2021-08-19T15:37:02.824Z,1629387422.824 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:37:02.824Z,1629387422.824 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:37:04.843Z,1629387424.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153657.00,A,4247.18393,N,08610.96220,W,6.726,9.05,190821,,,D*75 2021-08-19T15:37:04.848Z,1629387424.848 [NAL9602](INFO): GPS fix at 20210819T153657: (42.786399, -86.182703) 2021-08-19T15:37:04.863Z,1629387424.863 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:37:04.863Z,1629387424.863 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:37:12.051Z,1629387432.051 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0027.lzma 2021-08-19T15:37:13.054Z,1629387433.054 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0027.lzma.bak 2021-08-19T15:37:13.054Z,1629387433.054 [DataOverHttps](INFO): SBD MOMSN=15895499 2021-08-19T15:37:22.612Z,1629387442.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=46888, MT Status=2, MTMSN=0 2021-08-19T15:37:22.612Z,1629387442.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:37:30.268Z,1629387450.268 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0028.lzma 2021-08-19T15:37:31.270Z,1629387451.270 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0028.lzma.bak 2021-08-19T15:37:31.270Z,1629387451.270 [DataOverHttps](INFO): SBD MOMSN=15895502 2021-08-19T15:37:33.998Z,1629387453.998 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:37:33.998Z,1629387453.998 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:37:33.999Z,1629387453.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:38:08.712Z,1629387488.712 [NAL9602](INFO): SBD MO Status=2, MOMSN=46888, MT Status=2, MTMSN=0 2021-08-19T15:38:08.712Z,1629387488.712 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:38:38.203Z,1629387518.203 [NAL9602](INFO): SBD MO Status=0, MOMSN=46888, MT Status=0, MTMSN=0 2021-08-19T15:38:38.203Z,1629387518.203 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:39:08.948Z,1629387548.948 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:39:45.720Z,1629387585.720 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+9999.99,+9999.99 2021-08-19T15:42:25.269Z,1629387745.269 [DVL_micro](ERROR): Failed to parse: :SA,-00.76,-03.72,278.1 2021-08-19T15:42:34.559Z,1629387754.559 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:42:34.559Z,1629387754.559 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:42:34.559Z,1629387754.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:42:34.559Z,1629387754.559 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:42:34.973Z,1629387754.973 [Default:CheckIn:D] Stopped 2021-08-19T15:42:34.973Z,1629387754.973 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:42:35.402Z,1629387755.402 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.028206 min 2021-08-19T15:42:35.402Z,1629387755.402 [Default:CheckIn:E] Stopped 2021-08-19T15:42:35.402Z,1629387755.402 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn] Stopped 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn](INFO): Running loop #11 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn] Running Loop=11 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:42:35.403Z,1629387755.403 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:42:37.378Z,1629387757.378 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154230.00,A,4247.39462,N,08611.15016,W,0.078,280.65,190821,,,D*7F 2021-08-19T15:42:37.381Z,1629387757.381 [NAL9602](INFO): GPS fix at 20210819T154230: (42.789910, -86.185836) 2021-08-19T15:42:37.390Z,1629387757.390 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:42:37.390Z,1629387757.390 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:42:48.783Z,1629387768.783 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0030.lzma 2021-08-19T15:42:49.786Z,1629387769.786 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0030.lzma.bak 2021-08-19T15:42:49.786Z,1629387769.786 [DataOverHttps](INFO): SBD MOMSN=15895511 2021-08-19T15:42:57.640Z,1629387777.640 [NAL9602](INFO): SBD MO Status=0, MOMSN=46889, MT Status=0, MTMSN=0 2021-08-19T15:42:57.640Z,1629387777.640 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:43:03.287Z,1629387783.287 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T15:43:03.287Z,1629387783.287 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0000.0,148 2021-08-19T15:43:07.336Z,1629387787.336 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0031.lzma 2021-08-19T15:43:08.338Z,1629387788.338 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0031.lzma.bak 2021-08-19T15:43:08.338Z,1629387788.338 [DataOverHttps](INFO): SBD MOMSN=15895514 2021-08-19T15:43:11.047Z,1629387791.047 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:43:11.047Z,1629387791.047 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:43:11.047Z,1629387791.047 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:43:28.340Z,1629387808.340 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:46:11.159Z,1629387971.159 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:46:13.197Z,1629387973.197 [DVL_micro](ERROR): Failed to parse: 22,+01381,+00649,+00000,I 2021-08-19T15:46:22.874Z,1629387982.874 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:46:25.301Z,1629387985.301 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-08-19T15:46:34.186Z,1629387994.186 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:46:45.502Z,1629388005.502 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:46:56.814Z,1629388016.814 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:47:07.726Z,1629388027.726 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:47:19.120Z,1629388039.120 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:47:30.346Z,1629388050.346 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T15:47:55.010Z,1629388075.010 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T15:47:55.011Z,1629388075.011 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2021-08-19T15:48:11.572Z,1629388091.572 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:48:11.572Z,1629388091.572 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:48:11.573Z,1629388091.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:48:11.573Z,1629388091.573 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:48:11.980Z,1629388091.980 [Default:CheckIn:D] Stopped 2021-08-19T15:48:11.981Z,1629388091.981 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:48:12.413Z,1629388092.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.644995 min 2021-08-19T15:48:12.413Z,1629388092.413 [Default:CheckIn:E] Stopped 2021-08-19T15:48:12.413Z,1629388092.413 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:48:12.413Z,1629388092.413 [Default:CheckIn] Stopped 2021-08-19T15:48:12.414Z,1629388092.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:48:12.414Z,1629388092.414 [Default:CheckIn](INFO): Running loop #12 2021-08-19T15:48:12.414Z,1629388092.414 [Default:CheckIn] Running Loop=12 2021-08-19T15:48:12.414Z,1629388092.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:48:12.414Z,1629388092.414 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:48:14.395Z,1629388094.395 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154807.00,A,4247.39517,N,08611.14942,W,0.058,322.28,190821,,,D*79 2021-08-19T15:48:14.398Z,1629388094.398 [NAL9602](INFO): GPS fix at 20210819T154807: (42.789920, -86.185824) 2021-08-19T15:48:14.407Z,1629388094.407 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:48:14.407Z,1629388094.407 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:48:21.827Z,1629388101.827 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0033.lzma 2021-08-19T15:48:22.830Z,1629388102.830 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0033.lzma.bak 2021-08-19T15:48:22.830Z,1629388102.830 [DataOverHttps](INFO): SBD MOMSN=15895519 2021-08-19T15:48:30.954Z,1629388110.954 [NAL9602](INFO): SBD MO Status=0, MOMSN=46890, MT Status=0, MTMSN=0 2021-08-19T15:48:30.955Z,1629388110.955 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:48:40.315Z,1629388120.315 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210819T145007/Express0034.lzma 2021-08-19T15:48:41.318Z,1629388121.318 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0034.lzma.bak 2021-08-19T15:48:41.318Z,1629388121.318 [DataOverHttps](INFO): SBD MOMSN=15895522 2021-08-19T15:48:46.025Z,1629388126.025 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:48:46.025Z,1629388126.025 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:48:46.025Z,1629388126.025 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:49:01.718Z,1629388141.718 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:49:13.448Z,1629388153.448 [DVL_micro](ERROR): Failed to parse: :WI,+01735,-0015,+00000,A 2021-08-19T15:50:39.887Z,1629388239.887 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T15:50:39.903Z,1629388239.903 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+2.0,1489.0,000 2021-08-19T15:52:08.783Z,1629388328.783 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T15:52:08.783Z,1629388328.783 [DVL_micro](ERROR): Failed to parse: :TS,000000,35,0000.0,1489.0,,+01266,-0958,+00000,A 2021-08-19T15:52:41.909Z,1629388361.909 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-19T15:52:41.909Z,1629388361.909 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-19T15:52:41.912Z,1629388361.912 [BPC1](INFO): Received data from all battery sticks. 2021-08-19T15:53:46.552Z,1629388426.552 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:53:46.552Z,1629388426.552 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:53:46.552Z,1629388426.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:53:46.552Z,1629388426.552 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:53:46.951Z,1629388426.951 [Default:CheckIn:D] Stopped 2021-08-19T15:53:46.951Z,1629388426.951 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:53:47.403Z,1629388427.403 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.227832 min 2021-08-19T15:53:47.403Z,1629388427.403 [Default:CheckIn:E] Stopped 2021-08-19T15:53:47.403Z,1629388427.403 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:53:47.403Z,1629388427.403 [Default:CheckIn] Stopped 2021-08-19T15:53:47.403Z,1629388427.403 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:53:47.412Z,1629388427.412 [Default:CheckIn](INFO): Running loop #13 2021-08-19T15:53:47.412Z,1629388427.412 [Default:CheckIn] Running Loop=13 2021-08-19T15:53:47.412Z,1629388427.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:53:47.412Z,1629388427.412 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:53:49.372Z,1629388429.372 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155342.00,A,4247.39464,N,08611.14810,W,0.019,319.09,190821,,,D*7F 2021-08-19T15:53:49.374Z,1629388429.374 [NAL9602](INFO): GPS fix at 20210819T155342: (42.789911, -86.185802) 2021-08-19T15:53:49.383Z,1629388429.383 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:53:49.384Z,1629388429.384 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:53:56.940Z,1629388436.940 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210819T145007/Courier0036.lzma 2021-08-19T15:53:57.942Z,1629388437.942 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0036.lzma.bak 2021-08-19T15:53:57.942Z,1629388437.942 [DataOverHttps](INFO): SBD MOMSN=15895530 2021-08-19T15:54:13.623Z,1629388453.623 [NAL9602](INFO): SBD MO Status=2, MOMSN=46891, MT Status=2, MTMSN=0 2021-08-19T15:54:13.624Z,1629388453.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:54:15.199Z,1629388455.199 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210819T145007/Express0037.lzma 2021-08-19T15:54:16.202Z,1629388456.202 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0037.lzma.bak 2021-08-19T15:54:16.202Z,1629388456.202 [DataOverHttps](INFO): SBD MOMSN=15895533 2021-08-19T15:54:18.884Z,1629388458.884 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:54:18.885Z,1629388458.885 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:54:18.885Z,1629388458.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:54:45.525Z,1629388485.525 [NAL9602](INFO): SBD MO Status=2, MOMSN=46891, MT Status=2, MTMSN=0 2021-08-19T15:54:45.525Z,1629388485.525 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T15:54:55.623Z,1629388495.623 [NAL9602](INFO): SBD MO Status=0, MOMSN=46891, MT Status=0, MTMSN=0 2021-08-19T15:54:55.623Z,1629388495.623 [NAL9602](INFO): No messages in MT queue 2021-08-19T15:55:26.342Z,1629388526.342 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T15:58:03.900Z,1629388683.900 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T15:58:03.900Z,1629388683.900 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+29.0,0000.0,1489:WI,-01489,+01061,+00245,+00000,A 2021-08-19T15:59:19.494Z,1629388759.494 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T15:59:19.494Z,1629388759.494 [Default:CheckIn:C.Wait] Stopped 2021-08-19T15:59:19.494Z,1629388759.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T15:59:19.495Z,1629388759.495 [Default:CheckIn:D] Running Loop=1 2021-08-19T15:59:19.854Z,1629388759.854 [Default:CheckIn:D] Stopped 2021-08-19T15:59:19.854Z,1629388759.854 [Default:CheckIn:E] Running Loop=1 2021-08-19T15:59:20.385Z,1629388760.385 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.776213 min 2021-08-19T15:59:20.385Z,1629388760.385 [Default:CheckIn:E] Stopped 2021-08-19T15:59:20.385Z,1629388760.385 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T15:59:20.385Z,1629388760.385 [Default:CheckIn] Stopped 2021-08-19T15:59:20.385Z,1629388760.385 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T15:59:20.386Z,1629388760.386 [Default:CheckIn](INFO): Running loop #14 2021-08-19T15:59:20.386Z,1629388760.386 [Default:CheckIn] Running Loop=14 2021-08-19T15:59:20.386Z,1629388760.386 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T15:59:20.386Z,1629388760.386 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T15:59:22.270Z,1629388762.270 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155915.00,A,4247.39425,N,08611.18581,W,5.035,268.81,190821,,,A*72 2021-08-19T15:59:22.273Z,1629388762.273 [NAL9602](INFO): GPS fix at 20210819T155915: (42.789904, -86.186430) 2021-08-19T15:59:22.283Z,1629388762.283 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T15:59:22.283Z,1629388762.283 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T15:59:29.959Z,1629388769.959 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0039.lzma 2021-08-19T15:59:30.376Z,1629388770.376 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T15:59:30.377Z,1629388770.377 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2021-08-19T15:59:30.962Z,1629388770.962 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0039.lzma.bak 2021-08-19T15:59:30.962Z,1629388770.962 [DataOverHttps](INFO): SBD MOMSN=15895537 2021-08-19T15:59:35.619Z,1629388775.619 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+29.1,0000.0,1489.0,000 2021-08-19T15:59:51.140Z,1629388791.140 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0040.lzma 2021-08-19T15:59:52.142Z,1629388792.142 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0040.lzma.bak 2021-08-19T15:59:52.142Z,1629388792.142 [DataOverHttps](INFO): SBD MOMSN=15895544 2021-08-19T15:59:55.087Z,1629388795.087 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T15:59:55.108Z,1629388795.108 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T15:59:55.108Z,1629388795.108 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T15:59:57.086Z,1629388797.086 [NAL9602](INFO): SBD MO Status=2, MOMSN=46892, MT Status=2, MTMSN=0 2021-08-19T15:59:57.087Z,1629388797.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:00:15.663Z,1629388815.663 [NAL9602](INFO): SBD MO Status=0, MOMSN=46892, MT Status=0, MTMSN=0 2021-08-19T16:00:15.663Z,1629388815.663 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:00:46.375Z,1629388846.375 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:04:55.834Z,1629389095.834 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:04:55.834Z,1629389095.834 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:04:55.834Z,1629389095.834 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:04:55.834Z,1629389095.834 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:04:56.273Z,1629389096.273 [Default:CheckIn:D] Stopped 2021-08-19T16:04:56.273Z,1629389096.273 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:04:56.638Z,1629389096.638 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.382780 min 2021-08-19T16:04:56.638Z,1629389096.638 [Default:CheckIn:E] Stopped 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn] Stopped 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn](INFO): Running loop #15 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn] Running Loop=15 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:04:56.639Z,1629389096.639 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:04:58.669Z,1629389098.669 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160451.00,A,4247.39477,N,08611.19618,W,0.019,269.78,190821,,,D*75 2021-08-19T16:04:58.671Z,1629389098.671 [NAL9602](INFO): GPS fix at 20210819T160451: (42.789913, -86.186603) 2021-08-19T16:04:58.681Z,1629389098.681 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:04:58.681Z,1629389098.681 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:05:05.871Z,1629389105.871 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0042.lzma 2021-08-19T16:05:06.874Z,1629389106.874 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0042.lzma.bak 2021-08-19T16:05:06.874Z,1629389106.874 [DataOverHttps](INFO): SBD MOMSN=15895548 2021-08-19T16:05:11.178Z,1629389111.178 [NAL9602](INFO): SBD MO Status=0, MOMSN=46893, MT Status=0, MTMSN=0 2021-08-19T16:05:11.178Z,1629389111.178 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:05:27.064Z,1629389127.064 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210819T145007/Express0043.lzma 2021-08-19T16:05:28.066Z,1629389128.066 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0043.lzma.bak 2021-08-19T16:05:28.066Z,1629389128.066 [DataOverHttps](INFO): SBD MOMSN=15895551 2021-08-19T16:05:31.422Z,1629389131.422 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:05:31.422Z,1629389131.422 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:05:31.422Z,1629389131.422 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:05:41.966Z,1629389141.966 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:08:14.374Z,1629389294.374 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-19T16:10:32.161Z,1629389432.161 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:10:32.161Z,1629389432.161 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:10:32.161Z,1629389432.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:10:32.162Z,1629389432.162 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:10:32.564Z,1629389432.564 [Default:CheckIn:D] Stopped 2021-08-19T16:10:32.564Z,1629389432.564 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:10:32.979Z,1629389432.979 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.988053 min 2021-08-19T16:10:32.979Z,1629389432.979 [Default:CheckIn:E] Stopped 2021-08-19T16:10:32.979Z,1629389432.979 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:10:32.979Z,1629389432.979 [Default:CheckIn] Stopped 2021-08-19T16:10:32.979Z,1629389432.979 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:10:32.980Z,1629389432.980 [Default:CheckIn](INFO): Running loop #16 2021-08-19T16:10:32.980Z,1629389432.980 [Default:CheckIn] Running Loop=16 2021-08-19T16:10:32.980Z,1629389432.980 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:10:32.980Z,1629389432.980 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:10:34.979Z,1629389434.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161028.00,A,4247.58625,N,08610.51831,W,39.071,87.29,190821,,,D*76 2021-08-19T16:10:34.981Z,1629389434.981 [NAL9602](INFO): GPS fix at 20210819T161028: (42.793104, -86.175305) 2021-08-19T16:10:34.991Z,1629389434.991 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:10:34.991Z,1629389434.991 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:10:44.575Z,1629389444.575 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0045.lzma 2021-08-19T16:10:44.722Z,1629389444.722 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T16:10:44.723Z,1629389444.723 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.4,0000.0,1489.0,000 2021-08-19T16:10:45.578Z,1629389445.578 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0045.lzma.bak 2021-08-19T16:10:45.578Z,1629389445.578 [DataOverHttps](INFO): SBD MOMSN=15895559 2021-08-19T16:10:49.579Z,1629389449.579 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T16:10:49.579Z,1629389449.579 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+29.4,0000.0,1489.0,000 2021-08-19T16:10:57.659Z,1629389457.659 [NAL9602](INFO): SBD MO Status=0, MOMSN=46894, MT Status=0, MTMSN=0 2021-08-19T16:10:57.659Z,1629389457.659 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:11:05.779Z,1629389465.779 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0046.lzma 2021-08-19T16:11:06.782Z,1629389466.782 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0046.lzma.bak 2021-08-19T16:11:06.782Z,1629389466.782 [DataOverHttps](INFO): SBD MOMSN=15895562 2021-08-19T16:11:09.399Z,1629389469.399 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:11:09.400Z,1629389469.400 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:11:09.400Z,1629389469.400 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:11:28.360Z,1629389488.360 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:14:51.280Z,1629389691.280 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T16:14:59.313Z,1629389699.313 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247890 2021-08-19T16:15:43.217Z,1629389743.217 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003397 2021-08-19T16:16:10.004Z,1629389770.004 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:16:10.004Z,1629389770.004 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:16:10.004Z,1629389770.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:16:10.005Z,1629389770.005 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:16:10.382Z,1629389770.382 [Default:CheckIn:D] Stopped 2021-08-19T16:16:10.382Z,1629389770.382 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:16:10.787Z,1629389770.787 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.618359 min 2021-08-19T16:16:10.787Z,1629389770.787 [Default:CheckIn:E] Stopped 2021-08-19T16:16:10.787Z,1629389770.787 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:16:10.787Z,1629389770.787 [Default:CheckIn] Stopped 2021-08-19T16:16:10.787Z,1629389770.787 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:16:10.788Z,1629389770.788 [Default:CheckIn](INFO): Running loop #17 2021-08-19T16:16:10.788Z,1629389770.788 [Default:CheckIn] Running Loop=17 2021-08-19T16:16:10.788Z,1629389770.788 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:16:10.788Z,1629389770.788 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:16:12.796Z,1629389772.796 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161605.00,A,4248.16700,N,08606.70513,W,25.484,59.22,190821,,,A*7B 2021-08-19T16:16:12.798Z,1629389772.798 [NAL9602](INFO): GPS fix at 20210819T161605: (42.802783, -86.111752) 2021-08-19T16:16:12.831Z,1629389772.831 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:16:12.831Z,1629389772.831 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:16:20.995Z,1629389780.995 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0048.lzma 2021-08-19T16:16:21.998Z,1629389781.998 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0048.lzma.bak 2021-08-19T16:16:21.998Z,1629389781.998 [DataOverHttps](INFO): SBD MOMSN=15895566 2021-08-19T16:16:28.551Z,1629389788.551 [NAL9602](INFO): SBD MO Status=0, MOMSN=46895, MT Status=0, MTMSN=0 2021-08-19T16:16:28.552Z,1629389788.552 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:16:39.047Z,1629389799.047 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0049.lzma 2021-08-19T16:16:40.050Z,1629389800.050 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0049.lzma.bak 2021-08-19T16:16:40.050Z,1629389800.050 [DataOverHttps](INFO): SBD MOMSN=15895569 2021-08-19T16:16:43.228Z,1629389803.228 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-19T16:16:43.228Z,1629389803.228 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2021-08-19T16:16:43.621Z,1629389803.621 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:16:43.621Z,1629389803.621 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:16:43.621Z,1629389803.621 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:16:59.355Z,1629389819.355 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:18:45.222Z,1629389925.222 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T16:18:45.222Z,1629389925.222 [DVL_micro](ERROR): Failed to parse: :BI,+00261,+00226,-0000,I 2021-08-19T16:21:44.181Z,1629390104.181 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:21:44.182Z,1629390104.182 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:21:44.182Z,1629390104.182 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:21:44.182Z,1629390104.182 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:21:44.594Z,1629390104.594 [Default:CheckIn:D] Stopped 2021-08-19T16:21:44.594Z,1629390104.594 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:21:45.054Z,1629390105.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.188550 min 2021-08-19T16:21:45.055Z,1629390105.055 [Default:CheckIn:E] Stopped 2021-08-19T16:21:45.056Z,1629390105.056 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:21:45.056Z,1629390105.056 [Default:CheckIn] Stopped 2021-08-19T16:21:45.057Z,1629390105.057 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:21:45.058Z,1629390105.058 [Default:CheckIn](INFO): Running loop #18 2021-08-19T16:21:45.059Z,1629390105.059 [Default:CheckIn] Running Loop=18 2021-08-19T16:21:45.059Z,1629390105.059 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:21:45.059Z,1629390105.059 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:21:47.003Z,1629390107.003 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162140.00,A,4248.27025,N,08603.57008,W,0.058,152.79,190821,,,D*70 2021-08-19T16:21:47.006Z,1629390107.006 [NAL9602](INFO): GPS fix at 20210819T162140: (42.804504, -86.059501) 2021-08-19T16:21:47.038Z,1629390107.038 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:21:47.038Z,1629390107.038 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:21:54.335Z,1629390114.335 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0051.lzma 2021-08-19T16:21:55.346Z,1629390115.346 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0051.lzma.bak 2021-08-19T16:21:55.347Z,1629390115.347 [DataOverHttps](INFO): SBD MOMSN=15895578 2021-08-19T16:22:12.503Z,1629390132.503 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0052.lzma 2021-08-19T16:22:13.506Z,1629390133.506 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0052.lzma.bak 2021-08-19T16:22:13.506Z,1629390133.506 [DataOverHttps](INFO): SBD MOMSN=15895581 2021-08-19T16:22:16.120Z,1629390136.120 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:22:16.120Z,1629390136.120 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:22:16.120Z,1629390136.120 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:22:21.748Z,1629390141.748 [NAL9602](INFO): SBD MO Status=2, MOMSN=46896, MT Status=2, MTMSN=0 2021-08-19T16:22:21.748Z,1629390141.748 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:22:45.583Z,1629390165.583 [NAL9602](INFO): SBD MO Status=0, MOMSN=46896, MT Status=0, MTMSN=0 2021-08-19T16:22:45.583Z,1629390165.583 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:23:16.292Z,1629390196.292 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:24:30.296Z,1629390270.296 [DVL_micro](ERROR): DVL uart error: serial timeout 2021-08-19T16:24:30.296Z,1629390270.296 [DVL_micro] Communications Fault, FailCount= 1 2021-08-19T16:24:30.296Z,1629390270.296 [DVL_micro](ERROR): Communications Fault 2021-08-19T16:24:30.297Z,1629390270.297 [DVL_micro](ERROR): Failed to parse: 2021-08-19T16:24:30.333Z,1629390270.333 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-08-19T16:24:30.708Z,1629390270.708 [DVL_micro](INFO): Powering down 2021-08-19T16:24:31.475Z,1629390271.475 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-08-19T16:24:31.475Z,1629390271.475 [DVL_micro] No Fault, FailCount= 1 2021-08-19T16:25:57.904Z,1629390357.904 [DVL_micro](ERROR): Failed to parse: :WI,+00061,00297,+0:BI,+00061+00297,+0:BD,+00000000.00,+00000000.00,+00000999.99,000.00 2021-08-19T16:27:16.685Z,1629390436.685 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:27:16.685Z,1629390436.685 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:27:16.685Z,1629390436.685 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:27:16.685Z,1629390436.685 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:27:17.085Z,1629390437.085 [Default:CheckIn:D] Stopped 2021-08-19T16:27:17.085Z,1629390437.085 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:27:17.502Z,1629390437.502 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.730062 min 2021-08-19T16:27:17.502Z,1629390437.502 [Default:CheckIn:E] Stopped 2021-08-19T16:27:17.502Z,1629390437.502 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:27:17.502Z,1629390437.502 [Default:CheckIn] Stopped 2021-08-19T16:27:17.503Z,1629390437.503 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:27:17.503Z,1629390437.503 [Default:CheckIn](INFO): Running loop #19 2021-08-19T16:27:17.503Z,1629390437.503 [Default:CheckIn] Running Loop=19 2021-08-19T16:27:17.503Z,1629390437.503 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:27:17.503Z,1629390437.503 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:27:19.107Z,1629390439.107 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T16:27:19.107Z,1629390439.107 [DVL_micro](ERROR): Failed to parse: :BI,+00024,+00288,+0000,I 2021-08-19T16:27:19.526Z,1629390439.526 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162712.00,A,4248.26960,N,08603.56809,W,0.058,152.79,190821,,,D*70 2021-08-19T16:27:19.560Z,1629390439.560 [NAL9602](INFO): GPS fix at 20210819T162712: (42.804493, -86.059468) 2021-08-19T16:27:19.630Z,1629390439.630 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:27:19.630Z,1629390439.630 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:27:27.335Z,1629390447.335 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0054.lzma 2021-08-19T16:27:28.338Z,1629390448.338 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0054.lzma.bak 2021-08-19T16:27:28.338Z,1629390448.338 [DataOverHttps](INFO): SBD MOMSN=15895586 2021-08-19T16:27:41.430Z,1629390461.430 [NAL9602](INFO): SBD MO Status=2, MOMSN=46897, MT Status=2, MTMSN=0 2021-08-19T16:27:41.431Z,1629390461.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:27:48.472Z,1629390468.472 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20210819T145007/Express0055.lzma 2021-08-19T16:27:49.474Z,1629390469.474 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0055.lzma.bak 2021-08-19T16:27:49.474Z,1629390469.474 [DataOverHttps](INFO): SBD MOMSN=15895589 2021-08-19T16:27:52.412Z,1629390472.412 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:27:52.413Z,1629390472.413 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:27:52.413Z,1629390472.413 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:28:06.082Z,1629390486.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=46897, MT Status=2, MTMSN=0 2021-08-19T16:28:06.083Z,1629390486.083 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:28:25.081Z,1629390505.081 [NAL9602](INFO): SBD MO Status=2, MOMSN=46897, MT Status=2, MTMSN=0 2021-08-19T16:28:25.081Z,1629390505.081 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:29:05.895Z,1629390545.895 [NAL9602](INFO): SBD MO Status=0, MOMSN=46897, MT Status=0, MTMSN=0 2021-08-19T16:29:05.895Z,1629390545.895 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:29:36.585Z,1629390576.585 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:32:52.989Z,1629390772.989 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:32:52.990Z,1629390772.990 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:32:52.990Z,1629390772.990 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:32:52.990Z,1629390772.990 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:32:53.392Z,1629390773.392 [Default:CheckIn:D] Stopped 2021-08-19T16:32:53.392Z,1629390773.392 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:32:53.807Z,1629390773.807 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.335189 min 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn:E] Stopped 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn] Stopped 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn](INFO): Running loop #20 2021-08-19T16:32:53.808Z,1629390773.808 [Default:CheckIn] Running Loop=20 2021-08-19T16:32:53.809Z,1629390773.809 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:32:53.809Z,1629390773.809 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:32:55.806Z,1629390775.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163248.00,A,4248.24250,N,08603.49069,W,11.041,178.80,190821,,,D*47 2021-08-19T16:32:55.809Z,1629390775.809 [NAL9602](INFO): GPS fix at 20210819T163248: (42.804042, -86.058178) 2021-08-19T16:32:55.818Z,1629390775.819 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:32:55.819Z,1629390775.819 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:33:03.747Z,1629390783.747 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0057.lzma 2021-08-19T16:33:04.750Z,1629390784.750 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0057.lzma.bak 2021-08-19T16:33:04.750Z,1629390784.750 [DataOverHttps](INFO): SBD MOMSN=15895597 2021-08-19T16:33:12.066Z,1629390792.066 [NAL9602](INFO): SBD MO Status=2, MOMSN=46898, MT Status=2, MTMSN=0 2021-08-19T16:33:12.066Z,1629390792.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T16:33:21.334Z,1629390801.334 [NAL9602](INFO): SBD MO Status=0, MOMSN=46898, MT Status=0, MTMSN=0 2021-08-19T16:33:21.334Z,1629390801.334 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:33:22.564Z,1629390802.564 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0058.lzma 2021-08-19T16:33:23.566Z,1629390803.566 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0058.lzma.bak 2021-08-19T16:33:23.566Z,1629390803.566 [DataOverHttps](INFO): SBD MOMSN=15895600 2021-08-19T16:33:26.194Z,1629390806.194 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:33:26.194Z,1629390806.194 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:33:26.194Z,1629390806.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:33:52.094Z,1629390832.094 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:37:15.897Z,1629391035.897 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T16:37:15.897Z,1629391035.897 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+29.2,0000.,000 2021-08-19T16:38:26.641Z,1629391106.641 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:38:26.641Z,1629391106.641 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:38:26.641Z,1629391106.641 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:38:26.642Z,1629391106.642 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:38:27.072Z,1629391107.072 [Default:CheckIn:D] Stopped 2021-08-19T16:38:27.072Z,1629391107.072 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.896525 min 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn:E] Stopped 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn] Stopped 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn](INFO): Running loop #21 2021-08-19T16:38:27.457Z,1629391107.457 [Default:CheckIn] Running Loop=21 2021-08-19T16:38:27.458Z,1629391107.458 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:38:27.458Z,1629391107.458 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:38:29.459Z,1629391109.459 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163822.00,A,4248.67594,N,08559.55554,W,16.931,60.73,190821,,,D*7E 2021-08-19T16:38:29.461Z,1629391109.461 [NAL9602](INFO): GPS fix at 20210819T163822: (42.811266, -85.992592) 2021-08-19T16:38:29.491Z,1629391109.491 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:38:29.491Z,1629391109.491 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:38:37.307Z,1629391117.307 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0060.lzma 2021-08-19T16:38:38.310Z,1629391118.310 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0060.lzma.bak 2021-08-19T16:38:38.310Z,1629391118.310 [DataOverHttps](INFO): SBD MOMSN=15895604 2021-08-19T16:38:44.451Z,1629391124.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=46899, MT Status=0, MTMSN=0 2021-08-19T16:38:44.452Z,1629391124.452 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:38:59.814Z,1629391139.814 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0061.lzma 2021-08-19T16:39:00.406Z,1629391140.406 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0061.lzma.bak 2021-08-19T16:39:00.406Z,1629391140.406 [DataOverHttps](INFO): SBD MOMSN=15895607 2021-08-19T16:39:03.108Z,1629391143.108 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:39:03.109Z,1629391143.109 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:39:03.109Z,1629391143.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:39:15.198Z,1629391155.198 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:39:56.066Z,1629391196.066 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-19T16:39:56.067Z,1629391196.067 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,,+9999.99 2021-08-19T16:42:36.466Z,1629391356.466 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T16:42:36.466Z,1629391356.466 [DVL_micro](ERROR): Failed to parse: :BI,-00072,-00242,+0039,I 2021-08-19T16:44:03.785Z,1629391443.785 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:44:03.785Z,1629391443.785 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:44:03.785Z,1629391443.785 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:44:03.786Z,1629391443.786 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:44:04.169Z,1629391444.169 [Default:CheckIn:D] Stopped 2021-08-19T16:44:04.169Z,1629391444.169 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:44:04.578Z,1629391444.578 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.514811 min 2021-08-19T16:44:04.578Z,1629391444.578 [Default:CheckIn:E] Stopped 2021-08-19T16:44:04.578Z,1629391444.578 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:44:04.578Z,1629391444.578 [Default:CheckIn] Stopped 2021-08-19T16:44:04.579Z,1629391444.579 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:44:04.579Z,1629391444.579 [Default:CheckIn](INFO): Running loop #22 2021-08-19T16:44:04.579Z,1629391444.579 [Default:CheckIn] Running Loop=22 2021-08-19T16:44:04.579Z,1629391444.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:44:04.579Z,1629391444.579 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:44:06.594Z,1629391446.594 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164359.00,A,4250.09710,N,08554.10986,W,66.810,70.12,190821,,,D*7D 2021-08-19T16:44:06.597Z,1629391446.597 [NAL9602](INFO): GPS fix at 20210819T164359: (42.834952, -85.901831) 2021-08-19T16:44:06.606Z,1629391446.606 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:44:06.606Z,1629391446.606 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:44:15.221Z,1629391455.221 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0063.lzma 2021-08-19T16:44:16.227Z,1629391456.227 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0063.lzma.bak 2021-08-19T16:44:16.227Z,1629391456.227 [DataOverHttps](INFO): SBD MOMSN=15895615 2021-08-19T16:44:28.814Z,1629391468.814 [NAL9602](INFO): SBD MO Status=0, MOMSN=46900, MT Status=0, MTMSN=0 2021-08-19T16:44:28.814Z,1629391468.814 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:44:33.220Z,1629391473.220 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0064.lzma 2021-08-19T16:44:34.222Z,1629391474.222 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0064.lzma.bak 2021-08-19T16:44:34.222Z,1629391474.222 [DataOverHttps](INFO): SBD MOMSN=15895618 2021-08-19T16:44:36.921Z,1629391476.921 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:44:36.921Z,1629391476.921 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:44:36.921Z,1629391476.921 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:44:59.553Z,1629391499.553 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:45:21.375Z,1629391521.375 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-19T16:45:21.375Z,1629391521.375 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.999,+9999.99 2021-08-19T16:48:16.716Z,1629391696.716 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T16:48:16.716Z,1629391696.716 [DVL_micro](ERROR): Failed to parse: :BI,-00285,-00456,00000,I 2021-08-19T16:49:37.524Z,1629391777.524 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:49:37.524Z,1629391777.524 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:49:37.524Z,1629391777.524 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:49:37.525Z,1629391777.525 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:49:37.951Z,1629391777.951 [Default:CheckIn:D] Stopped 2021-08-19T16:49:37.951Z,1629391777.951 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:49:38.385Z,1629391778.385 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.077840 min 2021-08-19T16:49:38.385Z,1629391778.385 [Default:CheckIn:E] Stopped 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn] Stopped 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn](INFO): Running loop #23 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn] Running Loop=23 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:49:38.386Z,1629391778.386 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:49:40.347Z,1629391780.347 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164933.00,A,4250.74468,N,08547.60916,W,62.611,88.86,190821,,,D*70 2021-08-19T16:49:40.349Z,1629391780.349 [NAL9602](INFO): GPS fix at 20210819T164933: (42.845745, -85.793486) 2021-08-19T16:49:40.365Z,1629391780.365 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:49:40.365Z,1629391780.365 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:49:52.411Z,1629391792.411 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0066.lzma 2021-08-19T16:49:53.415Z,1629391793.415 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0066.lzma.bak 2021-08-19T16:49:53.416Z,1629391793.416 [DataOverHttps](INFO): SBD MOMSN=15895622 2021-08-19T16:50:04.180Z,1629391804.180 [NAL9602](INFO): SBD MO Status=0, MOMSN=46901, MT Status=0, MTMSN=0 2021-08-19T16:50:04.180Z,1629391804.180 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:50:11.783Z,1629391811.783 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0067.lzma 2021-08-19T16:50:12.786Z,1629391812.786 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0067.lzma.bak 2021-08-19T16:50:12.786Z,1629391812.786 [DataOverHttps](INFO): SBD MOMSN=15895625 2021-08-19T16:50:15.101Z,1629391815.101 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:50:15.101Z,1629391815.101 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:50:15.102Z,1629391815.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:50:34.884Z,1629391834.884 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T16:51:14.476Z,1629391874.476 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T16:51:14.476Z,1629391874.476 [DVL_micro](ERROR): Failed to parse: :TS,000000000000008.9,0000.0,1489.0,000 2021-08-19T16:53:48.398Z,1629392028.398 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:53:59.730Z,1629392039.730 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:54:11.049Z,1629392051.049 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:54:22.359Z,1629392062.359 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:54:33.263Z,1629392073.263 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:54:45.383Z,1629392085.383 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:54:56.296Z,1629392096.296 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:55:07.607Z,1629392107.607 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T16:55:15.720Z,1629392115.720 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T16:55:15.720Z,1629392115.720 [Default:CheckIn:C.Wait] Stopped 2021-08-19T16:55:15.720Z,1629392115.720 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T16:55:15.720Z,1629392115.720 [Default:CheckIn:D] Running Loop=1 2021-08-19T16:55:16.102Z,1629392116.102 [Default:CheckIn:D] Stopped 2021-08-19T16:55:16.102Z,1629392116.102 [Default:CheckIn:E] Running Loop=1 2021-08-19T16:55:16.503Z,1629392116.503 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.713680 min 2021-08-19T16:55:16.503Z,1629392116.503 [Default:CheckIn:E] Stopped 2021-08-19T16:55:16.503Z,1629392116.503 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T16:55:16.503Z,1629392116.503 [Default:CheckIn] Stopped 2021-08-19T16:55:16.503Z,1629392116.503 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T16:55:16.504Z,1629392116.504 [Default:CheckIn](INFO): Running loop #24 2021-08-19T16:55:16.504Z,1629392116.504 [Default:CheckIn] Running Loop=24 2021-08-19T16:55:16.504Z,1629392116.504 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T16:55:16.504Z,1629392116.504 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T16:55:18.525Z,1629392118.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165511.00,A,4250.92327,N,08539.53723,W,56.080,89.90,190821,,,D*77 2021-08-19T16:55:18.528Z,1629392118.528 [NAL9602](INFO): GPS fix at 20210819T165511: (42.848721, -85.658954) 2021-08-19T16:55:18.542Z,1629392118.542 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T16:55:18.542Z,1629392118.542 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T16:55:46.072Z,1629392146.072 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0069.lzma 2021-08-19T16:55:47.074Z,1629392147.074 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0069.lzma.bak 2021-08-19T16:55:47.074Z,1629392147.074 [DataOverHttps](INFO): SBD MOMSN=15895633 2021-08-19T16:55:48.522Z,1629392148.522 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T16:55:48.522Z,1629392148.522 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.99,+9999.99 2021-08-19T16:55:55.353Z,1629392155.353 [NAL9602](INFO): SBD MO Status=0, MOMSN=46902, MT Status=0, MTMSN=0 2021-08-19T16:55:55.353Z,1629392155.353 [NAL9602](INFO): No messages in MT queue 2021-08-19T16:56:05.896Z,1629392165.896 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0070.lzma 2021-08-19T16:56:06.898Z,1629392166.898 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0070.lzma.bak 2021-08-19T16:56:06.898Z,1629392166.898 [DataOverHttps](INFO): SBD MOMSN=15895636 2021-08-19T16:56:09.490Z,1629392169.490 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T16:56:09.490Z,1629392169.490 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T16:56:09.490Z,1629392169.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T16:56:26.037Z,1629392186.037 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:00:23.663Z,1629392423.663 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-19T17:00:23.668Z,1629392423.668 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-19T17:00:23.676Z,1629392423.676 [BPC1](INFO): Received data from all battery sticks. 2021-08-19T17:01:10.130Z,1629392470.130 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:01:10.130Z,1629392470.130 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:01:10.131Z,1629392470.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:01:10.131Z,1629392470.131 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:01:10.519Z,1629392470.519 [Default:CheckIn:D] Stopped 2021-08-19T17:01:10.519Z,1629392470.519 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:01:10.926Z,1629392470.926 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.620638 min 2021-08-19T17:01:10.926Z,1629392470.926 [Default:CheckIn:E] Stopped 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn] Stopped 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn](INFO): Running loop #25 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn] Running Loop=25 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:01:10.927Z,1629392470.927 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:01:12.942Z,1629392472.942 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170105.00,A,4251.17733,N,08531.69269,W,64.108,75.30,190821,,,D*7C 2021-08-19T17:01:12.945Z,1629392472.945 [NAL9602](INFO): GPS fix at 20210819T170105: (42.852956, -85.528211) 2021-08-19T17:01:12.954Z,1629392472.954 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:01:12.954Z,1629392472.954 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:01:20.932Z,1629392480.932 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210819T145007/Courier0072.lzma 2021-08-19T17:01:21.930Z,1629392481.930 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0072.lzma.bak 2021-08-19T17:01:21.930Z,1629392481.930 [DataOverHttps](INFO): SBD MOMSN=15895640 2021-08-19T17:01:30.311Z,1629392490.311 [NAL9602](INFO): SBD MO Status=0, MOMSN=46903, MT Status=0, MTMSN=0 2021-08-19T17:01:30.313Z,1629392490.313 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:01:39.516Z,1629392499.516 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0073.lzma 2021-08-19T17:01:40.518Z,1629392500.518 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0073.lzma.bak 2021-08-19T17:01:40.518Z,1629392500.518 [DataOverHttps](INFO): SBD MOMSN=15895643 2021-08-19T17:01:44.131Z,1629392504.131 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:01:44.132Z,1629392504.132 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:01:44.132Z,1629392504.132 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:02:00.715Z,1629392520.715 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:02:10.007Z,1629392530.007 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+29.1,0000.0,10 2021-08-19T17:04:42.396Z,1629392682.396 [DVL_micro](ERROR): DVL uart error: serial timeout 2021-08-19T17:04:42.396Z,1629392682.396 [DVL_micro] Communications Fault, FailCount= 1 2021-08-19T17:04:42.396Z,1629392682.396 [DVL_micro](ERROR): Communications Fault 2021-08-19T17:04:42.396Z,1629392682.396 [DVL_micro](ERROR): Failed to parse: 2021-08-19T17:04:42.446Z,1629392682.446 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-08-19T17:04:42.796Z,1629392682.796 [DVL_micro](INFO): Powering down 2021-08-19T17:04:43.123Z,1629392683.123 [Power24vConverter](INFO): Powering down. 2021-08-19T17:04:43.576Z,1629392683.576 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-08-19T17:04:43.576Z,1629392683.576 [DVL_micro] No Fault, FailCount= 1 2021-08-19T17:04:43.935Z,1629392683.935 [Power24vConverter](INFO): Powering up. 2021-08-19T17:06:05.161Z,1629392765.161 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2021-08-19T17:06:44.762Z,1629392804.762 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:06:44.762Z,1629392804.762 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:06:44.762Z,1629392804.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:06:44.763Z,1629392804.763 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:06:45.169Z,1629392805.169 [Default:CheckIn:D] Stopped 2021-08-19T17:06:45.170Z,1629392805.170 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.198145 min 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn:E] Stopped 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn] Stopped 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn](INFO): Running loop #26 2021-08-19T17:06:45.614Z,1629392805.614 [Default:CheckIn] Running Loop=26 2021-08-19T17:06:45.615Z,1629392805.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:06:45.615Z,1629392805.615 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:06:47.585Z,1629392807.585 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170640.00,A,4252.69643,N,08526.20721,W,56.838,89.24,190821,,,D*79 2021-08-19T17:06:47.587Z,1629392807.587 [NAL9602](INFO): GPS fix at 20210819T170640: (42.878274, -85.436787) 2021-08-19T17:06:47.596Z,1629392807.596 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:06:47.597Z,1629392807.597 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:06:56.568Z,1629392816.568 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0075.lzma 2021-08-19T17:06:57.570Z,1629392817.570 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0075.lzma.bak 2021-08-19T17:06:57.570Z,1629392817.570 [DataOverHttps](INFO): SBD MOMSN=15895652 2021-08-19T17:07:05.451Z,1629392825.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=46904, MT Status=0, MTMSN=0 2021-08-19T17:07:05.451Z,1629392825.451 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:07:14.688Z,1629392834.688 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0076.lzma 2021-08-19T17:07:15.690Z,1629392835.690 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0076.lzma.bak 2021-08-19T17:07:15.690Z,1629392835.690 [DataOverHttps](INFO): SBD MOMSN=15895655 2021-08-19T17:07:18.007Z,1629392838.007 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:07:18.012Z,1629392838.012 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:07:18.012Z,1629392838.012 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:07:36.146Z,1629392856.146 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:08:50.095Z,1629392930.095 [DVL_micro](ERROR): Failed to parse: :BI,+00299,+00744,+00191,+0:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-19T17:11:38.199Z,1629393098.199 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2021-08-19T17:12:18.570Z,1629393138.570 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:12:18.570Z,1629393138.570 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:12:18.570Z,1629393138.570 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:12:18.571Z,1629393138.571 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:12:18.987Z,1629393138.987 [Default:CheckIn:D] Stopped 2021-08-19T17:12:18.987Z,1629393138.987 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:12:19.374Z,1629393139.374 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.761768 min 2021-08-19T17:12:19.374Z,1629393139.374 [Default:CheckIn:E] Stopped 2021-08-19T17:12:19.374Z,1629393139.374 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:12:19.374Z,1629393139.374 [Default:CheckIn] Stopped 2021-08-19T17:12:19.375Z,1629393139.375 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:12:19.375Z,1629393139.375 [Default:CheckIn](INFO): Running loop #27 2021-08-19T17:12:19.375Z,1629393139.375 [Default:CheckIn] Running Loop=27 2021-08-19T17:12:19.375Z,1629393139.375 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:12:19.375Z,1629393139.375 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:12:21.397Z,1629393141.397 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171214.00,A,4252.53820,N,08518.91226,W,54.855,62.22,190821,,,A*75 2021-08-19T17:12:21.399Z,1629393141.399 [NAL9602](INFO): GPS fix at 20210819T171214: (42.875637, -85.315204) 2021-08-19T17:12:21.425Z,1629393141.425 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:12:21.425Z,1629393141.425 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:12:29.137Z,1629393149.137 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0078.lzma 2021-08-19T17:12:30.138Z,1629393150.138 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0078.lzma.bak 2021-08-19T17:12:30.138Z,1629393150.138 [DataOverHttps](INFO): SBD MOMSN=15895665 2021-08-19T17:12:33.510Z,1629393153.510 [NAL9602](INFO): SBD MO Status=0, MOMSN=46905, MT Status=0, MTMSN=0 2021-08-19T17:12:33.511Z,1629393153.511 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:12:51.104Z,1629393171.104 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210819T145007/Express0079.lzma 2021-08-19T17:12:52.106Z,1629393172.106 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0079.lzma.bak 2021-08-19T17:12:52.106Z,1629393172.106 [DataOverHttps](INFO): SBD MOMSN=15895670 2021-08-19T17:12:55.029Z,1629393175.029 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:12:55.029Z,1629393175.029 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:12:55.029Z,1629393175.029 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:13:04.297Z,1629393184.297 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:13:04.704Z,1629393184.704 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T17:13:04.705Z,1629393184.705 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-19T17:14:10.816Z,1629393250.816 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.047131 2021-08-19T17:14:45.596Z,1629393285.596 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003075 2021-08-19T17:15:55.360Z,1629393355.360 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T17:15:55.360Z,1629393355.360 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2021-08-19T17:17:55.837Z,1629393475.837 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:17:55.837Z,1629393475.837 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:17:55.837Z,1629393475.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:17:55.837Z,1629393475.837 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:17:56.244Z,1629393476.244 [Default:CheckIn:D] Stopped 2021-08-19T17:17:56.244Z,1629393476.244 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:17:56.709Z,1629393476.709 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.382715 min 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn:E] Stopped 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn] Stopped 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn](INFO): Running loop #28 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn] Running Loop=28 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:17:56.710Z,1629393476.710 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:17:58.655Z,1629393478.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171751.00,A,4252.75535,N,08510.79404,W,69.998,89.94,190821,,,A*72 2021-08-19T17:17:58.657Z,1629393478.657 [NAL9602](INFO): GPS fix at 20210819T171751: (42.879256, -85.179901) 2021-08-19T17:17:58.666Z,1629393478.666 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:17:58.666Z,1629393478.666 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:18:06.387Z,1629393486.387 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0081.lzma 2021-08-19T17:18:07.390Z,1629393487.390 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0081.lzma.bak 2021-08-19T17:18:07.390Z,1629393487.390 [DataOverHttps](INFO): SBD MOMSN=15895674 2021-08-19T17:18:20.875Z,1629393500.875 [NAL9602](INFO): SBD MO Status=2, MOMSN=46906, MT Status=2, MTMSN=0 2021-08-19T17:18:20.875Z,1629393500.875 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:18:24.841Z,1629393504.841 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0082.lzma 2021-08-19T17:18:25.502Z,1629393505.502 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0082.lzma.bak 2021-08-19T17:18:25.502Z,1629393505.502 [DataOverHttps](INFO): SBD MOMSN=15895678 2021-08-19T17:18:28.189Z,1629393508.189 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:18:28.189Z,1629393508.189 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:18:28.189Z,1629393508.189 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:18:43.162Z,1629393523.162 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T17:18:43.162Z,1629393523.162 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+29.7,0000.0,1489.WI,-00647,+00715,+00029,+00000,A 2021-08-19T17:19:02.139Z,1629393542.139 [NAL9602](INFO): SBD MO Status=0, MOMSN=46906, MT Status=0, MTMSN=0 2021-08-19T17:19:02.139Z,1629393542.139 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:19:32.852Z,1629393572.852 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:23:28.623Z,1629393808.623 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:23:28.623Z,1629393808.623 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:23:28.623Z,1629393808.623 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:23:28.624Z,1629393808.624 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:23:29.022Z,1629393809.022 [Default:CheckIn:D] Stopped 2021-08-19T17:23:29.022Z,1629393809.022 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:23:29.425Z,1629393809.425 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.929020 min 2021-08-19T17:23:29.425Z,1629393809.425 [Default:CheckIn:E] Stopped 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn] Stopped 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn](INFO): Running loop #29 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn] Running Loop=29 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:23:29.426Z,1629393809.426 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:23:31.437Z,1629393811.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172324.00,A,4252.73970,N,08502.45682,W,65.371,90.24,190821,,,D*7B 2021-08-19T17:23:31.439Z,1629393811.439 [NAL9602](INFO): GPS fix at 20210819T172324: (42.878995, -85.040947) 2021-08-19T17:23:31.447Z,1629393811.447 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:23:31.447Z,1629393811.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:23:38.411Z,1629393818.411 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0084.lzma 2021-08-19T17:23:39.414Z,1629393819.414 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0084.lzma.bak 2021-08-19T17:23:39.414Z,1629393819.414 [DataOverHttps](INFO): SBD MOMSN=15895697 2021-08-19T17:23:50.127Z,1629393830.127 [NAL9602](INFO): SBD MO Status=2, MOMSN=46907, MT Status=2, MTMSN=0 2021-08-19T17:23:50.127Z,1629393830.127 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:24:00.635Z,1629393840.635 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0085.lzma 2021-08-19T17:24:01.638Z,1629393841.638 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0085.lzma.bak 2021-08-19T17:24:01.638Z,1629393841.638 [DataOverHttps](INFO): SBD MOMSN=15895741 2021-08-19T17:24:04.310Z,1629393844.310 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:24:04.311Z,1629393844.311 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:24:04.311Z,1629393844.311 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:24:07.478Z,1629393847.478 [NAL9602](INFO): SBD MO Status=2, MOMSN=46907, MT Status=2, MTMSN=0 2021-08-19T17:24:07.478Z,1629393847.478 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:24:28.070Z,1629393868.070 [NAL9602](INFO): SBD MO Status=2, MOMSN=46907, MT Status=2, MTMSN=0 2021-08-19T17:24:28.070Z,1629393868.070 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:24:47.926Z,1629393887.926 [NAL9602](INFO): SBD MO Status=2, MOMSN=46907, MT Status=2, MTMSN=0 2021-08-19T17:24:47.927Z,1629393887.927 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:25:26.693Z,1629393926.693 [NAL9602](INFO): SBD MO Status=0, MOMSN=46907, MT Status=0, MTMSN=0 2021-08-19T17:25:26.693Z,1629393926.693 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:25:50.952Z,1629393950.952 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T17:25:50.952Z,1629393950.952 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489:WI,-00964,00029,+00000,A 2021-08-19T17:25:57.405Z,1629393957.405 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:26:14.080Z,1629393974.080 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T17:26:21.108Z,1629393981.108 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251293 2021-08-19T17:26:55.041Z,1629394015.041 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003063 2021-08-19T17:29:04.918Z,1629394144.918 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:29:04.919Z,1629394144.919 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:29:04.919Z,1629394144.919 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:29:04.919Z,1629394144.919 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:29:05.326Z,1629394145.326 [Default:CheckIn:D] Stopped 2021-08-19T17:29:05.326Z,1629394145.326 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:29:05.729Z,1629394145.729 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.534098 min 2021-08-19T17:29:05.729Z,1629394145.729 [Default:CheckIn:E] Stopped 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn] Stopped 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn](INFO): Running loop #30 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn] Running Loop=30 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:29:05.730Z,1629394145.730 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:29:07.731Z,1629394147.731 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172900.00,A,4251.62597,N,08454.54706,W,61.756,77.64,190821,,,D*76 2021-08-19T17:29:07.733Z,1629394147.733 [NAL9602](INFO): GPS fix at 20210819T172900: (42.860433, -84.909118) 2021-08-19T17:29:07.742Z,1629394147.742 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:29:07.742Z,1629394147.742 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:29:17.860Z,1629394157.860 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T17:29:23.894Z,1629394163.894 [NAL9602](INFO): SBD MO Status=0, MOMSN=46908, MT Status=0, MTMSN=0 2021-08-19T17:29:23.894Z,1629394163.894 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:29:24.889Z,1629394164.889 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.263355 2021-08-19T17:29:33.954Z,1629394173.954 [NAL9602](INFO): SBD MO Status=1, MOMSN=46909, MT Status=0, MTMSN=0 2021-08-19T17:29:34.012Z,1629394174.012 [NAL9602](INFO): Sent 70 bytes from file Logs/20210819T145007/Courier0087.lzma 2021-08-19T17:29:34.012Z,1629394174.012 [NAL9602](INFO): Packets left to send: 0 2021-08-19T17:29:42.932Z,1629394182.932 [NAL9602](INFO): SBD MO Status=1, MOMSN=46910, MT Status=0, MTMSN=0 2021-08-19T17:29:42.981Z,1629394182.981 [NAL9602](INFO): Sent 146 bytes from file Logs/20210819T145007/Express0088.lzma 2021-08-19T17:29:42.981Z,1629394182.981 [NAL9602](INFO): Packets left to send: 0 2021-08-19T17:29:50.791Z,1629394190.791 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T17:29:50.791Z,1629394190.791 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+30.0,0000.099.99 2021-08-19T17:29:50.793Z,1629394190.793 [NAL9602](INFO): SBD MO Status=0, MOMSN=46911, MT Status=0, MTMSN=0 2021-08-19T17:29:50.901Z,1629394190.901 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:29:50.902Z,1629394190.902 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:29:50.902Z,1629394190.902 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:29:55.808Z,1629394195.808 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003039 2021-08-19T17:30:21.497Z,1629394221.497 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:34:51.377Z,1629394491.377 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:34:51.377Z,1629394491.377 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:34:51.378Z,1629394491.378 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:34:51.378Z,1629394491.378 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:34:51.777Z,1629394491.777 [Default:CheckIn:D] Stopped 2021-08-19T17:34:51.777Z,1629394491.777 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:34:52.173Z,1629394492.173 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.308268 min 2021-08-19T17:34:52.173Z,1629394492.173 [Default:CheckIn:E] Stopped 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn] Stopped 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn](INFO): Running loop #31 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn] Running Loop=31 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:34:52.174Z,1629394492.174 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:34:54.187Z,1629394494.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173447.00,A,4249.71896,N,08450.38745,W,6.667,139.19,190821,,,D*74 2021-08-19T17:34:54.189Z,1629394494.189 [NAL9602](INFO): GPS fix at 20210819T173447: (42.828649, -84.839791) 2021-08-19T17:34:54.198Z,1629394494.198 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:34:54.198Z,1629394494.198 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:35:01.123Z,1629394501.123 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0090.lzma 2021-08-19T17:35:02.126Z,1629394502.126 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0090.lzma.bak 2021-08-19T17:35:02.126Z,1629394502.126 [DataOverHttps](INFO): SBD MOMSN=15896014 2021-08-19T17:35:07.945Z,1629394507.945 [NAL9602](INFO): SBD MO Status=0, MOMSN=46912, MT Status=0, MTMSN=0 2021-08-19T17:35:07.945Z,1629394507.945 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:35:19.270Z,1629394519.270 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0091.lzma 2021-08-19T17:35:20.270Z,1629394520.270 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0091.lzma.bak 2021-08-19T17:35:20.270Z,1629394520.270 [DataOverHttps](INFO): SBD MOMSN=15896017 2021-08-19T17:35:22.945Z,1629394522.945 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:35:22.945Z,1629394522.945 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:35:22.945Z,1629394522.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:35:38.637Z,1629394538.637 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:40:23.513Z,1629394823.513 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:40:23.514Z,1629394823.514 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:40:23.514Z,1629394823.514 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:40:23.514Z,1629394823.514 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:40:23.917Z,1629394823.917 [Default:CheckIn:D] Stopped 2021-08-19T17:40:23.917Z,1629394823.917 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.843929 min 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn:E] Stopped 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn] Stopped 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn](INFO): Running loop #32 2021-08-19T17:40:24.334Z,1629394824.334 [Default:CheckIn] Running Loop=32 2021-08-19T17:40:24.335Z,1629394824.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:40:24.335Z,1629394824.335 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:40:26.327Z,1629394826.327 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174019.00,A,4249.15227,N,08448.60062,W,52.503,111.55,190821,,,A*4F 2021-08-19T17:40:26.329Z,1629394826.329 [NAL9602](INFO): GPS fix at 20210819T174019: (42.819204, -84.810010) 2021-08-19T17:40:26.338Z,1629394826.338 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:40:26.338Z,1629394826.338 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:40:33.243Z,1629394833.243 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0093.lzma 2021-08-19T17:40:34.246Z,1629394834.246 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0093.lzma.bak 2021-08-19T17:40:34.246Z,1629394834.246 [DataOverHttps](INFO): SBD MOMSN=15896038 2021-08-19T17:40:38.455Z,1629394838.455 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T17:40:38.455Z,1629394838.455 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-19T17:40:46.967Z,1629394846.967 [NAL9602](INFO): SBD MO Status=2, MOMSN=46913, MT Status=2, MTMSN=0 2021-08-19T17:40:46.967Z,1629394846.967 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:40:56.274Z,1629394856.274 [NAL9602](INFO): SBD MO Status=0, MOMSN=46913, MT Status=0, MTMSN=0 2021-08-19T17:40:56.274Z,1629394856.274 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:40:56.956Z,1629394856.956 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0094.lzma 2021-08-19T17:40:59.957Z,1629394859.957 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0094.lzma.bak 2021-08-19T17:40:59.957Z,1629394859.957 [DataOverHttps](INFO): SBD MOMSN=15896084 2021-08-19T17:41:01.564Z,1629394861.564 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:41:01.565Z,1629394861.565 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:41:01.565Z,1629394861.565 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:41:21.730Z,1629394881.730 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T17:41:21.730Z,1629394881.730 [DVL_micro](ERROR): Failed to parse: :TS,000000000000+30.6,00000,000 2021-08-19T17:41:26.983Z,1629394886.983 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:43:27.039Z,1629395007.039 [DVL_micro](ERROR): Failed to parse: :SA,+01.86,-03.98,113.2 2021-08-19T17:44:19.341Z,1629395059.341 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.255466 2021-08-19T17:44:53.572Z,1629395093.572 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003071 2021-08-19T17:46:02.230Z,1629395162.230 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:46:02.230Z,1629395162.230 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:46:02.231Z,1629395162.231 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:46:02.231Z,1629395162.231 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:46:02.637Z,1629395162.637 [Default:CheckIn:D] Stopped 2021-08-19T17:46:02.637Z,1629395162.637 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:46:03.060Z,1629395163.060 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.489274 min 2021-08-19T17:46:03.060Z,1629395163.060 [Default:CheckIn:E] Stopped 2021-08-19T17:46:03.060Z,1629395163.060 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:46:03.060Z,1629395163.060 [Default:CheckIn] Stopped 2021-08-19T17:46:03.060Z,1629395163.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:46:03.061Z,1629395163.061 [Default:CheckIn](INFO): Running loop #33 2021-08-19T17:46:03.061Z,1629395163.061 [Default:CheckIn] Running Loop=33 2021-08-19T17:46:03.061Z,1629395163.061 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:46:03.061Z,1629395163.061 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:46:05.055Z,1629395165.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174558.00,A,4247.91374,N,08443.66262,W,67.315,90.65,190821,,,D*7C 2021-08-19T17:46:05.067Z,1629395165.067 [NAL9602](INFO): GPS fix at 20210819T174558: (42.798562, -84.727710) 2021-08-19T17:46:05.076Z,1629395165.076 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:46:05.076Z,1629395165.076 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:46:12.351Z,1629395172.351 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0096.lzma 2021-08-19T17:46:13.354Z,1629395173.354 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0096.lzma.bak 2021-08-19T17:46:13.354Z,1629395173.354 [DataOverHttps](INFO): SBD MOMSN=15896092 2021-08-19T17:46:22.834Z,1629395182.834 [NAL9602](INFO): SBD MO Status=2, MOMSN=46914, MT Status=2, MTMSN=0 2021-08-19T17:46:22.834Z,1629395182.834 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:46:32.672Z,1629395192.672 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20210819T145007/Express0097.lzma 2021-08-19T17:46:33.335Z,1629395193.335 [NAL9602](INFO): SBD MO Status=0, MOMSN=46914, MT Status=0, MTMSN=0 2021-08-19T17:46:33.336Z,1629395193.336 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:46:33.674Z,1629395193.674 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0097.lzma.bak 2021-08-19T17:46:33.674Z,1629395193.674 [DataOverHttps](INFO): SBD MOMSN=15896122 2021-08-19T17:46:36.217Z,1629395196.217 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:46:36.217Z,1629395196.217 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:46:36.217Z,1629395196.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:47:04.143Z,1629395224.143 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:51:36.799Z,1629395496.799 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:51:36.799Z,1629395496.799 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:51:36.799Z,1629395496.799 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:51:36.799Z,1629395496.799 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:51:37.211Z,1629395497.211 [Default:CheckIn:D] Stopped 2021-08-19T17:51:37.211Z,1629395497.211 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:51:37.620Z,1629395497.620 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.065495 min 2021-08-19T17:51:37.620Z,1629395497.620 [Default:CheckIn:E] Stopped 2021-08-19T17:51:37.620Z,1629395497.620 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:51:37.620Z,1629395497.620 [Default:CheckIn] Stopped 2021-08-19T17:51:37.620Z,1629395497.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:51:37.621Z,1629395497.621 [Default:CheckIn](INFO): Running loop #34 2021-08-19T17:51:37.621Z,1629395497.621 [Default:CheckIn] Running Loop=34 2021-08-19T17:51:37.621Z,1629395497.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:51:37.621Z,1629395497.621 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:51:39.623Z,1629395499.623 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175132.00,A,4243.78850,N,08440.12517,W,65.158,181.63,190821,,,D*40 2021-08-19T17:51:39.643Z,1629395499.643 [NAL9602](INFO): GPS fix at 20210819T175132: (42.729808, -84.668753) 2021-08-19T17:51:39.660Z,1629395499.660 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:51:39.661Z,1629395499.661 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:51:51.487Z,1629395511.487 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210819T145007/Courier0099.lzma 2021-08-19T17:51:52.490Z,1629395512.490 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0099.lzma.bak 2021-08-19T17:51:52.490Z,1629395512.490 [DataOverHttps](INFO): SBD MOMSN=15896159 2021-08-19T17:52:00.717Z,1629395520.717 [NAL9602](INFO): SBD MO Status=2, MOMSN=46915, MT Status=2, MTMSN=0 2021-08-19T17:52:00.717Z,1629395520.717 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:52:09.524Z,1629395529.524 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0100.lzma 2021-08-19T17:52:10.526Z,1629395530.526 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0100.lzma.bak 2021-08-19T17:52:10.526Z,1629395530.526 [DataOverHttps](INFO): SBD MOMSN=15896171 2021-08-19T17:52:12.887Z,1629395532.887 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:52:12.887Z,1629395532.887 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:52:12.887Z,1629395532.887 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:52:19.298Z,1629395539.298 [NAL9602](INFO): SBD MO Status=2, MOMSN=46915, MT Status=2, MTMSN=0 2021-08-19T17:52:19.298Z,1629395539.298 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T17:52:39.099Z,1629395559.099 [NAL9602](INFO): SBD MO Status=0, MOMSN=46915, MT Status=0, MTMSN=0 2021-08-19T17:52:39.099Z,1629395559.099 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:53:09.805Z,1629395589.805 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T17:57:13.416Z,1629395833.416 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T17:57:13.416Z,1629395833.416 [Default:CheckIn:C.Wait] Stopped 2021-08-19T17:57:13.417Z,1629395833.417 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T17:57:13.417Z,1629395833.417 [Default:CheckIn:D] Running Loop=1 2021-08-19T17:57:13.838Z,1629395833.838 [Default:CheckIn:D] Stopped 2021-08-19T17:57:13.838Z,1629395833.838 [Default:CheckIn:E] Running Loop=1 2021-08-19T17:57:14.233Z,1629395834.233 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.675944 min 2021-08-19T17:57:14.233Z,1629395834.233 [Default:CheckIn:E] Stopped 2021-08-19T17:57:14.233Z,1629395834.233 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T17:57:14.233Z,1629395834.233 [Default:CheckIn] Stopped 2021-08-19T17:57:14.233Z,1629395834.233 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T17:57:14.234Z,1629395834.234 [Default:CheckIn](INFO): Running loop #35 2021-08-19T17:57:14.234Z,1629395834.234 [Default:CheckIn] Running Loop=35 2021-08-19T17:57:14.234Z,1629395834.234 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T17:57:14.234Z,1629395834.234 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T17:57:16.238Z,1629395836.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175709.00,A,4239.92776,N,08435.96821,W,65.644,92.71,190821,,,D*70 2021-08-19T17:57:16.241Z,1629395836.241 [NAL9602](INFO): GPS fix at 20210819T175709: (42.665463, -84.599470) 2021-08-19T17:57:16.267Z,1629395836.267 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T17:57:16.267Z,1629395836.267 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T17:57:21.995Z,1629395841.995 [NAL9602](INFO): SBD MO Status=0, MOMSN=46916, MT Status=0, MTMSN=0 2021-08-19T17:57:21.995Z,1629395841.995 [NAL9602](INFO): No messages in MT queue 2021-08-19T17:57:23.775Z,1629395843.775 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0102.lzma 2021-08-19T17:57:24.778Z,1629395844.778 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0102.lzma.bak 2021-08-19T17:57:24.778Z,1629395844.778 [DataOverHttps](INFO): SBD MOMSN=15896179 2021-08-19T17:57:42.840Z,1629395862.840 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0103.lzma 2021-08-19T17:57:43.850Z,1629395863.850 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0103.lzma.bak 2021-08-19T17:57:43.851Z,1629395863.851 [DataOverHttps](INFO): SBD MOMSN=15896182 2021-08-19T17:57:47.215Z,1629395867.215 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T17:57:47.215Z,1629395867.215 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T17:57:47.240Z,1629395867.240 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T17:57:52.435Z,1629395872.435 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:01:30.139Z,1629396090.139 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:01:41.449Z,1629396101.449 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:01:52.358Z,1629396112.358 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:03.665Z,1629396123.665 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:14.579Z,1629396134.579 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:26.693Z,1629396146.693 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:37.603Z,1629396157.603 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:47.739Z,1629396167.739 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:02:47.739Z,1629396167.739 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:02:47.739Z,1629396167.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:02:47.739Z,1629396167.739 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:02:48.168Z,1629396168.168 [Default:CheckIn:D] Stopped 2021-08-19T18:02:48.168Z,1629396168.168 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.247656 min 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn:E] Stopped 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn] Stopped 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:02:48.574Z,1629396168.574 [Default:CheckIn](INFO): Running loop #36 2021-08-19T18:02:48.575Z,1629396168.575 [Default:CheckIn] Running Loop=36 2021-08-19T18:02:48.575Z,1629396168.575 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:02:48.575Z,1629396168.575 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:02:48.914Z,1629396168.914 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T18:02:50.560Z,1629396170.560 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180243.00,A,4240.66705,N,08427.95471,W,68.929,88.58,190821,,,A*75 2021-08-19T18:02:50.562Z,1629396170.562 [NAL9602](INFO): GPS fix at 20210819T180243: (42.677784, -84.465912) 2021-08-19T18:02:50.571Z,1629396170.571 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:02:50.571Z,1629396170.571 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:02:58.951Z,1629396178.951 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0105.lzma 2021-08-19T18:02:59.954Z,1629396179.954 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0105.lzma.bak 2021-08-19T18:02:59.954Z,1629396179.954 [DataOverHttps](INFO): SBD MOMSN=15896186 2021-08-19T18:03:17.308Z,1629396197.308 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0106.lzma 2021-08-19T18:03:18.310Z,1629396198.310 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0106.lzma.bak 2021-08-19T18:03:18.310Z,1629396198.310 [DataOverHttps](INFO): SBD MOMSN=15896189 2021-08-19T18:03:20.859Z,1629396200.859 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:03:20.859Z,1629396200.859 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:03:20.859Z,1629396200.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:03:25.687Z,1629396205.687 [NAL9602](INFO): SBD MO Status=2, MOMSN=46917, MT Status=2, MTMSN=0 2021-08-19T18:03:25.688Z,1629396205.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:03:32.976Z,1629396212.976 [NAL9602](INFO): SBD MO Status=0, MOMSN=46917, MT Status=0, MTMSN=0 2021-08-19T18:03:32.976Z,1629396212.976 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:04:03.669Z,1629396243.669 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:08:02.030Z,1629396482.030 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-19T18:08:02.031Z,1629396482.031 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-19T18:08:02.034Z,1629396482.034 [BPC1](INFO): Received data from all battery sticks. 2021-08-19T18:08:21.446Z,1629396501.446 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:08:21.446Z,1629396501.446 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:08:21.447Z,1629396501.447 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:08:21.447Z,1629396501.447 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:08:21.829Z,1629396501.829 [Default:CheckIn:D] Stopped 2021-08-19T18:08:21.829Z,1629396501.829 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:08:22.238Z,1629396502.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 208.809131 min 2021-08-19T18:08:22.238Z,1629396502.238 [Default:CheckIn:E] Stopped 2021-08-19T18:08:22.238Z,1629396502.238 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:08:22.238Z,1629396502.238 [Default:CheckIn] Stopped 2021-08-19T18:08:22.238Z,1629396502.238 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:08:22.239Z,1629396502.239 [Default:CheckIn](INFO): Running loop #37 2021-08-19T18:08:22.239Z,1629396502.239 [Default:CheckIn] Running Loop=37 2021-08-19T18:08:22.239Z,1629396502.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:08:22.239Z,1629396502.239 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:08:24.253Z,1629396504.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180817.00,A,4239.93379,N,08419.47797,W,67.782,88.31,190821,,,A*73 2021-08-19T18:08:24.255Z,1629396504.255 [NAL9602](INFO): GPS fix at 20210819T180817: (42.665563, -84.324633) 2021-08-19T18:08:24.270Z,1629396504.270 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:08:24.270Z,1629396504.270 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:08:31.155Z,1629396511.155 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210819T145007/Courier0108.lzma 2021-08-19T18:08:32.158Z,1629396512.158 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0108.lzma.bak 2021-08-19T18:08:32.158Z,1629396512.158 [DataOverHttps](INFO): SBD MOMSN=15896197 2021-08-19T18:08:42.037Z,1629396522.037 [NAL9602](INFO): SBD MO Status=0, MOMSN=46918, MT Status=0, MTMSN=0 2021-08-19T18:08:42.037Z,1629396522.037 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:08:53.140Z,1629396533.140 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210819T145007/Express0109.lzma 2021-08-19T18:08:54.142Z,1629396534.142 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0109.lzma.bak 2021-08-19T18:08:54.142Z,1629396534.142 [DataOverHttps](INFO): SBD MOMSN=15896200 2021-08-19T18:08:56.642Z,1629396536.642 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:08:56.643Z,1629396536.643 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:08:56.643Z,1629396536.643 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:09:12.768Z,1629396552.768 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:09:56.029Z,1629396596.029 [DVL_micro](ERROR): Failed to parse: :W,-00337,-00057,+00000,A 2021-08-19T18:13:57.417Z,1629396837.417 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:13:57.418Z,1629396837.418 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:13:57.418Z,1629396837.418 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:13:57.418Z,1629396837.418 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:13:57.832Z,1629396837.832 [Default:CheckIn:D] Stopped 2021-08-19T18:13:57.832Z,1629396837.832 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:13:58.230Z,1629396838.230 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.409196 min 2021-08-19T18:13:58.230Z,1629396838.230 [Default:CheckIn:E] Stopped 2021-08-19T18:13:58.230Z,1629396838.230 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:13:58.230Z,1629396838.230 [Default:CheckIn] Stopped 2021-08-19T18:13:58.230Z,1629396838.230 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:13:58.231Z,1629396838.231 [Default:CheckIn](INFO): Running loop #38 2021-08-19T18:13:58.231Z,1629396838.231 [Default:CheckIn] Running Loop=38 2021-08-19T18:13:58.231Z,1629396838.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:13:58.231Z,1629396838.231 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:14:00.239Z,1629396840.239 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181353.00,A,4239.34505,N,08411.52145,W,69.181,123.86,190821,,,A*4B 2021-08-19T18:14:00.241Z,1629396840.241 [NAL9602](INFO): GPS fix at 20210819T181353: (42.655751, -84.192024) 2021-08-19T18:14:00.250Z,1629396840.250 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:14:00.250Z,1629396840.250 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:14:07.524Z,1629396847.524 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0111.lzma 2021-08-19T18:14:08.526Z,1629396848.526 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0111.lzma.bak 2021-08-19T18:14:08.526Z,1629396848.526 [DataOverHttps](INFO): SBD MOMSN=15896352 2021-08-19T18:14:16.405Z,1629396856.405 [NAL9602](INFO): SBD MO Status=0, MOMSN=46919, MT Status=0, MTMSN=0 2021-08-19T18:14:16.406Z,1629396856.406 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:14:25.460Z,1629396865.460 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0112.lzma 2021-08-19T18:14:26.462Z,1629396866.462 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0112.lzma.bak 2021-08-19T18:14:26.462Z,1629396866.462 [DataOverHttps](INFO): SBD MOMSN=15896357 2021-08-19T18:14:28.973Z,1629396868.973 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:14:28.974Z,1629396868.974 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:14:28.974Z,1629396868.974 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:14:47.174Z,1629396887.174 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:15:11.018Z,1629396911.018 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T18:15:11.018Z,1629396911.018 [DVL_micro](ERROR): Failed to parse: :BI,-00536,+0166,+00000,I 2021-08-19T18:19:29.373Z,1629397169.373 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:19:29.374Z,1629397169.374 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:19:29.374Z,1629397169.374 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:19:29.374Z,1629397169.374 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:19:29.787Z,1629397169.787 [Default:CheckIn:D] Stopped 2021-08-19T18:19:29.787Z,1629397169.787 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:19:30.173Z,1629397170.173 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 219.941764 min 2021-08-19T18:19:30.173Z,1629397170.173 [Default:CheckIn:E] Stopped 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn] Stopped 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn](INFO): Running loop #39 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn] Running Loop=39 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:19:30.174Z,1629397170.174 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:19:32.191Z,1629397172.191 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181925.00,A,4238.74228,N,08403.07184,W,63.233,112.53,190821,,,D*4C 2021-08-19T18:19:32.197Z,1629397172.197 [NAL9602](INFO): GPS fix at 20210819T181925: (42.645705, -84.051197) 2021-08-19T18:19:32.233Z,1629397172.233 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:19:32.234Z,1629397172.234 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:19:41.992Z,1629397181.992 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0114.lzma 2021-08-19T18:19:42.994Z,1629397182.994 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0114.lzma.bak 2021-08-19T18:19:42.994Z,1629397182.994 [DataOverHttps](INFO): SBD MOMSN=15896382 2021-08-19T18:19:49.991Z,1629397189.991 [NAL9602](INFO): SBD MO Status=0, MOMSN=46920, MT Status=0, MTMSN=0 2021-08-19T18:19:49.991Z,1629397189.991 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:20:02.980Z,1629397202.980 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0115.lzma 2021-08-19T18:20:03.982Z,1629397203.982 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0115.lzma.bak 2021-08-19T18:20:03.982Z,1629397203.982 [DataOverHttps](INFO): SBD MOMSN=15896385 2021-08-19T18:20:06.571Z,1629397206.571 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:20:06.576Z,1629397206.576 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:20:06.576Z,1629397206.576 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:20:20.686Z,1629397220.686 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:20:21.503Z,1629397221.503 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T18:20:21.504Z,1629397221.504 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+31.8,0000.,000 2021-08-19T18:21:15.484Z,1629397275.484 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T18:21:24.791Z,1629397284.791 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=62.523983 2021-08-19T18:21:54.280Z,1629397314.280 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003006 2021-08-19T18:22:07.387Z,1629397327.387 [CBIT](IMPORTANT): Beginning ground fault scan 2021-08-19T18:22:18.291Z,1629397338.291 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002552 CHAN A1 (24V): 0.000419 CHAN A2 (12V): -0.005525 CHAN A3 (5V): -0.002757 CHAN B0 (3.3V): -0.001246 CHAN B1 (3.15aV): -0.001178 CHAN B2 (3.15bV): -0.001166 CHAN B3 (GND): 0.000391 OPEN: 0.004853 Full Scale Calc: 4.765 mA, -1.589 mA 2021-08-19T18:25:07.135Z,1629397507.135 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:25:07.135Z,1629397507.135 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:25:07.135Z,1629397507.135 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:25:07.136Z,1629397507.136 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:25:07.552Z,1629397507.552 [Default:CheckIn:D] Stopped 2021-08-19T18:25:07.552Z,1629397507.552 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:25:07.987Z,1629397507.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 225.571175 min 2021-08-19T18:25:07.987Z,1629397507.987 [Default:CheckIn:E] Stopped 2021-08-19T18:25:07.987Z,1629397507.987 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn] Stopped 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn](INFO): Running loop #40 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn] Running Loop=40 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:25:07.992Z,1629397507.992 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:25:09.956Z,1629397509.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182502.00,A,4235.70295,N,08356.41842,W,65.955,136.32,190821,,,D*43 2021-08-19T18:25:09.959Z,1629397509.959 [NAL9602](INFO): GPS fix at 20210819T182502: (42.595049, -83.940307) 2021-08-19T18:25:09.968Z,1629397509.968 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:25:09.968Z,1629397509.968 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:25:17.671Z,1629397517.671 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0117.lzma 2021-08-19T18:25:18.674Z,1629397518.674 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0117.lzma.bak 2021-08-19T18:25:18.674Z,1629397518.674 [DataOverHttps](INFO): SBD MOMSN=15896394 2021-08-19T18:25:25.734Z,1629397525.734 [NAL9602](INFO): SBD MO Status=0, MOMSN=46921, MT Status=0, MTMSN=0 2021-08-19T18:25:25.734Z,1629397525.734 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:25:36.912Z,1629397536.912 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20210819T145007/Express0118.lzma 2021-08-19T18:25:37.914Z,1629397537.914 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0118.lzma.bak 2021-08-19T18:25:37.914Z,1629397537.914 [DataOverHttps](INFO): SBD MOMSN=15896397 2021-08-19T18:25:41.673Z,1629397541.673 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:25:41.673Z,1629397541.673 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:25:41.673Z,1629397541.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:25:56.525Z,1629397556.525 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:26:54.309Z,1629397614.309 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T18:26:54.309Z,1629397614.309 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,39,0000.0,14 2021-08-19T18:28:06.671Z,1629397686.671 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T18:28:06.671Z,1629397686.671 [DVL_micro](ERROR): Failed to parse: :BI,-00070,-00010,-00026,+00000+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-19T18:30:32.057Z,1629397832.057 [DVL_micro](ERROR): only read 1 of 4 data items 2021-08-19T18:30:32.057Z,1629397832.057 [DVL_micro](ERROR): Failed to parse: :BI,-00092-00028,+00000,I 2021-08-19T18:30:42.215Z,1629397842.215 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:30:42.215Z,1629397842.215 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:30:42.215Z,1629397842.215 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:30:42.216Z,1629397842.216 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:30:42.559Z,1629397842.559 [Default:CheckIn:D] Stopped 2021-08-19T18:30:42.559Z,1629397842.559 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:30:42.968Z,1629397842.968 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 231.154639 min 2021-08-19T18:30:42.968Z,1629397842.968 [Default:CheckIn:E] Stopped 2021-08-19T18:30:42.968Z,1629397842.968 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:30:42.968Z,1629397842.968 [Default:CheckIn] Stopped 2021-08-19T18:30:42.968Z,1629397842.968 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:30:42.969Z,1629397842.969 [Default:CheckIn](INFO): Running loop #41 2021-08-19T18:30:42.969Z,1629397842.969 [Default:CheckIn] Running Loop=41 2021-08-19T18:30:42.969Z,1629397842.969 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:30:42.969Z,1629397842.969 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:30:45.007Z,1629397845.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183038.00,A,4233.47293,N,08349.42050,W,65.371,126.72,190821,,,A*40 2021-08-19T18:30:45.009Z,1629397845.009 [NAL9602](INFO): GPS fix at 20210819T183038: (42.557882, -83.823675) 2021-08-19T18:30:45.026Z,1629397845.026 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:30:45.026Z,1629397845.026 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:30:59.327Z,1629397859.327 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0120.lzma 2021-08-19T18:31:00.330Z,1629397860.330 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0120.lzma.bak 2021-08-19T18:31:00.330Z,1629397860.330 [DataOverHttps](INFO): SBD MOMSN=15896438 2021-08-19T18:31:08.862Z,1629397868.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=46922, MT Status=2, MTMSN=0 2021-08-19T18:31:08.862Z,1629397868.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:31:30.677Z,1629397890.677 [NAL9602](INFO): SBD MO Status=2, MOMSN=46922, MT Status=2, MTMSN=0 2021-08-19T18:31:30.677Z,1629397890.677 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:32:09.684Z,1629397929.684 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0121.lzma 2021-08-19T18:32:10.686Z,1629397930.686 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0121.lzma.bak 2021-08-19T18:32:10.686Z,1629397930.686 [DataOverHttps](INFO): SBD MOMSN=15896441 2021-08-19T18:32:13.137Z,1629397933.137 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:32:13.137Z,1629397933.137 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:32:13.137Z,1629397933.137 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:32:28.870Z,1629397948.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=46922, MT Status=2, MTMSN=0 2021-08-19T18:32:28.870Z,1629397948.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:32:56.389Z,1629397976.389 [NAL9602](INFO): SBD MO Status=0, MOMSN=46922, MT Status=0, MTMSN=0 2021-08-19T18:32:56.389Z,1629397976.389 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:33:27.090Z,1629398007.090 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:34:12.338Z,1629398052.338 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T18:34:12.338Z,1629398052.338 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,31,0000.0,1489.0,000 2021-08-19T18:37:13.740Z,1629398233.740 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:37:13.740Z,1629398233.740 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:37:13.740Z,1629398233.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:37:13.740Z,1629398233.740 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:37:14.137Z,1629398234.137 [Default:CheckIn:D] Stopped 2021-08-19T18:37:14.137Z,1629398234.137 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:37:14.541Z,1629398234.541 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.680924 min 2021-08-19T18:37:14.541Z,1629398234.541 [Default:CheckIn:E] Stopped 2021-08-19T18:37:14.541Z,1629398234.541 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:37:14.541Z,1629398234.541 [Default:CheckIn] Stopped 2021-08-19T18:37:14.541Z,1629398234.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:37:14.542Z,1629398234.542 [Default:CheckIn](INFO): Running loop #42 2021-08-19T18:37:14.542Z,1629398234.542 [Default:CheckIn] Running Loop=42 2021-08-19T18:37:14.542Z,1629398234.542 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:37:14.542Z,1629398234.542 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:37:16.557Z,1629398236.557 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183709.00,A,4228.40129,N,08345.35261,W,66.246,184.56,190821,,,D*4B 2021-08-19T18:37:16.559Z,1629398236.559 [NAL9602](INFO): GPS fix at 20210819T183709: (42.473355, -83.755877) 2021-08-19T18:37:16.568Z,1629398236.568 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:37:16.568Z,1629398236.568 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:37:30.699Z,1629398250.699 [NAL9602](INFO): SBD MO Status=0, MOMSN=46923, MT Status=0, MTMSN=0 2021-08-19T18:37:30.699Z,1629398250.699 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:37:48.948Z,1629398268.948 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210819T145007/Courier0123.lzma 2021-08-19T18:37:49.942Z,1629398269.942 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0123.lzma.bak 2021-08-19T18:37:49.943Z,1629398269.943 [DataOverHttps](INFO): SBD MOMSN=15896494 2021-08-19T18:38:01.476Z,1629398281.476 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:38:06.993Z,1629398286.993 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20210819T145007/Express0124.lzma 2021-08-19T18:38:07.994Z,1629398287.994 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0124.lzma.bak 2021-08-19T18:38:07.994Z,1629398287.994 [DataOverHttps](INFO): SBD MOMSN=15896497 2021-08-19T18:38:10.370Z,1629398290.370 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:38:10.371Z,1629398290.371 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:38:10.371Z,1629398290.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:38:19.657Z,1629398299.657 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T18:38:19.657Z,1629398299.657 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+32.2,0000.0,1489:WI,-00096,+00156,+00007,+00000,A 2021-08-19T18:43:10.949Z,1629398590.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:43:10.950Z,1629398590.950 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:43:10.950Z,1629398590.950 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:43:10.950Z,1629398590.950 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:43:11.353Z,1629398591.353 [Default:CheckIn:D] Stopped 2021-08-19T18:43:11.353Z,1629398591.353 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.634538 min 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn:E] Stopped 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn] Stopped 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn](INFO): Running loop #43 2021-08-19T18:43:11.741Z,1629398591.741 [Default:CheckIn] Running Loop=43 2021-08-19T18:43:11.742Z,1629398591.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:43:11.742Z,1629398591.742 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:43:13.771Z,1629398593.771 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184306.00,A,4222.59650,N,08345.32369,W,62.514,156.20,190821,,,D*48 2021-08-19T18:43:13.773Z,1629398593.773 [NAL9602](INFO): GPS fix at 20210819T184306: (42.376608, -83.755395) 2021-08-19T18:43:13.782Z,1629398593.782 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:43:13.782Z,1629398593.782 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:43:28.148Z,1629398608.148 [NAL9602](INFO): SBD MO Status=0, MOMSN=46924, MT Status=0, MTMSN=0 2021-08-19T18:43:28.148Z,1629398608.148 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:43:45.861Z,1629398625.861 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T18:43:53.520Z,1629398633.520 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0126.lzma 2021-08-19T18:43:55.024Z,1629398635.024 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0126.lzma.bak 2021-08-19T18:43:55.025Z,1629398635.025 [DataOverHttps](INFO): SBD MOMSN=15896501 2021-08-19T18:43:55.243Z,1629398635.243 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T18:43:55.243Z,1629398635.243 [DVL_micro](ERROR): Failed to parse: :BI,-00126,+00101,+00002,+00000+00000000.00,+00000000.00,+00000099.99,000.00 2021-08-19T18:43:58.850Z,1629398638.850 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:44:11.412Z,1629398651.412 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0127.lzma 2021-08-19T18:44:12.414Z,1629398652.414 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0127.lzma.bak 2021-08-19T18:44:12.414Z,1629398652.414 [DataOverHttps](INFO): SBD MOMSN=15896504 2021-08-19T18:44:15.047Z,1629398655.047 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:44:15.052Z,1629398655.052 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:44:15.052Z,1629398655.052 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:49:15.688Z,1629398955.688 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:49:15.688Z,1629398955.688 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:49:15.689Z,1629398955.689 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:49:15.689Z,1629398955.689 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:49:16.042Z,1629398956.042 [Default:CheckIn:D] Stopped 2021-08-19T18:49:16.042Z,1629398956.042 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 249.712695 min 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn:E] Stopped 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn] Stopped 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn](INFO): Running loop #44 2021-08-19T18:49:16.453Z,1629398956.453 [Default:CheckIn] Running Loop=44 2021-08-19T18:49:16.454Z,1629398956.454 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:49:16.454Z,1629398956.454 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:49:18.483Z,1629398958.483 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184911.00,A,4219.10510,N,08341.39920,W,54.972,155.76,190821,,,D*47 2021-08-19T18:49:18.490Z,1629398958.490 [NAL9602](INFO): GPS fix at 20210819T184911: (42.318418, -83.689987) 2021-08-19T18:49:18.499Z,1629398958.499 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:49:18.499Z,1629398958.499 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:49:27.456Z,1629398967.456 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T18:49:34.823Z,1629398974.823 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0129.lzma 2021-08-19T18:49:34.837Z,1629398974.837 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.628017 2021-08-19T18:49:45.944Z,1629398985.944 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003070 2021-08-19T18:49:47.242Z,1629398987.242 [NAL9602](INFO): SBD MO Status=2, MOMSN=46925, MT Status=2, MTMSN=0 2021-08-19T18:49:47.242Z,1629398987.242 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:49:54.936Z,1629398994.936 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0129.lzma 2021-08-19T18:49:55.938Z,1629398995.938 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0129.lzma.bak 2021-08-19T18:49:55.938Z,1629398995.938 [DataOverHttps](INFO): SBD MOMSN=15896513 2021-08-19T18:50:02.602Z,1629399002.602 [NAL9602](INFO): SBD MO Status=2, MOMSN=46925, MT Status=2, MTMSN=0 2021-08-19T18:50:02.602Z,1629399002.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:50:14.252Z,1629399014.252 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0130.lzma 2021-08-19T18:50:15.254Z,1629399015.254 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0130.lzma.bak 2021-08-19T18:50:15.254Z,1629399015.254 [DataOverHttps](INFO): SBD MOMSN=15896517 2021-08-19T18:50:17.557Z,1629399017.557 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:50:17.558Z,1629399017.558 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:50:17.558Z,1629399017.558 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:50:25.591Z,1629399025.591 [NAL9602](INFO): SBD MO Status=2, MOMSN=46925, MT Status=2, MTMSN=0 2021-08-19T18:50:25.591Z,1629399025.591 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:50:43.815Z,1629399043.815 [NAL9602](INFO): SBD MO Status=2, MOMSN=46925, MT Status=2, MTMSN=0 2021-08-19T18:50:43.815Z,1629399043.815 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T18:51:20.672Z,1629399080.672 [NAL9602](INFO): SBD MO Status=0, MOMSN=46925, MT Status=0, MTMSN=0 2021-08-19T18:51:20.673Z,1629399080.673 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:51:51.342Z,1629399111.342 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:55:18.249Z,1629399318.249 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T18:55:18.249Z,1629399318.249 [Default:CheckIn:C.Wait] Stopped 2021-08-19T18:55:18.250Z,1629399318.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T18:55:18.250Z,1629399318.250 [Default:CheckIn:D] Running Loop=1 2021-08-19T18:55:18.652Z,1629399318.652 [Default:CheckIn:D] Stopped 2021-08-19T18:55:18.653Z,1629399318.653 [Default:CheckIn:E] Running Loop=1 2021-08-19T18:55:19.049Z,1629399319.049 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 255.756201 min 2021-08-19T18:55:19.049Z,1629399319.049 [Default:CheckIn:E] Stopped 2021-08-19T18:55:19.049Z,1629399319.049 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T18:55:19.049Z,1629399319.049 [Default:CheckIn] Stopped 2021-08-19T18:55:19.050Z,1629399319.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T18:55:19.050Z,1629399319.050 [Default:CheckIn](INFO): Running loop #45 2021-08-19T18:55:19.050Z,1629399319.050 [Default:CheckIn] Running Loop=45 2021-08-19T18:55:19.050Z,1629399319.050 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T18:55:19.050Z,1629399319.050 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T18:55:21.063Z,1629399321.063 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185514.00,A,4213.89714,N,08341.88868,W,62.009,302.44,190821,,,D*45 2021-08-19T18:55:21.065Z,1629399321.065 [NAL9602](INFO): GPS fix at 20210819T185514: (42.231619, -83.698145) 2021-08-19T18:55:21.074Z,1629399321.074 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T18:55:21.075Z,1629399321.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T18:55:22.897Z,1629399322.897 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T18:55:30.225Z,1629399330.225 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247570 2021-08-19T18:55:37.224Z,1629399337.224 [NAL9602](INFO): SBD MO Status=0, MOMSN=46926, MT Status=0, MTMSN=0 2021-08-19T18:55:37.224Z,1629399337.224 [NAL9602](INFO): No messages in MT queue 2021-08-19T18:55:38.455Z,1629399338.455 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-19T18:55:38.455Z,1629399338.455 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2021-08-19T18:55:43.852Z,1629399343.852 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003040 2021-08-19T18:55:50.124Z,1629399350.124 [NAL9602](INFO): SBD MO Status=1, MOMSN=46927, MT Status=0, MTMSN=0 2021-08-19T18:55:50.173Z,1629399350.173 [NAL9602](INFO): Sent 72 bytes from file Logs/20210819T145007/Courier0132.lzma 2021-08-19T18:55:50.173Z,1629399350.173 [NAL9602](INFO): Packets left to send: 0 2021-08-19T18:55:54.237Z,1629399354.237 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210819T145007/Express0133.lzma 2021-08-19T18:55:55.242Z,1629399355.242 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0133.lzma.bak 2021-08-19T18:55:55.242Z,1629399355.242 [DataOverHttps](INFO): SBD MOMSN=15896523 2021-08-19T18:55:57.795Z,1629399357.795 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T18:55:57.800Z,1629399357.800 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T18:55:57.800Z,1629399357.800 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T18:56:20.816Z,1629399380.816 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T18:56:53.541Z,1629399413.541 [DVL_micro](ERROR): Failed to parse: :WI,-00034,-00006,-00102,+00000,A 2021-08-19T18:57:06.704Z,1629399426.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-19T18:57:13.733Z,1629399433.733 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239498 2021-08-19T18:57:47.941Z,1629399467.941 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003069 2021-08-19T19:00:58.603Z,1629399658.603 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T19:00:58.603Z,1629399658.603 [Default:CheckIn:C.Wait] Stopped 2021-08-19T19:00:58.608Z,1629399658.608 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T19:00:58.608Z,1629399658.608 [Default:CheckIn:D] Running Loop=1 2021-08-19T19:00:58.974Z,1629399658.974 [Default:CheckIn:D] Stopped 2021-08-19T19:00:58.974Z,1629399658.974 [Default:CheckIn:E] Running Loop=1 2021-08-19T19:00:59.375Z,1629399659.375 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 261.428206 min 2021-08-19T19:00:59.375Z,1629399659.375 [Default:CheckIn:E] Stopped 2021-08-19T19:00:59.375Z,1629399659.375 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T19:00:59.375Z,1629399659.375 [Default:CheckIn] Stopped 2021-08-19T19:00:59.375Z,1629399659.375 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T19:00:59.376Z,1629399659.376 [Default:CheckIn](INFO): Running loop #46 2021-08-19T19:00:59.376Z,1629399659.376 [Default:CheckIn] Running Loop=46 2021-08-19T19:00:59.376Z,1629399659.376 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T19:00:59.376Z,1629399659.376 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T19:01:01.405Z,1629399661.405 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190054.00,A,4213.01708,N,08344.22081,W,8.397,212.36,190821,,,D*7A 2021-08-19T19:01:01.407Z,1629399661.407 [NAL9602](INFO): GPS fix at 20210819T190054: (42.216951, -83.737014) 2021-08-19T19:01:01.416Z,1629399661.416 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T19:01:01.416Z,1629399661.416 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T19:01:08.219Z,1629399668.219 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0135.lzma 2021-08-19T19:01:09.222Z,1629399669.222 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0135.lzma.bak 2021-08-19T19:01:09.222Z,1629399669.222 [DataOverHttps](INFO): SBD MOMSN=15896532 2021-08-19T19:01:26.037Z,1629399686.037 [NAL9602](INFO): SBD MO Status=2, MOMSN=46928, MT Status=2, MTMSN=0 2021-08-19T19:01:26.037Z,1629399686.037 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-19T19:01:27.212Z,1629399687.212 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210819T145007/Express0136.lzma 2021-08-19T19:01:28.214Z,1629399688.214 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0136.lzma.bak 2021-08-19T19:01:28.214Z,1629399688.214 [DataOverHttps](INFO): SBD MOMSN=15896535 2021-08-19T19:01:30.907Z,1629399690.907 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T19:01:30.912Z,1629399690.912 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T19:01:30.913Z,1629399690.913 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T19:01:43.065Z,1629399703.065 [NAL9602](INFO): SBD MO Status=0, MOMSN=46928, MT Status=0, MTMSN=0 2021-08-19T19:01:43.066Z,1629399703.066 [NAL9602](INFO): No messages in MT queue 2021-08-19T19:02:13.750Z,1629399733.750 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T19:06:31.697Z,1629399991.697 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T19:06:31.697Z,1629399991.697 [Default:CheckIn:C.Wait] Stopped 2021-08-19T19:06:31.697Z,1629399991.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T19:06:31.697Z,1629399991.697 [Default:CheckIn:D] Running Loop=1 2021-08-19T19:06:32.105Z,1629399992.105 [Default:CheckIn:D] Stopped 2021-08-19T19:06:32.106Z,1629399992.106 [Default:CheckIn:E] Running Loop=1 2021-08-19T19:06:32.519Z,1629399992.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 266.980404 min 2021-08-19T19:06:32.519Z,1629399992.519 [Default:CheckIn:E] Stopped 2021-08-19T19:06:32.519Z,1629399992.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn] Stopped 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn](INFO): Running loop #47 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn] Running Loop=47 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T19:06:32.520Z,1629399992.520 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T19:06:34.524Z,1629399994.524 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190627.00,A,4212.99327,N,08344.18921,W,0.855,84.34,190821,,,D*49 2021-08-19T19:06:34.526Z,1629399994.526 [NAL9602](INFO): GPS fix at 20210819T190627: (42.216555, -83.736487) 2021-08-19T19:06:34.535Z,1629399994.535 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T19:06:34.535Z,1629399994.535 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T19:06:43.175Z,1629400003.175 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210819T145007/Courier0138.lzma 2021-08-19T19:06:44.178Z,1629400004.178 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0138.lzma.bak 2021-08-19T19:06:44.178Z,1629400004.178 [DataOverHttps](INFO): SBD MOMSN=15896543 2021-08-19T19:06:56.418Z,1629400016.418 [NAL9602](INFO): SBD MO Status=0, MOMSN=46929, MT Status=0, MTMSN=0 2021-08-19T19:06:56.418Z,1629400016.418 [NAL9602](INFO): No messages in MT queue 2021-08-19T19:07:04.848Z,1629400024.848 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20210819T145007/Express0139.lzma 2021-08-19T19:07:05.850Z,1629400025.850 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0139.lzma.bak 2021-08-19T19:07:05.851Z,1629400025.851 [DataOverHttps](INFO): SBD MOMSN=15896546 2021-08-19T19:07:08.165Z,1629400028.165 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T19:07:08.165Z,1629400028.165 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T19:07:08.166Z,1629400028.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T19:07:27.122Z,1629400047.122 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T19:09:08.934Z,1629400148.934 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:09:20.646Z,1629400160.646 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:09:31.962Z,1629400171.962 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:09:43.271Z,1629400183.271 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:09:54.178Z,1629400194.178 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:10:05.897Z,1629400205.897 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:10:17.216Z,1629400217.216 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:10:28.924Z,1629400228.924 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-19T19:10:53.572Z,1629400253.572 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-19T19:10:53.572Z,1629400253.572 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+33.1,0000.0000 2021-08-19T19:12:08.723Z,1629400328.723 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T19:12:08.723Z,1629400328.723 [Default:CheckIn:C.Wait] Stopped 2021-08-19T19:12:08.723Z,1629400328.723 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T19:12:08.723Z,1629400328.723 [Default:CheckIn:D] Running Loop=1 2021-08-19T19:12:09.141Z,1629400329.141 [Default:CheckIn:D] Stopped 2021-08-19T19:12:09.141Z,1629400329.141 [Default:CheckIn:E] Running Loop=1 2021-08-19T19:12:09.539Z,1629400329.539 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 272.597656 min 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn:E] Stopped 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn] Stopped 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn](INFO): Running loop #48 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn] Running Loop=48 2021-08-19T19:12:09.540Z,1629400329.540 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T19:12:09.541Z,1629400329.541 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T19:12:11.573Z,1629400331.573 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191204.00,A,4212.98224,N,08344.16899,W,1.905,223.04,190821,,,A*7E 2021-08-19T19:12:11.576Z,1629400331.576 [NAL9602](INFO): GPS fix at 20210819T191204: (42.216371, -83.736150) 2021-08-19T19:12:11.585Z,1629400331.585 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T19:12:11.585Z,1629400331.585 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T19:12:19.232Z,1629400339.232 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210819T145007/Courier0141.lzma 2021-08-19T19:12:20.234Z,1629400340.234 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0141.lzma.bak 2021-08-19T19:12:20.234Z,1629400340.234 [DataOverHttps](INFO): SBD MOMSN=15896550 2021-08-19T19:12:37.348Z,1629400357.348 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210819T145007/Express0142.lzma 2021-08-19T19:12:38.351Z,1629400358.351 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0142.lzma.bak 2021-08-19T19:12:38.351Z,1629400358.351 [DataOverHttps](INFO): SBD MOMSN=15896553 2021-08-19T19:12:42.150Z,1629400362.150 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T19:12:42.151Z,1629400362.151 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T19:12:42.151Z,1629400362.151 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T19:15:40.630Z,1629400540.630 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-19T19:15:40.630Z,1629400540.630 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-19T19:15:40.633Z,1629400540.633 [BPC1](INFO): Received data from all battery sticks. 2021-08-19T19:17:13.942Z,1629400633.942 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-19T19:17:40.222Z,1629400660.222 [DVL_micro](ERROR): Failed to parse: :SA,-03.74,-05.67,023.7 2021-08-19T19:17:42.661Z,1629400662.661 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T19:17:42.661Z,1629400662.661 [Default:CheckIn:C.Wait] Stopped 2021-08-19T19:17:42.661Z,1629400662.661 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T19:17:42.662Z,1629400662.662 [Default:CheckIn:D] Running Loop=1 2021-08-19T19:17:43.048Z,1629400663.048 [Default:CheckIn:D] Stopped 2021-08-19T19:17:43.048Z,1629400663.048 [Default:CheckIn:E] Running Loop=1 2021-08-19T19:17:43.497Z,1629400663.497 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 278.162793 min 2021-08-19T19:17:43.497Z,1629400663.497 [Default:CheckIn:E] Stopped 2021-08-19T19:17:43.497Z,1629400663.497 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T19:17:43.497Z,1629400663.497 [Default:CheckIn] Stopped 2021-08-19T19:17:43.498Z,1629400663.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T19:17:43.498Z,1629400663.498 [Default:CheckIn](INFO): Running loop #49 2021-08-19T19:17:43.498Z,1629400663.498 [Default:CheckIn] Running Loop=49 2021-08-19T19:17:43.498Z,1629400663.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-19T19:17:43.498Z,1629400663.498 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-19T19:17:45.481Z,1629400665.481 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191738.00,A,4213.00194,N,08344.17433,W,2.294,238.23,190821,,,A*7E 2021-08-19T19:17:45.483Z,1629400665.483 [NAL9602](INFO): GPS fix at 20210819T191738: (42.216699, -83.736239) 2021-08-19T19:17:45.492Z,1629400665.492 [Default:CheckIn:Read_GPS] Stopped 2021-08-19T19:17:45.492Z,1629400665.492 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-19T19:17:53.771Z,1629400673.771 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210819T145007/Courier0144.lzma 2021-08-19T19:17:54.774Z,1629400674.774 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Courier0144.lzma.bak 2021-08-19T19:17:54.774Z,1629400674.774 [DataOverHttps](INFO): SBD MOMSN=15896561 2021-08-19T19:18:11.980Z,1629400691.980 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20210819T145007/Express0145.lzma 2021-08-19T19:18:12.982Z,1629400692.982 [DataOverHttps](INFO): Moved sent file to Logs/20210819T145007/Express0145.lzma.bak 2021-08-19T19:18:12.982Z,1629400692.982 [DataOverHttps](INFO): SBD MOMSN=15896564 2021-08-19T19:18:15.603Z,1629400695.603 [Default:CheckIn:Read_Iridium] Stopped 2021-08-19T19:18:15.603Z,1629400695.603 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-19T19:18:15.603Z,1629400695.603 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-19T19:18:17.607Z,1629400697.607 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-19T19:20:02.262Z,1629400802.262 [DVL_micro](ERROR): Failed to parse: :SA,-03.76,-05.69,022.8 2021-08-19T19:21:59.475Z,1629400919.475 [DVL_micro](ERROR): Failed to parse:004,+00021+00000,I0000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-19T19:23:16.176Z,1629400996.176 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-19T19:23:16.176Z,1629400996.176 [Default:CheckIn:C.Wait] Stopped 2021-08-19T19:23:16.176Z,1629400996.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-19T19:23:16.176Z,1629400996.176 [Default:CheckIn:D] Running Loop=1 2021-08-19T19:23:16.581Z,1629400996.581 [Default:CheckIn:D] Stopped 2021-08-19T19:23:16.581Z,1629400996.581 [Default:CheckIn:E] Running Loop=1 2021-08-19T19:23:16.993Z,1629400996.993 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 283.721647 min 2021-08-19T19:23:16.993Z,1629400996.993 [Default:CheckIn:E] Stopped 2021-08-19T19:23:16.993Z,1629400996.993 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-19T19:23:16.993Z,1629400996.993 [Default:CheckIn] Stopped 2021-08-19T19:23:16.994Z,1629400996.994 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-19T19:23:16.994Z,1629400996.994 [Default:CheckIn](INFO): Running loop #50 2021-08-19T19:23:16.994Z,1629400996.994 [Default:CheckIn] Running Loop=50 2021-08-19T19:23:16.994Z,1629400996.994 [Default:CheckIn](DE