Skip to content

Instantly share code, notes, and snippets.

@codenrhoden

codenrhoden/withoutproxy.sh

Created May 25, 2017 19:15
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save codenrhoden/5b4c403c082ea12b986289a09e8b0360 to your computer and use it in GitHub Desktop.
Save codenrhoden/5b4c403c082ea12b986289a09e8b0360 to your computer and use it in GitHub Desktop.
Download ZIP
proxy showdown
Raw
withoutproxy.sh
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/" time=1495739064931
time="2017-05-25T12:04:24-07:00" level=debug msg="lsx binary name" lsx=lsx-darwin time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/etc/libstorage" time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/etc/libstorage/tls" time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/var/lib/libstorage" time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/var/log/libstorage" time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="mkdir -p" path="/var/run/libstorage" time=1495739064932
time="2017-05-25T12:04:24-07:00" level=debug msg="trapped signals" time=1495739064933
time="2017-05-25T12:04:24-07:00" level=debug msg="loading config" buildType="client+agent+controller" configFileName=rexray globalConfigFileExists=false globalConfigFilePath="/etc/rexray/rexray.yml" ignoreExists=false time=1495739064933 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/rexray.yml"
time="2017-05-25T12:04:24-07:00" level=debug msg="cannot find global or user file" buildType="client+agent+controller" configFileName=rexray globalConfigFileExists=false globalConfigFilePath="/etc/rexray/rexray.yml" ignoreExists=false time=1495739064933 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/rexray.yml"
time="2017-05-25T12:04:24-07:00" level=debug msg="loading config" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495739064933 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:04:24-07:00" level=debug msg="disabled config file exist check" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495739064933 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:04:24-07:00" level=debug msg="created new config" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495739064933 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:04:24-07:00" level=debug msg="initializing configuration"
time="2017-05-25T12:04:24-07:00" level=debug msg="loading yaml for Module"
time="2017-05-25T12:04:24-07:00" level=debug msg="loading yaml for Global"
time="2017-05-25T12:04:24-07:00" level=debug msg="usage template path" path="/Users/travis/.rexray/usage.template"
time="2017-05-25T12:04:24-07:00" level=debug msg="loaded usage template" source=UsageTemplate
time="2017-05-25T12:04:24-07:00" level=debug msg="updating log level" level=debug time=1495739064936
time="2017-05-25T12:04:24-07:00" level=info msg="updated log level" logLevel=debug
time="2017-05-25T12:04:24-07:00" level=debug msg=os.args time=1495739064936 val=[./rexray -s vfs volume ls]
time="2017-05-25T12:04:24-07:00" level=debug msg="activating libStorage" cmd=ls time=1495739064936
time="2017-05-25T12:04:24-07:00" level=debug msg="host is empty; initiliazing default services" time=1495739064938
time="2017-05-25T12:04:24-07:00" level=info msg="libStorage auto service mode enabled" driver=vfs time=1495739064938
time="2017-05-25T12:04:24-07:00" level=debug msg="starting embedded libStorage server" time=1495739064939
time="2017-05-25T12:04:24-07:00" level=debug msg="created scoped scope" new=libstorage.server parentScopes="rexray,"
time="2017-05-25T12:04:24-07:00" level=info msg="configured logging" libstorage.logging.httpRequests=true libstorage.logging.httpResponses=true libstorage.logging.level=debug server=basalt-sargent-sv time=1495739064949
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.disabled=false server=basalt-sargent-sv time=1495739064952
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.key= server=basalt-sargent-sv time=1495739064955
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.alg=HS256 server=basalt-sargent-sv time=1495739064956
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.allow=[] server=basalt-sargent-sv time=1495739064959
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.deny=[] server=basalt-sargent-sv time=1495739064961
time="2017-05-25T12:04:24-07:00" level=info msg="configured global auth" libstorage.server.auth.alg=HS256 libstorage.server.auth.allow=[] libstorage.server.auth.deny=[] libstorage.server.auth.disabled=false libstorage.server.auth.key= server=basalt-sargent-sv time=1495739064961
time="2017-05-25T12:04:24-07:00" level=info msg="initializing server" server=basalt-sargent-sv time=1495739064961
time="2017-05-25T12:04:24-07:00" level=info msg="initializing default endpoint" autoEndpointMode=unix server=basalt-sargent-sv time=1495739064962
time="2017-05-25T12:04:24-07:00" level=info msg="initializing auto unix endpoint" endpoint=libstorage.server.endpoints.localhost server=basalt-sargent-sv time=1495739064964
time="2017-05-25T12:04:24-07:00" level=debug msg="endpoint info" address="unix:///var/run/libstorage/176326092.sock" endpoint=libstorage.server.endpoints.localhost server=basalt-sargent-sv time=1495739064964
time="2017-05-25T12:04:24-07:00" level=debug msg="disabling tls for unix sockets" server=basalt-sargent-sv time=1495739064964
time="2017-05-25T12:04:24-07:00" level=info msg="configured endpoint" address="unix:///var/run/libstorage/176326092.sock" endpoint=localhost server=basalt-sargent-sv time=1495739064964
time="2017-05-25T12:04:24-07:00" level=info msg="server created" server=basalt-sargent-sv time=1495739064966
time="2017-05-25T12:04:24-07:00" level=info msg="initialized endpoints" server=basalt-sargent-sv time=1495739064966
time="2017-05-25T12:04:24-07:00" level=info msg="initializing server services" server=basalt-sargent-sv time=1495739064966
time="2017-05-25T12:04:24-07:00" level=debug msg="configured result schema validation" enabled=false server=basalt-sargent-sv time=1495739064966
time="2017-05-25T12:04:24-07:00" level=debug msg="got services map" count=1 server=basalt-sargent-sv time=1495739064967
time="2017-05-25T12:04:24-07:00" level=debug msg="processing service config" server=basalt-sargent-sv service=vfs time=1495739064967
time="2017-05-25T12:04:24-07:00" level=debug msg="getting scoped config for service" scope=libstorage.server.services.vfs server=basalt-sargent-sv service=vfs time=1495739064968
time="2017-05-25T12:04:24-07:00" level=debug msg="created scoped scope" new=libstorage.server.services.vfs parentScopes="libstorage.server,rexray,"
time="2017-05-25T12:04:24-07:00" level=debug msg="got driver name" driverName=vfs server=basalt-sargent-sv service=vfs time=1495739064969
time="2017-05-25T12:04:24-07:00" level=info msg=vfs.root server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739064972 vfs.root.path="/var/lib/libstorage/vfs"
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.disabled=false server=basalt-sargent-sv service=vfs time=1495739064981
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.key= server=basalt-sargent-sv service=vfs time=1495739064985
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.alg=HS256 server=basalt-sargent-sv service=vfs time=1495739064990
time="2017-05-25T12:04:24-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.allow=[] server=basalt-sargent-sv service=vfs time=1495739064995
time="2017-05-25T12:04:25-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.deny=[] server=basalt-sargent-sv service=vfs time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="configured service auth" libstorage.server.auth.alg=HS256 libstorage.server.auth.allow=[] libstorage.server.auth.deny=[] libstorage.server.auth.disabled=false libstorage.server.auth.key= server=basalt-sargent-sv service=vfs time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="created new service" server=basalt-sargent-sv service=vfs time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized services" server=basalt-sargent-sv time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=3 router=executor-router server=basalt-sargent-sv time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=4 router=help-router server=basalt-sargent-sv time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=1 router=root-router server=basalt-sargent-sv time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=2 router=service-router server=basalt-sargent-sv time=1495739065000
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=11 router=volume-router server=basalt-sargent-sv time=1495739065001
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=6 router=snapshot-router server=basalt-sargent-sv time=1495739065001
time="2017-05-25T12:04:25-07:00" level=info msg="initialized router" len(routes)=2 router=tasks-router server=basalt-sargent-sv time=1495739065001
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/executors" queries=[] route=executors server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/executors/{executor}" queries=[] route=executorInspect server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=HEAD path="/executors/{executor}" queries=[] route=executorHead server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/help" queries=[] route=version server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/help/config" queries=[] route=version server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/help/env" queries=[] route=version server=basalt-sargent-sv time=1495739065001 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/help/version" queries=[] route=version server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/" queries=[] route=root server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/services" queries=[] route=services server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/services/{service}" queries=[] route=serviceInspect server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/volumes" queries=[] route=volumes server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/volumes/{service}" queries=[] route=volumesForService server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/volumes/{service}/{volumeID}" queries=[] route=volumeInspect server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes/{service}" queries=[detach ] route=volumesDetachForService server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=POST path="/volumes/{service}" queries=[] route=volumeCreate server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[copy ] route=volumeCopy server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[snapshot ] route=volumeSnapshot server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[attach ] route=volumeAttach server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes" queries=[detach ] route=volumesDetachAll server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[detach ] route=volumeDetach server=basalt-sargent-sv time=1495739065002 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=DELETE path="/volumes/{service}/{volumeID}" queries=[] route=volumeRemove server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/snapshots" queries=[] route=snapshots server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/snapshots/{service}" queries=[] route=snapshotsForService server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/snapshots/{service}/{snapshotID}" queries=[] route=snapshotInspect server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/snapshots/{service}/{snapshotID}" queries=[create ] route=snapshotCreate server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=2 method=POST path="/snapshots/{service}/{snapshotID}" queries=[copy ] route=snapshotCopy server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=DELETE path="/snapshots/{service}/{snapshotID}" queries=[] route=snapshotRemove server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/tasks" queries=[] route=tasks server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/176326092.sock" len(queries)=0 method=GET path="/tasks/{taskID}" queries=[] route=taskInspect server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:25-07:00" level=info msg="waiting for err or close signal" server=basalt-sargent-sv time=1495739065003
time="2017-05-25T12:04:25-07:00" level=info msg="api listening" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv time=1495739065003 tls=false
time="2017-05-25T12:04:26-07:00" level=info msg="server started" server=basalt-sargent-sv time=1495739066003
time="2017-05-25T12:04:26-07:00" level=debug msg="got host from new server address server.Addrs()[0]" specHost="unix:///var/run/libstorage/176326092.sock" time=1495739066003
time="2017-05-25T12:04:26-07:00" level=debug msg="parseSafeHost - no change" postParse="unix:///var/run/libstorage/176326092.sock" preParse="unix:///var/run/libstorage/176326092.sock" time=1495739066003
time="2017-05-25T12:04:26-07:00" level=debug msg="got host from new server address; updated" specHost="unix:///var/run/libstorage/176326092.sock" time=1495739066003
time="2017-05-25T12:04:26-07:00" level=debug msg="set host in context" host="unix:///var/run/libstorage/176326092.sock" time=1495739066003
time="2017-05-25T12:04:26-07:00" level=debug msg="set host in config" host="unix:///var/run/libstorage/176326092.sock" time=1495739066004
time="2017-05-25T12:04:26-07:00" level=debug msg="created spec file" host="unix:///var/run/libstorage/176326092.sock" path="/var/run/rexray/rexray.spec" time=1495739066006
time="2017-05-25T12:04:26-07:00" level=debug msg="creating libStorage client" cmd=ls host="unix:///var/run/libstorage/176326092.sock" time=1495739066006
time="2017-05-25T12:04:26-07:00" level=debug msg="created scoped scope" new=libstorage.client parentScopes="rexray,"
time="2017-05-25T12:04:26-07:00" level=info msg="configured logging" host="unix:///var/run/libstorage/176326092.sock" libstorage.logging.httpRequests=true libstorage.logging.httpResponses=true libstorage.logging.level=debug time=1495739066027
time="2017-05-25T12:04:26-07:00" level=debug msg="got configured host address" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066030
time="2017-05-25T12:04:26-07:00" level=debug msg="disabling tls for unix sockets" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066030
time="2017-05-25T12:04:26-07:00" level=debug msg="getHost proto == \"unix\"" getHost=libstorage-server host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066030
time="2017-05-25T12:04:26-07:00" level=info msg="created libStorage client" clientType=integration disableKeepAlive=false enableInstanceIDHeaders=true enableLocalDevicesHeaders=true host="unix:///var/run/libstorage/176326092.sock" lAddr=libstorage-server logRequests=true logResponses=true lsxMutexPath="/var/run/libstorage/lsx-darwin.lock" lsxPath="/var/lib/libstorage/lsx-darwin" service=vfs storageDriver=libstorage time=1495739066034
time="2017-05-25T12:04:26-07:00" level=info msg="registered custom context key" externalID=Libstorage-Tx internalID=2 keyBitmask=2
time="2017-05-25T12:04:26-07:00" level=info msg="registered custom context key" externalID=Libstorage-Instanceid internalID=3 keyBitmask=2
time="2017-05-25T12:04:26-07:00" level=info msg="registered custom context key" externalID=Libstorage-Localdevices internalID=4 keyBitmask=2
time="2017-05-25T12:04:26-07:00" level=info msg="registered custom context key" externalID=Authorization internalID=5 keyBitmask=2
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /services HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=b402478b-8aba-4d67-5916-8069851a855f, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=debug msg="successful connection" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066035
time="2017-05-25T12:04:26-07:00" level=info msg="http request" host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=schema-validator route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-svc-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=local-devices-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=instanceIDs-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-global-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=error-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=logging-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=query-params-handler route=services server=basalt-sargent-sv time=1495739066036 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Tx="txID=b402478b-8aba-4d67-5916-8069851a855f, txCR=1495739066" host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false txCR=1495739066 txID=b402478b-8aba-4d67-5916-8069851a855f
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Instanceid=[] host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false txCR=1495739066 txID=b402478b-8aba-4d67-5916-8069851a855f
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false txCR=1495739066 txID=b402478b-8aba-4d67-5916-8069851a855f
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false txCR=1495739066 txID=b402478b-8aba-4d67-5916-8069851a855f
time="2017-05-25T12:04:26-07:00" level=debug msg="validated all services access" host="unix:///var/run/libstorage/176326092.sock" route=services server=basalt-sargent-sv time=1495739066037 tls=false txCR=1495739066 txID=b402478b-8aba-4d67-5916-8069851a855f
time="2017-05-25T12:04:26-07:00" level=info msg=" - - [25/May/2017:12:04:26 -0700] \"GET /services HTTP/1.1\" 200 202"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /services HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=b402478b-8aba-4d67-5916-8069851a855f, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"vfs\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length: 202"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:04:26-07:00" level=info msg=" Date: Thu, 25 May 2017 19:04:26 GMT"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Servername: basalt-sargent-sv"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"vfs\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg="initializing executors cache" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066039
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /executors HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=9af1a921-117b-4d11-5789-0f35c7593215, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg="http request" host="unix:///var/run/libstorage/176326092.sock" route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=local-devices-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=instanceIDs-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-global-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=error-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=logging-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=query-params-handler route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Tx="txID=9af1a921-117b-4d11-5789-0f35c7593215, txCR=1495739066" host="unix:///var/run/libstorage/176326092.sock" route=executors server=basalt-sargent-sv time=1495739066040 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=executors server=basalt-sargent-sv time=1495739066040 tls=false txCR=1495739066 txID=9af1a921-117b-4d11-5789-0f35c7593215
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Instanceid=[] host="unix:///var/run/libstorage/176326092.sock" route=executors server=basalt-sargent-sv time=1495739066040 tls=false txCR=1495739066 txID=9af1a921-117b-4d11-5789-0f35c7593215
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/176326092.sock" route=executors server=basalt-sargent-sv time=1495739066040 tls=false txCR=1495739066 txID=9af1a921-117b-4d11-5789-0f35c7593215
time="2017-05-25T12:04:26-07:00" level=info msg=" - - [25/May/2017:12:04:26 -0700] \"GET /executors HTTP/1.1\" 200 159"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /executors HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=9af1a921-117b-4d11-5789-0f35c7593215, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"lsx-darwin\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"lsx-darwin\","
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" \"md5checksum\": \"ceddaf3ed25e6cbc95b2a65d9898f748\","
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"size\": 10535056,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"lastModified\": 1495738966"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length: 159"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:04:26-07:00" level=info msg=" Date: Thu, 25 May 2017 19:04:26 GMT"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Servername: basalt-sargent-sv"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"lsx-darwin\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"lsx-darwin\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"md5checksum\": \"ceddaf3ed25e6cbc95b2a65d9898f748\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"size\": 10535056,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"lastModified\": 1495738966"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=debug msg="updating executor" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066041
time="2017-05-25T12:04:26-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066041
time="2017-05-25T12:04:26-07:00" level=debug msg="executor exists, getting local checksum" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066042
time="2017-05-25T12:04:26-07:00" level=debug msg="getting executor checksum" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066042
time="2017-05-25T12:04:26-07:00" level=debug msg="got local executor checksum" host="unix:///var/run/libstorage/176326092.sock" localChecksum=e606d48e09fb81c16d70805677ff6a81 service=vfs storageDriver=libstorage time=1495739066071
time="2017-05-25T12:04:26-07:00" level=debug msg="executor checksums do not match, download executor" host="unix:///var/run/libstorage/176326092.sock" localChecksum=e606d48e09fb81c16d70805677ff6a81 remoteChecksum=ceddaf3ed25e6cbc95b2a65d9898f748 service=vfs storageDriver=libstorage time=1495739066071
time="2017-05-25T12:04:26-07:00" level=debug msg="downloading executor" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066071
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /executors/lsx-darwin HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=39e467ea-9b46-4e1b-5229-21c087b22a7f, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg="http request" host="unix:///var/run/libstorage/176326092.sock" route=executorInspect server=basalt-sargent-sv time=1495739066072 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=executorInspect server=basalt-sargent-sv time=1495739066072 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=local-devices-handler route=executorInspect server=basalt-sargent-sv time=1495739066072 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=instanceIDs-handler route=executorInspect server=basalt-sargent-sv time=1495739066072 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-global-handler route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=error-handler route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=logging-handler route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=query-params-handler route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Tx="txID=39e467ea-9b46-4e1b-5229-21c087b22a7f, txCR=1495739066" host="unix:///var/run/libstorage/176326092.sock" route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false txCR=1495739066 txID=39e467ea-9b46-4e1b-5229-21c087b22a7f
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Instanceid=[] host="unix:///var/run/libstorage/176326092.sock" route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false txCR=1495739066 txID=39e467ea-9b46-4e1b-5229-21c087b22a7f
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/176326092.sock" route=executorInspect server=basalt-sargent-sv time=1495739066073 tls=false txCR=1495739066 txID=39e467ea-9b46-4e1b-5229-21c087b22a7f
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length: 10535056"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Ranges: bytes"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Md5: zt2vPtJebLyVsqZdmJj3SA=="
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type: application/octet-stream"
time="2017-05-25T12:04:26-07:00" level=info msg=" Date: Thu, 25 May 2017 19:04:26 GMT"
time="2017-05-25T12:04:26-07:00" level=info msg=" Last-Modified: Thu, 25 May 2017 12:02:46 MST"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Servername: basalt-sargent-sv"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" - - [25/May/2017:12:04:26 -0700] \"GET /executors/lsx-darwin HTTP/1.1\" 200 10535056"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /executors/lsx-darwin HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=39e467ea-9b46-4e1b-5229-21c087b22a7f, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Ranges=bytes"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length=10535056"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type=application/octet-stream"
time="2017-05-25T12:04:26-07:00" level=info msg=" Last-Modified=Thu, 25 May 2017 12:02:46 MST"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Md5=zt2vPtJebLyVsqZdmJj3SA=="
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=debug msg="downloaded executor" bytes=10535056 host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066208
time="2017-05-25T12:04:26-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066208
time="2017-05-25T12:04:26-07:00" level=info msg="initializing supported cache" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066208
time="2017-05-25T12:04:26-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066208 txCR=1495739066 txID=b8bf0de0-d492-4661-6de7-8a82d20c0123
time="2017-05-25T12:04:26-07:00" level=debug msg="invoking executor cli" args=[vfs supported] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066208 txCR=1495739066 txID=b8bf0de0-d492-4661-6de7-8a82d20c0123
time="2017-05-25T12:04:26-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066231 txCR=1495739066 txID=b8bf0de0-d492-4661-6de7-8a82d20c0123
time="2017-05-25T12:04:26-07:00" level=debug msg="cached supported flag" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage supported=63 time=1495739066232 txCR=1495739066 txID=b8bf0de0-d492-4661-6de7-8a82d20c0123
time="2017-05-25T12:04:26-07:00" level=info msg="initializing instance ID cache" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066232
time="2017-05-25T12:04:26-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066232 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="invoking executor cli" args=[vfs instanceID] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066232 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066258 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="sending instanceID in API.InstanceInspect call" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066259 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /services/vfs?instance HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Instanceid: vfs=,,InBlcnNlcGhvbmUubG9jYWwi"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg="http request" host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv time=1495739066259 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=schema-validator route=serviceInspect server=basalt-sargent-sv time=1495739066259 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-svc-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=service-validator route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=local-devices-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=instanceIDs-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-global-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=error-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=logging-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=query-params-handler route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="query param" host="unix:///var/run/libstorage/176326092.sock" key=instance len(value)=1 route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false value=[]
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Tx="txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7, txCR=1495739066" host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Instanceid=[vfs=,,InBlcnNlcGhvbmUubG9jYWwi] host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv time=1495739066260 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="getting storage service" host="unix:///var/run/libstorage/176326092.sock" route=serviceInspect server=basalt-sargent-sv service=vfs time=1495739066260 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" route=serviceInspect server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066260 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="vfs login=vfs=,,InBlcnNlcGhvbmUubG9jYWwi" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" route=serviceInspect server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066261 tls=false txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=info msg=" - - [25/May/2017:12:04:26 -0700] \"GET /services/vfs?instance HTTP/1.1\" 200 340"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /services/vfs?instance HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Instanceid: vfs=,,InBlcnNlcGhvbmUubG9jYWwi"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"instance\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"instanceID\": {"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" \"id\": \"persephone.local\","
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"service\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" },"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfsInstance\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"providerName\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" },"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length: 340"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:04:26-07:00" level=info msg=" Date: Thu, 25 May 2017 19:04:26 GMT"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Servername: basalt-sargent-sv"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"instance\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"instanceID\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"id\": \"persephone.local\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"service\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" },"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfsInstance\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"providerName\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" },"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:04:26-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:04:26-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=info msg=" }"
time="2017-05-25T12:04:26-07:00" level=debug msg="received instanceID from API.InstanceInspect call" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066261 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="cached instanceID" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066261 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=debug msg="xli instanceID success" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066262 txCR=1495739066 txID=d00695fa-6a8a-42ba-7c93-0e47f46dd2a7
time="2017-05-25T12:04:26-07:00" level=info msg="successefully dialed libStorage server" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066262
time="2017-05-25T12:04:26-07:00" level=info msg="storage driver initialized" host="unix:///var/run/libstorage/176326092.sock" service=vfs storageDriver=libstorage time=1495739066262
time="2017-05-25T12:04:26-07:00" level=info msg="os driver initialized" host="unix:///var/run/libstorage/176326092.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495739066262
time="2017-05-25T12:04:26-07:00" level=warning msg="no integration driver found" host="unix:///var/run/libstorage/176326092.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495739066263
time="2017-05-25T12:04:26-07:00" level=info msg="created libStorage client" host="unix:///var/run/libstorage/176326092.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495739066263
time="2017-05-25T12:04:26-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066263 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="invoking executor cli" args=[vfs localDevices quick] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066263 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdb" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdc" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdd" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvda" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="xli localdevices success" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=basalt-sargent-sv service=vfs storageDriver=libstorage time=1495739066286 txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /volumes/vfs?attachments=1 HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Instanceid: vfs:vfs=persephone.local"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Localdevices: vfs="
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg="http request" host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=schema-validator route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=storage-session-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-svc-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=service-validator route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=local-devices-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=instanceIDs-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=auth-global-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=error-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=transaction-handler route=volumesForService server=basalt-sargent-sv time=1495739066287 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=logging-handler route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/176326092.sock" middleware=query-params-handler route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="query param" host="unix:///var/run/libstorage/176326092.sock" key=attachments len(value)=1 route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false value=[1]
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Tx="txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3, txCR=1495739066" host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Instanceid=[vfs:vfs=persephone.local] host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="http header" Libstorage-Localdevices=[vfs=] host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="getting storage service" host="unix:///var/run/libstorage/176326092.sock" route=volumesForService server=basalt-sargent-sv service=vfs time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="vfs login=vfs:vfs=persephone.local" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="getting task service" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=info msg="executing task" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="querying volumes" attachments=1 host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 time=1495739066288 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="skipping response schema validation; disabled" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 time=1495739066289 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="task completed" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 time=1495739066289 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="getting task service" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs time=1495739066289 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=info msg=" - - [25/May/2017:12:04:26 -0700] \"GET /volumes/vfs?attachments=1 HTTP/1.1\" 200 2"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" GET /volumes/vfs?attachments=1 HTTP/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:04:26-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Instanceid: vfs:vfs=persephone.local"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Localdevices: vfs="
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Tx: txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3, txCR=1495739066"
time="2017-05-25T12:04:26-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" {}"
time="2017-05-25T12:04:26-07:00" level=info
time="2017-05-25T12:04:26-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:04:26-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Length: 2"
time="2017-05-25T12:04:26-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:04:26-07:00" level=info msg=" Date: Thu, 25 May 2017 19:04:26 GMT"
time="2017-05-25T12:04:26-07:00" level=info msg=" Libstorage-Servername: basalt-sargent-sv"
time="2017-05-25T12:04:26-07:00" level=info msg=" "
time="2017-05-25T12:04:26-07:00" level=info msg=" {}"
time="2017-05-25T12:04:26-07:00" level=debug msg="built output template" host="unix:///var/run/libstorage/176326092.sock" template="{{define \"printObject\"}}{{printf \"%v\" .}}{{end}}{{define \"printEncVolumeFields\"}}{{.ID}}\t{{.Name}}\t{{.AttachmentState | printAttState}}\t{{.Size}}\t{{.Encrypted}}{{end}}{{define \"printSnapshotFields\"}}{{.ID}}\t{{.Name}}\t{{.Status}}\t{{.VolumeID}}{{end}}{{define \"printInstanceFields\"}}{{.InstanceID.ID}}\t{{.Name}}\t{{.ProviderName}}\t{{.Region}}{{end}}{{define \"printMountFields\"}}{{.ID}}\t{{.Source}}\t{{.MountPoint}}{{end}}{{define \"printVolumeFields\"}}{{.ID}}\t{{.Name}}\t{{.AttachmentState | printAttState}}\t{{.Size}}{{end}}{{define \"printVolumeWithPathFields\"}}{{.ID}}\t{{.Name}}\t{{.Volume.AttachmentState | printAttState}}\t{{.Size}}\t{{.Path}}{{end}}{{define \"printEncVolumeWithPathFields\"}}{{.ID}}\t{{.Name}}\t{{.Volume.AttachmentState | printAttState}}\t{{.Size}}\t{{.Encrypted}}\t{{.Path}}{{end}}{{define \"printServiceFields\"}}{{.Name}}\t{{.Driver.Name}}{{end}}{{define \"printAuthTokenFields\"}}{{.Subject}}\t{{.IssuedAt}}\t{{.NotBefore}}\t{{.Expires}}{{end}}{{define \"printStringSlice\"}}{{.}}{{end}}{{define \"printVolumeID\"}}{{.ID}}{{end}}{{define \"printScriptFields\"}}{{.Path}}\t{{.Installed}}\t{{.Modified}}{{end}}{{define \"printJSON\"}}{{. | json}}{{end}}{{define \"printPrettyJSON\"}}{{. | jsonp}}{{end}}ID\tName\tStatus\tSize\n{{range sort .D \"Name\" }}{{template \"printVolumeFields\" .}}\n{{end}}" time=1495739066289
time="2017-05-25T12:04:26-07:00" level=debug msg="removing task" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" removedAfter=0s route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 tasksLen=1 time=1495739066290 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
time="2017-05-25T12:04:26-07:00" level=debug msg="removed task" host="unix:///var/run/libstorage/176326092.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=basalt-sargent-sv service=vfs storageDriver=vfs task=0 tasksLen=0 time=1495739066290 tls=false txCR=1495739066 txID=ef85248e-ce07-4cb6-7e65-21c2565df3a3
ID Name Status Size
time="2017-05-25T12:04:26-07:00" level=debug msg="waiting until libStorage is stopped" host="unix:///var/run/libstorage/176326092.sock" time=1495739066290
time="2017-05-25T12:04:26-07:00" level=info msg="shutting down server" server=basalt-sargent-sv time=1495739066290
time="2017-05-25T12:04:26-07:00" level=info msg="shutting down endpoint" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv time=1495739066290 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="removed unix socket" host="unix:///var/run/libstorage/176326092.sock" path="/var/run/libstorage/176326092.sock" server=basalt-sargent-sv time=1495739066290 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="shutdown endpoint complete" host="unix:///var/run/libstorage/176326092.sock" server=basalt-sargent-sv time=1495739066290 tls=false
time="2017-05-25T12:04:26-07:00" level=debug msg="shutdown server complete" server=basalt-sargent-sv time=1495739066290
time="2017-05-25T12:04:26-07:00" level=debug msg="received close signal" server=basalt-sargent-sv time=1495739066290
time="2017-05-25T12:04:26-07:00" level=info msg="closed server error channel" server=basalt-sargent-sv time=1495739066290
time="2017-05-25T12:04:26-07:00" level=info msg="all servers closed"
time="2017-05-25T12:04:26-07:00" level=debug msg="done sending close signals to libStorage" host="unix:///var/run/libstorage/176326092.sock" time=1495739066290
time="2017-05-25T12:04:26-07:00" level=debug msg="removed spec file" host="unix:///var/run/libstorage/176326092.sock" path="/var/run/rexray/rexray.spec" time=1495739066290
time="2017-05-25T12:04:26-07:00" level=debug msg="done waiting on err chan" host="unix:///var/run/libstorage/176326092.sock" time=1495739066291
time="2017-05-25T12:04:26-07:00" level=debug msg="completed cli execution" time=1495739066291
time="2017-05-25T12:04:26-07:00" level=info msg="exiting process" time=1495739066291
time="2017-05-25T12:04:26-07:00" level=debug msg="completed onExit at end of program" time=1495739066291
Raw
withstorageproxy.sh
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/" time=1495738841166
time="2017-05-25T12:00:41-07:00" level=debug msg="lsx binary name" lsx=lsx-darwin time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/etc/libstorage" time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/etc/libstorage/tls" time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/var/lib/libstorage" time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/var/log/libstorage" time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="mkdir -p" path="/var/run/libstorage" time=1495738841167
time="2017-05-25T12:00:41-07:00" level=debug msg="trapped signals" time=1495738841168
time="2017-05-25T12:00:41-07:00" level=debug msg="loading config" buildType="client+agent+controller" configFileName=rexray globalConfigFileExists=false globalConfigFilePath="/etc/rexray/rexray.yml" ignoreExists=false time=1495738841168 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/rexray.yml"
time="2017-05-25T12:00:41-07:00" level=debug msg="cannot find global or user file" buildType="client+agent+controller" configFileName=rexray globalConfigFileExists=false globalConfigFilePath="/etc/rexray/rexray.yml" ignoreExists=false time=1495738841168 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/rexray.yml"
time="2017-05-25T12:00:41-07:00" level=debug msg="loading config" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495738841168 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:00:41-07:00" level=debug msg="disabled config file exist check" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495738841168 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:00:41-07:00" level=debug msg="created new config" buildType="client+agent+controller" configFileName=config globalConfigFileExists=false globalConfigFilePath="/etc/rexray/config.yml" ignoreExists=true time=1495738841168 userConfigFileExists=false userConfigFilePath="/Users/travis/.rexray/config.yml"
time="2017-05-25T12:00:41-07:00" level=debug msg="initializing configuration"
time="2017-05-25T12:00:41-07:00" level=debug msg="loading yaml for Module"
time="2017-05-25T12:00:41-07:00" level=debug msg="loading yaml for Global"
time="2017-05-25T12:00:41-07:00" level=debug msg="usage template path" path="/Users/travis/.rexray/usage.template"
time="2017-05-25T12:00:41-07:00" level=debug msg="loaded usage template" source=UsageTemplate
time="2017-05-25T12:00:41-07:00" level=debug msg="updating log level" level=debug time=1495738841169
time="2017-05-25T12:00:41-07:00" level=info msg="updated log level" logLevel=debug
time="2017-05-25T12:00:41-07:00" level=debug msg=os.args time=1495738841169 val=[./rexray -s vfs volume ls]
time="2017-05-25T12:00:41-07:00" level=debug msg="activating libStorage" cmd=ls time=1495738841169
time="2017-05-25T12:00:41-07:00" level=debug msg="host is empty; initiliazing default services" time=1495738841171
time="2017-05-25T12:00:41-07:00" level=info msg="libStorage auto service mode enabled" driver=vfs time=1495738841171
time="2017-05-25T12:00:41-07:00" level=debug msg="starting embedded libStorage server" time=1495738841172
time="2017-05-25T12:00:41-07:00" level=debug msg="created scoped scope" new=libstorage.server parentScopes="rexray,"
time="2017-05-25T12:00:41-07:00" level=info msg="configured logging" libstorage.logging.httpRequests=true libstorage.logging.httpResponses=true libstorage.logging.level=debug server=lime-gem-ws time=1495738841181
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.disabled=false server=lime-gem-ws time=1495738841184
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.key= server=lime-gem-ws time=1495738841186
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.alg=HS256 server=lime-gem-ws time=1495738841187
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.allow=[] server=lime-gem-ws time=1495738841188
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.deny=[] server=lime-gem-ws time=1495738841190
time="2017-05-25T12:00:41-07:00" level=info msg="configured global auth" libstorage.server.auth.alg=HS256 libstorage.server.auth.allow=[] libstorage.server.auth.deny=[] libstorage.server.auth.disabled=false libstorage.server.auth.key= server=lime-gem-ws time=1495738841190
time="2017-05-25T12:00:41-07:00" level=info msg="initializing server" server=lime-gem-ws time=1495738841190
time="2017-05-25T12:00:41-07:00" level=info msg="initializing default endpoint" autoEndpointMode=unix server=lime-gem-ws time=1495738841192
time="2017-05-25T12:00:41-07:00" level=info msg="initializing auto unix endpoint" endpoint=libstorage.server.endpoints.localhost server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=debug msg="endpoint info" address="unix:///var/run/libstorage/368440648.sock" endpoint=libstorage.server.endpoints.localhost server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=debug msg="disabling tls for unix sockets" server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=info msg="configured endpoint" address="unix:///var/run/libstorage/368440648.sock" endpoint=localhost server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=info msg="server created" server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=info msg="initialized endpoints" server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=info msg="initializing server services" server=lime-gem-ws time=1495738841193
time="2017-05-25T12:00:41-07:00" level=debug msg="configured result schema validation" enabled=false server=lime-gem-ws time=1495738841194
time="2017-05-25T12:00:41-07:00" level=debug msg="got services map" count=1 server=lime-gem-ws time=1495738841194
time="2017-05-25T12:00:41-07:00" level=debug msg="processing service config" server=lime-gem-ws service=vfs time=1495738841194
time="2017-05-25T12:00:41-07:00" level=debug msg="getting scoped config for service" scope=libstorage.server.services.vfs server=lime-gem-ws service=vfs time=1495738841194
time="2017-05-25T12:00:41-07:00" level=debug msg="created scoped scope" new=libstorage.server.services.vfs parentScopes="libstorage.server,rexray,"
time="2017-05-25T12:00:41-07:00" level=debug msg="got driver name" driverName=vfs server=lime-gem-ws service=vfs time=1495738841196
time="2017-05-25T12:00:41-07:00" level=info msg=vfs.root server=lime-gem-ws service=vfs storageDriver=vfs time=1495738841200 vfs.root.path="/var/lib/libstorage/vfs"
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.disabled=false server=lime-gem-ws service=vfs time=1495738841208
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.key= server=lime-gem-ws service=vfs time=1495738841213
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.alg=HS256 server=lime-gem-ws service=vfs time=1495738841217
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.allow=[] server=lime-gem-ws service=vfs time=1495738841222
time="2017-05-25T12:00:41-07:00" level=debug msg="parsed server auth property" libstorage.server.auth.deny=[] server=lime-gem-ws service=vfs time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="configured service auth" libstorage.server.auth.alg=HS256 libstorage.server.auth.allow=[] libstorage.server.auth.deny=[] libstorage.server.auth.disabled=false libstorage.server.auth.key= server=lime-gem-ws service=vfs time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="created new service" server=lime-gem-ws service=vfs time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized services" server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=3 router=executor-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=4 router=help-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=1 router=root-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=2 router=service-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=11 router=volume-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=6 router=snapshot-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=info msg="initialized router" len(routes)=2 router=tasks-router server=lime-gem-ws time=1495738841227
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/executors" queries=[] route=executors server=lime-gem-ws time=1495738841227 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/executors/{executor}" queries=[] route=executorInspect server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=HEAD path="/executors/{executor}" queries=[] route=executorHead server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/help" queries=[] route=version server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/help/config" queries=[] route=version server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/help/env" queries=[] route=version server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/help/version" queries=[] route=version server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/" queries=[] route=root server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/services" queries=[] route=services server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/services/{service}" queries=[] route=serviceInspect server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/volumes" queries=[] route=volumes server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/volumes/{service}" queries=[] route=volumesForService server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/volumes/{service}/{volumeID}" queries=[] route=volumeInspect server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes/{service}" queries=[detach ] route=volumesDetachForService server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=POST path="/volumes/{service}" queries=[] route=volumeCreate server=lime-gem-ws time=1495738841228 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[copy ] route=volumeCopy server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[snapshot ] route=volumeSnapshot server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[attach ] route=volumeAttach server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes" queries=[detach ] route=volumesDetachAll server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/volumes/{service}/{volumeID}" queries=[detach ] route=volumeDetach server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=DELETE path="/volumes/{service}/{volumeID}" queries=[] route=volumeRemove server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/snapshots" queries=[] route=snapshots server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/snapshots/{service}" queries=[] route=snapshotsForService server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/snapshots/{service}/{snapshotID}" queries=[] route=snapshotInspect server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/snapshots/{service}/{snapshotID}" queries=[create ] route=snapshotCreate server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=2 method=POST path="/snapshots/{service}/{snapshotID}" queries=[copy ] route=snapshotCopy server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=DELETE path="/snapshots/{service}/{snapshotID}" queries=[] route=snapshotRemove server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/tasks" queries=[] route=tasks server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=debug msg="registered route" host="unix:///var/run/libstorage/368440648.sock" len(queries)=0 method=GET path="/tasks/{taskID}" queries=[] route=taskInspect server=lime-gem-ws time=1495738841229 tls=false
time="2017-05-25T12:00:41-07:00" level=info msg="waiting for err or close signal" server=lime-gem-ws time=1495738841230
time="2017-05-25T12:00:41-07:00" level=info msg="api listening" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws time=1495738841230 tls=false
time="2017-05-25T12:00:42-07:00" level=info msg="server started" server=lime-gem-ws time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="got host from new server address server.Addrs()[0]" specHost="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="parseSafeHost - no change" postParse="unix:///var/run/libstorage/368440648.sock" preParse="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="got host from new server address; updated" specHost="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="set host in context" host="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="set host in config" host="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="created spec file" host="unix:///var/run/libstorage/368440648.sock" path="/var/run/rexray/rexray.spec" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="creating libStorage client" cmd=ls host="unix:///var/run/libstorage/368440648.sock" time=1495738842231
time="2017-05-25T12:00:42-07:00" level=debug msg="created scoped scope" new=libstorage.client parentScopes="rexray,"
time="2017-05-25T12:00:42-07:00" level=info msg="configured logging" host="unix:///var/run/libstorage/368440648.sock" libstorage.logging.httpRequests=true libstorage.logging.httpResponses=true libstorage.logging.level=debug time=1495738842256
time="2017-05-25T12:00:42-07:00" level=debug msg="got configured host address" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842259
time="2017-05-25T12:00:42-07:00" level=debug msg="disabling tls for unix sockets" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842260
time="2017-05-25T12:00:42-07:00" level=debug msg="getHost proto == \"unix\"" getHost=libstorage-server host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842260
time="2017-05-25T12:00:42-07:00" level=info msg="created libStorage client" clientType=integration disableKeepAlive=false enableInstanceIDHeaders=true enableLocalDevicesHeaders=true host="unix:///var/run/libstorage/368440648.sock" lAddr=libstorage-server logRequests=true logResponses=true lsxMutexPath="/var/run/libstorage/lsx-darwin.lock" lsxPath="/var/lib/libstorage/lsx-darwin" service=vfs storageDriver=libstorage time=1495738842264
time="2017-05-25T12:00:42-07:00" level=info msg="registered custom context key" externalID=Libstorage-Tx internalID=2 keyBitmask=2
time="2017-05-25T12:00:42-07:00" level=info msg="registered custom context key" externalID=Libstorage-Instanceid internalID=3 keyBitmask=2
time="2017-05-25T12:00:42-07:00" level=info msg="registered custom context key" externalID=Libstorage-Localdevices internalID=4 keyBitmask=2
time="2017-05-25T12:00:42-07:00" level=info msg="registered custom context key" externalID=Authorization internalID=5 keyBitmask=2
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /services HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=c59a93b7-9526-4438-77be-780f6522a236, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=debug msg="successful connection" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842264
time="2017-05-25T12:00:42-07:00" level=info msg="http request" host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842264 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=schema-validator route=services server=lime-gem-ws time=1495738842264 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-svc-handler route=services server=lime-gem-ws time=1495738842264 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=services server=lime-gem-ws time=1495738842264 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=local-devices-handler route=services server=lime-gem-ws time=1495738842264 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=instanceIDs-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-global-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=error-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=logging-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=query-params-handler route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Tx="txID=c59a93b7-9526-4438-77be-780f6522a236, txCR=1495738842" host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false txCR=1495738842 txID=c59a93b7-9526-4438-77be-780f6522a236
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Instanceid=[] host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false txCR=1495738842 txID=c59a93b7-9526-4438-77be-780f6522a236
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false txCR=1495738842 txID=c59a93b7-9526-4438-77be-780f6522a236
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false txCR=1495738842 txID=c59a93b7-9526-4438-77be-780f6522a236
time="2017-05-25T12:00:42-07:00" level=debug msg="validated all services access" host="unix:///var/run/libstorage/368440648.sock" route=services server=lime-gem-ws time=1495738842265 tls=false txCR=1495738842 txID=c59a93b7-9526-4438-77be-780f6522a236
time="2017-05-25T12:00:42-07:00" level=info msg=" - - [25/May/2017:12:00:42 -0700] \"GET /services HTTP/1.1\" 200 202"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /services HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=c59a93b7-9526-4438-77be-780f6522a236, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"vfs\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Length: 202"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:00:42-07:00" level=info msg=" Date: Thu, 25 May 2017 19:00:42 GMT"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Servername: lime-gem-ws"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"vfs\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg="initializing executors cache" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842267
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /executors HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=c0ea722c-dcab-455b-48f0-7b38f39fde53, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg="http request" host="unix:///var/run/libstorage/368440648.sock" route=executors server=lime-gem-ws time=1495738842267 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=executors server=lime-gem-ws time=1495738842267 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=local-devices-handler route=executors server=lime-gem-ws time=1495738842267 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=instanceIDs-handler route=executors server=lime-gem-ws time=1495738842267 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-global-handler route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=error-handler route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=logging-handler route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=query-params-handler route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Tx="txID=c0ea722c-dcab-455b-48f0-7b38f39fde53, txCR=1495738842" host="unix:///var/run/libstorage/368440648.sock" route=executors server=lime-gem-ws time=1495738842268 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" route=executors server=lime-gem-ws time=1495738842268 tls=false txCR=1495738842 txID=c0ea722c-dcab-455b-48f0-7b38f39fde53
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Instanceid=[] host="unix:///var/run/libstorage/368440648.sock" route=executors server=lime-gem-ws time=1495738842268 tls=false txCR=1495738842 txID=c0ea722c-dcab-455b-48f0-7b38f39fde53
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/368440648.sock" route=executors server=lime-gem-ws time=1495738842268 tls=false txCR=1495738842 txID=c0ea722c-dcab-455b-48f0-7b38f39fde53
time="2017-05-25T12:00:42-07:00" level=info msg=" - - [25/May/2017:12:00:42 -0700] \"GET /executors HTTP/1.1\" 200 159"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /executors HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=c0ea722c-dcab-455b-48f0-7b38f39fde53, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"lsx-darwin\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"lsx-darwin\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"md5checksum\": \"e606d48e09fb81c16d70805677ff6a81\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"size\": 10535056,"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"lastModified\": 1495738673"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Length: 159"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:00:42-07:00" level=info msg=" Date: Thu, 25 May 2017 19:00:42 GMT"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Servername: lime-gem-ws"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"lsx-darwin\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"lsx-darwin\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"md5checksum\": \"e606d48e09fb81c16d70805677ff6a81\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"size\": 10535056,"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"lastModified\": 1495738673"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=debug msg="updating executor" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842268
time="2017-05-25T12:00:42-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842268
time="2017-05-25T12:00:42-07:00" level=debug msg="executor exists, getting local checksum" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842269
time="2017-05-25T12:00:42-07:00" level=debug msg="getting executor checksum" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842269
time="2017-05-25T12:00:42-07:00" level=debug msg="got local executor checksum" host="unix:///var/run/libstorage/368440648.sock" localChecksum=e606d48e09fb81c16d70805677ff6a81 service=vfs storageDriver=libstorage time=1495738842293
time="2017-05-25T12:00:42-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842293
time="2017-05-25T12:00:42-07:00" level=info msg="initializing supported cache" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842293
time="2017-05-25T12:00:42-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842294 txCR=1495738842 txID=11538d98-242e-493f-4ae9-f23528979a78
time="2017-05-25T12:00:42-07:00" level=debug msg="invoking executor cli" args=[vfs supported] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842294 txCR=1495738842 txID=11538d98-242e-493f-4ae9-f23528979a78
time="2017-05-25T12:00:42-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842316 txCR=1495738842 txID=11538d98-242e-493f-4ae9-f23528979a78
time="2017-05-25T12:00:42-07:00" level=debug msg="cached supported flag" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage supported=63 time=1495738842316 txCR=1495738842 txID=11538d98-242e-493f-4ae9-f23528979a78
time="2017-05-25T12:00:42-07:00" level=info msg="initializing instance ID cache" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842316
time="2017-05-25T12:00:42-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842316 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="invoking executor cli" args=[vfs instanceID] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842316 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842345 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="sending instanceID in API.InstanceInspect call" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842345 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /services/vfs?instance HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Instanceid: vfs=,,InBlcnNlcGhvbmUubG9jYWwi"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=736ce3b5-70f8-414f-5fc3-a37ddb893207, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg="http request" host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=schema-validator route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-svc-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=service-validator route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=local-devices-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=instanceIDs-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-global-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=error-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=logging-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=query-params-handler route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="query param" host="unix:///var/run/libstorage/368440648.sock" key=instance len(value)=1 route=serviceInspect server=lime-gem-ws time=1495738842346 tls=false value=[]
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Tx="txID=736ce3b5-70f8-414f-5fc3-a37ddb893207, txCR=1495738842" host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws time=1495738842347 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Instanceid=[vfs=,,InBlcnNlcGhvbmUubG9jYWwi] host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Localdevices=[] host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="getting storage service" host="unix:///var/run/libstorage/368440648.sock" route=serviceInspect server=lime-gem-ws service=vfs time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" route=serviceInspect server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="vfs login=vfs=,,InBlcnNlcGhvbmUubG9jYWwi" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" route=serviceInspect server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842347 tls=false txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=info msg=" - - [25/May/2017:12:00:42 -0700] \"GET /services/vfs?instance HTTP/1.1\" 200 340"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /services/vfs?instance HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Instanceid: vfs=,,InBlcnNlcGhvbmUubG9jYWwi"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=736ce3b5-70f8-414f-5fc3-a37ddb893207, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"instance\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"instanceID\": {"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" \"id\": \"persephone.local\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"service\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" },"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfsInstance\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"providerName\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" },"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Length: 340"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:00:42-07:00" level=info msg=" Date: Thu, 25 May 2017 19:00:42 GMT"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Servername: lime-gem-ws"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"instance\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"instanceID\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"id\": \"persephone.local\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"service\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" },"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfsInstance\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"providerName\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" },"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"driver\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"name\": \"vfs\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"type\": \"object\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"nextDevice\": {"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"ignore\": true,"
time="2017-05-25T12:00:42-07:00" level=info msg=" \"prefix\": \"\","
time="2017-05-25T12:00:42-07:00" level=info msg=" \"pattern\": \"\""
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=info msg=" }"
time="2017-05-25T12:00:42-07:00" level=debug msg="received instanceID from API.InstanceInspect call" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs=,,InBlcnNlcGhvbmUubG9jYWwi" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842348 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="cached instanceID" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842348 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=debug msg="xli instanceID success" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842348 txCR=1495738842 txID=736ce3b5-70f8-414f-5fc3-a37ddb893207
time="2017-05-25T12:00:42-07:00" level=info msg="successefully dialed libStorage server" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842348
time="2017-05-25T12:00:42-07:00" level=info msg="storage driver initialized" host="unix:///var/run/libstorage/368440648.sock" service=vfs storageDriver=libstorage time=1495738842348
time="2017-05-25T12:00:42-07:00" level=info msg="os driver initialized" host="unix:///var/run/libstorage/368440648.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495738842349
time="2017-05-25T12:00:42-07:00" level=warning msg="no integration driver found" host="unix:///var/run/libstorage/368440648.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495738842349
time="2017-05-25T12:00:42-07:00" level=info msg="created libStorage client" host="unix:///var/run/libstorage/368440648.sock" osDriver=darwin service=vfs storageDriver=libstorage time=1495738842349
time="2017-05-25T12:00:42-07:00" level=debug msg="waiting on executor lock" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842349 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="invoking executor cli" args=[vfs localDevices quick] cmd="/var/lib/libstorage/lsx-darwin" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842349 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="signalling executor lock" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842374 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvda" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842375 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdb" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842375 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdc" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842375 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=warning msg="removing local device w/ invalid volume id" deviceID="/dev/xvdd" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842375 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="xli localdevices success" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" osDriver=darwin server=lime-gem-ws service=vfs storageDriver=libstorage time=1495738842375 txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /volumes/vfs?attachments=1 HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Instanceid: vfs:vfs=persephone.local"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Localdevices: vfs="
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=b4fcbe30-c151-41de-7a44-4a64481d512f, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg="http request" host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=schema-validator route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=storage-session-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-svc-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added route middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=service-validator route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=local-devices-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=instanceIDs-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=auth-global-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=error-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=transaction-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=logging-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="added global middleware" host="unix:///var/run/libstorage/368440648.sock" middleware=query-params-handler route=volumesForService server=lime-gem-ws time=1495738842376 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="query param" host="unix:///var/run/libstorage/368440648.sock" key=attachments len(value)=1 route=volumesForService server=lime-gem-ws time=1495738842376 tls=false value=[1]
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Tx="txID=b4fcbe30-c151-41de-7a44-4a64481d512f, txCR=1495738842" host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws time=1495738842377 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping global auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Instanceid=[vfs:vfs=persephone.local] host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="http header" Libstorage-Localdevices=[vfs=] host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="getting storage service" host="unix:///var/run/libstorage/368440648.sock" route=volumesForService server=lime-gem-ws service=vfs time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping svc auth handler; empty allow & deny lists" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="vfs login=vfs:vfs=persephone.local" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="getting task service" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=info msg="executing task" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="querying volumes" attachments=1 host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="skipping response schema validation; disabled" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="task completed" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 time=1495738842377 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="getting task service" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs time=1495738842378 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=info msg=" - - [25/May/2017:12:00:42 -0700] \"GET /volumes/vfs?attachments=1 HTTP/1.1\" 200 2"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP REQUEST (SERVER) --------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" GET /volumes/vfs?attachments=1 HTTP/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" Host: libstorage-server"
time="2017-05-25T12:00:42-07:00" level=info msg=" Accept-Encoding: gzip"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Instanceid: vfs:vfs=persephone.local"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Localdevices: vfs="
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Tx: txID=b4fcbe30-c151-41de-7a44-4a64481d512f, txCR=1495738842"
time="2017-05-25T12:00:42-07:00" level=info msg=" User-Agent: Go-http-client/1.1"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (SERVER) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type=application/json"
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info
time="2017-05-25T12:00:42-07:00" level=info msg=" {}"
time="2017-05-25T12:00:42-07:00" level=info msg=" -------------------------- HTTP RESPONSE (CLIENT) -------------------------"
time="2017-05-25T12:00:42-07:00" level=info msg=" HTTP/1.1 200 OK"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Length: 2"
time="2017-05-25T12:00:42-07:00" level=info msg=" Content-Type: application/json"
time="2017-05-25T12:00:42-07:00" level=info msg=" Date: Thu, 25 May 2017 19:00:42 GMT"
time="2017-05-25T12:00:42-07:00" level=info msg=" Libstorage-Servername: lime-gem-ws"
time="2017-05-25T12:00:42-07:00" level=info msg=" "
time="2017-05-25T12:00:42-07:00" level=info msg=" {}"
time="2017-05-25T12:00:42-07:00" level=debug msg="built output template" host="unix:///var/run/libstorage/368440648.sock" template="{{define \"printObject\"}}{{printf \"%v\" .}}{{end}}{{define \"printVolumeFields\"}}{{.ID}}\t{{.Name}}\t{{.AttachmentState | printAttState}}\t{{.Size}}{{end}}{{define \"printEncVolumeFields\"}}{{.ID}}\t{{.Name}}\t{{.AttachmentState | printAttState}}\t{{.Size}}\t{{.Encrypted}}{{end}}{{define \"printInstanceFields\"}}{{.InstanceID.ID}}\t{{.Name}}\t{{.ProviderName}}\t{{.Region}}{{end}}{{define \"printScriptFields\"}}{{.Path}}\t{{.Installed}}\t{{.Modified}}{{end}}{{define \"printStringSlice\"}}{{.}}{{end}}{{define \"printJSON\"}}{{. | json}}{{end}}{{define \"printPrettyJSON\"}}{{. | jsonp}}{{end}}{{define \"printSnapshotFields\"}}{{.ID}}\t{{.Name}}\t{{.Status}}\t{{.VolumeID}}{{end}}{{define \"printServiceFields\"}}{{.Name}}\t{{.Driver.Name}}{{end}}{{define \"printMountFields\"}}{{.ID}}\t{{.Source}}\t{{.MountPoint}}{{end}}{{define \"printVolumeID\"}}{{.ID}}{{end}}{{define \"printVolumeWithPathFields\"}}{{.ID}}\t{{.Name}}\t{{.Volume.AttachmentState | printAttState}}\t{{.Size}}\t{{.Path}}{{end}}{{define \"printEncVolumeWithPathFields\"}}{{.ID}}\t{{.Name}}\t{{.Volume.AttachmentState | printAttState}}\t{{.Size}}\t{{.Encrypted}}\t{{.Path}}{{end}}{{define \"printAuthTokenFields\"}}{{.Subject}}\t{{.IssuedAt}}\t{{.NotBefore}}\t{{.Expires}}{{end}}ID\tName\tStatus\tSize\n{{range sort .D \"Name\" }}{{template \"printVolumeFields\" .}}\n{{end}}" time=1495738842378
time="2017-05-25T12:00:42-07:00" level=debug msg="removing task" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" removedAfter=0s route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 tasksLen=1 time=1495738842379 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
time="2017-05-25T12:00:42-07:00" level=debug msg="removed task" host="unix:///var/run/libstorage/368440648.sock" instanceID="vfs:vfs=persephone.local" route=volumesForService server=lime-gem-ws service=vfs storageDriver=vfs task=0 tasksLen=0 time=1495738842379 tls=false txCR=1495738842 txID=b4fcbe30-c151-41de-7a44-4a64481d512f
ID Name Status Size
time="2017-05-25T12:00:42-07:00" level=debug msg="waiting until libStorage is stopped" host="unix:///var/run/libstorage/368440648.sock" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=info msg="shutting down server" server=lime-gem-ws time=1495738842380
time="2017-05-25T12:00:42-07:00" level=info msg="shutting down endpoint" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws time=1495738842380 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="removed unix socket" host="unix:///var/run/libstorage/368440648.sock" path="/var/run/libstorage/368440648.sock" server=lime-gem-ws time=1495738842380 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="shutdown endpoint complete" host="unix:///var/run/libstorage/368440648.sock" server=lime-gem-ws time=1495738842380 tls=false
time="2017-05-25T12:00:42-07:00" level=debug msg="shutdown server complete" server=lime-gem-ws time=1495738842380
time="2017-05-25T12:00:42-07:00" level=debug msg="received close signal" server=lime-gem-ws time=1495738842380
time="2017-05-25T12:00:42-07:00" level=info msg="closed server error channel" server=lime-gem-ws time=1495738842380
time="2017-05-25T12:00:42-07:00" level=info msg="all servers closed"
time="2017-05-25T12:00:42-07:00" level=debug msg="done sending close signals to libStorage" host="unix:///var/run/libstorage/368440648.sock" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=debug msg="removed spec file" host="unix:///var/run/libstorage/368440648.sock" path="/var/run/rexray/rexray.spec" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=debug msg="done waiting on err chan" host="unix:///var/run/libstorage/368440648.sock" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=debug msg="completed cli execution" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=info msg="exiting process" time=1495738842380
time="2017-05-25T12:00:42-07:00" level=debug msg="completed onExit at end of program" time=1495738842380
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment