2017-08-31T19:02:18.384Z,1504206138.384 [DataOverHttps](INFO): Received command:restart logs
2017-08-31T19:02:18.413Z,1504206138.413 [CommandLine](IMPORTANT): got command restart logs
2017-08-31T19:04:09.350Z,1504206249.350 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:04:09.350Z,1504206249.350 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:04:09.350Z,1504206249.350 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:04:09.350Z,1504206249.350 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:04:09.761Z,1504206249.761 [Default:CheckIn:D] Stopped
2017-08-31T19:04:09.761Z,1504206249.761 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:04:10.169Z,1504206250.169 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.576825 min 
2017-08-31T19:04:10.169Z,1504206250.169 [Default:CheckIn:E] Stopped
2017-08-31T19:04:10.169Z,1504206250.169 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:04:10.169Z,1504206250.169 [Default:CheckIn] Stopped
2017-08-31T19:04:10.170Z,1504206250.170 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:04:10.170Z,1504206250.170 [Default:CheckIn](INFO): Running loop #3
2017-08-31T19:04:10.170Z,1504206250.170 [Default:CheckIn] Running Loop=3
2017-08-31T19:04:10.170Z,1504206250.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:04:10.170Z,1504206250.170 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:04:10.911Z,1504206250.911 [NAL9602](INFO): Powering up
2017-08-31T19:04:21.945Z,1504206261.945 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:05:12.855Z,1504206312.855 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:05:34.533Z,1504206334.533 [NAL9602](INFO): SBD MO Status=0, MOMSN=412, MT Status=0, MTMSN=0
2017-08-31T19:05:34.533Z,1504206334.533 [NAL9602](INFO): No messages in MT queue
2017-08-31T19:05:41.330Z,1504206341.330 [NAL9602](INFO): GPS fix at 20170831T190531: (36.807874, -121.785295)
2017-08-31T19:05:41.409Z,1504206341.409 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:05:41.410Z,1504206341.410 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:05:46.612Z,1504206346.612 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170830T173350/Courier0164.lzma
2017-08-31T19:05:47.377Z,1504206347.377 [DataOverHttps](INFO): Moved sent file to Logs/20170830T173350/Courier0164.lzma.bak
2017-08-31T19:05:47.378Z,1504206347.378 [DataOverHttps](INFO): SBD MOMSN=5071145
2017-08-31T19:05:51.623Z,1504206351.623 [NAL9602](INFO): Powering down
2017-08-31T19:06:01.916Z,1504206361.916 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20170831T190218/Courier0000.lzma
2017-08-31T19:06:02.653Z,1504206362.653 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0000.lzma.bak
2017-08-31T19:06:02.653Z,1504206362.653 [DataOverHttps](INFO): SBD MOMSN=5071147
2017-08-31T19:06:11.871Z,1504206371.871 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0004.lzma
2017-08-31T19:06:12.657Z,1504206372.657 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0004.lzma.bak
2017-08-31T19:06:12.658Z,1504206372.658 [DataOverHttps](INFO): SBD MOMSN=5071151
2017-08-31T19:06:22.114Z,1504206382.114 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20170830T173350/Express0165.lzma
2017-08-31T19:06:22.882Z,1504206382.882 [DataOverHttps](INFO): Moved sent file to Logs/20170830T173350/Express0165.lzma.bak
2017-08-31T19:06:22.882Z,1504206382.882 [DataOverHttps](INFO): SBD MOMSN=5071153
2017-08-31T19:06:37.327Z,1504206397.327 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20170831T190218/Express0001.lzma
2017-08-31T19:06:38.081Z,1504206398.081 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0001.lzma.bak
2017-08-31T19:06:38.081Z,1504206398.081 [DataOverHttps](INFO): SBD MOMSN=5071156
2017-08-31T19:06:47.319Z,1504206407.319 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Express0005.lzma
2017-08-31T19:06:48.105Z,1504206408.105 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0005.lzma.bak
2017-08-31T19:06:48.105Z,1504206408.105 [DataOverHttps](INFO): SBD MOMSN=5071160
2017-08-31T19:06:48.609Z,1504206408.609 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:06:48.610Z,1504206408.610 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:06:48.610Z,1504206408.610 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:11:49.008Z,1504206709.008 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:11:49.009Z,1504206709.009 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:11:49.009Z,1504206709.009 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:11:49.009Z,1504206709.009 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:11:49.399Z,1504206709.399 [Default:CheckIn:D] Stopped
2017-08-31T19:11:49.399Z,1504206709.399 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.237463 min 
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn:E] Stopped
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn] Stopped
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn](INFO): Running loop #4
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn] Running Loop=4
2017-08-31T19:11:49.806Z,1504206709.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:11:49.807Z,1504206709.807 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:11:53.431Z,1504206713.431 [NAL9602](INFO): Powering up
2017-08-31T19:12:04.332Z,1504206724.332 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:12:32.334Z,1504206752.334 [NAL9602](INFO): SBD MO Status=0, MOMSN=413, MT Status=0, MTMSN=0
2017-08-31T19:12:32.334Z,1504206752.334 [NAL9602](INFO): No messages in MT queue
2017-08-31T19:12:42.336Z,1504206762.336 [NAL9602](INFO): GPS fix at 20170831T191232: (36.802538, -121.787029)
2017-08-31T19:12:42.429Z,1504206762.429 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:12:42.429Z,1504206762.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:12:46.987Z,1504206766.987 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20170831T190218/Courier0008.lzma
2017-08-31T19:12:47.734Z,1504206767.734 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0008.lzma.bak
2017-08-31T19:12:47.734Z,1504206767.734 [DataOverHttps](INFO): SBD MOMSN=5071163
2017-08-31T19:12:52.312Z,1504206772.312 [NAL9602](INFO): Powering down
2017-08-31T19:12:56.939Z,1504206776.939 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20170831T190218/Express0009.lzma
2017-08-31T19:12:57.686Z,1504206777.686 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0009.lzma.bak
2017-08-31T19:12:57.686Z,1504206777.686 [DataOverHttps](INFO): SBD MOMSN=5071166
2017-08-31T19:12:58.182Z,1504206778.182 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:12:58.182Z,1504206778.182 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:12:58.182Z,1504206778.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:15:12.921Z,1504206912.921 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:17:58.753Z,1504207078.753 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:17:58.753Z,1504207078.753 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:17:58.753Z,1504207078.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:17:58.753Z,1504207078.753 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:17:59.140Z,1504207079.140 [Default:CheckIn:D] Stopped
2017-08-31T19:17:59.141Z,1504207079.141 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:17:59.560Z,1504207079.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.399827 min 
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn:E] Stopped
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn] Stopped
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn](INFO): Running loop #5
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn] Running Loop=5
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:17:59.561Z,1504207079.561 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:18:03.184Z,1504207083.184 [NAL9602](INFO): Powering up
2017-08-31T19:18:14.101Z,1504207094.101 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:18:54.494Z,1504207134.494 [NAL9602](INFO): SBD MO Status=2, MOMSN=414, MT Status=2, MTMSN=0
2017-08-31T19:18:54.494Z,1504207134.494 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T19:19:25.138Z,1504207165.138 [NAL9602](INFO): SBD MO Status=2, MOMSN=414, MT Status=2, MTMSN=0
2017-08-31T19:19:25.138Z,1504207165.138 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T19:20:18.278Z,1504207218.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=414, MT Status=2, MTMSN=0
2017-08-31T19:20:18.278Z,1504207218.278 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T19:20:35.882Z,1504207235.882 [NAL9602](INFO): SBD MO Status=0, MOMSN=414, MT Status=0, MTMSN=0
2017-08-31T19:20:35.883Z,1504207235.883 [NAL9602](INFO): No messages in MT queue
2017-08-31T19:20:37.097Z,1504207237.097 [NAL9602](INFO): GPS fix at 20170831T192026: (36.802331, -121.787278)
2017-08-31T19:20:37.155Z,1504207237.155 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:20:37.155Z,1504207237.155 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:20:41.777Z,1504207241.777 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20170831T190218/Courier0012.lzma
2017-08-31T19:20:42.517Z,1504207242.517 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0012.lzma.bak
2017-08-31T19:20:42.517Z,1504207242.517 [DataOverHttps](INFO): SBD MOMSN=5071170
2017-08-31T19:20:47.103Z,1504207247.103 [NAL9602](INFO): Powering down
2017-08-31T19:20:51.716Z,1504207251.716 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20170831T190218/Express0013.lzma
2017-08-31T19:20:52.480Z,1504207252.480 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0013.lzma.bak
2017-08-31T19:20:52.480Z,1504207252.480 [DataOverHttps](INFO): SBD MOMSN=5071173
2017-08-31T19:20:52.983Z,1504207252.983 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:20:52.983Z,1504207252.983 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:20:52.983Z,1504207252.983 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:25:12.969Z,1504207512.969 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:25:53.748Z,1504207553.748 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:25:53.749Z,1504207553.749 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:25:53.749Z,1504207553.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:25:53.749Z,1504207553.749 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:25:54.128Z,1504207554.128 [Default:CheckIn:D] Stopped
2017-08-31T19:25:54.128Z,1504207554.128 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:25:54.546Z,1504207554.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.316292 min 
2017-08-31T19:25:54.546Z,1504207554.546 [Default:CheckIn:E] Stopped
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn] Stopped
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn](INFO): Running loop #6
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn] Running Loop=6
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:25:54.547Z,1504207554.547 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:25:57.899Z,1504207557.899 [NAL9602](INFO): Powering up
2017-08-31T19:26:09.076Z,1504207569.076 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:30:54.615Z,1504207854.615 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T19:25:54.5Z
2017-08-31T19:30:54.615Z,1504207854.615 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:30:54.615Z,1504207854.615 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:30:59.266Z,1504207859.266 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0016.lzma
2017-08-31T19:31:00.009Z,1504207860.009 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0016.lzma.bak
2017-08-31T19:31:00.009Z,1504207860.009 [DataOverHttps](INFO): SBD MOMSN=5071177
2017-08-31T19:31:09.257Z,1504207869.257 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20170831T190218/Express0017.lzma
2017-08-31T19:31:09.996Z,1504207869.996 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0017.lzma.bak
2017-08-31T19:31:09.997Z,1504207869.997 [DataOverHttps](INFO): SBD MOMSN=5071179
2017-08-31T19:31:10.484Z,1504207870.484 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:31:10.484Z,1504207870.484 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:31:10.484Z,1504207870.484 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:31:14.292Z,1504207874.292 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T19:31:19.603Z,1504207879.603 [NAL9602](INFO): Powering down
2017-08-31T19:35:15.412Z,1504208115.412 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:36:11.101Z,1504208171.101 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:36:11.102Z,1504208171.102 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:36:11.102Z,1504208171.102 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:36:11.102Z,1504208171.102 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:36:11.473Z,1504208171.473 [Default:CheckIn:D] Stopped
2017-08-31T19:36:11.473Z,1504208171.473 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:36:11.875Z,1504208171.875 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.605367 min 
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn:E] Stopped
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn] Stopped
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn](INFO): Running loop #7
2017-08-31T19:36:11.876Z,1504208171.876 [Default:CheckIn] Running Loop=7
2017-08-31T19:36:11.877Z,1504208171.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:36:11.877Z,1504208171.877 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:36:15.533Z,1504208175.533 [NAL9602](INFO): Powering up
2017-08-31T19:36:26.408Z,1504208186.408 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:36:27.209Z,1504208187.209 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T19:36:27.209Z,1504208187.209 [NAL9602] Data Fault, FailCount= 1
2017-08-31T19:36:27.210Z,1504208187.210 [NAL9602](ERROR): Data Fault
2017-08-31T19:36:27.301Z,1504208187.301 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T19:36:27.610Z,1504208187.610 [NAL9602](INFO): Powering down
2017-08-31T19:36:28.475Z,1504208188.475 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T19:36:28.475Z,1504208188.475 [NAL9602] No Fault, FailCount= 1
2017-08-31T19:36:32.810Z,1504208192.810 [NAL9602](INFO): Powering up NAL9602
2017-08-31T19:36:42.848Z,1504208202.848 [PNI_TCM](ERROR): CRC does not match. Expected:0x45975 got:0x25881
2017-08-31T19:36:44.020Z,1504208204.020 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:37:07.674Z,1504208227.674 [PNI_TCM](ERROR): CRC does not match. Expected:0x10271 got:0x39704
2017-08-31T19:37:08.480Z,1504208228.480 [PNI_TCM](ERROR): CRC does not match. Expected:0x18383 got:0x44861
2017-08-31T19:37:18.068Z,1504208238.068 [PNI_TCM](ERROR): CRC does not match. Expected:0x12795 got:0x49234
2017-08-31T19:37:31.677Z,1504208251.677 [PNI_TCM](ERROR): CRC does not match. Expected:0x26156 got:0x49646
2017-08-31T19:37:32.478Z,1504208252.478 [PNI_TCM](ERROR): CRC does not match. Expected:0x63660 got:0x48823
2017-08-31T19:38:11.680Z,1504208291.680 [PNI_TCM](ERROR): CRC does not match. Expected:0x17022 got:0x6332
2017-08-31T19:38:12.452Z,1504208292.452 [PNI_TCM](ERROR): CRC does not match. Expected:0x15362 got:0x98
2017-08-31T19:41:12.250Z,1504208472.250 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T19:36:11.9Z
2017-08-31T19:41:12.250Z,1504208472.250 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:41:12.251Z,1504208472.251 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:41:16.650Z,1504208476.650 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0020.lzma
2017-08-31T19:41:17.417Z,1504208477.417 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0020.lzma.bak
2017-08-31T19:41:17.417Z,1504208477.417 [DataOverHttps](INFO): SBD MOMSN=5071182
2017-08-31T19:41:26.696Z,1504208486.696 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20170831T190218/Express0021.lzma
2017-08-31T19:41:27.433Z,1504208487.433 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0021.lzma.bak
2017-08-31T19:41:27.433Z,1504208487.433 [DataOverHttps](INFO): SBD MOMSN=5071184
2017-08-31T19:41:27.933Z,1504208487.933 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:41:27.933Z,1504208487.933 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:41:27.934Z,1504208487.934 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:41:47.412Z,1504208507.412 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T19:41:53.012Z,1504208513.012 [NAL9602](INFO): Powering down
2017-08-31T19:43:51.659Z,1504208631.659 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501
2017-08-31T19:44:06.059Z,1504208646.059 [PNI_TCM](ERROR): CRC does not match. Expected:0x24692 got:0x7361
2017-08-31T19:45:15.787Z,1504208715.787 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:46:28.473Z,1504208788.473 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:46:28.474Z,1504208788.474 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:46:28.474Z,1504208788.474 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:46:28.474Z,1504208788.474 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:46:28.856Z,1504208788.856 [Default:CheckIn:D] Stopped
2017-08-31T19:46:28.856Z,1504208788.856 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:46:29.255Z,1504208789.255 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.895089 min 
2017-08-31T19:46:29.255Z,1504208789.255 [Default:CheckIn:E] Stopped
2017-08-31T19:46:29.255Z,1504208789.255 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn] Stopped
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn](INFO): Running loop #8
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn] Running Loop=8
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:46:29.256Z,1504208789.256 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:46:34.262Z,1504208794.262 [NAL9602](INFO): Powering up
2017-08-31T19:46:45.431Z,1504208805.431 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:46:46.220Z,1504208806.220 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T19:46:46.220Z,1504208806.220 [NAL9602] Data Fault, FailCount= 2
2017-08-31T19:46:46.220Z,1504208806.220 [NAL9602](ERROR): Data Fault
2017-08-31T19:46:46.307Z,1504208806.307 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T19:46:46.633Z,1504208806.633 [NAL9602](INFO): Powering down
2017-08-31T19:46:47.494Z,1504208807.494 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T19:46:47.494Z,1504208807.494 [NAL9602] No Fault, FailCount= 2
2017-08-31T19:46:51.825Z,1504208811.825 [NAL9602](INFO): Powering up NAL9602
2017-08-31T19:47:03.023Z,1504208823.023 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:51:29.441Z,1504209089.441 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T19:46:29.3Z
2017-08-31T19:51:29.441Z,1504209089.441 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T19:51:29.441Z,1504209089.441 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T19:51:34.236Z,1504209094.236 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0024.lzma
2017-08-31T19:51:34.986Z,1504209094.986 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0024.lzma.bak
2017-08-31T19:51:34.986Z,1504209094.986 [DataOverHttps](INFO): SBD MOMSN=5071189
2017-08-31T19:51:44.259Z,1504209104.259 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20170831T190218/Express0025.lzma
2017-08-31T19:51:45.041Z,1504209105.041 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0025.lzma.bak
2017-08-31T19:51:45.041Z,1504209105.041 [DataOverHttps](INFO): SBD MOMSN=5071191
2017-08-31T19:51:45.559Z,1504209105.559 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T19:51:45.559Z,1504209105.559 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T19:51:45.559Z,1504209105.559 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T19:52:06.258Z,1504209126.258 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T19:52:11.848Z,1504209131.848 [NAL9602](INFO): Powering down
2017-08-31T19:55:16.169Z,1504209316.169 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T19:56:46.303Z,1504209406.303 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T19:56:46.303Z,1504209406.303 [Default:CheckIn:C.Wait] Stopped
2017-08-31T19:56:46.303Z,1504209406.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T19:56:46.304Z,1504209406.304 [Default:CheckIn:D] Running Loop=1
2017-08-31T19:56:46.705Z,1504209406.705 [Default:CheckIn:D] Stopped
2017-08-31T19:56:46.705Z,1504209406.705 [Default:CheckIn:E] Running Loop=1
2017-08-31T19:56:47.111Z,1504209407.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.192562 min 
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn:E] Stopped
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn] Stopped
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn](INFO): Running loop #9
2017-08-31T19:56:47.112Z,1504209407.112 [Default:CheckIn] Running Loop=9
2017-08-31T19:56:47.113Z,1504209407.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T19:56:47.113Z,1504209407.113 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T19:56:50.493Z,1504209410.493 [NAL9602](INFO): Powering up
2017-08-31T19:57:01.645Z,1504209421.645 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:57:33.644Z,1504209453.644 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2017-08-31T19:57:33.718Z,1504209453.718 [NAL9602](FAULT): received: 
+CSQ:0

OK4, 0, 0, 0, 0

OK
2017-08-31T19:57:33.718Z,1504209453.718 [NAL9602] Data Fault, FailCount= 3
2017-08-31T19:57:33.719Z,1504209453.719 [NAL9602](ERROR): Data Fault
2017-08-31T19:57:33.795Z,1504209453.795 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T19:57:34.049Z,1504209454.049 [NAL9602](INFO): Powering down
2017-08-31T19:57:34.936Z,1504209454.936 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T19:57:34.936Z,1504209454.936 [NAL9602] No Fault, FailCount= 3
2017-08-31T19:57:39.244Z,1504209459.244 [NAL9602](INFO): Powering up NAL9602
2017-08-31T19:57:51.088Z,1504209471.088 [NAL9602](INFO): NAL9602 initialized
2017-08-31T19:57:51.883Z,1504209471.883 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T19:57:51.883Z,1504209471.883 [NAL9602] Data Fault, FailCount= 4
2017-08-31T19:57:51.883Z,1504209471.883 [NAL9602](ERROR): Data Fault
2017-08-31T19:57:51.947Z,1504209471.947 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T19:57:52.281Z,1504209472.281 [NAL9602](INFO): Powering down
2017-08-31T19:57:53.142Z,1504209473.142 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T19:57:53.142Z,1504209473.142 [NAL9602] No Fault, FailCount= 4
2017-08-31T19:57:57.493Z,1504209477.493 [NAL9602](INFO): Powering up NAL9602
2017-08-31T19:58:08.687Z,1504209488.687 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:01:47.444Z,1504209707.444 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T19:56:47.1Z
2017-08-31T20:01:47.444Z,1504209707.444 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:01:47.444Z,1504209707.444 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:01:51.827Z,1504209711.827 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0028.lzma
2017-08-31T20:01:52.578Z,1504209712.578 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0028.lzma.bak
2017-08-31T20:01:52.578Z,1504209712.578 [DataOverHttps](INFO): SBD MOMSN=5071196
2017-08-31T20:02:01.708Z,1504209721.708 [NAL9602](INFO): SBD MO Status=2, MOMSN=415, MT Status=2, MTMSN=0
2017-08-31T20:02:01.708Z,1504209721.708 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:02:01.835Z,1504209721.835 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20170831T190218/Express0029.lzma
2017-08-31T20:02:02.618Z,1504209722.618 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0029.lzma.bak
2017-08-31T20:02:02.618Z,1504209722.618 [DataOverHttps](INFO): SBD MOMSN=5071198
2017-08-31T20:02:03.112Z,1504209723.112 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:02:03.112Z,1504209723.112 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:02:03.112Z,1504209723.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:02:06.908Z,1504209726.908 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T20:02:12.192Z,1504209732.192 [NAL9602](INFO): Powering down
2017-08-31T20:05:08.515Z,1504209908.515 [PNI_TCM](ERROR): CRC does not match. Expected:0x39939 got:0x142
2017-08-31T20:05:16.570Z,1504209916.570 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:05:22.910Z,1504209922.910 [PNI_TCM](ERROR): CRC does not match. Expected:0x29717 got:0x7490
2017-08-31T20:05:24.508Z,1504209924.508 [PNI_TCM](ERROR): CRC does not match. Expected:0x33301 got:0x7361
2017-08-31T20:07:03.511Z,1504210023.511 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:07:03.512Z,1504210023.512 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:07:03.512Z,1504210023.512 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:07:03.512Z,1504210023.512 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:07:03.913Z,1504210023.913 [Default:CheckIn:D] Stopped
2017-08-31T20:07:03.913Z,1504210023.913 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:07:04.280Z,1504210024.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.479378 min 
2017-08-31T20:07:04.280Z,1504210024.280 [Default:CheckIn:E] Stopped
2017-08-31T20:07:04.280Z,1504210024.280 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:07:04.280Z,1504210024.280 [Default:CheckIn] Stopped
2017-08-31T20:07:04.288Z,1504210024.288 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:07:04.289Z,1504210024.289 [Default:CheckIn](INFO): Running loop #10
2017-08-31T20:07:04.289Z,1504210024.289 [Default:CheckIn] Running Loop=10
2017-08-31T20:07:04.289Z,1504210024.289 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:07:04.289Z,1504210024.289 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:07:07.920Z,1504210027.920 [NAL9602](INFO): Powering up
2017-08-31T20:07:18.833Z,1504210038.833 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:07:50.833Z,1504210070.833 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2017-08-31T20:07:50.914Z,1504210070.914 [NAL9602](FAULT): received: 
+SBDI: 2, 415, 2, 0, 0, 0

OK
2017-08-31T20:07:50.914Z,1504210070.914 [NAL9602] Data Fault, FailCount= 5
2017-08-31T20:07:50.914Z,1504210070.914 [NAL9602](ERROR): Data Fault
2017-08-31T20:07:51.021Z,1504210071.021 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T20:07:51.021Z,1504210071.021 [CBIT](CRITICAL): Data Fault in component: NAL9602
2017-08-31T20:07:51.236Z,1504210071.236 [NAL9602](INFO): Powering down
2017-08-31T20:07:51.304Z,1504210071.304 [CommandLine](FAULT): Scheduling is paused
2017-08-31T20:07:51.304Z,1504210071.304 [CBIT](INFO): Critical error at 20170831T200751
2017-08-31T20:09:51.163Z,1504210191.163 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T20:09:51.163Z,1504210191.163 [NAL9602] No Fault, FailCount= 5
2017-08-31T20:09:51.502Z,1504210191.502 [NAL9602](INFO): Powering up NAL9602
2017-08-31T20:10:02.700Z,1504210202.700 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:10:03.505Z,1504210203.505 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T20:10:03.505Z,1504210203.505 [NAL9602] Data Fault, FailCount= 1
2017-08-31T20:10:03.505Z,1504210203.505 [NAL9602](ERROR): Data Fault
2017-08-31T20:10:03.589Z,1504210203.589 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T20:10:03.902Z,1504210203.902 [NAL9602](INFO): Powering down
2017-08-31T20:10:04.771Z,1504210204.771 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T20:10:04.771Z,1504210204.771 [NAL9602] No Fault, FailCount= 1
2017-08-31T20:10:09.270Z,1504210209.270 [NAL9602](INFO): Powering up NAL9602
2017-08-31T20:10:20.472Z,1504210220.472 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:12:04.304Z,1504210324.304 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T20:07:04.3Z
2017-08-31T20:12:04.304Z,1504210324.304 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:12:04.305Z,1504210324.305 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:12:08.935Z,1504210328.935 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20170831T190218/Courier0032.lzma
2017-08-31T20:12:09.677Z,1504210329.677 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0032.lzma.bak
2017-08-31T20:12:09.678Z,1504210329.678 [DataOverHttps](INFO): SBD MOMSN=5071204
2017-08-31T20:12:18.881Z,1504210338.881 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20170831T190218/Express0033.lzma
2017-08-31T20:12:19.665Z,1504210339.665 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0033.lzma.bak
2017-08-31T20:12:19.666Z,1504210339.666 [DataOverHttps](INFO): SBD MOMSN=5071207
2017-08-31T20:12:20.163Z,1504210340.163 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:12:20.164Z,1504210340.164 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:12:20.164Z,1504210340.164 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:12:23.790Z,1504210343.790 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T20:12:23.822Z,1504210343.822 [PNI_TCM](ERROR): CRC does not match. Expected:0x21586 got:0x27399
2017-08-31T20:12:23.823Z,1504210343.823 [PNI_TCM](ERROR): CRC does not match. Expected:0x18184 got:0x7175
2017-08-31T20:12:23.823Z,1504210343.823 [PNI_TCM](ERROR): CRC does not match. Expected:0x46773 got:0x24071
2017-08-31T20:12:23.823Z,1504210343.823 [PNI_TCM](ERROR): CRC does not match. Expected:0x12089 got:0x32263
2017-08-31T20:12:23.824Z,1504210343.824 [PNI_TCM](ERROR): CRC does not match. Expected:0x5645 got:0x39687
2017-08-31T20:12:23.824Z,1504210343.824 [PNI_TCM](ERROR): CRC does not match. Expected:0x61169 got:0x60935
2017-08-31T20:12:23.824Z,1504210343.824 [PNI_TCM](ERROR): CRC does not match. Expected:0x27207 got:0x49159
2017-08-31T20:12:23.825Z,1504210343.825 [PNI_TCM](ERROR): CRC does not match. Expected:0x8121 got:0x48391
2017-08-31T20:12:29.135Z,1504210349.135 [NAL9602](INFO): Powering down
2017-08-31T20:15:16.708Z,1504210516.708 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:15:28.556Z,1504210528.556 [PNI_TCM](ERROR): CRC does not match. Expected:0x2394 got:0x1857
2017-08-31T20:15:30.143Z,1504210530.143 [PNI_TCM](ERROR): CRC does not match. Expected:0x25845 got:0x6592
2017-08-31T20:15:33.347Z,1504210533.347 [PNI_TCM](ERROR): CRC does not match. Expected:0x64431 got:0x16787
2017-08-31T20:15:36.540Z,1504210536.540 [PNI_TCM](ERROR): CRC does not match. Expected:0x64639 got:0x41
2017-08-31T20:15:39.741Z,1504210539.741 [PNI_TCM](ERROR): CRC does not match. Expected:0x61927 got:0x1797
2017-08-31T20:15:50.939Z,1504210550.939 [PNI_TCM](ERROR): CRC does not match. Expected:0x3892 got:0x16394
2017-08-31T20:15:57.350Z,1504210557.350 [PNI_TCM](ERROR): CRC does not match. Expected:0x30874 got:0x247
2017-08-31T20:16:02.157Z,1504210562.157 [PNI_TCM](ERROR): CRC does not match. Expected:0x37170 got:0x16786
2017-08-31T20:16:05.354Z,1504210565.354 [PNI_TCM](ERROR): CRC does not match. Expected:0x61927 got:0x1797
2017-08-31T20:16:06.955Z,1504210566.955 [PNI_TCM](ERROR): CRC does not match. Expected:0x25873 got:0x13053
2017-08-31T20:16:08.544Z,1504210568.544 [PNI_TCM](ERROR): CRC does not match. Expected:0x43462 got:0x44592
2017-08-31T20:16:10.150Z,1504210570.150 [PNI_TCM](ERROR): CRC does not match. Expected:0x506 got:0x16802
2017-08-31T20:16:13.336Z,1504210573.336 [PNI_TCM](ERROR): CRC does not match. Expected:0x35720 got:0x1346
2017-08-31T20:16:13.736Z,1504210573.736 [PNI_TCM](ERROR): CRC does not match. Expected:0x2358 got:0x19229
2017-08-31T20:16:21.359Z,1504210581.359 [PNI_TCM](ERROR): CRC does not match. Expected:0x32759 got:0x16801
2017-08-31T20:17:20.922Z,1504210640.922 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:17:20.922Z,1504210640.922 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:17:20.922Z,1504210640.922 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:17:20.923Z,1504210640.923 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:17:21.318Z,1504210641.318 [Default:CheckIn:D] Stopped
2017-08-31T20:17:21.318Z,1504210641.318 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:17:21.733Z,1504210641.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.769442 min 
2017-08-31T20:17:21.733Z,1504210641.733 [Default:CheckIn:E] Stopped
2017-08-31T20:17:21.733Z,1504210641.733 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn] Stopped
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn](INFO): Running loop #11
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn] Running Loop=11
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:17:21.734Z,1504210641.734 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:17:25.080Z,1504210645.080 [NAL9602](INFO): Powering up
2017-08-31T20:17:36.221Z,1504210656.221 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:18:07.827Z,1504210687.827 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2017-08-31T20:18:07.910Z,1504210687.910 [NAL9602](FAULT): received: 
+CSQ:0

OK5, 2, 0, 0, 0

OK
2017-08-31T20:18:07.910Z,1504210687.910 [NAL9602] Data Fault, FailCount= 2
2017-08-31T20:18:07.910Z,1504210687.910 [NAL9602](ERROR): Data Fault
2017-08-31T20:18:08.020Z,1504210688.020 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T20:18:08.227Z,1504210688.227 [NAL9602](INFO): Powering down
2017-08-31T20:18:09.092Z,1504210689.092 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T20:18:09.092Z,1504210689.092 [NAL9602] No Fault, FailCount= 2
2017-08-31T20:18:13.416Z,1504210693.416 [NAL9602](INFO): Powering up NAL9602
2017-08-31T20:18:25.659Z,1504210705.659 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:21:20.613Z,1504210880.613 [NAL9602](INFO): SBD MO Status=0, MOMSN=415, MT Status=0, MTMSN=0
2017-08-31T20:21:20.613Z,1504210880.613 [NAL9602](INFO): No messages in MT queue
2017-08-31T20:21:21.425Z,1504210881.425 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T20:21:21.425Z,1504210881.425 [NAL9602] Data Fault, FailCount= 1
2017-08-31T20:21:21.425Z,1504210881.425 [NAL9602](ERROR): Data Fault
2017-08-31T20:21:21.514Z,1504210881.514 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T20:21:21.858Z,1504210881.858 [NAL9602](INFO): Powering down
2017-08-31T20:21:22.686Z,1504210882.686 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T20:21:22.686Z,1504210882.686 [NAL9602] No Fault, FailCount= 1
2017-08-31T20:21:27.176Z,1504210887.176 [NAL9602](INFO): Powering up NAL9602
2017-08-31T20:21:37.979Z,1504210897.979 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:22:22.047Z,1504210942.047 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T20:17:21.7Z
2017-08-31T20:22:22.047Z,1504210942.047 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:22:22.047Z,1504210942.047 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:22:26.298Z,1504210946.298 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0036.lzma
2017-08-31T20:22:27.070Z,1504210947.070 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0036.lzma.bak
2017-08-31T20:22:27.070Z,1504210947.070 [DataOverHttps](INFO): SBD MOMSN=5071215
2017-08-31T20:22:27.519Z,1504210947.519 [NAL9602](INFO): Powering down
2017-08-31T20:22:37.014Z,1504210957.014 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20170831T190218/Express0037.lzma
2017-08-31T20:22:37.791Z,1504210957.791 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0037.lzma.bak
2017-08-31T20:22:37.791Z,1504210957.791 [DataOverHttps](INFO): SBD MOMSN=5071217
2017-08-31T20:22:38.297Z,1504210958.297 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:22:38.297Z,1504210958.297 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:22:38.297Z,1504210958.297 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:25:16.924Z,1504211116.924 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:27:38.713Z,1504211258.713 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:27:38.713Z,1504211258.713 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:27:38.713Z,1504211258.713 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:27:38.713Z,1504211258.713 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:27:39.087Z,1504211259.087 [Default:CheckIn:D] Stopped
2017-08-31T20:27:39.087Z,1504211259.087 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:27:39.523Z,1504211259.523 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.065601 min 
2017-08-31T20:27:39.523Z,1504211259.523 [Default:CheckIn:E] Stopped
2017-08-31T20:27:39.523Z,1504211259.523 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn] Stopped
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn](INFO): Running loop #12
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn] Running Loop=12
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:27:39.524Z,1504211259.524 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:27:43.182Z,1504211263.182 [NAL9602](INFO): Powering up
2017-08-31T20:27:54.102Z,1504211274.102 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:29:25.460Z,1504211365.460 [NAL9602](INFO): SBD MO Status=2, MOMSN=416, MT Status=2, MTMSN=0
2017-08-31T20:29:25.460Z,1504211365.460 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:30:38.591Z,1504211438.591 [NAL9602](INFO): SBD MO Status=2, MOMSN=416, MT Status=2, MTMSN=0
2017-08-31T20:30:38.592Z,1504211438.592 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:31:51.598Z,1504211511.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=416, MT Status=2, MTMSN=0
2017-08-31T20:31:51.598Z,1504211511.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:32:39.643Z,1504211559.643 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T20:27:39.5Z
2017-08-31T20:32:39.643Z,1504211559.643 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:32:39.644Z,1504211559.644 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:32:44.196Z,1504211564.196 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0040.lzma
2017-08-31T20:32:44.928Z,1504211564.928 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0040.lzma.bak
2017-08-31T20:32:44.928Z,1504211564.928 [DataOverHttps](INFO): SBD MOMSN=5071224
2017-08-31T20:32:44.959Z,1504211564.959 [NAL9602](INFO): SBD MO Status=2, MOMSN=416, MT Status=2, MTMSN=0
2017-08-31T20:32:44.959Z,1504211564.959 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:32:49.034Z,1504211569.034 [PNI_TCM](ERROR): CRC does not match. Expected:0x48306 got:0x32795
2017-08-31T20:32:49.034Z,1504211569.034 [PNI_TCM](ERROR): CRC does not match. Expected:0x53704 got:0x27419
2017-08-31T20:32:49.034Z,1504211569.034 [PNI_TCM](ERROR): CRC does not match. Expected:0x14576 got:0x63259
2017-08-31T20:32:49.035Z,1504211569.035 [PNI_TCM](ERROR): CRC does not match. Expected:0x56118 got:0x44059
2017-08-31T20:32:49.035Z,1504211569.035 [PNI_TCM](ERROR): CRC does not match. Expected:0x43187 got:0x29467
2017-08-31T20:32:49.036Z,1504211569.036 [PNI_TCM](ERROR): CRC does not match. Expected:0x29535 got:0x9243
2017-08-31T20:32:49.036Z,1504211569.036 [PNI_TCM](ERROR): CRC does not match. Expected:0x57903 got:0x2587
2017-08-31T20:32:49.036Z,1504211569.036 [PNI_TCM](ERROR): CRC does not match. Expected:0x904 got:0x46619
2017-08-31T20:32:54.356Z,1504211574.356 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20170831T190218/Express0041.lzma
2017-08-31T20:32:55.131Z,1504211575.131 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0041.lzma.bak
2017-08-31T20:32:55.131Z,1504211575.131 [DataOverHttps](INFO): SBD MOMSN=5071226
2017-08-31T20:32:55.629Z,1504211575.629 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:32:55.629Z,1504211575.629 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:32:55.629Z,1504211575.629 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:33:06.589Z,1504211586.589 [NAL9602](INFO): SBD MO Status=2, MOMSN=416, MT Status=2, MTMSN=0
2017-08-31T20:33:06.590Z,1504211586.590 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:33:06.991Z,1504211586.991 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T20:33:12.577Z,1504211592.577 [NAL9602](INFO): Powering down
2017-08-31T20:35:17.280Z,1504211717.280 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:36:02.193Z,1504211762.193 [PNI_TCM](ERROR): CRC does not match. Expected:0x17260 got:0x62492
2017-08-31T20:36:14.978Z,1504211774.978 [PNI_TCM](ERROR): CRC does not match. Expected:0x10393 got:0x38330
2017-08-31T20:36:16.583Z,1504211776.583 [PNI_TCM](ERROR): CRC does not match. Expected:0x1663 got:0x6
2017-08-31T20:36:18.184Z,1504211778.184 [PNI_TCM](ERROR): CRC does not match. Expected:0x21656 got:0x16802
2017-08-31T20:36:20.185Z,1504211780.185 [PNI_TCM](ERROR): CRC does not match. Expected:0x32472 got:0x19053
2017-08-31T20:36:22.981Z,1504211782.981 [PNI_TCM](ERROR): CRC does not match. Expected:0x64639 got:0x41
2017-08-31T20:36:27.778Z,1504211787.778 [PNI_TCM](ERROR): CRC does not match. Expected:0x30956 got:0x29979
2017-08-31T20:36:29.388Z,1504211789.388 [PNI_TCM](ERROR): CRC does not match. Expected:0x55058 got:0x6334
2017-08-31T20:36:32.584Z,1504211792.584 [PNI_TCM](ERROR): CRC does not match. Expected:0x60450 got:0x16984
2017-08-31T20:36:35.783Z,1504211795.783 [PNI_TCM](ERROR): CRC does not match. Expected:0x22858 got:0x16972
2017-08-31T20:36:39.376Z,1504211799.376 [PNI_TCM](ERROR): CRC does not match. Expected:0x56128 got:0x44500
2017-08-31T20:36:43.784Z,1504211803.784 [PNI_TCM](ERROR): CRC does not match. Expected:0x16240 got:0x39850
2017-08-31T20:36:45.389Z,1504211805.389 [PNI_TCM](ERROR): CRC does not match. Expected:0x62019 got:0x44316
2017-08-31T20:36:50.182Z,1504211810.182 [PNI_TCM](ERROR): CRC does not match. Expected:0x48771 got:0x1287
2017-08-31T20:36:51.788Z,1504211811.788 [PNI_TCM](ERROR): CRC does not match. Expected:0x46739 got:0x41535
2017-08-31T20:37:56.050Z,1504211876.050 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:37:56.050Z,1504211876.050 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:37:56.050Z,1504211876.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:37:56.051Z,1504211876.051 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:37:56.451Z,1504211876.451 [Default:CheckIn:D] Stopped
2017-08-31T20:37:56.452Z,1504211876.452 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.355013 min 
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn:E] Stopped
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn] Stopped
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:37:56.844Z,1504211876.844 [Default:CheckIn](INFO): Running loop #13
2017-08-31T20:37:56.845Z,1504211876.845 [Default:CheckIn] Running Loop=13
2017-08-31T20:37:56.845Z,1504211876.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:37:56.845Z,1504211876.845 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:38:00.205Z,1504211880.205 [NAL9602](INFO): Powering up
2017-08-31T20:38:11.378Z,1504211891.378 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:38:12.174Z,1504211892.174 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-08-31T20:38:12.174Z,1504211892.174 [NAL9602] Data Fault, FailCount= 2
2017-08-31T20:38:12.174Z,1504211892.174 [NAL9602](ERROR): Data Fault
2017-08-31T20:38:12.261Z,1504211892.261 [CBIT](ERROR): Data Fault in component: NAL9602
2017-08-31T20:38:12.576Z,1504211892.576 [NAL9602](INFO): Powering down
2017-08-31T20:38:13.440Z,1504211893.440 [CBIT](INFO): Clearing failed state for component NAL9602
2017-08-31T20:38:13.441Z,1504211893.441 [NAL9602] No Fault, FailCount= 2
2017-08-31T20:38:17.785Z,1504211897.785 [NAL9602](INFO): Powering up NAL9602
2017-08-31T20:38:28.588Z,1504211908.588 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:39:14.337Z,1504211954.337 [NAL9602](INFO): SBD MO Status=0, MOMSN=416, MT Status=0, MTMSN=0
2017-08-31T20:39:14.337Z,1504211954.337 [NAL9602](INFO): No messages in MT queue
2017-08-31T20:40:13.387Z,1504212013.387 [PNI_TCM](ERROR): CRC does not match. Expected:0x6767 got:0x19676
2017-08-31T20:40:16.596Z,1504212016.596 [PNI_TCM](ERROR): CRC does not match. Expected:0x65146 got:0x37661
2017-08-31T20:42:13.408Z,1504212133.408 [NAL9602](INFO): GPS fix at 20170831T204203: (36.802746, -121.787964)
2017-08-31T20:42:13.479Z,1504212133.479 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:42:13.479Z,1504212133.479 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:42:18.059Z,1504212138.059 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20170831T190218/Courier0044.lzma
2017-08-31T20:42:18.794Z,1504212138.794 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0044.lzma.bak
2017-08-31T20:42:18.794Z,1504212138.794 [DataOverHttps](INFO): SBD MOMSN=5071231
2017-08-31T20:42:23.353Z,1504212143.353 [NAL9602](INFO): Powering down
2017-08-31T20:42:27.956Z,1504212147.956 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20170831T190218/Express0045.lzma
2017-08-31T20:42:28.706Z,1504212148.706 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0045.lzma.bak
2017-08-31T20:42:28.706Z,1504212148.706 [DataOverHttps](INFO): SBD MOMSN=5071234
2017-08-31T20:42:29.203Z,1504212149.203 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:42:29.203Z,1504212149.203 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:42:29.203Z,1504212149.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:45:17.512Z,1504212317.512 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:47:29.963Z,1504212449.963 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:47:29.963Z,1504212449.963 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:47:29.963Z,1504212449.963 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:47:29.963Z,1504212449.963 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:47:30.363Z,1504212450.363 [Default:CheckIn:D] Stopped
2017-08-31T20:47:30.363Z,1504212450.363 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:47:30.751Z,1504212450.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.920199 min 
2017-08-31T20:47:30.751Z,1504212450.751 [Default:CheckIn:E] Stopped
2017-08-31T20:47:30.751Z,1504212450.751 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:47:30.751Z,1504212450.751 [Default:CheckIn] Stopped
2017-08-31T20:47:30.751Z,1504212450.751 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:47:30.752Z,1504212450.752 [Default:CheckIn](INFO): Running loop #14
2017-08-31T20:47:30.752Z,1504212450.752 [Default:CheckIn] Running Loop=14
2017-08-31T20:47:30.752Z,1504212450.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:47:30.752Z,1504212450.752 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:47:34.116Z,1504212454.116 [NAL9602](INFO): Powering up
2017-08-31T20:47:45.298Z,1504212465.298 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:48:06.107Z,1504212486.107 [NAL9602](INFO): SBD MO Status=2, MOMSN=417, MT Status=2, MTMSN=0
2017-08-31T20:48:06.108Z,1504212486.108 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:48:25.699Z,1504212505.699 [NAL9602](INFO): SBD MO Status=0, MOMSN=417, MT Status=0, MTMSN=0
2017-08-31T20:48:25.699Z,1504212505.699 [NAL9602](INFO): No messages in MT queue
2017-08-31T20:48:25.699Z,1504212505.699 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2017-08-31T20:52:31.026Z,1504212751.026 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T20:47:30.8Z
2017-08-31T20:52:31.026Z,1504212751.026 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T20:52:31.027Z,1504212751.027 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T20:52:31.334Z,1504212751.334 [NAL9602](INFO): GPS fix at 20170831T205221: (36.802571, -121.788903)
2017-08-31T20:52:36.036Z,1504212756.036 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20170831T190218/Courier0048.lzma
2017-08-31T20:52:36.799Z,1504212756.799 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0048.lzma.bak
2017-08-31T20:52:36.800Z,1504212756.800 [DataOverHttps](INFO): SBD MOMSN=5071240
2017-08-31T20:52:41.410Z,1504212761.410 [NAL9602](INFO): Powering down
2017-08-31T20:52:45.988Z,1504212765.988 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20170831T190218/Express0049.lzma
2017-08-31T20:52:46.760Z,1504212766.760 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0049.lzma.bak
2017-08-31T20:52:46.760Z,1504212766.760 [DataOverHttps](INFO): SBD MOMSN=5071243
2017-08-31T20:52:47.253Z,1504212767.253 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T20:52:47.253Z,1504212767.253 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T20:52:47.253Z,1504212767.253 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T20:55:17.522Z,1504212917.522 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T20:57:47.944Z,1504213067.944 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T20:57:47.945Z,1504213067.945 [Default:CheckIn:C.Wait] Stopped
2017-08-31T20:57:47.951Z,1504213067.951 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T20:57:47.952Z,1504213067.952 [Default:CheckIn:D] Running Loop=1
2017-08-31T20:57:48.329Z,1504213068.329 [Default:CheckIn:D] Stopped
2017-08-31T20:57:48.329Z,1504213068.329 [Default:CheckIn:E] Running Loop=1
2017-08-31T20:57:48.739Z,1504213068.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.219637 min 
2017-08-31T20:57:48.739Z,1504213068.739 [Default:CheckIn:E] Stopped
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn] Stopped
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn](INFO): Running loop #15
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn] Running Loop=15
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T20:57:48.740Z,1504213068.740 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T20:57:52.083Z,1504213072.083 [NAL9602](INFO): Powering up
2017-08-31T20:58:03.223Z,1504213083.223 [NAL9602](INFO): NAL9602 initialized
2017-08-31T20:58:44.024Z,1504213124.024 [NAL9602](INFO): SBD MO Status=2, MOMSN=418, MT Status=2, MTMSN=0
2017-08-31T20:58:44.024Z,1504213124.024 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:58:57.938Z,1504213137.938 [NAL9602](INFO): SBD MO Status=2, MOMSN=418, MT Status=2, MTMSN=0
2017-08-31T20:58:57.939Z,1504213137.939 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:59:15.145Z,1504213155.145 [NAL9602](INFO): SBD MO Status=2, MOMSN=418, MT Status=2, MTMSN=0
2017-08-31T20:59:15.146Z,1504213155.146 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-08-31T20:59:36.744Z,1504213176.744 [NAL9602](INFO): SBD MO Status=0, MOMSN=418, MT Status=0, MTMSN=0
2017-08-31T20:59:36.744Z,1504213176.744 [NAL9602](INFO): No messages in MT queue
2017-08-31T20:59:53.028Z,1504213193.028 [PNI_TCM](ERROR): CRC does not match. Expected:0x25136 got:0x6334
2017-08-31T21:02:41.329Z,1504213361.329 [NAL9602](INFO): GPS fix at 20170831T210232: (36.802754, -121.787784)
2017-08-31T21:02:41.367Z,1504213361.367 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T21:02:41.367Z,1504213361.367 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T21:02:45.973Z,1504213365.973 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20170831T190218/Courier0052.lzma
2017-08-31T21:02:46.736Z,1504213366.736 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0052.lzma.bak
2017-08-31T21:02:46.736Z,1504213366.736 [DataOverHttps](INFO): SBD MOMSN=5071247
2017-08-31T21:02:51.310Z,1504213371.310 [NAL9602](INFO): Powering down
2017-08-31T21:02:55.931Z,1504213375.931 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20170831T190218/Express0053.lzma
2017-08-31T21:02:56.707Z,1504213376.707 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0053.lzma.bak
2017-08-31T21:02:56.708Z,1504213376.708 [DataOverHttps](INFO): SBD MOMSN=5071250
2017-08-31T21:02:57.202Z,1504213377.202 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T21:02:57.202Z,1504213377.202 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T21:02:57.203Z,1504213377.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T21:05:09.431Z,1504213509.431 [PNI_TCM](ERROR): CRC does not match. Expected:0x40104 got:0x6592
2017-08-31T21:05:09.829Z,1504213509.829 [PNI_TCM](ERROR): CRC does not match. Expected:0x9490 got:0x7490
2017-08-31T21:05:17.871Z,1504213517.871 [CBIT](DEBUG): EFC running - data check-sum false
2017-08-31T21:05:19.440Z,1504213519.440 [PNI_TCM](ERROR): CRC does not match. Expected:0x31136 got:0x5032
2017-08-31T21:05:23.835Z,1504213523.835 [PNI_TCM](ERROR): CRC does not match. Expected:0x7617 got:0x346
2017-08-31T21:05:28.637Z,1504213528.637 [PNI_TCM](ERROR): CRC does not match. Expected:0x4266 got:0x16984
2017-08-31T21:05:32.622Z,1504213532.622 [PNI_TCM](ERROR): CRC does not match. Expected:0x33553 got:0x4
2017-08-31T21:05:41.834Z,1504213541.834 [PNI_TCM](ERROR): CRC does not match. Expected:0x45015 got:0x31791
2017-08-31T21:05:45.424Z,1504213545.424 [PNI_TCM](ERROR): CRC does not match. Expected:0x23906 got:0x39552
2017-08-31T21:05:54.243Z,1504213554.243 [PNI_TCM](ERROR): CRC does not match. Expected:0x11106 got:0x16984
2017-08-31T21:07:57.615Z,1504213677.615 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-08-31T21:07:57.615Z,1504213677.615 [Default:CheckIn:C.Wait] Stopped
2017-08-31T21:07:57.615Z,1504213677.615 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T21:07:57.616Z,1504213677.616 [Default:CheckIn:D] Running Loop=1
2017-08-31T21:07:58.026Z,1504213678.026 [Default:CheckIn:D] Stopped
2017-08-31T21:07:58.026Z,1504213678.026 [Default:CheckIn:E] Running Loop=1
2017-08-31T21:07:58.416Z,1504213678.416 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.381250 min 
2017-08-31T21:07:58.416Z,1504213678.416 [Default:CheckIn:E] Stopped
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn] Stopped
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn](INFO): Running loop #16
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn] Running Loop=16
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-08-31T21:07:58.417Z,1504213678.417 [Default:CheckIn:Read_GPS] Running Loop=1
2017-08-31T21:08:02.045Z,1504213682.045 [NAL9602](INFO): Powering up
2017-08-31T21:08:12.943Z,1504213692.943 [NAL9602](INFO): NAL9602 initialized
2017-08-31T21:12:58.730Z,1504213978.730 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-08-31T21:07:58.4Z
2017-08-31T21:12:58.730Z,1504213978.730 [Default:CheckIn:Read_GPS] Stopped
2017-08-31T21:12:58.730Z,1504213978.730 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-08-31T21:13:03.405Z,1504213983.405 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170831T190218/Courier0056.lzma
2017-08-31T21:13:04.168Z,1504213984.168 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Courier0056.lzma.bak
2017-08-31T21:13:04.168Z,1504213984.168 [DataOverHttps](INFO): SBD MOMSN=5071253
2017-08-31T21:13:13.381Z,1504213993.381 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20170831T190218/Express0057.lzma
2017-08-31T21:13:14.152Z,1504213994.152 [DataOverHttps](INFO): Moved sent file to Logs/20170831T190218/Express0057.lzma.bak
2017-08-31T21:13:14.152Z,1504213994.152 [DataOverHttps](INFO): SBD MOMSN=5071255
2017-08-31T21:13:14.648Z,1504213994.648 [Default:CheckIn:Read_Iridium] Stopped
2017-08-31T21:13:14.648Z,1504213994.648 [Default:CheckIn:C.Wait] Running Loop=1
2017-08-31T21:13:14.648Z,1504213994.648 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-08-31T21:13:17.151Z,1504213997.151 [CommandLine](IMPORTANT): got command 
2017-08-31T21:13:17.151Z,1504213997.151 [CommandLine](FAULT): Incomplete syntax. Try: help
2017-08-31T21:13:18.351Z,1504213998.351 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-08-31T21:13:21.558Z,1504214001.558 [CommandLine](IMPORTANT): got command quit
2017-08-31T21:13:22.571Z,1504214002.571 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:22.571Z,1504214002.571 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:22.643Z,1504214002.643 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2017-08-31T21:13:22.643Z,1504214002.643 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:22.644Z,1504214002.644 [CommandLine](INFO): Join timeout helper Thread ID is 6552
2017-08-31T21:13:22.644Z,1504214002.644 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-08-31T21:13:22.644Z,1504214002.644 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:22.645Z,1504214002.645 [NavChartDb](INFO): Join timeout helper Thread ID is 6553
2017-08-31T21:13:22.815Z,1504214002.815 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:22.815Z,1504214002.815 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:22.823Z,1504214002.823 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-08-31T21:13:22.823Z,1504214002.823 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:22.824Z,1504214002.824 [Radio_Surface](INFO): Join timeout helper Thread ID is 6554
2017-08-31T21:13:23.148Z,1504214003.148 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:23.148Z,1504214003.148 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.152Z,1504214003.152 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-08-31T21:13:23.152Z,1504214003.152 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.152Z,1504214003.152 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6555
2017-08-31T21:13:23.388Z,1504214003.388 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:23.388Z,1504214003.388 [WetLabsBB2FL](INFO): Powering down
2017-08-31T21:13:23.389Z,1504214003.389 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.396Z,1504214003.396 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2017-08-31T21:13:23.396Z,1504214003.396 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.397Z,1504214003.397 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6556
2017-08-31T21:13:23.580Z,1504214003.580 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:23.698Z,1504214003.698 [NAL9602](INFO): Powering down
2017-08-31T21:13:23.723Z,1504214003.723 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-08-31T21:13:23.723Z,1504214003.723 [CTD_Seabird](INFO): Powering down
2017-08-31T21:13:23.724Z,1504214003.724 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.738Z,1504214003.738 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-08-31T21:13:23.738Z,1504214003.738 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.739Z,1504214003.739 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6558
2017-08-31T21:13:23.925Z,1504214003.925 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:23.926Z,1504214003.926 [CTD_NeilBrown](INFO): Powering down
2017-08-31T21:13:23.927Z,1504214003.927 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.946Z,1504214003.946 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-08-31T21:13:23.946Z,1504214003.946 [logger ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.947Z,1504214003.947 [logger](INFO): Join timeout helper Thread ID is 6559
2017-08-31T21:13:23.947Z,1504214003.947 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:23.947Z,1504214003.947 [logger ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.949Z,1504214003.949 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-08-31T21:13:23.949Z,1504214003.949 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.949Z,1504214003.949 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-08-31T21:13:23.949Z,1504214003.949 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:23.950Z,1504214003.950 [controlThread](INFO): Join timeout helper Thread ID is 6560
2017-08-31T21:13:24.069Z,1504214004.069 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-08-31T21:13:24.069Z,1504214004.069 [controlThread](DEBUG): Uninitializing ControlThread
2017-08-31T21:13:24.070Z,1504214004.070 [Aanderaa_O2](INFO): Powering down
2017-08-31T21:13:24.072Z,1504214004.072 [NAL9602](INFO): Powering down
2017-08-31T21:13:24.074Z,1504214004.074 [PNI_TCM](INFO): Powering down
2017-08-31T21:13:24.162Z,1504214004.162 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-08-31T21:13:24.163Z,1504214004.163 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-08-31T21:13:24.164Z,1504214004.164 [MissionManager](INFO): Uninitializing Mission Default
2017-08-31T21:13:24.164Z,1504214004.164 [Default] Stopped
2017-08-31T21:13:24.164Z,1504214004.164 [Default](DEBUG): Aggregate::uninitialize Default
2017-08-31T21:13:24.164Z,1504214004.164 [Default:B.GoToSurface] Stopped
2017-08-31T21:13:24.165Z,1504214004.165 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-08-31T21:13:24.165Z,1504214004.165 [Default:CheckIn] Stopped
2017-08-31T21:13:24.165Z,1504214004.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-08-31T21:13:24.165Z,1504214004.165 [Default:CheckIn:C.Wait] Stopped
2017-08-31T21:13:24.165Z,1504214004.165 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-08-31T21:13:24.168Z,1504214004.168 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-08-31T21:13:24.168Z,1504214004.168 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-08-31T21:13:24.168Z,1504214004.168 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-08-31T21:13:24.169Z,1504214004.169 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-08-31T21:13:24.169Z,1504214004.169 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-08-31T21:13:24.169Z,1504214004.169 [BuoyancyServo](INFO): Powering down
2017-08-31T21:13:24.181Z,1504214004.181 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-08-31T21:13:24.182Z,1504214004.182 [ElevatorServo](INFO): Powering down
2017-08-31T21:13:24.182Z,1504214004.182 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-08-31T21:13:24.183Z,1504214004.183 [MassServo](INFO): Powering down
2017-08-31T21:13:24.183Z,1504214004.183 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-08-31T21:13:24.184Z,1504214004.184 [RudderServo](INFO): Powering down
2017-08-31T21:13:24.184Z,1504214004.184 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-08-31T21:13:24.185Z,1504214004.185 [ThrusterServo](INFO): Powering down
2017-08-31T21:13:24.186Z,1504214004.186 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-08-31T21:13:24.186Z,1504214004.186 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-08-31T21:13:24.186Z,1504214004.186 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-08-31T21:13:24.187Z,1504214004.187 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.247Z,1504214004.247 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.251Z,1504214004.251 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.261Z,1504214004.261 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.275Z,1504214004.275 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.319Z,1504214004.319 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-08-31T21:13:24.420Z,1504214004.420 [logger ThreadHandler](INFO): Thread cancelled.