2020-03-05T21:03:33.897Z,1583442213.897 [DataOverHttps](INFO): Received command:restart logs 2020-03-05T21:03:33.918Z,1583442213.918 [CommandLine](IMPORTANT): got command restart logs 2020-03-05T21:04:08.149Z,1583442248.149 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:04:08.149Z,1583442248.149 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:04:08.149Z,1583442248.149 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:04:08.149Z,1583442248.149 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:04:08.543Z,1583442248.543 [Default:CheckIn:D] Stopped 2020-03-05T21:04:08.543Z,1583442248.543 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:04:08.942Z,1583442248.942 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.952702 min 2020-03-05T21:04:08.943Z,1583442248.943 [Default:CheckIn:E] Stopped 2020-03-05T21:04:08.944Z,1583442248.944 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:04:08.944Z,1583442248.944 [Default:CheckIn] Stopped 2020-03-05T21:04:08.945Z,1583442248.945 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:04:08.945Z,1583442248.945 [Default:CheckIn](INFO): Running loop #7 2020-03-05T21:04:08.945Z,1583442248.945 [Default:CheckIn] Running Loop=7 2020-03-05T21:04:08.946Z,1583442248.946 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:04:08.946Z,1583442248.946 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:04:10.935Z,1583442250.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210417.00,A,3647.82133,N,12150.64634,W,1.322,110.74,050320,,,D*74 2020-03-05T21:04:10.937Z,1583442250.937 [NAL9602](INFO): GPS fix at 20200305T210417: (36.797022, -121.844106) 2020-03-05T21:04:10.968Z,1583442250.968 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:04:10.968Z,1583442250.968 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:04:19.837Z,1583442259.837 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20200305T210333/Courier0000.lzma 2020-03-05T21:04:22.846Z,1583442262.846 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0000.lzma.bak 2020-03-05T21:04:22.846Z,1583442262.846 [DataOverHttps](INFO): SBD MOMSN=12297751 2020-03-05T21:04:42.449Z,1583442282.449 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20200305T170958/Express0046.lzma 2020-03-05T21:04:44.059Z,1583442284.059 [NAL9602](INFO): SBD MO Status=0, MOMSN=8017, MT Status=0, MTMSN=0 2020-03-05T21:04:44.059Z,1583442284.059 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:04:44.454Z,1583442284.454 [DataOverHttps](INFO): Moved sent file to Logs/20200305T170958/Express0046.lzma.bak 2020-03-05T21:04:44.455Z,1583442284.455 [DataOverHttps](INFO): SBD MOMSN=12297755 2020-03-05T21:05:05.114Z,1583442305.114 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20200305T210333/Express0001.lzma 2020-03-05T21:05:07.110Z,1583442307.110 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0001.lzma.bak 2020-03-05T21:05:07.110Z,1583442307.110 [DataOverHttps](INFO): SBD MOMSN=12297758 2020-03-05T21:05:14.754Z,1583442314.754 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:05:27.352Z,1583442327.352 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200305T210333/Express0004.lzma 2020-03-05T21:05:29.358Z,1583442329.358 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0004.lzma.bak 2020-03-05T21:05:29.358Z,1583442329.358 [DataOverHttps](INFO): SBD MOMSN=12297763 2020-03-05T21:05:30.941Z,1583442330.941 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:05:30.942Z,1583442330.942 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:05:30.942Z,1583442330.942 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:06:10.555Z,1583442370.555 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T21:08:52.559Z,1583442532.559 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-03-05T21:10:31.556Z,1583442631.556 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:10:31.556Z,1583442631.556 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:10:31.556Z,1583442631.556 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:10:31.557Z,1583442631.557 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:10:31.931Z,1583442631.931 [Default:CheckIn:D] Stopped 2020-03-05T21:10:31.931Z,1583442631.931 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.342505 min 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn:E] Stopped 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn] Stopped 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn](INFO): Running loop #8 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn] Running Loop=8 2020-03-05T21:10:32.331Z,1583442632.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:10:32.332Z,1583442632.332 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:10:34.324Z,1583442634.324 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211041.00,A,3648.34462,N,12147.44448,W,24.745,55.12,050320,,,D*7E 2020-03-05T21:10:34.326Z,1583442634.326 [NAL9602](INFO): GPS fix at 20200305T211041: (36.805744, -121.790741) 2020-03-05T21:10:34.377Z,1583442634.377 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:10:34.377Z,1583442634.377 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:10:42.384Z,1583442642.384 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0006.lzma 2020-03-05T21:10:44.391Z,1583442644.391 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0006.lzma.bak 2020-03-05T21:10:44.391Z,1583442644.391 [DataOverHttps](INFO): SBD MOMSN=12297783 2020-03-05T21:10:47.655Z,1583442647.655 [NAL9602](INFO): SBD MO Status=0, MOMSN=8018, MT Status=0, MTMSN=0 2020-03-05T21:10:47.656Z,1583442647.656 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:11:01.720Z,1583442661.720 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200305T210333/Express0007.lzma 2020-03-05T21:11:03.726Z,1583442663.726 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0007.lzma.bak 2020-03-05T21:11:03.727Z,1583442663.727 [DataOverHttps](INFO): SBD MOMSN=12297786 2020-03-05T21:11:05.060Z,1583442665.060 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:11:05.060Z,1583442665.060 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:11:05.060Z,1583442665.060 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:11:18.358Z,1583442678.358 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:16:05.640Z,1583442965.640 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:16:05.640Z,1583442965.640 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:16:05.640Z,1583442965.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:16:05.640Z,1583442965.640 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:16:06.088Z,1583442966.088 [Default:CheckIn:D] Stopped 2020-03-05T21:16:06.088Z,1583442966.088 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:16:06.448Z,1583442966.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.911776 min 2020-03-05T21:16:06.448Z,1583442966.448 [Default:CheckIn:E] Stopped 2020-03-05T21:16:06.448Z,1583442966.448 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:16:06.448Z,1583442966.448 [Default:CheckIn] Stopped 2020-03-05T21:16:06.448Z,1583442966.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:16:06.449Z,1583442966.449 [Default:CheckIn](INFO): Running loop #9 2020-03-05T21:16:06.449Z,1583442966.449 [Default:CheckIn] Running Loop=9 2020-03-05T21:16:06.449Z,1583442966.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:16:06.449Z,1583442966.449 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:16:08.440Z,1583442968.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211615.00,A,3648.31832,N,12147.12472,W,0.311,101.33,050320,,,D*7F 2020-03-05T21:16:08.443Z,1583442968.443 [NAL9602](INFO): GPS fix at 20200305T211615: (36.805305, -121.785412) 2020-03-05T21:16:08.494Z,1583442968.494 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:16:08.494Z,1583442968.494 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:16:16.640Z,1583442976.640 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0009.lzma 2020-03-05T21:16:18.646Z,1583442978.646 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0009.lzma.bak 2020-03-05T21:16:18.646Z,1583442978.646 [DataOverHttps](INFO): SBD MOMSN=12297791 2020-03-05T21:16:22.986Z,1583442982.986 [NAL9602](INFO): SBD MO Status=0, MOMSN=8019, MT Status=0, MTMSN=0 2020-03-05T21:16:22.986Z,1583442982.986 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:16:23.068Z,1583442983.068 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-03-05T21:16:53.682Z,1583443013.682 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:16:55.425Z,1583443015.425 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20200305T210333/Express0010.lzma 2020-03-05T21:16:57.430Z,1583443017.430 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0010.lzma.bak 2020-03-05T21:16:57.431Z,1583443017.431 [DataOverHttps](INFO): SBD MOMSN=12297795 2020-03-05T21:16:58.964Z,1583443018.964 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:16:58.965Z,1583443018.965 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:16:58.965Z,1583443018.965 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:21:59.584Z,1583443319.584 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:21:59.584Z,1583443319.584 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:21:59.584Z,1583443319.584 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:21:59.584Z,1583443319.584 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:21:59.956Z,1583443319.956 [Default:CheckIn:D] Stopped 2020-03-05T21:21:59.956Z,1583443319.956 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:22:00.397Z,1583443320.397 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.809587 min 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn:E] Stopped 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn] Stopped 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn](INFO): Running loop #10 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn] Running Loop=10 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:22:00.398Z,1583443320.398 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:22:02.348Z,1583443322.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212209.00,A,3648.31739,N,12147.14154,W,0.019,270.73,050320,,,D*7C 2020-03-05T21:22:02.350Z,1583443322.350 [NAL9602](INFO): GPS fix at 20200305T212209: (36.805290, -121.785692) 2020-03-05T21:22:02.401Z,1583443322.401 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:22:02.401Z,1583443322.401 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:22:10.392Z,1583443330.392 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0012.lzma 2020-03-05T21:22:12.398Z,1583443332.398 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0012.lzma.bak 2020-03-05T21:22:12.399Z,1583443332.399 [DataOverHttps](INFO): SBD MOMSN=12297815 2020-03-05T21:22:14.875Z,1583443334.875 [NAL9602](INFO): SBD MO Status=0, MOMSN=8020, MT Status=0, MTMSN=0 2020-03-05T21:22:14.876Z,1583443334.876 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:22:31.848Z,1583443351.848 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200305T210333/Express0013.lzma 2020-03-05T21:22:33.854Z,1583443353.854 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0013.lzma.bak 2020-03-05T21:22:33.855Z,1583443353.855 [DataOverHttps](INFO): SBD MOMSN=12297818 2020-03-05T21:22:35.101Z,1583443355.101 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:22:35.102Z,1583443355.102 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:22:35.102Z,1583443355.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:22:45.578Z,1583443365.578 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:23:29.257Z,1583443409.257 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-03-05T21:27:35.676Z,1583443655.676 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:27:35.676Z,1583443655.676 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:27:35.676Z,1583443655.676 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:27:35.676Z,1583443655.676 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:27:36.098Z,1583443656.098 [Default:CheckIn:D] Stopped 2020-03-05T21:27:36.098Z,1583443656.098 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:27:36.481Z,1583443656.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.411955 min 2020-03-05T21:27:36.481Z,1583443656.481 [Default:CheckIn:E] Stopped 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn] Stopped 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn](INFO): Running loop #11 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn] Running Loop=11 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:27:36.482Z,1583443656.482 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:27:38.474Z,1583443658.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212745.00,A,3648.31688,N,12147.14200,W,0.019,270.73,050320,,,D*78 2020-03-05T21:27:38.476Z,1583443658.476 [NAL9602](INFO): GPS fix at 20200305T212745: (36.805281, -121.785700) 2020-03-05T21:27:38.515Z,1583443658.515 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:27:38.515Z,1583443658.515 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:27:48.148Z,1583443668.148 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0015.lzma 2020-03-05T21:27:50.154Z,1583443670.154 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0015.lzma.bak 2020-03-05T21:27:50.154Z,1583443670.154 [DataOverHttps](INFO): SBD MOMSN=12297844 2020-03-05T21:27:53.832Z,1583443673.832 [NAL9602](INFO): SBD MO Status=0, MOMSN=8021, MT Status=0, MTMSN=0 2020-03-05T21:27:53.832Z,1583443673.832 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:28:10.768Z,1583443690.768 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0016.lzma 2020-03-05T21:28:12.774Z,1583443692.774 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0016.lzma.bak 2020-03-05T21:28:12.775Z,1583443692.775 [DataOverHttps](INFO): SBD MOMSN=12297847 2020-03-05T21:28:14.079Z,1583443694.079 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:28:14.080Z,1583443694.080 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:28:14.080Z,1583443694.080 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:28:24.534Z,1583443704.534 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:29:09.407Z,1583443749.407 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T21:33:14.657Z,1583443994.657 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:33:14.657Z,1583443994.657 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:33:14.657Z,1583443994.657 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:33:14.658Z,1583443994.658 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:33:15.042Z,1583443995.042 [Default:CheckIn:D] Stopped 2020-03-05T21:33:15.042Z,1583443995.042 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.061011 min 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn:E] Stopped 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn] Stopped 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn](INFO): Running loop #12 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn] Running Loop=12 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:33:15.455Z,1583443995.455 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:33:17.448Z,1583443997.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213324.00,A,3648.31681,N,12147.14245,W,0.058,270.73,050320,,,A*72 2020-03-05T21:33:17.450Z,1583443997.450 [NAL9602](INFO): GPS fix at 20200305T213324: (36.805280, -121.785708) 2020-03-05T21:33:17.491Z,1583443997.491 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:33:17.492Z,1583443997.492 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:33:25.380Z,1583444005.380 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0018.lzma 2020-03-05T21:33:27.386Z,1583444007.386 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0018.lzma.bak 2020-03-05T21:33:27.387Z,1583444007.387 [DataOverHttps](INFO): SBD MOMSN=12297851 2020-03-05T21:33:33.603Z,1583444013.603 [NAL9602](INFO): SBD MO Status=0, MOMSN=8022, MT Status=0, MTMSN=0 2020-03-05T21:33:33.604Z,1583444013.604 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:33:44.672Z,1583444024.672 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0019.lzma 2020-03-05T21:33:46.679Z,1583444026.679 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0019.lzma.bak 2020-03-05T21:33:46.679Z,1583444026.679 [DataOverHttps](INFO): SBD MOMSN=12297855 2020-03-05T21:33:48.192Z,1583444028.192 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:33:48.192Z,1583444028.192 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:33:48.192Z,1583444028.192 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:34:04.310Z,1583444044.310 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:38:48.756Z,1583444328.756 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:38:48.756Z,1583444328.756 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:38:48.756Z,1583444328.756 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:38:48.756Z,1583444328.756 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:38:49.172Z,1583444329.172 [Default:CheckIn:D] Stopped 2020-03-05T21:38:49.172Z,1583444329.172 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:38:49.560Z,1583444329.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.629850 min 2020-03-05T21:38:49.560Z,1583444329.560 [Default:CheckIn:E] Stopped 2020-03-05T21:38:49.560Z,1583444329.560 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:38:49.560Z,1583444329.560 [Default:CheckIn] Stopped 2020-03-05T21:38:49.560Z,1583444329.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:38:49.561Z,1583444329.561 [Default:CheckIn](INFO): Running loop #13 2020-03-05T21:38:49.561Z,1583444329.561 [Default:CheckIn] Running Loop=13 2020-03-05T21:38:49.561Z,1583444329.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:38:49.561Z,1583444329.561 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:38:51.561Z,1583444331.561 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213858.00,A,3648.31910,N,12147.14248,W,0.078,270.73,050320,,,D*7F 2020-03-05T21:38:51.563Z,1583444331.563 [NAL9602](INFO): GPS fix at 20200305T213858: (36.805318, -121.785708) 2020-03-05T21:38:51.618Z,1583444331.618 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:38:51.618Z,1583444331.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:39:01.185Z,1583444341.185 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0021.lzma 2020-03-05T21:39:03.190Z,1583444343.190 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0021.lzma.bak 2020-03-05T21:39:03.191Z,1583444343.191 [DataOverHttps](INFO): SBD MOMSN=12297878 2020-03-05T21:39:22.925Z,1583444362.925 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200305T210333/Express0022.lzma 2020-03-05T21:39:24.930Z,1583444364.930 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0022.lzma.bak 2020-03-05T21:39:24.931Z,1583444364.931 [DataOverHttps](INFO): SBD MOMSN=12297881 2020-03-05T21:39:26.368Z,1583444366.368 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:39:26.368Z,1583444366.368 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:39:26.368Z,1583444366.368 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:39:50.136Z,1583444390.136 [NAL9602](INFO): SBD MO Status=2, MOMSN=8023, MT Status=2, MTMSN=0 2020-03-05T21:39:50.136Z,1583444390.136 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T21:40:29.724Z,1583444429.724 [NAL9602](INFO): SBD MO Status=2, MOMSN=8023, MT Status=2, MTMSN=0 2020-03-05T21:40:29.724Z,1583444429.724 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T21:40:39.828Z,1583444439.828 [NAL9602](INFO): SBD MO Status=0, MOMSN=8023, MT Status=0, MTMSN=0 2020-03-05T21:40:39.828Z,1583444439.828 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:41:10.526Z,1583444470.526 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:44:26.923Z,1583444666.923 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:44:26.923Z,1583444666.923 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:44:26.923Z,1583444666.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:44:26.923Z,1583444666.923 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:44:27.309Z,1583444667.309 [Default:CheckIn:D] Stopped 2020-03-05T21:44:27.309Z,1583444667.309 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:44:27.812Z,1583444667.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.265470 min 2020-03-05T21:44:27.812Z,1583444667.812 [Default:CheckIn:E] Stopped 2020-03-05T21:44:27.812Z,1583444667.812 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:44:27.812Z,1583444667.812 [Default:CheckIn] Stopped 2020-03-05T21:44:27.812Z,1583444667.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:44:27.813Z,1583444667.813 [Default:CheckIn](INFO): Running loop #14 2020-03-05T21:44:27.814Z,1583444667.814 [Default:CheckIn] Running Loop=14 2020-03-05T21:44:27.814Z,1583444667.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:44:27.814Z,1583444667.814 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:44:29.703Z,1583444669.703 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214436.00,A,3648.18006,N,12147.19251,W,2.585,216.79,050320,,,D*73 2020-03-05T21:44:29.705Z,1583444669.705 [NAL9602](INFO): GPS fix at 20200305T214436: (36.803001, -121.786542) 2020-03-05T21:44:29.760Z,1583444669.760 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:44:29.760Z,1583444669.760 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:44:37.748Z,1583444677.748 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0024.lzma 2020-03-05T21:44:39.754Z,1583444679.754 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0024.lzma.bak 2020-03-05T21:44:39.754Z,1583444679.754 [DataOverHttps](INFO): SBD MOMSN=12297885 2020-03-05T21:44:40.634Z,1583444680.634 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-03-05T21:44:40.636Z,1583444680.636 [BPC1](INFO): Received data from all battery sticks. 2020-03-05T21:44:57.100Z,1583444697.100 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0025.lzma 2020-03-05T21:44:59.106Z,1583444699.106 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0025.lzma.bak 2020-03-05T21:44:59.106Z,1583444699.106 [DataOverHttps](INFO): SBD MOMSN=12297888 2020-03-05T21:45:00.455Z,1583444700.455 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:45:00.455Z,1583444700.455 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:45:00.455Z,1583444700.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:45:21.011Z,1583444721.011 [NAL9602](INFO): SBD MO Status=0, MOMSN=8024, MT Status=0, MTMSN=0 2020-03-05T21:45:21.012Z,1583444721.012 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:45:51.718Z,1583444751.718 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:49:50.921Z,1583444990.921 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-03-05T21:50:01.111Z,1583445001.111 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:50:01.111Z,1583445001.111 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:50:01.111Z,1583445001.111 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:50:01.111Z,1583445001.111 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:50:01.424Z,1583445001.424 [Default:CheckIn:D] Stopped 2020-03-05T21:50:01.424Z,1583445001.424 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:50:01.833Z,1583445001.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.834058 min 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn:E] Stopped 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn] Stopped 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn](INFO): Running loop #15 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn] Running Loop=15 2020-03-05T21:50:01.835Z,1583445001.835 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:50:01.836Z,1583445001.836 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:50:03.816Z,1583445003.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215010.00,A,3648.13751,N,12147.20513,W,0.097,243.24,050320,,,D*7B 2020-03-05T21:50:03.818Z,1583445003.818 [NAL9602](INFO): GPS fix at 20200305T215010: (36.802292, -121.786752) 2020-03-05T21:50:03.841Z,1583445003.841 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:50:03.842Z,1583445003.842 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:50:11.525Z,1583445011.525 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20200305T210333/Courier0027.lzma 2020-03-05T21:50:13.530Z,1583445013.530 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0027.lzma.bak 2020-03-05T21:50:13.531Z,1583445013.531 [DataOverHttps](INFO): SBD MOMSN=12297910 2020-03-05T21:50:33.933Z,1583445033.933 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0028.lzma 2020-03-05T21:50:35.938Z,1583445035.938 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0028.lzma.bak 2020-03-05T21:50:35.939Z,1583445035.939 [DataOverHttps](INFO): SBD MOMSN=12297913 2020-03-05T21:50:37.371Z,1583445037.371 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:50:37.371Z,1583445037.371 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:50:37.371Z,1583445037.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:50:51.104Z,1583445051.104 [NAL9602](INFO): SBD MO Status=0, MOMSN=8025, MT Status=0, MTMSN=0 2020-03-05T21:50:51.104Z,1583445051.104 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:51:21.786Z,1583445081.786 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T21:55:37.981Z,1583445337.981 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T21:55:37.982Z,1583445337.982 [Default:CheckIn:C.Wait] Stopped 2020-03-05T21:55:37.982Z,1583445337.982 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T21:55:37.983Z,1583445337.983 [Default:CheckIn:D] Running Loop=1 2020-03-05T21:55:38.399Z,1583445338.399 [Default:CheckIn:D] Stopped 2020-03-05T21:55:38.399Z,1583445338.399 [Default:CheckIn:E] Running Loop=1 2020-03-05T21:55:38.777Z,1583445338.777 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.450309 min 2020-03-05T21:55:38.777Z,1583445338.777 [Default:CheckIn:E] Stopped 2020-03-05T21:55:38.777Z,1583445338.777 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T21:55:38.777Z,1583445338.777 [Default:CheckIn] Stopped 2020-03-05T21:55:38.777Z,1583445338.777 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T21:55:38.778Z,1583445338.778 [Default:CheckIn](INFO): Running loop #16 2020-03-05T21:55:38.778Z,1583445338.778 [Default:CheckIn] Running Loop=16 2020-03-05T21:55:38.778Z,1583445338.778 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T21:55:38.778Z,1583445338.778 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T21:55:40.772Z,1583445340.772 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215547.00,A,3648.13987,N,12147.20739,W,0.019,270.49,050320,,,D*7E 2020-03-05T21:55:40.782Z,1583445340.782 [NAL9602](INFO): GPS fix at 20200305T215547: (36.802331, -121.786790) 2020-03-05T21:55:40.805Z,1583445340.805 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T21:55:40.805Z,1583445340.805 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T21:55:48.188Z,1583445348.188 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0030.lzma 2020-03-05T21:55:50.195Z,1583445350.195 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0030.lzma.bak 2020-03-05T21:55:50.195Z,1583445350.195 [DataOverHttps](INFO): SBD MOMSN=12297917 2020-03-05T21:55:52.487Z,1583445352.487 [NAL9602](INFO): SBD MO Status=0, MOMSN=8026, MT Status=0, MTMSN=0 2020-03-05T21:55:52.487Z,1583445352.487 [NAL9602](INFO): No messages in MT queue 2020-03-05T21:56:09.917Z,1583445369.917 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200305T210333/Express0031.lzma 2020-03-05T21:56:11.922Z,1583445371.922 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0031.lzma.bak 2020-03-05T21:56:11.923Z,1583445371.923 [DataOverHttps](INFO): SBD MOMSN=12297920 2020-03-05T21:56:13.524Z,1583445373.524 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T21:56:13.524Z,1583445373.524 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T21:56:13.524Z,1583445373.524 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T21:56:23.190Z,1583445383.190 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:00:24.023Z,1583445624.023 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-03-05T22:01:14.113Z,1583445674.113 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:01:14.113Z,1583445674.113 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:01:14.113Z,1583445674.113 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:01:14.114Z,1583445674.114 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:01:14.534Z,1583445674.534 [Default:CheckIn:D] Stopped 2020-03-05T22:01:14.534Z,1583445674.534 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:01:14.917Z,1583445674.917 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.052547 min 2020-03-05T22:01:14.917Z,1583445674.917 [Default:CheckIn:E] Stopped 2020-03-05T22:01:14.917Z,1583445674.917 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:01:14.917Z,1583445674.917 [Default:CheckIn] Stopped 2020-03-05T22:01:14.917Z,1583445674.917 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:01:14.918Z,1583445674.918 [Default:CheckIn](INFO): Running loop #17 2020-03-05T22:01:14.918Z,1583445674.918 [Default:CheckIn] Running Loop=17 2020-03-05T22:01:14.918Z,1583445674.918 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:01:14.918Z,1583445674.918 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:01:16.898Z,1583445676.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220123.00,A,3648.14031,N,12147.20874,W,0.000,270.49,050320,,,D*73 2020-03-05T22:01:16.900Z,1583445676.900 [NAL9602](INFO): GPS fix at 20200305T220123: (36.802338, -121.786812) 2020-03-05T22:01:16.946Z,1583445676.946 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:01:16.946Z,1583445676.946 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:01:24.569Z,1583445684.569 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0033.lzma 2020-03-05T22:01:26.574Z,1583445686.574 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0033.lzma.bak 2020-03-05T22:01:26.575Z,1583445686.575 [DataOverHttps](INFO): SBD MOMSN=12297946 2020-03-05T22:01:29.424Z,1583445689.424 [NAL9602](INFO): SBD MO Status=0, MOMSN=8027, MT Status=0, MTMSN=0 2020-03-05T22:01:29.424Z,1583445689.424 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:01:43.788Z,1583445703.788 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0034.lzma 2020-03-05T22:01:45.802Z,1583445705.802 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0034.lzma.bak 2020-03-05T22:01:45.803Z,1583445705.803 [DataOverHttps](INFO): SBD MOMSN=12297949 2020-03-05T22:01:47.240Z,1583445707.240 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:01:47.240Z,1583445707.240 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:01:47.270Z,1583445707.270 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:02:00.126Z,1583445720.126 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:06:47.835Z,1583446007.835 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:06:47.835Z,1583446007.835 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:06:47.836Z,1583446007.836 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:06:47.836Z,1583446007.836 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:06:48.233Z,1583446008.233 [Default:CheckIn:D] Stopped 2020-03-05T22:06:48.233Z,1583446008.233 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.614193 min 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn:E] Stopped 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn] Stopped 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:06:48.668Z,1583446008.668 [Default:CheckIn](INFO): Running loop #18 2020-03-05T22:06:48.671Z,1583446008.671 [Default:CheckIn] Running Loop=18 2020-03-05T22:06:48.671Z,1583446008.671 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:06:48.671Z,1583446008.671 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:06:50.614Z,1583446010.614 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220657.00,A,3648.14053,N,12147.20806,W,0.019,270.49,050320,,,D*7E 2020-03-05T22:06:50.616Z,1583446010.616 [NAL9602](INFO): GPS fix at 20200305T220657: (36.802342, -121.786801) 2020-03-05T22:06:50.657Z,1583446010.657 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:06:50.657Z,1583446010.657 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:06:58.713Z,1583446018.713 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0036.lzma 2020-03-05T22:07:00.718Z,1583446020.718 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0036.lzma.bak 2020-03-05T22:07:00.718Z,1583446020.718 [DataOverHttps](INFO): SBD MOMSN=12297953 2020-03-05T22:07:18.049Z,1583446038.049 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0037.lzma 2020-03-05T22:07:20.054Z,1583446040.054 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0037.lzma.bak 2020-03-05T22:07:20.055Z,1583446040.055 [DataOverHttps](INFO): SBD MOMSN=12297956 2020-03-05T22:07:21.382Z,1583446041.382 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:07:21.382Z,1583446041.382 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:07:21.382Z,1583446041.382 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:07:44.752Z,1583446064.752 [NAL9602](INFO): SBD MO Status=2, MOMSN=8028, MT Status=2, MTMSN=0 2020-03-05T22:07:44.752Z,1583446064.752 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T22:08:10.616Z,1583446090.616 [NAL9602](INFO): SBD MO Status=2, MOMSN=8028, MT Status=2, MTMSN=0 2020-03-05T22:08:10.616Z,1583446090.616 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T22:08:49.017Z,1583446129.017 [NAL9602](INFO): SBD MO Status=0, MOMSN=8028, MT Status=0, MTMSN=0 2020-03-05T22:08:49.017Z,1583446129.017 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:09:19.688Z,1583446159.688 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:12:21.932Z,1583446341.932 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:12:21.933Z,1583446341.933 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:12:21.933Z,1583446341.933 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:12:21.933Z,1583446341.933 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:12:22.340Z,1583446342.340 [Default:CheckIn:D] Stopped 2020-03-05T22:12:22.340Z,1583446342.340 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:12:22.723Z,1583446342.723 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.182650 min 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn:E] Stopped 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn] Stopped 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn](INFO): Running loop #19 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn] Running Loop=19 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:12:22.724Z,1583446342.724 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:12:24.728Z,1583446344.728 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221231.00,A,3648.14119,N,12147.20789,W,0.019,270.49,050320,,,D*7C 2020-03-05T22:12:24.730Z,1583446344.730 [NAL9602](INFO): GPS fix at 20200305T221231: (36.802353, -121.786798) 2020-03-05T22:12:24.774Z,1583446344.774 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:12:24.774Z,1583446344.774 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:12:32.853Z,1583446352.853 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0039.lzma 2020-03-05T22:12:34.028Z,1583446354.028 [NAL9602](INFO): SBD MO Status=0, MOMSN=8029, MT Status=0, MTMSN=0 2020-03-05T22:12:34.029Z,1583446354.029 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:12:34.858Z,1583446354.858 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0039.lzma.bak 2020-03-05T22:12:34.859Z,1583446354.859 [DataOverHttps](INFO): SBD MOMSN=12297978 2020-03-05T22:12:52.193Z,1583446372.193 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0040.lzma 2020-03-05T22:12:54.194Z,1583446374.194 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0040.lzma.bak 2020-03-05T22:12:54.195Z,1583446374.195 [DataOverHttps](INFO): SBD MOMSN=12297981 2020-03-05T22:12:55.468Z,1583446375.468 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:12:55.468Z,1583446375.468 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:12:55.468Z,1583446375.468 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:13:04.719Z,1583446384.719 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:14:02.089Z,1583446442.089 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2020-03-05T22:14:04.097Z,1583446444.097 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.027493 2020-03-05T22:14:16.767Z,1583446456.767 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003629 2020-03-05T22:17:56.094Z,1583446676.094 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:17:56.094Z,1583446676.094 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:17:56.094Z,1583446676.094 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:17:56.095Z,1583446676.095 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:17:56.468Z,1583446676.468 [Default:CheckIn:D] Stopped 2020-03-05T22:17:56.468Z,1583446676.468 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.751457 min 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn:E] Stopped 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn] Stopped 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn](INFO): Running loop #20 2020-03-05T22:17:56.847Z,1583446676.847 [Default:CheckIn] Running Loop=20 2020-03-05T22:17:56.848Z,1583446676.848 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:17:56.848Z,1583446676.848 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:17:58.840Z,1583446678.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221805.00,A,3648.14483,N,12147.25311,W,2.333,301.16,050320,,,D*73 2020-03-05T22:17:58.850Z,1583446678.850 [NAL9602](INFO): GPS fix at 20200305T221805: (36.802414, -121.787552) 2020-03-05T22:17:58.884Z,1583446678.884 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:17:58.884Z,1583446678.884 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:18:06.168Z,1583446686.168 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0042.lzma 2020-03-05T22:18:11.451Z,1583446691.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=8030, MT Status=0, MTMSN=0 2020-03-05T22:18:11.451Z,1583446691.451 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:18:15.922Z,1583446695.922 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0042.lzma 2020-03-05T22:18:17.923Z,1583446697.923 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0042.lzma.bak 2020-03-05T22:18:17.924Z,1583446697.924 [DataOverHttps](INFO): SBD MOMSN=12297985 2020-03-05T22:18:35.733Z,1583446715.733 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20200305T210333/Express0043.lzma 2020-03-05T22:18:37.738Z,1583446717.738 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0043.lzma.bak 2020-03-05T22:18:37.738Z,1583446717.738 [DataOverHttps](INFO): SBD MOMSN=12297988 2020-03-05T22:18:39.370Z,1583446719.370 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:18:39.370Z,1583446719.370 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:18:39.370Z,1583446719.370 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:18:42.166Z,1583446722.166 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:20:24.400Z,1583446824.400 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-03-05T22:23:39.955Z,1583447019.955 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:23:39.955Z,1583447019.955 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:23:39.955Z,1583447019.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:23:39.956Z,1583447019.956 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:23:40.371Z,1583447020.371 [Default:CheckIn:D] Stopped 2020-03-05T22:23:40.371Z,1583447020.371 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:23:40.748Z,1583447020.748 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.483171 min 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn:E] Stopped 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn] Stopped 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn](INFO): Running loop #21 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn] Running Loop=21 2020-03-05T22:23:40.749Z,1583447020.749 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:23:40.750Z,1583447020.750 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:23:42.752Z,1583447022.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222349.00,A,3648.16729,N,12147.28186,W,0.019,285.78,050320,,,D*7F 2020-03-05T22:23:42.754Z,1583447022.754 [NAL9602](INFO): GPS fix at 20200305T222349: (36.802788, -121.788031) 2020-03-05T22:23:42.796Z,1583447022.796 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:23:42.796Z,1583447022.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:23:50.352Z,1583447030.352 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0045.lzma 2020-03-05T22:23:52.358Z,1583447032.358 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0045.lzma.bak 2020-03-05T22:23:52.359Z,1583447032.359 [DataOverHttps](INFO): SBD MOMSN=12298010 2020-03-05T22:23:56.887Z,1583447036.887 [NAL9602](INFO): SBD MO Status=0, MOMSN=8031, MT Status=0, MTMSN=0 2020-03-05T22:23:56.888Z,1583447036.888 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:24:12.073Z,1583447052.073 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200305T210333/Express0046.lzma 2020-03-05T22:24:14.078Z,1583447054.078 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0046.lzma.bak 2020-03-05T22:24:14.079Z,1583447054.079 [DataOverHttps](INFO): SBD MOMSN=12298013 2020-03-05T22:24:15.493Z,1583447055.493 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:24:15.493Z,1583447055.493 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:24:15.493Z,1583447055.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:24:27.588Z,1583447067.588 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:29:16.132Z,1583447356.132 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:29:16.132Z,1583447356.132 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:29:16.132Z,1583447356.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:29:16.133Z,1583447356.133 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:29:16.504Z,1583447356.504 [Default:CheckIn:D] Stopped 2020-03-05T22:29:16.504Z,1583447356.504 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:29:16.908Z,1583447356.908 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.085376 min 2020-03-05T22:29:16.908Z,1583447356.908 [Default:CheckIn:E] Stopped 2020-03-05T22:29:16.908Z,1583447356.908 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:29:16.908Z,1583447356.908 [Default:CheckIn] Stopped 2020-03-05T22:29:16.908Z,1583447356.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:29:16.909Z,1583447356.909 [Default:CheckIn](INFO): Running loop #22 2020-03-05T22:29:16.909Z,1583447356.909 [Default:CheckIn] Running Loop=22 2020-03-05T22:29:16.909Z,1583447356.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:29:16.909Z,1583447356.909 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:29:18.900Z,1583447358.900 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222925.00,A,3648.17137,N,12147.28079,W,0.019,285.78,050320,,,A*73 2020-03-05T22:29:18.902Z,1583447358.902 [NAL9602](INFO): GPS fix at 20200305T222925: (36.802856, -121.788013) 2020-03-05T22:29:18.944Z,1583447358.944 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:29:18.944Z,1583447358.944 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:29:26.245Z,1583447366.245 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0048.lzma 2020-03-05T22:29:28.250Z,1583447368.250 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0048.lzma.bak 2020-03-05T22:29:28.251Z,1583447368.251 [DataOverHttps](INFO): SBD MOMSN=12298017 2020-03-05T22:29:45.670Z,1583447385.670 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200305T210333/Express0049.lzma 2020-03-05T22:29:47.675Z,1583447387.675 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0049.lzma.bak 2020-03-05T22:29:47.675Z,1583447387.675 [DataOverHttps](INFO): SBD MOMSN=12298020 2020-03-05T22:29:48.904Z,1583447388.904 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:29:48.904Z,1583447388.904 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:29:48.904Z,1583447388.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:32:35.735Z,1583447555.735 [NAL9602](INFO): SBD MO Status=0, MOMSN=8032, MT Status=0, MTMSN=0 2020-03-05T22:32:35.735Z,1583447555.735 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:33:06.432Z,1583447586.432 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:34:49.477Z,1583447689.477 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:34:49.477Z,1583447689.477 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:34:49.477Z,1583447689.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:34:49.478Z,1583447689.478 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:34:49.889Z,1583447689.889 [Default:CheckIn:D] Stopped 2020-03-05T22:34:49.889Z,1583447689.889 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.641805 min 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn:E] Stopped 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn] Stopped 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn](INFO): Running loop #23 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn] Running Loop=23 2020-03-05T22:34:50.305Z,1583447690.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:34:50.306Z,1583447690.306 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:34:52.288Z,1583447692.288 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223459.00,A,3648.17199,N,12147.28140,W,0.078,285.78,050320,,,A*7C 2020-03-05T22:34:52.290Z,1583447692.290 [NAL9602](INFO): GPS fix at 20200305T223459: (36.802867, -121.788023) 2020-03-05T22:34:52.314Z,1583447692.314 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:34:52.314Z,1583447692.314 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:34:59.924Z,1583447699.924 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0051.lzma 2020-03-05T22:35:01.930Z,1583447701.930 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0051.lzma.bak 2020-03-05T22:35:01.931Z,1583447701.931 [DataOverHttps](INFO): SBD MOMSN=12298056 2020-03-05T22:35:04.407Z,1583447704.407 [NAL9602](INFO): SBD MO Status=0, MOMSN=8033, MT Status=0, MTMSN=0 2020-03-05T22:35:04.407Z,1583447704.407 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:35:19.225Z,1583447719.225 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200305T210333/Express0052.lzma 2020-03-05T22:35:21.230Z,1583447721.230 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0052.lzma.bak 2020-03-05T22:35:21.231Z,1583447721.231 [DataOverHttps](INFO): SBD MOMSN=12298059 2020-03-05T22:35:22.620Z,1583447722.620 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:35:22.620Z,1583447722.620 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:35:22.620Z,1583447722.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:35:35.110Z,1583447735.110 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:40:23.223Z,1583448023.223 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:40:23.223Z,1583448023.223 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:40:23.224Z,1583448023.224 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:40:23.224Z,1583448023.224 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:40:23.593Z,1583448023.593 [Default:CheckIn:D] Stopped 2020-03-05T22:40:23.593Z,1583448023.593 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:40:23.998Z,1583448023.998 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.203540 min 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn:E] Stopped 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn] Stopped 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn](INFO): Running loop #24 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn] Running Loop=24 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:40:23.999Z,1583448023.999 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:40:26.019Z,1583448026.019 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224032.00,A,3648.17565,N,12147.28082,W,0.408,285.78,050320,,,A*79 2020-03-05T22:40:26.021Z,1583448026.021 [NAL9602](INFO): GPS fix at 20200305T224032: (36.802928, -121.788014) 2020-03-05T22:40:26.075Z,1583448026.075 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:40:26.075Z,1583448026.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:40:33.256Z,1583448033.256 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0054.lzma 2020-03-05T22:40:35.262Z,1583448035.262 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0054.lzma.bak 2020-03-05T22:40:35.263Z,1583448035.263 [DataOverHttps](INFO): SBD MOMSN=12298063 2020-03-05T22:40:54.777Z,1583448054.777 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200305T210333/Express0055.lzma 2020-03-05T22:40:56.783Z,1583448056.783 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0055.lzma.bak 2020-03-05T22:40:56.783Z,1583448056.783 [DataOverHttps](INFO): SBD MOMSN=12298066 2020-03-05T22:40:58.414Z,1583448058.414 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:40:58.414Z,1583448058.414 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:40:58.414Z,1583448058.414 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:42:46.235Z,1583448166.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=8034, MT Status=2, MTMSN=0 2020-03-05T22:42:46.236Z,1583448166.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T22:45:25.810Z,1583448325.810 [NAL9602](INFO): SBD MO Status=0, MOMSN=8034, MT Status=0, MTMSN=0 2020-03-05T22:45:25.810Z,1583448325.810 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:45:56.522Z,1583448356.522 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:45:59.023Z,1583448359.023 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:45:59.023Z,1583448359.023 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:45:59.023Z,1583448359.023 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:45:59.023Z,1583448359.023 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:45:59.370Z,1583448359.370 [Default:CheckIn:D] Stopped 2020-03-05T22:45:59.370Z,1583448359.370 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:45:59.780Z,1583448359.780 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.799821 min 2020-03-05T22:45:59.780Z,1583448359.780 [Default:CheckIn:E] Stopped 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn] Stopped 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn](INFO): Running loop #25 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn] Running Loop=25 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:45:59.781Z,1583448359.781 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:46:01.766Z,1583448361.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224608.00,A,3648.16667,N,12147.27820,W,0.175,166.66,050320,,,A*77 2020-03-05T22:46:01.769Z,1583448361.769 [NAL9602](INFO): GPS fix at 20200305T224608: (36.802778, -121.787970) 2020-03-05T22:46:01.824Z,1583448361.824 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:46:01.824Z,1583448361.824 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:46:11.780Z,1583448371.780 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0057.lzma 2020-03-05T22:46:13.786Z,1583448373.786 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0057.lzma.bak 2020-03-05T22:46:13.787Z,1583448373.787 [DataOverHttps](INFO): SBD MOMSN=12298091 2020-03-05T22:46:25.203Z,1583448385.203 [NAL9602](INFO): SBD MO Status=0, MOMSN=8035, MT Status=0, MTMSN=0 2020-03-05T22:46:25.203Z,1583448385.203 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:46:31.589Z,1583448391.589 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200305T210333/Express0058.lzma 2020-03-05T22:46:33.594Z,1583448393.594 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0058.lzma.bak 2020-03-05T22:46:33.595Z,1583448393.595 [DataOverHttps](INFO): SBD MOMSN=12298094 2020-03-05T22:46:34.935Z,1583448394.935 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:46:34.936Z,1583448394.936 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:46:34.936Z,1583448394.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:46:55.902Z,1583448415.902 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:47:01.625Z,1583448421.625 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2020-03-05T22:47:01.625Z,1583448421.625 [RDI_Pathfinder] Communications Fault, FailCount= 1 2020-03-05T22:47:01.625Z,1583448421.625 [RDI_Pathfinder](ERROR): Communications Fault 2020-03-05T22:47:01.648Z,1583448421.648 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2020-03-05T22:47:02.081Z,1583448422.081 [RDI_Pathfinder](INFO): Powering down 2020-03-05T22:47:02.808Z,1583448422.808 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2020-03-05T22:47:02.808Z,1583448422.808 [RDI_Pathfinder] No Fault, FailCount= 1 2020-03-05T22:51:35.504Z,1583448695.504 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:51:35.504Z,1583448695.504 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:51:35.504Z,1583448695.504 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:51:35.505Z,1583448695.505 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:51:35.918Z,1583448695.918 [Default:CheckIn:D] Stopped 2020-03-05T22:51:35.918Z,1583448695.918 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:51:36.313Z,1583448696.313 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.408952 min 2020-03-05T22:51:36.313Z,1583448696.313 [Default:CheckIn:E] Stopped 2020-03-05T22:51:36.313Z,1583448696.313 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn] Stopped 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn](INFO): Running loop #26 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn] Running Loop=26 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:51:36.314Z,1583448696.314 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:51:38.309Z,1583448698.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225145.00,A,3648.15868,N,12147.28364,W,0.194,166.66,050320,,,D*74 2020-03-05T22:51:38.311Z,1583448698.311 [NAL9602](INFO): GPS fix at 20200305T225145: (36.802645, -121.788061) 2020-03-05T22:51:38.339Z,1583448698.339 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:51:38.339Z,1583448698.339 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:51:46.016Z,1583448706.016 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0060.lzma 2020-03-05T22:51:48.023Z,1583448708.023 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0060.lzma.bak 2020-03-05T22:51:48.023Z,1583448708.023 [DataOverHttps](INFO): SBD MOMSN=12298099 2020-03-05T22:52:05.544Z,1583448725.544 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20200305T210333/Express0061.lzma 2020-03-05T22:52:07.548Z,1583448727.548 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0061.lzma.bak 2020-03-05T22:52:07.549Z,1583448727.549 [DataOverHttps](INFO): SBD MOMSN=12298102 2020-03-05T22:52:09.036Z,1583448729.036 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:52:09.036Z,1583448729.036 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:52:09.036Z,1583448729.036 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:52:10.652Z,1583448730.652 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-03-05T22:52:10.658Z,1583448730.658 [BPC1](INFO): Received data from all battery sticks. 2020-03-05T22:52:28.021Z,1583448748.021 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-03-05T22:52:30.430Z,1583448750.430 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T22:53:20.111Z,1583448800.111 [NAL9602](INFO): SBD MO Status=2, MOMSN=8036, MT Status=2, MTMSN=0 2020-03-05T22:53:20.111Z,1583448800.111 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T22:55:21.311Z,1583448921.311 [NAL9602](INFO): SBD MO Status=0, MOMSN=8036, MT Status=0, MTMSN=0 2020-03-05T22:55:21.312Z,1583448921.312 [NAL9602](INFO): No messages in MT queue 2020-03-05T22:55:52.008Z,1583448952.008 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T22:56:27.511Z,1583448987.511 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T22:56:27.658Z,1583448987.658 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T22:56:38.516Z,1583448998.516 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032462 CHAN A1 (24V): 0.035483 CHAN A2 (12V): -0.008038 CHAN A3 (5V): -0.002415 CHAN B0 (3.3V): 0.000160 CHAN B1 (3.15aV): 0.000275 CHAN B2 (3.15bV): -0.000301 CHAN B3 (GND): 0.002347 OPEN: 0.005246 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T22:56:48.489Z,1583449008.489 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T22:57:05.973Z,1583449025.973 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T22:57:09.638Z,1583449029.638 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T22:57:09.638Z,1583449029.638 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:57:09.638Z,1583449029.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:57:09.638Z,1583449029.638 [Default:CheckIn:D] Running Loop=1 2020-03-05T22:57:10.012Z,1583449030.012 [Default:CheckIn:D] Stopped 2020-03-05T22:57:10.012Z,1583449030.012 [Default:CheckIn:E] Running Loop=1 2020-03-05T22:57:10.424Z,1583449030.424 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.977181 min 2020-03-05T22:57:10.424Z,1583449030.424 [Default:CheckIn:E] Stopped 2020-03-05T22:57:10.424Z,1583449030.424 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T22:57:10.424Z,1583449030.424 [Default:CheckIn] Stopped 2020-03-05T22:57:10.425Z,1583449030.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:57:10.425Z,1583449030.425 [Default:CheckIn](INFO): Running loop #27 2020-03-05T22:57:10.425Z,1583449030.425 [Default:CheckIn] Running Loop=27 2020-03-05T22:57:10.425Z,1583449030.425 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T22:57:10.425Z,1583449030.425 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T22:57:12.410Z,1583449032.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225719.00,A,3648.16251,N,12147.28422,W,0.117,302.80,050320,,,D*7E 2020-03-05T22:57:12.412Z,1583449032.412 [NAL9602](INFO): GPS fix at 20200305T225719: (36.802709, -121.788070) 2020-03-05T22:57:12.459Z,1583449032.459 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T22:57:12.459Z,1583449032.459 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T22:57:19.732Z,1583449039.732 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T22:57:19.743Z,1583449039.743 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T22:57:20.088Z,1583449040.088 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20200305T210333/Courier0063.lzma 2020-03-05T22:57:22.094Z,1583449042.094 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0063.lzma.bak 2020-03-05T22:57:22.095Z,1583449042.095 [DataOverHttps](INFO): SBD MOMSN=12298124 2020-03-05T22:57:30.672Z,1583449050.672 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032712 CHAN A1 (24V): 0.035804 CHAN A2 (12V): -0.008169 CHAN A3 (5V): -0.002059 CHAN B0 (3.3V): -0.000207 CHAN B1 (3.15aV): -0.000054 CHAN B2 (3.15bV): 0.000528 CHAN B3 (GND): 0.001986 OPEN: 0.005426 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T22:57:39.425Z,1583449059.425 [DataOverHttps](INFO): Sending 403 bytes from file Logs/20200305T210333/Express0064.lzma 2020-03-05T22:57:41.431Z,1583449061.431 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0064.lzma.bak 2020-03-05T22:57:41.431Z,1583449061.431 [DataOverHttps](INFO): SBD MOMSN=12298128 2020-03-05T22:57:42.754Z,1583449062.754 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T22:57:42.754Z,1583449062.754 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T22:57:42.754Z,1583449062.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T22:57:57.209Z,1583449077.209 [CommandLine](IMPORTANT): got command configSet WetLabsUBAT.loadAtStartup 1.000000 bool persist 2020-03-05T22:57:57.209Z,1583449077.209 [CommandLine](IMPORTANT): configSet WetLabsUBAT.loadAtStartup requires a restart to take effect. 2020-03-05T22:58:08.422Z,1583449088.422 [CommandLine](IMPORTANT): got command run ./Missions/Insert/Science.xml 2020-03-05T22:58:08.423Z,1583449088.423 [MissionManager](INFO): Loading Mission: ./Missions/Insert/Science.xml 2020-03-05T22:58:08.726Z,1583449088.726 [MissionManager](INFO): DefineArg Science.SampleISUS = 0 bool 2020-03-05T22:58:08.729Z,1583449088.729 [MissionManager](INFO): DefineArg Science.SampleISUSmaxPitch = 60.000000 arcdeg 2020-03-05T22:58:08.733Z,1583449088.733 [MissionManager](INFO): DefineArg Science.SampleISUSminPitch = -60.000000 arcdeg 2020-03-05T22:58:08.737Z,1583449088.737 [MissionManager](INFO): DefineArg Science.PeakDetectChlActive = 0 bool 2020-03-05T22:58:08.740Z,1583449088.740 [MissionManager](INFO): DefineArg Science.TimeWindowPeakReport = nan min 2020-03-05T22:58:08.744Z,1583449088.744 [MissionManager](INFO): DefineArg Science.HighestChlPeakReportActive = 0 bool 2020-03-05T22:58:08.770Z,1583449088.770 [MissionManager](INFO): DefineArg Science.PatchTracking = 0 bool 2020-03-05T22:58:08.786Z,1583449088.786 [MissionManager](INFO): DefineArg Science.FilterWidthHorizontal = 3.000000 count 2020-03-05T22:58:08.801Z,1583449088.801 [MissionManager](INFO): DefineArg Science.NumProfilesSlidingwindow = 100.000000 count 2020-03-05T22:58:08.809Z,1583449088.809 [MissionManager](INFO): DefineArg Science.OffPeakFractionHorizontal = 80.000000 % 2020-03-05T22:58:08.837Z,1583449088.837 [MissionManager](INFO): DefineArg Science.PeakDetectNO3Active = 0 bool 2020-03-05T22:58:08.840Z,1583449088.840 [MissionManager](INFO): DefineArg Science.PeakDetectOilActive = 0 bool 2020-03-05T22:58:08.857Z,1583449088.857 [MissionManager](INFO): DefineArg Science.PeakDetectFDOMActive = 0 bool 2020-03-05T22:58:08.865Z,1583449088.865 [MissionManager](INFO): DefineArg Science.UpwardDerivativeOfTemperatureActive = 0 bool 2020-03-05T22:58:08.880Z,1583449088.880 [MissionManager](INFO): DefineArg Science.EnabledAanderaaO2 = 0.000000 bool 2020-03-05T22:58:08.900Z,1583449088.900 [MissionManager](INFO): DefineArg Science.EnabledNeilBrown = 0.000000 bool 2020-03-05T22:58:08.913Z,1583449088.913 [MissionManager](INFO): DefineArg Science.EnabledSeabird = 1.000000 bool 2020-03-05T22:58:08.926Z,1583449088.926 [MissionManager](INFO): DefineArg Science.EnabledTurbulence_NPS = 0.000000 bool 2020-03-05T22:58:08.938Z,1583449088.938 [MissionManager](INFO): DefineArg Science.EnabledWetLabsBB2FL = 1.000000 bool 2020-03-05T22:58:08.951Z,1583449088.951 [MissionManager](INFO): DefineArg Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool 2020-03-05T22:58:08.988Z,1583449088.988 [MissionManager](INFO): DefineArg Science.EnabledWetLabsUBAT = 1.000000 bool 2020-03-05T22:58:09.012Z,1583449089.012 [MissionManager](INFO): DefineArg Science.EnabledISUS = 0.000000 bool 2020-03-05T22:58:09.036Z,1583449089.036 [MissionManager](INFO): DefineArg Science.LowPassWindowLength = 20.000000 count 2020-03-05T22:58:09.048Z,1583449089.048 [MissionManager](INFO): DefineArg Science.MedianFilterLen = 5.000000 count 2020-03-05T22:58:09.068Z,1583449089.068 [MissionManager](INFO): DefineArg Science.PeakChlShallowBound = nan m 2020-03-05T22:58:09.092Z,1583449089.092 [MissionManager](INFO): DefineArg Science.PeakChlDeepBound = nan m 2020-03-05T22:58:09.099Z,1583449089.099 [MissionManager](INFO): DefineArg Science.PeakShallowBound = nan m 2020-03-05T22:58:09.115Z,1583449089.115 [MissionManager](INFO): DefineArg Science.PeakDeepBound = nan m 2020-03-05T22:58:09.120Z,1583449089.120 [MissionManager](INFO): DefineOutput Science.PeakChl = 0.000000 ug/l 2020-03-05T22:58:09.140Z,1583449089.140 [MissionManager](INFO): DefineOutput Science.PeakChlDepth = 0.000000 m 2020-03-05T22:58:09.144Z,1583449089.144 [MissionManager](INFO): DefineOutput Science.PeakChlTemperature = 0.000000 degC 2020-03-05T22:58:09.147Z,1583449089.147 [MissionManager](INFO): DefineOutput Science.PeakChlLatitude = nan arcdeg 2020-03-05T22:58:09.179Z,1583449089.179 [MissionManager](INFO): DefineOutput Science.PeakChlLongitude = nan arcdeg 2020-03-05T22:58:09.183Z,1583449089.183 [MissionManager](INFO): DefineOutput Science.PeakNO3 = 0.000000 umol/l 2020-03-05T22:58:09.187Z,1583449089.187 [MissionManager](INFO): DefineOutput Science.PeakNO3Depth = 0.000000 m 2020-03-05T22:58:09.214Z,1583449089.214 [MissionManager](INFO): DefineOutput Science.PeakNO3Latitude = nan arcdeg 2020-03-05T22:58:09.218Z,1583449089.218 [MissionManager](INFO): DefineOutput Science.PeakNO3Longitude = nan arcdeg 2020-03-05T22:58:09.236Z,1583449089.236 [MissionManager](INFO): DefineOutput Science.PatchChl = 0.000000 m 2020-03-05T22:58:09.240Z,1583449089.240 [MissionManager](INFO): DefineOutput Science.PatchChlDepth = 0.000000 m 2020-03-05T22:58:09.243Z,1583449089.243 [MissionManager](INFO): DefineOutput Science.PatchChlLatitude = nan arcdeg 2020-03-05T22:58:09.287Z,1583449089.287 [MissionManager](INFO): DefineOutput Science.PatchChlLongitude = nan arcdeg 2020-03-05T22:58:09.290Z,1583449089.290 [MissionManager](INFO): DefineOutput Science.PatchChlDistance = nan m 2020-03-05T22:58:09.307Z,1583449089.307 [MissionManager](INFO): DefineOutput Science.PeakOil = 0.000000 kg/m3 2020-03-05T22:58:09.311Z,1583449089.311 [MissionManager](INFO): DefineOutput Science.PeakOilDepth = 0.000000 m 2020-03-05T22:58:09.314Z,1583449089.314 [MissionManager](INFO): DefineOutput Science.PeakOilLatitude = nan arcdeg 2020-03-05T22:58:09.326Z,1583449089.326 [MissionManager](INFO): DefineOutput Science.PeakOilLongitude = nan arcdeg 2020-03-05T22:58:09.330Z,1583449089.330 [MissionManager](INFO): DefineOutput Science.PeakFDOM = 0.000000 ppb 2020-03-05T22:58:09.334Z,1583449089.334 [MissionManager](INFO): DefineOutput Science.PeakFDOMDepth = 0.000000 m 2020-03-05T22:58:09.417Z,1583449089.417 [MissionManager](INFO): DefineOutput Science.PeakFDOMLatitude = nan arcdeg 2020-03-05T22:58:09.433Z,1583449089.433 [MissionManager](INFO): DefineOutput Science.PeakFDOMLongitude = nan arcdeg 2020-03-05T22:58:09.449Z,1583449089.449 [MissionManager](INFO): DefineOutput Science.PatchFDOMDistance = nan m 2020-03-05T22:58:09.498Z,1583449089.498 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2020-03-05T22:58:09.527Z,1583449089.527 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2020-03-05T22:58:09.598Z,1583449089.598 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2020-03-05T22:58:09.631Z,1583449089.631 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2020-03-05T22:58:09.671Z,1583449089.671 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2020-03-05T22:58:09.786Z,1583449089.786 [MissionManager](DEBUG): Set either this or PeakDetectNO3Active to True in order to sample Nitrate. EnabledISUS must also be true. Maximum pitch to sample ISUS. (EnabledISUS must also be true.) 60.0 Minimum pitch to sample ISUS. (EnabledISUS must also be true.) -60.0 Turns on peak detection of Cholorphyll. If greater than zero, report a peak every window. If NaN or zero, this variable is ignored. NaN Turns on reporting of the highest peak value on yo-yo profiles in a horizontal sliding window (of length numProfilesSlidingwindow) If tracking a patch Width of boxcar filter applied to yoyo-wise chl peaks to pick out the highest peak. 3 Length of horizontal sliding window. The highest yoyo-wise chl peak (after low-pass filtering by a filter of length FilterWidthHorizontal) within this window. 100 When filtered horizontal value is this fraction of the peak, consider it outside the patch. 80 Turns on peak detection of Nitrate (and turns on ISUS). Turns on peak detection of Dissolved Oil. Turns on peak detection of concentration_of_chromophoric_dissolved_organic_matter_in_sea_water from FDOM sensor. Turns on seawater temperature derivative. Automatically set to True if the Aanderaa O2 sensor is installed. Set to false to disable reading Aandera O2. Automatically set to true if the Neil Brown CTD is enabled. Set to false to disable reading from the Neil Brown. Automatically set to true if the CTD is enabled. Set to false to disable reading from the CTD. Automatically set to true if the NPS Turbulence sensor is enabled. Set to false to disable reading from the NPS Turbulence sensor. Automatically set to true if the the WetLabs BB2FL is enabled. Set to false to disable the WetLabs BB2FL. Automatically set to true if the the WetLabs SeaOWL UV-A is enabled. Set to false to disable the WetLabs SeaOWL UV-A. Automatically set to true if the the WetLabs UBAT is enabled. Set to false to disable the WetLabs UBAT. Automatically set to True if ISUS is enabled. Set to false to disable ISUS. Low-pass window length (based on depth sensor sampling interval 0.4 second) for low-pass filtering. 20 Median filter length (only for chlorophyll fluorescence which tends to have spikes) 5 Shallow depth bound for detecting chl peak on each descent or ascent profile. NaN Deep depth bound for detecting chl peak on each descent or ascent profile. NaN Shallow depth bound for detecting any peak on each descent or ascent profile. NaN Deep depth bound for detecting any peak on each descent or ascent profile. NaN 0 0 0 NaN NaN 0 0 NaN NaN 0 0 NaN NaN NaN 0 0 NaN NaN 0 0 NaN NaN NaN 2020-03-05T22:58:09.788Z,1583449089.788 [CommandLine](IMPORTANT): Running ./Missions/Insert/Science.xml 2020-03-05T22:58:09.852Z,1583449089.852 [Default] Stopped 2020-03-05T22:58:09.852Z,1583449089.852 [Default](DEBUG): Aggregate::uninitialize Default 2020-03-05T22:58:09.852Z,1583449089.852 [Default:B.GoToSurface] Stopped 2020-03-05T22:58:09.853Z,1583449089.853 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-03-05T22:58:09.853Z,1583449089.853 [Default:CheckIn] Stopped 2020-03-05T22:58:09.853Z,1583449089.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T22:58:09.853Z,1583449089.853 [Default:CheckIn:C.Wait] Stopped 2020-03-05T22:58:09.853Z,1583449089.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T22:58:09.853Z,1583449089.853 [MissionManager](IMPORTANT): Started mission Science 2020-03-05T22:58:09.853Z,1583449089.853 [Science] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science](DEBUG): Aggregate::initialize Science 2020-03-05T22:58:09.854Z,1583449089.854 [Science:A] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:B] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:C] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:D] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:E] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:F] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:G] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:H] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:Read_Oil] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:PeakDetectChl] Running Loop=1 2020-03-05T22:58:09.854Z,1583449089.854 [Science:PeakDetectChl](DEBUG): Aggregate::initialize Science:PeakDetectChl 2020-03-05T22:58:09.855Z,1583449089.855 [Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2020-03-05T22:58:09.855Z,1583449089.855 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2020-03-05T22:58:09.856Z,1583449089.856 [Science:HighestChlPeakReport] Running Loop=1 2020-03-05T22:58:09.856Z,1583449089.856 [Science:HighestChlPeakReport](DEBUG): Aggregate::initialize Science:HighestChlPeakReport 2020-03-05T22:58:09.856Z,1583449089.856 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2020-03-05T22:58:09.856Z,1583449089.856 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2020-03-05T22:58:09.861Z,1583449089.861 [Science:PeakDetectNO3] Running Loop=1 2020-03-05T22:58:09.861Z,1583449089.861 [Science:PeakDetectNO3](DEBUG): Aggregate::initialize Science:PeakDetectNO3 2020-03-05T22:58:09.861Z,1583449089.861 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2020-03-05T22:58:09.861Z,1583449089.861 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2020-03-05T22:58:09.863Z,1583449089.863 [Science:PeakDetectOil] Running Loop=1 2020-03-05T22:58:09.863Z,1583449089.863 [Science:PeakDetectOil](DEBUG): Aggregate::initialize Science:PeakDetectOil 2020-03-05T22:58:09.863Z,1583449089.863 [Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2020-03-05T22:58:09.863Z,1583449089.863 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2020-03-05T22:58:09.869Z,1583449089.869 [Science:PeakDetectFDOM] Running Loop=1 2020-03-05T22:58:09.869Z,1583449089.869 [Science:PeakDetectFDOM](DEBUG): Aggregate::initialize Science:PeakDetectFDOM 2020-03-05T22:58:09.869Z,1583449089.869 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2020-03-05T22:58:09.869Z,1583449089.869 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectFDOM] Stopped 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize Science:PeakDetectFDOM 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectOil] Stopped 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectOil](DEBUG): Aggregate::uninitialize Science:PeakDetectOil 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2020-03-05T22:58:09.872Z,1583449089.872 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2020-03-05T22:58:09.885Z,1583449089.885 [Science:PeakDetectNO3] Stopped 2020-03-05T22:58:09.885Z,1583449089.885 [Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize Science:PeakDetectNO3 2020-03-05T22:58:09.885Z,1583449089.885 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2020-03-05T22:58:09.885Z,1583449089.885 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2020-03-05T22:58:09.885Z,1583449089.885 [Science:HighestChlPeakReport] Stopped 2020-03-05T22:58:09.885Z,1583449089.885 [Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize Science:HighestChlPeakReport 2020-03-05T22:58:09.885Z,1583449089.885 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2020-03-05T22:58:09.885Z,1583449089.885 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2020-03-05T22:58:09.885Z,1583449089.885 [Science:PeakDetectChl] Stopped 2020-03-05T22:58:09.886Z,1583449089.886 [Science:PeakDetectChl](DEBUG): Aggregate::uninitialize Science:PeakDetectChl 2020-03-05T22:58:09.886Z,1583449089.886 [Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2020-03-05T22:58:09.886Z,1583449089.886 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2020-03-05T22:58:09.886Z,1583449089.886 [Science:Read_Oil] Stopped 2020-03-05T22:58:09.886Z,1583449089.886 [Science:H] Running Loop=1 2020-03-05T22:58:09.887Z,1583449089.887 [Science:H](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.biolum_potential 2020-03-05T22:58:09.887Z,1583449089.887 [Science:G] Running Loop=1 2020-03-05T22:58:09.887Z,1583449089.887 [Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2020-03-05T22:58:09.887Z,1583449089.887 [Science:F] Stopped 2020-03-05T22:58:09.887Z,1583449089.887 [Science:E] Stopped 2020-03-05T22:58:09.888Z,1583449089.888 [Science:D] Running Loop=1 2020-03-05T22:58:09.888Z,1583449089.888 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2020-03-05T22:58:09.893Z,1583449089.893 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2020-03-05T22:58:09.893Z,1583449089.893 [Science:C] Running Loop=1 2020-03-05T22:58:09.894Z,1583449089.894 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2020-03-05T22:58:09.895Z,1583449089.895 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2020-03-05T22:58:09.895Z,1583449089.895 [Science:B] Stopped 2020-03-05T22:58:09.895Z,1583449089.895 [Science:A] Stopped 2020-03-05T22:58:10.022Z,1583449090.022 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2 2020-03-05T22:58:10.022Z,1583449090.022 [WetLabsBB2FL](INFO): Powering up 2020-03-05T22:58:10.274Z,1583449090.274 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2020-03-05T22:58:10.369Z,1583449090.369 [WetLabsUBAT](INFO): Initializing 2020-03-05T22:58:10.371Z,1583449090.371 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest 2020-03-05T22:58:10.371Z,1583449090.371 [WetLabsUBAT](INFO): Powering up 2020-03-05T22:58:10.371Z,1583449090.371 [WetLabsUBAT](INFO): Checking LCM 2020-03-05T22:58:10.371Z,1583449090.371 [WetLabsUBAT](INFO): LCM OK 2020-03-05T22:58:10.466Z,1583449090.466 [WetLabsUBAT](INFO): setup() - setLineFormat() 2020-03-05T22:58:13.286Z,1583449093.286 [CTD_Seabird](ERROR): Failed to parse device response: 2020-03-05T22:58:15.297Z,1583449095.297 [CTD_Seabird](ERROR): Salinity reading out of range: 0.542834 psu 2020-03-05T22:58:16.299Z,1583449096.299 [CTD_Seabird](ERROR): Salinity reading out of range: 0.528730 psu 2020-03-05T22:58:17.303Z,1583449097.303 [CTD_Seabird](ERROR): Salinity reading out of range: 0.537147 psu 2020-03-05T22:58:18.307Z,1583449098.307 [CTD_Seabird](ERROR): Salinity reading out of range: 0.526565 psu 2020-03-05T22:58:19.311Z,1583449099.311 [CTD_Seabird](ERROR): Salinity reading out of range: 0.532272 psu 2020-03-05T22:58:20.315Z,1583449100.315 [CTD_Seabird](ERROR): Salinity reading out of range: 0.525097 psu 2020-03-05T22:58:20.751Z,1583449100.751 [WetLabsUBAT](INFO): Got instrument prompt 2020-03-05T22:58:21.319Z,1583449101.319 [CTD_Seabird](ERROR): Salinity reading out of range: 0.508437 psu 2020-03-05T22:58:22.324Z,1583449102.324 [CTD_Seabird](ERROR): Salinity reading out of range: 0.516298 psu 2020-03-05T22:58:22.887Z,1583449102.887 [WetLabsUBAT](INFO): Got instrument prompt 2020-03-05T22:58:23.327Z,1583449103.327 [CTD_Seabird](ERROR): Salinity reading out of range: 0.509490 psu 2020-03-05T22:58:23.953Z,1583449103.953 [WetLabsUBAT..StreamSerialDriver](INFO): device metadata: Override SerialDriver::getDeviceMetadata() 2020-03-05T22:58:24.331Z,1583449104.331 [CTD_Seabird](ERROR): Salinity reading out of range: 0.514400 psu 2020-03-05T22:58:25.335Z,1583449105.335 [CTD_Seabird](ERROR): Salinity reading out of range: 0.506318 psu 2020-03-05T22:58:26.339Z,1583449106.339 [CTD_Seabird](ERROR): Salinity reading out of range: 0.495057 psu 2020-03-05T22:58:27.343Z,1583449107.343 [CTD_Seabird](ERROR): Salinity reading out of range: 0.531456 psu 2020-03-05T22:58:28.355Z,1583449108.355 [CTD_Seabird](ERROR): Salinity reading out of range: 0.525467 psu 2020-03-05T22:58:29.359Z,1583449109.359 [CTD_Seabird](ERROR): Salinity reading out of range: 0.511944 psu 2020-03-05T22:58:30.364Z,1583449110.364 [CTD_Seabird](ERROR): Salinity reading out of range: 0.497240 psu 2020-03-05T22:58:31.367Z,1583449111.367 [CTD_Seabird](ERROR): Salinity reading out of range: 0.502477 psu 2020-03-05T22:58:32.371Z,1583449112.371 [CTD_Seabird](ERROR): Salinity reading out of range: 0.509791 psu 2020-03-05T22:58:33.375Z,1583449113.375 [CTD_Seabird](ERROR): Salinity reading out of range: 0.522206 psu 2020-03-05T22:58:34.379Z,1583449114.379 [CTD_Seabird](ERROR): Salinity reading out of range: 0.517775 psu 2020-03-05T22:58:35.383Z,1583449115.383 [CTD_Seabird](ERROR): Salinity reading out of range: 0.503780 psu 2020-03-05T22:58:36.388Z,1583449116.388 [CTD_Seabird](ERROR): Salinity reading out of range: 0.497480 psu 2020-03-05T22:58:37.392Z,1583449117.392 [CTD_Seabird](ERROR): Salinity reading out of range: 0.498617 psu 2020-03-05T22:58:38.395Z,1583449118.395 [CTD_Seabird](ERROR): Salinity reading out of range: 0.514227 psu 2020-03-05T22:58:39.400Z,1583449119.400 [CTD_Seabird](ERROR): Salinity reading out of range: 0.525436 psu 2020-03-05T22:58:40.403Z,1583449120.403 [CTD_Seabird](ERROR): Salinity reading out of range: 0.521419 psu 2020-03-05T22:58:41.407Z,1583449121.407 [CTD_Seabird](ERROR): Salinity reading out of range: 0.505292 psu 2020-03-05T22:58:42.411Z,1583449122.411 [CTD_Seabird](ERROR): Salinity reading out of range: 0.503040 psu 2020-03-05T22:58:43.415Z,1583449123.415 [CTD_Seabird](ERROR): Salinity reading out of range: 0.502854 psu 2020-03-05T22:58:44.419Z,1583449124.419 [CTD_Seabird](ERROR): Salinity reading out of range: 0.487363 psu 2020-03-05T22:58:45.425Z,1583449125.425 [CTD_Seabird](ERROR): Salinity reading out of range: 0.488885 psu 2020-03-05T22:58:46.427Z,1583449126.427 [CTD_Seabird](ERROR): Salinity reading out of range: 0.485128 psu 2020-03-05T22:58:46.610Z,1583449126.610 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-03-05T22:58:47.431Z,1583449127.431 [CTD_Seabird](ERROR): Salinity reading out of range: 0.495935 psu 2020-03-05T22:58:48.435Z,1583449128.435 [CTD_Seabird](ERROR): Salinity reading out of range: 0.486075 psu 2020-03-05T22:58:48.512Z,1583449128.512 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T22:58:48.678Z,1583449128.678 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T22:58:49.443Z,1583449129.443 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:50.442Z,1583449130.442 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:51.447Z,1583449131.447 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:52.451Z,1583449132.451 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:53.455Z,1583449133.455 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:54.458Z,1583449134.458 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:55.463Z,1583449135.463 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:56.466Z,1583449136.466 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:57.471Z,1583449137.471 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:58.475Z,1583449138.475 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:59.480Z,1583449139.480 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:58:59.619Z,1583449139.619 [CBIT](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.361340 CHAN A1 (24V): 0.692046 CHAN A2 (12V): 0.286081 CHAN A3 (5V): 0.067565 CHAN B0 (3.3V): 0.065952 CHAN B1 (3.15aV): 0.037980 CHAN B2 (3.15bV): 0.072681 CHAN B3 (GND): -0.062157 OPEN: 0.009182 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T22:59:00.483Z,1583449140.483 [CTD_Seabird](ERROR): Salinity reading out of range: 0.466847 psu 2020-03-05T22:59:01.487Z,1583449141.487 [CTD_Seabird](ERROR): Salinity reading out of range: 0.468344 psu 2020-03-05T22:59:02.491Z,1583449142.491 [CTD_Seabird](ERROR): Salinity reading out of range: 0.467137 psu 2020-03-05T22:59:03.495Z,1583449143.495 [CTD_Seabird](ERROR): Salinity reading out of range: 0.469781 psu 2020-03-05T22:59:03.940Z,1583449143.940 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T22:59:04.499Z,1583449144.499 [CTD_Seabird](ERROR): Salinity reading out of range: 0.474293 psu 2020-03-05T22:59:05.503Z,1583449145.503 [CTD_Seabird](ERROR): Salinity reading out of range: 0.468682 psu 2020-03-05T22:59:06.511Z,1583449146.511 [CTD_Seabird](ERROR): Salinity reading out of range: 0.463680 psu 2020-03-05T22:59:07.511Z,1583449147.511 [CTD_Seabird](ERROR): Salinity reading out of range: 0.453262 psu 2020-03-05T22:59:08.518Z,1583449148.518 [CTD_Seabird](ERROR): Salinity reading out of range: 0.457835 psu 2020-03-05T22:59:09.519Z,1583449149.519 [CTD_Seabird](ERROR): Salinity reading out of range: 0.464629 psu 2020-03-05T22:59:10.523Z,1583449150.523 [CTD_Seabird](ERROR): Salinity reading out of range: 0.473903 psu 2020-03-05T22:59:11.527Z,1583449151.527 [CTD_Seabird](ERROR): Salinity reading out of range: 0.487345 psu 2020-03-05T22:59:12.531Z,1583449152.531 [CTD_Seabird](ERROR): Salinity reading out of range: 0.473882 psu 2020-03-05T22:59:13.535Z,1583449153.535 [CTD_Seabird](ERROR): Salinity reading out of range: 0.470919 psu 2020-03-05T22:59:14.543Z,1583449154.543 [CTD_Seabird](ERROR): Salinity reading out of range: 0.471493 psu 2020-03-05T22:59:15.544Z,1583449155.544 [CTD_Seabird](ERROR): Salinity reading out of range: 0.460900 psu 2020-03-05T22:59:16.547Z,1583449156.547 [CTD_Seabird](ERROR): Salinity reading out of range: 0.456681 psu 2020-03-05T22:59:17.551Z,1583449157.551 [CTD_Seabird](ERROR): Salinity reading out of range: 0.451091 psu 2020-03-05T22:59:18.556Z,1583449158.556 [CTD_Seabird](ERROR): Salinity reading out of range: 0.457214 psu 2020-03-05T22:59:19.564Z,1583449159.564 [CTD_Seabird](ERROR): Salinity reading out of range: 0.447580 psu 2020-03-05T22:59:20.566Z,1583449160.566 [CTD_Seabird](ERROR): Salinity reading out of range: 0.447222 psu 2020-03-05T22:59:21.571Z,1583449161.571 [CTD_Seabird](ERROR): Salinity reading out of range: 0.455395 psu 2020-03-05T22:59:21.738Z,1583449161.738 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T22:59:22.577Z,1583449162.577 [CTD_Seabird](ERROR): Salinity reading out of range: 0.460856 psu 2020-03-05T22:59:23.579Z,1583449163.579 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459295 psu 2020-03-05T22:59:24.178Z,1583449164.178 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T22:59:24.588Z,1583449164.588 [CTD_Seabird](ERROR): Salinity reading out of range: 0.451527 psu 2020-03-05T22:59:24.611Z,1583449164.611 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T22:59:25.586Z,1583449165.586 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:25.894Z,1583449165.894 [WetLabsUBAT](ERROR): Invalid data record: got 67 tokens 2020-03-05T22:59:26.591Z,1583449166.591 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:27.595Z,1583449167.595 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:28.598Z,1583449168.598 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:29.599Z,1583449169.599 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:30.603Z,1583449170.603 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:30.635Z,1583449170.635 [NAL9602](INFO): SBD MO Status=2, MOMSN=8037, MT Status=2, MTMSN=0 2020-03-05T22:59:30.635Z,1583449170.635 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T22:59:30.897Z,1583449170.897 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:30.897Z,1583449170.897 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:30.897Z,1583449170.897 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:30.898Z,1583449170.898 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:31.607Z,1583449171.607 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:32.649Z,1583449172.649 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:33.649Z,1583449173.649 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:34.655Z,1583449174.655 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T22:59:35.500Z,1583449175.500 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.033171 CHAN A1 (24V): 0.036054 CHAN A2 (12V): -0.007477 CHAN A3 (5V): -0.002337 CHAN B0 (3.3V): -0.000322 CHAN B1 (3.15aV): -0.000467 CHAN B2 (3.15bV): -0.000290 CHAN B3 (GND): 0.002157 OPEN: 0.005008 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T22:59:35.650Z,1583449175.650 [CTD_Seabird](ERROR): Salinity reading out of range: 0.471111 psu 2020-03-05T22:59:35.900Z,1583449175.900 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:35.900Z,1583449175.900 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:35.900Z,1583449175.900 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:35.901Z,1583449175.901 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:36.650Z,1583449176.650 [CTD_Seabird](ERROR): Salinity reading out of range: 0.465497 psu 2020-03-05T22:59:37.655Z,1583449177.655 [CTD_Seabird](ERROR): Salinity reading out of range: 0.466567 psu 2020-03-05T22:59:38.658Z,1583449178.658 [CTD_Seabird](ERROR): Salinity reading out of range: 0.460848 psu 2020-03-05T22:59:39.654Z,1583449179.654 [CTD_Seabird](ERROR): Salinity reading out of range: 0.458910 psu 2020-03-05T22:59:40.654Z,1583449180.654 [CTD_Seabird](ERROR): Salinity reading out of range: 0.461915 psu 2020-03-05T22:59:40.903Z,1583449180.903 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:40.903Z,1583449180.903 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:40.903Z,1583449180.903 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:40.904Z,1583449180.904 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:41.648Z,1583449181.648 [CTD_Seabird](ERROR): Salinity reading out of range: 0.464857 psu 2020-03-05T22:59:42.651Z,1583449182.651 [CTD_Seabird](ERROR): Salinity reading out of range: 0.461841 psu 2020-03-05T22:59:43.655Z,1583449183.655 [CTD_Seabird](ERROR): Salinity reading out of range: 0.475259 psu 2020-03-05T22:59:44.659Z,1583449184.659 [CTD_Seabird](ERROR): Salinity reading out of range: 0.475138 psu 2020-03-05T22:59:45.663Z,1583449185.663 [CTD_Seabird](ERROR): Salinity reading out of range: 0.486045 psu 2020-03-05T22:59:45.906Z,1583449185.906 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:45.906Z,1583449185.906 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:45.906Z,1583449185.906 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:45.906Z,1583449185.906 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:46.667Z,1583449186.667 [CTD_Seabird](ERROR): Salinity reading out of range: 0.478865 psu 2020-03-05T22:59:47.671Z,1583449187.671 [CTD_Seabird](ERROR): Salinity reading out of range: 0.469524 psu 2020-03-05T22:59:48.675Z,1583449188.675 [CTD_Seabird](ERROR): Salinity reading out of range: 0.460666 psu 2020-03-05T22:59:49.679Z,1583449189.679 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459517 psu 2020-03-05T22:59:50.683Z,1583449190.683 [CTD_Seabird](ERROR): Salinity reading out of range: 0.468057 psu 2020-03-05T22:59:50.909Z,1583449190.909 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:50.909Z,1583449190.909 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:50.909Z,1583449190.909 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:50.910Z,1583449190.910 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:51.687Z,1583449191.687 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459448 psu 2020-03-05T22:59:52.691Z,1583449192.691 [CTD_Seabird](ERROR): Salinity reading out of range: 0.454630 psu 2020-03-05T22:59:53.695Z,1583449193.695 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459433 psu 2020-03-05T22:59:54.700Z,1583449194.700 [CTD_Seabird](ERROR): Salinity reading out of range: 0.446749 psu 2020-03-05T22:59:55.703Z,1583449195.703 [CTD_Seabird](ERROR): Salinity reading out of range: 0.444342 psu 2020-03-05T22:59:55.912Z,1583449195.912 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T22:59:55.912Z,1583449195.912 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T22:59:55.912Z,1583449195.912 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T22:59:55.913Z,1583449195.913 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T22:59:56.707Z,1583449196.707 [CTD_Seabird](ERROR): Salinity reading out of range: 0.437739 psu 2020-03-05T22:59:57.711Z,1583449197.711 [CTD_Seabird](ERROR): Salinity reading out of range: 0.438038 psu 2020-03-05T22:59:58.715Z,1583449198.715 [CTD_Seabird](ERROR): Salinity reading out of range: 0.444452 psu 2020-03-05T22:59:59.719Z,1583449199.719 [CTD_Seabird](ERROR): Salinity reading out of range: 0.440903 psu 2020-03-05T23:00:00.723Z,1583449200.723 [CTD_Seabird](ERROR): Salinity reading out of range: 0.437414 psu 2020-03-05T23:00:00.915Z,1583449200.915 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T23:00:00.915Z,1583449200.915 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T23:00:00.915Z,1583449200.915 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T23:00:00.916Z,1583449200.916 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T23:00:01.727Z,1583449201.727 [CTD_Seabird](ERROR): Salinity reading out of range: 0.443291 psu 2020-03-05T23:00:02.731Z,1583449202.731 [CTD_Seabird](ERROR): Salinity reading out of range: 0.479187 psu 2020-03-05T23:00:03.736Z,1583449203.736 [CTD_Seabird](ERROR): Salinity reading out of range: 0.472262 psu 2020-03-05T23:00:04.739Z,1583449204.739 [CTD_Seabird](ERROR): Salinity reading out of range: 0.463404 psu 2020-03-05T23:00:05.749Z,1583449205.749 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459193 psu 2020-03-05T23:00:05.918Z,1583449205.918 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T23:00:05.918Z,1583449205.918 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T23:00:05.918Z,1583449205.918 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T23:00:05.919Z,1583449205.919 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T23:00:06.751Z,1583449206.751 [CTD_Seabird](ERROR): Salinity reading out of range: 0.451367 psu 2020-03-05T23:00:07.755Z,1583449207.755 [CTD_Seabird](ERROR): Salinity reading out of range: 0.448113 psu 2020-03-05T23:00:07.776Z,1583449207.776 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:00:08.760Z,1583449208.760 [CTD_Seabird](ERROR): Salinity reading out of range: 0.443906 psu 2020-03-05T23:00:09.763Z,1583449209.763 [CTD_Seabird](ERROR): Salinity reading out of range: 0.440597 psu 2020-03-05T23:00:10.769Z,1583449210.769 [CTD_Seabird](ERROR): Salinity reading out of range: 0.445328 psu 2020-03-05T23:00:10.921Z,1583449210.921 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T23:00:10.921Z,1583449210.921 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T23:00:10.922Z,1583449210.922 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T23:00:10.922Z,1583449210.922 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T23:00:11.771Z,1583449211.771 [CTD_Seabird](ERROR): Salinity reading out of range: 0.456444 psu 2020-03-05T23:00:12.776Z,1583449212.776 [CTD_Seabird](ERROR): Salinity reading out of range: 0.459020 psu 2020-03-05T23:00:13.779Z,1583449213.779 [CTD_Seabird](ERROR): Salinity reading out of range: 0.452284 psu 2020-03-05T23:00:14.783Z,1583449214.783 [CTD_Seabird](ERROR): Salinity reading out of range: 0.465983 psu 2020-03-05T23:00:15.787Z,1583449215.787 [CTD_Seabird](ERROR): Salinity reading out of range: 0.467552 psu 2020-03-05T23:00:15.924Z,1583449215.924 [WetLabsUBAT..SerialDriver](ERROR): WetLabsUBAT::readRecord() - serial device timed out 2020-03-05T23:00:15.924Z,1583449215.924 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop(): read -2147483648 bytes 2020-03-05T23:00:15.924Z,1583449215.924 [WetLabsUBAT..StreamSerialDriver](ERROR): processLoop() - error from readRecord(); skipped process/publish 2020-03-05T23:00:15.925Z,1583449215.925 [WetLabsUBAT..StreamSerialDriver](ERROR): device state: Error 2020-03-05T23:00:16.791Z,1583449216.791 [CTD_Seabird](ERROR): Salinity reading out of range: 0.472421 psu 2020-03-05T23:00:17.795Z,1583449217.795 [CTD_Seabird](ERROR): Salinity reading out of range: 0.462366 psu 2020-03-05T23:00:18.800Z,1583449218.800 [CTD_Seabird](ERROR): Salinity reading out of range: 0.454425 psu 2020-03-05T23:00:19.803Z,1583449219.803 [CTD_Seabird](ERROR): Salinity reading out of range: 0.452977 psu 2020-03-05T23:00:20.807Z,1583449220.807 [CTD_Seabird](ERROR): Salinity reading out of range: 0.441037 psu 2020-03-05T23:00:21.811Z,1583449221.811 [CTD_Seabird](ERROR): Salinity reading out of range: 0.444574 psu 2020-03-05T23:00:22.815Z,1583449222.815 [CTD_Seabird](ERROR): Salinity reading out of range: 0.440915 psu 2020-03-05T23:00:23.819Z,1583449223.819 [CTD_Seabird](ERROR): Salinity reading out of range: 0.444740 psu 2020-03-05T23:00:24.823Z,1583449224.823 [CTD_Seabird](ERROR): Salinity reading out of range: 0.435249 psu 2020-03-05T23:00:25.827Z,1583449225.827 [CTD_Seabird](ERROR): Salinity reading out of range: 0.428844 psu 2020-03-05T23:00:26.831Z,1583449226.831 [CTD_Seabird](ERROR): Salinity reading out of range: 0.434595 psu 2020-03-05T23:00:27.835Z,1583449227.835 [CTD_Seabird](ERROR): Salinity reading out of range: 0.424337 psu 2020-03-05T23:00:28.839Z,1583449228.839 [CTD_Seabird](ERROR): Salinity reading out of range: 0.431463 psu 2020-03-05T23:00:29.843Z,1583449229.843 [CTD_Seabird](ERROR): Salinity reading out of range: 0.426306 psu 2020-03-05T23:00:30.847Z,1583449230.847 [CTD_Seabird](ERROR): Salinity reading out of range: 0.426537 psu 2020-03-05T23:00:31.851Z,1583449231.851 [CTD_Seabird](ERROR): Salinity reading out of range: 0.417615 psu 2020-03-05T23:00:32.855Z,1583449232.855 [CTD_Seabird](ERROR): Salinity reading out of range: 0.425570 psu 2020-03-05T23:00:33.860Z,1583449233.860 [CTD_Seabird](ERROR): Salinity reading out of range: 0.423230 psu 2020-03-05T23:00:34.863Z,1583449234.863 [CTD_Seabird](ERROR): Salinity reading out of range: 0.425558 psu 2020-03-05T23:00:35.867Z,1583449235.867 [CTD_Seabird](ERROR): Salinity reading out of range: 0.427583 psu 2020-03-05T23:00:36.871Z,1583449236.871 [CTD_Seabird](ERROR): Salinity reading out of range: 0.432319 psu 2020-03-05T23:00:37.875Z,1583449237.875 [CTD_Seabird](ERROR): Salinity reading out of range: 0.442804 psu 2020-03-05T23:00:38.880Z,1583449238.880 [CTD_Seabird](ERROR): Salinity reading out of range: 0.440569 psu 2020-03-05T23:00:39.883Z,1583449239.883 [CTD_Seabird](ERROR): Salinity reading out of range: 0.435943 psu 2020-03-05T23:00:40.887Z,1583449240.887 [CTD_Seabird](ERROR): Salinity reading out of range: 0.427426 psu 2020-03-05T23:00:41.891Z,1583449241.891 [CTD_Seabird](ERROR): Salinity reading out of range: 0.421680 psu 2020-03-05T23:00:42.895Z,1583449242.895 [CTD_Seabird](ERROR): Salinity reading out of range: 0.423470 psu 2020-03-05T23:00:43.899Z,1583449243.899 [CTD_Seabird](ERROR): Salinity reading out of range: 0.420945 psu 2020-03-05T23:00:44.491Z,1583449244.491 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:00:44.619Z,1583449244.619 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:00:44.903Z,1583449244.903 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:44.978Z,1583449244.978 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T23:00:45.907Z,1583449245.907 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:46.911Z,1583449246.911 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:47.003Z,1583449247.003 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-03-05T23:00:47.915Z,1583449247.915 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:48.919Z,1583449248.919 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:49.923Z,1583449249.923 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:50.927Z,1583449250.927 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:51.931Z,1583449251.931 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:52.935Z,1583449252.935 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:53.939Z,1583449253.939 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:54.943Z,1583449254.943 [CTD_Seabird](INFO): Ground Fault scan is active; will mark data as invalid. 2020-03-05T23:00:55.494Z,1583449255.494 [CBIT](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.326490 CHAN A1 (24V): 0.713442 CHAN A2 (12V): 0.317723 CHAN A3 (5V): 0.067418 CHAN B0 (3.3V): 0.039147 CHAN B1 (3.15aV): 0.076301 CHAN B2 (3.15bV): 0.036014 CHAN B3 (GND): -0.034864 OPEN: 0.012948 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:00:55.949Z,1583449255.949 [CTD_Seabird](ERROR): Salinity reading out of range: 0.412532 psu 2020-03-05T23:00:56.951Z,1583449256.951 [CTD_Seabird](ERROR): Salinity reading out of range: 0.408287 psu 2020-03-05T23:00:57.955Z,1583449257.955 [CTD_Seabird](ERROR): Salinity reading out of range: 0.407990 psu 2020-03-05T23:00:58.411Z,1583449258.411 [CommandLine](IMPORTANT): got command stop 2020-03-05T23:00:58.411Z,1583449258.411 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2020-03-05T23:00:58.717Z,1583449258.717 [MissionManager](INFO): MissionManager is completed. 2020-03-05T23:00:58.717Z,1583449258.717 [MissionManager](INFO): Uninitializing Mission Science 2020-03-05T23:00:58.717Z,1583449258.717 [Science] Stopped 2020-03-05T23:00:58.717Z,1583449258.717 [Science](DEBUG): Aggregate::uninitialize Science 2020-03-05T23:00:58.717Z,1583449258.717 [Science:C] Stopped 2020-03-05T23:00:58.718Z,1583449258.718 [Science:D] Stopped 2020-03-05T23:00:58.718Z,1583449258.718 [Science:G] Stopped 2020-03-05T23:00:58.718Z,1583449258.718 [Science:H] Stopped 2020-03-05T23:00:59.071Z,1583449259.071 [WetLabsBB2FL](INFO): Powering down 2020-03-05T23:00:59.128Z,1583449259.128 [MissionManager](IMPORTANT): Started mission Default 2020-03-05T23:00:59.128Z,1583449259.128 [Default] Running Loop=1 2020-03-05T23:00:59.129Z,1583449259.129 [Default](DEBUG): Aggregate::initialize Default 2020-03-05T23:00:59.129Z,1583449259.129 [Default:B.GoToSurface] Running Loop=1 2020-03-05T23:00:59.129Z,1583449259.129 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-03-05T23:00:59.129Z,1583449259.129 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-03-05T23:00:59.130Z,1583449259.130 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-03-05T23:00:59.130Z,1583449259.130 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-03-05T23:00:59.131Z,1583449259.131 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-03-05T23:00:59.131Z,1583449259.131 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-03-05T23:00:59.132Z,1583449259.132 [Default:A.Wait] Running Loop=1 2020-03-05T23:00:59.132Z,1583449259.132 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:00:59.217Z,1583449259.217 [WetLabsUBAT](INFO): Powering down 2020-03-05T23:01:04.651Z,1583449264.651 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:01:04.800Z,1583449264.800 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:01:12.428Z,1583449272.428 [Default:A.Wait](INFO): Done Waiting. 2020-03-05T23:01:12.428Z,1583449272.428 [Default:A.Wait] Stopped 2020-03-05T23:01:12.428Z,1583449272.428 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:01:12.848Z,1583449272.848 [Default:CheckIn] Running Loop=1 2020-03-05T23:01:12.849Z,1583449272.849 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:01:12.849Z,1583449272.849 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:01:15.702Z,1583449275.702 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.442096 CHAN A1 (24V): 0.744416 CHAN A2 (12V): 0.361331 CHAN A3 (5V): 0.135288 CHAN B0 (3.3V): 0.092849 CHAN B1 (3.15aV): 0.094794 CHAN B2 (3.15bV): 0.096548 CHAN B3 (GND): 0.001738 OPEN: 0.020044 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:01:19.883Z,1583449279.883 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:01:20.147Z,1583449280.147 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:01:31.084Z,1583449291.084 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.448797 CHAN A1 (24V): 0.746952 CHAN A2 (12V): 0.363396 CHAN A3 (5V): 0.136264 CHAN B0 (3.3V): 0.093270 CHAN B1 (3.15aV): 0.095901 CHAN B2 (3.15bV): 0.097194 CHAN B3 (GND): 0.002715 OPEN: 0.020485 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:01:47.211Z,1583449307.211 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:01:53.149Z,1583449313.149 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:01:53.244Z,1583449313.244 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:02:04.184Z,1583449324.184 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032642 CHAN A1 (24V): 0.035601 CHAN A2 (12V): -0.007988 CHAN A3 (5V): -0.002308 CHAN B0 (3.3V): -0.000174 CHAN B1 (3.15aV): 0.000178 CHAN B2 (3.15bV): -0.000263 CHAN B3 (GND): 0.002118 OPEN: 0.005267 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:02:15.038Z,1583449335.038 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:02:19.488Z,1583449339.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230226.00,A,3648.16441,N,12147.28612,W,0.019,302.80,050320,,,D*7A 2020-03-05T23:02:19.490Z,1583449339.490 [NAL9602](INFO): GPS fix at 20200305T230226: (36.802740, -121.788102) 2020-03-05T23:02:19.540Z,1583449339.540 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:02:19.541Z,1583449339.541 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:02:27.512Z,1583449347.512 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0066.lzma 2020-03-05T23:02:29.518Z,1583449349.518 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0066.lzma.bak 2020-03-05T23:02:29.519Z,1583449349.519 [DataOverHttps](INFO): SBD MOMSN=12298135 2020-03-05T23:02:46.679Z,1583449366.679 [DataOverHttps](INFO): Sending 1149 bytes from file Logs/20200305T210333/Express0067.lzma 2020-03-05T23:02:48.683Z,1583449368.683 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0067.lzma.bak 2020-03-05T23:02:48.683Z,1583449368.683 [DataOverHttps](INFO): SBD MOMSN=12298138 2020-03-05T23:02:50.220Z,1583449370.220 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:02:50.220Z,1583449370.220 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:02:50.220Z,1583449370.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:02:52.206Z,1583449372.206 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:07:50.824Z,1583449670.824 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:07:50.824Z,1583449670.824 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:07:50.824Z,1583449670.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:07:50.825Z,1583449670.825 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:07:51.205Z,1583449671.205 [Default:CheckIn:D] Stopped 2020-03-05T23:07:51.205Z,1583449671.205 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:07:51.623Z,1583449671.623 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.867945 min 2020-03-05T23:07:51.623Z,1583449671.623 [Default:CheckIn:E] Stopped 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn] Stopped 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn](INFO): Running loop #2 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn] Running Loop=2 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:07:51.624Z,1583449671.624 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:07:53.606Z,1583449673.606 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230800.00,A,3648.16833,N,12147.28520,W,0.175,302.80,050320,,,D*74 2020-03-05T23:07:53.608Z,1583449673.608 [NAL9602](INFO): GPS fix at 20200305T230800: (36.802805, -121.788087) 2020-03-05T23:07:53.675Z,1583449673.675 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:07:53.675Z,1583449673.675 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:08:02.896Z,1583449682.896 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0069.lzma 2020-03-05T23:08:04.904Z,1583449684.904 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0069.lzma.bak 2020-03-05T23:08:04.904Z,1583449684.904 [DataOverHttps](INFO): SBD MOMSN=12298191 2020-03-05T23:08:22.466Z,1583449702.466 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20200305T210333/Express0070.lzma 2020-03-05T23:08:24.314Z,1583449704.314 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-03-05T23:08:24.397Z,1583449704.397 [NAL9602](FAULT): received: +CSQ:0 OK37, 2, 0, 0, 0 OK 2020-03-05T23:08:24.397Z,1583449704.397 [NAL9602] Data Fault, FailCount= 1 2020-03-05T23:08:24.397Z,1583449704.397 [NAL9602](ERROR): Data Fault 2020-03-05T23:08:24.471Z,1583449704.471 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0070.lzma.bak 2020-03-05T23:08:24.471Z,1583449704.471 [DataOverHttps](INFO): SBD MOMSN=12298194 2020-03-05T23:08:24.533Z,1583449704.533 [CBIT](ERROR): Data Fault in component: NAL9602 2020-03-05T23:08:24.722Z,1583449704.722 [NAL9602](INFO): Powering down 2020-03-05T23:08:25.634Z,1583449705.634 [CBIT](INFO): Clearing failed state for component NAL9602 2020-03-05T23:08:25.634Z,1583449705.634 [NAL9602] No Fault, FailCount= 1 2020-03-05T23:08:25.956Z,1583449705.956 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:08:25.973Z,1583449705.973 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:08:25.973Z,1583449705.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:08:55.018Z,1583449735.018 [NAL9602](INFO): Powering up NAL9602 2020-03-05T23:09:05.926Z,1583449745.926 [NAL9602](INFO): NAL9602 initialized 2020-03-05T23:09:07.592Z,1583449747.592 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-03-05T23:09:37.034Z,1583449777.034 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:13:17.441Z,1583449997.441 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:13:22.495Z,1583450002.495 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:13:22.516Z,1583450002.516 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:13:26.540Z,1583450006.540 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:13:26.540Z,1583450006.540 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:13:26.540Z,1583450006.540 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:13:26.541Z,1583450006.541 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:13:26.949Z,1583450006.949 [Default:CheckIn:D] Stopped 2020-03-05T23:13:26.949Z,1583450006.949 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:13:27.352Z,1583450007.352 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.463680 min 2020-03-05T23:13:27.352Z,1583450007.352 [Default:CheckIn:E] Stopped 2020-03-05T23:13:27.352Z,1583450007.352 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:13:27.352Z,1583450007.352 [Default:CheckIn] Stopped 2020-03-05T23:13:27.352Z,1583450007.352 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:13:27.353Z,1583450007.353 [Default:CheckIn](INFO): Running loop #3 2020-03-05T23:13:27.353Z,1583450007.353 [Default:CheckIn] Running Loop=3 2020-03-05T23:13:27.353Z,1583450007.353 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:13:27.353Z,1583450007.353 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:13:29.340Z,1583450009.340 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231335.00,A,3648.15653,N,12147.27671,W,0.175,0.00,050320,,,A*77 2020-03-05T23:13:29.342Z,1583450009.342 [NAL9602](INFO): GPS fix at 20200305T231335: (36.802609, -121.787945) 2020-03-05T23:13:29.366Z,1583450009.366 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:13:29.366Z,1583450009.366 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:13:31.818Z,1583450011.818 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:13:33.486Z,1583450013.486 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032771 CHAN A1 (24V): 0.035921 CHAN A2 (12V): -0.007574 CHAN A3 (5V): -0.002307 CHAN B0 (3.3V): 0.000350 CHAN B1 (3.15aV): -0.000270 CHAN B2 (3.15bV): -0.000014 CHAN B3 (GND): 0.002072 OPEN: 0.005168 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:13:36.756Z,1583450016.756 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0072.lzma 2020-03-05T23:13:38.762Z,1583450018.762 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0072.lzma.bak 2020-03-05T23:13:38.763Z,1583450018.763 [DataOverHttps](INFO): SBD MOMSN=12298197 2020-03-05T23:13:49.443Z,1583450029.443 [CommandLine](IMPORTANT): got command ! echo d > /dev/loadC1 2020-03-05T23:13:51.003Z,1583450031.003 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:13:51.254Z,1583450031.254 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:14:01.009Z,1583450041.009 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20200305T210333/Express0073.lzma 2020-03-05T23:14:02.183Z,1583450042.183 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032812 CHAN A1 (24V): 0.036172 CHAN A2 (12V): -0.007582 CHAN A3 (5V): -0.002327 CHAN B0 (3.3V): -0.000198 CHAN B1 (3.15aV): 0.000343 CHAN B2 (3.15bV): -0.000045 CHAN B3 (GND): 0.002081 OPEN: 0.005409 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:14:02.542Z,1583450042.542 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:14:03.015Z,1583450043.015 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0073.lzma.bak 2020-03-05T23:14:03.015Z,1583450043.015 [DataOverHttps](INFO): SBD MOMSN=12298200 2020-03-05T23:14:04.628Z,1583450044.628 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:14:04.629Z,1583450044.629 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:14:04.629Z,1583450044.629 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:14:20.481Z,1583450060.481 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:16:28.807Z,1583450188.807 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:19:05.170Z,1583450345.170 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:19:05.170Z,1583450345.170 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:19:05.170Z,1583450345.170 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:19:05.171Z,1583450345.171 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:19:05.616Z,1583450345.616 [Default:CheckIn:D] Stopped 2020-03-05T23:19:05.616Z,1583450345.616 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:19:05.985Z,1583450345.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.108130 min 2020-03-05T23:19:05.985Z,1583450345.985 [Default:CheckIn:E] Stopped 2020-03-05T23:19:05.985Z,1583450345.985 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:19:05.985Z,1583450345.985 [Default:CheckIn] Stopped 2020-03-05T23:19:05.985Z,1583450345.985 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:19:05.986Z,1583450345.986 [Default:CheckIn](INFO): Running loop #4 2020-03-05T23:19:05.986Z,1583450345.986 [Default:CheckIn] Running Loop=4 2020-03-05T23:19:05.986Z,1583450345.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:19:05.986Z,1583450345.986 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:19:07.970Z,1583450347.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231914.00,A,3648.16058,N,12147.28063,W,0.039,324.32,050320,,,A*77 2020-03-05T23:19:07.973Z,1583450347.973 [NAL9602](INFO): GPS fix at 20200305T231914: (36.802676, -121.788010) 2020-03-05T23:19:08.018Z,1583450348.018 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:19:08.018Z,1583450348.018 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:19:15.696Z,1583450355.696 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0075.lzma 2020-03-05T23:19:17.703Z,1583450357.703 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0075.lzma.bak 2020-03-05T23:19:17.703Z,1583450357.703 [DataOverHttps](INFO): SBD MOMSN=12298228 2020-03-05T23:19:30.639Z,1583450370.639 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:19:30.692Z,1583450370.692 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:19:37.559Z,1583450377.559 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20200305T210333/Express0076.lzma 2020-03-05T23:19:39.558Z,1583450379.558 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0076.lzma.bak 2020-03-05T23:19:39.559Z,1583450379.559 [DataOverHttps](INFO): SBD MOMSN=12298231 2020-03-05T23:19:41.136Z,1583450381.136 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:19:41.136Z,1583450381.136 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:19:41.136Z,1583450381.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:19:41.596Z,1583450381.596 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.365735 CHAN A1 (24V): 0.720502 CHAN A2 (12V): 0.339931 CHAN A3 (5V): 0.070376 CHAN B0 (3.3V): 0.042046 CHAN B1 (3.15aV): 0.074368 CHAN B2 (3.15bV): 0.037437 CHAN B3 (GND): -0.022144 OPEN: 0.012045 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:19:53.752Z,1583450393.752 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:20:40.927Z,1583450440.927 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-03-05T23:22:02.902Z,1583450522.902 [NAL9602](INFO): SBD MO Status=2, MOMSN=8037, MT Status=2, MTMSN=0 2020-03-05T23:22:02.902Z,1583450522.902 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T23:22:44.668Z,1583450564.668 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:22:44.981Z,1583450564.981 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:22:55.899Z,1583450575.899 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.033172 CHAN A1 (24V): 0.035156 CHAN A2 (12V): -0.007418 CHAN A3 (5V): -0.001395 CHAN B0 (3.3V): -0.000158 CHAN B1 (3.15aV): -0.001011 CHAN B2 (3.15bV): -0.000226 CHAN B3 (GND): 0.002216 OPEN: 0.005483 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:22:59.988Z,1583450579.988 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:23:29.108Z,1583450609.108 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:23:29.410Z,1583450609.410 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:23:40.319Z,1583450620.319 [CBIT](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.366524 CHAN A1 (24V): 0.741216 CHAN A2 (12V): 0.279025 CHAN A3 (5V): 0.085982 CHAN B0 (3.3V): 0.062545 CHAN B1 (3.15aV): 0.035880 CHAN B2 (3.15bV): 0.083004 CHAN B3 (GND): -0.047585 OPEN: 0.014467 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:23:48.636Z,1583450628.636 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:24:09.766Z,1583450649.766 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:24:40.466Z,1583450680.466 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:24:41.712Z,1583450681.712 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:24:41.712Z,1583450681.712 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:24:41.712Z,1583450681.712 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:24:41.712Z,1583450681.712 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:24:42.121Z,1583450682.121 [Default:CheckIn:D] Stopped 2020-03-05T23:24:42.121Z,1583450682.121 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:24:42.544Z,1583450682.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.716547 min 2020-03-05T23:24:42.544Z,1583450682.544 [Default:CheckIn:E] Stopped 2020-03-05T23:24:42.544Z,1583450682.544 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn] Stopped 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn](INFO): Running loop #5 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn] Running Loop=5 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:24:42.549Z,1583450682.549 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:24:44.514Z,1583450684.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232451.00,A,3648.16598,N,12147.28253,W,0.194,126.16,050320,,,A*70 2020-03-05T23:24:44.516Z,1583450684.516 [NAL9602](INFO): GPS fix at 20200305T232451: (36.802766, -121.788042) 2020-03-05T23:24:44.544Z,1583450684.544 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:24:44.544Z,1583450684.544 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:24:51.797Z,1583450691.797 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0078.lzma 2020-03-05T23:24:53.803Z,1583450693.803 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0078.lzma.bak 2020-03-05T23:24:53.803Z,1583450693.803 [DataOverHttps](INFO): SBD MOMSN=12298242 2020-03-05T23:25:11.346Z,1583450711.346 [DataOverHttps](INFO): Sending 641 bytes from file Logs/20200305T210333/Express0079.lzma 2020-03-05T23:25:13.351Z,1583450713.351 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0079.lzma.bak 2020-03-05T23:25:13.351Z,1583450713.351 [DataOverHttps](INFO): SBD MOMSN=12298245 2020-03-05T23:25:14.868Z,1583450714.868 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:25:14.868Z,1583450714.868 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:25:14.868Z,1583450714.868 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:25:15.238Z,1583450715.238 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-03-05T23:25:15.317Z,1583450715.317 [NAL9602](FAULT): received: +CSQ:0 OK37, 2, 0, 0, 0 OK 2020-03-05T23:25:15.317Z,1583450715.317 [NAL9602] Data Fault, FailCount= 1 2020-03-05T23:25:15.317Z,1583450715.317 [NAL9602](ERROR): Data Fault 2020-03-05T23:25:15.406Z,1583450715.406 [CBIT](ERROR): Data Fault in component: NAL9602 2020-03-05T23:25:15.638Z,1583450715.638 [NAL9602](INFO): Powering down 2020-03-05T23:25:16.495Z,1583450716.495 [CBIT](INFO): Clearing failed state for component NAL9602 2020-03-05T23:25:16.495Z,1583450716.495 [NAL9602] No Fault, FailCount= 1 2020-03-05T23:25:45.936Z,1583450745.936 [NAL9602](INFO): Powering up NAL9602 2020-03-05T23:25:56.882Z,1583450756.882 [NAL9602](INFO): NAL9602 initialized 2020-03-05T23:26:27.979Z,1583450787.979 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:30:15.483Z,1583451015.483 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:30:15.483Z,1583451015.483 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:30:15.483Z,1583451015.483 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:30:15.484Z,1583451015.484 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:30:15.908Z,1583451015.908 [Default:CheckIn:D] Stopped 2020-03-05T23:30:15.908Z,1583451015.908 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:30:16.284Z,1583451016.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.279655 min 2020-03-05T23:30:16.284Z,1583451016.284 [Default:CheckIn:E] Stopped 2020-03-05T23:30:16.284Z,1583451016.284 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:30:16.284Z,1583451016.284 [Default:CheckIn] Stopped 2020-03-05T23:30:16.284Z,1583451016.284 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:30:16.285Z,1583451016.285 [Default:CheckIn](INFO): Running loop #6 2020-03-05T23:30:16.285Z,1583451016.285 [Default:CheckIn] Running Loop=6 2020-03-05T23:30:16.285Z,1583451016.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:30:16.285Z,1583451016.285 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:30:18.274Z,1583451018.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233024.00,A,3648.16151,N,12147.28148,W,0.194,149.49,050320,,,A*7C 2020-03-05T23:30:18.276Z,1583451018.276 [NAL9602](INFO): GPS fix at 20200305T233024: (36.802692, -121.788025) 2020-03-05T23:30:18.340Z,1583451018.340 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:30:18.341Z,1583451018.341 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:30:20.746Z,1583451020.746 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:30:25.556Z,1583451025.556 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0081.lzma 2020-03-05T23:30:27.563Z,1583451027.563 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0081.lzma.bak 2020-03-05T23:30:27.563Z,1583451027.563 [DataOverHttps](INFO): SBD MOMSN=12298280 2020-03-05T23:30:45.073Z,1583451045.073 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20200305T210333/Express0082.lzma 2020-03-05T23:30:47.079Z,1583451047.079 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0082.lzma.bak 2020-03-05T23:30:47.079Z,1583451047.079 [DataOverHttps](INFO): SBD MOMSN=12298283 2020-03-05T23:30:48.645Z,1583451048.645 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:30:48.646Z,1583451048.646 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:30:48.646Z,1583451048.646 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:30:51.450Z,1583451051.450 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:35:49.250Z,1583451349.250 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:35:49.250Z,1583451349.250 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:35:49.250Z,1583451349.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:35:49.250Z,1583451349.250 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:35:49.648Z,1583451349.648 [Default:CheckIn:D] Stopped 2020-03-05T23:35:49.648Z,1583451349.648 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:35:50.069Z,1583451350.069 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.841984 min 2020-03-05T23:35:50.069Z,1583451350.069 [Default:CheckIn:E] Stopped 2020-03-05T23:35:50.069Z,1583451350.069 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:35:50.069Z,1583451350.069 [Default:CheckIn] Stopped 2020-03-05T23:35:50.070Z,1583451350.070 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:35:50.070Z,1583451350.070 [Default:CheckIn](INFO): Running loop #7 2020-03-05T23:35:50.070Z,1583451350.070 [Default:CheckIn] Running Loop=7 2020-03-05T23:35:50.070Z,1583451350.070 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:35:50.070Z,1583451350.070 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:35:52.059Z,1583451352.059 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233559.00,A,3648.16647,N,12147.28405,W,0.272,149.49,050320,,,A*74 2020-03-05T23:35:52.062Z,1583451352.062 [NAL9602](INFO): GPS fix at 20200305T233559: (36.802774, -121.788067) 2020-03-05T23:35:52.086Z,1583451352.086 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:35:52.086Z,1583451352.086 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:36:01.828Z,1583451361.828 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200305T210333/Courier0084.lzma 2020-03-05T23:36:03.834Z,1583451363.834 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0084.lzma.bak 2020-03-05T23:36:03.835Z,1583451363.835 [DataOverHttps](INFO): SBD MOMSN=12298287 2020-03-05T23:36:21.546Z,1583451381.546 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20200305T210333/Express0085.lzma 2020-03-05T23:36:21.767Z,1583451381.767 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:36:21.990Z,1583451381.990 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:36:23.156Z,1583451383.156 [NAL9602](INFO): SBD MO Status=2, MOMSN=8037, MT Status=2, MTMSN=0 2020-03-05T23:36:23.156Z,1583451383.156 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-03-05T23:36:23.551Z,1583451383.551 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0085.lzma.bak 2020-03-05T23:36:23.551Z,1583451383.551 [DataOverHttps](INFO): SBD MOMSN=12298290 2020-03-05T23:36:24.802Z,1583451384.802 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:36:24.802Z,1583451384.802 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:36:24.802Z,1583451384.802 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:36:32.908Z,1583451392.908 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.032837 CHAN A1 (24V): 0.035439 CHAN A2 (12V): -0.007922 CHAN A3 (5V): -0.002648 CHAN B0 (3.3V): 0.000596 CHAN B1 (3.15aV): -0.000351 CHAN B2 (3.15bV): 0.000178 CHAN B3 (GND): 0.002337 OPEN: 0.005418 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:36:36.715Z,1583451396.715 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:37:07.498Z,1583451427.498 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:37:07.637Z,1583451427.637 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:37:18.536Z,1583451438.536 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.155806 CHAN A1 (24V): 0.423589 CHAN A2 (12V): 0.167030 CHAN A3 (5V): 0.049094 CHAN B0 (3.3V): 0.010858 CHAN B1 (3.15aV): 0.024582 CHAN B2 (3.15bV): 0.027664 CHAN B3 (GND): -0.032457 OPEN: 0.010417 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:37:26.894Z,1583451446.894 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:37:27.076Z,1583451447.076 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:37:37.975Z,1583451457.975 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.186529 CHAN A1 (24V): 0.420599 CHAN A2 (12V): 0.158180 CHAN A3 (5V): 0.043615 CHAN B0 (3.3V): 0.016119 CHAN B1 (3.15aV): 0.013838 CHAN B2 (3.15bV): 0.033925 CHAN B3 (GND): -0.015009 OPEN: 0.010685 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:37:51.052Z,1583451471.052 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:40:35.976Z,1583451635.976 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadC1 2020-03-05T23:40:39.177Z,1583451639.177 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:40:39.343Z,1583451639.343 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:40:50.247Z,1583451650.247 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.103370 CHAN A1 (24V): 0.270606 CHAN A2 (12V): 0.102442 CHAN A3 (5V): -0.003741 CHAN B0 (3.3V): 0.012917 CHAN B1 (3.15aV): 0.014420 CHAN B2 (3.15bV): 0.021095 CHAN B3 (GND): -0.027618 OPEN: 0.010064 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:40:53.834Z,1583451653.834 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:40:53.895Z,1583451653.895 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:40:53.904Z,1583451653.904 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:41:04.780Z,1583451664.780 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.084206 CHAN A1 (24V): 0.261716 CHAN A2 (12V): 0.092686 CHAN A3 (5V): 0.024287 CHAN B0 (3.3V): 0.014398 CHAN B1 (3.15aV): 0.014806 CHAN B2 (3.15bV): 0.017288 CHAN B3 (GND): -0.022304 OPEN: 0.007884 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:41:08.894Z,1583451668.894 [CommandLine](IMPORTANT): got command gfscan 2020-03-05T23:41:09.238Z,1583451669.238 [CBIT](IMPORTANT): Beginning ground fault scan 2020-03-05T23:41:20.162Z,1583451680.162 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.087101 CHAN A1 (24V): 0.276468 CHAN A2 (12V): 0.099283 CHAN A3 (5V): 0.034705 CHAN B0 (3.3V): 0.003024 CHAN B1 (3.15aV): 0.008149 CHAN B2 (3.15bV): 0.014244 CHAN B3 (GND): -0.019141 OPEN: 0.007354 Full Scale Calc: 4.765 mA, -1.589 mA 2020-03-05T23:41:24.532Z,1583451684.532 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:41:25.377Z,1583451685.377 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:41:25.377Z,1583451685.377 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:41:25.377Z,1583451685.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:41:25.377Z,1583451685.377 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:41:25.779Z,1583451685.779 [Default:CheckIn:D] Stopped 2020-03-05T23:41:25.779Z,1583451685.779 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.444173 min 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn:E] Stopped 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn] Stopped 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn](INFO): Running loop #8 2020-03-05T23:41:26.199Z,1583451686.199 [Default:CheckIn] Running Loop=8 2020-03-05T23:41:26.200Z,1583451686.200 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:41:26.200Z,1583451686.200 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:41:28.176Z,1583451688.176 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234135.00,A,3648.16008,N,12147.28051,W,0.117,162.10,050320,,,A*70 2020-03-05T23:41:28.178Z,1583451688.178 [NAL9602](INFO): GPS fix at 20200305T234135: (36.802668, -121.788009) 2020-03-05T23:41:28.239Z,1583451688.239 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:41:28.239Z,1583451688.239 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:41:36.273Z,1583451696.273 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200305T210333/Courier0087.lzma 2020-03-05T23:41:38.279Z,1583451698.279 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0087.lzma.bak 2020-03-05T23:41:38.279Z,1583451698.279 [DataOverHttps](INFO): SBD MOMSN=12298313 2020-03-05T23:41:55.930Z,1583451715.930 [DataOverHttps](INFO): Sending 750 bytes from file Logs/20200305T210333/Express0088.lzma 2020-03-05T23:41:57.935Z,1583451717.935 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0088.lzma.bak 2020-03-05T23:41:57.935Z,1583451717.935 [DataOverHttps](INFO): SBD MOMSN=12298316 2020-03-05T23:41:58.874Z,1583451718.874 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-03-05T23:41:58.977Z,1583451718.977 [NAL9602](FAULT): received: +CSQ:0 OK37, 2, 0, 0, 0 OK 2020-03-05T23:41:58.977Z,1583451718.977 [NAL9602] Data Fault, FailCount= 1 2020-03-05T23:41:58.977Z,1583451718.977 [NAL9602](ERROR): Data Fault 2020-03-05T23:41:59.094Z,1583451719.094 [CBIT](ERROR): Data Fault in component: NAL9602 2020-03-05T23:41:59.278Z,1583451719.278 [NAL9602](INFO): Powering down 2020-03-05T23:41:59.716Z,1583451719.716 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:41:59.716Z,1583451719.716 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:41:59.716Z,1583451719.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:42:00.139Z,1583451720.139 [CBIT](INFO): Clearing failed state for component NAL9602 2020-03-05T23:42:00.140Z,1583451720.140 [NAL9602] No Fault, FailCount= 1 2020-03-05T23:42:29.577Z,1583451749.577 [NAL9602](INFO): Powering up NAL9602 2020-03-05T23:42:40.486Z,1583451760.486 [NAL9602](INFO): NAL9602 initialized 2020-03-05T23:43:11.598Z,1583451791.598 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:44:06.561Z,1583451846.561 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1 2020-03-05T23:47:00.302Z,1583452020.302 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-03-05T23:47:00.303Z,1583452020.303 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:47:00.303Z,1583452020.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:47:00.303Z,1583452020.303 [Default:CheckIn:D] Running Loop=1 2020-03-05T23:47:00.696Z,1583452020.696 [Default:CheckIn:D] Stopped 2020-03-05T23:47:00.696Z,1583452020.696 [Default:CheckIn:E] Running Loop=1 2020-03-05T23:47:01.100Z,1583452021.100 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.026123 min 2020-03-05T23:47:01.100Z,1583452021.100 [Default:CheckIn:E] Stopped 2020-03-05T23:47:01.100Z,1583452021.100 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-03-05T23:47:01.100Z,1583452021.100 [Default:CheckIn] Stopped 2020-03-05T23:47:01.101Z,1583452021.101 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:47:01.101Z,1583452021.101 [Default:CheckIn](INFO): Running loop #9 2020-03-05T23:47:01.101Z,1583452021.101 [Default:CheckIn] Running Loop=9 2020-03-05T23:47:01.101Z,1583452021.101 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-03-05T23:47:01.101Z,1583452021.101 [Default:CheckIn:Read_GPS] Running Loop=1 2020-03-05T23:47:03.086Z,1583452023.086 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234708.00,A,3648.16956,N,12147.28646,W,0.369,191.75,050320,,,A*7E 2020-03-05T23:47:03.088Z,1583452023.088 [NAL9602](INFO): GPS fix at 20200305T234708: (36.802826, -121.788108) 2020-03-05T23:47:03.140Z,1583452023.140 [Default:CheckIn:Read_GPS] Stopped 2020-03-05T23:47:03.140Z,1583452023.140 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-03-05T23:47:05.519Z,1583452025.519 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-03-05T23:47:10.764Z,1583452030.764 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200305T210333/Courier0090.lzma 2020-03-05T23:47:12.772Z,1583452032.772 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Courier0090.lzma.bak 2020-03-05T23:47:12.772Z,1583452032.772 [DataOverHttps](INFO): SBD MOMSN=12298341 2020-03-05T23:47:33.153Z,1583452053.153 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20200305T210333/Express0091.lzma 2020-03-05T23:47:35.159Z,1583452055.159 [DataOverHttps](INFO): Moved sent file to Logs/20200305T210333/Express0091.lzma.bak 2020-03-05T23:47:35.159Z,1583452055.159 [DataOverHttps](INFO): SBD MOMSN=12298344 2020-03-05T23:47:36.212Z,1583452056.212 [NAL9602](INFO): Not Powering down - fast GPS 2020-03-05T23:47:36.646Z,1583452056.646 [Default:CheckIn:Read_Iridium] Stopped 2020-03-05T23:47:36.646Z,1583452056.646 [Default:CheckIn:C.Wait] Running Loop=1 2020-03-05T23:47:36.646Z,1583452056.646 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-03-05T23:48:15.053Z,1583452095.053 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2020-03-05T23:50:15.136Z,1583452215.136 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-03-05T23:51:33.399Z,1583452293.399 [CommandLine](IMPORTANT): got command restart application 2020-03-05T23:51:34.409Z,1583452294.409 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:34.409Z,1583452294.409 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.577Z,1583452294.577 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-03-05T23:51:34.577Z,1583452294.577 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.578Z,1583452294.578 [CommandLine](INFO): Join timeout helper Thread ID is 6891 2020-03-05T23:51:34.578Z,1583452294.578 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-03-05T23:51:34.578Z,1583452294.578 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.579Z,1583452294.579 [NavChartDb](INFO): Join timeout helper Thread ID is 6892 2020-03-05T23:51:34.637Z,1583452294.637 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:34.637Z,1583452294.637 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.641Z,1583452294.641 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2020-03-05T23:51:34.641Z,1583452294.641 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.641Z,1583452294.641 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 6893 2020-03-05T23:51:34.865Z,1583452294.865 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:34.865Z,1583452294.865 [WetLabsUBAT](INFO): Powering down 2020-03-05T23:51:34.866Z,1583452294.866 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.887Z,1583452294.887 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-03-05T23:51:34.887Z,1583452294.887 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:34.887Z,1583452294.887 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6894 2020-03-05T23:51:35.149Z,1583452295.149 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:35.149Z,1583452295.149 [WetLabsBB2FL](INFO): Powering down 2020-03-05T23:51:35.150Z,1583452295.150 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:35.165Z,1583452295.165 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-03-05T23:51:35.165Z,1583452295.165 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:35.165Z,1583452295.165 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6895 2020-03-05T23:51:35.745Z,1583452295.745 [CTD_Seabird](INFO): Powering down 2020-03-05T23:51:35.757Z,1583452295.757 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:35.757Z,1583452295.757 [CTD_Seabird](INFO): Powering down 2020-03-05T23:51:35.769Z,1583452295.769 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:35.782Z,1583452295.782 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2020-03-05T23:51:35.782Z,1583452295.782 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:35.782Z,1583452295.782 [BackSeatDriver](INFO): Join timeout helper Thread ID is 6896 2020-03-05T23:51:36.054Z,1583452296.054 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:36.054Z,1583452296.054 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:36.058Z,1583452296.058 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-03-05T23:51:36.058Z,1583452296.058 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:36.058Z,1583452296.058 [Radio_Surface](INFO): Join timeout helper Thread ID is 6897 2020-03-05T23:51:36.457Z,1583452296.457 [Radio_Surface](INFO): Powering down 2020-03-05T23:51:36.458Z,1583452296.458 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:36.458Z,1583452296.458 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:36.477Z,1583452296.477 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-03-05T23:51:36.478Z,1583452296.478 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:36.478Z,1583452296.478 [DataOverHttps](INFO): Join timeout helper Thread ID is 6898 2020-03-05T23:51:37.309Z,1583452297.309 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:37.309Z,1583452297.309 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.329Z,1583452297.329 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-03-05T23:51:37.330Z,1583452297.330 [logger ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.330Z,1583452297.330 [logger](INFO): Join timeout helper Thread ID is 6899 2020-03-05T23:51:37.333Z,1583452297.333 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:37.333Z,1583452297.333 [logger ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.349Z,1583452297.349 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-03-05T23:51:37.350Z,1583452297.350 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.350Z,1583452297.350 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-03-05T23:51:37.350Z,1583452297.350 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.350Z,1583452297.350 [controlThread](INFO): Join timeout helper Thread ID is 6900 2020-03-05T23:51:37.493Z,1583452297.493 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-03-05T23:51:37.493Z,1583452297.493 [controlThread](DEBUG): Uninitializing ControlThread 2020-03-05T23:51:37.494Z,1583452297.494 [AHRS_M2](INFO): Powering down 2020-03-05T23:51:37.565Z,1583452297.565 [NAL9602](INFO): Powering down 2020-03-05T23:51:37.637Z,1583452297.637 [RDI_Pathfinder](INFO): Powering down 2020-03-05T23:51:37.638Z,1583452297.638 [DAT](INFO): Powering down 2020-03-05T23:51:37.758Z,1583452297.758 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-03-05T23:51:37.758Z,1583452297.758 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-03-05T23:51:37.759Z,1583452297.759 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-03-05T23:51:37.759Z,1583452297.759 [MissionManager](INFO): Uninitializing Mission Default 2020-03-05T23:51:37.759Z,1583452297.759 [Default] Stopped 2020-03-05T23:51:37.760Z,1583452297.760 [Default](DEBUG): Aggregate::uninitialize Default 2020-03-05T23:51:37.760Z,1583452297.760 [Default:B.GoToSurface] Stopped 2020-03-05T23:51:37.760Z,1583452297.760 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-03-05T23:51:37.760Z,1583452297.760 [Default:CheckIn] Stopped 2020-03-05T23:51:37.760Z,1583452297.760 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-03-05T23:51:37.760Z,1583452297.760 [Default:CheckIn:C.Wait] Stopped 2020-03-05T23:51:37.760Z,1583452297.760 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-03-05T23:51:37.763Z,1583452297.763 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-03-05T23:51:37.763Z,1583452297.763 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-03-05T23:51:37.763Z,1583452297.763 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-03-05T23:51:37.763Z,1583452297.763 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-03-05T23:51:37.764Z,1583452297.764 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-03-05T23:51:37.764Z,1583452297.764 [BuoyancyServo](INFO): Powering down 2020-03-05T23:51:37.777Z,1583452297.777 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-03-05T23:51:37.777Z,1583452297.777 [ElevatorServo](INFO): Powering down 2020-03-05T23:51:37.778Z,1583452297.778 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-03-05T23:51:37.778Z,1583452297.778 [MassServo](INFO): Powering down 2020-03-05T23:51:37.779Z,1583452297.779 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-03-05T23:51:37.779Z,1583452297.779 [RudderServo](INFO): Powering down 2020-03-05T23:51:37.779Z,1583452297.779 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-03-05T23:51:37.780Z,1583452297.780 [ThrusterServo](INFO): Powering down 2020-03-05T23:51:37.780Z,1583452297.780 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-03-05T23:51:37.781Z,1583452297.781 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-03-05T23:51:37.781Z,1583452297.781 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-03-05T23:51:37.781Z,1583452297.781 [CBIT](DEBUG): Powering off loads. 2020-03-05T23:51:37.793Z,1583452297.793 [CBIT](DEBUG): Disabling WDT. 2020-03-05T23:51:37.805Z,1583452297.805 [CBIT](DEBUG): Opening all GF detection circuits. 2020-03-05T23:51:37.805Z,1583452297.805 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.897Z,1583452297.897 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.904Z,1583452297.904 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.973Z,1583452297.973 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:37.974Z,1583452297.974 [WetLabsUBAT](INFO): WetLabs destructor: dataLog is open - close it 2020-03-05T23:51:37.975Z,1583452297.975 [WetLabsUBAT](INFO): WetLabs destructor: done 2020-03-05T23:51:38.027Z,1583452298.027 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:38.030Z,1583452298.030 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:38.033Z,1583452298.033 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:38.047Z,1583452298.047 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-03-05T23:51:38.151Z,1583452298.151 [logger ThreadHandler](INFO): Thread cancelled.