2014-05-15T21:48:36.200Z,1400190516.200 [CommandLine](IMPORTANT): got command restart logs
2014-05-15T21:48:56.683Z,1400190536.683 [NAL9602](INFO): SBD MO Status=2, MOMSN=30247, MT Status=2, MTMSN=0
2014-05-15T21:48:56.684Z,1400190536.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:49:19.477Z,1400190559.477 [NAL9602](INFO): SBD MO Status=2, MOMSN=30247, MT Status=2, MTMSN=0
2014-05-15T21:49:19.478Z,1400190559.478 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:49:20.795Z,1400190560.795 [NAL9602](IMPORTANT): GPS fix at: 1400190551.00
2014-05-15T21:49:20.833Z,1400190560.833 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 968.614, recording fix residuals...
2014-05-15T21:49:20.865Z,1400190560.865 [UniversalFixResidualReporter](DEBUG): Fix parameters were touched since the last run.
2014-05-15T21:49:20.866Z,1400190560.866 [UniversalFixResidualReporter](IMPORTANT): Fix residual: 9.2 %DT, over the last 853.1 m. Residual distance 89.1 m at bearing -28.5 degrees. Fix at (36.7981, -121.8051) with 853.1 m made good.
2014-05-15T21:49:20.873Z,1400190560.873 [Default:GPS:Read_GPS] Stopped
2014-05-15T21:49:20.873Z,1400190560.873 [Default:GPS:D] Running Loop=1
2014-05-15T21:49:21.338Z,1400190561.338 [Default:GPS:D] Stopped
2014-05-15T21:49:21.338Z,1400190561.338 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T21:49:21.338Z,1400190561.338 [Default:GPS] Stopped
2014-05-15T21:49:21.339Z,1400190561.339 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T21:49:21.339Z,1400190561.339 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T21:49:21.339Z,1400190561.339 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T21:49:33.820Z,1400190573.820 [NAL9602](INFO): SBD MO Status=2, MOMSN=30247, MT Status=2, MTMSN=0
2014-05-15T21:49:33.820Z,1400190573.820 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:49:53.068Z,1400190593.068 [NAL9602](INFO): SBD MO Status=2, MOMSN=30247, MT Status=2, MTMSN=0
2014-05-15T21:49:53.068Z,1400190593.068 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:50:21.042Z,1400190621.042 [NAL9602](INFO): SBD MO Status=1, MOMSN=30247, MT Status=0, MTMSN=0
2014-05-15T21:50:21.093Z,1400190621.093 [NAL9602](INFO): Sent 45 bytes from file Logs/20140515T180730/Courier0164.lzma
2014-05-15T21:50:21.093Z,1400190621.093 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:50:21.095Z,1400190621.095 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T180730/Courier0164.lzma.parts/0000.sbd
2014-05-15T21:50:21.096Z,1400190621.096 [NAL9602](INFO): Completed sending Logs/20140515T180730/Courier0164.lzma
2014-05-15T21:50:32.711Z,1400190632.711 [NAL9602](INFO): SBD MO Status=1, MOMSN=30248, MT Status=0, MTMSN=0
2014-05-15T21:50:32.764Z,1400190632.764 [NAL9602](INFO): Sent 195 bytes from file Logs/20140515T180730/Express0161.lzma
2014-05-15T21:50:32.765Z,1400190632.765 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:50:32.767Z,1400190632.767 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T180730/Express0161.lzma.parts/0000.sbd
2014-05-15T21:50:32.767Z,1400190632.767 [NAL9602](INFO): Completed sending Logs/20140515T180730/Express0161.lzma
2014-05-15T21:50:41.810Z,1400190641.810 [NAL9602](INFO): SBD MO Status=1, MOMSN=30249, MT Status=0, MTMSN=0
2014-05-15T21:50:41.867Z,1400190641.867 [NAL9602](INFO): Sent 140 bytes from file Logs/20140515T180730/Express0165.lzma
2014-05-15T21:50:41.867Z,1400190641.867 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:50:41.869Z,1400190641.869 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T180730/Express0165.lzma.parts/0000.sbd
2014-05-15T21:50:41.869Z,1400190641.869 [NAL9602](INFO): Completed sending Logs/20140515T180730/Express0165.lzma
2014-05-15T21:50:57.577Z,1400190657.577 [NAL9602](INFO): SBD MO Status=2, MOMSN=30250, MT Status=2, MTMSN=0
2014-05-15T21:50:57.577Z,1400190657.577 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:51:08.907Z,1400190668.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=30250, MT Status=0, MTMSN=0
2014-05-15T21:51:30.829Z,1400190690.829 [NAL9602](INFO): SBD MO Status=1, MOMSN=30251, MT Status=0, MTMSN=0
2014-05-15T21:51:30.890Z,1400190690.890 [NAL9602](INFO): Sent 297 bytes from file Logs/20140515T214836/Courier0000.lzma
2014-05-15T21:51:30.891Z,1400190690.891 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:51:30.892Z,1400190690.892 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0000.lzma.parts/0000.sbd
2014-05-15T21:51:30.893Z,1400190690.893 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0000.lzma
2014-05-15T21:51:40.923Z,1400190700.923 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:43.230Z,1400190703.230 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:45.854Z,1400190705.854 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:46.320Z,1400190706.320 [NAL9602](INFO): SBD MO Status=1, MOMSN=30252, MT Status=0, MTMSN=0
2014-05-15T21:51:46.379Z,1400190706.379 [NAL9602](INFO): Sent 332 bytes from file Logs/20140515T214836/Express0001.lzma
2014-05-15T21:51:46.379Z,1400190706.379 [NAL9602](INFO): Packets left to send: 1
2014-05-15T21:51:46.380Z,1400190706.380 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0001.lzma.parts/0001.sbd
2014-05-15T21:51:50.115Z,1400190710.115 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:52.877Z,1400190712.877 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:55.457Z,1400190715.457 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:51:57.658Z,1400190717.658 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:00.308Z,1400190720.308 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:01.211Z,1400190721.211 [NAL9602](INFO): SBD MO Status=2, MOMSN=30253, MT Status=2, MTMSN=0
2014-05-15T21:52:01.211Z,1400190721.211 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T21:52:02.616Z,1400190722.616 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:04.875Z,1400190724.875 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:09.613Z,1400190729.613 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:12.248Z,1400190732.248 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:14.506Z,1400190734.506 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:16.645Z,1400190736.645 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:19.313Z,1400190739.313 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:19.368Z,1400190739.368 [NAL9602](INFO): SBD MO Status=1, MOMSN=30253, MT Status=0, MTMSN=0
2014-05-15T21:52:19.422Z,1400190739.422 [NAL9602](INFO): Sent 285 bytes from file Logs/20140515T214836/Express0001.lzma
2014-05-15T21:52:19.422Z,1400190739.422 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:52:19.423Z,1400190739.423 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0001.lzma.parts/0000.sbd
2014-05-15T21:52:19.423Z,1400190739.423 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0001.lzma
2014-05-15T21:52:21.782Z,1400190741.782 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:23.994Z,1400190743.994 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:26.221Z,1400190746.221 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535
2014-05-15T21:52:27.109Z,1400190747.109 [NAL9602](INFO): SBD MO Status=0, MOMSN=30254, MT Status=0, MTMSN=0
2014-05-15T21:52:27.211Z,1400190747.211 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T21:52:27.212Z,1400190747.212 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T21:52:27.212Z,1400190747.212 [Default:Iridium] Stopped
2014-05-15T21:52:27.212Z,1400190747.212 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T21:52:27.212Z,1400190747.212 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T21:52:27.212Z,1400190747.212 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T21:52:27.623Z,1400190747.623 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T21:52:27.623Z,1400190747.623 [Default:CallIridium:B] Stopped
2014-05-15T21:52:27.623Z,1400190747.623 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T21:52:27.623Z,1400190747.623 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T21:52:27.624Z,1400190747.624 [Default:CallIridium] Stopped
2014-05-15T21:52:27.624Z,1400190747.624 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T21:52:37.728Z,1400190757.728 [NAL9602](INFO): Powering down
2014-05-15T21:57:27.775Z,1400191047.775 [Default:CallIridium] Running Loop=1
2014-05-15T21:57:27.775Z,1400191047.775 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T21:57:27.776Z,1400191047.776 [Default:CallIridium:A] Running Loop=1
2014-05-15T21:57:27.776Z,1400191047.776 [Default:CallIridium:A] Stopped
2014-05-15T21:57:27.776Z,1400191047.776 [Default:CallIridium:B] Running Loop=1
2014-05-15T21:57:27.776Z,1400191047.776 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T21:57:32.899Z,1400191052.899 [Default:Iridium] Running Loop=1
2014-05-15T21:57:32.900Z,1400191052.900 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T21:57:32.900Z,1400191052.900 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T21:57:32.900Z,1400191052.900 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T21:57:32.900Z,1400191052.900 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T21:57:32.900Z,1400191052.900 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T21:57:32.901Z,1400191052.901 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T21:57:32.901Z,1400191052.901 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T21:57:32.901Z,1400191052.901 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T21:57:32.901Z,1400191052.901 [Default:GPS] Running Loop=1
2014-05-15T21:57:32.901Z,1400191052.901 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T21:57:32.902Z,1400191052.902 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T21:57:32.902Z,1400191052.902 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T21:57:32.902Z,1400191052.902 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T21:57:32.902Z,1400191052.902 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T21:57:32.903Z,1400191052.903 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T21:57:32.903Z,1400191052.903 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T21:57:32.903Z,1400191052.903 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T21:57:34.010Z,1400191054.010 [NAL9602](INFO): Powering up
2014-05-15T21:57:44.711Z,1400191064.711 [NAL9602](INFO): NAL9602 initialized
2014-05-15T21:58:09.770Z,1400191089.770 [NAL9602](INFO): SBD MO Status=1, MOMSN=30255, MT Status=0, MTMSN=0
2014-05-15T21:58:09.825Z,1400191089.825 [NAL9602](INFO): Sent 47 bytes from file Logs/20140515T214836/Courier0004.lzma
2014-05-15T21:58:09.825Z,1400191089.825 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:58:09.827Z,1400191089.827 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0004.lzma.parts/0000.sbd
2014-05-15T21:58:09.827Z,1400191089.827 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0004.lzma
2014-05-15T21:58:15.013Z,1400191095.013 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46
2014-05-15T21:58:15.014Z,1400191095.014 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.2 25.8 20.0 19.3 -809.0 -316.9 725.3 185.9 -763 -360 606 255 -2047.7 -671.1 -57.9 1 2153.2 -102.7 12.0 1 -1827 -820 -70 2 1999 111 -70 2 -11.80 -1.92 159.0 19.3 14.0 0.005 35.0 1489 107
2014-05-15T21:58:22.948Z,1400191102.948 [NAL9602](INFO): SBD MO Status=1, MOMSN=30256, MT Status=0, MTMSN=0
2014-05-15T21:58:23.002Z,1400191103.002 [NAL9602](INFO): Sent 191 bytes from file Logs/20140515T214836/Express0005.lzma
2014-05-15T21:58:23.002Z,1400191103.002 [NAL9602](INFO): Packets left to send: 0
2014-05-15T21:58:23.004Z,1400191103.004 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0005.lzma.parts/0000.sbd
2014-05-15T21:58:23.004Z,1400191103.004 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0005.lzma
2014-05-15T21:58:25.778Z,1400191105.778 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-05-15T21:58:25.778Z,1400191105.778 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 39.1 26.3 31.7 0 -94.8 713.8 158.9 -470 -93 642 134 19 12 5 8 -1819.8 -338.6 34.6 1 1837.1 -217.5 72.2 1 -1484 -303 57 2 1507 -144 57  -0.68 163.0 26.3 14.0 0.005 35.0 1489 122
2014-05-15T21:58:45.650Z,1400191125.650 [NAL9602](INFO): SBD MO Status=0, MOMSN=30257, MT Status=0, MTMSN=0
2014-05-15T21:58:45.746Z,1400191125.746 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T21:58:45.747Z,1400191125.747 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T21:58:45.747Z,1400191125.747 [Default:Iridium] Stopped
2014-05-15T21:58:45.747Z,1400191125.747 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T21:58:45.747Z,1400191125.747 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T21:58:45.747Z,1400191125.747 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T21:58:46.170Z,1400191126.170 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T21:58:46.170Z,1400191126.170 [Default:CallIridium:B] Stopped
2014-05-15T21:58:46.170Z,1400191126.170 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T21:58:46.171Z,1400191126.171 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T21:58:46.171Z,1400191126.171 [Default:CallIridium] Stopped
2014-05-15T21:58:46.171Z,1400191126.171 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T21:58:47.021Z,1400191127.021 [NAL9602](IMPORTANT): GPS fix at: 1400191117.00
2014-05-15T21:58:47.034Z,1400191127.034 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 935.338, recording fix residuals...
2014-05-15T21:58:47.079Z,1400191127.079 [UniversalFixResidualReporter](DEBUG): Fix parameters were touched since the last run.
2014-05-15T21:58:47.080Z,1400191127.080 [UniversalFixResidualReporter](IMPORTANT): Fix residual: 9.2 %DT, over the last 1223.1 m. Residual distance 125.1 m at bearing -91.9 degrees. Fix at (36.8036, -121.7932) with 1223.1 m made good.
2014-05-15T21:58:47.082Z,1400191127.082 [Default:GPS:Read_GPS] Stopped
2014-05-15T21:58:47.082Z,1400191127.082 [Default:GPS:D] Running Loop=1
2014-05-15T21:58:47.529Z,1400191127.529 [Default:GPS:D] Stopped
2014-05-15T21:58:47.530Z,1400191127.530 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T21:58:47.530Z,1400191127.530 [Default:GPS] Stopped
2014-05-15T21:58:47.530Z,1400191127.530 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T21:58:47.530Z,1400191127.530 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T21:58:47.530Z,1400191127.530 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T21:59:08.142Z,1400191148.142 [NAL9602](INFO): Powering down
2014-05-15T22:03:48.143Z,1400191428.143 [Default:CallIridium] Running Loop=1
2014-05-15T22:03:48.144Z,1400191428.144 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:03:48.144Z,1400191428.144 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:03:48.144Z,1400191428.144 [Default:CallIridium:A] Stopped
2014-05-15T22:03:48.144Z,1400191428.144 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:03:48.145Z,1400191428.145 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:03:53.136Z,1400191433.136 [Default:Iridium] Running Loop=1
2014-05-15T22:03:53.136Z,1400191433.136 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:03:53.136Z,1400191433.136 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:03:53.136Z,1400191433.136 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:03:53.137Z,1400191433.137 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:03:53.137Z,1400191433.137 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:03:53.138Z,1400191433.138 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:03:53.138Z,1400191433.138 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:03:53.138Z,1400191433.138 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:03:53.138Z,1400191433.138 [Default:GPS] Running Loop=1
2014-05-15T22:03:53.138Z,1400191433.138 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:03:53.138Z,1400191433.138 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:03:53.138Z,1400191433.138 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:03:53.139Z,1400191433.139 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:03:53.139Z,1400191433.139 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:03:53.139Z,1400191433.139 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:03:53.139Z,1400191433.139 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:03:53.140Z,1400191433.140 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:03:54.289Z,1400191434.289 [NAL9602](INFO): Powering up
2014-05-15T22:04:04.948Z,1400191444.948 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:04:24.300Z,1400191464.300 [NAL9602](INFO): SBD MO Status=1, MOMSN=30258, MT Status=0, MTMSN=0
2014-05-15T22:04:24.359Z,1400191464.359 [NAL9602](INFO): Sent 78 bytes from file Logs/20140515T214836/Courier0008.lzma
2014-05-15T22:04:24.359Z,1400191464.359 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:04:24.360Z,1400191464.360 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0008.lzma.parts/0000.sbd
2014-05-15T22:04:24.361Z,1400191464.361 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0008.lzma
2014-05-15T22:04:43.700Z,1400191483.700 [NAL9602](INFO): SBD MO Status=2, MOMSN=30259, MT Status=2, MTMSN=0
2014-05-15T22:04:43.700Z,1400191483.700 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:05:09.886Z,1400191509.886 [NAL9602](INFO): SBD MO Status=2, MOMSN=30259, MT Status=2, MTMSN=0
2014-05-15T22:05:09.887Z,1400191509.887 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:05:11.191Z,1400191511.191 [NAL9602](IMPORTANT): GPS fix at: 1400191502.00
2014-05-15T22:05:11.204Z,1400191511.204 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 545.587, recording fix residuals...
2014-05-15T22:05:11.217Z,1400191511.217 [UniversalFixResidualReporter](DEBUG): Fix parameters were touched since the last run.
2014-05-15T22:05:11.218Z,1400191511.218 [UniversalFixResidualReporter](IMPORTANT): Fix residual: 21.6 %DT, over the last 541.2 m. Residual distance 117.8 m at bearing -133.2 degrees. Fix at (36.8073, -121.7892) with 541.2 m made good.
2014-05-15T22:05:11.221Z,1400191511.221 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:05:11.221Z,1400191511.221 [Default:GPS:D] Running Loop=1
2014-05-15T22:05:11.703Z,1400191511.703 [Default:GPS:D] Stopped
2014-05-15T22:05:11.704Z,1400191511.704 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:05:11.704Z,1400191511.704 [Default:GPS] Stopped
2014-05-15T22:05:11.704Z,1400191511.704 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:05:11.704Z,1400191511.704 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:05:11.704Z,1400191511.704 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:05:38.290Z,1400191538.290 [NAL9602](INFO): SBD MO Status=1, MOMSN=30259, MT Status=0, MTMSN=0
2014-05-15T22:05:38.340Z,1400191538.340 [NAL9602](INFO): Sent 332 bytes from file Logs/20140515T214836/Express0009.lzma
2014-05-15T22:05:38.341Z,1400191538.341 [NAL9602](INFO): Packets left to send: 1
2014-05-15T22:05:38.342Z,1400191538.342 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0009.lzma.parts/0001.sbd
2014-05-15T22:05:51.899Z,1400191551.899 [NAL9602](INFO): SBD MO Status=1, MOMSN=30260, MT Status=0, MTMSN=0
2014-05-15T22:05:51.959Z,1400191551.959 [NAL9602](INFO): Sent 110 bytes from file Logs/20140515T214836/Express0009.lzma
2014-05-15T22:05:51.959Z,1400191551.959 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:05:51.960Z,1400191551.960 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0009.lzma.parts/0000.sbd
2014-05-15T22:05:51.961Z,1400191551.961 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0009.lzma
2014-05-15T22:06:08.119Z,1400191568.119 [NAL9602](INFO): SBD MO Status=2, MOMSN=30261, MT Status=2, MTMSN=0
2014-05-15T22:06:08.119Z,1400191568.119 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:06:13.550Z,1400191573.550 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:06:16.501Z,1400191576.501 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:06:39.355Z,1400191599.355 [NAL9602](INFO): SBD MO Status=2, MOMSN=30261, MT Status=2, MTMSN=0
2014-05-15T22:06:39.355Z,1400191599.355 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:06:44.825Z,1400191604.825 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:06:47.809Z,1400191607.809 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:07:11.808Z,1400191631.808 [NAL9602](INFO): SBD MO Status=2, MOMSN=30261, MT Status=2, MTMSN=0
2014-05-15T22:07:11.808Z,1400191631.808 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:07:17.332Z,1400191637.332 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:07:20.557Z,1400191640.557 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:07:31.413Z,1400191651.413 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2014-05-15T22:07:45.987Z,1400191665.987 [NAL9602](INFO): SBD MO Status=0, MOMSN=30261, MT Status=0, MTMSN=0
2014-05-15T22:07:46.273Z,1400191666.273 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:07:46.273Z,1400191666.273 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:07:46.274Z,1400191666.274 [Default:Iridium] Stopped
2014-05-15T22:07:46.274Z,1400191666.274 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:07:46.274Z,1400191666.274 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:07:46.274Z,1400191666.274 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:07:46.681Z,1400191666.681 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:07:46.681Z,1400191666.681 [Default:CallIridium:B] Stopped
2014-05-15T22:07:46.681Z,1400191666.681 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:07:46.681Z,1400191666.681 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:07:46.681Z,1400191666.681 [Default:CallIridium] Stopped
2014-05-15T22:07:46.682Z,1400191666.682 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:07:56.815Z,1400191676.815 [NAL9602](INFO): Powering down
2014-05-15T22:12:46.854Z,1400191966.854 [Default:CallIridium] Running Loop=1
2014-05-15T22:12:46.854Z,1400191966.854 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:12:46.855Z,1400191966.855 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:12:46.855Z,1400191966.855 [Default:CallIridium:A] Stopped
2014-05-15T22:12:46.855Z,1400191966.855 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:12:46.855Z,1400191966.855 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium] Running Loop=1
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:12:51.863Z,1400191971.863 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:12:51.864Z,1400191971.864 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:12:51.864Z,1400191971.864 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:12:51.864Z,1400191971.864 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS] Running Loop=1
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:12:51.865Z,1400191971.865 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:12:51.866Z,1400191971.866 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:12:51.866Z,1400191971.866 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:12:51.866Z,1400191971.866 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:12:52.924Z,1400191972.924 [NAL9602](INFO): Powering up
2014-05-15T22:13:03.515Z,1400191983.515 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:13:23.979Z,1400192003.979 [NAL9602](INFO): SBD MO Status=1, MOMSN=30262, MT Status=0, MTMSN=0
2014-05-15T22:13:24.038Z,1400192004.038 [NAL9602](INFO): Sent 76 bytes from file Logs/20140515T214836/Courier0012.lzma
2014-05-15T22:13:24.039Z,1400192004.039 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:13:24.040Z,1400192004.040 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0012.lzma.parts/0000.sbd
2014-05-15T22:13:24.041Z,1400192004.041 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0012.lzma
2014-05-15T22:13:34.894Z,1400192014.894 [NAL9602](INFO): SBD MO Status=1, MOMSN=30263, MT Status=0, MTMSN=0
2014-05-15T22:13:34.952Z,1400192014.952 [NAL9602](INFO): Sent 332 bytes from file Logs/20140515T214836/Express0013.lzma
2014-05-15T22:13:34.952Z,1400192014.952 [NAL9602](INFO): Packets left to send: 1
2014-05-15T22:13:34.956Z,1400192014.956 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0013.lzma.parts/0001.sbd
2014-05-15T22:13:42.747Z,1400192022.747 [NAL9602](INFO): SBD MO Status=1, MOMSN=30264, MT Status=0, MTMSN=0
2014-05-15T22:13:42.804Z,1400192022.804 [NAL9602](INFO): Sent 6 bytes from file Logs/20140515T214836/Express0013.lzma
2014-05-15T22:13:42.804Z,1400192022.804 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:13:42.805Z,1400192022.805 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0013.lzma.parts/0000.sbd
2014-05-15T22:13:42.805Z,1400192022.805 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0013.lzma
2014-05-15T22:13:49.567Z,1400192029.567 [NAL9602](INFO): SBD MO Status=0, MOMSN=30265, MT Status=0, MTMSN=0
2014-05-15T22:13:49.669Z,1400192029.669 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:13:49.670Z,1400192029.670 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:13:49.670Z,1400192029.670 [Default:Iridium] Stopped
2014-05-15T22:13:49.670Z,1400192029.670 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:13:49.670Z,1400192029.670 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:13:49.670Z,1400192029.670 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:13:50.170Z,1400192030.170 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:13:50.170Z,1400192030.170 [Default:CallIridium:B] Stopped
2014-05-15T22:13:50.171Z,1400192030.171 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:13:50.171Z,1400192030.171 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:13:50.171Z,1400192030.171 [Default:CallIridium] Stopped
2014-05-15T22:13:50.171Z,1400192030.171 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:13:51.054Z,1400192031.054 [NAL9602](IMPORTANT): GPS fix at: 1400192022.00
2014-05-15T22:13:51.067Z,1400192031.067 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 817.23, recording fix residuals...
2014-05-15T22:13:51.079Z,1400192031.079 [UniversalFixResidualReporter](DEBUG): Fix parameters were touched since the last run.
2014-05-15T22:13:51.080Z,1400192031.080 [UniversalFixResidualReporter](IMPORTANT): Fix residual: 5.9 %DT, over the last 431.9 m. Residual distance 48.0 m at bearing -90.7 degrees. Fix at (36.8044, -121.7860) with 431.9 m made good.
2014-05-15T22:13:51.082Z,1400192031.082 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:13:51.082Z,1400192031.082 [Default:GPS:D] Running Loop=1
2014-05-15T22:13:51.554Z,1400192031.554 [Default:GPS:D] Stopped
2014-05-15T22:13:51.555Z,1400192031.555 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:13:51.555Z,1400192031.555 [Default:GPS] Stopped
2014-05-15T22:13:51.555Z,1400192031.555 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:13:51.555Z,1400192031.555 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:13:51.555Z,1400192031.555 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:14:12.143Z,1400192052.143 [NAL9602](INFO): Powering down
2014-05-15T22:18:52.143Z,1400192332.143 [Default:CallIridium] Running Loop=1
2014-05-15T22:18:52.144Z,1400192332.144 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:18:52.144Z,1400192332.144 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:18:52.144Z,1400192332.144 [Default:CallIridium:A] Stopped
2014-05-15T22:18:52.144Z,1400192332.144 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:18:52.145Z,1400192332.145 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:18:57.173Z,1400192337.173 [Default:Iridium] Running Loop=1
2014-05-15T22:18:57.173Z,1400192337.173 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:18:57.174Z,1400192337.174 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:18:57.174Z,1400192337.174 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:18:57.174Z,1400192337.174 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:18:57.174Z,1400192337.174 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:18:57.175Z,1400192337.175 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:18:57.175Z,1400192337.175 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:18:57.175Z,1400192337.175 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS] Running Loop=1
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:18:57.176Z,1400192337.176 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:18:57.177Z,1400192337.177 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:18:57.177Z,1400192337.177 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:18:57.177Z,1400192337.177 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:18:58.454Z,1400192338.454 [NAL9602](INFO): Powering up
2014-05-15T22:19:09.455Z,1400192349.455 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:19:28.815Z,1400192368.815 [NAL9602](INFO): SBD MO Status=1, MOMSN=30266, MT Status=0, MTMSN=0
2014-05-15T22:19:28.864Z,1400192368.864 [NAL9602](INFO): Sent 75 bytes from file Logs/20140515T214836/Courier0016.lzma
2014-05-15T22:19:28.864Z,1400192368.864 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:19:28.866Z,1400192368.866 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0016.lzma.parts/0000.sbd
2014-05-15T22:19:28.866Z,1400192368.866 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0016.lzma
2014-05-15T22:19:39.439Z,1400192379.439 [NAL9602](INFO): SBD MO Status=1, MOMSN=30267, MT Status=0, MTMSN=0
2014-05-15T22:19:39.489Z,1400192379.489 [NAL9602](INFO): Sent 332 bytes from file Logs/20140515T214836/Express0017.lzma
2014-05-15T22:19:39.489Z,1400192379.489 [NAL9602](INFO): Packets left to send: 1
2014-05-15T22:19:39.490Z,1400192379.490 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0017.lzma.parts/0001.sbd
2014-05-15T22:19:48.113Z,1400192388.113 [NAL9602](INFO): SBD MO Status=1, MOMSN=30268, MT Status=0, MTMSN=0
2014-05-15T22:19:48.170Z,1400192388.170 [NAL9602](INFO): Sent 128 bytes from file Logs/20140515T214836/Express0017.lzma
2014-05-15T22:19:48.170Z,1400192388.170 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:19:48.171Z,1400192388.171 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0017.lzma.parts/0000.sbd
2014-05-15T22:19:48.172Z,1400192388.172 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0017.lzma
2014-05-15T22:19:55.859Z,1400192395.859 [NAL9602](INFO): SBD MO Status=0, MOMSN=30269, MT Status=0, MTMSN=0
2014-05-15T22:19:55.968Z,1400192395.968 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:19:55.968Z,1400192395.968 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:19:55.968Z,1400192395.968 [Default:Iridium] Stopped
2014-05-15T22:19:55.969Z,1400192395.969 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:19:55.969Z,1400192395.969 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:19:55.969Z,1400192395.969 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium:B] Stopped
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium] Stopped
2014-05-15T22:19:56.430Z,1400192396.430 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:19:57.279Z,1400192397.279 [NAL9602](IMPORTANT): GPS fix at: 1400192388.00
2014-05-15T22:19:57.330Z,1400192397.330 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:19:57.330Z,1400192397.330 [Default:GPS:D] Running Loop=1
2014-05-15T22:19:57.845Z,1400192397.845 [Default:GPS:D] Stopped
2014-05-15T22:19:57.846Z,1400192397.846 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:19:57.846Z,1400192397.846 [Default:GPS] Stopped
2014-05-15T22:19:57.846Z,1400192397.846 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:19:57.846Z,1400192397.846 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:19:57.846Z,1400192397.846 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:20:13.383Z,1400192413.383 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:20:13.383Z,1400192413.383 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:20:13.383Z,1400192413.383 [DVL_micro](ERROR): Data Fault
2014-05-15T22:20:13.416Z,1400192413.416 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:20:18.390Z,1400192418.390 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:20:18.392Z,1400192418.392 [NAL9602](INFO): Powering down
2014-05-15T22:20:23.318Z,1400192423.318 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:20:23.318Z,1400192423.318 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:20:23.318Z,1400192423.318 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:20:28.416Z,1400192428.416 [DVL_micro](INFO): Initializing
2014-05-15T22:20:28.470Z,1400192428.470 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:20:28.470Z,1400192428.470 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:23:48.391Z,1400192628.391 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:23:48.391Z,1400192628.391 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:23:48.391Z,1400192628.391 [DVL_micro](ERROR): Data Fault
2014-05-15T22:23:48.480Z,1400192628.480 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:23:53.372Z,1400192633.372 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:23:58.399Z,1400192638.399 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:23:58.399Z,1400192638.399 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:23:58.399Z,1400192638.399 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:24:03.374Z,1400192643.374 [DVL_micro](INFO): Initializing
2014-05-15T22:24:03.429Z,1400192643.429 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:24:03.430Z,1400192643.430 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:24:58.429Z,1400192698.429 [Default:CallIridium] Running Loop=1
2014-05-15T22:24:58.429Z,1400192698.429 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:24:58.430Z,1400192698.430 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:24:58.430Z,1400192698.430 [Default:CallIridium:A] Stopped
2014-05-15T22:24:58.430Z,1400192698.430 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:24:58.430Z,1400192698.430 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium] Running Loop=1
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:25:03.469Z,1400192703.469 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:25:03.470Z,1400192703.470 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:25:03.470Z,1400192703.470 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:25:03.470Z,1400192703.470 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS] Running Loop=1
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:25:03.471Z,1400192703.471 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:25:03.472Z,1400192703.472 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:25:03.472Z,1400192703.472 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:25:03.472Z,1400192703.472 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:25:04.511Z,1400192704.511 [NAL9602](INFO): Powering up
2014-05-15T22:25:15.393Z,1400192715.393 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:25:58.647Z,1400192758.647 [NAL9602](INFO): SBD MO Status=2, MOMSN=30270, MT Status=0, MTMSN=0
2014-05-15T22:25:58.648Z,1400192758.648 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:25:59.995Z,1400192759.995 [NAL9602](IMPORTANT): GPS fix at: 1400192750.00
2014-05-15T22:26:00.045Z,1400192760.045 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:26:00.046Z,1400192760.046 [Default:GPS:D] Running Loop=1
2014-05-15T22:26:00.555Z,1400192760.555 [Default:GPS:D] Stopped
2014-05-15T22:26:00.555Z,1400192760.555 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:26:00.555Z,1400192760.555 [Default:GPS] Stopped
2014-05-15T22:26:00.555Z,1400192760.555 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:26:00.555Z,1400192760.555 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:26:00.556Z,1400192760.556 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:26:17.813Z,1400192777.813 [NAL9602](INFO): SBD MO Status=1, MOMSN=30270, MT Status=0, MTMSN=0
2014-05-15T22:26:17.862Z,1400192777.862 [NAL9602](INFO): Sent 76 bytes from file Logs/20140515T214836/Courier0020.lzma
2014-05-15T22:26:17.862Z,1400192777.862 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:26:17.864Z,1400192777.864 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0020.lzma.parts/0000.sbd
2014-05-15T22:26:17.864Z,1400192777.864 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0020.lzma
2014-05-15T22:26:28.082Z,1400192788.082 [NAL9602](INFO): SBD MO Status=1, MOMSN=30271, MT Status=0, MTMSN=0
2014-05-15T22:26:28.139Z,1400192788.139 [NAL9602](INFO): Sent 273 bytes from file Logs/20140515T214836/Express0021.lzma
2014-05-15T22:26:28.139Z,1400192788.139 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:26:28.141Z,1400192788.141 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0021.lzma.parts/0000.sbd
2014-05-15T22:26:28.141Z,1400192788.141 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0021.lzma
2014-05-15T22:26:43.393Z,1400192803.393 [NAL9602](INFO): SBD MO Status=0, MOMSN=30272, MT Status=0, MTMSN=0
2014-05-15T22:26:43.502Z,1400192803.502 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:26:43.503Z,1400192803.503 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:26:43.503Z,1400192803.503 [Default:Iridium] Stopped
2014-05-15T22:26:43.503Z,1400192803.503 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:26:43.503Z,1400192803.503 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:26:43.503Z,1400192803.503 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:26:43.938Z,1400192803.938 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:26:43.938Z,1400192803.938 [Default:CallIridium:B] Stopped
2014-05-15T22:26:43.938Z,1400192803.938 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:26:43.939Z,1400192803.939 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:26:43.939Z,1400192803.939 [Default:CallIridium] Stopped
2014-05-15T22:26:43.939Z,1400192803.939 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:26:54.080Z,1400192814.080 [NAL9602](INFO): Powering down
2014-05-15T22:27:29.058Z,1400192849.058 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:27:29.058Z,1400192849.058 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:27:29.058Z,1400192849.058 [DVL_micro](ERROR): Data Fault
2014-05-15T22:27:29.128Z,1400192849.128 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:27:34.084Z,1400192854.084 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:27:39.057Z,1400192859.057 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:27:39.057Z,1400192859.057 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:27:39.057Z,1400192859.057 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:27:44.142Z,1400192864.142 [DVL_micro](INFO): Initializing
2014-05-15T22:27:44.174Z,1400192864.174 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:27:44.174Z,1400192864.174 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:31:14.043Z,1400193074.043 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:31:14.044Z,1400193074.044 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:31:14.044Z,1400193074.044 [DVL_micro](ERROR): Data Fault
2014-05-15T22:31:14.122Z,1400193074.122 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:31:19.063Z,1400193079.063 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:31:24.078Z,1400193084.078 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:31:24.078Z,1400193084.078 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:31:24.079Z,1400193084.079 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:31:29.092Z,1400193089.092 [DVL_micro](INFO): Initializing
2014-05-15T22:31:29.139Z,1400193089.139 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:31:29.139Z,1400193089.139 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:31:44.134Z,1400193104.134 [Default:CallIridium] Running Loop=1
2014-05-15T22:31:44.134Z,1400193104.134 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:31:44.135Z,1400193104.135 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:31:44.135Z,1400193104.135 [Default:CallIridium:A] Stopped
2014-05-15T22:31:44.135Z,1400193104.135 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:31:44.135Z,1400193104.135 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:31:49.097Z,1400193109.097 [Default:Iridium] Running Loop=1
2014-05-15T22:31:49.097Z,1400193109.097 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:31:49.097Z,1400193109.097 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:31:49.097Z,1400193109.097 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:31:49.098Z,1400193109.098 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:31:49.098Z,1400193109.098 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:31:49.098Z,1400193109.098 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:31:49.098Z,1400193109.098 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:31:49.099Z,1400193109.099 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:31:49.099Z,1400193109.099 [Default:GPS] Running Loop=1
2014-05-15T22:31:49.099Z,1400193109.099 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:31:49.099Z,1400193109.099 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:31:49.099Z,1400193109.099 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:31:49.100Z,1400193109.100 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:31:49.100Z,1400193109.100 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:31:49.100Z,1400193109.100 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:31:49.100Z,1400193109.100 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:31:49.101Z,1400193109.101 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:31:50.123Z,1400193110.123 [NAL9602](INFO): Powering up
2014-05-15T22:32:00.758Z,1400193120.758 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:32:20.965Z,1400193140.965 [NAL9602](INFO): SBD MO Status=1, MOMSN=30273, MT Status=0, MTMSN=0
2014-05-15T22:32:21.021Z,1400193141.021 [NAL9602](INFO): Sent 76 bytes from file Logs/20140515T214836/Courier0024.lzma
2014-05-15T22:32:21.021Z,1400193141.021 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:32:21.697Z,1400193141.697 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0024.lzma.parts/0000.sbd
2014-05-15T22:32:21.697Z,1400193141.697 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0024.lzma
2014-05-15T22:32:47.414Z,1400193167.414 [NAL9602](INFO): SBD MO Status=2, MOMSN=30274, MT Status=0, MTMSN=0
2014-05-15T22:32:47.414Z,1400193167.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:33:09.736Z,1400193189.736 [NAL9602](INFO): SBD MO Status=1, MOMSN=30274, MT Status=0, MTMSN=0
2014-05-15T22:33:09.785Z,1400193189.785 [NAL9602](INFO): Sent 236 bytes from file Logs/20140515T214836/Express0025.lzma
2014-05-15T22:33:09.785Z,1400193189.785 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:33:09.787Z,1400193189.787 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0025.lzma.parts/0000.sbd
2014-05-15T22:33:09.787Z,1400193189.787 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0025.lzma
2014-05-15T22:34:14.063Z,1400193254.063 [NAL9602](INFO): SBD MO Status=2, MOMSN=30275, MT Status=2, MTMSN=0
2014-05-15T22:34:14.064Z,1400193254.064 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:34:27.388Z,1400193267.388 [NAL9602](INFO): SBD MO Status=0, MOMSN=30275, MT Status=0, MTMSN=0
2014-05-15T22:34:27.494Z,1400193267.494 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:34:27.494Z,1400193267.494 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:34:27.495Z,1400193267.495 [Default:Iridium] Stopped
2014-05-15T22:34:27.495Z,1400193267.495 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:34:27.495Z,1400193267.495 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:34:27.495Z,1400193267.495 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:34:27.912Z,1400193267.912 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:34:27.912Z,1400193267.912 [Default:CallIridium:B] Stopped
2014-05-15T22:34:27.912Z,1400193267.912 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:34:27.913Z,1400193267.913 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:34:27.913Z,1400193267.913 [Default:CallIridium] Stopped
2014-05-15T22:34:27.913Z,1400193267.913 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:34:43.217Z,1400193283.217 [NAL9602](IMPORTANT): GPS fix at: 1400193274.00
2014-05-15T22:34:43.248Z,1400193283.248 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:34:43.248Z,1400193283.248 [Default:GPS:D] Running Loop=1
2014-05-15T22:34:43.799Z,1400193283.799 [Default:GPS:D] Stopped
2014-05-15T22:34:43.799Z,1400193283.799 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:34:43.799Z,1400193283.799 [Default:GPS] Stopped
2014-05-15T22:34:43.799Z,1400193283.799 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:34:43.800Z,1400193283.800 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:34:43.800Z,1400193283.800 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:34:49.390Z,1400193289.390 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:34:49.390Z,1400193289.390 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:34:49.390Z,1400193289.390 [DVL_micro](ERROR): Data Fault
2014-05-15T22:34:49.449Z,1400193289.449 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:34:54.349Z,1400193294.349 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:34:59.336Z,1400193299.336 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:34:59.336Z,1400193299.336 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:34:59.336Z,1400193299.336 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:35:04.297Z,1400193304.297 [DVL_micro](INFO): Initializing
2014-05-15T22:35:04.299Z,1400193304.299 [NAL9602](INFO): Powering down
2014-05-15T22:35:04.352Z,1400193304.352 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:35:04.352Z,1400193304.352 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:38:34.326Z,1400193514.326 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:38:34.326Z,1400193514.326 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:38:34.326Z,1400193514.326 [DVL_micro](ERROR): Data Fault
2014-05-15T22:38:34.358Z,1400193514.358 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:38:39.350Z,1400193519.350 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:38:44.319Z,1400193524.319 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:38:44.319Z,1400193524.319 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:38:44.319Z,1400193524.319 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:38:49.423Z,1400193529.423 [DVL_micro](INFO): Initializing
2014-05-15T22:38:49.455Z,1400193529.455 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:38:49.455Z,1400193529.455 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:39:29.423Z,1400193569.423 [Default:CallIridium] Running Loop=1
2014-05-15T22:39:29.423Z,1400193569.423 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:39:29.423Z,1400193569.423 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:39:29.424Z,1400193569.424 [Default:CallIridium:A] Stopped
2014-05-15T22:39:29.424Z,1400193569.424 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:39:29.424Z,1400193569.424 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium] Running Loop=1
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:39:34.366Z,1400193574.366 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:39:34.367Z,1400193574.367 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:39:34.367Z,1400193574.367 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:39:34.367Z,1400193574.367 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS] Running Loop=1
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:39:34.368Z,1400193574.368 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:39:34.369Z,1400193574.369 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:39:34.369Z,1400193574.369 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:39:34.369Z,1400193574.369 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:39:35.395Z,1400193575.395 [NAL9602](INFO): Powering up
2014-05-15T22:39:46.188Z,1400193586.188 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:40:04.476Z,1400193604.476 [NAL9602](INFO): SBD MO Status=1, MOMSN=30276, MT Status=0, MTMSN=0
2014-05-15T22:40:04.528Z,1400193604.528 [NAL9602](INFO): Sent 76 bytes from file Logs/20140515T214836/Courier0028.lzma
2014-05-15T22:40:04.528Z,1400193604.528 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:40:04.530Z,1400193604.530 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Courier0028.lzma.parts/0000.sbd
2014-05-15T22:40:04.530Z,1400193604.530 [NAL9602](INFO): Completed sending Logs/20140515T214836/Courier0028.lzma
2014-05-15T22:40:04.964Z,1400193604.964 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 29 of 46
2014-05-15T22:40:04.965Z,1400193604.965 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -671 -815 -870 -770 2 2 2 2 26-3.0 18.2 0.005 35.0 1489 77
2014-05-15T22:40:14.887Z,1400193614.887 [NAL9602](INFO): SBD MO Status=1, MOMSN=30277, MT Status=0, MTMSN=0
2014-05-15T22:40:14.936Z,1400193614.936 [NAL9602](INFO): Sent 276 bytes from file Logs/20140515T214836/Express0029.lzma
2014-05-15T22:40:14.936Z,1400193614.936 [NAL9602](INFO): Packets left to send: 0
2014-05-15T22:40:14.938Z,1400193614.938 [NAL9602](INFO): Stored copy of sent data in Logs/20140515T214836/Express0029.lzma.parts/0000.sbd
2014-05-15T22:40:14.938Z,1400193614.938 [NAL9602](INFO): Completed sending Logs/20140515T214836/Express0029.lzma
2014-05-15T22:40:26.382Z,1400193626.382 [NAL9602](INFO): SBD MO Status=0, MOMSN=30278, MT Status=0, MTMSN=0
2014-05-15T22:40:26.476Z,1400193626.476 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:40:26.477Z,1400193626.477 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-15T22:40:26.477Z,1400193626.477 [Default:Iridium] Stopped
2014-05-15T22:40:26.477Z,1400193626.477 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:40:26.477Z,1400193626.477 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:40:26.477Z,1400193626.477 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium:B] Stopped
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium] Stopped
2014-05-15T22:40:26.913Z,1400193626.913 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:41:36.388Z,1400193696.388 [NAL9602](IMPORTANT): GPS fix at: 1400193688.00
2014-05-15T22:41:36.440Z,1400193696.440 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:41:36.440Z,1400193696.440 [Default:GPS:D] Running Loop=1
2014-05-15T22:41:36.879Z,1400193696.879 [Default:GPS:D] Stopped
2014-05-15T22:41:36.879Z,1400193696.879 [Default:GPS](INFO): Completed Default:GPS
2014-05-15T22:41:36.879Z,1400193696.879 [Default:GPS] Stopped
2014-05-15T22:41:36.880Z,1400193696.880 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:41:36.880Z,1400193696.880 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:41:36.880Z,1400193696.880 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:41:57.485Z,1400193717.485 [NAL9602](INFO): Powering down
2014-05-15T22:42:17.432Z,1400193737.432 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:42:17.432Z,1400193737.432 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:42:17.432Z,1400193737.432 [DVL_micro](ERROR): Data Fault
2014-05-15T22:42:17.464Z,1400193737.464 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:42:22.411Z,1400193742.411 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:42:27.423Z,1400193747.423 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:42:27.423Z,1400193747.423 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:42:27.423Z,1400193747.423 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:42:32.414Z,1400193752.414 [DVL_micro](INFO): Initializing
2014-05-15T22:42:32.470Z,1400193752.470 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:42:32.470Z,1400193752.470 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:45:27.456Z,1400193927.456 [Default:CallIridium] Running Loop=1
2014-05-15T22:45:27.484Z,1400193927.484 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-15T22:45:27.485Z,1400193927.485 [Default:CallIridium:A] Running Loop=1
2014-05-15T22:45:27.485Z,1400193927.485 [Default:CallIridium:A] Stopped
2014-05-15T22:45:27.485Z,1400193927.485 [Default:CallIridium:B] Running Loop=1
2014-05-15T22:45:27.486Z,1400193927.486 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium] Running Loop=1
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-15T22:45:32.478Z,1400193932.478 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:45:32.479Z,1400193932.479 [Default:Iridium:B.GoToSurface] Stopped
2014-05-15T22:45:32.479Z,1400193932.479 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:45:32.479Z,1400193932.479 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-15T22:45:32.479Z,1400193932.479 [Default:GPS] Running Loop=1
2014-05-15T22:45:32.480Z,1400193932.480 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-15T22:45:32.480Z,1400193932.480 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-15T22:45:32.484Z,1400193932.484 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-15T22:45:32.484Z,1400193932.484 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-15T22:45:32.484Z,1400193932.484 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-15T22:45:32.485Z,1400193932.485 [Default:GPS:B.GoToSurface] Stopped
2014-05-15T22:45:32.485Z,1400193932.485 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:45:32.485Z,1400193932.485 [Default:GPS:Read_GPS] Running Loop=1
2014-05-15T22:45:33.520Z,1400193933.520 [NAL9602](INFO): Powering up
2014-05-15T22:45:44.351Z,1400193944.351 [NAL9602](INFO): NAL9602 initialized
2014-05-15T22:45:53.405Z,1400193953.405 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:45:53.406Z,1400193953.406 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:45:53.406Z,1400193953.406 [DVL_micro](ERROR): Data Fault
2014-05-15T22:45:53.458Z,1400193953.458 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:45:53.815Z,1400193953.815 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:45:54.259Z,1400193954.259 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:45:54.259Z,1400193954.259 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:45:54.259Z,1400193954.259 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:45:54.705Z,1400193954.705 [DVL_micro](INFO): Initializing
2014-05-15T22:45:54.783Z,1400193954.783 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:45:54.783Z,1400193954.783 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:48:59.150Z,1400194139.150 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-05-15T22:48:59.150Z,1400194139.150 [DVL_micro] Data Fault, FailCount= 1
2014-05-15T22:48:59.150Z,1400194139.150 [DVL_micro](ERROR): Data Fault
2014-05-15T22:48:59.211Z,1400194139.211 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-05-15T22:48:59.575Z,1400194139.575 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:48:59.991Z,1400194139.991 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-05-15T22:48:59.991Z,1400194139.991 [DVL_micro] Hardware Fault, FailCount= 1
2014-05-15T22:48:59.991Z,1400194139.991 [DVL_micro](ERROR): Hardware Fault
2014-05-15T22:49:00.410Z,1400194140.410 [DVL_micro](INFO): Initializing
2014-05-15T22:49:00.473Z,1400194140.473 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-05-15T22:49:00.473Z,1400194140.473 [DVL_micro] No Fault, FailCount= 1
2014-05-15T22:49:13.777Z,1400194153.777 [CommandLine](IMPORTANT): got command quit
2014-05-15T22:49:14.784Z,1400194154.784 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:14.784Z,1400194154.784 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:14.877Z,1400194154.877 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-05-15T22:49:14.877Z,1400194154.877 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:14.878Z,1400194154.878 [CommandLine](INFO): Join timeout helper Thread ID is 9518
2014-05-15T22:49:14.879Z,1400194154.879 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-15T22:49:14.879Z,1400194154.879 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:14.880Z,1400194154.880 [NavChartDb](INFO): Join timeout helper Thread ID is 9519
2014-05-15T22:49:15.070Z,1400194155.070 [NAL9602](INFO): SBD MO Status=2, MOMSN=30279, MT Status=2, MTMSN=0
2014-05-15T22:49:15.070Z,1400194155.070 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-15T22:49:15.238Z,1400194155.238 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:15.239Z,1400194155.239 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.245Z,1400194155.245 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-15T22:49:15.245Z,1400194155.245 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.246Z,1400194155.246 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9520
2014-05-15T22:49:15.526Z,1400194155.526 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:15.526Z,1400194155.526 [WetLabsBB2FL](INFO): Powering down
2014-05-15T22:49:15.527Z,1400194155.527 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.528Z,1400194155.528 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-15T22:49:15.528Z,1400194155.528 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.528Z,1400194155.528 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 9521
2014-05-15T22:49:15.895Z,1400194155.895 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:15.895Z,1400194155.895 [CTD_NeilBrown](INFO): Powering down
2014-05-15T22:49:15.895Z,1400194155.895 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.906Z,1400194155.906 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-05-15T22:49:15.907Z,1400194155.907 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.907Z,1400194155.907 [AsyncPiEstimator](INFO): Join timeout helper Thread ID is 9522
2014-05-15T22:49:15.943Z,1400194155.943 [AsyncPiEstimator ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:15.943Z,1400194155.943 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-05-15T22:49:15.943Z,1400194155.943 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.945Z,1400194155.945 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-15T22:49:15.945Z,1400194155.945 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:15.945Z,1400194155.945 [Radio_Freewave](INFO): Join timeout helper Thread ID is 9523
2014-05-15T22:49:16.163Z,1400194156.163 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:16.281Z,1400194156.281 [Radio_Freewave](INFO): Powering down
2014-05-15T22:49:16.684Z,1400194156.684 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.692Z,1400194156.692 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-15T22:49:16.693Z,1400194156.693 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.693Z,1400194156.693 [logger](INFO): Join timeout helper Thread ID is 9525
2014-05-15T22:49:16.720Z,1400194156.720 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:16.720Z,1400194156.720 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.733Z,1400194156.733 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-15T22:49:16.733Z,1400194156.733 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.733Z,1400194156.733 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-15T22:49:16.733Z,1400194156.733 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.734Z,1400194156.734 [controlThread](INFO): Join timeout helper Thread ID is 9526
2014-05-15T22:49:16.903Z,1400194156.903 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-15T22:49:16.903Z,1400194156.903 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-15T22:49:16.904Z,1400194156.904 [AHRS_sp3003D](INFO): Powering down
2014-05-15T22:49:16.905Z,1400194156.905 [DVL_micro](INFO): uninitialize:Powering down
2014-05-15T22:49:16.906Z,1400194156.906 [NAL9602](INFO): Powering down
2014-05-15T22:49:16.909Z,1400194156.909 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-15T22:49:16.911Z,1400194156.911 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-15T22:49:16.911Z,1400194156.911 [Default] Stopped
2014-05-15T22:49:16.911Z,1400194156.911 [Default](INFO): Aggregate::uninitialize Default
2014-05-15T22:49:16.911Z,1400194156.911 [Default:GPS] Stopped
2014-05-15T22:49:16.911Z,1400194156.911 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-15T22:49:16.911Z,1400194156.911 [Default:GPS:A.SetSpeed] Stopped
2014-05-15T22:49:16.912Z,1400194156.912 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:49:16.912Z,1400194156.912 [Default:GPS:Read_GPS] Stopped
2014-05-15T22:49:16.912Z,1400194156.912 [Default:Iridium] Stopped
2014-05-15T22:49:16.912Z,1400194156.912 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-15T22:49:16.912Z,1400194156.912 [Default:Iridium:A.SetSpeed] Stopped
2014-05-15T22:49:16.912Z,1400194156.912 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:49:16.912Z,1400194156.912 [Default:Iridium:Read_Iridium] Stopped
2014-05-15T22:49:16.912Z,1400194156.912 [Default:CallIridium] Stopped
2014-05-15T22:49:16.913Z,1400194156.913 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-15T22:49:16.913Z,1400194156.913 [Default:CallIridium:B] Stopped
2014-05-15T22:49:16.913Z,1400194156.913 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface] Stopped
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-05-15T22:49:16.913Z,1400194156.913 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-15T22:49:16.919Z,1400194156.919 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-15T22:49:16.919Z,1400194156.919 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-15T22:49:16.919Z,1400194156.919 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-15T22:49:16.920Z,1400194156.920 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-15T22:49:16.920Z,1400194156.920 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-15T22:49:16.920Z,1400194156.920 [BuoyancyServo](INFO): Powering down
2014-05-15T22:49:16.932Z,1400194156.932 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-15T22:49:16.932Z,1400194156.932 [ElevatorServo](INFO): Powering down
2014-05-15T22:49:16.933Z,1400194156.933 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-15T22:49:16.933Z,1400194156.933 [MassServo](INFO): Powering down
2014-05-15T22:49:16.934Z,1400194156.934 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-15T22:49:16.934Z,1400194156.934 [RudderServo](INFO): Powering down
2014-05-15T22:49:16.935Z,1400194156.935 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-15T22:49:16.935Z,1400194156.935 [ThrusterServo](INFO): Powering down
2014-05-15T22:49:16.936Z,1400194156.936 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-15T22:49:16.936Z,1400194156.936 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-15T22:49:16.937Z,1400194156.937 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-15T22:49:16.984Z,1400194156.984 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:16.998Z,1400194156.998 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:17.046Z,1400194157.046 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:17.073Z,1400194157.073 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:17.076Z,1400194157.076 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:17.104Z,1400194157.104 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-15T22:49:17.155Z,1400194157.155 [logger ThreadHandler](INFO): Thread cancelled.