2012-01-20T18:19:06.69930Z,1327083546.6993 [NAL9601](IMPORTANT): GPS fix at: 1327083541 2012-01-20T18:19:06.73540Z,1327083546.7354 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:19:06.73580Z,1327083546.7358 [Default:GPS](INFO): Completed Default:GPS 2012-01-20T18:19:06.73590Z,1327083546.7359 [Default:GPS] Stopped 2012-01-20T18:19:06.73600Z,1327083546.736 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:19:06.73610Z,1327083546.7361 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:19:06.73610Z,1327083546.7361 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:19:06.73630Z,1327083546.7363 [Default:Iridium] Running Loop=1 2012-01-20T18:19:06.73640Z,1327083546.7364 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-01-20T18:19:06.73650Z,1327083546.7365 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-01-20T18:19:06.73650Z,1327083546.7365 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:19:06.73670Z,1327083546.7367 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-01-20T18:19:06.73680Z,1327083546.7368 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:19:07.21780Z,1327083547.2178 [Default:Iridium:B.GoToSurface] Stopped 2012-01-20T18:19:07.21790Z,1327083547.2179 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:19:07.21800Z,1327083547.218 [Default:Iridium:Read_Iridium] Running Loop=1 2012-01-20T18:19:24.95380Z,1327083564.9538 [NAL9601](INFO): SBD MO Status=1, MOMSN=42130, MT Status=0, MTMSN=0 2012-01-20T18:19:25.10730Z,1327083565.1073 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:19:25.10760Z,1327083565.1076 [NAL9601](INFO): Packets left to send: 5 2012-01-20T18:19:25.10860Z,1327083565.1086 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000097 2012-01-20T18:19:37.82990Z,1327083577.8299 [NAL9601](INFO): SBD MO Status=1, MOMSN=42131, MT Status=0, MTMSN=0 2012-01-20T18:19:37.98740Z,1327083577.9874 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:19:37.98760Z,1327083577.9876 [NAL9601](INFO): Packets left to send: 4 2012-01-20T18:19:37.98870Z,1327083577.9887 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000098 2012-01-20T18:19:51.33370Z,1327083591.3337 [NAL9601](INFO): SBD MO Status=1, MOMSN=42132, MT Status=0, MTMSN=0 2012-01-20T18:19:51.46730Z,1327083591.4673 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:19:51.46750Z,1327083591.4675 [NAL9601](INFO): Packets left to send: 3 2012-01-20T18:19:51.46870Z,1327083591.4687 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000099 2012-01-20T18:20:08.67770Z,1327083608.6777 [NAL9601](INFO): SBD MO Status=1, MOMSN=42133, MT Status=0, MTMSN=0 2012-01-20T18:20:08.83930Z,1327083608.8393 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:20:08.83960Z,1327083608.8396 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:20:08.84060Z,1327083608.8406 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000100 2012-01-20T18:20:27.17400Z,1327083627.174 [NAL9601](INFO): SBD MO Status=1, MOMSN=42134, MT Status=0, MTMSN=0 2012-01-20T18:20:27.31150Z,1327083627.3115 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:20:27.31170Z,1327083627.3117 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:20:27.31270Z,1327083627.3127 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000101 2012-01-20T18:20:37.67640Z,1327083637.6764 [NAL9601](INFO): SBD MO Status=1, MOMSN=42135, MT Status=0, MTMSN=0 2012-01-20T18:20:37.89530Z,1327083637.8953 [NAL9601](INFO): Sent 323 bytes from file Logs/20120120T163905/shore0016.lzma 2012-01-20T18:20:37.89560Z,1327083637.8956 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:20:37.89660Z,1327083637.8966 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000102 2012-01-20T18:20:45.33360Z,1327083645.3336 [NAL9601](INFO): SBD MO Status=1, MOMSN=42136, MT Status=0, MTMSN=0 2012-01-20T18:20:45.48330Z,1327083645.4833 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0000.lzma 2012-01-20T18:20:45.48360Z,1327083645.4836 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:20:45.48460Z,1327083645.4846 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000103 2012-01-20T18:20:54.28170Z,1327083654.2817 [NAL9601](INFO): SBD MO Status=1, MOMSN=42137, MT Status=0, MTMSN=0 2012-01-20T18:20:54.46730Z,1327083654.4673 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0000.lzma 2012-01-20T18:20:54.46750Z,1327083654.4675 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:20:54.46860Z,1327083654.4686 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000104 2012-01-20T18:21:01.55670Z,1327083661.5567 [NAL9601](INFO): SBD MO Status=1, MOMSN=42138, MT Status=0, MTMSN=0 2012-01-20T18:21:01.75530Z,1327083661.7553 [NAL9601](INFO): Sent 209 bytes from file Logs/20120120T181903/shore0000.lzma 2012-01-20T18:21:01.75550Z,1327083661.7555 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:21:01.75660Z,1327083661.7566 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000105 2012-01-20T18:21:06.36160Z,1327083666.3616 [NAL9601](INFO): SBD MO Status=0, MOMSN=42139, MT Status=0, MTMSN=0 2012-01-20T18:21:06.56070Z,1327083666.5607 [Default:Iridium:Read_Iridium] Stopped 2012-01-20T18:21:06.56110Z,1327083666.5611 [Default:Iridium](INFO): Completed Default:Iridium 2012-01-20T18:21:06.56120Z,1327083666.5612 [Default:Iridium] Stopped 2012-01-20T18:21:06.56130Z,1327083666.5613 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-01-20T18:21:06.56140Z,1327083666.5614 [Default:Iridium:A.SetSpeed] Stopped 2012-01-20T18:21:06.56150Z,1327083666.5615 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:21:06.56160Z,1327083666.5616 [Default:G.Wait] Running Loop=1 2012-01-20T18:21:06.56170Z,1327083666.5617 [Default:G.Wait](DEBUG): Initialize Wait Component. 2012-01-20T18:21:16.93110Z,1327083676.9311 [NAL9601](INFO): Powering down 2012-01-20T18:26:06.95960Z,1327083966.9596 [Default:CallIridium] Running Loop=1 2012-01-20T18:26:06.95980Z,1327083966.9598 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-01-20T18:26:06.95990Z,1327083966.9599 [Default:CallIridium:A] Running Loop=1 2012-01-20T18:26:06.96010Z,1327083966.9601 [Default:CallIridium:A](INFO): Aggregate::initialize Default:CallIridium:A 2012-01-20T18:26:06.96020Z,1327083966.9602 [Default:CallGPS] Running Loop=1 2012-01-20T18:26:06.96030Z,1327083966.9603 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2012-01-20T18:26:06.96050Z,1327083966.9605 [Default:CallGPS:A] Running Loop=1 2012-01-20T18:26:06.96060Z,1327083966.9606 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A 2012-01-20T18:26:11.98520Z,1327083971.9852 [Default:Iridium] Running Loop=1 2012-01-20T18:26:11.98540Z,1327083971.9854 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-01-20T18:26:11.98540Z,1327083971.9854 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-01-20T18:26:11.98550Z,1327083971.9855 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:26:11.98570Z,1327083971.9857 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-01-20T18:26:11.98580Z,1327083971.9858 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:26:11.98640Z,1327083971.9864 [Default:Iridium:B.GoToSurface] Stopped 2012-01-20T18:26:11.98650Z,1327083971.9865 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:26:11.98670Z,1327083971.9867 [Default:Iridium:Read_Iridium] Running Loop=1 2012-01-20T18:26:11.98700Z,1327083971.987 [Default:GPS] Running Loop=1 2012-01-20T18:26:11.98710Z,1327083971.9871 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:26:11.98720Z,1327083971.9872 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:26:11.98730Z,1327083971.9873 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:26:11.98740Z,1327083971.9874 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:26:11.98750Z,1327083971.9875 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:26:11.98810Z,1327083971.9881 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:26:11.98820Z,1327083971.9882 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:26:11.98830Z,1327083971.9883 [Default:GPS:Read_GPS] Running Loop=1 2012-01-20T18:26:12.56050Z,1327083972.5605 [NAL9601](INFO): Powering up 2012-01-20T18:27:18.27140Z,1327084038.2714 [NAL9601](INFO): NAL9601 initialized 2012-01-20T18:27:19.39860Z,1327084039.3986 [NAL9601](IMPORTANT): GPS fix at: 1327084001 2012-01-20T18:27:19.41270Z,1327084039.4127 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:27:19.41300Z,1327084039.413 [Default:GPS](INFO): Completed Default:GPS 2012-01-20T18:27:19.41310Z,1327084039.4131 [Default:GPS] Stopped 2012-01-20T18:27:19.41320Z,1327084039.4132 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:27:19.41330Z,1327084039.4133 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:27:19.41340Z,1327084039.4134 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:27:19.76890Z,1327084039.7689 [Default:CallGPS:A](INFO): Completed Default:CallGPS:A 2012-01-20T18:27:19.76900Z,1327084039.769 [Default:CallGPS:A] Stopped 2012-01-20T18:27:19.76910Z,1327084039.7691 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A 2012-01-20T18:27:19.76930Z,1327084039.7693 [Default:CallGPS](INFO): Completed Default:CallGPS 2012-01-20T18:27:19.76940Z,1327084039.7694 [Default:CallGPS] Stopped 2012-01-20T18:27:19.76950Z,1327084039.7695 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2012-01-20T18:27:20.17280Z,1327084040.1728 [Default:CallGPS] Running Loop=1 2012-01-20T18:27:20.17300Z,1327084040.173 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2012-01-20T18:27:20.17310Z,1327084040.1731 [Default:CallGPS:A] Running Loop=1 2012-01-20T18:27:20.17330Z,1327084040.1733 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A 2012-01-20T18:27:20.71720Z,1327084040.7172 [Default:GPS] Running Loop=1 2012-01-20T18:27:20.71740Z,1327084040.7174 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:27:20.71750Z,1327084040.7175 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:27:20.71760Z,1327084040.7176 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:27:20.71770Z,1327084040.7177 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:27:20.71780Z,1327084040.7178 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:27:20.71850Z,1327084040.7185 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:27:20.71860Z,1327084040.7186 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:27:20.71870Z,1327084040.7187 [Default:GPS:Read_GPS] Running Loop=1 2012-01-20T18:27:39.71840Z,1327084059.7184 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=42140, MT Status=1, MTMSN=3477 2012-01-20T18:27:39.92730Z,1327084059.9273 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0001.lzma 2012-01-20T18:27:39.92750Z,1327084059.9275 [NAL9601](INFO): Packets left to send: 3 2012-01-20T18:27:39.92870Z,1327084059.9287 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000106 2012-01-20T18:27:40.29250Z,1327084060.2925 [NAL9601](INFO): Received command:load Transport/transit_3km.xml;set transit_3km.Wpt1Lat 36.828 degree;set transit_3km.Wpt1Lon -121.831 degree;run 2012-01-20T18:27:40.30810Z,1327084060.3081 [CommandLine](IMPORTANT): got command load ./Missions/Transport/transit_3km.xml 2012-01-20T18:27:40.30840Z,1327084060.3084 [MissionManager](INFO): Loading Mission: ./Missions/Transport/transit_3km.xml 2012-01-20T18:27:40.34090Z,1327084060.3409 [MissionManager](INFO): DefineArg transit_3km.ApproachDepth = 10 m 2012-01-20T18:27:40.34330Z,1327084060.3433 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lat = 36.806966 arcdeg 2012-01-20T18:27:40.34550Z,1327084060.3455 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lon = -121.824326 arcdeg 2012-01-20T18:27:40.34760Z,1327084060.3476 [MissionManager](INFO): DefineArg transit_3km.Speed = 1 m/s 2012-01-20T18:27:40.34980Z,1327084060.3498 [MissionManager](INFO): DefineArg transit_3km.MaxDepth = 20 m 2012-01-20T18:27:40.35120Z,1327084060.3512 [transit_3km:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-01-20T18:27:40.35600Z,1327084060.356 [transit_3km:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-01-20T18:27:40.39330Z,1327084060.3933 [transit_3km:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2012-01-20T18:27:40.39810Z,1327084060.3981 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-01-20T18:27:40.40140Z,1327084060.4014 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Construct. 2012-01-20T18:27:40.41020Z,1327084060.4102 [transit_3km:WaypointOne:A.Pitch](DEBUG): Construct. 2012-01-20T18:27:40.41470Z,1327084060.4147 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Construct. 2012-01-20T18:27:40.41690Z,1327084060.4169 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Construct Waypoint. 2012-01-20T18:27:40.42550Z,1327084060.4255 [MissionManager](DEBUG): 10.0 36.806966 -121.824326 1 Maximum depth for the entire mission. 20 7 1 0 35 2012-01-20T18:27:40.42590Z,1327084060.4259 [CommandLine](IMPORTANT): Loaded ./Missions/Transport/transit_3km.xml 2012-01-20T18:27:40.50980Z,1327084060.5098 [CommandLine](IMPORTANT): got command set transit_3km.Wpt1Lat 36.82799911 degree 2012-01-20T18:27:40.59400Z,1327084060.594 [CommandLine](IMPORTANT): got command set transit_3km.Wpt1Lon -121.8310013 degree 2012-01-20T18:27:40.59540Z,1327084060.5954 [CommandLine](IMPORTANT): got command run 2012-01-20T18:27:40.59560Z,1327084060.5956 [CommandLine](IMPORTANT): Running 2012-01-20T18:27:40.60860Z,1327084060.6086 [Default] Stopped 2012-01-20T18:27:40.60880Z,1327084060.6088 [Default](INFO): Aggregate::uninitialize Default 2012-01-20T18:27:40.60900Z,1327084060.609 [Default:GPS] Stopped 2012-01-20T18:27:40.60910Z,1327084060.6091 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:27:40.60920Z,1327084060.6092 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:27:40.60930Z,1327084060.6093 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:27:40.60940Z,1327084060.6094 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:27:40.60940Z,1327084060.6094 [Default:Iridium] Stopped 2012-01-20T18:27:40.60950Z,1327084060.6095 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-01-20T18:27:40.60960Z,1327084060.6096 [Default:Iridium:A.SetSpeed] Stopped 2012-01-20T18:27:40.60970Z,1327084060.6097 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:27:40.60980Z,1327084060.6098 [Default:Iridium:Read_Iridium] Stopped 2012-01-20T18:27:40.60980Z,1327084060.6098 [Default:CallGPS] Stopped 2012-01-20T18:27:40.60990Z,1327084060.6099 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2012-01-20T18:27:40.61000Z,1327084060.61 [Default:CallGPS:A] Stopped 2012-01-20T18:27:40.61010Z,1327084060.6101 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A 2012-01-20T18:27:40.61020Z,1327084060.6102 [Default:CallIridium] Stopped 2012-01-20T18:27:40.61030Z,1327084060.6103 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-01-20T18:27:40.61040Z,1327084060.6104 [Default:CallIridium:A] Stopped 2012-01-20T18:27:40.61050Z,1327084060.6105 [Default:CallIridium:A](INFO): Aggregate::uninitialize Default:CallIridium:A 2012-01-20T18:27:40.61060Z,1327084060.6106 [Default:E.SetSpeed] Stopped 2012-01-20T18:27:40.61070Z,1327084060.6107 [Default:E.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:27:40.61070Z,1327084060.6107 [Default:F.GoToSurface] Stopped 2012-01-20T18:27:40.61080Z,1327084060.6108 [Default:F.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:27:40.61090Z,1327084060.6109 [Default:G.Wait] Stopped 2012-01-20T18:27:40.61100Z,1327084060.611 [Default:G.Wait](DEBUG): Uninitialize Wait Component. 2012-01-20T18:27:40.61110Z,1327084060.6111 [MissionManager](IMPORTANT): Started mission transit_3km 2012-01-20T18:27:40.61120Z,1327084060.6112 [transit_3km] Running Loop=1 2012-01-20T18:27:40.61140Z,1327084060.6114 [transit_3km](INFO): Aggregate::initialize transit_3km 2012-01-20T18:27:40.61140Z,1327084060.6114 [transit_3km:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:27:40.61150Z,1327084060.6115 [transit_3km:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-01-20T18:27:40.61170Z,1327084060.6117 [transit_3km:B.DepthEnvelope] Running Loop=1 2012-01-20T18:27:40.61170Z,1327084060.6117 [transit_3km:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-01-20T18:27:40.61240Z,1327084060.6124 [transit_3km:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:27:40.61240Z,1327084060.6124 [transit_3km:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2012-01-20T18:27:40.61260Z,1327084060.6126 [transit_3km:SURFACECOMMS] Running Loop=1 2012-01-20T18:27:40.61270Z,1327084060.6127 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS 2012-01-20T18:27:40.61280Z,1327084060.6128 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1 2012-01-20T18:27:40.61290Z,1327084060.6129 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:27:40.61450Z,1327084060.6145 [transit_3km:SURFACECOMMS:B] Running Loop=1 2012-01-20T18:27:40.61470Z,1327084060.6147 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B 2012-01-20T18:27:40.61480Z,1327084060.6148 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1 2012-01-20T18:27:40.61490Z,1327084060.6149 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:27:40.61510Z,1327084060.6151 [transit_3km:SURFACECOMMS:B:B] Running Loop=1 2012-01-20T18:27:40.61520Z,1327084060.6152 [transit_3km:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:27:40.61610Z,1327084060.6161 [transit_3km:B.DepthEnvelope] Running Loop=1 2012-01-20T18:27:40.61710Z,1327084060.6171 [transit_3km:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:27:40.83750Z,1327084060.8375 [transit_3km:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-01-20T18:27:40.83840Z,1327084060.8384 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1 2012-01-20T18:27:42.82780Z,1327084062.8278 [NAL9601](IMPORTANT): GPS fix at: 1327084025 2012-01-20T18:27:42.84120Z,1327084062.8412 [transit_3km:SURFACECOMMS:B:B] Stopped 2012-01-20T18:27:42.84140Z,1327084062.8414 [transit_3km:SURFACECOMMS:B:C] Running Loop=1 2012-01-20T18:27:43.23320Z,1327084063.2332 [transit_3km:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-01-20T18:28:02.69370Z,1327084082.6937 [NAL9601](INFO): SBD MO Status=1, MOMSN=42141, MT Status=0, MTMSN=0 2012-01-20T18:28:02.89130Z,1327084082.8913 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0001.lzma 2012-01-20T18:28:02.89150Z,1327084082.8915 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:28:02.89260Z,1327084082.8926 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000107 2012-01-20T18:28:20.58670Z,1327084100.5867 [NAL9601](INFO): SBD MO Status=1, MOMSN=42142, MT Status=0, MTMSN=0 2012-01-20T18:28:20.76330Z,1327084100.7633 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0001.lzma 2012-01-20T18:28:20.76350Z,1327084100.7635 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:28:20.76460Z,1327084100.7646 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000108 2012-01-20T18:28:32.64500Z,1327084112.645 [NAL9601](INFO): SBD MO Status=1, MOMSN=42143, MT Status=0, MTMSN=0 2012-01-20T18:28:32.84330Z,1327084112.8433 [NAL9601](INFO): Sent 285 bytes from file Logs/20120120T181903/shore0001.lzma 2012-01-20T18:28:32.84350Z,1327084112.8435 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:28:32.84460Z,1327084112.8446 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000109 2012-01-20T18:28:43.04970Z,1327084123.0497 [NAL9601](INFO): SBD MO Status=0, MOMSN=42144, MT Status=0, MTMSN=0 2012-01-20T18:29:03.59380Z,1327084143.5938 [NAL9601](INFO): SBD MO Status=1, MOMSN=42145, MT Status=0, MTMSN=0 2012-01-20T18:29:03.79530Z,1327084143.7953 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0002.lzma 2012-01-20T18:29:03.79560Z,1327084143.7956 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:29:03.79670Z,1327084143.7967 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000110 2012-01-20T18:29:15.45440Z,1327084155.4544 [NAL9601](INFO): SBD MO Status=1, MOMSN=42146, MT Status=0, MTMSN=0 2012-01-20T18:29:15.57930Z,1327084155.5793 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0002.lzma 2012-01-20T18:29:15.57950Z,1327084155.5795 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:29:15.58060Z,1327084155.5806 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000111 2012-01-20T18:29:28.05150Z,1327084168.0515 [NAL9601](INFO): SBD MO Status=1, MOMSN=42147, MT Status=0, MTMSN=0 2012-01-20T18:29:28.25930Z,1327084168.2593 [NAL9601](INFO): Sent 247 bytes from file Logs/20120120T181903/shore0002.lzma 2012-01-20T18:29:28.25960Z,1327084168.2596 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:29:28.40300Z,1327084168.403 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000112 2012-01-20T18:29:36.51870Z,1327084176.5187 [NAL9601](INFO): SBD MO Status=0, MOMSN=42148, MT Status=0, MTMSN=0 2012-01-20T18:29:36.69350Z,1327084176.6935 [transit_3km:SURFACECOMMS:B:C] Stopped 2012-01-20T18:29:36.69360Z,1327084176.6936 [transit_3km:SURFACECOMMS:B:D] Running Loop=1 2012-01-20T18:29:36.95110Z,1327084176.9511 [transit_3km:SURFACECOMMS:B:D](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-01-20T18:29:38.89830Z,1327084178.8983 [NAL9601](IMPORTANT): GPS fix at: 1327084174 2012-01-20T18:29:38.91170Z,1327084178.9117 [transit_3km:SURFACECOMMS:B:D] Stopped 2012-01-20T18:29:38.91210Z,1327084178.9121 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B 2012-01-20T18:29:38.91220Z,1327084178.9122 [transit_3km:SURFACECOMMS:B] Stopped 2012-01-20T18:29:38.91230Z,1327084178.9123 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B 2012-01-20T18:29:38.91240Z,1327084178.9124 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped 2012-01-20T18:29:38.91240Z,1327084178.9124 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:29:38.91290Z,1327084178.9129 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS 2012-01-20T18:29:38.91290Z,1327084178.9129 [transit_3km:SURFACECOMMS] Stopped 2012-01-20T18:29:38.91310Z,1327084178.9131 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS 2012-01-20T18:29:38.91310Z,1327084178.9131 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped 2012-01-20T18:29:38.91320Z,1327084178.9132 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:29:38.91340Z,1327084178.9134 [transit_3km:WaypointOne] Running Loop=1 2012-01-20T18:29:38.91350Z,1327084178.9135 [transit_3km:WaypointOne](INFO): Aggregate::initialize transit_3km:WaypointOne 2012-01-20T18:29:38.91360Z,1327084178.9136 [transit_3km:WaypointOne:A.Pitch] Running Loop=1 2012-01-20T18:29:38.91360Z,1327084178.9136 [transit_3km:WaypointOne:A.Pitch](DEBUG): Initialize. 2012-01-20T18:29:38.91390Z,1327084178.9139 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1 2012-01-20T18:29:38.91390Z,1327084178.9139 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Initialize. 2012-01-20T18:29:38.91420Z,1327084178.9142 [transit_3km:WaypointOne:WaypointW1.Waypoint] Running Loop=1 2012-01-20T18:29:38.91420Z,1327084178.9142 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Initialize WaypointComponent. 2012-01-20T18:29:39.33420Z,1327084179.3342 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1 2012-01-20T18:29:39.33510Z,1327084179.3351 [transit_3km:WaypointOne:A.Pitch] Running Loop=1 2012-01-20T18:29:45.41040Z,1327084185.4104 [NAL9601](INFO): Powering down 2012-01-20T18:30:10.50160Z,1327084210.5016 [Radio_Freewave](INFO): Powering down 2012-01-20T18:30:32.25860Z,1327084232.2586 [Radio_Freewave](INFO): Powering up 2012-01-20T18:30:35.93790Z,1327084235.9379 [Radio_Freewave](INFO): Powering down 2012-01-20T18:30:54.51570Z,1327084254.5157 [Radio_Freewave](INFO): Powering up 2012-01-20T18:30:56.11380Z,1327084256.1138 [Radio_Freewave](INFO): Powering down 2012-01-20T18:30:56.89300Z,1327084256.893 [Radio_Freewave](INFO): Powering up 2012-01-20T18:30:58.66120Z,1327084258.6612 [Radio_Freewave](INFO): Powering down 2012-01-20T18:39:29.12610Z,1327084769.1261 [transit_3km:WaypointOne:WaypointW1.Waypoint](INFO): Reached Waypoint: 36.82799751,-121.8309995 2012-01-20T18:39:29.12640Z,1327084769.1264 [transit_3km:WaypointOne:WaypointW1.Waypoint] Stopped 2012-01-20T18:39:29.12650Z,1327084769.1265 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2012-01-20T18:39:29.12660Z,1327084769.1266 [transit_3km:WaypointOne:PHONEHOMEWPT1] Running Loop=1 2012-01-20T18:39:29.13000Z,1327084769.13 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::initialize transit_3km:WaypointOne:PHONEHOMEWPT1 2012-01-20T18:39:29.54200Z,1327084769.542 [transit_3km:SURFACECOMMS] Running Loop=1 2012-01-20T18:39:29.54220Z,1327084769.5422 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS 2012-01-20T18:39:29.54230Z,1327084769.5423 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1 2012-01-20T18:39:29.54230Z,1327084769.5423 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:42:30.40190Z,1327084950.4019 [Radio_Freewave](INFO): Powering up 2012-01-20T18:42:30.41170Z,1327084950.4117 [transit_3km:SURFACECOMMS:B] Running Loop=1 2012-01-20T18:42:30.41180Z,1327084950.4118 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B 2012-01-20T18:42:30.41190Z,1327084950.4119 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1 2012-01-20T18:42:30.41200Z,1327084950.412 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:42:30.41220Z,1327084950.4122 [transit_3km:SURFACECOMMS:B:B] Running Loop=1 2012-01-20T18:42:31.19970Z,1327084951.1997 [NAL9601](INFO): Powering up 2012-01-20T18:43:36.91140Z,1327085016.9114 [NAL9601](INFO): NAL9601 initialized 2012-01-20T18:43:38.01190Z,1327085018.0119 [NAL9601](IMPORTANT): GPS fix at: 1327084981 2012-01-20T18:43:38.02520Z,1327085018.0252 [transit_3km:SURFACECOMMS:B:B] Stopped 2012-01-20T18:43:38.02540Z,1327085018.0254 [transit_3km:SURFACECOMMS:B:C] Running Loop=1 2012-01-20T18:43:52.39130Z,1327085032.3913 [NAL9601](INFO): SBD MO Status=1, MOMSN=42149, MT Status=0, MTMSN=0 2012-01-20T18:43:52.57560Z,1327085032.5756 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:43:52.57580Z,1327085032.5758 [NAL9601](INFO): Packets left to send: 7 2012-01-20T18:43:52.57680Z,1327085032.5768 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000113 2012-01-20T18:44:02.15900Z,1327085042.159 [NAL9601](INFO): SBD MO Status=1, MOMSN=42150, MT Status=0, MTMSN=0 2012-01-20T18:44:02.35930Z,1327085042.3593 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:02.35950Z,1327085042.3595 [NAL9601](INFO): Packets left to send: 6 2012-01-20T18:44:02.36060Z,1327085042.3606 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000114 2012-01-20T18:44:11.86580Z,1327085051.8658 [NAL9601](INFO): SBD MO Status=1, MOMSN=42151, MT Status=0, MTMSN=0 2012-01-20T18:44:12.04330Z,1327085052.0433 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:12.04360Z,1327085052.0436 [NAL9601](INFO): Packets left to send: 5 2012-01-20T18:44:12.50210Z,1327085052.5021 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000115 2012-01-20T18:44:21.97310Z,1327085061.9731 [NAL9601](INFO): SBD MO Status=1, MOMSN=42152, MT Status=0, MTMSN=0 2012-01-20T18:44:22.13130Z,1327085062.1313 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:22.13150Z,1327085062.1315 [NAL9601](INFO): Packets left to send: 4 2012-01-20T18:44:22.13260Z,1327085062.1326 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000116 2012-01-20T18:44:30.86570Z,1327085070.8657 [NAL9601](INFO): SBD MO Status=1, MOMSN=42153, MT Status=0, MTMSN=0 2012-01-20T18:44:31.01540Z,1327085071.0154 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:31.01560Z,1327085071.0156 [NAL9601](INFO): Packets left to send: 3 2012-01-20T18:44:31.01670Z,1327085071.0167 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000117 2012-01-20T18:44:38.90170Z,1327085078.9017 [NAL9601](INFO): SBD MO Status=1, MOMSN=42154, MT Status=0, MTMSN=0 2012-01-20T18:44:39.10340Z,1327085079.1034 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:39.10360Z,1327085079.1036 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:44:39.14490Z,1327085079.1449 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000118 2012-01-20T18:44:47.02040Z,1327085087.0204 [NAL9601](INFO): SBD MO Status=1, MOMSN=42155, MT Status=0, MTMSN=0 2012-01-20T18:44:47.19130Z,1327085087.1913 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:47.19150Z,1327085087.1915 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:44:47.19260Z,1327085087.1926 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000119 2012-01-20T18:44:52.83080Z,1327085092.8308 [NAL9601](INFO): SBD MO Status=1, MOMSN=42156, MT Status=0, MTMSN=0 2012-01-20T18:44:52.97970Z,1327085092.9797 [NAL9601](INFO): Sent 67 bytes from file Logs/20120120T181903/shore0003.lzma 2012-01-20T18:44:52.97990Z,1327085092.9799 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:44:52.98100Z,1327085092.981 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000120 2012-01-20T18:44:59.60970Z,1327085099.6097 [NAL9601](INFO): SBD MO Status=0, MOMSN=42157, MT Status=0, MTMSN=0 2012-01-20T18:44:59.78460Z,1327085099.7846 [transit_3km:SURFACECOMMS:B:C] Stopped 2012-01-20T18:44:59.78480Z,1327085099.7848 [transit_3km:SURFACECOMMS:B:D] Running Loop=1 2012-01-20T18:45:02.02470Z,1327085102.0247 [NAL9601](IMPORTANT): GPS fix at: 1327085065 2012-01-20T18:45:02.03830Z,1327085102.0383 [transit_3km:SURFACECOMMS:B:D] Stopped 2012-01-20T18:45:02.03870Z,1327085102.0387 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B 2012-01-20T18:45:02.03880Z,1327085102.0388 [transit_3km:SURFACECOMMS:B] Stopped 2012-01-20T18:45:02.03890Z,1327085102.0389 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B 2012-01-20T18:45:02.03900Z,1327085102.039 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped 2012-01-20T18:45:02.03910Z,1327085102.0391 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:45:02.03950Z,1327085102.0395 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS 2012-01-20T18:45:02.03960Z,1327085102.0396 [transit_3km:SURFACECOMMS] Stopped 2012-01-20T18:45:02.03970Z,1327085102.0397 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS 2012-01-20T18:45:02.03980Z,1327085102.0398 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped 2012-01-20T18:45:02.03990Z,1327085102.0399 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:45:02.46530Z,1327085102.4653 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Completed transit_3km:WaypointOne:PHONEHOMEWPT1 2012-01-20T18:45:02.46540Z,1327085102.4654 [transit_3km:WaypointOne:PHONEHOMEWPT1] Stopped 2012-01-20T18:45:02.46560Z,1327085102.4656 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::uninitialize transit_3km:WaypointOne:PHONEHOMEWPT1 2012-01-20T18:45:02.46640Z,1327085102.4664 [transit_3km:WaypointOne](INFO): Completed transit_3km:WaypointOne 2012-01-20T18:45:02.46640Z,1327085102.4664 [transit_3km:WaypointOne] Stopped 2012-01-20T18:45:02.46660Z,1327085102.4666 [transit_3km:WaypointOne](INFO): Aggregate::uninitialize transit_3km:WaypointOne 2012-01-20T18:45:02.46660Z,1327085102.4666 [transit_3km:WaypointOne:A.Pitch] Stopped 2012-01-20T18:45:02.46670Z,1327085102.4667 [transit_3km:WaypointOne:B.SetSpeed] Stopped 2012-01-20T18:45:02.47490Z,1327085102.4749 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:45:02.47630Z,1327085102.4763 [transit_3km](INFO): Completed transit_3km 2012-01-20T18:45:02.47640Z,1327085102.4764 [transit_3km] Stopped 2012-01-20T18:45:02.47660Z,1327085102.4766 [transit_3km](INFO): Aggregate::uninitialize transit_3km 2012-01-20T18:45:02.47670Z,1327085102.4767 [transit_3km:A.AltitudeEnvelope] Stopped 2012-01-20T18:45:02.47670Z,1327085102.4767 [transit_3km:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-01-20T18:45:02.47680Z,1327085102.4768 [transit_3km:B.DepthEnvelope] Stopped 2012-01-20T18:45:02.47690Z,1327085102.4769 [transit_3km:B.DepthEnvelope](DEBUG): Uninitialize. 2012-01-20T18:45:02.47690Z,1327085102.4769 [transit_3km:C.OffshoreEnvelope] Stopped 2012-01-20T18:45:02.47700Z,1327085102.477 [transit_3km:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2012-01-20T18:45:02.93840Z,1327085102.9384 [MissionManager](IMPORTANT): Started mission Default 2012-01-20T18:45:02.93850Z,1327085102.9385 [Default] Running Loop=1 2012-01-20T18:45:02.93860Z,1327085102.9386 [Default](INFO): Aggregate::initialize Default 2012-01-20T18:45:02.93870Z,1327085102.9387 [Default:E.SetSpeed] Running Loop=1 2012-01-20T18:45:02.93880Z,1327085102.9388 [Default:E.SetSpeed](DEBUG): Initialize. 2012-01-20T18:45:02.93890Z,1327085102.9389 [Default:F.GoToSurface] Running Loop=1 2012-01-20T18:45:02.93900Z,1327085102.939 [Default:F.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:45:02.93940Z,1327085102.9394 [Default:GPS] Running Loop=1 2012-01-20T18:45:02.93960Z,1327085102.9396 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:45:02.93970Z,1327085102.9397 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:45:02.93970Z,1327085102.9397 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:45:02.93990Z,1327085102.9399 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:45:02.94000Z,1327085102.94 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:45:02.94170Z,1327085102.9417 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:45:02.94180Z,1327085102.9418 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:45:02.94190Z,1327085102.9419 [Default:GPS:Read_GPS] Running Loop=1 2012-01-20T18:45:05.21150Z,1327085105.2115 [NAL9601](IMPORTANT): GPS fix at: 1327085069 2012-01-20T18:45:05.22530Z,1327085105.2253 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:45:05.22570Z,1327085105.2257 [Default:GPS](INFO): Completed Default:GPS 2012-01-20T18:45:05.22580Z,1327085105.2258 [Default:GPS] Stopped 2012-01-20T18:45:05.22590Z,1327085105.2259 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:45:05.22600Z,1327085105.226 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:45:05.22610Z,1327085105.2261 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:45:05.22620Z,1327085105.2262 [Default:Iridium] Running Loop=1 2012-01-20T18:45:05.22630Z,1327085105.2263 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-01-20T18:45:05.22640Z,1327085105.2264 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-01-20T18:45:05.22650Z,1327085105.2265 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:45:05.22660Z,1327085105.2266 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-01-20T18:45:05.22670Z,1327085105.2267 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:45:05.68200Z,1327085105.682 [Default:Iridium:B.GoToSurface] Stopped 2012-01-20T18:45:05.68210Z,1327085105.6821 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:45:05.68220Z,1327085105.6822 [Default:Iridium:Read_Iridium] Running Loop=1 2012-01-20T18:45:23.55060Z,1327085123.5506 [NAL9601](INFO): SBD MO Status=1, MOMSN=42158, MT Status=0, MTMSN=0 2012-01-20T18:45:23.73530Z,1327085123.7353 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0004.lzma 2012-01-20T18:45:23.73550Z,1327085123.7355 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:45:23.73660Z,1327085123.7366 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000121 2012-01-20T18:45:33.61780Z,1327085133.6178 [NAL9601](INFO): SBD MO Status=1, MOMSN=42159, MT Status=0, MTMSN=0 2012-01-20T18:45:33.81940Z,1327085133.8194 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0004.lzma 2012-01-20T18:45:33.81960Z,1327085133.8196 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:45:33.82070Z,1327085133.8207 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000122 2012-01-20T18:45:41.69780Z,1327085141.6978 [NAL9601](INFO): SBD MO Status=1, MOMSN=42160, MT Status=0, MTMSN=0 2012-01-20T18:45:41.91130Z,1327085141.9113 [NAL9601](INFO): Sent 58 bytes from file Logs/20120120T181903/shore0004.lzma 2012-01-20T18:45:41.91150Z,1327085141.9115 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:45:41.91260Z,1327085141.9126 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000123 2012-01-20T18:45:51.69780Z,1327085151.6978 [NAL9601](INFO): SBD MO Status=0, MOMSN=42161, MT Status=0, MTMSN=0 2012-01-20T18:45:51.90410Z,1327085151.9041 [Default:Iridium:Read_Iridium] Stopped 2012-01-20T18:45:51.90460Z,1327085151.9046 [Default:Iridium](INFO): Completed Default:Iridium 2012-01-20T18:45:51.90470Z,1327085151.9047 [Default:Iridium] Stopped 2012-01-20T18:45:51.90480Z,1327085151.9048 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-01-20T18:45:51.90490Z,1327085151.9049 [Default:Iridium:A.SetSpeed] Stopped 2012-01-20T18:45:51.90500Z,1327085151.905 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:45:51.90510Z,1327085151.9051 [Default:G.Wait] Running Loop=1 2012-01-20T18:45:51.90520Z,1327085151.9052 [Default:G.Wait](DEBUG): Initialize Wait Component. 2012-01-20T18:46:02.27180Z,1327085162.2718 [NAL9601](INFO): Powering down 2012-01-20T18:50:52.27190Z,1327085452.2719 [Default:CallIridium] Running Loop=1 2012-01-20T18:50:52.27210Z,1327085452.2721 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-01-20T18:50:52.27230Z,1327085452.2723 [Default:CallIridium:A] Running Loop=1 2012-01-20T18:50:52.27240Z,1327085452.2724 [Default:CallIridium:A](INFO): Aggregate::initialize Default:CallIridium:A 2012-01-20T18:50:52.27250Z,1327085452.2725 [Default:CallGPS] Running Loop=1 2012-01-20T18:50:52.27260Z,1327085452.2726 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2012-01-20T18:50:52.27280Z,1327085452.2728 [Default:CallGPS:A] Running Loop=1 2012-01-20T18:50:52.27290Z,1327085452.2729 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A 2012-01-20T18:50:57.45700Z,1327085457.457 [Default:Iridium] Running Loop=1 2012-01-20T18:50:57.45720Z,1327085457.4572 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-01-20T18:50:57.45730Z,1327085457.4573 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-01-20T18:50:57.45740Z,1327085457.4574 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:50:57.45760Z,1327085457.4576 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-01-20T18:50:57.45760Z,1327085457.4576 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:50:57.45820Z,1327085457.4582 [Default:Iridium:B.GoToSurface] Stopped 2012-01-20T18:50:57.45830Z,1327085457.4583 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:50:57.45840Z,1327085457.4584 [Default:Iridium:Read_Iridium] Running Loop=1 2012-01-20T18:50:57.45880Z,1327085457.4588 [Default:GPS] Running Loop=1 2012-01-20T18:50:57.45900Z,1327085457.459 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:50:57.45910Z,1327085457.4591 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:50:57.45910Z,1327085457.4591 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:50:57.45930Z,1327085457.4593 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:50:57.45940Z,1327085457.4594 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:50:57.46000Z,1327085457.46 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:50:57.46010Z,1327085457.4601 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:50:57.46020Z,1327085457.4602 [Default:GPS:Read_GPS] Running Loop=1 2012-01-20T18:50:57.99660Z,1327085457.9966 [NAL9601](INFO): Powering up 2012-01-20T18:52:03.72610Z,1327085523.7261 [NAL9601](INFO): NAL9601 initialized 2012-01-20T18:52:04.81530Z,1327085524.8153 [NAL9601](IMPORTANT): GPS fix at: 1327085489 2012-01-20T18:52:04.82910Z,1327085524.8291 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:52:04.82950Z,1327085524.8295 [Default:GPS](INFO): Completed Default:GPS 2012-01-20T18:52:04.82950Z,1327085524.8295 [Default:GPS] Stopped 2012-01-20T18:52:04.82970Z,1327085524.8297 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:52:04.82970Z,1327085524.8297 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:52:04.82980Z,1327085524.8298 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:52:05.22590Z,1327085525.2259 [Default:CallGPS:A](INFO): Completed Default:CallGPS:A 2012-01-20T18:52:05.22600Z,1327085525.226 [Default:CallGPS:A] Stopped 2012-01-20T18:52:05.22610Z,1327085525.2261 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A 2012-01-20T18:52:05.22630Z,1327085525.2263 [Default:CallGPS](INFO): Completed Default:CallGPS 2012-01-20T18:52:05.22640Z,1327085525.2264 [Default:CallGPS] Stopped 2012-01-20T18:52:05.22650Z,1327085525.2265 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2012-01-20T18:52:05.62910Z,1327085525.6291 [Default:CallGPS] Running Loop=1 2012-01-20T18:52:05.62920Z,1327085525.6292 [Default:CallGPS](INFO): Aggregate::initialize Default:CallGPS 2012-01-20T18:52:05.62940Z,1327085525.6294 [Default:CallGPS:A] Running Loop=1 2012-01-20T18:52:05.62950Z,1327085525.6295 [Default:CallGPS:A](INFO): Aggregate::initialize Default:CallGPS:A 2012-01-20T18:52:06.07200Z,1327085526.072 [Default:GPS] Running Loop=1 2012-01-20T18:52:06.07220Z,1327085526.0722 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:52:06.07230Z,1327085526.0723 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:52:06.07230Z,1327085526.0723 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:52:06.07250Z,1327085526.0725 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:52:06.07260Z,1327085526.0726 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:52:06.07320Z,1327085526.0732 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:52:06.07330Z,1327085526.0733 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:52:06.07340Z,1327085526.0734 [Default:GPS:Read_GPS] Running Loop=1 2012-01-20T18:52:24.72590Z,1327085544.7259 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=42162, MT Status=1, MTMSN=3478 2012-01-20T18:52:24.86330Z,1327085544.8633 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0005.lzma 2012-01-20T18:52:24.86350Z,1327085544.8635 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:52:24.86460Z,1327085544.8646 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000124 2012-01-20T18:52:25.46820Z,1327085545.4682 [NAL9601](INFO): Received command:load Engineering/Homing_altitude.xml;set homing_altitude.Altitude 9 meter;set homing_altitude.dockBearing 330 degree;set homing_altitude.finalApproach 0.1 meter;run 2012-01-20T18:52:25.48630Z,1327085545.4863 [CommandLine](IMPORTANT): got command load ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:25.48650Z,1327085545.4865 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:25.54180Z,1327085545.5418 [MissionManager](INFO): DefineArg homing_altitude.Wpt1Lat = 36.823 arcdeg 2012-01-20T18:52:25.54400Z,1327085545.544 [MissionManager](INFO): DefineArg homing_altitude.Wpt1Lon = -121.83 arcdeg 2012-01-20T18:52:25.54620Z,1327085545.5462 [MissionManager](INFO): DefineArg homing_altitude.Altitude = 10 m 2012-01-20T18:52:25.54840Z,1327085545.5484 [MissionManager](INFO): DefineArg homing_altitude.Speed = 1 m/s 2012-01-20T18:52:25.55060Z,1327085545.5506 [MissionManager](INFO): DefineArg homing_altitude.MassDefault = nan n/a 2012-01-20T18:52:25.55280Z,1327085545.5528 [MissionManager](INFO): DefineArg homing_altitude.BuoyancyNeutral = nan n/a 2012-01-20T18:52:25.55500Z,1327085545.555 [MissionManager](INFO): DefineArg homing_altitude.dockBearing = 10 arcdeg 2012-01-20T18:52:25.55700Z,1327085545.557 [MissionManager](INFO): DefineArg homing_altitude.inTrkOffset = 0 m 2012-01-20T18:52:25.55910Z,1327085545.5591 [MissionManager](INFO): DefineArg homing_altitude.xTrkOffset = 0 m 2012-01-20T18:52:25.56130Z,1327085545.5613 [MissionManager](INFO): DefineArg homing_altitude.finalApproach = 200 m 2012-01-20T18:52:25.56340Z,1327085545.5634 [MissionManager](INFO): DefineArg homing_altitude.clusterRadius = 20 m 2012-01-20T18:52:25.56570Z,1327085545.5657 [MissionManager](INFO): DefineArg homing_altitude.SampleNeilBrown = 1 n/a 2012-01-20T18:52:25.56780Z,1327085545.5678 [MissionManager](INFO): DefineArg homing_altitude.TimeoutDuration = 40 min 2012-01-20T18:52:25.56990Z,1327085545.5699 [MissionManager](INFO): DefineArg homing_altitude.kpAltitude = -0.08 n/a 2012-01-20T18:52:25.57200Z,1327085545.572 [MissionManager](INFO): DefineArg homing_altitude.kiAltitude = 0 n/a 2012-01-20T18:52:25.57400Z,1327085545.574 [MissionManager](INFO): DefineArg homing_altitude.kdAltitude = 0 n/a 2012-01-20T18:52:25.57550Z,1327085545.5755 [homing_altitude:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-01-20T18:52:25.58020Z,1327085545.5802 [homing_altitude:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-01-20T18:52:25.58590Z,1327085545.5859 [homing_altitude:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2012-01-20T18:52:25.59100Z,1327085545.591 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2012-01-20T18:52:25.60900Z,1327085545.609 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfaceDepthRate = nan m/s 2012-01-20T18:52:25.61110Z,1327085545.6111 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfacePitch = nan arcdeg 2012-01-20T18:52:25.61320Z,1327085545.6132 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfaceSpeed = 0.5 m/s 2012-01-20T18:52:25.61530Z,1327085545.6153 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.IridiumTimeout = 30 min 2012-01-20T18:52:25.61620Z,1327085545.6162 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-01-20T18:52:25.62500Z,1327085545.625 [homing_altitude:WaypointOne:B.Pitch](DEBUG): Construct. 2012-01-20T18:52:25.62950Z,1327085545.6295 [homing_altitude:WaypointOne:C.Buoyancy](DEBUG): Construct Buoyancy. 2012-01-20T18:52:25.63440Z,1327085545.6344 [homing_altitude:WaypointOne:D.SetSpeed](DEBUG): Construct. 2012-01-20T18:52:25.63680Z,1327085545.6368 [homing_altitude:WaypointOne:E.PitchServo](DEBUG): Construct. 2012-01-20T18:52:25.64320Z,1327085545.6432 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Waypoint. 2012-01-20T18:52:25.64590Z,1327085545.6459 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Homing. 2012-01-20T18:52:25.65440Z,1327085545.6544 [homing_altitude:H.Execute](DEBUG): Construct Execute. 2012-01-20T18:52:25.66310Z,1327085545.6631 [MissionManager](DEBUG): 36.823 -121.83 10 1 10 0 0 200 20 Set either this or PeakDetectChlActive to True in order to sample from the Neil Brown CTD. Maximum length of mission 40 PID loop parameter for following the bottom. -0.08 PID loop parameter for following the bottom. 0 PID loop parameter for following the bottom. 0 7 0 37 2.0 1 -1 restart logs 2012-01-20T18:52:25.66350Z,1327085545.6635 [CommandLine](IMPORTANT): Loaded ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:25.76430Z,1327085545.7643 [CommandLine](IMPORTANT): got command set homing_altitude.Altitude 9 meter 2012-01-20T18:52:25.90510Z,1327085545.9051 [CommandLine](IMPORTANT): got command set homing_altitude.dockBearing 330 degree 2012-01-20T18:52:26.02430Z,1327085546.0243 [CommandLine](IMPORTANT): got command set homing_altitude.finalApproach 0.1000000015 meter 2012-01-20T18:52:26.02570Z,1327085546.0257 [CommandLine](IMPORTANT): got command run 2012-01-20T18:52:26.02590Z,1327085546.0259 [CommandLine](IMPORTANT): Running 2012-01-20T18:52:26.03840Z,1327085546.0384 [Default] Stopped 2012-01-20T18:52:26.03860Z,1327085546.0386 [Default](INFO): Aggregate::uninitialize Default 2012-01-20T18:52:26.03870Z,1327085546.0387 [Default:GPS] Stopped 2012-01-20T18:52:26.03880Z,1327085546.0388 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-01-20T18:52:26.03890Z,1327085546.0389 [Default:GPS:A.SetSpeed] Stopped 2012-01-20T18:52:26.03900Z,1327085546.039 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:52:26.03910Z,1327085546.0391 [Default:GPS:Read_GPS] Stopped 2012-01-20T18:52:26.03910Z,1327085546.0391 [Default:Iridium] Stopped 2012-01-20T18:52:26.03920Z,1327085546.0392 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-01-20T18:52:26.03930Z,1327085546.0393 [Default:Iridium:A.SetSpeed] Stopped 2012-01-20T18:52:26.03940Z,1327085546.0394 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:52:26.03940Z,1327085546.0394 [Default:Iridium:Read_Iridium] Stopped 2012-01-20T18:52:26.03950Z,1327085546.0395 [Default:CallGPS] Stopped 2012-01-20T18:52:26.03960Z,1327085546.0396 [Default:CallGPS](INFO): Aggregate::uninitialize Default:CallGPS 2012-01-20T18:52:26.03970Z,1327085546.0397 [Default:CallGPS:A] Stopped 2012-01-20T18:52:26.03980Z,1327085546.0398 [Default:CallGPS:A](INFO): Aggregate::uninitialize Default:CallGPS:A 2012-01-20T18:52:26.03990Z,1327085546.0399 [Default:CallIridium] Stopped 2012-01-20T18:52:26.04000Z,1327085546.04 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-01-20T18:52:26.04010Z,1327085546.0401 [Default:CallIridium:A] Stopped 2012-01-20T18:52:26.04020Z,1327085546.0402 [Default:CallIridium:A](INFO): Aggregate::uninitialize Default:CallIridium:A 2012-01-20T18:52:26.04030Z,1327085546.0403 [Default:E.SetSpeed] Stopped 2012-01-20T18:52:26.04030Z,1327085546.0403 [Default:E.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:52:26.04040Z,1327085546.0404 [Default:F.GoToSurface] Stopped 2012-01-20T18:52:26.04050Z,1327085546.0405 [Default:F.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:52:26.04060Z,1327085546.0406 [Default:G.Wait] Stopped 2012-01-20T18:52:26.04060Z,1327085546.0406 [Default:G.Wait](DEBUG): Uninitialize Wait Component. 2012-01-20T18:52:26.04080Z,1327085546.0408 [MissionManager](IMPORTANT): Started mission homing_altitude 2012-01-20T18:52:26.04090Z,1327085546.0409 [homing_altitude] Running Loop=1 2012-01-20T18:52:26.04110Z,1327085546.0411 [homing_altitude](INFO): Aggregate::initialize homing_altitude 2012-01-20T18:52:26.04110Z,1327085546.0411 [homing_altitude:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:52:26.04120Z,1327085546.0412 [homing_altitude:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-01-20T18:52:26.04140Z,1327085546.0414 [homing_altitude:B.DepthEnvelope] Running Loop=1 2012-01-20T18:52:26.04140Z,1327085546.0414 [homing_altitude:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-01-20T18:52:26.04200Z,1327085546.042 [homing_altitude:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:52:26.04210Z,1327085546.0421 [homing_altitude:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2012-01-20T18:52:26.04220Z,1327085546.0422 [homing_altitude:D] Running Loop=1 2012-01-20T18:52:26.04230Z,1327085546.0423 [homing_altitude:SURFACECOMMS] Running Loop=1 2012-01-20T18:52:26.04240Z,1327085546.0424 [homing_altitude:SURFACECOMMS](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS 2012-01-20T18:52:26.04250Z,1327085546.0425 [homing_altitude:SURFACECOMMS:A.GoToSurface] Running Loop=1 2012-01-20T18:52:26.04260Z,1327085546.0426 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:52:26.04420Z,1327085546.0442 [homing_altitude:SURFACECOMMS:B] Running Loop=1 2012-01-20T18:52:26.04440Z,1327085546.0444 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:52:26.04450Z,1327085546.0445 [homing_altitude:SURFACECOMMS:B:A] Running Loop=1 2012-01-20T18:52:26.04460Z,1327085546.0446 [homing_altitude:D] Running Loop=1 2012-01-20T18:52:26.04510Z,1327085546.0451 [homing_altitude:D](DEBUG): Initialize ReadDataComponent to sense platform_orientation 2012-01-20T18:52:26.04590Z,1327085546.0459 [homing_altitude:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:52:26.04670Z,1327085546.0467 [homing_altitude:B.DepthEnvelope] Running Loop=1 2012-01-20T18:52:26.04780Z,1327085546.0478 [homing_altitude:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:52:26.66380Z,1327085546.6638 [homing_altitude:SURFACECOMMS:B:A](DEBUG): Initialize ReadDataComponent to sense time_fix 2012-01-20T18:52:28.65980Z,1327085548.6598 [NAL9601](IMPORTANT): GPS fix at: 1327085513 2012-01-20T18:52:28.67320Z,1327085548.6732 [homing_altitude:SURFACECOMMS:B:A] Stopped 2012-01-20T18:52:28.67350Z,1327085548.6735 [homing_altitude:SURFACECOMMS:B:B] Running Loop=1 2012-01-20T18:52:29.05140Z,1327085549.0514 [homing_altitude:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-01-20T18:52:49.34670Z,1327085569.3467 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=42163, MT Status=1, MTMSN=3479 2012-01-20T18:52:49.52730Z,1327085569.5273 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0005.lzma 2012-01-20T18:52:49.52750Z,1327085569.5275 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:52:49.52870Z,1327085569.5287 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000125 2012-01-20T18:52:50.03220Z,1327085570.0322 [NAL9601](INFO): Received command:load Engineering/Homing_altitude.xml;set homing_altitude.Altitude 9 meter;set homing_altitude.dockBearing 330 degree;set homing_altitude.finalApproach 0.1 meter;run 2012-01-20T18:52:50.06980Z,1327085570.0698 [CommandLine](IMPORTANT): got command load ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:50.06990Z,1327085570.0699 [homing_altitude] Stopped 2012-01-20T18:52:50.07000Z,1327085570.07 [homing_altitude](INFO): Aggregate::uninitialize homing_altitude 2012-01-20T18:52:50.07010Z,1327085570.0701 [homing_altitude:A.AltitudeEnvelope] Stopped 2012-01-20T18:52:50.07020Z,1327085570.0702 [homing_altitude:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-01-20T18:52:50.07030Z,1327085570.0703 [homing_altitude:B.DepthEnvelope] Stopped 2012-01-20T18:52:50.07030Z,1327085570.0703 [homing_altitude:B.DepthEnvelope](DEBUG): Uninitialize. 2012-01-20T18:52:50.07040Z,1327085570.0704 [homing_altitude:C.OffshoreEnvelope] Stopped 2012-01-20T18:52:50.07050Z,1327085570.0705 [homing_altitude:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2012-01-20T18:52:50.07050Z,1327085570.0705 [homing_altitude:D] Stopped 2012-01-20T18:52:50.07060Z,1327085570.0706 [homing_altitude:SURFACECOMMS] Stopped 2012-01-20T18:52:50.07070Z,1327085570.0707 [homing_altitude:SURFACECOMMS](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS 2012-01-20T18:52:50.07100Z,1327085570.071 [homing_altitude:SURFACECOMMS:A.GoToSurface] Stopped 2012-01-20T18:52:50.07100Z,1327085570.071 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:52:50.07110Z,1327085570.0711 [homing_altitude:SURFACECOMMS:B] Stopped 2012-01-20T18:52:50.07120Z,1327085570.0712 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:52:50.07130Z,1327085570.0713 [homing_altitude:SURFACECOMMS:B:B] Stopped 2012-01-20T18:52:50.08070Z,1327085570.0807 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:50.13700Z,1327085570.137 [MissionManager](INFO): DefineArg homing_altitude.Wpt1Lat = 36.823 arcdeg 2012-01-20T18:52:50.13940Z,1327085570.1394 [MissionManager](INFO): DefineArg homing_altitude.Wpt1Lon = -121.83 arcdeg 2012-01-20T18:52:50.14160Z,1327085570.1416 [MissionManager](INFO): DefineArg homing_altitude.Altitude = 10 m 2012-01-20T18:52:50.14390Z,1327085570.1439 [MissionManager](INFO): DefineArg homing_altitude.Speed = 1 m/s 2012-01-20T18:52:50.14610Z,1327085570.1461 [MissionManager](INFO): DefineArg homing_altitude.MassDefault = nan n/a 2012-01-20T18:52:50.14860Z,1327085570.1486 [MissionManager](INFO): DefineArg homing_altitude.BuoyancyNeutral = nan n/a 2012-01-20T18:52:50.15070Z,1327085570.1507 [MissionManager](INFO): DefineArg homing_altitude.dockBearing = 10 arcdeg 2012-01-20T18:52:50.15310Z,1327085570.1531 [MissionManager](INFO): DefineArg homing_altitude.inTrkOffset = 0 m 2012-01-20T18:52:50.15530Z,1327085570.1553 [MissionManager](INFO): DefineArg homing_altitude.xTrkOffset = 0 m 2012-01-20T18:52:50.15750Z,1327085570.1575 [MissionManager](INFO): DefineArg homing_altitude.finalApproach = 200 m 2012-01-20T18:52:50.15990Z,1327085570.1599 [MissionManager](INFO): DefineArg homing_altitude.clusterRadius = 20 m 2012-01-20T18:52:50.16220Z,1327085570.1622 [MissionManager](INFO): DefineArg homing_altitude.SampleNeilBrown = 1 n/a 2012-01-20T18:52:50.16450Z,1327085570.1645 [MissionManager](INFO): DefineArg homing_altitude.TimeoutDuration = 40 min 2012-01-20T18:52:50.16660Z,1327085570.1666 [MissionManager](INFO): DefineArg homing_altitude.kpAltitude = -0.08 n/a 2012-01-20T18:52:50.16870Z,1327085570.1687 [MissionManager](INFO): DefineArg homing_altitude.kiAltitude = 0 n/a 2012-01-20T18:52:50.17090Z,1327085570.1709 [MissionManager](INFO): DefineArg homing_altitude.kdAltitude = 0 n/a 2012-01-20T18:52:50.17230Z,1327085570.1723 [homing_altitude:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-01-20T18:52:50.17700Z,1327085570.177 [homing_altitude:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-01-20T18:52:50.18300Z,1327085570.183 [homing_altitude:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2012-01-20T18:52:50.18800Z,1327085570.188 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2012-01-20T18:52:50.20580Z,1327085570.2058 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfaceDepthRate = nan m/s 2012-01-20T18:52:50.20790Z,1327085570.2079 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfacePitch = nan arcdeg 2012-01-20T18:52:50.21000Z,1327085570.21 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.SurfaceSpeed = 0.5 m/s 2012-01-20T18:52:50.21230Z,1327085570.2123 [MissionManager](INFO): DefineArg homing_altitude:SURFACECOMMS.IridiumTimeout = 30 min 2012-01-20T18:52:50.21320Z,1327085570.2132 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-01-20T18:52:50.22200Z,1327085570.222 [homing_altitude:WaypointOne:B.Pitch](DEBUG): Construct. 2012-01-20T18:52:50.22670Z,1327085570.2267 [homing_altitude:WaypointOne:C.Buoyancy](DEBUG): Construct Buoyancy. 2012-01-20T18:52:50.22930Z,1327085570.2293 [homing_altitude:WaypointOne:D.SetSpeed](DEBUG): Construct. 2012-01-20T18:52:50.23180Z,1327085570.2318 [homing_altitude:WaypointOne:E.PitchServo](DEBUG): Construct. 2012-01-20T18:52:50.23810Z,1327085570.2381 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Waypoint. 2012-01-20T18:52:50.24080Z,1327085570.2408 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Construct Homing. 2012-01-20T18:52:50.24940Z,1327085570.2494 [homing_altitude:H.Execute](DEBUG): Construct Execute. 2012-01-20T18:52:50.25820Z,1327085570.2582 [MissionManager](DEBUG): 36.823 -121.83 10 1 10 0 0 200 20 Set either this or PeakDetectChlActive to True in order to sample from the Neil Brown CTD. Maximum length of mission 40 PID loop parameter for following the bottom. -0.08 PID loop parameter for following the bottom. 0 PID loop parameter for following the bottom. 0 7 0 37 2.0 1 -1 restart logs 2012-01-20T18:52:50.25860Z,1327085570.2586 [CommandLine](IMPORTANT): Loaded ./Missions/Engineering/Homing_altitude.xml 2012-01-20T18:52:50.36260Z,1327085570.3626 [CommandLine](IMPORTANT): got command set homing_altitude.Altitude 9 meter 2012-01-20T18:52:50.49300Z,1327085570.493 [CommandLine](IMPORTANT): got command set homing_altitude.dockBearing 330 degree 2012-01-20T18:52:50.60920Z,1327085570.6092 [CommandLine](IMPORTANT): got command set homing_altitude.finalApproach 0.1000000015 meter 2012-01-20T18:52:50.61050Z,1327085570.6105 [CommandLine](IMPORTANT): got command run 2012-01-20T18:52:50.61070Z,1327085570.6107 [CommandLine](IMPORTANT): Running 2012-01-20T18:52:50.62420Z,1327085570.6242 [MissionManager](IMPORTANT): Started mission homing_altitude 2012-01-20T18:52:50.62440Z,1327085570.6244 [homing_altitude] Running Loop=1 2012-01-20T18:52:50.62450Z,1327085570.6245 [homing_altitude](INFO): Aggregate::initialize homing_altitude 2012-01-20T18:52:50.62460Z,1327085570.6246 [homing_altitude:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:52:50.62470Z,1327085570.6247 [homing_altitude:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-01-20T18:52:50.62480Z,1327085570.6248 [homing_altitude:B.DepthEnvelope] Running Loop=1 2012-01-20T18:52:50.62490Z,1327085570.6249 [homing_altitude:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-01-20T18:52:50.62550Z,1327085570.6255 [homing_altitude:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:52:50.62560Z,1327085570.6256 [homing_altitude:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2012-01-20T18:52:50.62570Z,1327085570.6257 [homing_altitude:D] Running Loop=1 2012-01-20T18:52:50.62580Z,1327085570.6258 [homing_altitude:SURFACECOMMS] Running Loop=1 2012-01-20T18:52:50.62590Z,1327085570.6259 [homing_altitude:SURFACECOMMS](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS 2012-01-20T18:52:50.62600Z,1327085570.626 [homing_altitude:SURFACECOMMS:A.GoToSurface] Running Loop=1 2012-01-20T18:52:50.62610Z,1327085570.6261 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:52:50.62790Z,1327085570.6279 [homing_altitude:SURFACECOMMS:B] Running Loop=1 2012-01-20T18:52:50.62800Z,1327085570.628 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:52:50.62820Z,1327085570.6282 [homing_altitude:SURFACECOMMS:B:A] Running Loop=1 2012-01-20T18:52:50.62820Z,1327085570.6282 [homing_altitude:D] Running Loop=1 2012-01-20T18:52:50.62870Z,1327085570.6287 [homing_altitude:D](DEBUG): Initialize ReadDataComponent to sense platform_orientation 2012-01-20T18:52:50.62950Z,1327085570.6295 [homing_altitude:C.OffshoreEnvelope] Running Loop=1 2012-01-20T18:52:50.63040Z,1327085570.6304 [homing_altitude:B.DepthEnvelope] Running Loop=1 2012-01-20T18:52:50.63400Z,1327085570.634 [homing_altitude:A.AltitudeEnvelope] Running Loop=1 2012-01-20T18:52:51.33400Z,1327085571.334 [homing_altitude:SURFACECOMMS:B:A](DEBUG): Initialize ReadDataComponent to sense time_fix 2012-01-20T18:52:53.31460Z,1327085573.3146 [NAL9601](IMPORTANT): GPS fix at: 1327085537 2012-01-20T18:52:53.32790Z,1327085573.3279 [homing_altitude:SURFACECOMMS:B:A] Stopped 2012-01-20T18:52:53.32810Z,1327085573.3281 [homing_altitude:SURFACECOMMS:B:B] Running Loop=1 2012-01-20T18:52:53.69280Z,1327085573.6928 [homing_altitude:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-01-20T18:53:03.18570Z,1327085583.1857 [NAL9601](INFO): SBD MO Status=1, MOMSN=42164, MT Status=0, MTMSN=0 2012-01-20T18:53:03.30340Z,1327085583.3034 [NAL9601](INFO): Sent 266 bytes from file Logs/20120120T181903/shore0005.lzma 2012-01-20T18:53:03.30360Z,1327085583.3036 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:53:03.30470Z,1327085583.3047 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000126 2012-01-20T18:53:11.98800Z,1327085591.988 [NAL9601](INFO): SBD MO Status=0, MOMSN=42165, MT Status=0, MTMSN=0 2012-01-20T18:53:24.33390Z,1327085604.3339 [NAL9601](INFO): SBD MO Status=1, MOMSN=42166, MT Status=0, MTMSN=0 2012-01-20T18:53:24.47130Z,1327085604.4713 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0006.lzma 2012-01-20T18:53:24.47150Z,1327085604.4715 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:53:24.47270Z,1327085604.4727 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000127 2012-01-20T18:53:32.07730Z,1327085612.0773 [NAL9601](INFO): SBD MO Status=1, MOMSN=42167, MT Status=0, MTMSN=0 2012-01-20T18:53:32.25930Z,1327085612.2593 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0006.lzma 2012-01-20T18:53:32.25950Z,1327085612.2595 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:53:32.26140Z,1327085612.2614 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000128 2012-01-20T18:53:40.32040Z,1327085620.3204 [NAL9601](INFO): SBD MO Status=1, MOMSN=42168, MT Status=0, MTMSN=0 2012-01-20T18:53:40.44730Z,1327085620.4473 [NAL9601](INFO): Sent 230 bytes from file Logs/20120120T181903/shore0006.lzma 2012-01-20T18:53:40.44760Z,1327085620.4476 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:53:40.44870Z,1327085620.4487 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000129 2012-01-20T18:53:45.85490Z,1327085625.8549 [NAL9601](INFO): SBD MO Status=0, MOMSN=42169, MT Status=0, MTMSN=0 2012-01-20T18:53:46.05280Z,1327085626.0528 [homing_altitude:SURFACECOMMS:B:B] Stopped 2012-01-20T18:53:46.05300Z,1327085626.053 [homing_altitude:SURFACECOMMS:B:C] Running Loop=1 2012-01-20T18:53:46.25910Z,1327085626.2591 [homing_altitude:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2012-01-20T18:53:48.25230Z,1327085628.2523 [NAL9601](IMPORTANT): GPS fix at: 1327085626 2012-01-20T18:53:48.26580Z,1327085628.2658 [homing_altitude:SURFACECOMMS:B:C] Stopped 2012-01-20T18:53:48.26610Z,1327085628.2661 [homing_altitude:SURFACECOMMS:B](INFO): Completed homing_altitude:SURFACECOMMS:B 2012-01-20T18:53:48.26610Z,1327085628.2661 [homing_altitude:SURFACECOMMS:B] Stopped 2012-01-20T18:53:48.26630Z,1327085628.2663 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:53:48.26670Z,1327085628.2667 [homing_altitude:SURFACECOMMS](INFO): Completed homing_altitude:SURFACECOMMS 2012-01-20T18:53:48.26680Z,1327085628.2668 [homing_altitude:SURFACECOMMS] Stopped 2012-01-20T18:53:48.26700Z,1327085628.267 [homing_altitude:SURFACECOMMS](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS 2012-01-20T18:53:48.26700Z,1327085628.267 [homing_altitude:SURFACECOMMS:A.GoToSurface] Stopped 2012-01-20T18:53:48.26710Z,1327085628.2671 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:53:48.26730Z,1327085628.2673 [homing_altitude:WaypointOne] Running Loop=1 2012-01-20T18:53:48.26740Z,1327085628.2674 [homing_altitude:WaypointOne](INFO): Aggregate::initialize homing_altitude:WaypointOne 2012-01-20T18:53:48.26750Z,1327085628.2675 [homing_altitude:WaypointOne:A] Running Loop=1 2012-01-20T18:53:48.26750Z,1327085628.2675 [homing_altitude:WaypointOne:B.Pitch] Running Loop=1 2012-01-20T18:53:48.26760Z,1327085628.2676 [homing_altitude:WaypointOne:B.Pitch](DEBUG): Initialize. 2012-01-20T18:53:48.26780Z,1327085628.2678 [homing_altitude:WaypointOne:C.Buoyancy] Running Loop=1 2012-01-20T18:53:48.26790Z,1327085628.2679 [homing_altitude:WaypointOne:C.Buoyancy](DEBUG): Initialize Buoyancy Component. 2012-01-20T18:53:48.26830Z,1327085628.2683 [homing_altitude:WaypointOne:D.SetSpeed] Running Loop=1 2012-01-20T18:53:48.26840Z,1327085628.2684 [homing_altitude:WaypointOne:D.SetSpeed](DEBUG): Initialize. 2012-01-20T18:53:48.26850Z,1327085628.2685 [homing_altitude:WaypointOne:E.PitchServo] Running Loop=1 2012-01-20T18:53:48.26850Z,1327085628.2685 [homing_altitude:WaypointOne:E.PitchServo](DEBUG): Initialize. 2012-01-20T18:53:48.26880Z,1327085628.2688 [homing_altitude:WaypointOne:E.PitchServo](INFO): Initialize with holdValue=height_above_sea_floor 2012-01-20T18:53:48.26970Z,1327085628.2697 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint] Running Loop=1 2012-01-20T18:53:48.26970Z,1327085628.2697 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Initialize HomingComponent. 2012-01-20T18:53:48.26980Z,1327085628.2698 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Initialize WaypointComponent. 2012-01-20T18:53:48.64730Z,1327085628.6473 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon has exited the DAT FOV with dtw = 787.55. Turning DAT off. 2012-01-20T18:53:48.64890Z,1327085628.6489 [homing_altitude:WaypointOne:E.PitchServo] Running Loop=1 2012-01-20T18:53:48.64980Z,1327085628.6498 [homing_altitude:WaypointOne:D.SetSpeed] Running Loop=1 2012-01-20T18:53:48.65050Z,1327085628.6505 [homing_altitude:WaypointOne:C.Buoyancy] Running Loop=1 2012-01-20T18:53:48.65180Z,1327085628.6518 [homing_altitude:WaypointOne:B.Pitch] Running Loop=1 2012-01-20T18:53:48.65270Z,1327085628.6527 [homing_altitude:WaypointOne:A] Running Loop=1 2012-01-20T18:53:48.65320Z,1327085628.6532 [homing_altitude:WaypointOne:A](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2012-01-20T18:53:48.65370Z,1327085628.6537 [homing_altitude:WaypointOne:A](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2012-01-20T18:53:54.65300Z,1327085634.653 [NAL9601](INFO): Powering down 2012-01-20T18:54:04.96210Z,1327085644.9621 [Radio_Freewave](INFO): Powering down 2012-01-20T18:54:05.28980Z,1327085645.2898 [Radio_Freewave](INFO): Powering up 2012-01-20T18:54:06.88030Z,1327085646.8803 [Radio_Freewave](INFO): Powering down 2012-01-20T18:54:12.55750Z,1327085652.5575 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 796.42. Turning DAT on. 2012-01-20T18:54:12.88600Z,1327085652.886 [DAT](INFO): Powering up 2012-01-20T18:54:27.56110Z,1327085667.5611 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: The Usbl has 1 transponder hits. 2012-01-20T18:54:27.81700Z,1327085667.817 [Radio_Freewave](INFO): Powering up 2012-01-20T18:54:27.82880Z,1327085667.8288 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon has exited the DAT FOV with dtw = 39.15. Turning DAT off. 2012-01-20T18:54:28.61250Z,1327085668.6125 [DAT](INFO): Powering down 2012-01-20T18:54:41.08970Z,1327085681.0897 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 43.57. Turning DAT on. 2012-01-20T18:54:41.80520Z,1327085681.8052 [DAT](INFO): Powering up 2012-01-20T18:54:56.47070Z,1327085696.4707 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: The Usbl has 2 transponder hits. 2012-01-20T18:54:56.83640Z,1327085696.8364 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon has exited the DAT FOV with dtw = 39.12. Turning DAT off. 2012-01-20T18:54:57.61390Z,1327085697.6139 [DAT](INFO): Powering down 2012-01-20T18:55:12.14160Z,1327085712.1416 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 46.15. Turning DAT on. 2012-01-20T18:55:12.50150Z,1327085712.5015 [DAT](INFO): Powering up 2012-01-20T18:55:21.79770Z,1327085721.7977 [Radio_Freewave](INFO): Powering down 2012-01-20T18:55:26.95720Z,1327085726.9572 [Radio_Freewave](INFO): Powering up 2012-01-20T18:55:27.43950Z,1327085727.4395 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: The Usbl has 3 transponder hits. 2012-01-20T18:55:27.77360Z,1327085727.7736 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon has exited the DAT FOV with dtw = 39.17. Turning DAT off. 2012-01-20T18:55:28.95140Z,1327085728.9514 [DAT](INFO): Powering down 2012-01-20T18:55:32.82690Z,1327085732.8269 [AHRS_sp3003D](FAULT): Read Heading/Pitch/Roll Failure. 2012-01-20T18:55:32.82700Z,1327085732.827 [AHRS_sp3003D] Communications Fault, FailCount= 1 2012-01-20T18:55:32.82710Z,1327085732.8271 [AHRS_sp3003D](ERROR): Communications Fault 2012-01-20T18:55:32.98190Z,1327085732.9819 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2012-01-20T18:55:33.15220Z,1327085733.1522 [AHRS_sp3003D](INFO): Powering down 2012-01-20T18:55:33.54510Z,1327085733.5451 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2012-01-20T18:55:33.54520Z,1327085733.5452 [AHRS_sp3003D] No Fault, FailCount= 1 2012-01-20T18:55:34.40040Z,1327085734.4004 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-01-20T18:55:39.96180Z,1327085739.9618 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 43.76. Turning DAT on. 2012-01-20T18:55:40.26490Z,1327085740.2649 [DAT](INFO): Powering up 2012-01-20T18:55:40.27610Z,1327085740.2761 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon has exited the DAT FOV with dtw = 43.70. Turning DAT off. 2012-01-20T18:55:41.08060Z,1327085741.0806 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Homing:: Beacon is in the DAT FOV with dtw = 43.53. Turning DAT on. 2012-01-20T18:56:07.82690Z,1327085767.8269 [DAT](ERROR): No response from remote modem 2012-01-20T18:56:20.69890Z,1327085780.6989 [DAT](ERROR): No response from remote modem 2012-01-20T18:56:29.67630Z,1327085789.6763 [Batt_Ocean_Server](INFO): Over Temperature Alarm! Battery Bank #5 STATUS: 5911 2012-01-20T18:56:29.67660Z,1327085789.6766 [Batt_Ocean_Server](INFO): Not Initialized - Battery Bank #5 STATUS: 5911 2012-01-20T18:56:38.93420Z,1327085798.9342 [Batt_Ocean_Server](INFO): Over Temperature Alarm! Battery Bank #4 STATUS: 5911 2012-01-20T18:56:38.93450Z,1327085798.9345 [Batt_Ocean_Server](INFO): Not Initialized - Battery Bank #4 STATUS: 5911 2012-01-20T18:56:39.77490Z,1327085799.7749 [DAT](ERROR): No response from remote modem 2012-01-20T18:56:44.47900Z,1327085804.479 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](IMPORTANT): Homing:: Terminating now. dtw = -0.1 m, DATRange = nan m. 2012-01-20T18:56:44.47960Z,1327085804.4796 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](INFO): Homing::Reached Waypoint 36.8304407,-121.8311333 2012-01-20T18:56:44.47990Z,1327085804.4799 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint] Stopped 2012-01-20T18:56:44.47990Z,1327085804.4799 [homing_altitude:WaypointOne:WaypointW1.HomingWaypoint](DEBUG): Uninitialize HomingComponent. 2012-01-20T18:56:44.48120Z,1327085804.4812 [homing_altitude:WaypointOne](INFO): Completed homing_altitude:WaypointOne 2012-01-20T18:56:44.48130Z,1327085804.4813 [homing_altitude:WaypointOne] Stopped 2012-01-20T18:56:44.48140Z,1327085804.4814 [homing_altitude:WaypointOne](INFO): Aggregate::uninitialize homing_altitude:WaypointOne 2012-01-20T18:56:44.48150Z,1327085804.4815 [homing_altitude:WaypointOne:A] Stopped 2012-01-20T18:56:44.48150Z,1327085804.4815 [homing_altitude:WaypointOne:B.Pitch] Stopped 2012-01-20T18:56:44.48160Z,1327085804.4816 [homing_altitude:WaypointOne:C.Buoyancy] Stopped 2012-01-20T18:56:44.48160Z,1327085804.4816 [homing_altitude:WaypointOne:C.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2012-01-20T18:56:44.48170Z,1327085804.4817 [homing_altitude:WaypointOne:D.SetSpeed] Stopped 2012-01-20T18:56:44.48180Z,1327085804.4818 [homing_altitude:WaypointOne:D.SetSpeed](DEBUG): Uninitialize. 2012-01-20T18:56:44.48190Z,1327085804.4819 [homing_altitude:WaypointOne:E.PitchServo] Stopped 2012-01-20T18:56:44.48190Z,1327085804.4819 [homing_altitude:WaypointOne:E.PitchServo](DEBUG): Uninitialize. 2012-01-20T18:56:44.48210Z,1327085804.4821 [homing_altitude:PHONEHOMEWPT1] Running Loop=1 2012-01-20T18:56:44.48220Z,1327085804.4822 [homing_altitude:PHONEHOMEWPT1](INFO): Aggregate::initialize homing_altitude:PHONEHOMEWPT1 2012-01-20T18:56:44.93270Z,1327085804.9327 [homing_altitude:SURFACECOMMS] Running Loop=1 2012-01-20T18:56:44.93290Z,1327085804.9329 [homing_altitude:SURFACECOMMS](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS 2012-01-20T18:56:44.93300Z,1327085804.933 [homing_altitude:SURFACECOMMS:A.GoToSurface] Running Loop=1 2012-01-20T18:56:44.93310Z,1327085804.9331 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:56:44.93420Z,1327085804.9342 [homing_altitude:SURFACECOMMS:B] Running Loop=1 2012-01-20T18:56:44.93440Z,1327085804.9344 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::initialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:56:44.93450Z,1327085804.9345 [homing_altitude:SURFACECOMMS:B:A] Running Loop=1 2012-01-20T18:56:45.31280Z,1327085805.3128 [DAT](INFO): Powering down 2012-01-20T18:56:46.38440Z,1327085806.3844 [NAL9601](INFO): Powering up 2012-01-20T18:57:51.89540Z,1327085871.8954 [NAL9601](INFO): NAL9601 initialized 2012-01-20T18:57:53.08730Z,1327085873.0873 [NAL9601](IMPORTANT): GPS fix at: 1327085838 2012-01-20T18:57:53.10070Z,1327085873.1007 [homing_altitude:SURFACECOMMS:B:A] Stopped 2012-01-20T18:57:53.10090Z,1327085873.1009 [homing_altitude:SURFACECOMMS:B:B] Running Loop=1 2012-01-20T18:58:13.83830Z,1327085893.8383 [NAL9601](INFO): SBD MO Status=1, MOMSN=42170, MT Status=0, MTMSN=0 2012-01-20T18:58:14.05130Z,1327085894.0513 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:14.05150Z,1327085894.0515 [NAL9601](INFO): Packets left to send: 7 2012-01-20T18:58:14.05270Z,1327085894.0527 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000130 2012-01-20T18:58:22.32900Z,1327085902.329 [NAL9601](INFO): SBD MO Status=1, MOMSN=42171, MT Status=0, MTMSN=0 2012-01-20T18:58:22.53930Z,1327085902.5393 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:22.53950Z,1327085902.5395 [NAL9601](INFO): Packets left to send: 6 2012-01-20T18:58:22.54060Z,1327085902.5406 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000131 2012-01-20T18:58:30.83370Z,1327085910.8337 [NAL9601](INFO): SBD MO Status=1, MOMSN=42172, MT Status=0, MTMSN=0 2012-01-20T18:58:31.02330Z,1327085911.0233 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:31.02360Z,1327085911.0236 [NAL9601](INFO): Packets left to send: 5 2012-01-20T18:58:31.02470Z,1327085911.0247 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000132 2012-01-20T18:58:39.39340Z,1327085919.3934 [NAL9601](INFO): SBD MO Status=1, MOMSN=42173, MT Status=0, MTMSN=0 2012-01-20T18:58:39.61130Z,1327085919.6113 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:39.61160Z,1327085919.6116 [NAL9601](INFO): Packets left to send: 4 2012-01-20T18:58:39.61350Z,1327085919.6135 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000133 2012-01-20T18:58:49.07780Z,1327085929.0778 [NAL9601](INFO): SBD MO Status=1, MOMSN=42174, MT Status=0, MTMSN=0 2012-01-20T18:58:49.19530Z,1327085929.1953 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:49.19550Z,1327085929.1955 [NAL9601](INFO): Packets left to send: 3 2012-01-20T18:58:49.19660Z,1327085929.1966 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000134 2012-01-20T18:58:56.87380Z,1327085936.8738 [NAL9601](INFO): SBD MO Status=1, MOMSN=42175, MT Status=0, MTMSN=0 2012-01-20T18:58:57.08340Z,1327085937.0834 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:58:57.08360Z,1327085937.0836 [NAL9601](INFO): Packets left to send: 2 2012-01-20T18:58:57.08470Z,1327085937.0847 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000135 2012-01-20T18:59:05.83380Z,1327085945.8338 [NAL9601](INFO): SBD MO Status=1, MOMSN=42176, MT Status=0, MTMSN=0 2012-01-20T18:59:05.96750Z,1327085945.9675 [NAL9601](INFO): Sent 332 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:59:05.96770Z,1327085945.9677 [NAL9601](INFO): Packets left to send: 1 2012-01-20T18:59:05.96890Z,1327085945.9689 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000136 2012-01-20T18:59:15.12580Z,1327085955.1258 [NAL9601](INFO): SBD MO Status=1, MOMSN=42177, MT Status=0, MTMSN=0 2012-01-20T18:59:15.25530Z,1327085955.2553 [NAL9601](INFO): Sent 89 bytes from file Logs/20120120T181903/shore0007.lzma 2012-01-20T18:59:15.25550Z,1327085955.2555 [NAL9601](INFO): Packets left to send: 0 2012-01-20T18:59:15.25670Z,1327085955.2567 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000137 2012-01-20T18:59:24.72480Z,1327085964.7248 [NAL9601](INFO): SBD MO Status=0, MOMSN=42178, MT Status=0, MTMSN=0 2012-01-20T18:59:24.95190Z,1327085964.9519 [homing_altitude:SURFACECOMMS:B:B] Stopped 2012-01-20T18:59:24.95210Z,1327085964.9521 [homing_altitude:SURFACECOMMS:B:C] Running Loop=1 2012-01-20T18:59:27.14420Z,1327085967.1442 [NAL9601](IMPORTANT): GPS fix at: 1327085932 2012-01-20T18:59:27.15770Z,1327085967.1577 [homing_altitude:SURFACECOMMS:B:C] Stopped 2012-01-20T18:59:27.15800Z,1327085967.158 [homing_altitude:SURFACECOMMS:B](INFO): Completed homing_altitude:SURFACECOMMS:B 2012-01-20T18:59:27.15810Z,1327085967.1581 [homing_altitude:SURFACECOMMS:B] Stopped 2012-01-20T18:59:27.15820Z,1327085967.1582 [homing_altitude:SURFACECOMMS:B](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS:B 2012-01-20T18:59:27.15870Z,1327085967.1587 [homing_altitude:SURFACECOMMS](INFO): Completed homing_altitude:SURFACECOMMS 2012-01-20T18:59:27.15890Z,1327085967.1589 [homing_altitude:SURFACECOMMS] Stopped 2012-01-20T18:59:27.15900Z,1327085967.159 [homing_altitude:SURFACECOMMS](INFO): Aggregate::uninitialize homing_altitude:SURFACECOMMS 2012-01-20T18:59:27.15910Z,1327085967.1591 [homing_altitude:SURFACECOMMS:A.GoToSurface] Stopped 2012-01-20T18:59:27.15910Z,1327085967.1591 [homing_altitude:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:59:27.53630Z,1327085967.5363 [homing_altitude:PHONEHOMEWPT1](INFO): Completed homing_altitude:PHONEHOMEWPT1 2012-01-20T18:59:27.53640Z,1327085967.5364 [homing_altitude:PHONEHOMEWPT1] Stopped 2012-01-20T18:59:27.53650Z,1327085967.5365 [homing_altitude:PHONEHOMEWPT1](INFO): Aggregate::uninitialize homing_altitude:PHONEHOMEWPT1 2012-01-20T18:59:27.53670Z,1327085967.5367 [homing_altitude:H.Execute] Running Loop=1 2012-01-20T18:59:28.01450Z,1327085968.0145 [homing_altitude:H.Execute](INFO): Executing command restart logs 2012-01-20T18:59:28.01620Z,1327085968.0162 [homing_altitude:H.Execute] Stopped 2012-01-20T18:59:28.01750Z,1327085968.0175 [homing_altitude](INFO): Completed homing_altitude 2012-01-20T18:59:28.01750Z,1327085968.0175 [homing_altitude] Stopped 2012-01-20T18:59:28.01770Z,1327085968.0177 [homing_altitude](INFO): Aggregate::uninitialize homing_altitude 2012-01-20T18:59:28.01770Z,1327085968.0177 [homing_altitude:A.AltitudeEnvelope] Stopped 2012-01-20T18:59:28.01780Z,1327085968.0178 [homing_altitude:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-01-20T18:59:28.01790Z,1327085968.0179 [homing_altitude:B.DepthEnvelope] Stopped 2012-01-20T18:59:28.01800Z,1327085968.018 [homing_altitude:B.DepthEnvelope](DEBUG): Uninitialize. 2012-01-20T18:59:28.01800Z,1327085968.018 [homing_altitude:C.OffshoreEnvelope] Stopped 2012-01-20T18:59:28.01810Z,1327085968.0181 [homing_altitude:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2012-01-20T18:59:28.01820Z,1327085968.0182 [homing_altitude:D] Stopped 2012-01-20T18:59:28.09530Z,1327085968.0953 [CommandLine](IMPORTANT): got command restart logs 2012-01-20T18:59:28.35720Z,1327085968.3572 [MissionManager](IMPORTANT): Started mission Default 2012-01-20T18:59:28.35730Z,1327085968.3573 [Default] Running Loop=1 2012-01-20T18:59:28.35750Z,1327085968.3575 [Default](INFO): Aggregate::initialize Default 2012-01-20T18:59:28.35760Z,1327085968.3576 [Default:E.SetSpeed] Running Loop=1 2012-01-20T18:59:28.35760Z,1327085968.3576 [Default:E.SetSpeed](DEBUG): Initialize. 2012-01-20T18:59:28.35770Z,1327085968.3577 [Default:F.GoToSurface] Running Loop=1 2012-01-20T18:59:28.35780Z,1327085968.3578 [Default:F.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:59:28.35830Z,1327085968.3583 [Default:GPS] Running Loop=1 2012-01-20T18:59:28.35840Z,1327085968.3584 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-01-20T18:59:28.35850Z,1327085968.3585 [Default:GPS:A.SetSpeed] Running Loop=1 2012-01-20T18:59:28.35850Z,1327085968.3585 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-01-20T18:59:28.35870Z,1327085968.3587 [Default:GPS:B.GoToSurface] Running Loop=1 2012-01-20T18:59:28.35880Z,1327085968.3588 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-01-20T18:59:28.36050Z,1327085968.3605 [Default:GPS:B.GoToSurface] Stopped 2012-01-20T18:59:28.36050Z,1327085968.3605 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-01-20T18:59:28.36070Z,1327085968.3607 [Default:GPS:Read_GPS] Running Loop=1