2022-08-03T19:04:08.383Z,1659553448.383 [CommandExec](IMPORTANT): got command restart logs 2022-08-03T19:04:09.303Z,1659553449.303 [DataOverHttps](IMPORTANT): SBD MTMSN=20220803T190408 2022-08-03T19:04:18.205Z,1659553458.205 [DataOverHttps](INFO): Received command: gfscan 2022-08-03T19:04:18.263Z,1659553458.263 [CommandExec](IMPORTANT): got command gfscan 2022-08-03T19:04:18.542Z,1659553458.542 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-03T19:04:29.469Z,1659553469.469 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005130 CHAN A1 (24V): -0.001944 CHAN A2 (12V): -0.000457 CHAN A3 (5V): -0.000149 CHAN B0 (3.3V): 0.000093 CHAN B1 (3.15aV): 0.000401 CHAN B2 (3.15bV): 0.000925 CHAN B3 (GND): 0.001278 OPEN: 0.004537 Full Scale: +/- 1 mA 2022-08-03T19:04:55.289Z,1659553495.289 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-08-03T18:59:55.1Z 2022-08-03T19:04:55.289Z,1659553495.289 [Default:CheckIn:Read_GPS] Stopped 2022-08-03T19:04:55.289Z,1659553495.289 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-03T19:05:04.213Z,1659553504.213 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220803T134251/Courier0094.lzma 2022-08-03T19:05:05.216Z,1659553505.216 [DataOverHttps](INFO): Moved sent file to Logs/20220803T134251/Courier0094.lzma.bak 2022-08-03T19:05:05.216Z,1659553505.216 [DataOverHttps](IMPORTANT): SBD MOMSN=17079002, MTMSN=20220803T190504 2022-08-03T19:05:13.557Z,1659553513.557 [DataOverHttps](INFO): Received command: load Maintenance/sample_lab.xml;set sample_lab.CartridgeType -1 count;run 2022-08-03T19:05:13.640Z,1659553513.640 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/sample_lab.xml 2022-08-03T19:05:13.641Z,1659553513.641 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/sample_lab.xml 2022-08-03T19:05:13.663Z,1659553513.663 [MissionManager](INFO): DefineArg sample_lab.MissionTimeout = 90.000000 min 2022-08-03T19:05:13.665Z,1659553513.665 [MissionManager](INFO): DefineArg sample_lab.CartridgeType = -4.000000 count 2022-08-03T19:05:13.687Z,1659553513.687 [MissionManager](INFO): DefineArg sample_lab.NumberOfSamples = 1.000000 count 2022-08-03T19:05:13.688Z,1659553513.688 [sample_lab:A.AbortSample](DEBUG): Construct. 2022-08-03T19:05:13.703Z,1659553513.703 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](DEBUG): Construct. 2022-08-03T19:05:13.720Z,1659553513.720 [MissionManager](DEBUG): This mission is designed to run in the lab only and triggers an ESP sample with specified type. How long to let the mission run. 90 Specifies ESP cartridge type code (defaults to archiveHiBiomass_bac: -4) -4 Number of samples to take. 1 Sampling ESP cartridge type 2022-08-03T19:05:13.721Z,1659553513.721 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/sample_lab.xml 2022-08-03T19:05:15.724Z,1659553515.724 [CommandExec](IMPORTANT): got command set sample_lab.CartridgeType -1 count 2022-08-03T19:05:15.725Z,1659553515.725 [CommandExec](IMPORTANT): got command run 2022-08-03T19:05:15.729Z,1659553515.729 [CommandExec](IMPORTANT): Running 2022-08-03T19:05:15.923Z,1659553515.923 [Default] Stopped 2022-08-03T19:05:15.923Z,1659553515.923 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-03T19:05:15.923Z,1659553515.923 [Default:B.GoToSurface] Stopped 2022-08-03T19:05:15.923Z,1659553515.923 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-03T19:05:15.923Z,1659553515.923 [Default:CheckIn] Stopped 2022-08-03T19:05:15.923Z,1659553515.923 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-03T19:05:15.923Z,1659553515.923 [Default:CheckIn:Read_Iridium] Stopped 2022-08-03T19:05:15.923Z,1659553515.923 [MissionManager](IMPORTANT): Started mission sample_lab 2022-08-03T19:05:15.923Z,1659553515.923 [sample_lab] Running Loop=1 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab](DEBUG): Aggregate::initialize sample_lab 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab:A.AbortSample] Running Loop=1 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab:A.AbortSample](INFO): Initializing AbortSample. 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab:SampleRepeater] Running Loop=1 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab:SampleRepeater](DEBUG): Aggregate::initialize sample_lab:SampleRepeater 2022-08-03T19:05:15.924Z,1659553515.924 [sample_lab:SampleRepeater:A] Running Loop=1 2022-08-03T19:05:15.925Z,1659553515.925 [sample_lab:SampleRepeater:A](IMPORTANT): Sampling ESP cartridge type -1.000000 count 2022-08-03T19:05:15.925Z,1659553515.925 [sample_lab:SampleRepeater:A] Stopped 2022-08-03T19:05:15.925Z,1659553515.925 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Running Loop=1 2022-08-03T19:05:15.925Z,1659553515.925 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect. 2022-08-03T19:05:15.925Z,1659553515.925 [sample_lab:A.AbortSample] Running Loop=1 2022-08-03T19:05:16.302Z,1659553516.302 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -1. 2022-08-03T19:05:16.303Z,1659553516.303 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Stopped 2022-08-03T19:05:16.303Z,1659553516.303 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect. 2022-08-03T19:05:16.303Z,1659553516.303 [sample_lab:SampleRepeater:TriggerESP] Running Loop=1 2022-08-03T19:05:16.715Z,1659553516.715 [sample_lab:SampleRepeater:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling 2022-08-03T19:05:17.515Z,1659553517.515 [ESPComponent](DEBUG): (612) Will wait for 10.0000 before power-up/connection sequence 2022-08-03T19:05:21.881Z,1659553521.881 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220803T190408/Courier0000.lzma 2022-08-03T19:05:22.883Z,1659553522.883 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Courier0000.lzma.bak 2022-08-03T19:05:22.883Z,1659553522.883 [DataOverHttps](INFO): SBD MOMSN=17079005 2022-08-03T19:05:27.623Z,1659553527.623 [ESPComponent](DEBUG): (612) Done with wait. Will continue with general power-up/connection sequence 2022-08-03T19:05:27.692Z,1659553527.692 [ESPComponent](INFO): powering up ESP 2022-08-03T19:05:27.710Z,1659553527.710 [ESPComponent](INFO): powering up ESP secondary power supply 2022-08-03T19:05:27.726Z,1659553527.726 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8 2022-08-03T19:05:27.877Z,1659553527.877 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000) 2022-08-03T19:05:28.094Z,1659553528.094 [ESPComponent](INFO): console: 2022-08-03T19:05:28.810Z,1659553528.810 [ESPComponent](INFO): console: 2022-08-03T19:05:29.223Z,1659553529.223 [ESPComponent](INFO): console:NAND: 256 MiB 2022-08-03T19:05:29.625Z,1659553529.625 [ESPComponent](INFO): console: BOOTMODE: SPI 2022-08-03T19:05:30.059Z,1659553530.059 [ESPComponent](INFO): console: reading SPI NOR..Done 2022-08-03T19:05:30.447Z,1659553530.447 [ESPComponent](INFO): console: 2022-08-03T19:05:30.850Z,1659553530.850 [ESPComponent](INFO): console: 2022-08-03T19:05:31.235Z,1659553531.235 [ESPComponent](INFO): console: U-Boot 2009.11-mbariD (Oct 20 2020 - 11:20:51) 2022-08-03T19:05:31.645Z,1659553531.645 [ESPComponent](INFO): console: 2022-08-03T19:05:32.043Z,1659553532.043 [ESPComponent](INFO): console: MBARI LPC31xx ESP 3G 2022-08-03T19:05:32.473Z,1659553532.473 [ESPComponent](INFO): console: flash params are already written into flash 2022-08-03T19:05:32.853Z,1659553532.853 [ESPComponent](INFO): console: DRAM: 64 MB 2022-08-03T19:05:33.275Z,1659553533.275 [ESPComponent](INFO): console: In: serial 2022-08-03T19:05:33.679Z,1659553533.679 [ESPComponent](INFO): console: Out: serial 2022-08-03T19:05:34.083Z,1659553534.083 [ESPComponent](INFO): console: Err: serial 2022-08-03T19:05:34.473Z,1659553534.473 [ESPComponent](INFO): console: Net: ks8851_mll 2022-08-03T19:05:34.878Z,1659553534.878 [ESPComponent](INFO): console: Hit to stop autoboot: 1  0 2022-08-03T19:05:35.292Z,1659553535.292 [ESPComponent](INFO): console: 4096 KiB S25FL032P at 0:0 is now current device 2022-08-03T19:05:35.687Z,1659553535.687 [ESPComponent](INFO): console: Loading kernel from SPI flash...done 2022-08-03T19:05:36.104Z,1659553536.104 [ESPComponent](INFO): console: ## Booting kernel from Legacy Image at 31000000 ... 2022-08-03T19:05:36.504Z,1659553536.504 [ESPComponent](INFO): console: Image Name: Linux-3.18.140-lpc31-mbari4 2022-08-03T19:05:36.911Z,1659553536.911 [ESPComponent](INFO): console: Image Type: ARM Linux Kernel Image (uncompressed) 2022-08-03T19:05:37.302Z,1659553537.302 [ESPComponent](INFO): console: Data Size: 2336344 Bytes = 2.2 MB 2022-08-03T19:05:37.720Z,1659553537.720 [ESPComponent](INFO): console: Load Address: 30008000 2022-08-03T19:05:38.110Z,1659553538.110 [ESPComponent](INFO): console: Entry Point: 30008000 2022-08-03T19:05:38.514Z,1659553538.514 [ESPComponent](INFO): console: Verifying Checksum ... OK 2022-08-03T19:05:38.931Z,1659553538.931 [ESPComponent](INFO): console: Loading Kernel Image ... OK 2022-08-03T19:05:39.334Z,1659553539.334 [ESPComponent](INFO): console: OK 2022-08-03T19:05:39.736Z,1659553539.736 [ESPComponent](INFO): console: 2022-08-03T19:05:40.136Z,1659553540.136 [ESPComponent](INFO): console: Starting kernel ... 2022-08-03T19:05:40.533Z,1659553540.533 [ESPComponent](INFO): console: 2022-08-03T19:05:40.960Z,1659553540.960 [ESPComponent](INFO): console: Uncompressing Linux... Booting kernel... 2022-08-03T19:05:41.351Z,1659553541.351 [ESPComponent](INFO): console: [ 0.06] MBARI ESP 3G 2022-08-03T19:05:41.751Z,1659553541.751 [ESPComponent](INFO): console: 2022-08-03T19:05:42.155Z,1659553542.155 [ESPComponent](INFO): console:INIT: version 2.85 booting 2022-08-03T19:05:42.549Z,1659553542.549 [ESPComponent](INFO): console: 2022-08-03T19:05:42.984Z,1659553542.984 [ESPComponent](INFO): console:MBARI ESP Embedded Linux http://www.mbari.org mailto:brent@mbari.org 2022-08-03T19:05:43.377Z,1659553543.377 [ESPComponent](INFO): console: ESPmv1 2022-08-03T19:05:43.779Z,1659553543.779 [ESPComponent](INFO): console: 2022-08-03T19:05:44.170Z,1659553544.170 [ESPComponent](INFO): console:INIT: Entering runlevel: 3 2022-08-03T19:05:44.574Z,1659553544.574 [ESPComponent](INFO): console: 2022-08-03T19:05:44.988Z,1659553544.988 [ESPComponent](INFO): console:Loading kernel modules 2022-08-03T19:05:45.408Z,1659553545.408 [ESPComponent](INFO): console: Mounting filesystems and adding swapfiles listed in /etc/fstab 2022-08-03T19:05:45.804Z,1659553545.804 [ESPComponent](INFO): console: Starting device events handler 2022-08-03T19:05:46.246Z,1659553546.246 [ESPComponent](INFO): console: 2022-08-03T19:05:49.882Z,1659553549.882 [ESPComponent](INFO): console:Set system clock to: 2022-08-03T19:05:50.226Z,1659553550.226 [ESPComponent](INFO): console:Wed Aug 3 15:05:58 EDT 2022 2022-08-03T19:05:50.653Z,1659553550.653 [ESPComponent](INFO): console: Starting syslogd klogd... 2022-08-03T19:05:51.047Z,1659553551.047 [ESPComponent](INFO): console: stopped syslogd (pid 689) 2022-08-03T19:05:51.451Z,1659553551.451 [ESPComponent](INFO): console: Bringing up lo ... 2022-08-03T19:05:51.855Z,1659553551.855 [ESPComponent](INFO): console: lo IP=127.0.0.1 2022-08-03T19:05:52.245Z,1659553552.245 [ESPComponent](INFO): console: Packet forwarding enabled 2022-08-03T19:05:52.649Z,1659553552.649 [ESPComponent](INFO): console: Bringing up wg2shore ... 2022-08-03T19:05:53.084Z,1659553553.084 [ESPComponent](INFO): console: [#] ip link add wg2shore type wireguard 2022-08-03T19:05:53.522Z,1659553553.522 [ESPComponent](INFO): console: 2022-08-03T19:05:54.691Z,1659553554.691 [ESPComponent](INFO): console:[#] wg setconf wg2shore /dev/fd/63 2022-08-03T19:05:55.087Z,1659553555.087 [ESPComponent](INFO): console: [#] ip -4 address add 192.168.5.31 dev wg2shore 2022-08-03T19:05:55.506Z,1659553555.506 [ESPComponent](INFO): console: [#] ip link set mtu 1420 up dev wg2shore 2022-08-03T19:05:55.881Z,1659553555.881 [ESPComponent](INFO): console: [#] ip -4 route add 192.168.4.0/23 dev wg2shore 2022-08-03T19:05:56.286Z,1659553556.286 [ESPComponent](INFO): console: Bringing up platform ... 2022-08-03T19:05:56.689Z,1659553556.689 [ESPComponent](INFO): console: Starting netplugd... 2022-08-03T19:05:57.124Z,1659553557.124 [ESPComponent](INFO): console: Starting portmap... 2022-08-03T19:05:57.516Z,1659553557.516 [ESPComponent](INFO): console: Network unavailable: Local time is Wed Aug 3 15:06:05 EDT 2022 2022-08-03T19:05:57.939Z,1659553557.939 [ESPComponent](INFO): console: Starting chronyd... 2022-08-03T19:05:58.305Z,1659553558.305 [ESPComponent](INFO): console: Starting thttpd... 2022-08-03T19:05:58.720Z,1659553558.720 [ESPComponent](INFO): console: Starting dnsmasq... 2022-08-03T19:05:59.182Z,1659553559.182 [ESPComponent](INFO): console: 2022-08-03T19:06:00.759Z,1659553560.759 [ESPComponent](INFO): console:Bringing up wired ... 2022-08-03T19:06:01.206Z,1659553561.206 [ESPComponent](INFO): console: 2022-08-03T19:06:01.537Z,1659553561.537 [ESPComponent](INFO): console: 2022-08-03T19:06:01.960Z,1659553561.960 [ESPComponent](INFO): console: MBARI ESP Embedded Linux 2.75a -- 4/28/22 brent@mbari.org 2022-08-03T19:06:02.366Z,1659553562.366 [ESPComponent](INFO): console: 2022-08-03T19:06:02.769Z,1659553562.769 [ESPComponent](INFO): console:ESPmv1 login: Determining IP configuration for wired ...udhcpc (v1.11.2) started 2022-08-03T19:06:03.168Z,1659553563.168 [ESPComponent](INFO): console: Sending discover... 2022-08-03T19:06:03.626Z,1659553563.626 [ESPComponent](INFO): console: 2022-08-03T19:06:05.177Z,1659553565.177 [ESPComponent](INFO): console:Sending discover... 2022-08-03T19:06:05.666Z,1659553565.666 [ESPComponent](INFO): console: 2022-08-03T19:06:08.064Z,1659553568.064 [ESPComponent](INFO): console:Sending discover... 2022-08-03T19:06:08.490Z,1659553568.490 [ESPComponent](INFO): console: 2022-08-03T19:06:11.234Z,1659553571.234 [ESPComponent](INFO): console:No lease, forking to background 2022-08-03T19:06:11.698Z,1659553571.698 [ESPComponent](INFO): console: 2022-08-03T19:06:12.045Z,1659553572.045 [ESPComponent](INFO): console:Bringing up direct ... 2022-08-03T19:06:12.522Z,1659553572.522 [ESPComponent](INFO): console: 2022-08-03T19:06:12.853Z,1659553572.853 [ESPComponent](INFO): console:direct IP=10.10.10.10 2022-08-03T19:06:13.362Z,1659553573.362 [ESPComponent](INFO): console: 2022-08-03T19:06:26.588Z,1659553586.588 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 41 2022-08-03T19:06:26.589Z,1659553586.589 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-08-03T19:06:26.622Z,1659553586.622 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-08-03T19:06:26.986Z,1659553586.986 [ESPComponent](IMPORTANT): ESP has connected as client 2022-08-03T19:06:27.001Z,1659553587.001 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-08-03T19:06:27.001Z,1659553587.001 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 41 2022-08-03T19:06:27.816Z,1659553587.816 [ESPComponent](IMPORTANT): [sample #2] Setting cartridge argument to -1 2022-08-03T19:06:27.816Z,1659553587.816 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT 2022-08-03T19:06:27.817Z,1659553587.817 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=2 2022-08-03T19:06:27.824Z,1659553587.824 [sample_lab:SampleRepeater:TriggerESP] Stopped 2022-08-03T19:06:27.824Z,1659553587.824 [sample_lab:SampleRepeater:WaitForESP] Running Loop=1 2022-08-03T19:06:28.228Z,1659553588.228 [sample_lab:SampleRepeater:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number 2022-08-03T19:06:28.647Z,1659553588.647 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_LOG 2022-08-03T19:06:29.023Z,1659553589.023 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_STATUS 2022-08-03T19:06:31.051Z,1659553591.051 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_LOADING_CARTRIDGE 2022-08-03T19:07:05.383Z,1659553625.383 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PRIMING (@57,aRNAl_bac) 2022-08-03T19:07:08.211Z,1659553628.211 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PRIMING (@100.0) 2022-08-03T19:07:08.212Z,1659553628.212 [ESPComponent](IMPORTANT): Filtering timeoutMinutes=92.070000 issuedCmd_=Cmd.startFiltering 2022-08-03T19:07:08.619Z,1659553628.619 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_FILTERING (@100.0) 2022-08-03T19:07:17.092Z,1659553637.092 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-03T19:07:17.092Z,1659553637.092 [DVL_micro](ERROR): Failed to parse: :BI,+00871,-03320,+00677, 2022-08-03T19:09:25.159Z,1659553765.159 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_FILTERING (@0.0) 2022-08-03T19:09:25.562Z,1659553765.562 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0) 2022-08-03T19:09:27.599Z,1659553767.599 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 42 2022-08-03T19:09:27.599Z,1659553767.599 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-08-03T19:09:27.617Z,1659553767.617 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-08-03T19:09:28.027Z,1659553768.027 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-08-03T19:09:28.027Z,1659553768.027 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 42 2022-08-03T19:12:08.024Z,1659553928.024 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-08-03T19:12:08.024Z,1659553928.024 [NAL9602] Data Fault, FailCount= 5 2022-08-03T19:12:08.024Z,1659553928.024 [NAL9602](ERROR): Data Fault 2022-08-03T19:12:08.040Z,1659553928.040 [CBIT](ERROR): Data Fault in component: NAL9602 2022-08-03T19:12:08.041Z,1659553928.041 [CBIT](CRITICAL): Data Fault in component: NAL9602 2022-08-03T19:12:08.424Z,1659553928.424 [NAL9602](INFO): Powering down 2022-08-03T19:12:08.460Z,1659553928.460 [CBIT](INFO): Critical error at 20220803T191208 2022-08-03T19:12:08.460Z,1659553928.460 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-08-03T19:12:08.840Z,1659553928.840 [MissionManager](INFO): MissionManager is completed. 2022-08-03T19:12:08.840Z,1659553928.840 [MissionManager](INFO): Uninitializing Mission sample_lab 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab] Stopped 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab](DEBUG): Aggregate::uninitialize sample_lab 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab:A.AbortSample] Stopped 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab:A.AbortSample](INFO): Uninitializing AbortSample. 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab:SampleRepeater] Stopped 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab:SampleRepeater](DEBUG): Aggregate::uninitialize sample_lab:SampleRepeater 2022-08-03T19:12:08.840Z,1659553928.840 [sample_lab:SampleRepeater:WaitForESP] Stopped 2022-08-03T19:12:09.236Z,1659553929.236 [ESPComponent](DEBUG): Resetting stopSampling to false 2022-08-03T19:12:09.237Z,1659553929.237 [ESPComponent](IMPORTANT): [sample #2] Stop sampling requested. 2022-08-03T19:12:09.244Z,1659553929.244 [MissionManager](IMPORTANT): Started mission Default 2022-08-03T19:12:09.245Z,1659553929.245 [Default] Running Loop=1 2022-08-03T19:12:09.245Z,1659553929.245 [Default](DEBUG): Aggregate::initialize Default 2022-08-03T19:12:09.245Z,1659553929.245 [Default:B.GoToSurface] Running Loop=1 2022-08-03T19:12:09.245Z,1659553929.245 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-08-03T19:12:09.245Z,1659553929.245 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-08-03T19:12:09.246Z,1659553929.246 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-08-03T19:12:09.246Z,1659553929.246 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-08-03T19:12:09.246Z,1659553929.246 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-08-03T19:12:09.247Z,1659553929.247 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-08-03T19:12:09.247Z,1659553929.247 [Default:A.Wait] Running Loop=1 2022-08-03T19:12:09.247Z,1659553929.247 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-08-03T19:12:09.641Z,1659553929.641 [ESPComponent](IMPORTANT): Stop sampling requested. Issuing Cmd.pauseFiltering 2022-08-03T19:12:15.302Z,1659553935.302 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PAUSED (@101.6) 2022-08-03T19:12:15.302Z,1659553935.302 [ESPComponent](DEBUG): Writing sampleVolume=101.599998 2022-08-03T19:12:15.701Z,1659553935.701 [ESPComponent](IMPORTANT): In S_PAUSED received result: 101.6 2022-08-03T19:12:16.109Z,1659553936.109 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PROCESSING (@101.6) 2022-08-03T19:12:18.130Z,1659553938.130 [ESPComponent](IMPORTANT): Processing timeoutMinutes=30.000000 issuedCmd_=Cmd.startProcessing 2022-08-03T19:12:18.529Z,1659553938.529 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PROCESSED (@57,aRNAl_bac) 2022-08-03T19:12:22.576Z,1659553942.576 [Default:A.Wait](INFO): Done Waiting. 2022-08-03T19:12:22.577Z,1659553942.577 [Default:A.Wait] Stopped 2022-08-03T19:12:22.577Z,1659553942.577 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-08-03T19:12:23.006Z,1659553943.006 [Default:CheckIn] Running Loop=1 2022-08-03T19:12:23.006Z,1659553943.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-03T19:12:23.006Z,1659553943.006 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-03T19:12:28.634Z,1659553948.634 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 43 2022-08-03T19:12:28.634Z,1659553948.634 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-08-03T19:12:28.645Z,1659553948.645 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-08-03T19:12:29.047Z,1659553949.047 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-08-03T19:12:29.047Z,1659553949.047 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 43 2022-08-03T19:13:33.575Z,1659554013.575 [CommandExec](IMPORTANT): got command failComponent 2022-08-03T19:13:33.576Z,1659554013.576 [CommandExec](IMPORTANT): Failed components: 2022-08-03T19:13:33.576Z,1659554013.576 [CommandExec](IMPORTANT): NAL9602: Data Fault 2022-08-03T19:13:53.465Z,1659554033.465 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPING (@57,aRNAl_bac) 2022-08-03T19:14:00.741Z,1659554040.741 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 esp@esp:'/var/log/esp/real /var/log/esp/real.out /var/log/esp/real.slot /var/log/esp/*.spr*' /LRAUV/ESPlogs & 2022-08-03T19:14:00.770Z,1659554040.770 [ESPComponent](INFO): closing pipe. 2022-08-03T19:14:01.144Z,1659554041.144 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPED 2022-08-03T19:14:08.444Z,1659554048.444 [CBIT](INFO): Clearing failed state for component NAL9602 2022-08-03T19:14:08.444Z,1659554048.444 [NAL9602] No Fault, FailCount= 5 2022-08-03T19:14:08.820Z,1659554048.820 [NAL9602](INFO): Powering up NAL9602 2022-08-03T19:14:19.728Z,1659554059.728 [NAL9602](INFO): NAL9602 initialized 2022-08-03T19:15:29.628Z,1659554129.628 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 44 2022-08-03T19:15:29.628Z,1659554129.628 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-08-03T19:15:29.656Z,1659554129.656 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-08-03T19:15:30.045Z,1659554130.045 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-08-03T19:15:30.045Z,1659554130.045 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 44 2022-08-03T19:16:48.402Z,1659554208.402 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-03T19:16:48.402Z,1659554208.402 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+23.61489.0,0003272,-0237,+0000,+03272,-0126,+00000,I 2022-08-03T19:17:23.179Z,1659554243.179 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-08-03T19:12:23.0Z 2022-08-03T19:17:23.179Z,1659554243.179 [Default:CheckIn:Read_GPS] Stopped 2022-08-03T19:17:23.180Z,1659554243.180 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-03T19:17:31.613Z,1659554251.613 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220803T190408/Courier0006.lzma 2022-08-03T19:17:32.615Z,1659554252.615 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Courier0006.lzma.bak 2022-08-03T19:17:32.616Z,1659554252.616 [DataOverHttps](INFO): SBD MOMSN=17079015 2022-08-03T19:17:50.786Z,1659554270.786 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20220803T190408/Courier0009.lzma 2022-08-03T19:17:51.788Z,1659554271.788 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Courier0009.lzma.bak 2022-08-03T19:17:51.788Z,1659554271.788 [DataOverHttps](INFO): SBD MOMSN=17079017 2022-08-03T19:18:05.248Z,1659554285.248 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 3101 2022-08-03T19:18:05.250Z,1659554285.250 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-08-03T19:18:11.802Z,1659554291.802 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20220803T134251/Express0095.lzma 2022-08-03T19:18:12.804Z,1659554292.804 [DataOverHttps](INFO): Moved sent file to Logs/20220803T134251/Express0095.lzma.bak 2022-08-03T19:18:12.804Z,1659554292.804 [DataOverHttps](INFO): SBD MOMSN=17079020 2022-08-03T19:18:30.346Z,1659554310.346 [DataOverHttps](INFO): Sending 475 bytes from file Logs/20220803T190408/Express0001.lzma 2022-08-03T19:18:30.754Z,1659554310.754 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 45 2022-08-03T19:18:30.754Z,1659554310.754 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-08-03T19:18:30.765Z,1659554310.765 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-08-03T19:18:31.129Z,1659554311.129 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-08-03T19:18:31.129Z,1659554311.129 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 45 2022-08-03T19:18:31.347Z,1659554311.347 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Express0001.lzma.bak 2022-08-03T19:18:31.348Z,1659554311.348 [DataOverHttps](INFO): SBD MOMSN=17079022 2022-08-03T19:18:48.909Z,1659554328.909 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220803T190408/Express0004.lzma 2022-08-03T19:18:49.911Z,1659554329.911 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Express0004.lzma.bak 2022-08-03T19:18:49.912Z,1659554329.912 [DataOverHttps](INFO): SBD MOMSN=17079029 2022-08-03T19:19:00.997Z,1659554340.997 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence completed normally. 2022-08-03T19:19:00.998Z,1659554340.998 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=2 2022-08-03T19:19:01.423Z,1659554341.423 [ESPComponent](IMPORTANT): [sample #2] ESP log summary report (2 messages): @15:06:43.46 Selecting Cartridge 57 @15:12:13.62 Cmd::Paused in FILTERING -- paused by LRAUV during Sample Pump (SP) move after sampling 101.6ml 2022-08-03T19:19:01.424Z,1659554341.424 [ESPComponent](INFO): powering down ESP 2022-08-03T19:19:01.424Z,1659554341.424 [ESPComponent](INFO): powering down ESP secondary power supply 2022-08-03T19:19:08.838Z,1659554348.838 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20220803T190408/Express0007.lzma 2022-08-03T19:19:09.839Z,1659554349.839 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Express0007.lzma.bak 2022-08-03T19:19:09.840Z,1659554349.840 [DataOverHttps](INFO): SBD MOMSN=17079032 2022-08-03T19:19:27.423Z,1659554367.423 [DataOverHttps](INFO): Sending 1080 bytes from file Logs/20220803T190408/Express0010.lzma 2022-08-03T19:19:28.423Z,1659554368.423 [DataOverHttps](INFO): Moved sent file to Logs/20220803T190408/Express0010.lzma.bak 2022-08-03T19:19:28.424Z,1659554368.424 [DataOverHttps](INFO): SBD MOMSN=17079043 2022-08-03T19:19:31.725Z,1659554371.725 [Default:CheckIn:Read_Iridium] Stopped 2022-08-03T19:19:31.725Z,1659554371.725 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-03T19:19:31.725Z,1659554371.725 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-03T19:19:47.987Z,1659554387.987 [DataOverHttps](IMPORTANT): SBD MTMSN=20220803T191947 2022-08-03T19:19:54.807Z,1659554394.807 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-03T19:19:54.807Z,1659554394.807 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-08-03T19:19:57.946Z,1659554397.946 [DataOverHttps](INFO): Received command: restart app 2022-08-03T19:19:58.019Z,1659554398.019 [CommandExec](IMPORTANT): got command restart application 2022-08-03T19:19:59.022Z,1659554399.022 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.022Z,1659554399.022 [CommandExec](INFO): Uninitializing the command executive. 2022-08-03T19:19:59.022Z,1659554399.022 [CommandExec](INFO): Uninitializing the command scheduler. 2022-08-03T19:19:59.022Z,1659554399.022 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.062Z,1659554399.062 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-08-03T19:19:59.062Z,1659554399.062 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-08-03T19:19:59.062Z,1659554399.062 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.063Z,1659554399.063 [NavChartDb](INFO): Join timeout helper Thread ID is 4176 2022-08-03T19:19:59.094Z,1659554399.094 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.094Z,1659554399.094 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.102Z,1659554399.102 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-08-03T19:19:59.102Z,1659554399.102 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.102Z,1659554399.102 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4177 2022-08-03T19:19:59.262Z,1659554399.262 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.262Z,1659554399.262 [WetLabsBB2FL](INFO): Powering down 2022-08-03T19:19:59.263Z,1659554399.263 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.274Z,1659554399.274 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-08-03T19:19:59.274Z,1659554399.274 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.274Z,1659554399.274 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4179 2022-08-03T19:19:59.370Z,1659554399.370 [CTD_Seabird](INFO): Powering down 2022-08-03T19:19:59.382Z,1659554399.382 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.382Z,1659554399.382 [CTD_Seabird](INFO): Powering down 2022-08-03T19:19:59.394Z,1659554399.394 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.398Z,1659554399.398 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-08-03T19:19:59.398Z,1659554399.398 [DAT ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.398Z,1659554399.398 [DAT](INFO): Join timeout helper Thread ID is 4180 2022-08-03T19:19:59.494Z,1659554399.494 [DAT](INFO): Powering down 2022-08-03T19:19:59.566Z,1659554399.566 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.566Z,1659554399.566 [DAT](INFO): Powering down 2022-08-03T19:19:59.567Z,1659554399.567 [DAT ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.578Z,1659554399.578 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-08-03T19:19:59.578Z,1659554399.578 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.578Z,1659554399.578 [Radio_Surface](INFO): Join timeout helper Thread ID is 4182 2022-08-03T19:19:59.830Z,1659554399.830 [Radio_Surface](INFO): Powering down 2022-08-03T19:19:59.831Z,1659554399.831 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:19:59.831Z,1659554399.831 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.838Z,1659554399.838 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-08-03T19:19:59.839Z,1659554399.839 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:19:59.839Z,1659554399.839 [Onboard](INFO): Join timeout helper Thread ID is 4183 2022-08-03T19:19:59.950Z,1659554399.950 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-08-03T19:20:03.486Z,1659554403.486 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:03.486Z,1659554403.486 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:03.490Z,1659554403.490 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-08-03T19:20:03.490Z,1659554403.490 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:03.491Z,1659554403.491 [DataOverHttps](INFO): Join timeout helper Thread ID is 4184 2022-08-03T19:20:03.966Z,1659554403.966 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:03.966Z,1659554403.966 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:03.974Z,1659554403.974 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-08-03T19:20:03.974Z,1659554403.974 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:03.975Z,1659554403.975 [BackseatComponent](INFO): Join timeout helper Thread ID is 4185 2022-08-03T19:20:04.038Z,1659554404.038 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:04.038Z,1659554404.038 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.054Z,1659554404.054 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-08-03T19:20:04.054Z,1659554404.054 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.055Z,1659554404.055 [logger](INFO): Join timeout helper Thread ID is 4186 2022-08-03T19:20:04.058Z,1659554404.058 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:04.058Z,1659554404.058 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.075Z,1659554404.075 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-08-03T19:20:04.075Z,1659554404.075 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.075Z,1659554404.075 [CommandLine](INFO): Join timeout helper Thread ID is 4187 2022-08-03T19:20:04.150Z,1659554404.150 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:04.150Z,1659554404.150 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.158Z,1659554404.158 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-08-03T19:20:04.158Z,1659554404.158 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.159Z,1659554404.159 [CommandExec](INFO): Join timeout helper Thread ID is 4188 2022-08-03T19:20:04.160Z,1659554404.160 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-08-03T19:20:04.160Z,1659554404.160 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.161Z,1659554404.161 [controlThread](INFO): Join timeout helper Thread ID is 4189 2022-08-03T19:20:04.466Z,1659554404.466 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-03T19:20:04.466Z,1659554404.466 [controlThread](DEBUG): Uninitializing ControlThread 2022-08-03T19:20:04.466Z,1659554404.466 [AHRS_M2](INFO): Powering down 2022-08-03T19:20:04.610Z,1659554404.610 [DVL_micro](INFO): Powering down 2022-08-03T19:20:04.611Z,1659554404.611 [NAL9602](INFO): Powering down 2022-08-03T19:20:04.614Z,1659554404.614 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-08-03T19:20:04.615Z,1659554404.615 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-08-03T19:20:04.615Z,1659554404.615 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-08-03T19:20:04.616Z,1659554404.616 [MissionManager](INFO): Uninitializing Mission Default 2022-08-03T19:20:04.616Z,1659554404.616 [Default] Stopped 2022-08-03T19:20:04.616Z,1659554404.616 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-03T19:20:04.616Z,1659554404.616 [Default:B.GoToSurface] Stopped 2022-08-03T19:20:04.616Z,1659554404.616 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-03T19:20:04.616Z,1659554404.616 [Default:CheckIn] Stopped 2022-08-03T19:20:04.616Z,1659554404.616 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-03T19:20:04.616Z,1659554404.616 [Default:CheckIn:C.Wait] Stopped 2022-08-03T19:20:04.616Z,1659554404.616 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-03T19:20:04.619Z,1659554404.619 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-08-03T19:20:04.619Z,1659554404.619 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-08-03T19:20:04.620Z,1659554404.620 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-08-03T19:20:04.620Z,1659554404.620 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-08-03T19:20:04.620Z,1659554404.620 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-08-03T19:20:04.620Z,1659554404.620 [BuoyancyServo](INFO): Powering down 2022-08-03T19:20:04.634Z,1659554404.634 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-08-03T19:20:04.634Z,1659554404.634 [ElevatorServo](INFO): Powering down 2022-08-03T19:20:04.635Z,1659554404.635 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-08-03T19:20:04.635Z,1659554404.635 [MassServo](INFO): Powering down 2022-08-03T19:20:04.636Z,1659554404.636 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-08-03T19:20:04.636Z,1659554404.636 [RudderServo](INFO): Powering down 2022-08-03T19:20:04.637Z,1659554404.637 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-08-03T19:20:04.637Z,1659554404.637 [ThrusterHE](INFO): Powering down 2022-08-03T19:20:04.638Z,1659554404.638 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-08-03T19:20:04.638Z,1659554404.638 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-08-03T19:20:04.638Z,1659554404.638 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-08-03T19:20:04.638Z,1659554404.638 [CBIT](DEBUG): Powering off loads. 2022-08-03T19:20:04.649Z,1659554404.649 [CBIT](DEBUG): Disabling WDT. 2022-08-03T19:20:04.661Z,1659554404.661 [CBIT](DEBUG): Opening all GF detection circuits. 2022-08-03T19:20:04.663Z,1659554404.663 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.715Z,1659554404.715 [DAT ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.720Z,1659554404.720 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.722Z,1659554404.722 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.729Z,1659554404.729 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.773Z,1659554404.773 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.825Z,1659554404.825 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.903Z,1659554404.903 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.926Z,1659554404.926 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-03T19:20:04.983Z,1659554404.983 [logger ThreadHandler](INFO): Thread cancelled.