2018-03-07T01:18:17.690Z,1520385497.690 [CommandLine](IMPORTANT): got command restart logs 2018-03-07T01:18:55.034Z,1520385535.034 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-03-07T01:18:56.299Z,1520385536.299 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = 0.000000, longitudeAccuracy_ = 0.000000, depthAccuracy_ = nan 2018-03-07T01:18:56.300Z,1520385536.300 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 6 2018-03-07T01:18:56.300Z,1520385536.300 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2018-03-07T01:18:56.312Z,1520385536.312 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2018-03-07T01:18:56.717Z,1520385536.717 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2018-03-07T01:18:56.718Z,1520385536.718 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 6 2018-03-07T01:18:57.102Z,1520385537.102 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2018-03-07T01:18:57.103Z,1520385537.103 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2018-03-07T01:18:57.103Z,1520385537.103 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2018-03-07T01:19:29.616Z,1520385569.616 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002188 2018-03-07T01:20:29.803Z,1520385629.803 [DataOverHttps](IMPORTANT): SBD MTMSN=20180307T012009 2018-03-07T01:20:34.031Z,1520385634.031 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 3 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 10 second;set sample:SampleAtDepth.TargetDepth 3 meter" 4zqc0 1 2 2018-03-07T01:20:34.087Z,1520385634.087 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 3 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 10 second;set sample:SampleAtDepth.TargetDepth 3 meter" 4zqc0 1 2.000000 2018-03-07T01:20:34.088Z,1520385634.088 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=4zqc0 2018-03-07T01:20:34.088Z,1520385634.088 [CommandLine](IMPORTANT): Scheduled #9 (#1 of 2 with id='4zqc0'): "load Maintenance/sample.xml;set sample.MissionTimeout 3 hour;set sample.Depth 3 meter;set sample.NumberOfSamples 2 count;set sample.WaitBeforeSample 10 second;set sample:SampleAtDepth.TargetDepth 3 meter" ASAP 2018-03-07T01:20:34.779Z,1520385634.779 [DataOverHttps](IMPORTANT): SBD MTMSN=20180307T012014 2018-03-07T01:20:39.416Z,1520385639.416 [DataOverHttps](INFO): Received command:sched asap "set sample:SampleAtDepth.SettleTime 15 second;run " 4zqc0 2 2 2018-03-07T01:20:39.502Z,1520385639.502 [CommandLine](IMPORTANT): got command schedule asap "set sample:SampleAtDepth.SettleTime 15 second;run " 4zqc0 2 2.000000 2018-03-07T01:20:39.502Z,1520385639.502 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=4zqc0 2018-03-07T01:20:39.503Z,1520385639.503 [CommandLine](IMPORTANT): Scheduled #10 (#2 of 2 with id='4zqc0'): "set sample:SampleAtDepth.SettleTime 15 second;run " ASAP 2018-03-07T01:20:39.563Z,1520385639.563 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml 2018-03-07T01:20:39.563Z,1520385639.563 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml 2018-03-07T01:20:39.598Z,1520385639.598 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min 2018-03-07T01:20:39.600Z,1520385639.600 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m 2018-03-07T01:20:39.610Z,1520385639.610 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count 2018-03-07T01:20:39.612Z,1520385639.612 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min 2018-03-07T01:20:39.618Z,1520385639.618 [sample:A.Pitch](DEBUG): Construct. 2018-03-07T01:20:39.625Z,1520385639.625 [sample:B.SetSpeed](DEBUG): Construct. 2018-03-07T01:20:39.627Z,1520385639.627 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml 2018-03-07T01:20:39.733Z,1520385639.733 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m 2018-03-07T01:20:39.735Z,1520385639.735 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s 2018-03-07T01:20:39.737Z,1520385639.737 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h 2018-03-07T01:20:39.739Z,1520385639.739 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool 2018-03-07T01:20:39.742Z,1520385639.742 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool 2018-03-07T01:20:39.744Z,1520385639.744 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool 2018-03-07T01:20:39.747Z,1520385639.747 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min 2018-03-07T01:20:39.762Z,1520385639.762 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min 2018-03-07T01:20:39.764Z,1520385639.764 [sample:SampleAtDepth:B.Pitch](DEBUG): Construct. 2018-03-07T01:20:39.791Z,1520385639.791 [sample:SampleAtDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-03-07T01:20:39.799Z,1520385639.799 [sample:SampleAtDepth:D.Wait](DEBUG): Construct Wait. 2018-03-07T01:20:39.853Z,1520385639.853 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-03-07T01:20:39.856Z,1520385639.856 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-03-07T01:20:39.856Z,1520385639.856 [MissionManager](ERROR): Slate does not contain celsius 2018-03-07T01:20:39.872Z,1520385639.872 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute. 2018-03-07T01:20:39.913Z,1520385639.913 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2018-03-07T01:20:39.913Z,1520385639.913 [MissionManager](ERROR): Slate does not contain celsius 2018-03-07T01:20:39.930Z,1520385639.930 [MissionManager](DEBUG): This mission is designed to be run in the test tank only and samples whichever sampler is installed once the vehicle reaches the target depth. How long to let the mission run. 90 Depth to sample at. 7 Number of samples to take. 1 How long to wait between samples. This starts *before* the first sample to exercise the SettleTime setting in the insert aggregate. 3 0 2018-03-07T01:20:39.930Z,1520385639.930 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml 2018-03-07T01:20:48.463Z,1520385648.463 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 3.000000 hour 2018-03-07T01:20:48.463Z,1520385648.463 [CommandLine](IMPORTANT): got command set sample.Depth 3.000000 meter 2018-03-07T01:20:48.464Z,1520385648.464 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 2.000000 count 2018-03-07T01:20:48.465Z,1520385648.465 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 10.000000 second 2018-03-07T01:20:48.466Z,1520385648.466 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 3.000000 meter 2018-03-07T01:20:50.968Z,1520385650.968 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SettleTime 15.000000 second 2018-03-07T01:20:50.969Z,1520385650.969 [CommandLine](IMPORTANT): got command run 2018-03-07T01:20:50.970Z,1520385650.970 [CommandLine](IMPORTANT): Running 2018-03-07T01:20:51.086Z,1520385651.086 [Default] Stopped 2018-03-07T01:20:51.086Z,1520385651.086 [Default](DEBUG): Aggregate::uninitialize Default 2018-03-07T01:20:51.086Z,1520385651.086 [Default:B.GoToSurface] Stopped 2018-03-07T01:20:51.086Z,1520385651.086 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-03-07T01:20:51.086Z,1520385651.086 [Default:CheckIn] Stopped 2018-03-07T01:20:51.086Z,1520385651.086 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-03-07T01:20:51.086Z,1520385651.086 [Default:CheckIn:Read_GPS] Stopped 2018-03-07T01:20:51.087Z,1520385651.087 [MissionManager](IMPORTANT): Started mission sample 2018-03-07T01:20:51.087Z,1520385651.087 [sample] Running Loop=1 2018-03-07T01:20:51.087Z,1520385651.087 [sample](DEBUG): Aggregate::initialize sample 2018-03-07T01:20:51.087Z,1520385651.087 [sample:A.Pitch] Running Loop=1 2018-03-07T01:20:51.087Z,1520385651.087 [sample:A.Pitch](DEBUG): Initialize. 2018-03-07T01:20:51.087Z,1520385651.087 [sample:B.SetSpeed] Running Loop=1 2018-03-07T01:20:51.087Z,1520385651.087 [sample:B.SetSpeed](DEBUG): Initialize. 2018-03-07T01:20:51.088Z,1520385651.088 [sample:D] Running Loop=1 2018-03-07T01:20:51.089Z,1520385651.089 [sample:D] Stopped 2018-03-07T01:20:51.089Z,1520385651.089 [sample:E] Running Loop=1 2018-03-07T01:20:51.089Z,1520385651.089 [sample:B.SetSpeed] Running Loop=1 2018-03-07T01:20:51.090Z,1520385651.090 [sample:A.Pitch] Running Loop=1 2018-03-07T01:20:51.498Z,1520385651.498 [sample:E] Stopped 2018-03-07T01:20:51.498Z,1520385651.498 [sample:SampleRepeater] Running Loop=1 2018-03-07T01:20:51.498Z,1520385651.498 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater 2018-03-07T01:20:51.498Z,1520385651.498 [sample:SampleRepeater:Sample] Running Loop=1 2018-03-07T01:20:51.499Z,1520385651.499 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample 2018-03-07T01:20:51.859Z,1520385651.859 [sample:SampleAtDepth] Running Loop=1 2018-03-07T01:20:51.859Z,1520385651.859 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth 2018-03-07T01:20:51.859Z,1520385651.859 [sample:SampleAtDepth:B.Pitch] Running Loop=1 2018-03-07T01:20:51.860Z,1520385651.860 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize. 2018-03-07T01:20:51.860Z,1520385651.860 [sample:SampleAtDepth:A] Running Loop=1 2018-03-07T01:20:51.861Z,1520385651.861 [sample:SampleAtDepth:A](INFO): Moving to 3.000000 m 2018-03-07T01:20:51.862Z,1520385651.862 [sample:SampleAtDepth:A] Stopped 2018-03-07T01:20:58.111Z,1520385658.111 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 3.000000 meter 2018-03-07T01:20:58.112Z,1520385658.112 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2018-03-07T01:20:58.348Z,1520385658.348 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-03-07T01:20:58.666Z,1520385658.666 [sample:SampleAtDepth:C] Running Loop=1 2018-03-07T01:20:58.914Z,1520385658.914 [Radio_Surface](INFO): Powering down 2018-03-07T01:20:59.063Z,1520385659.063 [sample:SampleAtDepth:C](INFO): At 3.000000 m , settling for 0.166667 min 2018-03-07T01:20:59.064Z,1520385659.064 [sample:SampleAtDepth:C] Stopped 2018-03-07T01:20:59.064Z,1520385659.064 [sample:SampleAtDepth:D.Wait] Running Loop=1 2018-03-07T01:20:59.064Z,1520385659.064 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component. 2018-03-07T01:21:09.013Z,1520385669.013 [Radio_Surface](INFO): Powering up 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting. 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:D.Wait] Stopped 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component. 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper] Running Loop=1 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1 2018-03-07T01:21:09.859Z,1520385669.859 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1 2018-03-07T01:21:09.860Z,1520385669.860 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1 2018-03-07T01:21:10.256Z,1520385670.256 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped 2018-03-07T01:21:10.256Z,1520385670.256 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP 2018-03-07T01:21:10.257Z,1520385670.257 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1 2018-03-07T01:21:10.661Z,1520385670.661 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling 2018-03-07T01:21:11.805Z,1520385671.805 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:12.605Z,1520385672.605 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:13.405Z,1520385673.405 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:14.205Z,1520385674.205 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:14.670Z,1520385674.670 [Radio_Surface](INFO): Powering down 2018-03-07T01:21:15.005Z,1520385675.005 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:15.805Z,1520385675.805 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:16.605Z,1520385676.605 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:17.406Z,1520385677.406 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:18.205Z,1520385678.205 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:19.005Z,1520385679.005 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:19.805Z,1520385679.805 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:20.605Z,1520385680.605 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:20.982Z,1520385680.982 [CommandLine](IMPORTANT): got command stop 2018-03-07T01:21:20.983Z,1520385680.983 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2018-03-07T01:21:21.074Z,1520385681.074 [MissionManager](INFO): MissionManager is completed. 2018-03-07T01:21:21.074Z,1520385681.074 [MissionManager](INFO): Uninitializing Mission sample 2018-03-07T01:21:21.074Z,1520385681.074 [sample] Stopped 2018-03-07T01:21:21.074Z,1520385681.074 [sample](DEBUG): Aggregate::uninitialize sample 2018-03-07T01:21:21.074Z,1520385681.074 [sample:A.Pitch] Stopped 2018-03-07T01:21:21.074Z,1520385681.074 [sample:B.SetSpeed] Stopped 2018-03-07T01:21:21.074Z,1520385681.074 [sample:B.SetSpeed](DEBUG): Uninitialize. 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:B.Pitch] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:SampleWrapper] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleRepeater] Stopped 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater 2018-03-07T01:21:21.075Z,1520385681.075 [sample:SampleRepeater:Sample] Stopped 2018-03-07T01:21:21.076Z,1520385681.076 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample 2018-03-07T01:21:21.406Z,1520385681.406 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port 2018-03-07T01:21:21.477Z,1520385681.477 [MissionManager](IMPORTANT): Started mission Default 2018-03-07T01:21:21.477Z,1520385681.477 [Default] Running Loop=1 2018-03-07T01:21:21.477Z,1520385681.477 [Default](DEBUG): Aggregate::initialize Default 2018-03-07T01:21:21.477Z,1520385681.477 [Default:B.GoToSurface] Running Loop=1 2018-03-07T01:21:21.478Z,1520385681.478 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-03-07T01:21:21.478Z,1520385681.478 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-03-07T01:21:21.478Z,1520385681.478 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-03-07T01:21:21.478Z,1520385681.478 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-03-07T01:21:21.479Z,1520385681.479 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 30.000000 seconds. 2018-03-07T01:21:21.479Z,1520385681.479 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-03-07T01:21:21.479Z,1520385681.479 [Default:A.Wait] Running Loop=1 2018-03-07T01:21:21.479Z,1520385681.479 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-03-07T01:21:22.204Z,1520385682.204 [ESPComponent](INFO): powering down ESP 2018-03-07T01:21:22.350Z,1520385682.350 [Radio_Surface](INFO): Powering up 2018-03-07T01:21:22.626Z,1520385682.626 [NAL9602](INFO): Powering down 2018-03-07T01:21:23.692Z,1520385683.692 [CommandLine](IMPORTANT): got command restart application 2018-03-07T01:21:24.701Z,1520385684.701 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:24.701Z,1520385684.701 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:24.705Z,1520385684.705 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-03-07T01:21:24.705Z,1520385684.705 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:24.706Z,1520385684.706 [CommandLine](INFO): Join timeout helper Thread ID is 5988 2018-03-07T01:21:24.707Z,1520385684.707 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-03-07T01:21:24.707Z,1520385684.707 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:24.707Z,1520385684.707 [NavChartDb](INFO): Join timeout helper Thread ID is 5989 2018-03-07T01:21:24.853Z,1520385684.853 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:24.854Z,1520385684.854 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:24.865Z,1520385684.865 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-03-07T01:21:24.865Z,1520385684.865 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:24.865Z,1520385684.865 [Radio_Surface](INFO): Join timeout helper Thread ID is 5990 2018-03-07T01:21:25.182Z,1520385685.182 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:25.182Z,1520385685.182 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.197Z,1520385685.197 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2018-03-07T01:21:25.197Z,1520385685.197 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.197Z,1520385685.197 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5991 2018-03-07T01:21:25.221Z,1520385685.221 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:25.221Z,1520385685.221 [WetLabsBB2FL](INFO): Powering down 2018-03-07T01:21:25.222Z,1520385685.222 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.229Z,1520385685.229 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2018-03-07T01:21:25.229Z,1520385685.229 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.229Z,1520385685.229 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5992 2018-03-07T01:21:25.585Z,1520385685.585 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:25.776Z,1520385685.776 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-03-07T01:21:25.776Z,1520385685.776 [CTD_Seabird](INFO): Powering down 2018-03-07T01:21:25.777Z,1520385685.777 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.782Z,1520385685.782 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-03-07T01:21:25.782Z,1520385685.782 [logger ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.783Z,1520385685.783 [logger](INFO): Join timeout helper Thread ID is 5994 2018-03-07T01:21:25.809Z,1520385685.809 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:25.809Z,1520385685.809 [logger ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.822Z,1520385685.822 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-03-07T01:21:25.822Z,1520385685.822 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.822Z,1520385685.822 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-03-07T01:21:25.822Z,1520385685.822 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:25.822Z,1520385685.822 [controlThread](INFO): Join timeout helper Thread ID is 5995 2018-03-07T01:21:25.937Z,1520385685.937 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-03-07T01:21:25.937Z,1520385685.937 [controlThread](DEBUG): Uninitializing ControlThread 2018-03-07T01:21:25.938Z,1520385685.938 [Aanderaa_O2](INFO): Powering down 2018-03-07T01:21:25.942Z,1520385685.942 [NAL9602](INFO): Powering down 2018-03-07T01:21:25.947Z,1520385685.947 [DAT](INFO): Powering down 2018-03-07T01:21:26.069Z,1520385686.069 [PNI_TCM](INFO): Powering down 2018-03-07T01:21:26.158Z,1520385686.158 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-03-07T01:21:26.160Z,1520385686.160 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-03-07T01:21:26.160Z,1520385686.160 [MissionManager](INFO): Uninitializing Mission Default 2018-03-07T01:21:26.160Z,1520385686.160 [Default] Stopped 2018-03-07T01:21:26.161Z,1520385686.161 [Default](DEBUG): Aggregate::uninitialize Default 2018-03-07T01:21:26.161Z,1520385686.161 [Default:A.Wait] Stopped 2018-03-07T01:21:26.161Z,1520385686.161 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-03-07T01:21:26.161Z,1520385686.161 [Default:B.GoToSurface] Stopped 2018-03-07T01:21:26.161Z,1520385686.161 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-03-07T01:21:26.164Z,1520385686.164 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-03-07T01:21:26.165Z,1520385686.165 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-03-07T01:21:26.165Z,1520385686.165 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-03-07T01:21:26.165Z,1520385686.165 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-03-07T01:21:26.165Z,1520385686.165 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-03-07T01:21:26.166Z,1520385686.166 [BuoyancyServo](INFO): Powering down 2018-03-07T01:21:26.181Z,1520385686.181 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-03-07T01:21:26.181Z,1520385686.181 [ElevatorServo](INFO): Powering down 2018-03-07T01:21:26.182Z,1520385686.182 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-03-07T01:21:26.182Z,1520385686.182 [MassServo](INFO): Powering down 2018-03-07T01:21:26.183Z,1520385686.183 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-03-07T01:21:26.183Z,1520385686.183 [RudderServo](INFO): Powering down 2018-03-07T01:21:26.184Z,1520385686.184 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-03-07T01:21:26.184Z,1520385686.184 [ThrusterServo](INFO): Powering down 2018-03-07T01:21:26.184Z,1520385686.184 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-03-07T01:21:26.185Z,1520385686.185 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-03-07T01:21:26.185Z,1520385686.185 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-03-07T01:21:26.186Z,1520385686.186 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:26.265Z,1520385686.265 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:26.272Z,1520385686.272 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:26.355Z,1520385686.355 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:26.748Z,1520385686.748 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-03-07T01:21:26.806Z,1520385686.806 [logger ThreadHandler](INFO): Thread cancelled.