2019-05-29T07:34:25.418Z,1559115265.418 [ESPComponent] Loaded
2019-05-29T07:34:25.418Z,1559115265.418 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-05-29T07:34:26.487Z,1559115266.487 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-29T07:35:41.398Z,1559115341.398 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2019-05-29T09:39:02.665Z,1559122742.665 [Smear:ESPSampling:TriggerESP:E](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2019-05-29T09:39:03.434Z,1559122743.434 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::'
2019-05-29T09:39:03.529Z,1559122743.529 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::"
2019-05-29T09:39:03.834Z,1559122743.834 [ESPComponent](INFO): powering up ESP
2019-05-29T09:39:03.835Z,1559122743.835 [ESPComponent](INFO): powering up ESP secondary power supply
2019-05-29T09:39:03.854Z,1559122743.854 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.8.2:10.89.8.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2019-05-29T09:39:04.299Z,1559122744.299 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2019-05-29T09:39:38.005Z,1559122778.005 [ESPComponent](IMPORTANT): ESP has connected as client
2019-05-29T09:39:38.955Z,1559122778.955 [ESPComponent](IMPORTANT): [sample #1] Explicit cartridge argument not given
2019-05-29T09:39:38.956Z,1559122778.956 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT
2019-05-29T09:39:38.956Z,1559122778.956 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2019-05-29T09:39:39.698Z,1559122779.698 [Smear:ESPSampling:TriggerESP:G](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2019-05-29T09:39:40.040Z,1559122780.040 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG
2019-05-29T09:39:40.419Z,1559122780.419 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS
2019-05-29T09:39:42.029Z,1559122782.029 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE
2019-05-29T09:40:14.858Z,1559122814.858 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@58)
2019-05-29T09:40:16.448Z,1559122816.448 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@0.0)
2019-05-29T09:40:17.263Z,1559122817.263 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@0.0)
2019-05-29T09:42:47.995Z,1559122967.995 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0)
2019-05-29T09:42:48.438Z,1559122968.438 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)
2019-05-29T10:07:36.490Z,1559124456.490 [ESPComponent](DEBUG): Resetting stopSampling to false
2019-05-29T10:07:36.491Z,1559124456.491 [ESPComponent](IMPORTANT): [sample #1] Stop sampling requested.
2019-05-29T10:07:36.890Z,1559124456.890 [ESPComponent](IMPORTANT): Stop sampling requested. Issuing Cmd.pauseFiltering
2019-05-29T10:07:42.323Z,1559124462.323 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@486.135)
2019-05-29T10:07:42.324Z,1559124462.324 [ESPComponent](DEBUG): Writing sampleVolume=486.135010
2019-05-29T10:07:42.721Z,1559124462.721 [ESPComponent](IMPORTANT): In S_PAUSED received result: 486.135
2019-05-29T10:07:43.127Z,1559124463.127 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@486.135)
2019-05-29T10:07:46.356Z,1559124466.356 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@58)
2019-05-29T10:19:09.924Z,1559125149.924 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@58)
2019-05-29T10:19:34.977Z,1559125174.977 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally.
2019-05-29T10:19:34.977Z,1559125174.977 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=1
2019-05-29T10:19:35.384Z,1559125175.384 [ESPComponent](DEBUG): Resetting stopSampling to false
2019-05-29T10:19:35.386Z,1559125175.386 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages):
2019-05-29T10:19:35.387Z,1559125175.387 [ESPComponent](INFO): powering down ESP
2019-05-29T10:19:35.387Z,1559125175.387 [ESPComponent](INFO): powering down ESP secondary power supply