2022-04-13T22:25:18.245Z,1649888718.245 [CommandExec](IMPORTANT): got command restart logs 2022-04-13T22:25:25.273Z,1649888725.273 [CommandExec](IMPORTANT): got command failComponent hardware DAT 2022-04-13T22:25:25.273Z,1649888725.273 [DAT] Hardware Fault, FailCount= 1 2022-04-13T22:25:25.273Z,1649888725.273 [DAT](ERROR): Hardware Fault 2022-04-13T22:25:25.274Z,1649888725.274 [CommandExec](IMPORTANT): DAT failureMode is Hardware Fault 2022-04-13T22:25:25.374Z,1649888725.374 [DAT](INFO): Powering down 2022-04-13T22:25:25.413Z,1649888725.413 [CBIT](ERROR): Hardware Fault in component: DAT 2022-04-13T22:25:25.848Z,1649888725.848 [DAT](FAULT): LCB fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown. 2022-04-13T22:25:26.581Z,1649888726.581 [CBIT](INFO): Clearing failed state for component DAT 2022-04-13T22:25:26.581Z,1649888726.581 [DAT] No Fault, FailCount= 1 2022-04-13T22:25:28.420Z,1649888728.420 [DAT](INFO): Powering up 2022-04-13T22:25:28.420Z,1649888728.420 [DAT](DEBUG): Initializing DAT. 2022-04-13T22:25:40.280Z,1649888740.280 [DAT](INFO): DAT read: 2022-04-13T22:25:40.281Z,1649888740.281 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2022-04-13T22:25:42.045Z,1649888742.045 [DAT](INFO): DAT read: MF Frequency Band 2022-04-13T22:25:42.046Z,1649888742.046 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2022-04-13T22:25:42.046Z,1649888742.046 [DAT](INFO): DAT read: Apr 13 2022 22:25:36 2022-04-13T22:25:43.053Z,1649888743.053 [DAT](INFO): DAT read: Features enabled [Bearing] 2022-04-13T22:25:43.054Z,1649888743.054 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2022-04-13T22:25:43.054Z,1649888743.054 [DAT](INFO): commRate: 800 2022-04-13T22:25:45.121Z,1649888745.121 [DAT](INFO): entering command mode 2022-04-13T22:25:45.320Z,1649888745.320 [DAT](INFO): DAT read: 2022-04-13T22:25:45.321Z,1649888745.321 [DAT](INFO): DAT read: user:1> 2022-04-13T22:25:45.321Z,1649888745.321 [DAT](INFO): setting verbose to 3 2022-04-13T22:25:45.574Z,1649888745.574 [DAT](INFO): DAT read: user:1> 2022-04-13T22:25:45.577Z,1649888745.577 [DAT](INFO): DAT read: Verbose | 3 2022-04-13T22:25:45.577Z,1649888745.577 [DAT](INFO): set verbose to 3 2022-04-13T22:25:45.578Z,1649888745.578 [DAT](INFO): setting DatVerbose to 27440 2022-04-13T22:25:45.824Z,1649888745.824 [DAT](INFO): DAT read: user:2> 2022-04-13T22:25:45.825Z,1649888745.825 [DAT](INFO): DAT read: DatVerbose | 27440 2022-04-13T22:25:45.826Z,1649888745.826 [DAT](INFO): set DatVerbose to 27440 2022-04-13T22:25:45.826Z,1649888745.826 [DAT](INFO): setting transmit power to 8 2022-04-13T22:25:46.076Z,1649888746.076 [DAT](INFO): DAT read: user:3> 2022-04-13T22:25:46.077Z,1649888746.077 [DAT](INFO): DAT read: TxPower | 8 (Max) 2022-04-13T22:25:46.078Z,1649888746.078 [DAT](INFO): set transmit power to 8 2022-04-13T22:25:46.078Z,1649888746.078 [DAT](INFO): setting local address to 9 2022-04-13T22:25:46.329Z,1649888746.329 [DAT](INFO): DAT read: user:4> 2022-04-13T22:25:46.330Z,1649888746.330 [DAT](INFO): DAT read: LocalAddr | 9 2022-04-13T22:25:46.330Z,1649888746.330 [DAT](INFO): set local address to 9 2022-04-13T22:25:46.330Z,1649888746.330 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:46.580Z,1649888746.580 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:46.832Z,1649888746.832 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:47.086Z,1649888747.086 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:47.336Z,1649888747.336 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:47.590Z,1649888747.590 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:47.840Z,1649888747.840 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:48.092Z,1649888748.092 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:48.356Z,1649888748.356 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:48.596Z,1649888748.596 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:48.848Z,1649888748.848 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:49.101Z,1649888749.101 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:49.352Z,1649888749.352 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:49.605Z,1649888749.605 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:49.856Z,1649888749.856 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:50.108Z,1649888750.108 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:50.360Z,1649888750.360 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:50.612Z,1649888750.612 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:50.864Z,1649888750.864 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:51.116Z,1649888751.116 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:51.368Z,1649888751.368 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:51.622Z,1649888751.622 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:51.872Z,1649888751.872 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:52.124Z,1649888752.124 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:52.376Z,1649888752.376 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:52.629Z,1649888752.629 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:52.880Z,1649888752.880 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:52.922Z,1649888752.922 [CommandExec](IMPORTANT): got command get DAT.verbosity 2022-04-13T22:25:52.923Z,1649888752.923 [CommandExec](IMPORTANT): DAT.verbosity 2 count 2022-04-13T22:25:53.132Z,1649888753.132 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:53.384Z,1649888753.384 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:53.636Z,1649888753.636 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:53.888Z,1649888753.888 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:54.140Z,1649888754.140 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:54.392Z,1649888754.392 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:54.644Z,1649888754.644 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:54.896Z,1649888754.896 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:55.149Z,1649888755.149 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:55.400Z,1649888755.400 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:55.660Z,1649888755.660 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:55.912Z,1649888755.912 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:56.166Z,1649888756.166 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:56.416Z,1649888756.416 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:56.668Z,1649888756.668 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:56.920Z,1649888756.920 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:57.172Z,1649888757.172 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:57.424Z,1649888757.424 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:57.676Z,1649888757.676 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:57.928Z,1649888757.928 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:58.180Z,1649888758.180 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:58.432Z,1649888758.432 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:58.684Z,1649888758.684 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:58.943Z,1649888758.943 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:59.197Z,1649888759.197 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:59.448Z,1649888759.448 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:59.700Z,1649888759.700 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:25:59.952Z,1649888759.952 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:00.204Z,1649888760.204 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:00.257Z,1649888760.257 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:26:00.258Z,1649888760.258 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:26:00.271Z,1649888760.271 [MissionManager](DEBUG): 2022-04-13T22:26:00.273Z,1649888760.273 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:26:00.456Z,1649888760.456 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:00.502Z,1649888760.502 [Default] Stopped 2022-04-13T22:26:00.502Z,1649888760.502 [Default](DEBUG): Aggregate::uninitialize Default 2022-04-13T22:26:00.502Z,1649888760.502 [Default:B.GoToSurface] Stopped 2022-04-13T22:26:00.502Z,1649888760.502 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-04-13T22:26:00.502Z,1649888760.502 [Default:CheckIn] Stopped 2022-04-13T22:26:00.502Z,1649888760.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-13T22:26:00.502Z,1649888760.502 [Default:CheckIn:Read_GPS] Stopped 2022-04-13T22:26:00.503Z,1649888760.503 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2022-04-13T22:26:00.503Z,1649888760.503 [senddata_direct_test] Running Loop=1 2022-04-13T22:26:00.503Z,1649888760.503 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2022-04-13T22:26:00.503Z,1649888760.503 [senddata_direct_test:A] Running Loop=1 2022-04-13T22:26:00.524Z,1649888760.524 [senddata_direct_test:A](INFO): Queuing up send data for Onboard.Pressure with destination: modem:1:_.pressure 2022-04-13T22:26:00.524Z,1649888760.524 [senddata_direct_test:A] Stopped 2022-04-13T22:26:00.525Z,1649888760.525 [senddata_direct_test:B] Running Loop=1 2022-04-13T22:26:00.708Z,1649888760.708 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:00.914Z,1649888760.914 [senddata_direct_test:B](INFO): Queuing up send data for Onboard.Temperature with destination: modem:1:_.temperature 2022-04-13T22:26:00.914Z,1649888760.914 [senddata_direct_test:B] Stopped 2022-04-13T22:26:00.914Z,1649888760.914 [senddata_direct_test:C] Running Loop=1 2022-04-13T22:26:00.960Z,1649888760.960 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:01.212Z,1649888761.212 [DAT](DEBUG): checking for time setting acknowledgment 2022-04-13T22:26:01.212Z,1649888761.212 [DAT](FAULT): failed to set time 2022-04-13T22:26:01.315Z,1649888761.315 [senddata_direct_test:C](INFO): Queuing up send data for Onboard.Humidity with destination: modem:1:_.humidity 2022-04-13T22:26:01.315Z,1649888761.315 [senddata_direct_test:C] Stopped 2022-04-13T22:26:01.315Z,1649888761.315 [senddata_direct_test](INFO): Completed senddata_direct_test 2022-04-13T22:26:01.315Z,1649888761.315 [MissionManager](INFO): senddata_direct_test is completed. 2022-04-13T22:26:01.315Z,1649888761.315 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2022-04-13T22:26:01.315Z,1649888761.315 [senddata_direct_test] Stopped 2022-04-13T22:26:01.316Z,1649888761.316 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2022-04-13T22:26:01.465Z,1649888761.465 [DAT](INFO): Setting time to: 22:26:1 And date to:4/13/2022 2022-04-13T22:26:01.717Z,1649888761.717 [DAT](INFO): DAT read: user:5> 2022-04-13T22:26:01.717Z,1649888761.717 [DAT](INFO): DAT read: Wed Apr 13, 2022 22:26:01 2022-04-13T22:26:01.718Z,1649888761.718 [DAT](INFO): Local DAT time set to Wed Apr 13, 2022 22:26:01 2022-04-13T22:26:01.732Z,1649888761.732 [MissionManager](IMPORTANT): Started mission Default 2022-04-13T22:26:01.733Z,1649888761.733 [Default] Running Loop=1 2022-04-13T22:26:01.733Z,1649888761.733 [Default](DEBUG): Aggregate::initialize Default 2022-04-13T22:26:01.733Z,1649888761.733 [Default:B.GoToSurface] Running Loop=1 2022-04-13T22:26:01.733Z,1649888761.733 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-04-13T22:26:01.733Z,1649888761.733 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-04-13T22:26:01.733Z,1649888761.733 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-04-13T22:26:01.734Z,1649888761.734 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-04-13T22:26:01.734Z,1649888761.734 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-04-13T22:26:01.734Z,1649888761.734 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-04-13T22:26:01.735Z,1649888761.735 [Default:A.Wait] Running Loop=1 2022-04-13T22:26:01.735Z,1649888761.735 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-04-13T22:26:01.969Z,1649888761.969 [DAT](INFO): modem://1: set _.pressure 0.521850 atmosphere 2022-04-13T22:26:01.969Z,1649888761.969 [DAT](INFO): #Outgoing data=1 2022-04-13T22:26:01.969Z,1649888761.969 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:26:02.221Z,1649888762.221 [DAT](INFO): setting remote address to 1 2022-04-13T22:26:02.472Z,1649888762.472 [DAT](INFO): DAT read: user:6> 2022-04-13T22:26:02.473Z,1649888762.473 [DAT](INFO): DAT read: RemoteAddr | 1 2022-04-13T22:26:02.474Z,1649888762.474 [DAT](INFO): set remote address to 1 2022-04-13T22:26:02.474Z,1649888762.474 [DAT](INFO): entering online mode 2022-04-13T22:26:02.725Z,1649888762.725 [DAT](INFO): DAT read: user:7> 2022-04-13T22:26:02.725Z,1649888762.725 [DAT](INFO): DAT read: 2022-04-13T22:26:02.726Z,1649888762.726 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2022-04-13T22:26:02.727Z,1649888762.727 [DAT](INFO): commRate: 800 2022-04-13T22:26:02.727Z,1649888762.727 [DAT](INFO): online mode acknowledged 2022-04-13T22:26:02.727Z,1649888762.727 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:26:06.001Z,1649888766.001 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:26:05.5185 2022-04-13T22:26:06.001Z,1649888766.001 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:26:15.030Z,1649888775.030 [Default:A.Wait](INFO): Done Waiting. 2022-04-13T22:26:15.030Z,1649888775.030 [Default:A.Wait] Stopped 2022-04-13T22:26:15.030Z,1649888775.030 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-04-13T22:26:15.435Z,1649888775.435 [Default:CheckIn] Running Loop=1 2022-04-13T22:26:15.435Z,1649888775.435 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-13T22:26:15.435Z,1649888775.435 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-13T22:26:16.080Z,1649888776.080 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:26:16.080Z,1649888776.080 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:26:16.333Z,1649888776.333 [DAT](INFO): modem://1: set _.temperature 23.655237 celsius 2022-04-13T22:26:16.333Z,1649888776.333 [DAT](INFO): #Outgoing data=1 2022-04-13T22:26:16.333Z,1649888776.333 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:26:16.584Z,1649888776.584 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:26:19.863Z,1649888779.863 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:26:19.3685 2022-04-13T22:26:19.864Z,1649888779.864 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:26:28.353Z,1649888788.353 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-04-13T22:26:28.353Z,1649888788.353 [NAL9602] Data Fault, FailCount= 1 2022-04-13T22:26:28.353Z,1649888788.353 [NAL9602](ERROR): Data Fault 2022-04-13T22:26:28.399Z,1649888788.399 [CBIT](ERROR): Data Fault in component: NAL9602 2022-04-13T22:26:28.753Z,1649888788.753 [NAL9602](INFO): Powering down 2022-04-13T22:26:29.643Z,1649888789.643 [CBIT](INFO): Clearing failed state for component NAL9602 2022-04-13T22:26:29.643Z,1649888789.643 [NAL9602] No Fault, FailCount= 1 2022-04-13T22:26:29.948Z,1649888789.948 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:26:29.949Z,1649888789.949 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:26:30.201Z,1649888790.201 [DAT](INFO): modem://1: set _.humidity 22.268343 percent 2022-04-13T22:26:30.201Z,1649888790.201 [DAT](INFO): #Outgoing data=2 2022-04-13T22:26:30.201Z,1649888790.201 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:26:30.452Z,1649888790.452 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:26:33.729Z,1649888793.729 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:26:30.2185 2022-04-13T22:26:33.729Z,1649888793.729 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:26:43.820Z,1649888803.820 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:26:43.820Z,1649888803.820 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:26:44.072Z,1649888804.072 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:26:44.324Z,1649888804.324 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:26:47.603Z,1649888807.603 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:26:44.1185 2022-04-13T22:26:47.604Z,1649888807.604 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:26:57.680Z,1649888817.680 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:26:57.680Z,1649888817.680 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:26:57.932Z,1649888817.932 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:26:58.185Z,1649888818.185 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:26:58.436Z,1649888818.436 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:26:59.058Z,1649888819.058 [NAL9602](INFO): Powering up NAL9602 2022-04-13T22:27:01.713Z,1649888821.713 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:26:58.2184 2022-04-13T22:27:01.713Z,1649888821.713 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:27:09.961Z,1649888829.961 [NAL9602](INFO): NAL9602 initialized 2022-04-13T22:27:11.800Z,1649888831.800 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:27:11.800Z,1649888831.800 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:27:12.052Z,1649888832.052 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:27:12.304Z,1649888832.304 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:27:12.556Z,1649888832.556 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:27:15.833Z,1649888835.833 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:27:12.3684 2022-04-13T22:27:15.833Z,1649888835.833 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:27:25.912Z,1649888845.912 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:27:25.912Z,1649888845.912 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:27:26.164Z,1649888846.164 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:27:48.772Z,1649888868.772 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2022-04-13T22:27:48.772Z,1649888868.772 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-04-13T22:27:48.783Z,1649888868.783 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-04-13T22:27:49.174Z,1649888869.174 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-04-13T22:27:49.174Z,1649888869.174 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2022-04-13T22:30:46.531Z,1649889046.531 [CBIT](INFO): Clearing failed state for component DropWeight 2022-04-13T22:30:46.531Z,1649889046.531 [DropWeight] No Fault, FailCount= 1 2022-04-13T22:30:49.780Z,1649889049.780 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2022-04-13T22:30:49.780Z,1649889049.780 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-04-13T22:30:49.798Z,1649889049.798 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-04-13T22:30:50.178Z,1649889050.178 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-04-13T22:30:50.178Z,1649889050.178 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2022-04-13T22:31:15.666Z,1649889075.666 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-04-13T22:26:15.4Z 2022-04-13T22:31:15.666Z,1649889075.666 [Default:CheckIn:Read_GPS] Stopped 2022-04-13T22:31:15.667Z,1649889075.667 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-13T22:31:16.046Z,1649889076.046 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-04-13T22:31:21.100Z,1649889081.100 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20220413T221533/Courier0004.lzma 2022-04-13T22:31:22.098Z,1649889082.098 [DataOverHttps](INFO): Moved sent file to Logs/20220413T221533/Courier0004.lzma.bak 2022-04-13T22:31:22.098Z,1649889082.098 [DataOverHttps](INFO): SBD MOMSN=16644674 2022-04-13T22:31:38.079Z,1649889098.079 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220413T222518/Courier0000.lzma 2022-04-13T22:31:39.078Z,1649889099.078 [DataOverHttps](INFO): Moved sent file to Logs/20220413T222518/Courier0000.lzma.bak 2022-04-13T22:31:39.078Z,1649889099.078 [DataOverHttps](INFO): SBD MOMSN=16644676 2022-04-13T22:31:54.943Z,1649889114.943 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20220402T011830/Express0022.lzma 2022-04-13T22:31:55.946Z,1649889115.946 [DataOverHttps](INFO): Moved sent file to Logs/20220402T011830/Express0022.lzma.bak 2022-04-13T22:31:55.946Z,1649889115.946 [DataOverHttps](INFO): SBD MOMSN=16644679 2022-04-13T22:32:11.865Z,1649889131.865 [DataOverHttps](INFO): Sending 1011 bytes from file Logs/20220413T221533/Express0001.lzma 2022-04-13T22:32:12.866Z,1649889132.866 [DataOverHttps](INFO): Moved sent file to Logs/20220413T221533/Express0001.lzma.bak 2022-04-13T22:32:12.866Z,1649889132.866 [DataOverHttps](INFO): SBD MOMSN=16644682 2022-04-13T22:32:28.833Z,1649889148.833 [DataOverHttps](INFO): Sending 802 bytes from file Logs/20220413T221533/Express0005.lzma 2022-04-13T22:32:29.834Z,1649889149.834 [DataOverHttps](INFO): Moved sent file to Logs/20220413T221533/Express0005.lzma.bak 2022-04-13T22:32:29.834Z,1649889149.834 [DataOverHttps](INFO): SBD MOMSN=16644707 2022-04-13T22:32:46.317Z,1649889166.317 [DataOverHttps](INFO): Sending 599 bytes from file Logs/20220413T222518/Express0001.lzma 2022-04-13T22:32:47.318Z,1649889167.318 [DataOverHttps](INFO): Moved sent file to Logs/20220413T222518/Express0001.lzma.bak 2022-04-13T22:32:47.318Z,1649889167.318 [DataOverHttps](INFO): SBD MOMSN=16644753 2022-04-13T22:32:49.465Z,1649889169.465 [Default:CheckIn:Read_Iridium] Stopped 2022-04-13T22:32:49.466Z,1649889169.466 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-13T22:32:49.466Z,1649889169.466 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.