@16:36:41.92PST30-Jan-18 <MAIN> >BREAK< ESP3 Gateway v0.80 for core bus
@16:36:42.88 
Configuration for koa by brent@mbari.org
/home/esp/esp2/type/auv/koa/configure.rb
@16:36:43.83 Polling Can every 10:00
@16:36:44.09 Clients may connect on TCP port 9999
@16:36:44.10 Connecting to 134.89.95.2:9999
@16:36:44.13 Errno::ECONNREFUSED in MAIN -- Could not connect to initial client because Connection refused - connect(2)
@16:36:44.14 Waiting for espclients...
@16:36:56.35 <preston> Session Begun
@16:46:43.10 -> ESP.configure
@16:46:43.15 Powering core bus
@16:46:45.83 ArS.configure ArSconfig
@16:46:45.93 LyS1.configure LyS1config
@16:46:46.05 LyS2.configure LyS2config
@16:46:46.16 AirS.configure AirSconfig
@16:46:46.27 TV.configure TVconfig
@16:46:46.39 SP.configure SPconfig
@16:46:46.51 Sea.configure SPconfig
@16:46:46.65 SC.configure SCconfig
@16:46:46.77 PV.configure PVconfig
@16:46:46.82 All elf controllers running firmware version 4.41
@16:46:46.84 Gate.power :main,:ON,limit to 5000mA
@16:46:46.86 Gate.power :motor,:ON,limit to 5000mA
@16:46:46.95 <closeIntake> Intake.close
@16:46:46.99 <closeExhaust> Exhaust.close
@16:46:47.02 <closePB> PB.close
@16:46:55.38 <preston> -> SC.monitorAbsPos
@16:46:55.40 SC.configure #<struct I2C::Servo::Configuration updatePeriod=50, encoder=:positive, threshold=:off, home=:off, jogHome=false, homeDirection=:reverse, thresholdOffset=0, maxPositionErr=45, stopWindow=31748, gain=#<struct PIDgain P=2, I=17, D=27>, acceleration=1000, deceleration=0, stopRate=0, maxSpeed=2000, minSpeed=0, maxPWM=40, minPWM=14, maxSettling=150, maxCurrent=0, stiction=0, friction=-32240, hunt=false, brake=false, maxDeltaPress=12, maxInPress=0, maxOutPress=0, minDeltaPress=17890, minInPress=0, minOutPress=0, pressBias=0, pressGain=0, inputDeltaPress=false, externalCurrent=false, debug=false>
@16:46:55.62 SC: absPos=40918, freqShift=-2203, B/A mismatch=-800, amplitude=6656/6656
@16:46:56.28 SC: absPos=40918, freqShift=-2189, B/A mismatch=-922, amplitude=6656/6656
@16:46:56.94 SC: absPos=40918, freqShift=-2190, B/A mismatch=-977, amplitude=6656/6656
@16:46:57.79 SC: absPos=40918, freqShift=-2200, B/A mismatch=-956, amplitude=6656/6656
@16:46:58.47 SC: absPos=40918, freqShift=-2197, B/A mismatch=-886, amplitude=6656/6656
@16:46:59.13 SC: absPos=40918, freqShift=-2194, B/A mismatch=-866, amplitude=6656/6656
@16:46:59.79 SC: absPos=40918, freqShift=-2196, B/A mismatch=-817, amplitude=6656/6656
@16:47:00.46 SC: absPos=40918, freqShift=-2202, B/A mismatch=-848, amplitude=6656/6656
@16:47:01.12 SC: absPos=40918, freqShift=-2203, B/A mismatch=-921, amplitude=6656/6656
@16:47:01.78 SC: absPos=40918, freqShift=-2192, B/A mismatch=-970, amplitude=6656/6656
@16:47:02.46 Errno::EPIPE in preston aborter-'s_reader -- Broken pipe
@16:47:02.48 UserAbort in preston -- 
@16:47:02.50 Errno::EPIPE in preston's_reader -- Broken pipe
@16:47:44.40 <preston> Session Begun
@16:47:59.86 -> ESP.ready!
@16:48:00.18 <ArS_home> ArS.reconfigure ArSconfig
@16:48:00.22 <LyS2_home> LyS2.reconfigure LyS2config
@16:48:00.30 <LyS1_home> LyS1.reconfigure LyS1config
@16:48:00.40 <AirS_home> AirS.reconfigure AirSconfig
@16:48:00.45 <TV_home> TV.reconfigure TVconfig
@16:48:00.51 <ArS_home> ArS.home.jog 0
@16:48:00.55 <LyS2_home> LyS2.home.jog 0
@16:48:00.59 <PV_home> PV.reconfigure PVconfig
@16:48:00.68 <LyS1_home> LyS1.home.jog 0
@16:48:00.79 <AirS_home> AirS.home.jog 0
@16:48:00.87 <TV_home> TV.home.jog 0
@16:48:00.96 <PV_home> PV.home.jog 0
@16:48:01.43 <TV_home> TV.reconfigure HomeTV
@16:48:01.49 <AirS_home> AirS.reconfigure HomeMagSyringe
@16:48:01.53 <LyS1_home> LyS1.reconfigure HomeSyringe
@16:48:01.57 <ArS_home> ArS.reconfigure HomeMagSyringe
@16:48:01.61 <PV_home> PV.reconfigure HomingPV
@16:48:01.66 <LyS2_home> LyS2.reconfigure HomeSyringe
@16:48:01.82 <TV_home> TV.jog -501
@16:48:01.86 <AirS_home> AirS.jog -127
@16:48:01.90 <LyS1_home> LyS1.jog -113
@16:48:01.93 <PV_home> PV.jog -113
@16:48:01.98 <ArS_home> ArS.jog -132
@16:48:02.01 <LyS2_home> LyS2.jog -120
@16:48:02.51 <AirS_home> AirS.setRawPosition! -50
@16:48:02.58 AirS.seek :home
@16:48:02.67 <PV_home> PV.setRawPosition! -50
@16:48:02.69 <LyS2_home> LyS2.setRawPosition! -50
@16:48:02.72 <LyS1_home> LyS1.setRawPosition! -50
@16:48:02.75 <ArS_home> ArS.setRawPosition! -50
@16:48:02.85 <PV_home> PV.seek :home
@16:48:02.96 <LyS1_home> LyS1.seek :home
@16:48:03.00 <ArS_home> ArS.seek :home
@16:48:03.03 <LyS2_home> LyS2.seek :home
@16:48:03.22 <PV_home> PV.reconfigure PVconfig
@16:48:03.24 <AirS_home> AirS.reconfigure AirSconfig
@16:48:03.38 <ArS_home> ArS.reconfigure ArSconfig
@16:48:03.47 <LyS2_home> LyS2.reconfigure LyS2config
@16:48:03.49 <LyS1_home> LyS1.reconfigure LyS1config
@16:48:03.70 <TV_home> TV.setRawPosition! 0
@16:48:03.75 TV.seek :home
@16:48:03.84 TV.reconfigure TVconfig
@16:48:04.05 <preston> TV.seek :clear
@16:48:05.67 SC.reconfigure HomeSC
@16:48:05.73 SC.home.jog 0
@16:48:17.03 -> SC.monitorAbsPos
@16:48:17.05 SC.configure #<struct I2C::Servo::Configuration updatePeriod=50, encoder=:positive, threshold=:off, home=:off, jogHome=false, homeDirection=:reverse, thresholdOffset=0, maxPositionErr=45, stopWindow=31748, gain=#<struct PIDgain P=2, I=17, D=27>, acceleration=1000, deceleration=0, stopRate=0, maxSpeed=2000, minSpeed=0, maxPWM=40, minPWM=14, maxSettling=150, maxCurrent=0, stiction=0, friction=-32240, hunt=false, brake=false, maxDeltaPress=12, maxInPress=0, maxOutPress=0, minDeltaPress=17890, minInPress=0, minOutPress=0, pressBias=0, pressGain=0, inputDeltaPress=false, externalCurrent=false, debug=false>
@16:48:17.29 SC: absPos=40920, freqShift=-2183, B/A mismatch=-833, amplitude=6656/6656
@16:48:17.98 SC: absPos=40920, freqShift=-2185, B/A mismatch=-804, amplitude=6656/6656
@16:48:18.68 SC: absPos=40920, freqShift=-2190, B/A mismatch=-863, amplitude=6656/6656
@16:48:19.37 SC: absPos=40920, freqShift=-2183, B/A mismatch=-923, amplitude=6656/6656
@16:48:20.07 SC: absPos=40920, freqShift=-2187, B/A mismatch=-808, amplitude=6656/6656
@16:48:20.77 SC: absPos=40920, freqShift=-2188, B/A mismatch=-900, amplitude=6656/6656
@16:48:21.46 SC: absPos=40920, freqShift=-2188, B/A mismatch=-867, amplitude=6656/6656
@16:48:22.17 SC: absPos=40920, freqShift=-2189, B/A mismatch=-724, amplitude=6656/6656
@16:48:22.65 UserAbort in preston -- 
@16:48:22.67 Errno::EPIPE in preston aborter-'s_reader -- Broken pipe
@16:48:22.69 Session Ended
@16:48:22.70 Errno::EPIPE in preston's_reader -- Broken pipe
@16:48:33.13 <preston> Session Begun
@16:50:26.98 -> runMission 'processAll'
@16:50:27.01 <processAll> Processing all remaining dry cartridges
@16:50:27.03 Warning:  There are 57 cartridges that are not :dry!
@16:50:27.15 {4 => 898.965957446809,
 5 => 999.999734042553,
 6 => 368.417553191489,
 7 => 350.141489361702,
 8 => 352.093882978723,
 9 => 390.022340425532,
 10 => 387.428457446809,
 11 => 392.861170212766,
 12 => 417.567287234043,
 13 => 387.684574468085,
 14 => 405.354255319149,
 15 => 417.375,
 16 => 361.110638297872,
 17 => 348.678989361702,
 18 => 349.689893617021,
 19 => 347.622606382979,
 20 => 347.009042553192,
 21 => 384.715691489362,
 22 => 381.617553191489,
 23 => 375.947872340426,
 24 => 353.406382978723,
 25 => 708.780319148936,
 26 => 708.349468085106,
 27 => 649.727393617021,
 28 => 674.679255319149,
 29 => 685.848670212766,
 30 => 629.047340425532,
 31 => 693.507446808511,
 32 => 760.523936170213,
 33 => 790.527925531915,
 34 => 954.276063829787,
 35 => 834.153191489362,
 36 => 653.703989361702,
 37 => 680.021808510638,
 38 => 553.216755319149,
 39 => 632.858776595745,
 40 => 496.180053191489,
 41 => 515.897872340426,
 42 => 483.274468085106,
 43 => 999.999734042553,
 44 => 999.999734042553,
 45 => :wet,
 46 => 999.999734042553,
 47 => 999.999734042553,
 48 => 999.999734042553,
 49 => 999.999734042553,
 50 => 999.999734042553,
 51 => 999.999734042553,
 52 => 999.999734042553,
 53 => 999.999734042553,
 54 => 999.999734042553,
 55 => 787.433776595745,
 56 => 999.999734042553,
 57 => 2.79734042553192,
 58 => 999.999734042553,
 59 => 741.624734042553,
 60 => 2.96728723404255}
@16:50:27.17 delay 1:00
@16:51:29.10 ArS.configure ArSconfig
@16:51:29.46 LyS1.configure LyS1config
@16:51:29.58 LyS2.configure LyS2config
@16:51:29.69 AirS.configure AirSconfig
@16:51:29.81 TV.hold
@16:51:29.92 TV.configure TVconfig
@16:51:30.04 SP.configure SPconfig
@16:51:30.16 Sea.configure SPconfig
@16:51:30.44 SC.reconfigure SCconfig
@16:51:30.50 SC.hold
@16:51:30.58 SC.configure SCconfig
@16:51:30.70 PV.configure PVconfig
@16:51:30.76 All elf controllers running firmware version 4.41
@16:51:31.30 Selecting Cartridge slot 3
@16:51:31.70 SC.seek 3
@16:51:32.90 <LyS2> LyS2.seek :cartridge
@16:51:32.94 <PV> PV.seek :cartridge
@16:51:34.92 <FILTERING> Duration of filtering limited to 1:05:00
@16:51:35.11 Priming sample loop w/100ml, bypass w/10ml
@16:51:35.13 TV.seek :bypass
@16:51:36.76 TV.seek :free
@16:51:38.43 TV.coast
@16:51:38.48 <openPB> PB.open
@16:51:38.50 <FILTERING> Exhaust.close
@16:51:39.22 Intake.open
@16:51:40.02 Sea @-3.4psia
@16:51:40.03 Waiting 4 - 300s for filter pressure to stabilize +/-0.5psi
@16:51:45.56 Vacuum tare is 23% of full scale
@16:51:45.64 Sea @-3.4psia
@16:51:45.65 SP.setPosition! 0ml
@16:51:45.72 SP.reconfigure SPprime
@16:51:45.79 SP.seek 10ml,1:21
@16:51:56.36 <closePB> PB.close
@16:51:56.38 <FILTERING> Exhaust.open
@16:51:57.24 Sea @-4.1psia
@16:51:57.25 SP.setPosition! 0ml
@16:51:57.32 SP.seek 100ml,8:51
@16:53:47.55 Pressurizing cartridge to 26psi
@16:53:47.56 <closeIntake> Intake.close
@16:53:47.60 <closeExhaust> Exhaust.close
@16:53:48.42 <FILTERING> PB.open
@16:53:49.12 delay 2 seconds
@16:53:51.21 TV.seek :crack
@16:53:52.04 TV.seek :free
@16:53:52.85 TV.coast
@16:53:52.90 Intake.open
@16:53:53.67 delay 2 seconds
@16:53:55.69 PB.close
@16:53:56.45 Sea @-4.2psia
@16:53:56.46 SP.setPosition! 0ml
@16:53:56.52 SP.reconfigure SPcharge
@16:53:56.59 SP.seek 5ml,3:46
@16:54:08.79 Cartridge pressurized to 26.2psi
@16:54:09.02 delay 3 seconds
@16:54:12.10 Cartridge at 20.7psi 3 seconds later
@16:54:12.23 TV.seek :cartridge
@16:54:14.04 TV.seek :free
@16:54:14.14 TV.coast
@16:54:14.19 TV.seek :bypass
@16:54:14.28 TV.coast
@16:54:14.33 Slide::Error in FILTERING -- Toroid Valve notReady
@16:54:14.34 Waiting to Resume from Checkpoint "Toroid Valve notReady"
@16:54:59.54 <preston> -> ESP.ready!
@16:54:59.94 <TV_home> TV.reconfigure TVconfig
@16:55:00.02 TV.home.jog 0
@16:55:00.17 TV.reconfigure HomeTV
@16:55:00.53 TV.jog -981
@16:55:03.80 TV.setRawPosition! 0
@16:55:03.85 TV.seek :home
@16:55:03.93 TV.reconfigure TVconfig
@16:55:32.16 <preston> -> Thread[:FILTERING].resume
@16:55:32.18 <FILTERING> Resuming Thread after Toroid Valve notReady at 16:54:14
@16:55:32.22 TV.seek :bypass
@16:55:32.32 TV.seek :free
@16:55:33.99 TV.coast
@16:55:34.04 Slide::Error in FILTERING -- Toroid Valve positionErr
@16:55:34.06 Waiting to Resume from Checkpoint "Toroid Valve notReady"
@16:55:45.54 <preston> -> TV.home.to :home
@16:55:45.56 TV.reconfigure TVconfig
@16:55:45.64 TV.home.seek :home
@16:55:51.10 -> TV.goHome!
@16:55:51.12 TV.reconfigure TVconfig
@16:55:51.20 TV.home.jog 0
@16:55:51.36 TV.reconfigure HomeTV
@16:55:51.42 TV.jog -97
@16:55:51.81 TV.setRawPosition! 0
@16:55:51.87 TV.seek :home
@16:55:51.95 TV.reconfigure TVconfig
@16:55:55.77 -> TV.bypass
@16:55:55.79 TV.seek :bypass
@16:55:55.88 TV.seek :free
@16:55:57.54 TV.coast
@16:56:00.72 -> Thread[:FILTERING].resume
@16:56:00.74 <FILTERING> Resuming Thread after Toroid Valve notReady at 16:54:14
@16:56:00.76 TV.seek :bypass
@16:56:02.40 TV.seek :free
@16:56:04.07 TV.coast
@16:56:04.12 Slide::Error in FILTERING -- Toroid Valve positionErr
@16:56:04.13 Waiting to Resume from Checkpoint "Toroid Valve notReady"
@16:56:23.55 <preston> -> TV.status
@16:56:44.69 -> TV.legend
@16:56:54.73 -> TV.to :bypass
@16:56:54.74 TV.seek :bypass
@16:57:07.29 -> TV.status
@16:57:21.70 -> TV.to :bypass
@16:57:21.72 TV.seek :bypass
@16:57:34.14 -> TV.to :clear
@16:57:34.16 TV.seek :clear
@16:57:42.00 -> TV.status
@16:57:50.28 -> TV.goHome!
@16:57:50.30 TV.reconfigure TVconfig
@16:57:50.38 TV.home.jog 0
@16:57:50.53 TV.reconfigure HomeTV
@16:57:50.59 TV.jog -507
@16:57:52.31 TV.setRawPosition! 0
@16:57:52.37 TV.seek :home
@16:57:52.45 TV.reconfigure TVconfig
@16:57:55.68 -> TV.status
@16:58:17.26 -> Thread[:FILTERING].resume
@16:58:17.28 <FILTERING> Resuming Thread after Toroid Valve notReady at 16:54:14
@16:58:17.30 TV.seek :bypass
@16:58:17.43 TV.seek :free
@16:58:19.10 TV.coast
@16:58:19.15 Slide::Error in FILTERING -- Toroid Valve positionErr
@16:58:19.16 Waiting to Resume from Checkpoint "Toroid Valve notReady"
@17:00:19.40 <preston> -> TV.goHome!
@17:00:19.42 TV.reconfigure TVconfig
@17:00:19.49 TV.home.jog 0
@17:00:19.64 TV.reconfigure HomeTV
@17:00:19.70 TV.jog -502
@17:00:21.40 TV.setRawPosition! 0
@17:00:21.46 TV.seek :home
@17:00:21.54 TV.reconfigure TVconfig
@17:00:31.92 -> TV.crack
@17:00:32.00 TV.seek :crack
@17:00:34.35 TV.seek :free
@17:00:35.14 TV.coast
@17:00:39.13 -> TV.cartridge
@17:00:39.21 TV.seek :cartridge
@17:00:41.02 TV.seek :free
@17:00:42.82 TV.coast
@17:00:51.20 -> Thread[:FILTERING].recover
@17:00:51.22 <FILTERING> Recovering Thread after Toroid Valve positionErr at 16:54:14
@17:00:51.26 TV.seek :free
@17:00:51.35 TV.coast
@17:00:51.40 Sampling 1000.0ml
@17:00:51.41 Exhaust.open
@17:00:52.22 Sea @-42.9psia
@17:00:52.24 SP.setPosition! 0ml
@17:00:52.30 SP.reconfigure SPsample
@17:00:52.38 SP.seek 1000ml,1:23:53
@17:00:53.12 Flow estimate reduced to 0.77ml/s
@17:00:53.14 Waiting up to 28 seconds for vacuum to reduce from 33.1 to 18.0psi
@17:00:53.33 <sampling> Cartridge 3 sampling 0/1000ml at 0.00ml/s with 9.1psi vacuum -39.0m deep (-42.9psia)
@17:00:53.77 <FILTERING> Relieved excess vacuum in 1.3 seconds
@17:00:53.79 SP.seek 1000ml,1:23:51
@17:01:53.34 <sampling> Cartridge 3 sampling 28/1000ml at 0.47ml/s with 19.7psi vacuum -39.0m deep (-42.9psia)
@17:02:53.34 Cartridge 3 sampling 57/1000ml at 0.46ml/s with 23.9psi vacuum -39.0m deep (-42.9psia)
/home/esp/esp2/lib/schedule.rb:100: [BUG] Segmentation fault
ruby 1.8.7 (2017-5-8 MBARI8esp7/0x8770 on patchlevel 352) [arm-linux-eabi]