2020-08-25T18:14:43.514Z,1598379283.514 [CommandLine](IMPORTANT): got command restart logs
2020-08-25T18:16:03.604Z,1598379363.604 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml
2020-08-25T18:16:03.605Z,1598379363.605 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml
2020-08-25T18:16:03.637Z,1598379363.637 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_test">

    <SendData Service="Direct" Destination="modem:6:_.pressure">
        <Sensor:Onboard.Pressure/><Units:atmosphere/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:6:_.temperature">
        <Sensor:Onboard.Temperature/><Units:celsius/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:6:_.humidity">
        <Sensor:Onboard.Humidity/><Units:percent/>
    </SendData>

</Mission>


2020-08-25T18:16:03.639Z,1598379363.639 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml
2020-08-25T18:16:03.857Z,1598379363.857 [Default] Stopped
2020-08-25T18:16:03.857Z,1598379363.857 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-25T18:16:03.857Z,1598379363.857 [Default:B.GoToSurface] Stopped
2020-08-25T18:16:03.857Z,1598379363.857 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T18:16:03.857Z,1598379363.857 [Default:CheckIn] Stopped
2020-08-25T18:16:03.858Z,1598379363.858 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:16:03.858Z,1598379363.858 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:16:03.858Z,1598379363.858 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:16:03.858Z,1598379363.858 [MissionManager](IMPORTANT): Started mission senddata_direct_test
2020-08-25T18:16:03.858Z,1598379363.858 [senddata_direct_test] Running Loop=1
2020-08-25T18:16:03.858Z,1598379363.858 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test
2020-08-25T18:16:03.859Z,1598379363.859 [senddata_direct_test:A] Running Loop=1
2020-08-25T18:16:03.859Z,1598379363.859 [senddata_direct_test:A] Stopped
2020-08-25T18:16:03.859Z,1598379363.859 [senddata_direct_test:B] Running Loop=1
2020-08-25T18:16:04.259Z,1598379364.259 [senddata_direct_test:B] Stopped
2020-08-25T18:16:04.259Z,1598379364.259 [senddata_direct_test:C] Running Loop=1
2020-08-25T18:16:04.666Z,1598379364.666 [senddata_direct_test:C] Stopped
2020-08-25T18:16:04.667Z,1598379364.667 [senddata_direct_test](INFO): Completed senddata_direct_test
2020-08-25T18:16:04.667Z,1598379364.667 [MissionManager](INFO): senddata_direct_test is completed.
2020-08-25T18:16:04.667Z,1598379364.667 [MissionManager](INFO): Uninitializing Mission senddata_direct_test
2020-08-25T18:16:04.667Z,1598379364.667 [senddata_direct_test] Stopped
2020-08-25T18:16:04.667Z,1598379364.667 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test
2020-08-25T18:16:05.067Z,1598379365.067 [MissionManager](IMPORTANT): Started mission Default
2020-08-25T18:16:05.067Z,1598379365.067 [Default] Running Loop=1
2020-08-25T18:16:05.067Z,1598379365.067 [Default](DEBUG): Aggregate::initialize Default
2020-08-25T18:16:05.067Z,1598379365.067 [Default:B.GoToSurface] Running Loop=1
2020-08-25T18:16:05.068Z,1598379365.068 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T18:16:05.068Z,1598379365.068 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T18:16:05.068Z,1598379365.068 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T18:16:05.068Z,1598379365.068 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T18:16:05.069Z,1598379365.069 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T18:16:05.069Z,1598379365.069 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T18:16:05.069Z,1598379365.069 [Default:A.Wait] Running Loop=1
2020-08-25T18:16:05.069Z,1598379365.069 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:16:05.459Z,1598379365.459 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T18:16:08.691Z,1598379368.691 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:15:48.9380

2020-08-25T18:16:08.691Z,1598379368.691 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T18:16:18.402Z,1598379378.402 [Default:A.Wait](INFO): Done Waiting.
2020-08-25T18:16:18.402Z,1598379378.402 [Default:A.Wait] Stopped
2020-08-25T18:16:18.402Z,1598379378.402 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:16:18.810Z,1598379378.810 [Default:CheckIn] Running Loop=1
2020-08-25T18:16:18.810Z,1598379378.810 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:16:18.811Z,1598379378.811 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:16:20.817Z,1598379380.817 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181619.00,A,3648.16638,N,12147.28109,W,0.194,306.48,250820,,,A*72
2020-08-25T18:16:20.819Z,1598379380.819 [NAL9602](INFO): GPS fix at 20200825T181619: (36.802773, -121.788018)
2020-08-25T18:16:20.829Z,1598379380.829 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:16:20.829Z,1598379380.829 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:16:25.668Z,1598379385.668 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T18:16:25.668Z,1598379385.668 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T18:16:26.088Z,1598379386.088 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T18:16:26.497Z,1598379386.497 [DAT](INFO): modem://6: set _.pressure 0.506848 atmosphere
2020-08-25T18:16:26.497Z,1598379386.497 [DAT](INFO): #Outgoing data=4
2020-08-25T18:16:26.497Z,1598379386.497 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T18:16:26.892Z,1598379386.892 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T18:16:30.153Z,1598379390.153 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:16:10.3880

2020-08-25T18:16:30.153Z,1598379390.153 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T18:16:35.898Z,1598379395.898 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T173544/Courier0025.lzma
2020-08-25T18:16:36.900Z,1598379396.900 [DataOverHttps](INFO): Moved sent file to Logs/20200825T173544/Courier0025.lzma.bak
2020-08-25T18:16:36.901Z,1598379396.901 [DataOverHttps](INFO): SBD MOMSN=12615544
2020-08-25T18:16:37.036Z,1598379397.036 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T18:16:47.140Z,1598379407.140 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T18:16:47.140Z,1598379407.140 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T18:16:47.538Z,1598379407.538 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T18:16:47.948Z,1598379407.948 [DAT](INFO): modem://6: set _.temperature 21.519953 celsius
2020-08-25T18:16:47.949Z,1598379407.949 [DAT](INFO): #Outgoing data=4
2020-08-25T18:16:47.949Z,1598379407.949 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T18:16:48.351Z,1598379408.351 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T18:16:51.586Z,1598379411.586 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:16:31.8380

2020-08-25T18:16:51.587Z,1598379411.587 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T18:16:54.154Z,1598379414.154 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20200825T181443/Courier0000.lzma
2020-08-25T18:16:55.156Z,1598379415.156 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0000.lzma.bak
2020-08-25T18:16:55.156Z,1598379415.156 [DataOverHttps](INFO): SBD MOMSN=12615546
2020-08-25T18:17:07.741Z,1598379427.741 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T18:17:08.552Z,1598379428.552 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T18:17:08.552Z,1598379428.552 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T18:17:08.952Z,1598379428.952 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T18:17:09.360Z,1598379429.360 [DAT](INFO): modem://6: set _.humidity 24.343792 percent
2020-08-25T18:17:09.361Z,1598379429.361 [DAT](INFO): #Outgoing data=4
2020-08-25T18:17:09.361Z,1598379429.361 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T18:17:13.555Z,1598379433.555 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20200825T173544/Express0026.lzma
2020-08-25T18:17:14.556Z,1598379434.556 [DataOverHttps](INFO): Moved sent file to Logs/20200825T173544/Express0026.lzma.bak
2020-08-25T18:17:14.556Z,1598379434.556 [DataOverHttps](INFO): SBD MOMSN=12615550
2020-08-25T18:17:31.967Z,1598379451.967 [DataOverHttps](INFO): Sending 416 bytes from file Logs/20200825T181443/Express0001.lzma
2020-08-25T18:17:32.968Z,1598379452.968 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0001.lzma.bak
2020-08-25T18:17:32.968Z,1598379452.968 [DataOverHttps](INFO): SBD MOMSN=12615556
2020-08-25T18:17:35.647Z,1598379455.647 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:17:35.647Z,1598379455.647 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:17:35.647Z,1598379455.647 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:22:36.236Z,1598379756.236 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:22:36.236Z,1598379756.236 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:22:36.236Z,1598379756.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:22:36.236Z,1598379756.236 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:22:36.641Z,1598379756.641 [Default:CheckIn:D] Stopped
2020-08-25T18:22:36.642Z,1598379756.642 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:22:37.058Z,1598379757.058 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.526232 min 
2020-08-25T18:22:37.058Z,1598379757.058 [Default:CheckIn:E] Stopped
2020-08-25T18:22:37.058Z,1598379757.058 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:22:37.058Z,1598379757.058 [Default:CheckIn] Stopped
2020-08-25T18:22:37.059Z,1598379757.059 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:22:37.059Z,1598379757.059 [Default:CheckIn](INFO): Running loop #2
2020-08-25T18:22:37.059Z,1598379757.059 [Default:CheckIn] Running Loop=2
2020-08-25T18:22:37.059Z,1598379757.059 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:22:37.059Z,1598379757.059 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:22:39.057Z,1598379759.057 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182237.00,A,3648.16314,N,12147.28009,W,0.019,311.12,250820,,,A*7E
2020-08-25T18:22:39.059Z,1598379759.059 [NAL9602](INFO): GPS fix at 20200825T182237: (36.802719, -121.788002)
2020-08-25T18:22:39.068Z,1598379759.068 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:22:39.068Z,1598379759.068 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:22:46.686Z,1598379766.686 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0003.lzma
2020-08-25T18:22:47.688Z,1598379767.688 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0003.lzma.bak
2020-08-25T18:22:47.688Z,1598379767.688 [DataOverHttps](INFO): SBD MOMSN=12615598
2020-08-25T18:23:05.695Z,1598379785.695 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20200825T181443/Express0004.lzma
2020-08-25T18:23:06.696Z,1598379786.696 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0004.lzma.bak
2020-08-25T18:23:06.696Z,1598379786.696 [DataOverHttps](INFO): SBD MOMSN=12615601
2020-08-25T18:23:09.764Z,1598379789.764 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T18:23:09.846Z,1598379789.846 [NAL9602](FAULT): received: 
+CSQ:0

OK14, 2, 0, 0, 0

OK
2020-08-25T18:23:09.846Z,1598379789.846 [NAL9602] Data Fault, FailCount= 1
2020-08-25T18:23:09.847Z,1598379789.847 [NAL9602](ERROR): Data Fault
2020-08-25T18:23:09.857Z,1598379789.857 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:23:09.858Z,1598379789.858 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:23:09.858Z,1598379789.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:23:09.867Z,1598379789.867 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T18:23:10.163Z,1598379790.163 [NAL9602](INFO): Powering down
2020-08-25T18:23:11.025Z,1598379791.025 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T18:23:11.026Z,1598379791.026 [NAL9602] No Fault, FailCount= 1
2020-08-25T18:23:40.463Z,1598379820.463 [NAL9602](INFO): Powering up NAL9602
2020-08-25T18:23:51.375Z,1598379831.375 [NAL9602](INFO): NAL9602 initialized
2020-08-25T18:24:22.479Z,1598379862.479 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T18:28:10.363Z,1598380090.363 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:28:10.363Z,1598380090.363 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:28:10.363Z,1598380090.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:28:10.364Z,1598380090.364 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:28:10.780Z,1598380090.780 [Default:CheckIn:D] Stopped
2020-08-25T18:28:10.780Z,1598380090.780 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:28:11.173Z,1598380091.173 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.095214 min 
2020-08-25T18:28:11.174Z,1598380091.174 [Default:CheckIn:E] Stopped
2020-08-25T18:28:11.174Z,1598380091.174 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:28:11.174Z,1598380091.174 [Default:CheckIn] Stopped
2020-08-25T18:28:11.174Z,1598380091.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:28:11.217Z,1598380091.217 [Default:CheckIn](INFO): Running loop #3
2020-08-25T18:28:11.217Z,1598380091.217 [Default:CheckIn] Running Loop=3
2020-08-25T18:28:11.217Z,1598380091.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:28:11.217Z,1598380091.217 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:28:14.796Z,1598380094.796 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T18:28:27.725Z,1598380107.725 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182826.00,A,3648.16235,N,12147.28491,W,0.525,0.00,250820,,,A*79
2020-08-25T18:28:27.739Z,1598380107.739 [NAL9602](INFO): GPS fix at 20200825T182826: (36.802706, -121.788082)
2020-08-25T18:28:27.761Z,1598380107.761 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:28:27.761Z,1598380107.761 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:28:39.542Z,1598380119.542 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0006.lzma
2020-08-25T18:28:40.544Z,1598380120.544 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0006.lzma.bak
2020-08-25T18:28:40.544Z,1598380120.544 [DataOverHttps](INFO): SBD MOMSN=12615627
2020-08-25T18:28:57.899Z,1598380137.899 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20200825T181443/Express0007.lzma
2020-08-25T18:28:58.901Z,1598380138.901 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0007.lzma.bak
2020-08-25T18:28:58.901Z,1598380138.901 [DataOverHttps](INFO): SBD MOMSN=12615638
2020-08-25T18:29:00.191Z,1598380140.191 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T18:29:01.833Z,1598380141.833 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:29:01.834Z,1598380141.834 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:29:01.834Z,1598380141.834 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:34:02.399Z,1598380442.399 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:34:02.400Z,1598380442.400 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:34:02.400Z,1598380442.400 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:34:02.400Z,1598380442.400 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:34:02.805Z,1598380442.805 [Default:CheckIn:D] Stopped
2020-08-25T18:34:02.805Z,1598380442.805 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.962299 min 
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn:E] Stopped
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn] Stopped
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn](INFO): Running loop #4
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn] Running Loop=4
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:34:03.209Z,1598380443.209 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:34:05.217Z,1598380445.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183403.00,A,3648.16122,N,12147.28428,W,0.136,0.00,250820,,,A*72
2020-08-25T18:34:05.219Z,1598380445.219 [NAL9602](INFO): GPS fix at 20200825T183403: (36.802687, -121.788071)
2020-08-25T18:34:05.228Z,1598380445.228 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:34:05.228Z,1598380445.228 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:34:13.582Z,1598380453.582 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0009.lzma
2020-08-25T18:34:14.584Z,1598380454.584 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0009.lzma.bak
2020-08-25T18:34:14.584Z,1598380454.584 [DataOverHttps](INFO): SBD MOMSN=12615672
2020-08-25T18:34:36.310Z,1598380476.310 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200825T181443/Express0010.lzma
2020-08-25T18:34:37.312Z,1598380477.312 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0010.lzma.bak
2020-08-25T18:34:37.312Z,1598380477.312 [DataOverHttps](INFO): SBD MOMSN=12615675
2020-08-25T18:34:40.404Z,1598380480.404 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:34:40.405Z,1598380480.405 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:34:40.405Z,1598380480.405 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:38:24.209Z,1598380704.209 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:38:24.209Z,1598380704.209 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:38:42.571Z,1598380722.571 [CommandLine](IMPORTANT): got command strobe off
2020-08-25T18:38:42.572Z,1598380722.572 [CommandLine](IMPORTANT): Deactivating strobe
2020-08-25T18:38:58.985Z,1598380738.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:38:58.985Z,1598380738.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:39:16.365Z,1598380756.365 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:39:16.365Z,1598380756.365 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:39:16.765Z,1598380756.765 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T18:39:41.011Z,1598380781.011 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:39:41.011Z,1598380781.011 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:39:41.011Z,1598380781.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:39:41.012Z,1598380781.012 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:39:41.427Z,1598380781.427 [Default:CheckIn:D] Stopped
2020-08-25T18:39:41.427Z,1598380781.427 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:39:41.814Z,1598380781.814 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.605992 min 
2020-08-25T18:39:41.814Z,1598380781.814 [Default:CheckIn:E] Stopped
2020-08-25T18:39:41.814Z,1598380781.814 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:39:41.814Z,1598380781.814 [Default:CheckIn] Stopped
2020-08-25T18:39:41.815Z,1598380781.815 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:39:41.815Z,1598380781.815 [Default:CheckIn](INFO): Running loop #5
2020-08-25T18:39:41.815Z,1598380781.815 [Default:CheckIn] Running Loop=5
2020-08-25T18:39:41.815Z,1598380781.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:39:41.815Z,1598380781.815 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:39:43.837Z,1598380783.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183943.00,A,3648.16288,N,12147.28009,W,0.175,0.00,250820,,,D*7D
2020-08-25T18:39:43.839Z,1598380783.839 [NAL9602](INFO): GPS fix at 20200825T183943: (36.802715, -121.788002)
2020-08-25T18:39:43.848Z,1598380783.848 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:39:43.848Z,1598380783.848 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:39:51.262Z,1598380791.262 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0012.lzma
2020-08-25T18:39:52.264Z,1598380792.264 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0012.lzma.bak
2020-08-25T18:39:52.264Z,1598380792.264 [DataOverHttps](INFO): SBD MOMSN=12615706
2020-08-25T18:40:09.418Z,1598380809.418 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20200825T181443/Express0013.lzma
2020-08-25T18:40:10.420Z,1598380810.420 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0013.lzma.bak
2020-08-25T18:40:10.420Z,1598380810.420 [DataOverHttps](INFO): SBD MOMSN=12615709
2020-08-25T18:40:13.342Z,1598380813.342 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:40:13.342Z,1598380813.342 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:40:13.342Z,1598380813.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:40:16.147Z,1598380816.147 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T18:45:14.052Z,1598381114.052 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:45:14.052Z,1598381114.052 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:45:14.052Z,1598381114.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:45:14.053Z,1598381114.053 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:45:14.361Z,1598381114.361 [Default:CheckIn:D] Stopped
2020-08-25T18:45:14.361Z,1598381114.361 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:45:14.751Z,1598381114.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.154897 min 
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn:E] Stopped
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn] Stopped
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn](INFO): Running loop #6
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn] Running Loop=6
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:45:14.752Z,1598381114.752 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:45:16.737Z,1598381116.737 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184516.00,A,3648.16065,N,12147.28639,W,0.214,0.00,250820,,,D*76
2020-08-25T18:45:16.739Z,1598381116.739 [NAL9602](INFO): GPS fix at 20200825T184516: (36.802678, -121.788106)
2020-08-25T18:45:16.749Z,1598381116.749 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:45:16.749Z,1598381116.749 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:45:24.915Z,1598381124.915 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200825T181443/Courier0015.lzma
2020-08-25T18:45:25.916Z,1598381125.916 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0015.lzma.bak
2020-08-25T18:45:25.916Z,1598381125.916 [DataOverHttps](INFO): SBD MOMSN=12615715
2020-08-25T18:45:43.467Z,1598381143.467 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200825T181443/Express0016.lzma
2020-08-25T18:45:44.464Z,1598381144.464 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0016.lzma.bak
2020-08-25T18:45:44.464Z,1598381144.464 [DataOverHttps](INFO): SBD MOMSN=12615718
2020-08-25T18:45:47.058Z,1598381147.058 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:45:47.058Z,1598381147.058 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:45:47.082Z,1598381147.082 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:46:18.952Z,1598381178.952 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:46:18.953Z,1598381178.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:46:33.093Z,1598381193.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:46:33.093Z,1598381193.093 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:47:11.469Z,1598381231.469 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:47:11.469Z,1598381231.469 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:47:37.329Z,1598381257.329 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:47:37.329Z,1598381257.329 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:48:03.585Z,1598381283.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:48:03.585Z,1598381283.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:48:40.759Z,1598381320.759 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:48:40.759Z,1598381320.759 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:49:08.633Z,1598381348.633 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:49:08.633Z,1598381348.633 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:49:47.815Z,1598381387.815 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T18:49:47.815Z,1598381387.815 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T18:50:18.927Z,1598381418.927 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T18:50:37.631Z,1598381437.631 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-08-25T18:50:47.756Z,1598381447.756 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:50:47.756Z,1598381447.756 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:50:47.756Z,1598381447.756 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:50:47.756Z,1598381447.756 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:50:48.142Z,1598381448.142 [Default:CheckIn:D] Stopped
2020-08-25T18:50:48.142Z,1598381448.142 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:50:48.558Z,1598381448.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.717908 min 
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn:E] Stopped
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn] Stopped
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn](INFO): Running loop #7
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn] Running Loop=7
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:50:48.558Z,1598381448.558 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:50:50.540Z,1598381450.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185050.00,A,3648.16261,N,12147.28297,W,0.117,0.00,250820,,,D*76
2020-08-25T18:50:50.542Z,1598381450.542 [NAL9602](INFO): GPS fix at 20200825T185050: (36.802710, -121.788049)
2020-08-25T18:50:50.585Z,1598381450.585 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:50:50.585Z,1598381450.585 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:50:54.260Z,1598381454.260 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-25T18:50:54.262Z,1598381454.262 [BPC1](INFO): Received data from all battery sticks.
2020-08-25T18:50:58.874Z,1598381458.874 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0018.lzma
2020-08-25T18:50:59.876Z,1598381459.876 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0018.lzma.bak
2020-08-25T18:50:59.877Z,1598381459.877 [DataOverHttps](INFO): SBD MOMSN=12615759
2020-08-25T18:51:18.342Z,1598381478.342 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20200825T181443/Express0019.lzma
2020-08-25T18:51:19.344Z,1598381479.344 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0019.lzma.bak
2020-08-25T18:51:19.344Z,1598381479.344 [DataOverHttps](INFO): SBD MOMSN=12615762
2020-08-25T18:51:22.138Z,1598381482.138 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:51:22.139Z,1598381482.139 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:51:22.139Z,1598381482.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:51:23.339Z,1598381483.339 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T18:56:22.774Z,1598381782.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T18:56:22.774Z,1598381782.774 [Default:CheckIn:C.Wait] Stopped
2020-08-25T18:56:22.774Z,1598381782.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T18:56:22.774Z,1598381782.774 [Default:CheckIn:D] Running Loop=1
2020-08-25T18:56:23.190Z,1598381783.190 [Default:CheckIn:D] Stopped
2020-08-25T18:56:23.190Z,1598381783.190 [Default:CheckIn:E] Running Loop=1
2020-08-25T18:56:23.581Z,1598381783.581 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.302043 min 
2020-08-25T18:56:23.581Z,1598381783.581 [Default:CheckIn:E] Stopped
2020-08-25T18:56:23.582Z,1598381783.582 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T18:56:23.582Z,1598381783.582 [Default:CheckIn] Stopped
2020-08-25T18:56:23.582Z,1598381783.582 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T18:56:23.582Z,1598381783.582 [Default:CheckIn](INFO): Running loop #8
2020-08-25T18:56:23.582Z,1598381783.582 [Default:CheckIn] Running Loop=8
2020-08-25T18:56:23.603Z,1598381783.603 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T18:56:23.603Z,1598381783.603 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T18:56:25.597Z,1598381785.597 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185625.00,A,3648.16137,N,12147.28088,W,0.233,0.00,250820,,,D*7B
2020-08-25T18:56:25.599Z,1598381785.599 [NAL9602](INFO): GPS fix at 20200825T185625: (36.802689, -121.788015)
2020-08-25T18:56:25.634Z,1598381785.634 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T18:56:25.634Z,1598381785.634 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T18:56:37.631Z,1598381797.631 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20200825T181443/Courier0021.lzma
2020-08-25T18:56:38.632Z,1598381798.632 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0021.lzma.bak
2020-08-25T18:56:38.633Z,1598381798.633 [DataOverHttps](INFO): SBD MOMSN=12615773
2020-08-25T18:56:56.342Z,1598381816.342 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200825T181443/Express0022.lzma
2020-08-25T18:56:56.388Z,1598381816.388 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T18:56:56.470Z,1598381816.470 [NAL9602](FAULT): received: 
+CSQ:0

OK14, 2, 0, 0, 0

OK
2020-08-25T18:56:56.470Z,1598381816.470 [NAL9602] Data Fault, FailCount= 1
2020-08-25T18:56:56.470Z,1598381816.470 [NAL9602](ERROR): Data Fault
2020-08-25T18:56:56.487Z,1598381816.487 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T18:56:56.784Z,1598381816.784 [NAL9602](INFO): Powering down
2020-08-25T18:56:57.344Z,1598381817.344 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0022.lzma.bak
2020-08-25T18:56:57.344Z,1598381817.344 [DataOverHttps](INFO): SBD MOMSN=12615776
2020-08-25T18:56:57.637Z,1598381817.637 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T18:56:57.637Z,1598381817.637 [NAL9602] No Fault, FailCount= 1
2020-08-25T18:57:00.854Z,1598381820.854 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T18:57:00.855Z,1598381820.855 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T18:57:00.855Z,1598381820.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T18:57:27.087Z,1598381847.087 [NAL9602](INFO): Powering up NAL9602
2020-08-25T18:57:37.995Z,1598381857.995 [NAL9602](INFO): NAL9602 initialized
2020-08-25T18:58:09.103Z,1598381889.103 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:02:01.431Z,1598382121.431 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:02:01.431Z,1598382121.431 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:02:01.431Z,1598382121.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:02:01.432Z,1598382121.432 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:02:01.832Z,1598382121.832 [Default:CheckIn:D] Stopped
2020-08-25T19:02:01.832Z,1598382121.832 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:02:02.242Z,1598382122.242 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.946073 min 
2020-08-25T19:02:02.242Z,1598382122.242 [Default:CheckIn:E] Stopped
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn] Stopped
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn](INFO): Running loop #9
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn] Running Loop=9
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:02:02.243Z,1598382122.243 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:02:04.258Z,1598382124.258 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190203.00,A,3648.16147,N,12147.28392,W,0.622,5.51,250820,,,D*75
2020-08-25T19:02:04.260Z,1598382124.260 [NAL9602](INFO): GPS fix at 20200825T190203: (36.802691, -121.788065)
2020-08-25T19:02:04.286Z,1598382124.286 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:02:04.286Z,1598382124.286 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:02:05.864Z,1598382125.864 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:02:12.890Z,1598382132.890 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0024.lzma
2020-08-25T19:02:13.892Z,1598382133.892 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0024.lzma.bak
2020-08-25T19:02:13.892Z,1598382133.892 [DataOverHttps](INFO): SBD MOMSN=12615811
2020-08-25T19:02:35.690Z,1598382155.690 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20200825T181443/Express0025.lzma
2020-08-25T19:02:36.615Z,1598382156.615 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:02:36.692Z,1598382156.692 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0025.lzma.bak
2020-08-25T19:02:36.692Z,1598382156.692 [DataOverHttps](INFO): SBD MOMSN=12615814
2020-08-25T19:02:39.874Z,1598382159.874 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:02:39.874Z,1598382159.874 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:02:39.874Z,1598382159.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:03:34.507Z,1598382214.507 [CommandLine](IMPORTANT): got command show variable address
2020-08-25T19:03:34.508Z,1598382214.508 [CommandLine](IMPORTANT): acoustic_contact_address (unknown)
2020-08-25T19:03:34.530Z,1598382214.530 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2020-08-25T19:03:34.530Z,1598382214.530 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2020-08-25T19:03:34.531Z,1598382214.531 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2020-08-25T19:03:34.533Z,1598382214.533 [CommandLine](IMPORTANT): DAT.localAddress (count)
2020-08-25T19:03:34.533Z,1598382214.533 [CommandLine](IMPORTANT): DAT.sbdAddress (enum)
2020-08-25T19:03:34.534Z,1598382214.534 [CommandLine](IMPORTANT): DAT.transponderAddress (enum)
2020-08-25T19:03:34.537Z,1598382214.537 [CommandLine](IMPORTANT): Micromodem.localAddress (enum)
2020-08-25T19:03:34.537Z,1598382214.537 [CommandLine](IMPORTANT): Micromodem.destinationAddress (enum)
2020-08-25T19:03:34.721Z,1598382214.721 [CommandLine](IMPORTANT): DAT.remoteAddress (enum)
2020-08-25T19:03:34.722Z,1598382214.722 [CommandLine](IMPORTANT): DAT.localAddressReading (enum)
2020-08-25T19:03:45.565Z,1598382225.565 [CommandLine](IMPORTANT): got command configSet DAT.sbdAddress 6.000000 enum persist
2020-08-25T19:03:48.379Z,1598382228.379 [CommandLine](IMPORTANT): got command failComponent hardware DAT
2020-08-25T19:03:48.379Z,1598382228.379 [DAT] Hardware Fault, FailCount= 1
2020-08-25T19:03:48.379Z,1598382228.379 [DAT](ERROR): Hardware Fault
2020-08-25T19:03:48.379Z,1598382228.379 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault
2020-08-25T19:03:48.539Z,1598382228.539 [DAT](INFO): Powering down
2020-08-25T19:03:48.680Z,1598382228.680 [CBIT](ERROR): Hardware Fault in component: DAT
2020-08-25T19:03:49.365Z,1598382229.365 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T19:03:49.365Z,1598382229.365 [DAT] No Fault, FailCount= 1
2020-08-25T19:03:51.773Z,1598382231.773 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T19:03:51.773Z,1598382231.773 [DAT](INFO): Powering up
2020-08-25T19:03:51.773Z,1598382231.773 [DAT](DEBUG): Initializing DAT.
2020-08-25T19:03:51.786Z,1598382231.786 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T19:04:02.272Z,1598382242.272 [DAT](INFO): DAT read: 

2020-08-25T19:04:02.273Z,1598382242.273 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T19:04:03.484Z,1598382243.484 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T19:04:03.485Z,1598382243.485 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T19:04:03.486Z,1598382243.486 [DAT](INFO): DAT read: Aug 25 2020 19:03:40 

2020-08-25T19:04:04.292Z,1598382244.292 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T19:04:04.294Z,1598382244.294 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T19:04:04.294Z,1598382244.294 [DAT](INFO): commRate: 800
2020-08-25T19:04:04.294Z,1598382244.294 [DAT](INFO): commRate: 800
2020-08-25T19:04:04.696Z,1598382244.696 [DAT](INFO): entering command mode
2020-08-25T19:04:05.100Z,1598382245.100 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:05.504Z,1598382245.504 [DAT](INFO): DAT read: 

2020-08-25T19:04:05.504Z,1598382245.504 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:05.913Z,1598382245.913 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:06.316Z,1598382246.316 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:06.724Z,1598382246.724 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:07.118Z,1598382247.118 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:07.529Z,1598382247.529 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:07.932Z,1598382247.932 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:08.330Z,1598382248.330 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:08.740Z,1598382248.740 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:09.149Z,1598382249.149 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:09.543Z,1598382249.543 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:09.952Z,1598382249.952 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:10.352Z,1598382250.352 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:10.754Z,1598382250.754 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:11.164Z,1598382251.164 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:11.568Z,1598382251.568 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:11.972Z,1598382251.972 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:12.372Z,1598382252.372 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:12.776Z,1598382252.776 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:13.178Z,1598382253.178 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:13.589Z,1598382253.589 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:13.988Z,1598382253.988 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:14.400Z,1598382254.400 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:14.808Z,1598382254.808 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:15.208Z,1598382255.208 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:15.603Z,1598382255.603 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:16.008Z,1598382256.008 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:16.412Z,1598382256.412 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:16.820Z,1598382256.820 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:17.220Z,1598382257.220 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:17.628Z,1598382257.628 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:18.026Z,1598382258.026 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:18.436Z,1598382258.436 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:18.838Z,1598382258.838 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:19.238Z,1598382259.238 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:19.644Z,1598382259.644 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:20.057Z,1598382260.057 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:04:20.057Z,1598382260.057 [DAT](FAULT): failed to enter command mode
2020-08-25T19:04:20.456Z,1598382260.456 [DAT](INFO): entering command mode
2020-08-25T19:04:20.856Z,1598382260.856 [DAT](INFO): DAT read: user:1>

2020-08-25T19:04:20.857Z,1598382260.857 [DAT](INFO): DAT read: Command '+++' not found

2020-08-25T19:04:20.857Z,1598382260.857 [DAT](INFO): DAT read: Error

2020-08-25T19:04:20.857Z,1598382260.857 [DAT](INFO): setting verbose to 3
2020-08-25T19:04:21.266Z,1598382261.266 [DAT](INFO): DAT read: user:2>

2020-08-25T19:04:21.267Z,1598382261.267 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T19:04:21.268Z,1598382261.268 [DAT](INFO): set verbose to 3
2020-08-25T19:04:21.268Z,1598382261.268 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T19:04:21.662Z,1598382261.662 [DAT](INFO): DAT read: user:3>

2020-08-25T19:04:21.663Z,1598382261.663 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T19:04:21.663Z,1598382261.663 [DAT](INFO): set DatVerbose to 27440
2020-08-25T19:04:21.664Z,1598382261.664 [DAT](INFO): setting transmit power to 8
2020-08-25T19:04:22.074Z,1598382262.074 [DAT](INFO): DAT read: user:4>

2020-08-25T19:04:22.075Z,1598382262.075 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T19:04:22.075Z,1598382262.075 [DAT](INFO): set transmit power to 8
2020-08-25T19:04:22.075Z,1598382262.075 [DAT](INFO): setting local address to 9
2020-08-25T19:04:22.480Z,1598382262.480 [DAT](INFO): DAT read: user:5>

2020-08-25T19:04:22.481Z,1598382262.481 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T19:04:22.481Z,1598382262.481 [DAT](INFO): set local address to 9
2020-08-25T19:07:40.463Z,1598382460.463 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:07:40.464Z,1598382460.464 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:07:40.464Z,1598382460.464 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:07:40.464Z,1598382460.464 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:07:40.882Z,1598382460.882 [Default:CheckIn:D] Stopped
2020-08-25T19:07:40.882Z,1598382460.882 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.596908 min 
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn:E] Stopped
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn] Stopped
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:07:41.302Z,1598382461.302 [Default:CheckIn](INFO): Running loop #10
2020-08-25T19:07:41.303Z,1598382461.303 [Default:CheckIn] Running Loop=10
2020-08-25T19:07:41.303Z,1598382461.303 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:07:41.303Z,1598382461.303 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:07:43.293Z,1598382463.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190742.00,A,3648.16267,N,12147.28511,W,0.058,78.82,250820,,,D*46
2020-08-25T19:07:43.295Z,1598382463.295 [NAL9602](INFO): GPS fix at 20200825T190742: (36.802711, -121.788085)
2020-08-25T19:07:43.304Z,1598382463.304 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:07:43.304Z,1598382463.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:07:45.308Z,1598382465.308 [DAT](INFO): setting remote address to 6
2020-08-25T19:07:45.715Z,1598382465.715 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:46.123Z,1598382466.123 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:46.521Z,1598382466.521 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:46.924Z,1598382466.924 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:47.332Z,1598382467.332 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:47.732Z,1598382467.732 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:48.136Z,1598382468.136 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:48.540Z,1598382468.540 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:48.948Z,1598382468.948 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:49.348Z,1598382469.348 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:49.767Z,1598382469.767 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:50.171Z,1598382470.171 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:50.560Z,1598382470.560 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:50.970Z,1598382470.970 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0027.lzma
2020-08-25T19:07:50.980Z,1598382470.980 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:51.367Z,1598382471.367 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:51.772Z,1598382471.772 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:51.972Z,1598382471.972 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0027.lzma.bak
2020-08-25T19:07:51.972Z,1598382471.972 [DataOverHttps](INFO): SBD MOMSN=12615826
2020-08-25T19:07:52.182Z,1598382472.182 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:52.580Z,1598382472.580 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:53.032Z,1598382473.032 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:53.388Z,1598382473.388 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:53.804Z,1598382473.804 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:54.207Z,1598382474.207 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:54.612Z,1598382474.612 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:55.004Z,1598382475.004 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:55.413Z,1598382475.413 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:55.847Z,1598382475.847 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:56.215Z,1598382476.215 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:56.620Z,1598382476.620 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:57.028Z,1598382477.028 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:57.428Z,1598382477.428 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:57.832Z,1598382477.832 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:58.244Z,1598382478.244 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:58.648Z,1598382478.648 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:59.044Z,1598382479.044 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:59.448Z,1598382479.448 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:07:59.852Z,1598382479.852 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:00.256Z,1598382480.256 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:00.660Z,1598382480.660 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:00.660Z,1598382480.660 [DAT](FAULT): failed to set remote address
2020-08-25T19:08:00.660Z,1598382480.660 [DAT](ERROR): Failure setting remote address to 6
2020-08-25T19:08:01.064Z,1598382481.064 [DAT](INFO): setting remote address to 6
2020-08-25T19:08:01.472Z,1598382481.472 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:01.873Z,1598382481.873 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:02.276Z,1598382482.276 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:02.691Z,1598382482.691 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:03.099Z,1598382483.099 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:03.488Z,1598382483.488 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:03.892Z,1598382483.892 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:04.300Z,1598382484.300 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:04.706Z,1598382484.706 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:05.109Z,1598382485.109 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:05.512Z,1598382485.512 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:05.916Z,1598382485.916 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:06.316Z,1598382486.316 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:06.724Z,1598382486.724 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:07.128Z,1598382487.128 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:07.528Z,1598382487.528 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:07.932Z,1598382487.932 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:08.343Z,1598382488.343 [DAT](INFO): DAT read: user:6>

2020-08-25T19:08:08.343Z,1598382488.343 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:08.740Z,1598382488.740 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:09.144Z,1598382489.144 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:09.548Z,1598382489.548 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:09.952Z,1598382489.952 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:10.362Z,1598382490.362 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:10.760Z,1598382490.760 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:10.799Z,1598382490.799 [DataOverHttps](INFO): Sending 530 bytes from file Logs/20200825T181443/Express0028.lzma
2020-08-25T19:08:11.164Z,1598382491.164 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:11.587Z,1598382491.587 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:11.800Z,1598382491.800 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0028.lzma.bak
2020-08-25T19:08:11.800Z,1598382491.800 [DataOverHttps](INFO): SBD MOMSN=12615829
2020-08-25T19:08:11.994Z,1598382491.994 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:12.376Z,1598382492.376 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:12.786Z,1598382492.786 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:13.184Z,1598382493.184 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:13.588Z,1598382493.588 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:13.992Z,1598382493.992 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:14.396Z,1598382494.396 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:14.810Z,1598382494.810 [DAT](DEBUG): checking for remote address setting acknowledgment
2020-08-25T19:08:14.829Z,1598382494.829 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:08:14.829Z,1598382494.829 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:08:14.829Z,1598382494.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:08:24.968Z,1598382504.968 [CommandLine](IMPORTANT): got command failComponent
2020-08-25T19:08:24.968Z,1598382504.968 [CommandLine](IMPORTANT): Failed components:
2020-08-25T19:08:24.969Z,1598382504.969 [CommandLine](IMPORTANT): No failed Components.
2020-08-25T19:08:32.032Z,1598382512.032 [CommandLine](IMPORTANT): got command get DAT.sbdAddress
2020-08-25T19:08:32.032Z,1598382512.032 [CommandLine](IMPORTANT): DAT.sbdAddress 6 enum
2020-08-25T19:09:19.869Z,1598382559.869 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T19:09:19.869Z,1598382559.869 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T19:09:31.131Z,1598382571.131 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.000000 centimeter
2020-08-25T19:09:31.132Z,1598382571.132 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2020-08-25T19:09:31.209Z,1598382571.209 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-08-25T19:10:59.293Z,1598382659.293 [CommandLine](IMPORTANT): got command failComponent hardware DAT
2020-08-25T19:10:59.293Z,1598382659.293 [DAT] Hardware Fault, FailCount= 2
2020-08-25T19:10:59.293Z,1598382659.293 [DAT](ERROR): Hardware Fault
2020-08-25T19:10:59.293Z,1598382659.293 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault
2020-08-25T19:10:59.664Z,1598382659.664 [DAT](INFO): Powering down
2020-08-25T19:10:59.799Z,1598382659.799 [CBIT](ERROR): Hardware Fault in component: DAT
2020-08-25T19:11:00.489Z,1598382660.489 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T19:11:00.489Z,1598382660.489 [DAT] No Fault, FailCount= 2
2020-08-25T19:11:02.908Z,1598382662.908 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T19:11:02.909Z,1598382662.909 [DAT](INFO): Powering up
2020-08-25T19:11:02.909Z,1598382662.909 [DAT](DEBUG): Initializing DAT.
2020-08-25T19:11:03.003Z,1598382663.003 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T19:11:13.408Z,1598382673.408 [DAT](INFO): DAT read: 

2020-08-25T19:11:13.409Z,1598382673.409 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T19:11:14.616Z,1598382674.616 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T19:11:14.617Z,1598382674.617 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T19:11:14.618Z,1598382674.618 [DAT](INFO): DAT read: Aug 25 2020 19:10:51 

2020-08-25T19:11:15.421Z,1598382675.421 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T19:11:15.422Z,1598382675.422 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T19:11:15.422Z,1598382675.422 [DAT](INFO): commRate: 800
2020-08-25T19:11:15.423Z,1598382675.423 [DAT](INFO): commRate: 800
2020-08-25T19:11:15.825Z,1598382675.825 [DAT](INFO): entering command mode
2020-08-25T19:11:16.239Z,1598382676.239 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:16.646Z,1598382676.646 [DAT](INFO): DAT read: 

2020-08-25T19:11:16.646Z,1598382676.646 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:17.047Z,1598382677.047 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:17.451Z,1598382677.451 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:17.844Z,1598382677.844 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:18.252Z,1598382678.252 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:18.651Z,1598382678.651 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:19.061Z,1598382679.061 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:19.464Z,1598382679.464 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:19.863Z,1598382679.863 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:20.268Z,1598382680.268 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:20.678Z,1598382680.678 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:21.087Z,1598382681.087 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:21.496Z,1598382681.496 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:21.884Z,1598382681.884 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:22.287Z,1598382682.287 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:22.692Z,1598382682.692 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:23.096Z,1598382683.096 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:23.499Z,1598382683.499 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:23.904Z,1598382683.904 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:24.327Z,1598382684.327 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:24.739Z,1598382684.739 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:25.120Z,1598382685.120 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:25.520Z,1598382685.520 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:25.924Z,1598382685.924 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:26.333Z,1598382686.333 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:26.732Z,1598382686.732 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:27.136Z,1598382687.136 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:27.545Z,1598382687.545 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T19:11:27.950Z,1598382687.950 [DAT](INFO): DAT read: user:1>Rx Time:19:11:08.2904

2020-08-25T19:11:27.951Z,1598382687.951 [DAT](INFO): setting verbose to 3
2020-08-25T19:11:28.347Z,1598382688.347 [DAT](INFO): DAT read: 

2020-08-25T19:11:28.348Z,1598382688.348 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T19:11:28.348Z,1598382688.348 [DAT](INFO): set verbose to 3
2020-08-25T19:11:28.348Z,1598382688.348 [DAT](INFO): DAT read: user:2>

2020-08-25T19:11:28.349Z,1598382688.349 [DAT](INFO): DAT read: $Packet for address 9

2020-08-25T19:11:28.349Z,1598382688.349 [DAT](INFO): received a packet notification
2020-08-25T19:11:28.367Z,1598382688.367 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T19:11:28.752Z,1598382688.752 [DAT](INFO): DAT read: 

2020-08-25T19:11:28.753Z,1598382688.753 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T19:11:28.753Z,1598382688.753 [DAT](INFO): set DatVerbose to 27440
2020-08-25T19:11:28.754Z,1598382688.754 [DAT](INFO): setting transmit power to 8
2020-08-25T19:11:29.160Z,1598382689.160 [DAT](INFO): DAT read: user:3>

2020-08-25T19:11:29.161Z,1598382689.161 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T19:11:29.161Z,1598382689.161 [DAT](INFO): set transmit power to 8
2020-08-25T19:11:29.162Z,1598382689.162 [DAT](INFO): setting local address to 9
2020-08-25T19:11:29.561Z,1598382689.561 [DAT](INFO): DAT read: user:4>

2020-08-25T19:11:29.570Z,1598382689.570 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T19:11:29.571Z,1598382689.571 [DAT](INFO): set local address to 9
2020-08-25T19:12:40.513Z,1598382760.513 [CommandLine](IMPORTANT): got command get DAT.sbdAddress
2020-08-25T19:12:40.514Z,1598382760.514 [CommandLine](IMPORTANT): DAT.sbdAddress 6 enum
2020-08-25T19:12:45.115Z,1598382765.115 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:13:15.428Z,1598382795.428 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:13:15.429Z,1598382795.429 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:13:15.429Z,1598382795.429 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:13:15.429Z,1598382795.429 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:13:15.827Z,1598382795.827 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:13:15.837Z,1598382795.837 [Default:CheckIn:D] Stopped
2020-08-25T19:13:15.837Z,1598382795.837 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.179492 min 
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn:E] Stopped
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn] Stopped
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn](INFO): Running loop #11
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn] Running Loop=11
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:13:16.231Z,1598382796.231 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:13:18.249Z,1598382798.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191317.00,A,3648.16388,N,12147.28672,W,0.175,122.50,250820,,,D*7A
2020-08-25T19:13:18.252Z,1598382798.252 [NAL9602](INFO): GPS fix at 20200825T191317: (36.802731, -121.788112)
2020-08-25T19:13:18.260Z,1598382798.260 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:13:18.260Z,1598382798.260 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:13:20.265Z,1598382800.265 [DAT](INFO): DAT read: user:5>Rx Time:19:12:50.5562

2020-08-25T19:13:20.265Z,1598382800.265 [DAT](INFO): DAT read: 

2020-08-25T19:13:20.267Z,1598382800.267 [DAT](INFO): DAT read: DATA(0020):���$�O�7y�;�&���R

2020-08-25T19:13:20.267Z,1598382800.267 [DAT](INFO): Got DATA 20
2020-08-25T19:13:20.268Z,1598382800.268 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-25T19:13:20.268Z,1598382800.268 [DAT](INFO): Got Src/Dest after DATA 
2020-08-25T19:13:20.268Z,1598382800.268 [DAT](INFO): DATA Src=6, Dst=9
2020-08-25T19:13:20.270Z,1598382800.270 [DAT](INFO): DAT read: CRC:Fail {0001} MPD:02.2 PSNR:06.9 AGC:88 SPD:+00.0 CCERR:005

2020-08-25T19:13:20.274Z,1598382800.274 [DAT](INFO): unknown deviceResponse_: CRC:Fail {0001} MPD:02.2 PSNR:06.9 AGC:88 SPD:+00.0 CCERR:005

2020-08-25T19:13:20.275Z,1598382800.275 [DAT](INFO): DAT read: 

2020-08-25T19:13:20.275Z,1598382800.275 [DAT](INFO): DAT read: <EOP>

2020-08-25T19:13:20.276Z,1598382800.276 [DAT](INFO): setting remote address to 6
2020-08-25T19:13:20.668Z,1598382800.668 [DAT](INFO): DAT read: 

2020-08-25T19:13:20.669Z,1598382800.669 [DAT](INFO): DAT read: RemoteAddr      | 6           

2020-08-25T19:13:20.669Z,1598382800.669 [DAT](INFO): set remote address to 6
2020-08-25T19:13:20.669Z,1598382800.669 [DAT](INFO): entering online mode
2020-08-25T19:13:21.096Z,1598382801.096 [DAT](INFO): DAT read: user:8>

2020-08-25T19:13:21.097Z,1598382801.097 [DAT](INFO): DAT read: 

2020-08-25T19:13:21.102Z,1598382801.102 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T19:13:21.103Z,1598382801.103 [DAT](INFO): commRate: 800
2020-08-25T19:13:21.103Z,1598382801.103 [DAT](INFO): online mode acknowledged
2020-08-25T19:13:21.104Z,1598382801.104 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:13:23.901Z,1598382803.901 [DAT](INFO): DAT read: Rx Time:19:13:03.4071

2020-08-25T19:13:23.901Z,1598382803.901 [DAT](INFO): received an acoustic signal
2020-08-25T19:13:24.709Z,1598382804.709 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:13:04.8207

2020-08-25T19:13:24.710Z,1598382804.710 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:13:24.710Z,1598382804.710 [DAT](INFO): DAT read: 

2020-08-25T19:13:24.711Z,1598382804.711 [DAT](INFO): DAT read: DATA(0020):�I�hY���׆k�=��	���

2020-08-25T19:13:24.712Z,1598382804.712 [DAT](INFO): Got DATA 20
2020-08-25T19:13:24.712Z,1598382804.712 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-25T19:13:24.712Z,1598382804.712 [DAT](INFO): Got Src/Dest after DATA 
2020-08-25T19:13:24.713Z,1598382804.713 [DAT](INFO): DATA Src=6, Dst=9
2020-08-25T19:13:24.714Z,1598382804.714 [DAT](INFO): DAT read: CRC:Pass MPD:13.3 PSNR:08.7 AGC:86 SPD:-00.1 CCERR:007

2020-08-25T19:13:24.714Z,1598382804.714 [DAT](INFO): Got CRC:Pass
2020-08-25T19:13:24.714Z,1598382804.714 [DAT](INFO): Got CRC:Pass
2020-08-25T19:13:24.714Z,1598382804.714 [DAT](INFO): Incoming data is intended for us
2020-08-25T19:13:24.720Z,1598382804.720 [DAT](INFO): Received command:failc
2020-08-25T19:13:24.723Z,1598382804.723 [DAT](INFO): Sending ack
2020-08-25T19:13:24.724Z,1598382804.724 [DAT](INFO): DAT read: 

2020-08-25T19:13:24.725Z,1598382804.725 [DAT](INFO): DAT read: <EOP>

2020-08-25T19:13:24.756Z,1598382804.756 [CommandLine](IMPORTANT): got command failComponent
2020-08-25T19:13:24.756Z,1598382804.756 [CommandLine](IMPORTANT): Failed components:
2020-08-25T19:13:24.756Z,1598382804.756 [CommandLine](IMPORTANT): No failed Components.
2020-08-25T19:13:27.595Z,1598382807.595 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0030.lzma
2020-08-25T19:13:27.947Z,1598382807.947 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:13:08.1707

2020-08-25T19:13:28.592Z,1598382808.592 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0030.lzma.bak
2020-08-25T19:13:28.592Z,1598382808.592 [DataOverHttps](INFO): SBD MOMSN=12615874
2020-08-25T19:13:41.278Z,1598382821.278 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:13:41.278Z,1598382821.278 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:13:42.901Z,1598382822.901 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:13:43.032Z,1598382823.032 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:13:46.229Z,1598382826.229 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:13:26.5208

2020-08-25T19:13:46.230Z,1598382826.230 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:13:46.712Z,1598382826.712 [DataOverHttps](INFO): Sending 451 bytes from file Logs/20200825T181443/Express0031.lzma
2020-08-25T19:13:47.712Z,1598382827.712 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0031.lzma.bak
2020-08-25T19:13:47.712Z,1598382827.712 [DataOverHttps](INFO): SBD MOMSN=12615877
2020-08-25T19:13:48.653Z,1598382828.653 [DAT](INFO): DAT read: Rx Time:19:13:28.2075

2020-08-25T19:13:48.653Z,1598382828.653 [DAT](INFO): received an acoustic signal
2020-08-25T19:13:49.056Z,1598382829.056 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T19:13:49.138Z,1598382829.138 [NAL9602](FAULT): received: 
+CSQ:0

OK14, 2, 0, 0, 0

OK
2020-08-25T19:13:49.139Z,1598382829.139 [NAL9602] Data Fault, FailCount= 1
2020-08-25T19:13:49.139Z,1598382829.139 [NAL9602](ERROR): Data Fault
2020-08-25T19:13:49.159Z,1598382829.159 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T19:13:49.462Z,1598382829.462 [NAL9602](INFO): Powering down
2020-08-25T19:13:49.468Z,1598382829.468 [DAT](INFO): DAT read: 

2020-08-25T19:13:49.469Z,1598382829.469 [DAT](INFO): DAT read: DATA(0020):�I�hY���׆kz��0�̍

2020-08-25T19:13:49.469Z,1598382829.469 [DAT](INFO): Got DATA 20
2020-08-25T19:13:49.474Z,1598382829.474 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-25T19:13:49.475Z,1598382829.475 [DAT](INFO): Got Src/Dest after DATA 
2020-08-25T19:13:49.475Z,1598382829.475 [DAT](INFO): DATA Src=6, Dst=9
2020-08-25T19:13:49.865Z,1598382829.865 [DAT](INFO): DAT read: CRC:Fail {0001} MPD:03.9 PSNR:08.6 AGC:89 SPD:-00.3 CCERR:006

2020-08-25T19:13:49.866Z,1598382829.866 [DAT](INFO): unknown deviceResponse_: CRC:Fail {0001} MPD:03.9 PSNR:08.6 AGC:89 SPD:-00.3 CCERR:006

2020-08-25T19:13:49.866Z,1598382829.866 [DAT](INFO): DAT read: 

2020-08-25T19:13:49.867Z,1598382829.867 [DAT](INFO): DAT read: <EOP>

2020-08-25T19:13:50.302Z,1598382830.302 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T19:13:50.302Z,1598382830.302 [NAL9602] No Fault, FailCount= 1
2020-08-25T19:13:50.697Z,1598382830.697 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:13:50.697Z,1598382830.697 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:13:50.697Z,1598382830.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:14:19.758Z,1598382859.758 [NAL9602](INFO): Powering up NAL9602
2020-08-25T19:14:30.672Z,1598382870.672 [NAL9602](INFO): NAL9602 initialized
2020-08-25T19:15:01.776Z,1598382901.776 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:16:28.086Z,1598382988.086 [CommandLine](IMPORTANT): got command maintain clear
2020-08-25T19:16:28.376Z,1598382988.376 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-08-25T19:18:51.415Z,1598383131.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:18:51.415Z,1598383131.415 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:18:51.416Z,1598383131.416 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:18:51.416Z,1598383131.416 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:18:51.732Z,1598383131.732 [Default:CheckIn:D] Stopped
2020-08-25T19:18:51.732Z,1598383131.732 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.777751 min 
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn:E] Stopped
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn] Stopped
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn](INFO): Running loop #12
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn] Running Loop=12
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:18:52.133Z,1598383132.133 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:18:54.145Z,1598383134.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191852.00,A,3648.16004,N,12147.28767,W,1.166,290.41,250820,,,D*7B
2020-08-25T19:18:54.157Z,1598383134.157 [NAL9602](INFO): GPS fix at 20200825T191852: (36.802667, -121.788128)
2020-08-25T19:18:54.167Z,1598383134.167 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:18:54.167Z,1598383134.167 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:18:55.756Z,1598383135.756 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:19:02.570Z,1598383142.570 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0033.lzma
2020-08-25T19:19:03.572Z,1598383143.572 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0033.lzma.bak
2020-08-25T19:19:03.572Z,1598383143.572 [DataOverHttps](INFO): SBD MOMSN=12615907
2020-08-25T19:19:15.601Z,1598383155.601 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:19:15.601Z,1598383155.601 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:19:19.393Z,1598383159.393 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:19:19.620Z,1598383159.620 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:19:23.197Z,1598383163.197 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:19:03.1211

2020-08-25T19:19:23.197Z,1598383163.197 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:19:26.264Z,1598383166.264 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20200825T181443/Express0034.lzma
2020-08-25T19:19:26.419Z,1598383166.419 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:19:27.276Z,1598383167.276 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0034.lzma.bak
2020-08-25T19:19:27.276Z,1598383167.276 [DataOverHttps](INFO): SBD MOMSN=12615910
2020-08-25T19:19:30.516Z,1598383170.516 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:19:30.516Z,1598383170.516 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:19:30.517Z,1598383170.517 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:24:31.388Z,1598383471.388 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:24:31.388Z,1598383471.388 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:24:31.389Z,1598383471.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:24:31.389Z,1598383471.389 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:24:31.605Z,1598383471.605 [Default:CheckIn:D] Stopped
2020-08-25T19:24:31.605Z,1598383471.605 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:24:31.998Z,1598383471.998 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.442293 min 
2020-08-25T19:24:31.998Z,1598383471.998 [Default:CheckIn:E] Stopped
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn] Stopped
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn](INFO): Running loop #13
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn] Running Loop=13
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:24:31.999Z,1598383471.999 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:24:33.947Z,1598383473.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192432.00,A,3648.15833,N,12147.28770,W,0.058,231.49,250820,,,D*75
2020-08-25T19:24:33.949Z,1598383473.949 [NAL9602](INFO): GPS fix at 20200825T192432: (36.802639, -121.788128)
2020-08-25T19:24:34.041Z,1598383474.041 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:24:34.041Z,1598383474.041 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:24:41.967Z,1598383481.967 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200825T181443/Courier0036.lzma
2020-08-25T19:24:42.976Z,1598383482.976 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0036.lzma.bak
2020-08-25T19:24:42.976Z,1598383482.976 [DataOverHttps](INFO): SBD MOMSN=12615955
2020-08-25T19:24:56.272Z,1598383496.272 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:24:56.272Z,1598383496.272 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:24:57.609Z,1598383497.609 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:24:57.732Z,1598383497.732 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:25:01.285Z,1598383501.285 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:24:41.2194

2020-08-25T19:25:01.285Z,1598383501.285 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:25:02.514Z,1598383502.514 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20200825T181443/Express0037.lzma
2020-08-25T19:25:03.516Z,1598383503.516 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0037.lzma.bak
2020-08-25T19:25:03.516Z,1598383503.516 [DataOverHttps](INFO): SBD MOMSN=12615958
2020-08-25T19:25:06.138Z,1598383506.138 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:25:06.138Z,1598383506.138 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:25:06.138Z,1598383506.138 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:26:39.456Z,1598383599.456 [NAL9602](INFO): SBD MO Status=2, MOMSN=8114, MT Status=2, MTMSN=0
2020-08-25T19:26:39.456Z,1598383599.456 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T19:29:36.418Z,1598383776.418 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:30:06.732Z,1598383806.732 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:30:06.732Z,1598383806.732 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:30:06.732Z,1598383806.732 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:30:06.732Z,1598383806.732 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:30:07.123Z,1598383807.123 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:30:07.142Z,1598383807.142 [Default:CheckIn:D] Stopped
2020-08-25T19:30:07.142Z,1598383807.142 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:30:07.542Z,1598383807.542 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.034570 min 
2020-08-25T19:30:07.542Z,1598383807.542 [Default:CheckIn:E] Stopped
2020-08-25T19:30:07.542Z,1598383807.542 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:30:07.542Z,1598383807.542 [Default:CheckIn] Stopped
2020-08-25T19:30:07.543Z,1598383807.543 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:30:07.543Z,1598383807.543 [Default:CheckIn](INFO): Running loop #14
2020-08-25T19:30:07.543Z,1598383807.543 [Default:CheckIn] Running Loop=14
2020-08-25T19:30:07.543Z,1598383807.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:30:07.543Z,1598383807.543 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:30:09.548Z,1598383809.548 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193009.00,A,3648.16058,N,12147.28682,W,0.233,231.49,250820,,,D*7D
2020-08-25T19:30:09.550Z,1598383809.550 [NAL9602](INFO): GPS fix at 20200825T193009: (36.802676, -121.788114)
2020-08-25T19:30:09.559Z,1598383809.559 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:30:09.560Z,1598383809.560 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:30:18.366Z,1598383818.366 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0039.lzma
2020-08-25T19:30:19.368Z,1598383819.368 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0039.lzma.bak
2020-08-25T19:30:19.368Z,1598383819.368 [DataOverHttps](INFO): SBD MOMSN=12615970
2020-08-25T19:30:30.984Z,1598383830.984 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:30:30.984Z,1598383830.984 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T19:30:31.372Z,1598383831.372 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:30:34.013Z,1598383834.013 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:30:34.244Z,1598383834.244 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:30:37.761Z,1598383837.761 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:30:17.7188

2020-08-25T19:30:37.761Z,1598383837.761 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:30:40.188Z,1598383840.188 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T19:30:40.262Z,1598383840.262 [NAL9602](FAULT): received: 
+CSQ:0

OK14, 2, 0, 0, 0

OK
2020-08-25T19:30:40.262Z,1598383840.262 [NAL9602] Data Fault, FailCount= 1
2020-08-25T19:30:40.263Z,1598383840.263 [NAL9602](ERROR): Data Fault
2020-08-25T19:30:40.319Z,1598383840.319 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T19:30:40.591Z,1598383840.591 [NAL9602](INFO): Powering down
2020-08-25T19:30:41.419Z,1598383841.419 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T19:30:41.419Z,1598383841.419 [NAL9602] No Fault, FailCount= 1
2020-08-25T19:30:43.239Z,1598383843.239 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20200825T181443/Express0040.lzma
2020-08-25T19:30:44.240Z,1598383844.240 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0040.lzma.bak
2020-08-25T19:30:44.240Z,1598383844.240 [DataOverHttps](INFO): SBD MOMSN=12615973
2020-08-25T19:30:47.081Z,1598383847.081 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:30:47.081Z,1598383847.081 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:30:47.081Z,1598383847.081 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:31:10.889Z,1598383870.889 [NAL9602](INFO): Powering up NAL9602
2020-08-25T19:31:21.815Z,1598383881.815 [NAL9602](INFO): NAL9602 initialized
2020-08-25T19:31:52.915Z,1598383912.915 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:35:47.661Z,1598384147.661 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:35:47.661Z,1598384147.661 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:35:47.661Z,1598384147.661 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:35:47.683Z,1598384147.683 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:35:48.062Z,1598384148.062 [Default:CheckIn:D] Stopped
2020-08-25T19:35:48.062Z,1598384148.062 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:35:48.472Z,1598384148.472 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.716577 min 
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn:E] Stopped
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn] Stopped
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn](INFO): Running loop #15
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn] Running Loop=15
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:35:48.473Z,1598384148.473 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:35:50.489Z,1598384150.489 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193549.00,A,3648.16626,N,12147.28363,W,0.544,73.22,250820,,,A*42
2020-08-25T19:35:50.499Z,1598384150.499 [NAL9602](INFO): GPS fix at 20200825T193549: (36.802771, -121.788061)
2020-08-25T19:35:50.518Z,1598384150.518 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:35:50.518Z,1598384150.518 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:35:52.931Z,1598384152.931 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:35:57.386Z,1598384157.386 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0042.lzma
2020-08-25T19:35:58.388Z,1598384158.388 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0042.lzma.bak
2020-08-25T19:35:58.388Z,1598384158.388 [DataOverHttps](INFO): SBD MOMSN=12616012
2020-08-25T19:36:11.912Z,1598384171.912 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:36:11.912Z,1598384171.912 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T19:36:12.320Z,1598384172.320 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:36:14.247Z,1598384174.247 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:36:14.372Z,1598384174.372 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:36:16.490Z,1598384176.490 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20200825T181443/Express0043.lzma
2020-08-25T19:36:17.492Z,1598384177.492 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0043.lzma.bak
2020-08-25T19:36:17.492Z,1598384177.492 [DataOverHttps](INFO): SBD MOMSN=12616015
2020-08-25T19:36:17.944Z,1598384177.944 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:35:57.8683

2020-08-25T19:36:17.945Z,1598384177.945 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:36:20.373Z,1598384180.373 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:36:20.374Z,1598384180.374 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:36:20.374Z,1598384180.374 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:36:23.595Z,1598384183.595 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:41:20.995Z,1598384480.995 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:41:20.996Z,1598384480.996 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:41:20.996Z,1598384480.996 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:41:20.996Z,1598384480.996 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:41:21.370Z,1598384481.370 [Default:CheckIn:D] Stopped
2020-08-25T19:41:21.370Z,1598384481.370 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:41:21.792Z,1598384481.792 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.271704 min 
2020-08-25T19:41:21.792Z,1598384481.792 [Default:CheckIn:E] Stopped
2020-08-25T19:41:21.792Z,1598384481.792 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn] Stopped
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn](INFO): Running loop #16
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn] Running Loop=16
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:41:21.793Z,1598384481.793 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:41:23.790Z,1598384483.790 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194123.00,A,3648.16696,N,12147.28180,W,0.058,73.22,250820,,,A*41
2020-08-25T19:41:23.792Z,1598384483.792 [NAL9602](INFO): GPS fix at 20200825T194123: (36.802783, -121.788030)
2020-08-25T19:41:23.801Z,1598384483.801 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:41:23.801Z,1598384483.801 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:41:32.370Z,1598384492.370 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0045.lzma
2020-08-25T19:41:33.372Z,1598384493.372 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0045.lzma.bak
2020-08-25T19:41:33.372Z,1598384493.372 [DataOverHttps](INFO): SBD MOMSN=12616028
2020-08-25T19:41:45.200Z,1598384505.200 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:41:45.200Z,1598384505.200 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T19:41:45.608Z,1598384505.608 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:41:47.113Z,1598384507.113 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:41:47.219Z,1598384507.219 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:41:50.425Z,1598384510.425 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:41:30.7187

2020-08-25T19:41:50.426Z,1598384510.426 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T19:41:51.163Z,1598384511.163 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20200825T181443/Express0046.lzma
2020-08-25T19:41:52.164Z,1598384512.164 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0046.lzma.bak
2020-08-25T19:41:52.164Z,1598384512.164 [DataOverHttps](INFO): SBD MOMSN=12616031
2020-08-25T19:41:54.886Z,1598384514.886 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:41:54.886Z,1598384514.886 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:41:54.886Z,1598384514.886 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:46:25.978Z,1598384785.978 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:46:55.487Z,1598384815.487 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:46:55.488Z,1598384815.488 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:46:55.488Z,1598384815.488 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:46:55.488Z,1598384815.488 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:46:55.892Z,1598384815.892 [Default:CheckIn:D] Stopped
2020-08-25T19:46:55.892Z,1598384815.892 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.847087 min 
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn:E] Stopped
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn] Stopped
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn](INFO): Running loop #17
2020-08-25T19:46:56.297Z,1598384816.297 [Default:CheckIn] Running Loop=17
2020-08-25T19:46:56.298Z,1598384816.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:46:56.298Z,1598384816.298 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:46:56.687Z,1598384816.687 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:46:58.309Z,1598384818.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194657.00,A,3648.15862,N,12147.29883,W,0.933,158.43,250820,,,A*73
2020-08-25T19:46:58.323Z,1598384818.323 [NAL9602](INFO): GPS fix at 20200825T194657: (36.802644, -121.788314)
2020-08-25T19:46:58.331Z,1598384818.331 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:46:58.332Z,1598384818.332 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:47:06.742Z,1598384826.742 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T181443/Courier0048.lzma
2020-08-25T19:47:07.744Z,1598384827.744 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0048.lzma.bak
2020-08-25T19:47:07.744Z,1598384827.744 [DataOverHttps](INFO): SBD MOMSN=12616064
2020-08-25T19:47:19.721Z,1598384839.721 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T19:47:19.721Z,1598384839.721 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-25T19:47:20.120Z,1598384840.120 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:47:27.571Z,1598384847.571 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20200825T181443/Express0049.lzma
2020-08-25T19:47:28.572Z,1598384848.572 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0049.lzma.bak
2020-08-25T19:47:28.572Z,1598384848.572 [DataOverHttps](INFO): SBD MOMSN=12616067
2020-08-25T19:47:29.164Z,1598384849.164 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T19:47:29.238Z,1598384849.238 [NAL9602](FAULT): received: 
+CSQ:0

OK14, 2, 0, 0, 0

OK
2020-08-25T19:47:29.238Z,1598384849.238 [NAL9602] Data Fault, FailCount= 1
2020-08-25T19:47:29.238Z,1598384849.238 [NAL9602](ERROR): Data Fault
2020-08-25T19:47:30.443Z,1598384850.443 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T19:47:30.521Z,1598384850.521 [NAL9602](INFO): Powering down
2020-08-25T19:47:33.799Z,1598384853.799 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:47:33.799Z,1598384853.799 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:47:33.799Z,1598384853.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:47:33.925Z,1598384853.925 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T19:47:33.925Z,1598384853.925 [NAL9602] No Fault, FailCount= 1
2020-08-25T19:48:00.908Z,1598384880.908 [NAL9602](INFO): Powering up NAL9602
2020-08-25T19:48:11.815Z,1598384891.815 [NAL9602](INFO): NAL9602 initialized
2020-08-25T19:48:42.917Z,1598384922.917 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:48:50.139Z,1598384930.139 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.682011
2020-08-25T19:49:00.487Z,1598384940.487 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003552
2020-08-25T19:52:34.257Z,1598385154.257 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T19:52:34.258Z,1598385154.258 [Default:CheckIn:C.Wait] Stopped
2020-08-25T19:52:34.258Z,1598385154.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T19:52:34.258Z,1598385154.258 [Default:CheckIn:D] Running Loop=1
2020-08-25T19:52:34.669Z,1598385154.669 [Default:CheckIn:D] Stopped
2020-08-25T19:52:34.669Z,1598385154.669 [Default:CheckIn:E] Running Loop=1
2020-08-25T19:52:35.090Z,1598385155.090 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.493368 min 
2020-08-25T19:52:35.090Z,1598385155.090 [Default:CheckIn:E] Stopped
2020-08-25T19:52:35.090Z,1598385155.090 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T19:52:35.102Z,1598385155.102 [Default:CheckIn] Stopped
2020-08-25T19:52:35.102Z,1598385155.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T19:52:35.103Z,1598385155.103 [Default:CheckIn](INFO): Running loop #18
2020-08-25T19:52:35.103Z,1598385155.103 [Default:CheckIn] Running Loop=18
2020-08-25T19:52:35.103Z,1598385155.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T19:52:35.103Z,1598385155.103 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T19:52:38.287Z,1598385158.287 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T19:57:35.393Z,1598385455.393 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T19:52:35.1Z
2020-08-25T19:57:35.393Z,1598385455.393 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T19:57:35.394Z,1598385455.394 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T19:57:37.389Z,1598385457.389 [DAT](INFO): DAT read: Rx Time:19:56:32.7134

2020-08-25T19:57:37.389Z,1598385457.389 [DAT](INFO): received an acoustic signal
2020-08-25T19:57:37.389Z,1598385457.389 [DAT](INFO): DAT read: range request

2020-08-25T19:57:37.390Z,1598385457.390 [DAT](INFO): received a range request message
2020-08-25T19:57:37.390Z,1598385457.390 [DAT](INFO): DAT read: Tx time:19:56:34.3163

2020-08-25T19:57:37.391Z,1598385457.391 [DAT](INFO): Ping request sent.
2020-08-25T19:57:37.391Z,1598385457.391 [DAT](INFO): transmitted an acoustic signal
2020-08-25T19:57:38.348Z,1598385458.348 [DAT](INFO): #Outgoing data=1
2020-08-25T19:57:38.348Z,1598385458.348 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:57:38.349Z,1598385458.349 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone
2020-08-25T19:57:38.349Z,1598385458.349 [DAT](INFO): publishing transmit ping time
2020-08-25T19:57:38.350Z,1598385458.350 [DAT](INFO): publishing range request flag
2020-08-25T19:57:38.461Z,1598385458.461 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T19:57:38.801Z,1598385458.801 [DAT](INFO): DAT read: 
user:12>kbd break

2020-08-25T19:57:38.802Z,1598385458.802 [DAT](INFO): DAT read: user:12>
Command 'vi?rpv' not found

2020-08-25T19:57:38.839Z,1598385458.839 [DAT](INFO): DAT read: Error

2020-08-25T19:57:38.839Z,1598385458.839 [DAT](INFO): unknown deviceResponse_: Error

2020-08-25T19:57:43.626Z,1598385463.626 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T181443/Courier0051.lzma
2020-08-25T19:57:44.628Z,1598385464.628 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0051.lzma.bak
2020-08-25T19:57:44.628Z,1598385464.628 [DataOverHttps](INFO): SBD MOMSN=12616107
2020-08-25T19:57:58.592Z,1598385478.592 [DAT](FAULT): Buffer send receipt timeout failure.
2020-08-25T19:57:58.592Z,1598385478.592 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2020-08-25T19:58:01.393Z,1598385481.393 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T19:58:01.512Z,1598385481.512 [DAT](INFO): entering online mode
2020-08-25T19:58:01.852Z,1598385481.852 [DAT](INFO): DAT read: user:13>

2020-08-25T19:58:01.853Z,1598385481.853 [DAT](INFO): DAT read: Command 'ox$sfp}&`' not found

2020-08-25T19:58:01.853Z,1598385481.853 [DAT](INFO): unknown deviceResponse_: Command 'ox$sfp}&`' not found

2020-08-25T19:58:01.854Z,1598385481.854 [DAT](INFO): DAT read: Error

2020-08-25T19:58:01.854Z,1598385481.854 [DAT](INFO): unknown deviceResponse_: Error

2020-08-25T19:58:01.854Z,1598385481.854 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:02.256Z,1598385482.256 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:02.665Z,1598385482.665 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:03.073Z,1598385483.073 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:03.472Z,1598385483.472 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:03.495Z,1598385483.495 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20200825T181443/Express0052.lzma
2020-08-25T19:58:03.872Z,1598385483.872 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:04.281Z,1598385484.281 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:04.496Z,1598385484.496 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0052.lzma.bak
2020-08-25T19:58:04.496Z,1598385484.496 [DataOverHttps](INFO): SBD MOMSN=12616109
2020-08-25T19:58:04.680Z,1598385484.680 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:05.088Z,1598385485.088 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:05.486Z,1598385485.486 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:05.896Z,1598385485.896 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:06.296Z,1598385486.296 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:06.700Z,1598385486.700 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:07.104Z,1598385487.104 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:07.508Z,1598385487.508 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T19:58:07.546Z,1598385487.546 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T19:58:07.546Z,1598385487.546 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T19:58:07.546Z,1598385487.546 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T19:58:09.123Z,1598385489.123 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T19:58:26.504Z,1598385506.504 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-25T19:58:26.506Z,1598385506.506 [BPC1](INFO): Received data from all battery sticks.
2020-08-25T20:03:08.107Z,1598385788.107 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T20:03:08.108Z,1598385788.108 [Default:CheckIn:C.Wait] Stopped
2020-08-25T20:03:08.108Z,1598385788.108 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T20:03:08.108Z,1598385788.108 [Default:CheckIn:D] Running Loop=1
2020-08-25T20:03:08.503Z,1598385788.503 [Default:CheckIn:D] Stopped
2020-08-25T20:03:08.503Z,1598385788.503 [Default:CheckIn:E] Running Loop=1
2020-08-25T20:03:08.902Z,1598385788.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.057259 min 
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn:E] Stopped
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn] Stopped
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn](INFO): Running loop #19
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn] Running Loop=19
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T20:03:08.903Z,1598385788.903 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T20:03:10.516Z,1598385790.516 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-25T20:03:10.516Z,1598385790.516 [NAL9602] Data Fault, FailCount= 1
2020-08-25T20:03:10.516Z,1598385790.516 [NAL9602](ERROR): Data Fault
2020-08-25T20:03:10.534Z,1598385790.534 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T20:03:10.920Z,1598385790.920 [NAL9602](INFO): Powering down
2020-08-25T20:03:11.744Z,1598385791.744 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T20:03:11.744Z,1598385791.744 [NAL9602] No Fault, FailCount= 1
2020-08-25T20:03:41.255Z,1598385821.255 [NAL9602](INFO): Powering up NAL9602
2020-08-25T20:03:52.157Z,1598385832.157 [NAL9602](INFO): NAL9602 initialized
2020-08-25T20:08:09.137Z,1598386089.137 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T20:03:08.9Z
2020-08-25T20:08:09.137Z,1598386089.137 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T20:08:09.137Z,1598386089.137 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T20:08:11.148Z,1598386091.148 [DAT](DEBUG): checking for online mode acknowledgment
2020-08-25T20:08:11.148Z,1598386091.148 [DAT](FAULT): failed to enter online mode
2020-08-25T20:08:11.148Z,1598386091.148 [DAT](FAULT): Failure returning to online mode
2020-08-25T20:08:11.148Z,1598386091.148 [DAT] Communications Fault, FailCount= 1
2020-08-25T20:08:11.148Z,1598386091.148 [DAT](ERROR): Communications Fault
2020-08-25T20:08:11.166Z,1598386091.166 [CBIT](ERROR): Communications Fault in component: DAT
2020-08-25T20:08:11.552Z,1598386091.552 [DAT](INFO): Powering down
2020-08-25T20:08:12.421Z,1598386092.421 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T20:08:12.421Z,1598386092.421 [DAT] No Fault, FailCount= 1
2020-08-25T20:08:14.782Z,1598386094.782 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T20:08:14.782Z,1598386094.782 [DAT](INFO): Powering up
2020-08-25T20:08:14.782Z,1598386094.782 [DAT](DEBUG): Initializing DAT.
2020-08-25T20:08:14.859Z,1598386094.859 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T20:08:16.143Z,1598386096.143 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200825T181443/Courier0054.lzma
2020-08-25T20:08:17.144Z,1598386097.144 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0054.lzma.bak
2020-08-25T20:08:17.144Z,1598386097.144 [DataOverHttps](INFO): SBD MOMSN=12616173
2020-08-25T20:08:25.284Z,1598386105.284 [DAT](INFO): DAT read: 

2020-08-25T20:08:25.285Z,1598386105.285 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T20:08:26.497Z,1598386106.497 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T20:08:26.499Z,1598386106.499 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T20:08:26.499Z,1598386106.499 [DAT](INFO): DAT read: Aug 25 2020 20:08:03 

2020-08-25T20:08:27.303Z,1598386107.303 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T20:08:27.304Z,1598386107.304 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T20:08:27.304Z,1598386107.304 [DAT](INFO): commRate: 800
2020-08-25T20:08:27.304Z,1598386107.304 [DAT](INFO): commRate: 800
2020-08-25T20:08:27.723Z,1598386107.723 [DAT](INFO): entering command mode
2020-08-25T20:08:28.123Z,1598386108.123 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:28.530Z,1598386108.530 [DAT](INFO): DAT read: 

2020-08-25T20:08:28.531Z,1598386108.531 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:28.935Z,1598386108.935 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:29.328Z,1598386109.328 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:29.732Z,1598386109.732 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:30.132Z,1598386110.132 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:30.536Z,1598386110.536 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:30.940Z,1598386110.940 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:31.348Z,1598386111.348 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:31.748Z,1598386111.748 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:32.152Z,1598386112.152 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:32.556Z,1598386112.556 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:32.975Z,1598386112.975 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:33.382Z,1598386113.382 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:33.779Z,1598386113.779 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:34.199Z,1598386114.199 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:34.514Z,1598386114.514 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20200825T181443/Express0055.lzma
2020-08-25T20:08:34.584Z,1598386114.584 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:34.979Z,1598386114.979 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:35.382Z,1598386115.382 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:35.516Z,1598386115.516 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0055.lzma.bak
2020-08-25T20:08:35.516Z,1598386115.516 [DataOverHttps](INFO): SBD MOMSN=12616175
2020-08-25T20:08:35.788Z,1598386115.788 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:36.203Z,1598386116.203 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:36.612Z,1598386116.612 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:37.004Z,1598386117.004 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:37.404Z,1598386117.404 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:37.808Z,1598386117.808 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:38.223Z,1598386118.223 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:38.236Z,1598386118.236 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T20:08:38.236Z,1598386118.236 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T20:08:38.236Z,1598386118.236 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T20:08:38.627Z,1598386118.627 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:39.043Z,1598386119.043 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:39.435Z,1598386119.435 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:39.836Z,1598386119.836 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:40.236Z,1598386120.236 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:40.640Z,1598386120.640 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:41.044Z,1598386121.044 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:41.444Z,1598386121.444 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:41.848Z,1598386121.848 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:42.252Z,1598386122.252 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:42.656Z,1598386122.656 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:43.060Z,1598386123.060 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:08:43.060Z,1598386123.060 [DAT](FAULT): failed to enter command mode
2020-08-25T20:08:43.487Z,1598386123.487 [DAT](INFO): entering command mode
2020-08-25T20:08:43.879Z,1598386123.879 [DAT](INFO): DAT read: user:1>

2020-08-25T20:08:43.880Z,1598386123.880 [DAT](INFO): DAT read: Command '+++' not found

2020-08-25T20:08:43.881Z,1598386123.881 [DAT](INFO): DAT read: Error

2020-08-25T20:08:43.881Z,1598386123.881 [DAT](INFO): setting verbose to 3
2020-08-25T20:08:44.283Z,1598386124.283 [DAT](INFO): DAT read: user:2>

2020-08-25T20:08:44.284Z,1598386124.284 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T20:08:44.284Z,1598386124.284 [DAT](INFO): set verbose to 3
2020-08-25T20:08:44.284Z,1598386124.284 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T20:08:44.687Z,1598386124.687 [DAT](INFO): DAT read: user:3>

2020-08-25T20:08:44.688Z,1598386124.688 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T20:08:44.688Z,1598386124.688 [DAT](INFO): set DatVerbose to 27440
2020-08-25T20:08:44.689Z,1598386124.689 [DAT](INFO): setting transmit power to 8
2020-08-25T20:08:45.080Z,1598386125.080 [DAT](INFO): DAT read: user:4>

2020-08-25T20:08:45.081Z,1598386125.081 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T20:08:45.081Z,1598386125.081 [DAT](INFO): set transmit power to 8
2020-08-25T20:08:45.082Z,1598386125.082 [DAT](INFO): setting local address to 9
2020-08-25T20:08:45.484Z,1598386125.484 [DAT](INFO): DAT read: user:5>

2020-08-25T20:08:45.485Z,1598386125.485 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T20:08:45.486Z,1598386125.486 [DAT](INFO): set local address to 9
2020-08-25T20:08:55.180Z,1598386135.180 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T20:09:25.883Z,1598386165.883 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T20:13:38.799Z,1598386418.799 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T20:13:38.799Z,1598386418.799 [Default:CheckIn:C.Wait] Stopped
2020-08-25T20:13:38.799Z,1598386418.799 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T20:13:38.800Z,1598386418.800 [Default:CheckIn:D] Running Loop=1
2020-08-25T20:13:39.215Z,1598386419.215 [Default:CheckIn:D] Stopped
2020-08-25T20:13:39.215Z,1598386419.215 [Default:CheckIn:E] Running Loop=1
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.569116 min 
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn:E] Stopped
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn] Stopped
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn](INFO): Running loop #20
2020-08-25T20:13:39.608Z,1598386419.608 [Default:CheckIn] Running Loop=20
2020-08-25T20:13:39.609Z,1598386419.609 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T20:13:39.609Z,1598386419.609 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T20:18:39.798Z,1598386719.798 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T20:13:39.6Z
2020-08-25T20:18:39.798Z,1598386719.798 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T20:18:39.798Z,1598386719.798 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T20:18:41.796Z,1598386721.796 [DAT](INFO): setting remote address to 6
2020-08-25T20:18:42.201Z,1598386722.201 [DAT](INFO): DAT read: user:6>

2020-08-25T20:18:42.201Z,1598386722.201 [DAT](INFO): DAT read: RemoteAddr      | 6           

2020-08-25T20:18:42.202Z,1598386722.202 [DAT](INFO): set remote address to 6
2020-08-25T20:18:42.204Z,1598386722.204 [DAT](INFO): entering online mode
2020-08-25T20:18:42.627Z,1598386722.627 [DAT](INFO): DAT read: user:7>

2020-08-25T20:18:42.628Z,1598386722.628 [DAT](INFO): DAT read: 

2020-08-25T20:18:42.629Z,1598386722.629 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T20:18:42.629Z,1598386722.629 [DAT](INFO): commRate: 800
2020-08-25T20:18:42.629Z,1598386722.629 [DAT](INFO): online mode acknowledged
2020-08-25T20:18:42.630Z,1598386722.630 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T20:18:43.815Z,1598386723.815 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T20:18:46.241Z,1598386726.241 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:18:26.1411

2020-08-25T20:18:46.241Z,1598386726.241 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T20:18:47.450Z,1598386727.450 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T181443/Courier0057.lzma
2020-08-25T20:18:48.452Z,1598386728.452 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0057.lzma.bak
2020-08-25T20:18:48.452Z,1598386728.452 [DataOverHttps](INFO): SBD MOMSN=12616210
2020-08-25T20:19:02.808Z,1598386742.808 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T20:19:02.808Z,1598386742.808 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T20:19:04.034Z,1598386744.034 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T20:19:04.136Z,1598386744.136 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T20:19:07.712Z,1598386747.712 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:18:47.6413

2020-08-25T20:19:07.713Z,1598386747.713 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T20:19:08.483Z,1598386748.483 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20200825T181443/Express0058.lzma
2020-08-25T20:19:09.484Z,1598386749.484 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0058.lzma.bak
2020-08-25T20:19:09.485Z,1598386749.485 [DataOverHttps](INFO): SBD MOMSN=12616212
2020-08-25T20:19:12.177Z,1598386752.177 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T20:19:12.177Z,1598386752.177 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T20:19:12.177Z,1598386752.177 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T20:19:14.591Z,1598386754.591 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T20:24:12.748Z,1598387052.748 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T20:24:12.748Z,1598387052.748 [Default:CheckIn:C.Wait] Stopped
2020-08-25T20:24:12.748Z,1598387052.748 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T20:24:12.748Z,1598387052.748 [Default:CheckIn:D] Running Loop=1
2020-08-25T20:24:13.142Z,1598387053.142 [Default:CheckIn:D] Stopped
2020-08-25T20:24:13.142Z,1598387053.142 [Default:CheckIn:E] Running Loop=1
2020-08-25T20:24:13.546Z,1598387053.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.134578 min 
2020-08-25T20:24:13.546Z,1598387053.546 [Default:CheckIn:E] Stopped
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn] Stopped
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn](INFO): Running loop #21
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn] Running Loop=21
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T20:24:13.547Z,1598387053.547 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T20:24:15.159Z,1598387055.159 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-25T20:24:15.159Z,1598387055.159 [NAL9602] Data Fault, FailCount= 2
2020-08-25T20:24:15.160Z,1598387055.160 [NAL9602](ERROR): Data Fault
2020-08-25T20:24:15.177Z,1598387055.177 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T20:24:15.567Z,1598387055.567 [NAL9602](INFO): Powering down
2020-08-25T20:24:16.410Z,1598387056.410 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T20:24:16.410Z,1598387056.410 [NAL9602] No Fault, FailCount= 2
2020-08-25T20:24:45.863Z,1598387085.863 [NAL9602](INFO): Powering up NAL9602
2020-08-25T20:24:56.766Z,1598387096.766 [NAL9602](INFO): NAL9602 initialized
2020-08-25T20:25:42.992Z,1598387142.992 [CommandLine](IMPORTANT): got command restart application
2020-08-25T20:25:43.998Z,1598387143.998 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-08-25T20:25:43.999Z,1598387143.999 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:43.999Z,1598387143.999 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.114Z,1598387144.114 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-08-25T20:25:44.115Z,1598387144.115 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.115Z,1598387144.115 [CommandLine](INFO): Join timeout helper Thread ID is 3073
2020-08-25T20:25:44.116Z,1598387144.116 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-08-25T20:25:44.116Z,1598387144.116 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.117Z,1598387144.117 [NavChartDb](INFO): Join timeout helper Thread ID is 3074
2020-08-25T20:25:44.507Z,1598387144.507 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:44.507Z,1598387144.507 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.514Z,1598387144.514 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-08-25T20:25:44.514Z,1598387144.514 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.515Z,1598387144.515 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3075
2020-08-25T20:25:44.535Z,1598387144.535 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:44.535Z,1598387144.535 [WetLabsBB2FL](INFO): Powering down
2020-08-25T20:25:44.536Z,1598387144.536 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.554Z,1598387144.554 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-08-25T20:25:44.554Z,1598387144.554 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.555Z,1598387144.555 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3076
2020-08-25T20:25:44.679Z,1598387144.679 [CTD_Seabird](INFO): Powering down
2020-08-25T20:25:44.691Z,1598387144.691 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:44.691Z,1598387144.691 [CTD_Seabird](INFO): Powering down
2020-08-25T20:25:44.702Z,1598387144.702 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.714Z,1598387144.714 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-08-25T20:25:44.714Z,1598387144.714 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:44.715Z,1598387144.715 [BackSeatDriver](INFO): Join timeout helper Thread ID is 3077
2020-08-25T20:25:45.075Z,1598387145.075 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:45.075Z,1598387145.075 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:45.087Z,1598387145.087 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-08-25T20:25:45.087Z,1598387145.087 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:45.088Z,1598387145.088 [Radio_Surface](INFO): Join timeout helper Thread ID is 3078
2020-08-25T20:25:45.474Z,1598387145.474 [Radio_Surface](INFO): Powering down
2020-08-25T20:25:45.475Z,1598387145.475 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:45.476Z,1598387145.476 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:45.495Z,1598387145.495 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-08-25T20:25:45.495Z,1598387145.495 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:45.496Z,1598387145.496 [Onboard](INFO): Join timeout helper Thread ID is 3079
2020-08-25T20:25:45.891Z,1598387145.891 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-08-25T20:25:49.666Z,1598387149.666 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:49.667Z,1598387149.667 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.691Z,1598387149.691 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-08-25T20:25:49.691Z,1598387149.691 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.692Z,1598387149.692 [DataOverHttps](INFO): Join timeout helper Thread ID is 3080
2020-08-25T20:25:49.710Z,1598387149.710 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2285304 %. Average:280240.312500
2020-08-25T20:25:49.906Z,1598387149.906 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:49.907Z,1598387149.907 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.923Z,1598387149.923 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-08-25T20:25:49.923Z,1598387149.923 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.924Z,1598387149.924 [logger](INFO): Join timeout helper Thread ID is 3081
2020-08-25T20:25:49.930Z,1598387149.930 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:49.931Z,1598387149.931 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.943Z,1598387149.943 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-08-25T20:25:49.943Z,1598387149.943 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.943Z,1598387149.943 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-08-25T20:25:49.943Z,1598387149.943 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:49.944Z,1598387149.944 [controlThread](INFO): Join timeout helper Thread ID is 3082
2020-08-25T20:25:50.078Z,1598387150.078 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T20:25:50.079Z,1598387150.079 [controlThread](DEBUG): Uninitializing ControlThread
2020-08-25T20:25:50.079Z,1598387150.079 [AHRS_M2](INFO): Powering down
2020-08-25T20:25:50.151Z,1598387150.151 [NAL9602](INFO): Powering down
2020-08-25T20:25:50.152Z,1598387150.152 [DAT](INFO): Powering down
2020-08-25T20:25:50.271Z,1598387150.271 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-08-25T20:25:50.272Z,1598387150.272 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-08-25T20:25:50.272Z,1598387150.272 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-08-25T20:25:50.273Z,1598387150.273 [MissionManager](INFO): Uninitializing Mission Default
2020-08-25T20:25:50.273Z,1598387150.273 [Default] Stopped
2020-08-25T20:25:50.273Z,1598387150.273 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-25T20:25:50.273Z,1598387150.273 [Default:B.GoToSurface] Stopped
2020-08-25T20:25:50.273Z,1598387150.273 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T20:25:50.273Z,1598387150.273 [Default:CheckIn] Stopped
2020-08-25T20:25:50.273Z,1598387150.273 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T20:25:50.274Z,1598387150.274 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T20:25:50.276Z,1598387150.276 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-08-25T20:25:50.276Z,1598387150.276 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-08-25T20:25:50.277Z,1598387150.277 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-08-25T20:25:50.277Z,1598387150.277 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-08-25T20:25:50.277Z,1598387150.277 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-08-25T20:25:50.277Z,1598387150.277 [BuoyancyServo](INFO): Powering down
2020-08-25T20:25:50.290Z,1598387150.290 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-08-25T20:25:50.291Z,1598387150.291 [ElevatorServo](INFO): Powering down
2020-08-25T20:25:50.291Z,1598387150.291 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-08-25T20:25:50.291Z,1598387150.291 [MassServo](INFO): Powering down
2020-08-25T20:25:50.292Z,1598387150.292 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T20:25:50.292Z,1598387150.292 [RudderServo](INFO): Powering down
2020-08-25T20:25:50.293Z,1598387150.293 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-08-25T20:25:50.293Z,1598387150.293 [ThrusterServo](INFO): Powering down
2020-08-25T20:25:50.294Z,1598387150.294 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-08-25T20:25:50.294Z,1598387150.294 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-08-25T20:25:50.295Z,1598387150.295 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-08-25T20:25:50.295Z,1598387150.295 [CBIT](DEBUG): Powering off loads.
2020-08-25T20:25:50.306Z,1598387150.306 [CBIT](DEBUG): Disabling WDT.
2020-08-25T20:25:50.318Z,1598387150.318 [CBIT](DEBUG): Opening all GF detection circuits.
2020-08-25T20:25:50.319Z,1598387150.319 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.417Z,1598387150.417 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.419Z,1598387150.419 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.425Z,1598387150.425 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.491Z,1598387150.491 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.495Z,1598387150.495 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.498Z,1598387150.498 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.507Z,1598387150.507 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T20:25:50.586Z,1598387150.586 [logger ThreadHandler](INFO): Thread cancelled.