2019-07-03T18:31:05.961Z,1562178665.961 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-03T18:34:04.162Z,1562178844.162 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-03T18:34:04.162Z,1562178844.162 [Default:CheckIn:C.Wait] Stopped 2019-07-03T18:34:04.162Z,1562178844.162 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-03T18:34:04.163Z,1562178844.163 [Default:CheckIn:D] Running Loop=1 2019-07-03T18:34:04.572Z,1562178844.572 [Default:CheckIn:D] Stopped 2019-07-03T18:34:04.572Z,1562178844.572 [Default:CheckIn:E] Running Loop=1 2019-07-03T18:34:04.967Z,1562178844.967 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.685154 min 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn:E] Stopped 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn] Stopped 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn](INFO): Running loop #6 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn] Running Loop=6 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-03T18:34:04.968Z,1562178844.968 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-03T18:34:06.559Z,1562178846.559 [NAL9602](DEBUG): Fix Requested 2019-07-03T18:34:06.955Z,1562178846.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183354.00,A,3648.44025,N,12149.24560,W,6.201,262.22,030719,,,D*7A 2019-07-03T18:34:06.957Z,1562178846.957 [NAL9602](INFO): GPS fix at 20190703T183354: (36.807338, -121.820760) 2019-07-03T18:34:06.986Z,1562178846.986 [Default:CheckIn:Read_GPS] Stopped 2019-07-03T18:34:06.986Z,1562178846.986 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-03T18:34:07.769Z,1562178847.769 [Micromodem](ERROR): Buffer fill timout failure. 2019-07-03T18:34:09.287Z,1562178849.287 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 5FF41C5D000001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567 2019-07-03T18:34:09.287Z,1562178849.287 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 266CC0E6F1A517638CB0C0B8BE3619E02B8F4A169EC22D30546A87042BC836DF836B942BC3C4A9EFC1B6C4BDD91F97B2782B4B03CB56EA92D77C6909485B9FDE 2019-07-03T18:34:09.288Z,1562178849.288 [Micromodem](INFO): Outgoing frame #3, 64 bytes: C9BA76D6E11C7243AB9F1CB76D4E14F7CBE1C6B0B40F2F0A19DC25B10B3C6279A2D80F52F03F1275F5BE973EA20943C61E76D18516091C6196716250936B1655 2019-07-03T18:34:09.288Z,1562178849.288 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53 2019-07-03T18:34:09.465Z,1562178849.465 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51 2019-07-03T18:34:09.809Z,1562178849.809 [Micromodem](INFO): Nmea in: $CADRQ,183410,1,9,0,64,1*41 2019-07-03T18:34:09.810Z,1562178849.810 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,5FF41C5D000001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*0F 2019-07-03T18:34:10.213Z,1562178850.213 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T18:34:10.617Z,1562178850.617 [Micromodem](INFO): Nmea in: $CADRQ,183410,1,9,0,64,2*42 2019-07-03T18:34:10.618Z,1562178850.618 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,266CC0E6F1A517638CB0C0B8BE3619E02B8F4A169EC22D30546A87042BC836DF836B942BC3C4A9EFC1B6C4BDD91F97B2782B4B03CB56EA92D77C6909485B9FDE*74 2019-07-03T18:34:11.034Z,1562178851.034 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T18:34:11.425Z,1562178851.425 [Micromodem](INFO): Nmea in: $CADRQ,183411,1,9,0,64,3*42 2019-07-03T18:34:11.426Z,1562178851.426 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,C9BA76D6E11C7243AB9F1CB76D4E14F7CBE1C6B0B40F2F0A19DC25B10B3C6279A2D80F52F03F1275F5BE973EA20943C61E76D18516091C6196716250936B1655*08 2019-07-03T18:34:11.837Z,1562178851.837 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T18:34:12.229Z,1562178852.229 [Micromodem](INFO): Nmea in: $CATXP,192*48 2019-07-03T18:34:15.859Z,1562178855.859 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190703T183055/Courier0000.lzma 2019-07-03T18:34:15.871Z,1562178855.871 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2019-07-03T18:34:16.653Z,1562178856.653 [DataOverHttps](INFO): Moved sent file to Logs/20190703T183055/Courier0000.lzma.bak 2019-07-03T18:34:16.653Z,1562178856.653 [DataOverHttps](INFO): SBD MOMSN=11426503 2019-07-03T18:34:17.092Z,1562178857.092 [Micromodem](INFO): Nmea in: $CAXST,6,20190703,183412.299089,3,0,200,4000,10000,1,1,9,1,3,3,3,192*40 2019-07-03T18:34:29.555Z,1562178869.555 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20190703T160007/Express0040.lzma 2019-07-03T18:34:30.361Z,1562178870.361 [DataOverHttps](INFO): Moved sent file to Logs/20190703T160007/Express0040.lzma.bak 2019-07-03T18:34:30.361Z,1562178870.361 [DataOverHttps](INFO): SBD MOMSN=11426507 2019-07-03T18:34:40.106Z,1562178880.106 [NAL9602](INFO): SBD MO Status=0, MOMSN=8047, MT Status=0, MTMSN=0 2019-07-03T18:34:40.106Z,1562178880.106 [NAL9602](INFO): No messages in MT queue 2019-07-03T18:34:44.101Z,1562178884.101 [DataOverHttps](INFO): Sending 339 bytes from file Logs/20190703T183055/Express0001.lzma 2019-07-03T18:34:44.905Z,1562178884.905 [DataOverHttps](INFO): Moved sent file to Logs/20190703T183055/Express0001.lzma.bak 2019-07-03T18:34:44.905Z,1562178884.905 [DataOverHttps](INFO): SBD MOMSN=11426511 2019-07-03T18:34:57.795Z,1562178897.795 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190703T183055/Express0004.lzma 2019-07-03T18:34:58.601Z,1562178898.601 [DataOverHttps](INFO): Moved sent file to Logs/20190703T183055/Express0004.lzma.bak 2019-07-03T18:34:58.601Z,1562178898.601 [DataOverHttps](INFO): SBD MOMSN=11426514 2019-07-03T18:35:00.760Z,1562178900.760 [Default:CheckIn:Read_Iridium] Stopped 2019-07-03T18:35:00.760Z,1562178900.760 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-03T18:35:00.761Z,1562178900.761 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-03T18:35:10.808Z,1562178910.808 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-03T18:35:53.077Z,1562178953.077 [DataOverHttps](IMPORTANT): SBD MTMSN=20190703T183540 2019-07-03T18:36:04.315Z,1562178964.315 [DataOverHttps](INFO): Received command:configSet Micromodem.loadAtStartup 0 bool persist 2019-07-03T18:36:04.684Z,1562178964.684 [CommandLine](IMPORTANT): got command configSet Micromodem.loadAtStartup 0.000000 bool persist 2019-07-03T18:36:04.684Z,1562178964.684 [CommandLine](IMPORTANT): configSet Micromodem.loadAtStartup requires a restart to take effect. 2019-07-03T18:36:38.696Z,1562178998.696 [DataOverHttps](IMPORTANT): SBD MTMSN=20190703T183625 2019-07-03T18:36:46.511Z,1562179006.511 [DataOverHttps](INFO): Received command:restart app 2019-07-03T18:36:46.576Z,1562179006.576 [CommandLine](IMPORTANT): got command restart application 2019-07-03T18:36:47.579Z,1562179007.579 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:47.580Z,1562179007.580 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.583Z,1562179007.583 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-07-03T18:36:47.583Z,1562179007.583 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.584Z,1562179007.584 [CommandLine](INFO): Join timeout helper Thread ID is 7903 2019-07-03T18:36:47.585Z,1562179007.585 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-07-03T18:36:47.585Z,1562179007.585 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.585Z,1562179007.585 [NavChartDb](INFO): Join timeout helper Thread ID is 7904 2019-07-03T18:36:47.739Z,1562179007.739 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:47.740Z,1562179007.740 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.751Z,1562179007.751 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-07-03T18:36:47.751Z,1562179007.751 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.752Z,1562179007.752 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7905 2019-07-03T18:36:47.931Z,1562179007.931 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:47.931Z,1562179007.931 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-07-03T18:36:47.932Z,1562179007.932 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.939Z,1562179007.939 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-07-03T18:36:47.939Z,1562179007.939 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:47.940Z,1562179007.940 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7906 2019-07-03T18:36:48.063Z,1562179008.063 [CTD_NeilBrown](INFO): Powering down 2019-07-03T18:36:48.075Z,1562179008.075 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:48.075Z,1562179008.075 [CTD_NeilBrown](INFO): Powering down 2019-07-03T18:36:48.087Z,1562179008.087 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.105Z,1562179008.105 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-07-03T18:36:48.105Z,1562179008.105 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.106Z,1562179008.106 [Radio_Surface](INFO): Join timeout helper Thread ID is 7907 2019-07-03T18:36:48.196Z,1562179008.196 [Radio_Surface](INFO): Powering down 2019-07-03T18:36:48.197Z,1562179008.197 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:48.197Z,1562179008.197 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.204Z,1562179008.204 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-07-03T18:36:48.204Z,1562179008.204 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.205Z,1562179008.205 [DataOverHttps](INFO): Join timeout helper Thread ID is 7908 2019-07-03T18:36:48.527Z,1562179008.527 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:48.528Z,1562179008.528 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.536Z,1562179008.536 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-07-03T18:36:48.536Z,1562179008.536 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.536Z,1562179008.536 [logger](INFO): Join timeout helper Thread ID is 7909 2019-07-03T18:36:48.615Z,1562179008.615 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:48.616Z,1562179008.616 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.628Z,1562179008.628 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-07-03T18:36:48.628Z,1562179008.628 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.628Z,1562179008.628 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-07-03T18:36:48.628Z,1562179008.628 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:48.629Z,1562179008.629 [controlThread](INFO): Join timeout helper Thread ID is 7910 2019-07-03T18:36:48.636Z,1562179008.636 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T18:36:48.636Z,1562179008.636 [controlThread](DEBUG): Uninitializing ControlThread 2019-07-03T18:36:48.636Z,1562179008.636 [AHRS_M2](INFO): Powering down 2019-07-03T18:36:48.708Z,1562179008.708 [DUSBL_Hydroid](INFO): Powering down 2019-07-03T18:36:48.800Z,1562179008.800 [Micromodem](INFO): Powering down 2019-07-03T18:36:48.896Z,1562179008.896 [NAL9602](INFO): Powering down 2019-07-03T18:36:48.967Z,1562179008.967 [RDI_Pathfinder](INFO): Powering down 2019-07-03T18:36:48.969Z,1562179008.969 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-07-03T18:36:48.969Z,1562179008.969 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-07-03T18:36:48.970Z,1562179008.970 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-07-03T18:36:48.970Z,1562179008.970 [MissionManager](INFO): Uninitializing Mission Default 2019-07-03T18:36:48.970Z,1562179008.970 [Default] Stopped 2019-07-03T18:36:48.971Z,1562179008.971 [Default](DEBUG): Aggregate::uninitialize Default 2019-07-03T18:36:48.971Z,1562179008.971 [Default:B.GoToSurface] Stopped 2019-07-03T18:36:48.971Z,1562179008.971 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-03T18:36:48.971Z,1562179008.971 [Default:CheckIn] Stopped 2019-07-03T18:36:48.971Z,1562179008.971 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-03T18:36:48.971Z,1562179008.971 [Default:CheckIn:C.Wait] Stopped 2019-07-03T18:36:48.971Z,1562179008.971 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-03T18:36:48.973Z,1562179008.973 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-07-03T18:36:48.974Z,1562179008.974 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-07-03T18:36:48.974Z,1562179008.974 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-07-03T18:36:48.974Z,1562179008.974 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-07-03T18:36:48.975Z,1562179008.975 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-03T18:36:48.975Z,1562179008.975 [BuoyancyServo](INFO): Powering down 2019-07-03T18:36:48.987Z,1562179008.987 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-07-03T18:36:48.987Z,1562179008.987 [ElevatorServo](INFO): Powering down 2019-07-03T18:36:48.988Z,1562179008.988 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-07-03T18:36:48.988Z,1562179008.988 [MassServo](INFO): Powering down 2019-07-03T18:36:48.989Z,1562179008.989 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-03T18:36:48.989Z,1562179008.989 [RudderServo](INFO): Powering down 2019-07-03T18:36:48.990Z,1562179008.990 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-07-03T18:36:48.990Z,1562179008.990 [ThrusterServo](INFO): Powering down 2019-07-03T18:36:48.991Z,1562179008.991 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-07-03T18:36:48.991Z,1562179008.991 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-07-03T18:36:48.991Z,1562179008.991 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-07-03T18:36:48.992Z,1562179008.992 [CBIT](DEBUG): Powering off loads. 2019-07-03T18:36:49.003Z,1562179009.003 [CBIT](DEBUG): Disabling WDT. 2019-07-03T18:36:49.015Z,1562179009.015 [CBIT](DEBUG): Opening all GF detection circuits. 2019-07-03T18:36:49.016Z,1562179009.016 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.073Z,1562179009.073 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.083Z,1562179009.083 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.125Z,1562179009.125 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.127Z,1562179009.127 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.184Z,1562179009.184 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T18:36:49.256Z,1562179009.256 [logger ThreadHandler](INFO): Thread cancelled.