2019-12-16T17:58:03.833Z,1576519083.833 [NAL9602](INFO): Received command:restart logs 2019-12-16T17:58:03.858Z,1576519083.858 [CommandLine](IMPORTANT): got command restart logs 2019-12-16T17:58:04.968Z,1576519084.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175138.00,A,3647.79157,N,12150.85644,W,1.380,119.36,161219,,,A*78 2019-12-16T17:58:04.970Z,1576519084.970 [NAL9602](INFO): GPS fix at 20191216T175138: (36.796526, -121.847607) 2019-12-16T17:58:05.011Z,1576519085.011 [UniversalFixResidualReporter](INFO): Fix residual: 4.8 %DT, over the last 6677.6 m. Residual distance 320.1 m at bearing -54.0 degrees. Fix at (36.7965, -121.8476) with 197.4 m made good. 2019-12-16T17:58:05.013Z,1576519085.013 [spiral_cast:NeedComms:C] Stopped 2019-12-16T17:58:05.014Z,1576519085.014 [spiral_cast:NeedComms:D] Running Loop=1 2019-12-16T17:58:26.024Z,1576519106.024 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20191216T150333/Courier0006.lzma 2019-12-16T17:58:28.030Z,1576519108.030 [DataOverHttps](INFO): Moved sent file to Logs/20191216T150333/Courier0006.lzma.bak 2019-12-16T17:58:28.031Z,1576519108.031 [DataOverHttps](INFO): SBD MOMSN=12171280 2019-12-16T17:58:37.758Z,1576519117.758 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T17:58:45.840Z,1576519125.840 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191216T175803/Courier0000.lzma 2019-12-16T17:58:47.846Z,1576519127.846 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0000.lzma.bak 2019-12-16T17:58:47.846Z,1576519127.846 [DataOverHttps](INFO): SBD MOMSN=12171283 2019-12-16T17:59:07.519Z,1576519147.519 [DataOverHttps](INFO): Sending 3804 bytes from file Logs/20191216T150333/Express0007.lzma 2019-12-16T17:59:09.518Z,1576519149.518 [DataOverHttps](INFO): Moved sent file to Logs/20191216T150333/Express0007.lzma.bak 2019-12-16T17:59:09.519Z,1576519149.519 [DataOverHttps](INFO): SBD MOMSN=12171286 2019-12-16T17:59:27.308Z,1576519167.308 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191216T175803/Express0001.lzma 2019-12-16T17:59:29.314Z,1576519169.314 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0001.lzma.bak 2019-12-16T17:59:29.314Z,1576519169.314 [DataOverHttps](INFO): SBD MOMSN=12171336 2019-12-16T17:59:30.739Z,1576519170.739 [spiral_cast:NeedComms:D] Stopped 2019-12-16T17:59:30.739Z,1576519170.739 [spiral_cast:NeedComms:E] Running Loop=1 2019-12-16T17:59:32.720Z,1576519172.720 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175305.00,A,3647.78894,N,12150.85585,W,0.428,246.46,161219,,,A*77 2019-12-16T17:59:32.722Z,1576519172.722 [NAL9602](INFO): GPS fix at 20191216T175305: (36.796482, -121.847598) 2019-12-16T17:59:32.799Z,1576519172.799 [spiral_cast:NeedComms:E] Stopped 2019-12-16T17:59:32.800Z,1576519172.800 [spiral_cast:NeedComms](INFO): Completed spiral_cast:NeedComms 2019-12-16T17:59:32.800Z,1576519172.800 [spiral_cast:NeedComms] Stopped 2019-12-16T17:59:32.800Z,1576519172.800 [spiral_cast:NeedComms](DEBUG): Aggregate::uninitialize spiral_cast:NeedComms 2019-12-16T17:59:32.800Z,1576519172.800 [spiral_cast:NeedComms:B.GoToSurface] Stopped 2019-12-16T17:59:32.800Z,1576519172.800 [spiral_cast:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T17:59:33.177Z,1576519173.177 [spiral_cast:CastComplete](INFO): Completed spiral_cast:CastComplete 2019-12-16T17:59:33.177Z,1576519173.177 [spiral_cast:CastComplete] Stopped 2019-12-16T17:59:33.177Z,1576519173.177 [spiral_cast:CastComplete](DEBUG): Aggregate::uninitialize spiral_cast:CastComplete 2019-12-16T17:59:33.180Z,1576519173.180 [spiral_cast](INFO): Completed spiral_cast 2019-12-16T17:59:33.180Z,1576519173.180 [MissionManager](INFO): spiral_cast is completed. 2019-12-16T17:59:33.180Z,1576519173.180 [MissionManager](INFO): Uninitializing Mission spiral_cast 2019-12-16T17:59:33.180Z,1576519173.180 [spiral_cast] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast](DEBUG): Aggregate::uninitialize spiral_cast 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science](DEBUG): Aggregate::uninitialize spiral_cast:Science 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:C] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:D] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:G] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:PeakDetectChl] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize spiral_cast:Science:PeakDetectChl 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:StandardEnvelopes] Stopped 2019-12-16T17:59:33.181Z,1576519173.181 [spiral_cast:StandardEnvelopes](DEBUG): Aggregate::uninitialize spiral_cast:StandardEnvelopes 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:B.DepthEnvelope] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:I.Pitch] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:J.Buoyancy] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:K.Point] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:L.SetSpeed] Stopped 2019-12-16T17:59:33.182Z,1576519173.182 [spiral_cast:L.SetSpeed](DEBUG): Uninitialize. 2019-12-16T17:59:33.576Z,1576519173.576 [MissionManager](IMPORTANT): Started mission Default 2019-12-16T17:59:33.589Z,1576519173.589 [Default] Running Loop=1 2019-12-16T17:59:33.589Z,1576519173.589 [Default](DEBUG): Aggregate::initialize Default 2019-12-16T17:59:33.589Z,1576519173.589 [Default:B.GoToSurface] Running Loop=1 2019-12-16T17:59:33.589Z,1576519173.589 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T17:59:33.589Z,1576519173.589 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-16T17:59:33.590Z,1576519173.590 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-16T17:59:33.590Z,1576519173.590 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-16T17:59:33.590Z,1576519173.590 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T17:59:33.591Z,1576519173.591 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T17:59:33.591Z,1576519173.591 [Default:A.Wait] Running Loop=1 2019-12-16T17:59:33.591Z,1576519173.591 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-16T17:59:33.721Z,1576519173.721 [WetLabsBB2FL](INFO): Powering down 2019-12-16T17:59:34.129Z,1576519174.129 [WetLabsBB2FL](FAULT): LCB fault: Software Overcurrent. 2019-12-16T17:59:34.129Z,1576519174.129 [WetLabsBB2FL] Hardware Fault, FailCount= 1 2019-12-16T17:59:34.129Z,1576519174.129 [WetLabsBB2FL](ERROR): Hardware Fault 2019-12-16T17:59:34.568Z,1576519174.568 [CBIT](ERROR): Hardware Fault in component: WetLabsBB2FL 2019-12-16T17:59:34.568Z,1576519174.568 [CBIT](INFO): Clearing failed state for component WetLabsBB2FL 2019-12-16T17:59:34.569Z,1576519174.569 [WetLabsBB2FL] No Fault, FailCount= 1 2019-12-16T17:59:34.938Z,1576519174.938 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2 2019-12-16T17:59:34.938Z,1576519174.938 [WetLabsBB2FL](INFO): Powering up 2019-12-16T17:59:37.049Z,1576519177.049 [WetLabsBB2FL](INFO): Powering down 2019-12-16T17:59:46.890Z,1576519186.890 [Default:A.Wait](INFO): Done Waiting. 2019-12-16T17:59:46.890Z,1576519186.890 [Default:A.Wait] Stopped 2019-12-16T17:59:46.890Z,1576519186.890 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-16T17:59:47.301Z,1576519187.301 [Default:CheckIn] Running Loop=1 2019-12-16T17:59:47.301Z,1576519187.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-16T17:59:47.301Z,1576519187.301 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-16T18:00:06.255Z,1576519206.255 [NAL9602](INFO): SBD MO Status=0, MOMSN=18381, MT Status=0, MTMSN=0 2019-12-16T18:00:06.255Z,1576519206.255 [NAL9602](INFO): No messages in MT queue 2019-12-16T18:00:07.461Z,1576519207.461 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175340.00,A,3647.78834,N,12150.85607,W,0.739,239.01,161219,,,A*7D 2019-12-16T18:00:07.463Z,1576519207.463 [NAL9602](INFO): GPS fix at 20191216T175340: (36.796472, -121.847601) 2019-12-16T18:00:07.521Z,1576519207.521 [Default:CheckIn:Read_GPS] Stopped 2019-12-16T18:00:07.522Z,1576519207.522 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-16T18:00:17.286Z,1576519217.286 [DataOverHttps](INFO): Sending 277 bytes from file Logs/20191216T175803/Courier0003.lzma 2019-12-16T18:00:19.291Z,1576519219.291 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0003.lzma.bak 2019-12-16T18:00:19.291Z,1576519219.291 [DataOverHttps](INFO): SBD MOMSN=12171338 2019-12-16T18:00:36.501Z,1576519236.501 [DataOverHttps](INFO): Sending 564 bytes from file Logs/20191216T175803/Express0004.lzma 2019-12-16T18:00:38.506Z,1576519238.506 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0004.lzma.bak 2019-12-16T18:00:38.506Z,1576519238.506 [DataOverHttps](INFO): SBD MOMSN=12171342 2019-12-16T18:00:39.782Z,1576519239.782 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T18:00:39.834Z,1576519239.834 [Default:CheckIn:Read_Iridium] Stopped 2019-12-16T18:00:39.835Z,1576519239.835 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-16T18:00:39.835Z,1576519239.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-16T18:02:50.590Z,1576519370.590 [DataOverHttps](IMPORTANT): SBD MTMSN=20191216T175622 2019-12-16T18:02:58.245Z,1576519378.245 [DataOverHttps](INFO): Received command:load Science/profile_station.xml;set profile_station.NeedCommsTime 20 minute;set profile_station.YoYoMaxDepth 20 meter;set profile_station.MaxDepth 30 meter;run 2019-12-16T18:02:58.282Z,1576519378.282 [CommandLine](IMPORTANT): got command load ./Missions/Science/profile_station.xml 2019-12-16T18:02:58.283Z,1576519378.283 [MissionManager](INFO): Loading Mission: ./Missions/Science/profile_station.xml 2019-12-16T18:02:58.416Z,1576519378.416 [MissionManager](INFO): DefineArg profile_station.MissionTimeout = 4.000000 h 2019-12-16T18:02:58.458Z,1576519378.458 [MissionManager](INFO): DefineArg profile_station.NeedCommsTime = 60.000000 min 2019-12-16T18:02:58.460Z,1576519378.460 [MissionManager](INFO): DefineArg profile_station.Lat = 36.806966 arcdeg 2019-12-16T18:02:58.463Z,1576519378.463 [MissionManager](INFO): DefineArg profile_station.Lon = -121.824326 arcdeg 2019-12-16T18:02:58.465Z,1576519378.465 [MissionManager](INFO): DefineArg profile_station.Radius = 300.000000 m 2019-12-16T18:02:58.467Z,1576519378.467 [MissionManager](INFO): DefineArg profile_station.YoYoMinDepth = 2.000000 m 2019-12-16T18:02:58.469Z,1576519378.469 [MissionManager](INFO): DefineArg profile_station.YoYoMaxDepth = 200.000000 m 2019-12-16T18:02:58.472Z,1576519378.472 [MissionManager](INFO): DefineArg profile_station.YoYoMinAltitude = 7.000000 m 2019-12-16T18:02:58.493Z,1576519378.493 [MissionManager](INFO): DefineArg profile_station.YoYoPitch = 20.000000 arcdeg 2019-12-16T18:02:58.496Z,1576519378.496 [MissionManager](INFO): DefineArg profile_station.Speed = 1.000000 m/s 2019-12-16T18:02:58.498Z,1576519378.498 [MissionManager](INFO): DefineArg profile_station.CircleMaxError = 100.000000 m 2019-12-16T18:02:58.500Z,1576519378.500 [MissionManager](INFO): DefineArg profile_station.CircleTurnToPort = 0 bool 2019-12-16T18:02:58.518Z,1576519378.518 [MissionManager](INFO): DefineArg profile_station.KwpHeading = 0.010000 rad/m 2019-12-16T18:02:58.521Z,1576519378.521 [MissionManager](INFO): DefineArg profile_station.MinAltitude = 5.000000 m 2019-12-16T18:02:58.523Z,1576519378.523 [MissionManager](INFO): DefineArg profile_station.MaxDepth = 205.000000 m 2019-12-16T18:02:58.525Z,1576519378.525 [MissionManager](INFO): DefineArg profile_station.MinOffshore = 2.000000 km 2019-12-16T18:02:58.526Z,1576519378.526 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2019-12-16T18:02:58.853Z,1576519378.853 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUS = 0 bool 2019-12-16T18:02:58.856Z,1576519378.856 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2019-12-16T18:02:58.887Z,1576519378.887 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSminPitch = -60.000000 arcdeg 2019-12-16T18:02:58.897Z,1576519378.897 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectChlActive = 0 bool 2019-12-16T18:02:58.899Z,1576519378.899 [MissionManager](INFO): DefineArg profile_station:Science.TimeWindowPeakReport = nan min 2019-12-16T18:02:58.926Z,1576519378.926 [MissionManager](INFO): DefineArg profile_station:Science.HighestChlPeakReportActive = 0 bool 2019-12-16T18:02:58.928Z,1576519378.928 [MissionManager](INFO): DefineArg profile_station:Science.PatchTracking = 0 bool 2019-12-16T18:02:58.936Z,1576519378.936 [MissionManager](INFO): DefineArg profile_station:Science.FilterWidthHorizontal = 3.000000 count 2019-12-16T18:02:58.939Z,1576519378.939 [MissionManager](INFO): DefineArg profile_station:Science.NumProfilesSlidingwindow = 100.000000 count 2019-12-16T18:02:58.953Z,1576519378.953 [MissionManager](INFO): DefineArg profile_station:Science.OffPeakFractionHorizontal = 80.000000 % 2019-12-16T18:02:58.956Z,1576519378.956 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectNO3Active = 0 bool 2019-12-16T18:02:58.977Z,1576519378.977 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectOilActive = 0 bool 2019-12-16T18:02:58.980Z,1576519378.980 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectFDOMActive = 0 bool 2019-12-16T18:02:58.982Z,1576519378.982 [MissionManager](INFO): DefineArg profile_station:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2019-12-16T18:02:58.985Z,1576519378.985 [MissionManager](INFO): DefineArg profile_station:Science.EnabledAanderaaO2 = 0.000000 bool 2019-12-16T18:02:58.988Z,1576519378.988 [MissionManager](INFO): DefineArg profile_station:Science.EnabledNeilBrown = 0.000000 bool 2019-12-16T18:02:58.998Z,1576519378.998 [MissionManager](INFO): DefineArg profile_station:Science.EnabledSeabird = 1.000000 bool 2019-12-16T18:02:59.001Z,1576519379.001 [MissionManager](INFO): DefineArg profile_station:Science.EnabledTurbulence_NPS = 0.000000 bool 2019-12-16T18:02:59.026Z,1576519379.026 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsBB2FL = 1.000000 bool 2019-12-16T18:02:59.029Z,1576519379.029 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool 2019-12-16T18:02:59.031Z,1576519379.031 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsUBAT = 0.000000 bool 2019-12-16T18:02:59.053Z,1576519379.053 [MissionManager](INFO): DefineArg profile_station:Science.EnabledISUS = 0.000000 bool 2019-12-16T18:02:59.055Z,1576519379.055 [MissionManager](INFO): DefineArg profile_station:Science.LowPassWindowLength = 20.000000 count 2019-12-16T18:02:59.062Z,1576519379.062 [MissionManager](INFO): DefineArg profile_station:Science.MedianFilterLen = 5.000000 count 2019-12-16T18:02:59.064Z,1576519379.064 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlShallowBound = nan m 2019-12-16T18:02:59.071Z,1576519379.071 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlDeepBound = nan m 2019-12-16T18:02:59.085Z,1576519379.085 [MissionManager](INFO): DefineArg profile_station:Science.PeakShallowBound = nan m 2019-12-16T18:02:59.087Z,1576519379.087 [MissionManager](INFO): DefineArg profile_station:Science.PeakDeepBound = nan m 2019-12-16T18:02:59.108Z,1576519379.108 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChl = 0.000000 ug/l 2019-12-16T18:02:59.118Z,1576519379.118 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlDepth = 0.000000 m 2019-12-16T18:02:59.129Z,1576519379.129 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlTemperature = 0.000000 degC 2019-12-16T18:02:59.132Z,1576519379.132 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLatitude = nan arcdeg 2019-12-16T18:02:59.143Z,1576519379.143 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLongitude = nan arcdeg 2019-12-16T18:02:59.186Z,1576519379.186 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3 = 0.000000 umol/l 2019-12-16T18:02:59.188Z,1576519379.188 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Depth = 0.000000 m 2019-12-16T18:02:59.203Z,1576519379.203 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Latitude = nan arcdeg 2019-12-16T18:02:59.210Z,1576519379.210 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Longitude = nan arcdeg 2019-12-16T18:02:59.212Z,1576519379.212 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChl = 0.000000 m 2019-12-16T18:02:59.242Z,1576519379.242 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDepth = 0.000000 m 2019-12-16T18:02:59.244Z,1576519379.244 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLatitude = nan arcdeg 2019-12-16T18:02:59.254Z,1576519379.254 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLongitude = nan arcdeg 2019-12-16T18:02:59.256Z,1576519379.256 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDistance = nan m 2019-12-16T18:02:59.259Z,1576519379.259 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOil = 0.000000 kg/m3 2019-12-16T18:02:59.273Z,1576519379.273 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilDepth = 0.000000 m 2019-12-16T18:02:59.276Z,1576519379.276 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLatitude = nan arcdeg 2019-12-16T18:02:59.278Z,1576519379.278 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLongitude = nan arcdeg 2019-12-16T18:02:59.281Z,1576519379.281 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOM = 0.000000 ppb 2019-12-16T18:02:59.283Z,1576519379.283 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMDepth = 0.000000 m 2019-12-16T18:02:59.298Z,1576519379.298 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLatitude = nan arcdeg 2019-12-16T18:02:59.300Z,1576519379.300 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLongitude = nan arcdeg 2019-12-16T18:02:59.303Z,1576519379.303 [MissionManager](INFO): DefineOutput profile_station:Science.PatchFDOMDistance = nan m 2019-12-16T18:02:59.331Z,1576519379.331 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-16T18:02:59.354Z,1576519379.354 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2019-12-16T18:02:59.382Z,1576519379.382 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-16T18:02:59.402Z,1576519379.402 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-16T18:02:59.411Z,1576519379.411 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-16T18:02:59.422Z,1576519379.422 [MissionManager](INFO): RedefineArg profile_station:Science.SampleISUS = value:1 bool 2019-12-16T18:02:59.424Z,1576519379.424 [MissionManager](INFO): RedefineArg profile_station:Science.PeakDetectChlActive = value:1 bool 2019-12-16T18:02:59.424Z,1576519379.424 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml 2019-12-16T18:02:59.461Z,1576519379.461 [MissionManager](INFO): DefineArg profile_station:NeedComms.DiveInterval = 3.000000 h 2019-12-16T18:02:59.463Z,1576519379.463 [MissionManager](INFO): DefineArg profile_station:NeedComms.WaitForPitchUp = 10.000000 min 2019-12-16T18:02:59.466Z,1576519379.466 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfacePitch = 20.000000 arcdeg 2019-12-16T18:02:59.468Z,1576519379.468 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceDepthRate = nan m/s 2019-12-16T18:02:59.471Z,1576519379.471 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceSpeed = 1.000000 m/s 2019-12-16T18:02:59.473Z,1576519379.473 [MissionManager](INFO): DefineArg profile_station:NeedComms.GPSTimeout = 7.000000 min 2019-12-16T18:02:59.475Z,1576519379.475 [MissionManager](INFO): DefineArg profile_station:NeedComms.CommsTimeout = 30.000000 min 2019-12-16T18:02:59.480Z,1576519379.480 [profile_station:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-16T18:02:59.540Z,1576519379.540 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml 2019-12-16T18:02:59.644Z,1576519379.644 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinAltitude = 5.000000 m 2019-12-16T18:02:59.646Z,1576519379.646 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MaxDepth = 200.000000 m 2019-12-16T18:02:59.648Z,1576519379.648 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinOffshore = 2000.000000 m 2019-12-16T18:02:59.670Z,1576519379.670 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2019-12-16T18:02:59.675Z,1576519379.675 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2019-12-16T18:02:59.721Z,1576519379.721 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2019-12-16T18:02:59.731Z,1576519379.731 [profile_station:I.Pitch](DEBUG): Construct. 2019-12-16T18:02:59.747Z,1576519379.747 [profile_station:J.Buoyancy](DEBUG): Construct Buoyancy. 2019-12-16T18:02:59.750Z,1576519379.750 [profile_station:K.SetSpeed](DEBUG): Construct. 2019-12-16T18:02:59.752Z,1576519379.752 [profile_station:L.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2019-12-16T18:02:59.768Z,1576519379.768 [profile_station:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2019-12-16T18:02:59.773Z,1576519379.773 [profile_station:N.YoYo](DEBUG): Construct YoYo. 2019-12-16T18:02:59.801Z,1576519379.801 [profile_station:CircleWrapper:B.Circle](DEBUG): Construct. 2019-12-16T18:02:59.856Z,1576519379.856 [MissionManager](DEBUG): This mission yoyos in a circle around a specified location. Maximum duration of mission 4 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications 60 The latitude of the center of the circle. 36.806966 The longitude of the center of the circle. -121.824326 Radius to circle at 300 Minimum depth while performing the YoYo behavior. 2 Maximum depth while performing the YoYo behavior. 200 Minimum altitude while performing the YoYo behavior (for bottom-terminated YoYos). 7 Pitch (plus and minus) for yo-yo behavior. 20 Vehicle speed. 1 If this distance away from the circle, drive straight towards (or away from the center). Otherwise, try to reduce distance from the ideal circle. 100 If true, vehicle turns to the left around the center point. If false, vehicle turns to the right. Used to relax waypoint cross-track error constant that is adjusted for docking. (You can override this setting by passing an argument.) 0.010 Minimum height above the sea floor for the entire mission. 5 Maximum depth for the entire mission. 205 Minimum offshore distance for the entire mission. 2 Most missions will run the science sensors. If you don't place this aggregate above NeedComms, science instruments get turned off on the last upcast and while floating on the surface. Another depth envelope for the YoYo behavior. This envelope should fall within the limits of the standard safety envelopes in Insert/StandardEnvelopes.xml in order to avoid commanding high pitch angles for depth-terminated YoYos. Another altitude envelope for the YoYo behavior. This envelope should fall within the limits of the standard safety envelopes in Insert/StandardEnvelopes.xml in order to avoid commanding high pitch angles for bottom-terminated YoYos. 2019-12-16T18:02:59.857Z,1576519379.857 [CommandLine](IMPORTANT): Loaded ./Missions/Science/profile_station.xml 2019-12-16T18:03:13.238Z,1576519393.238 [CommandLine](IMPORTANT): got command set profile_station.NeedCommsTime 20.000000 minute 2019-12-16T18:03:13.239Z,1576519393.239 [CommandLine](IMPORTANT): got command set profile_station.YoYoMaxDepth 20.000000 meter 2019-12-16T18:03:13.240Z,1576519393.240 [CommandLine](IMPORTANT): got command set profile_station.MaxDepth 30.000000 meter 2019-12-16T18:03:13.240Z,1576519393.240 [CommandLine](IMPORTANT): got command run 2019-12-16T18:03:13.242Z,1576519393.242 [CommandLine](IMPORTANT): Running 2019-12-16T18:03:13.405Z,1576519393.405 [Default] Stopped 2019-12-16T18:03:13.405Z,1576519393.405 [Default](DEBUG): Aggregate::uninitialize Default 2019-12-16T18:03:13.405Z,1576519393.405 [Default:B.GoToSurface] Stopped 2019-12-16T18:03:13.405Z,1576519393.405 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T18:03:13.405Z,1576519393.405 [Default:CheckIn] Stopped 2019-12-16T18:03:13.405Z,1576519393.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-16T18:03:13.406Z,1576519393.406 [Default:CheckIn:C.Wait] Stopped 2019-12-16T18:03:13.406Z,1576519393.406 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-16T18:03:13.406Z,1576519393.406 [MissionManager](IMPORTANT): Started mission profile_station 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station] Running Loop=1 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station](DEBUG): Aggregate::initialize profile_station 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station:Science] Running Loop=1 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station:Science](DEBUG): Aggregate::initialize profile_station:Science 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station:Science:A] Running Loop=1 2019-12-16T18:03:13.406Z,1576519393.406 [profile_station:Science:B] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:C] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:D] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:E] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:F] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:G] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:H] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:Read_Oil] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:PeakDetectChl] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectChl 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2019-12-16T18:03:13.407Z,1576519393.407 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-16T18:03:13.408Z,1576519393.408 [profile_station:Science:HighestChlPeakReport] Running Loop=1 2019-12-16T18:03:13.409Z,1576519393.409 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize profile_station:Science:HighestChlPeakReport 2019-12-16T18:03:13.409Z,1576519393.409 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2019-12-16T18:03:13.409Z,1576519393.409 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2019-12-16T18:03:13.409Z,1576519393.409 [profile_station:Science:PeakDetectNO3] Running Loop=1 2019-12-16T18:03:13.410Z,1576519393.410 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectNO3 2019-12-16T18:03:13.410Z,1576519393.410 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2019-12-16T18:03:13.410Z,1576519393.410 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-16T18:03:13.411Z,1576519393.411 [profile_station:Science:PeakDetectOil] Running Loop=1 2019-12-16T18:03:13.411Z,1576519393.411 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectOil 2019-12-16T18:03:13.411Z,1576519393.411 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2019-12-16T18:03:13.411Z,1576519393.411 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-16T18:03:13.412Z,1576519393.412 [profile_station:Science:PeakDetectFDOM] Running Loop=1 2019-12-16T18:03:13.412Z,1576519393.412 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectFDOM 2019-12-16T18:03:13.412Z,1576519393.412 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2019-12-16T18:03:13.413Z,1576519393.413 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes] Running Loop=1 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes](DEBUG): Aggregate::initialize profile_station:StandardEnvelopes 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2019-12-16T18:03:13.414Z,1576519393.414 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:I.Pitch] Running Loop=1 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:I.Pitch](DEBUG): Initialize. 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:J.Buoyancy] Running Loop=1 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:J.Buoyancy](DEBUG): Initialize Buoyancy Component. 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:K.SetSpeed] Running Loop=1 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:K.SetSpeed](DEBUG): Initialize. 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:L.DepthEnvelope] Running Loop=1 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2019-12-16T18:03:13.415Z,1576519393.415 [profile_station:M.AltitudeEnvelope] Running Loop=1 2019-12-16T18:03:13.416Z,1576519393.416 [profile_station:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2019-12-16T18:03:13.416Z,1576519393.416 [profile_station:N.YoYo] Running Loop=1 2019-12-16T18:03:13.416Z,1576519393.416 [profile_station:N.YoYo](DEBUG): Initialize YoYoComponent. 2019-12-16T18:03:13.416Z,1576519393.416 [profile_station:C] Running Loop=1 2019-12-16T18:03:13.417Z,1576519393.417 [profile_station:N.YoYo] Running Loop=1 2019-12-16T18:03:13.417Z,1576519393.417 [profile_station:M.AltitudeEnvelope] Running Loop=1 2019-12-16T18:03:13.417Z,1576519393.417 [profile_station:L.DepthEnvelope] Running Loop=1 2019-12-16T18:03:13.418Z,1576519393.418 [profile_station:K.SetSpeed] Running Loop=1 2019-12-16T18:03:13.418Z,1576519393.418 [profile_station:J.Buoyancy] Running Loop=1 2019-12-16T18:03:13.419Z,1576519393.419 [profile_station:I.Pitch] Running Loop=1 2019-12-16T18:03:13.419Z,1576519393.419 [profile_station:StandardEnvelopes] Running Loop=1 2019-12-16T18:03:13.419Z,1576519393.419 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2019-12-16T18:03:13.419Z,1576519393.419 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2019-12-16T18:03:13.419Z,1576519393.419 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2019-12-16T18:03:13.420Z,1576519393.420 [profile_station:C] Stopped 2019-12-16T18:03:13.420Z,1576519393.420 [profile_station:E] Running Loop=1 2019-12-16T18:03:13.420Z,1576519393.420 [profile_station:Science] Running Loop=1 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectFDOM] Stopped 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectFDOM 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectOil] Stopped 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectOil 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-16T18:03:13.438Z,1576519393.438 [profile_station:Science:PeakDetectNO3] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectNO3 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:HighestChlPeakReport] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize profile_station:Science:HighestChlPeakReport 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:PeakDetectChl] Running Loop=1 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:Read_Oil] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:H] Stopped 2019-12-16T18:03:13.439Z,1576519393.439 [profile_station:Science:G] Running Loop=1 2019-12-16T18:03:13.440Z,1576519393.440 [profile_station:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2019-12-16T18:03:13.440Z,1576519393.440 [profile_station:Science:F] Stopped 2019-12-16T18:03:13.440Z,1576519393.440 [profile_station:Science:E] Stopped 2019-12-16T18:03:13.440Z,1576519393.440 [profile_station:Science:D] Running Loop=1 2019-12-16T18:03:13.445Z,1576519393.445 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2019-12-16T18:03:13.445Z,1576519393.445 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2019-12-16T18:03:13.445Z,1576519393.445 [profile_station:Science:C] Running Loop=1 2019-12-16T18:03:13.446Z,1576519393.446 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2019-12-16T18:03:13.446Z,1576519393.446 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2019-12-16T18:03:13.446Z,1576519393.446 [profile_station:Science:B] Stopped 2019-12-16T18:03:13.447Z,1576519393.447 [profile_station:Science:A] Stopped 2019-12-16T18:03:13.786Z,1576519393.786 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2 2019-12-16T18:03:13.786Z,1576519393.786 [WetLabsBB2FL](INFO): Powering up 2019-12-16T18:03:13.827Z,1576519393.827 [profile_station:E] Stopped 2019-12-16T18:03:13.827Z,1576519393.827 [profile_station:F] Running Loop=1 2019-12-16T18:03:14.199Z,1576519394.199 [profile_station:F] Stopped 2019-12-16T18:03:14.199Z,1576519394.199 [profile_station:G] Running Loop=1 2019-12-16T18:03:14.434Z,1576519394.434 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-12-16T18:03:14.608Z,1576519394.608 [profile_station:G] Stopped 2019-12-16T18:03:14.608Z,1576519394.608 [profile_station:StartingMission] Running Loop=1 2019-12-16T18:03:14.608Z,1576519394.608 [profile_station:StartingMission](DEBUG): Aggregate::initialize profile_station:StartingMission 2019-12-16T18:03:15.014Z,1576519395.014 [profile_station:M.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2019-12-16T18:03:15.016Z,1576519395.016 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2019-12-16T18:03:15.016Z,1576519395.016 [profile_station:NeedComms] Running Loop=1 2019-12-16T18:03:15.016Z,1576519395.016 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T18:03:15.017Z,1576519395.017 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T18:03:15.017Z,1576519395.017 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T18:03:15.017Z,1576519395.017 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T18:03:15.018Z,1576519395.018 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T18:03:15.018Z,1576519395.018 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T18:03:15.018Z,1576519395.018 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T18:03:15.019Z,1576519395.019 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T18:03:15.019Z,1576519395.019 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T18:03:15.020Z,1576519395.020 [profile_station:NeedComms:A](INFO): last time_fix was: 1576518820.000000 second since 1970/01/01T00:00:00Z 2019-12-16T18:03:15.020Z,1576519395.020 [profile_station:NeedComms:A] Stopped 2019-12-16T18:03:15.432Z,1576519395.432 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T18:03:15.821Z,1576519395.821 [profile_station:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-12-16T18:03:17.416Z,1576519397.416 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175650.00,A,3647.78032,N,12150.85720,W,0.253,125.61,161219,,,D*77 2019-12-16T18:03:17.418Z,1576519397.418 [NAL9602](INFO): GPS fix at 20191216T175650: (36.796339, -121.847620) 2019-12-16T18:03:17.446Z,1576519397.446 [CTD_Seabird](ERROR): Failed to parse device response: 2019-12-16T18:03:17.488Z,1576519397.488 [profile_station:NeedComms:C] Stopped 2019-12-16T18:03:17.493Z,1576519397.493 [profile_station:NeedComms:D] Running Loop=1 2019-12-16T18:03:17.872Z,1576519397.872 [profile_station:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-16T18:03:25.312Z,1576519405.312 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191216T175803/Courier0006.lzma 2019-12-16T18:03:27.318Z,1576519407.318 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0006.lzma.bak 2019-12-16T18:03:27.319Z,1576519407.319 [DataOverHttps](INFO): SBD MOMSN=12171350 2019-12-16T18:03:45.340Z,1576519425.340 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191216T175803/Courier0009.lzma 2019-12-16T18:03:47.299Z,1576519427.299 [NAL9602](INFO): SBD MO Status=2, MOMSN=18382, MT Status=2, MTMSN=0 2019-12-16T18:03:47.300Z,1576519427.300 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:03:47.346Z,1576519427.346 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0009.lzma.bak 2019-12-16T18:03:47.347Z,1576519427.347 [DataOverHttps](INFO): SBD MOMSN=12171353 2019-12-16T18:04:05.441Z,1576519445.441 [DataOverHttps](INFO): Sending 317 bytes from file Logs/20191216T175803/Express0007.lzma 2019-12-16T18:04:07.446Z,1576519447.446 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0007.lzma.bak 2019-12-16T18:04:07.447Z,1576519447.447 [DataOverHttps](INFO): SBD MOMSN=12171355 2019-12-16T18:04:15.988Z,1576519455.988 [NAL9602](INFO): SBD MO Status=2, MOMSN=18382, MT Status=2, MTMSN=0 2019-12-16T18:04:15.988Z,1576519455.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:04:25.716Z,1576519465.716 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20191216T175803/Express0010.lzma 2019-12-16T18:04:27.722Z,1576519467.722 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0010.lzma.bak 2019-12-16T18:04:27.722Z,1576519467.722 [DataOverHttps](INFO): SBD MOMSN=12171366 2019-12-16T18:04:28.962Z,1576519468.962 [profile_station:NeedComms:D] Stopped 2019-12-16T18:04:28.963Z,1576519468.963 [profile_station:NeedComms:E] Running Loop=1 2019-12-16T18:04:29.363Z,1576519469.363 [profile_station:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-12-16T18:06:19.631Z,1576519579.631 [NAL9602](INFO): SBD MO Status=0, MOMSN=18382, MT Status=0, MTMSN=0 2019-12-16T18:06:19.632Z,1576519579.632 [NAL9602](INFO): No messages in MT queue 2019-12-16T18:06:20.856Z,1576519580.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175953.00,A,3647.77324,N,12150.85659,W,0.311,234.25,161219,,,D*7B 2019-12-16T18:06:20.858Z,1576519580.858 [NAL9602](INFO): GPS fix at 20191216T175953: (36.796221, -121.847610) 2019-12-16T18:06:20.885Z,1576519580.885 [profile_station:NeedComms:E] Stopped 2019-12-16T18:06:20.886Z,1576519580.886 [profile_station:NeedComms](INFO): Completed profile_station:NeedComms 2019-12-16T18:06:20.886Z,1576519580.886 [profile_station:NeedComms] Stopped 2019-12-16T18:06:20.887Z,1576519580.887 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T18:06:20.887Z,1576519580.887 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T18:06:20.887Z,1576519580.887 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T18:06:21.299Z,1576519581.299 [profile_station:StartingMission](INFO): Completed profile_station:StartingMission 2019-12-16T18:06:21.300Z,1576519581.300 [profile_station:StartingMission] Stopped 2019-12-16T18:06:21.300Z,1576519581.300 [profile_station:StartingMission](DEBUG): Aggregate::uninitialize profile_station:StartingMission 2019-12-16T18:06:21.300Z,1576519581.300 [profile_station:CircleWrapper] Running Loop=1 2019-12-16T18:06:21.300Z,1576519581.300 [profile_station:CircleWrapper](DEBUG): Aggregate::initialize profile_station:CircleWrapper 2019-12-16T18:06:21.300Z,1576519581.300 [profile_station:CircleWrapper:A] Running Loop=1 2019-12-16T18:06:21.301Z,1576519581.301 [profile_station:CircleWrapper:B.Circle] Running Loop=1 2019-12-16T18:06:21.301Z,1576519581.301 [profile_station:CircleWrapper:B.Circle](DEBUG): Initialize CircleComponent. 2019-12-16T18:06:21.689Z,1576519581.689 [profile_station:CircleWrapper:A] Running Loop=1 2019-12-16T18:06:53.574Z,1576519613.574 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T18:07:21.872Z,1576519641.872 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch -20.00 deg, mass-position -9.00 mm (4 active estimators). 2019-12-16T18:08:01.877Z,1576519681.877 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:08:22.401Z,1576519702.401 [Radio_Surface](INFO): Powering down 2019-12-16T18:08:33.001Z,1576519713.001 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:08:34.006Z,1576519714.006 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-12-16T18:10:12.397Z,1576519812.397 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.725494 2019-12-16T18:23:13.398Z,1576520593.398 [CTD_Seabird](ERROR): Failed to parse device response: .78 2019-12-16T18:27:06.896Z,1576520826.896 [profile_station:NeedComms] Running Loop=1 2019-12-16T18:27:06.896Z,1576520826.896 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T18:27:06.896Z,1576520826.896 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T18:27:06.896Z,1576520826.896 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T18:27:06.896Z,1576520826.896 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T18:27:06.897Z,1576520826.897 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T18:27:06.897Z,1576520826.897 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T18:27:06.898Z,1576520826.898 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T18:27:06.898Z,1576520826.898 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T18:27:06.898Z,1576520826.898 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T18:27:06.900Z,1576520826.900 [profile_station:NeedComms:A](INFO): last time_fix was: 1576519193.000000 second since 1970/01/01T00:00:00Z 2019-12-16T18:27:06.900Z,1576520826.900 [profile_station:NeedComms:A] Stopped 2019-12-16T18:28:13.707Z,1576520893.707 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T18:28:14.265Z,1576520894.265 [Radio_Surface](INFO): Powering up 2019-12-16T18:28:19.957Z,1576520899.957 [DataOverHttps](INFO): Radio surface powered ON. 2019-12-16T18:28:47.255Z,1576520927.255 [NAL9602](INFO): SBD MO Status=0, MOMSN=18383, MT Status=0, MTMSN=0 2019-12-16T18:28:47.255Z,1576520927.255 [NAL9602](INFO): No messages in MT queue 2019-12-16T18:28:48.468Z,1576520928.468 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182218.00,A,3648.01895,N,12150.13179,W,0.428,50.10,161219,,,A*4C 2019-12-16T18:28:48.470Z,1576520928.470 [NAL9602](INFO): GPS fix at 20191216T182218: (36.800316, -121.835530) 2019-12-16T18:28:48.516Z,1576520928.516 [UniversalFixResidualReporter](INFO): Fix residual: 12.2 %DT, over the last 1236.5 m. Residual distance 151.2 m at bearing 0.4 degrees. Fix at (36.8003, -121.8355) with 1168.0 m made good. 2019-12-16T18:28:48.530Z,1576520928.530 [profile_station:NeedComms:C] Stopped 2019-12-16T18:28:48.530Z,1576520928.530 [profile_station:NeedComms:D] Running Loop=1 2019-12-16T18:28:50.077Z,1576520930.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:29:07.590Z,1576520947.590 [NAL9602](INFO): SBD MO Status=1, MOMSN=18384, MT Status=0, MTMSN=0 2019-12-16T18:29:07.653Z,1576520947.653 [NAL9602](INFO): Sent 72 bytes from file Logs/20191216T175803/Courier0012.lzma 2019-12-16T18:29:07.653Z,1576520947.653 [NAL9602](INFO): Packets left to send: 0 2019-12-16T18:29:21.205Z,1576520961.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:29:24.247Z,1576520964.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=18385, MT Status=2, MTMSN=0 2019-12-16T18:29:24.248Z,1576520964.248 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:29:41.748Z,1576520981.748 [NAL9602](INFO): SBD MO Status=1, MOMSN=18385, MT Status=0, MTMSN=0 2019-12-16T18:29:41.797Z,1576520981.797 [NAL9602](INFO): Sent 332 bytes from file Logs/20191216T175803/Express0013.lzma 2019-12-16T18:29:41.797Z,1576520981.797 [NAL9602](INFO): Packets left to send: 1 2019-12-16T18:29:52.329Z,1576520992.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:29:55.207Z,1576520995.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:29:55.207Z,1576520995.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:30:13.120Z,1576521013.120 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:30:13.121Z,1576521013.121 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:30:23.453Z,1576521023.453 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:30:54.577Z,1576521054.577 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:31:13.842Z,1576521073.842 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:31:13.842Z,1576521073.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:31:25.709Z,1576521085.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:31:39.802Z,1576521099.802 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:31:39.803Z,1576521099.803 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:31:57.194Z,1576521117.194 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004114 2019-12-16T18:32:05.298Z,1576521125.298 [DataOverHttps](INFO): Sending 568 bytes from file Logs/20191216T175803/Express0013.lzma 2019-12-16T18:32:07.302Z,1576521127.302 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0013.lzma.bak 2019-12-16T18:32:07.303Z,1576521127.303 [DataOverHttps](INFO): SBD MOMSN=12171460 2019-12-16T18:32:08.676Z,1576521128.676 [profile_station:NeedComms:D] Stopped 2019-12-16T18:32:08.676Z,1576521128.676 [profile_station:NeedComms:E] Running Loop=1 2019-12-16T18:32:17.113Z,1576521137.113 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:32:17.114Z,1576521137.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:32:18.348Z,1576521138.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182548.00,A,3648.01552,N,12150.13277,W,0.816,207.84,161219,,,A*79 2019-12-16T18:32:18.350Z,1576521138.350 [NAL9602](INFO): GPS fix at 20191216T182548: (36.800259, -121.835546) 2019-12-16T18:32:18.404Z,1576521138.404 [profile_station:NeedComms:E] Stopped 2019-12-16T18:32:18.405Z,1576521138.405 [profile_station:NeedComms](INFO): Completed profile_station:NeedComms 2019-12-16T18:32:18.405Z,1576521138.405 [profile_station:NeedComms] Stopped 2019-12-16T18:32:18.406Z,1576521138.406 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T18:32:18.406Z,1576521138.406 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T18:32:18.406Z,1576521138.406 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T18:32:19.165Z,1576521139.165 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position -9.00 mm. 2019-12-16T18:32:51.045Z,1576521171.045 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T18:33:31.514Z,1576521211.514 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position -9.00 mm (4 active estimators). 2019-12-16T18:33:40.410Z,1576521220.410 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:33:44.553Z,1576521224.553 [Radio_Surface](INFO): Powering down 2019-12-16T18:34:11.533Z,1576521251.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:34:12.537Z,1576521252.537 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-12-16T18:35:17.801Z,1576521317.801 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.299759 2019-12-16T18:39:26.643Z,1576521566.643 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-16T18:39:26.645Z,1576521566.645 [BPC1](INFO): Received data from all battery sticks. 2019-12-16T18:41:54.087Z,1576521714.087 [CTD_Seabird](ERROR): Failed to parse device response: ,13.6463,3.97196,3740.65 2019-12-16T18:52:40.936Z,1576522360.936 [profile_station:NeedComms] Running Loop=1 2019-12-16T18:52:40.936Z,1576522360.936 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T18:52:40.936Z,1576522360.936 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T18:52:40.936Z,1576522360.936 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T18:52:40.936Z,1576522360.936 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T18:52:40.937Z,1576522360.937 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T18:52:40.937Z,1576522360.937 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T18:52:40.938Z,1576522360.938 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T18:52:40.938Z,1576522360.938 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T18:52:40.938Z,1576522360.938 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T18:52:40.940Z,1576522360.940 [profile_station:NeedComms:A](INFO): last time_fix was: 1576520748.000000 second since 1970/01/01T00:00:00Z 2019-12-16T18:52:40.940Z,1576522360.940 [profile_station:NeedComms:A] Stopped 2019-12-16T18:53:49.319Z,1576522429.319 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T18:53:49.817Z,1576522429.817 [Radio_Surface](INFO): Powering up 2019-12-16T18:53:55.469Z,1576522435.469 [DataOverHttps](INFO): Radio surface powered ON. 2019-12-16T18:54:25.589Z,1576522465.589 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:54:44.419Z,1576522484.419 [NAL9602](INFO): SBD MO Status=2, MOMSN=18386, MT Status=2, MTMSN=0 2019-12-16T18:54:44.419Z,1576522484.419 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:54:56.722Z,1576522496.722 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:55:13.918Z,1576522513.918 [NAL9602](INFO): SBD MO Status=1, MOMSN=18386, MT Status=0, MTMSN=0 2019-12-16T18:55:13.918Z,1576522513.918 [NAL9602](INFO): No messages in MT queue 2019-12-16T18:55:15.128Z,1576522515.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184842.00,A,3648.41894,N,12149.63072,W,0.428,17.49,161219,,,D*45 2019-12-16T18:55:15.130Z,1576522515.130 [NAL9602](INFO): GPS fix at 20191216T184842: (36.806982, -121.827179) 2019-12-16T18:55:15.169Z,1576522515.169 [UniversalFixResidualReporter](INFO): Fix residual: 10.2 %DT, over the last 1218.4 m. Residual distance 124.2 m at bearing -16.3 degrees. Fix at (36.8070, -121.8272) with 1055.4 m made good. 2019-12-16T18:55:15.170Z,1576522515.170 [profile_station:CircleWrapper:B.Circle] Stopped 2019-12-16T18:55:15.170Z,1576522515.170 [profile_station:CircleWrapper:B.Circle](DEBUG): Uninitialize. 2019-12-16T18:55:15.171Z,1576522515.171 [profile_station:CircleWrapper](INFO): Completed profile_station:CircleWrapper 2019-12-16T18:55:15.171Z,1576522515.171 [profile_station:CircleWrapper] Stopped 2019-12-16T18:55:15.171Z,1576522515.171 [profile_station:CircleWrapper](DEBUG): Aggregate::uninitialize profile_station:CircleWrapper 2019-12-16T18:55:15.171Z,1576522515.171 [profile_station:CircleWrapper:A] Stopped 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper](INFO): Running loop #2 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper] Running Loop=2 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper](DEBUG): Aggregate::initialize profile_station:CircleWrapper 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper:A] Running Loop=1 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper:B.Circle] Running Loop=1 2019-12-16T18:55:15.172Z,1576522515.172 [profile_station:CircleWrapper:B.Circle](DEBUG): Initialize CircleComponent. 2019-12-16T18:55:15.183Z,1576522515.183 [profile_station:NeedComms:C] Stopped 2019-12-16T18:55:15.183Z,1576522515.183 [profile_station:NeedComms:D] Running Loop=1 2019-12-16T18:55:27.845Z,1576522527.845 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:55:33.459Z,1576522533.459 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:55:33.459Z,1576522533.459 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:55:58.969Z,1576522558.969 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:56:22.823Z,1576522582.823 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:56:22.824Z,1576522582.824 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:56:30.093Z,1576522590.093 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:56:45.983Z,1576522605.983 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:56:45.984Z,1576522605.984 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:57:01.217Z,1576522621.217 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:57:11.091Z,1576522631.091 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:57:11.091Z,1576522631.091 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:57:28.519Z,1576522648.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:57:28.519Z,1576522648.519 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:57:31.614Z,1576522651.614 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004065 2019-12-16T18:57:39.425Z,1576522659.425 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20191216T175803/Courier0015.lzma 2019-12-16T18:57:41.430Z,1576522661.430 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0015.lzma.bak 2019-12-16T18:57:41.431Z,1576522661.431 [DataOverHttps](INFO): SBD MOMSN=12171530 2019-12-16T18:57:54.503Z,1576522674.503 [NAL9602](INFO): SBD MO Status=2, MOMSN=18387, MT Status=2, MTMSN=0 2019-12-16T18:57:54.504Z,1576522674.504 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T18:57:59.618Z,1576522679.618 [DataOverHttps](INFO): Sending 734 bytes from file Logs/20191216T175803/Express0016.lzma 2019-12-16T18:58:01.622Z,1576522681.622 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0016.lzma.bak 2019-12-16T18:58:01.622Z,1576522681.622 [DataOverHttps](INFO): SBD MOMSN=12171538 2019-12-16T18:58:03.022Z,1576522683.022 [profile_station:NeedComms:D] Stopped 2019-12-16T18:58:03.022Z,1576522683.022 [profile_station:NeedComms:E] Running Loop=1 2019-12-16T18:58:05.004Z,1576522685.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185132.00,A,3648.41612,N,12149.63046,W,0.525,131.22,161219,,,D*79 2019-12-16T18:58:05.006Z,1576522685.006 [NAL9602](INFO): GPS fix at 20191216T185132: (36.806935, -121.827174) 2019-12-16T18:58:05.095Z,1576522685.095 [profile_station:NeedComms:E] Stopped 2019-12-16T18:58:05.096Z,1576522685.096 [profile_station:NeedComms](INFO): Completed profile_station:NeedComms 2019-12-16T18:58:05.096Z,1576522685.096 [profile_station:NeedComms] Stopped 2019-12-16T18:58:05.096Z,1576522685.096 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T18:58:05.096Z,1576522685.096 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T18:58:05.096Z,1576522685.096 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T18:58:37.341Z,1576522717.341 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T18:59:35.307Z,1576522775.307 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T18:59:36.885Z,1576522776.885 [Radio_Surface](INFO): Powering down 2019-12-16T19:00:06.442Z,1576522806.442 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:00:07.445Z,1576522807.445 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-12-16T19:01:12.705Z,1576522872.705 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.337524 2019-12-16T19:05:03.693Z,1576523103.693 [ThrusterServo](FAULT): Overload Error 2019-12-16T19:05:03.693Z,1576523103.693 [ThrusterServo] Hardware Fault, FailCount= 1 2019-12-16T19:05:03.693Z,1576523103.693 [ThrusterServo](ERROR): Hardware Fault 2019-12-16T19:05:03.697Z,1576523103.697 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2019-12-16T19:05:04.105Z,1576523104.105 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-12-16T19:05:04.105Z,1576523104.105 [ThrusterServo](INFO): Powering down 2019-12-16T19:05:04.898Z,1576523104.898 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-12-16T19:05:05.015Z,1576523105.015 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-12-16T19:05:05.018Z,1576523105.018 [CBIT](INFO): Clearing failed state for component ThrusterServo 2019-12-16T19:05:05.019Z,1576523105.019 [ThrusterServo] No Fault, FailCount= 1 2019-12-16T19:18:21.543Z,1576523901.543 [profile_station:NeedComms] Running Loop=1 2019-12-16T19:18:21.543Z,1576523901.543 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T19:18:21.543Z,1576523901.543 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T19:18:21.543Z,1576523901.543 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T19:18:21.543Z,1576523901.543 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T19:18:21.544Z,1576523901.544 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T19:18:21.544Z,1576523901.544 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T19:18:21.544Z,1576523901.544 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T19:18:21.545Z,1576523901.545 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T19:18:21.545Z,1576523901.545 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T19:18:21.546Z,1576523901.546 [profile_station:NeedComms:A](INFO): last time_fix was: 1576522292.000000 second since 1970/01/01T00:00:00Z 2019-12-16T19:18:21.546Z,1576523901.546 [profile_station:NeedComms:A] Stopped 2019-12-16T19:19:29.062Z,1576523969.062 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T19:19:29.609Z,1576523969.609 [Radio_Surface](INFO): Powering up 2019-12-16T19:19:35.329Z,1576523975.329 [DataOverHttps](INFO): Radio surface powered ON. 2019-12-16T19:20:05.449Z,1576524005.449 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:20:36.573Z,1576524036.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:21:01.571Z,1576524061.571 [NAL9602](INFO): SBD MO Status=1, MOMSN=18387, MT Status=0, MTMSN=0 2019-12-16T19:21:01.572Z,1576524061.572 [NAL9602](INFO): No messages in MT queue 2019-12-16T19:21:02.768Z,1576524062.768 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191428.00,A,3648.26652,N,12149.30327,W,0.292,151.04,161219,,,A*79 2019-12-16T19:21:02.770Z,1576524062.770 [NAL9602](INFO): GPS fix at 20191216T191428: (36.804442, -121.821721) 2019-12-16T19:21:02.831Z,1576524062.831 [UniversalFixResidualReporter](INFO): Fix residual: 7.2 %DT, over the last 1209.4 m. Residual distance 87.5 m at bearing -0.8 degrees. Fix at (36.8044, -121.8217) with 559.1 m made good. 2019-12-16T19:21:02.850Z,1576524062.850 [profile_station:NeedComms:C] Stopped 2019-12-16T19:21:02.851Z,1576524062.851 [profile_station:NeedComms:D] Running Loop=1 2019-12-16T19:21:07.697Z,1576524067.697 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:21:24.746Z,1576524084.746 [NAL9602](INFO): SBD MO Status=2, MOMSN=18388, MT Status=2, MTMSN=0 2019-12-16T19:21:24.746Z,1576524084.746 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:21:38.837Z,1576524098.837 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:21:47.535Z,1576524107.535 [NAL9602](INFO): SBD MO Status=1, MOMSN=18388, MT Status=0, MTMSN=0 2019-12-16T19:21:47.593Z,1576524107.593 [NAL9602](INFO): Sent 72 bytes from file Logs/20191216T175803/Courier0018.lzma 2019-12-16T19:21:47.593Z,1576524107.593 [NAL9602](INFO): Packets left to send: 0 2019-12-16T19:22:08.235Z,1576524128.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=18389, MT Status=2, MTMSN=0 2019-12-16T19:22:08.236Z,1576524128.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:22:09.961Z,1576524129.961 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:22:30.603Z,1576524150.603 [NAL9602](INFO): SBD MO Status=1, MOMSN=18389, MT Status=0, MTMSN=0 2019-12-16T19:22:30.653Z,1576524150.653 [NAL9602](INFO): Sent 332 bytes from file Logs/20191216T175803/Express0019.lzma 2019-12-16T19:22:30.653Z,1576524150.653 [NAL9602](INFO): Packets left to send: 2 2019-12-16T19:22:41.093Z,1576524161.093 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:22:48.191Z,1576524168.191 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:22:48.191Z,1576524168.191 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:23:11.368Z,1576524191.368 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:23:11.368Z,1576524191.368 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:23:12.730Z,1576524192.730 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004077 2019-12-16T19:23:21.115Z,1576524201.115 [DataOverHttps](INFO): Sending 886 bytes from file Logs/20191216T175803/Express0019.lzma 2019-12-16T19:23:23.118Z,1576524203.118 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0019.lzma.bak 2019-12-16T19:23:23.119Z,1576524203.119 [DataOverHttps](INFO): SBD MOMSN=12171614 2019-12-16T19:23:24.322Z,1576524204.322 [profile_station:NeedComms:D] Stopped 2019-12-16T19:23:24.322Z,1576524204.322 [profile_station:NeedComms:E] Running Loop=1 2019-12-16T19:23:26.308Z,1576524206.308 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191651.00,A,3648.25996,N,12149.31105,W,0.272,202.70,161219,,,A*7A 2019-12-16T19:23:26.310Z,1576524206.310 [NAL9602](INFO): GPS fix at 20191216T191651: (36.804333, -121.821851) 2019-12-16T19:23:26.388Z,1576524206.388 [profile_station:NeedComms:E] Stopped 2019-12-16T19:23:26.397Z,1576524206.397 [profile_station:NeedComms](INFO): Completed profile_station:NeedComms 2019-12-16T19:23:26.397Z,1576524206.397 [profile_station:NeedComms] Stopped 2019-12-16T19:23:26.397Z,1576524206.397 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T19:23:26.397Z,1576524206.397 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T19:23:26.397Z,1576524206.397 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T19:23:58.627Z,1576524238.627 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T19:24:25.301Z,1576524265.301 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:24:52.941Z,1576524292.941 [Radio_Surface](INFO): Powering down 2019-12-16T19:24:56.433Z,1576524296.433 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:24:57.437Z,1576524297.437 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-12-16T19:26:34.833Z,1576524394.833 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.735458 2019-12-16T19:36:35.025Z,1576524995.025 [profile_station:CircleWrapper:B.Circle] Stopped 2019-12-16T19:36:35.025Z,1576524995.025 [profile_station:CircleWrapper:B.Circle](DEBUG): Uninitialize. 2019-12-16T19:36:35.026Z,1576524995.026 [profile_station:CircleWrapper](INFO): Completed profile_station:CircleWrapper 2019-12-16T19:36:35.026Z,1576524995.026 [profile_station:CircleWrapper] Stopped 2019-12-16T19:36:35.026Z,1576524995.026 [profile_station:CircleWrapper](DEBUG): Aggregate::uninitialize profile_station:CircleWrapper 2019-12-16T19:36:35.026Z,1576524995.026 [profile_station:CircleWrapper:A] Stopped 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper](INFO): Running loop #3 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper] Running Loop=3 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper](DEBUG): Aggregate::initialize profile_station:CircleWrapper 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper:A] Running Loop=1 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper:B.Circle] Running Loop=1 2019-12-16T19:36:35.027Z,1576524995.027 [profile_station:CircleWrapper:B.Circle](DEBUG): Initialize CircleComponent. 2019-12-16T19:43:55.904Z,1576525435.904 [profile_station:NeedComms] Running Loop=1 2019-12-16T19:43:55.904Z,1576525435.904 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T19:43:55.904Z,1576525435.904 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T19:43:55.904Z,1576525435.904 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T19:43:55.905Z,1576525435.905 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T19:43:55.905Z,1576525435.905 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T19:43:55.906Z,1576525435.906 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T19:43:55.906Z,1576525435.906 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T19:43:55.906Z,1576525435.906 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T19:43:55.907Z,1576525435.907 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T19:43:55.908Z,1576525435.908 [profile_station:NeedComms:A](INFO): last time_fix was: 1576523811.000000 second since 1970/01/01T00:00:00Z 2019-12-16T19:43:55.908Z,1576525435.908 [profile_station:NeedComms:A] Stopped 2019-12-16T19:45:04.103Z,1576525504.103 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T19:45:04.685Z,1576525504.685 [Radio_Surface](INFO): Powering up 2019-12-16T19:45:06.055Z,1576525506.055 [CTD_Seabird](ERROR): Salinity reading out of range: 27.816793 psu 2019-12-16T19:45:07.059Z,1576525507.059 [CTD_Seabird](ERROR): Salinity reading out of range: 18.490700 psu 2019-12-16T19:45:10.509Z,1576525510.509 [DataOverHttps](INFO): Radio surface powered ON. 2019-12-16T19:45:40.625Z,1576525540.625 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:46:11.757Z,1576525571.757 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:46:29.417Z,1576525589.417 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:46:29.417Z,1576525589.417 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:46:42.897Z,1576525602.897 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:46:54.880Z,1576525614.880 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-16T19:46:54.882Z,1576525614.882 [BPC1](INFO): Received data from all battery sticks. 2019-12-16T19:47:01.327Z,1576525621.327 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:47:01.327Z,1576525621.327 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:47:14.021Z,1576525634.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:47:18.703Z,1576525638.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:47:18.703Z,1576525638.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:47:45.145Z,1576525665.145 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:47:59.099Z,1576525679.099 [NAL9602](INFO): SBD MO Status=2, MOMSN=18390, MT Status=2, MTMSN=0 2019-12-16T19:47:59.099Z,1576525679.099 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T19:48:16.277Z,1576525696.277 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:48:47.846Z,1576525727.846 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2019-12-16T19:48:58.085Z,1576525738.085 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004043 2019-12-16T19:50:08.788Z,1576525808.788 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-16T19:50:13.644Z,1576525813.644 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194336.00,A,3648.51534,N,12149.39666,W,0.233,226.17,161219,,,A*74 2019-12-16T19:50:13.646Z,1576525813.646 [NAL9602](INFO): GPS fix at 20191216T194336: (36.808589, -121.823278) 2019-12-16T19:50:13.700Z,1576525813.700 [UniversalFixResidualReporter](INFO): Fix residual: 11.2 %DT, over the last 1235.3 m. Residual distance 138.7 m at bearing -31.2 degrees. Fix at (36.8086, -121.8233) with 490.0 m made good. 2019-12-16T19:50:13.713Z,1576525813.713 [profile_station:NeedComms:C] Stopped 2019-12-16T19:50:13.714Z,1576525813.714 [profile_station:NeedComms:D] Running Loop=1 2019-12-16T19:50:21.876Z,1576525821.876 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20191216T175803/Courier0021.lzma 2019-12-16T19:50:23.882Z,1576525823.882 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0021.lzma.bak 2019-12-16T19:50:23.883Z,1576525823.883 [DataOverHttps](INFO): SBD MOMSN=12171662 2019-12-16T19:50:42.115Z,1576525842.115 [DataOverHttps](INFO): Sending 956 bytes from file Logs/20191216T175803/Express0022.lzma 2019-12-16T19:50:44.119Z,1576525844.119 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0022.lzma.bak 2019-12-16T19:50:44.119Z,1576525844.119 [DataOverHttps](INFO): SBD MOMSN=12171669 2019-12-16T19:50:45.258Z,1576525845.258 [profile_station:NeedComms:D] Stopped 2019-12-16T19:50:45.258Z,1576525845.258 [profile_station:NeedComms:E] Running Loop=1 2019-12-16T19:50:47.219Z,1576525847.219 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194409.00,A,3648.51409,N,12149.39753,W,0.564,214.80,161219,,,A*7D 2019-12-16T19:50:47.226Z,1576525847.226 [NAL9602](INFO): GPS fix at 20191216T194409: (36.808568, -121.823292) 2019-12-16T19:50:47.294Z,1576525847.294 [profile_station:NeedComms:E] Stopped 2019-12-16T19:50:47.301Z,1576525847.301 [profile_station:NeedComms](INFO): Completed profile_station:NeedComms 2019-12-16T19:50:47.302Z,1576525847.302 [profile_station:NeedComms] Stopped 2019-12-16T19:50:47.302Z,1576525847.302 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T19:50:47.302Z,1576525847.302 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T19:50:47.302Z,1576525847.302 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T19:51:19.126Z,1576525879.126 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T19:52:17.173Z,1576525937.173 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:52:43.705Z,1576525963.705 [Radio_Surface](INFO): Powering down 2019-12-16T19:52:48.297Z,1576525968.297 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T19:52:49.301Z,1576525969.301 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-12-16T19:54:26.705Z,1576526066.705 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.735596 2019-12-16T20:08:40.728Z,1576526920.728 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm. 2019-12-16T20:08:40.729Z,1576526920.729 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -9.00 mm. 2019-12-16T20:08:41.285Z,1576526921.285 [Radio_Surface](INFO): Powering up 2019-12-16T20:08:47.345Z,1576526927.345 [Radio_Surface](INFO): Powering down 2019-12-16T20:11:46.999Z,1576527106.999 [profile_station:NeedComms] Running Loop=1 2019-12-16T20:11:46.999Z,1576527106.999 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms 2019-12-16T20:11:46.999Z,1576527106.999 [profile_station:NeedComms:B.GoToSurface] Running Loop=1 2019-12-16T20:11:46.999Z,1576527106.999 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T20:11:46.999Z,1576527106.999 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-12-16T20:11:46.000Z,1576527107.000 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-12-16T20:11:47.000Z,1576527107.000 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-12-16T20:11:47.000Z,1576527107.000 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T20:11:47.005Z,1576527107.005 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T20:11:47.005Z,1576527107.005 [profile_station:NeedComms:A] Running Loop=1 2019-12-16T20:11:47.007Z,1576527107.007 [profile_station:NeedComms:A](INFO): last time_fix was: 1576525449.000000 second since 1970/01/01T00:00:00Z 2019-12-16T20:11:47.007Z,1576527107.007 [profile_station:NeedComms:A] Stopped 2019-12-16T20:12:55.431Z,1576527175.431 [profile_station:NeedComms:C] Running Loop=1 2019-12-16T20:12:55.873Z,1576527175.873 [Radio_Surface](INFO): Powering up 2019-12-16T20:13:01.389Z,1576527181.389 [DataOverHttps](INFO): Radio surface powered ON. 2019-12-16T20:13:28.221Z,1576527208.221 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-12-16T20:13:28.298Z,1576527208.298 [NAL9602](FAULT): received: +CSQ:0 OK390, 2, 0, 0, 0 OK 2019-12-16T20:13:28.298Z,1576527208.298 [NAL9602] Data Fault, FailCount= 1 2019-12-16T20:13:28.298Z,1576527208.298 [NAL9602](ERROR): Data Fault 2019-12-16T20:13:28.533Z,1576527208.533 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-16T20:13:28.631Z,1576527208.631 [NAL9602](INFO): Powering down 2019-12-16T20:13:29.553Z,1576527209.553 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-16T20:13:29.553Z,1576527209.553 [NAL9602] No Fault, FailCount= 1 2019-12-16T20:13:31.523Z,1576527211.523 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:13:58.926Z,1576527238.926 [NAL9602](INFO): Powering up NAL9602 2019-12-16T20:14:02.645Z,1576527242.645 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:14:09.836Z,1576527249.836 [NAL9602](INFO): NAL9602 initialized 2019-12-16T20:14:21.556Z,1576527261.556 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=18390, MT Status=1, MTMSN=2188 2019-12-16T20:14:21.556Z,1576527261.556 [NAL9602](INFO): Data available in MT queue 2019-12-16T20:14:22.037Z,1576527262.037 [NAL9602](INFO): Received command:stop 2019-12-16T20:14:22.089Z,1576527262.089 [CommandLine](IMPORTANT): got command stop 2019-12-16T20:14:22.089Z,1576527262.089 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2019-12-16T20:14:22.446Z,1576527262.446 [MissionManager](INFO): MissionManager is completed. 2019-12-16T20:14:22.447Z,1576527262.447 [MissionManager](INFO): Uninitializing Mission profile_station 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station](DEBUG): Aggregate::uninitialize profile_station 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science](DEBUG): Aggregate::uninitialize profile_station:Science 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:C] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:D] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:G] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:PeakDetectChl] Stopped 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectChl 2019-12-16T20:14:22.447Z,1576527262.447 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:NeedComms] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:NeedComms:B.GoToSurface] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:NeedComms:C] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes](DEBUG): Aggregate::uninitialize profile_station:StandardEnvelopes 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes:B.DepthEnvelope] Stopped 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2019-12-16T20:14:22.448Z,1576527262.448 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:I.Pitch] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:J.Buoyancy] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:K.SetSpeed] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:K.SetSpeed](DEBUG): Uninitialize. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:L.DepthEnvelope] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:L.DepthEnvelope](DEBUG): Uninitialize. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:M.AltitudeEnvelope] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:N.YoYo] Stopped 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:N.YoYo](DEBUG): Uninitialize YoYoComponent. 2019-12-16T20:14:22.460Z,1576527262.460 [profile_station:CircleWrapper] Stopped 2019-12-16T20:14:22.465Z,1576527262.465 [profile_station:CircleWrapper](DEBUG): Aggregate::uninitialize profile_station:CircleWrapper 2019-12-16T20:14:22.465Z,1576527262.465 [profile_station:CircleWrapper:A] Stopped 2019-12-16T20:14:22.465Z,1576527262.465 [profile_station:CircleWrapper:B.Circle] Stopped 2019-12-16T20:14:22.465Z,1576527262.465 [profile_station:CircleWrapper:B.Circle](DEBUG): Uninitialize. 2019-12-16T20:14:22.597Z,1576527262.597 [WetLabsBB2FL](INFO): Powering down 2019-12-16T20:14:22.812Z,1576527262.812 [MissionManager](IMPORTANT): Started mission Default 2019-12-16T20:14:22.812Z,1576527262.812 [Default] Running Loop=1 2019-12-16T20:14:22.817Z,1576527262.817 [Default](DEBUG): Aggregate::initialize Default 2019-12-16T20:14:22.817Z,1576527262.817 [Default:B.GoToSurface] Running Loop=1 2019-12-16T20:14:22.817Z,1576527262.817 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-16T20:14:22.817Z,1576527262.817 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-16T20:14:22.818Z,1576527262.818 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-16T20:14:22.818Z,1576527262.818 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-16T20:14:22.818Z,1576527262.818 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-16T20:14:22.819Z,1576527262.819 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-16T20:14:22.819Z,1576527262.819 [Default:A.Wait] Running Loop=1 2019-12-16T20:14:22.819Z,1576527262.819 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-16T20:14:33.777Z,1576527273.777 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:14:36.126Z,1576527276.126 [Default:A.Wait](INFO): Done Waiting. 2019-12-16T20:14:36.126Z,1576527276.126 [Default:A.Wait] Stopped 2019-12-16T20:14:36.126Z,1576527276.126 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-16T20:14:36.543Z,1576527276.543 [Default:CheckIn] Running Loop=1 2019-12-16T20:14:36.543Z,1576527276.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-16T20:14:36.543Z,1576527276.543 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-16T20:14:58.728Z,1576527298.728 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200818.00,A,3648.35983,N,12149.66116,W,0.991,264.90,161219,,,A*7F 2019-12-16T20:14:58.742Z,1576527298.742 [NAL9602](INFO): GPS fix at 20191216T200818: (36.805997, -121.827686) 2019-12-16T20:14:58.768Z,1576527298.768 [UniversalFixResidualReporter](INFO): Fix residual: 6.8 %DT, over the last 1262.8 m. Residual distance 86.2 m at bearing 0.3 degrees. Fix at (36.8060, -121.8277) with 484.5 m made good. 2019-12-16T20:14:58.768Z,1576527298.768 [Default:CheckIn:Read_GPS] Stopped 2019-12-16T20:14:58.769Z,1576527298.769 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-16T20:15:04.901Z,1576527304.901 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:15:26.675Z,1576527326.675 [NAL9602](INFO): SBD MO Status=1, MOMSN=18391, MT Status=0, MTMSN=0 2019-12-16T20:15:26.736Z,1576527326.736 [NAL9602](INFO): Sent 72 bytes from file Logs/20191216T175803/Courier0024.lzma 2019-12-16T20:15:26.736Z,1576527326.736 [NAL9602](INFO): Packets left to send: 0 2019-12-16T20:15:36.025Z,1576527336.025 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:15:43.727Z,1576527343.727 [NAL9602](INFO): SBD MO Status=2, MOMSN=18392, MT Status=2, MTMSN=0 2019-12-16T20:15:43.727Z,1576527343.727 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T20:16:05.615Z,1576527365.615 [NAL9602](INFO): SBD MO Status=2, MOMSN=18392, MT Status=2, MTMSN=0 2019-12-16T20:16:05.615Z,1576527365.615 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T20:16:07.149Z,1576527367.149 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-16T20:16:27.101Z,1576527387.101 [NAL9602](INFO): SBD MO Status=2, MOMSN=18392, MT Status=2, MTMSN=0 2019-12-16T20:16:27.101Z,1576527387.101 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T20:16:36.621Z,1576527396.621 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003604 2019-12-16T20:16:47.290Z,1576527407.290 [DataOverHttps](INFO): Sending 999 bytes from file Logs/20191216T175803/Express0025.lzma 2019-12-16T20:16:49.294Z,1576527409.294 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0025.lzma.bak 2019-12-16T20:16:49.295Z,1576527409.295 [DataOverHttps](INFO): SBD MOMSN=12171701 2019-12-16T20:16:50.645Z,1576527410.645 [Default:CheckIn:Read_Iridium] Stopped 2019-12-16T20:16:50.645Z,1576527410.645 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-16T20:16:50.645Z,1576527410.645 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-16T20:16:53.035Z,1576527413.035 [NAL9602](INFO): SBD MO Status=2, MOMSN=18392, MT Status=2, MTMSN=0 2019-12-16T20:16:53.036Z,1576527413.036 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-16T20:17:12.450Z,1576527432.450 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm (3 active estimators). 2019-12-16T20:17:23.834Z,1576527443.834 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-16T20:21:51.479Z,1576527711.479 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-16T20:21:51.479Z,1576527711.479 [Default:CheckIn:C.Wait] Stopped 2019-12-16T20:21:51.479Z,1576527711.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-16T20:21:51.479Z,1576527711.479 [Default:CheckIn:D] Running Loop=1 2019-12-16T20:21:51.851Z,1576527711.851 [Default:CheckIn:D] Stopped 2019-12-16T20:21:51.851Z,1576527711.851 [Default:CheckIn:E] Running Loop=1 2019-12-16T20:21:52.265Z,1576527712.265 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.483975 min 2019-12-16T20:21:52.265Z,1576527712.265 [Default:CheckIn:E] Stopped 2019-12-16T20:21:52.265Z,1576527712.265 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-16T20:21:52.265Z,1576527712.265 [Default:CheckIn] Stopped 2019-12-16T20:21:52.266Z,1576527712.266 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-16T20:21:52.266Z,1576527712.266 [Default:CheckIn](INFO): Running loop #2 2019-12-16T20:21:52.266Z,1576527712.266 [Default:CheckIn] Running Loop=2 2019-12-16T20:21:52.266Z,1576527712.266 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-16T20:21:52.266Z,1576527712.266 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-16T20:21:54.246Z,1576527714.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201513.00,A,3648.21880,N,12149.23061,W,19.866,94.54,161219,,,A*7B 2019-12-16T20:21:54.248Z,1576527714.248 [NAL9602](INFO): GPS fix at 20191216T201513: (36.803647, -121.820510) 2019-12-16T20:21:54.290Z,1576527714.290 [Default:CheckIn:Read_GPS] Stopped 2019-12-16T20:21:54.290Z,1576527714.290 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-16T20:22:03.468Z,1576527723.468 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191216T175803/Courier0027.lzma 2019-12-16T20:22:05.474Z,1576527725.474 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Courier0027.lzma.bak 2019-12-16T20:22:05.475Z,1576527725.475 [DataOverHttps](INFO): SBD MOMSN=12171713 2019-12-16T20:22:22.457Z,1576527742.457 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20191216T175803/Express0028.lzma 2019-12-16T20:22:24.462Z,1576527744.462 [DataOverHttps](INFO): Moved sent file to Logs/20191216T175803/Express0028.lzma.bak 2019-12-16T20:22:24.463Z,1576527744.463 [DataOverHttps](INFO): SBD MOMSN=12171721 2019-12-16T20:22:25.807Z,1576527745.807 [Default:CheckIn:Read_Iridium] Stopped 2019-12-16T20:22:25.808Z,1576527745.808 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-16T20:22:25.808Z,1576527745.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-16T20:22:53.650Z,1576527773.650 [NAL9602](INFO): SBD MO Status=1, MOMSN=18392, MT Status=0, MTMSN=0 2019-12-16T20:22:53.650Z,1576527773.650 [NAL9602](INFO): No messages in MT queue 2019-12-16T20:23:04.994Z,1576527784.994 [DataOverHttps](IMPORTANT): SBD MTMSN=20191216T201623 2019-12-16T20:23:12.600Z,1576527792.600 [DataOverHttps](INFO): Received command:restart logs