search

jeff1evesque / machine-learning

Web-interface + rest API for classification and regression (https://jeff1evesque.github.io/machine-learning.docs)
Other
257 stars 85 forks source link

Rancher AWS instance unhealthy #3271

Closed jeff1evesque closed 6 years ago

jeff1evesque commented 6 years ago

Our deployed rancher instance, on AWS is unhealthy:

rancher

We may need to look into adjusting our install_rancher script.

jeff1evesque commented 6 years ago

Each container has the following rancher log, when attempting to manually start the service:

mongodb-log

jeff1evesque commented 6 years ago

When we attempt to view our rancher-agent logs:

root@ip-xxx-xxx-xxx-xxx:/home/ubuntu# docker logs -f rancher-agent
[...TRACE-REDUCED...]
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:41:39Z" level=fatal msg="Failed to find state.json"
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:42:39Z" level=fatal msg="Failed to find state.json"
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:43:40Z" level=fatal msg="Failed to find state.json"
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:44:40Z" level=fatal msg="Failed to find state.json"
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:45:40Z" level=fatal msg="Failed to find state.json"
Found container ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Checking root: /host/run/runc
Checking root: /host/var/run/runc
Checking root: /host/run/docker/execdriver/native
Checking root: /host/var/run/docker/execdriver/native
time="2018-06-23T13:46:41Z" level=fatal msg="Failed to find state.json"
jeff1evesque commented 6 years ago

The following is our rancher server logs:

root@ip-xxx-xxx-xxx-xxx:/home/ubuntu# docker logs -f rancher
180622  0:59:33 [Note] /usr/sbin/mysqld (mysqld 5.5.59-0ubuntu0.14.04.1) starting as process 25 ...
Uptime: 2  Threads: 1  Questions: 2  Slow queries: 0  Opens: 33  Flush tables: 1  Open tables: 26  Queries per second avg: 1.000
Setting up database
Importing schema
CATTLE_AGENT_PACKAGE_HOST_API_URL=/usr/share/cattle/artifacts/host-api.tar.gz
CATTLE_AGENT_PACKAGE_PER_HOST_SUBNET_URL=/usr/share/cattle/artifacts/rancher-per-host-subnet.zip
CATTLE_AGENT_PACKAGE_PYTHON_AGENT_URL=/usr/share/cattle/artifacts/go-agent.tar.gz
CATTLE_AGENT_PACKAGE_WINDOWS_AGENT_URL=/usr/share/cattle/artifacts/go-agent.zip
CATTLE_API_UI_URL=//releases.rancher.com/api-ui/1.0.8
CATTLE_CATTLE_VERSION=v0.183.52
CATTLE_DB_CATTLE_DATABASE=mysql
CATTLE_DB_CATTLE_MYSQL_HOST=localhost
CATTLE_DB_CATTLE_MYSQL_NAME=cattle
CATTLE_DB_CATTLE_MYSQL_PORT=3306
CATTLE_DB_CATTLE_USERNAME=cattle
CATTLE_GRAPHITE_HOST=
CATTLE_GRAPHITE_PORT=
CATTLE_HOME=/var/lib/cattle
CATTLE_HOST_API_PROXY_MODE=embedded
CATTLE_LOGBACK_OUTPUT_GELF_HOST=
CATTLE_LOGBACK_OUTPUT_GELF_PORT=
CATTLE_RANCHER_CLI_VERSION=v0.6.10
CATTLE_RANCHER_COMPOSE_VERSION=v0.12.5
CATTLE_RANCHER_SERVER_IMAGE=rancher/server
CATTLE_RANCHER_SERVER_VERSION=v1.6.18
CATTLE_USE_LOCAL_ARTIFACTS=true
DEFAULT_CATTLE_API_UI_CSS_URL=/api-ui/ui.min.css
DEFAULT_CATTLE_API_UI_INDEX=//releases.rancher.com/ui/1.6.43
DEFAULT_CATTLE_API_UI_JS_URL=/api-ui/ui.min.js
DEFAULT_CATTLE_AUTH_SERVICE_EXECUTE=true
DEFAULT_CATTLE_CATALOG_EXECUTE=true
DEFAULT_CATTLE_CATALOG_URL={"catalogs":{"community":{"url":"https://git.rancher.io/community-catalog.git","branch":"master"},"library":{"url":"https://git.rancher.io/rancher-catalog.git","branch":"${RELEASE}"}}}
DEFAULT_CATTLE_COMPOSE_EXECUTOR_EXECUTE=true
DEFAULT_CATTLE_MACHINE_EXECUTE=true
DEFAULT_CATTLE_RANCHER_CLI_DARWIN_URL=https://releases.rancher.com/cli/v0.6.10/rancher-darwin-amd64-v0.6.10.tar.gz
DEFAULT_CATTLE_RANCHER_CLI_LINUX_URL=https://releases.rancher.com/cli/v0.6.10/rancher-linux-amd64-v0.6.10.tar.gz
DEFAULT_CATTLE_RANCHER_CLI_WINDOWS_URL=https://releases.rancher.com/cli/v0.6.10/rancher-windows-386-v0.6.10.zip
DEFAULT_CATTLE_RANCHER_COMPOSE_DARWIN_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-darwin-amd64-v0.12.5.tar.gz
DEFAULT_CATTLE_RANCHER_COMPOSE_LINUX_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-linux-amd64-v0.12.5.tar.gz
DEFAULT_CATTLE_RANCHER_COMPOSE_WINDOWS_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-windows-386-v0.12.5.zip
DEFAULT_CATTLE_SECRETS_API_EXECUTE=true
DEFAULT_CATTLE_WEBHOOK_SERVICE_EXECUTE=true
00:59:46.430 [main] INFO  ConsoleStatus - Loading configuration
2018-06-22 00:59:55,236 INFO    [main] [ConsoleStatus] Starting DB migration
2018-06-22 00:59:59,025 WARN    [main] [liquibase] modifyDataType will lose primary key/autoincrement/not null settings for mysql.  Use <sql> and re-specify all configuration if this is the case
2018-06-22 00:59:59,030 WARN    [main] [liquibase] modifyDataType will lose primary key/autoincrement/not null settings for mysql.  Use <sql> and re-specify all configuration if this is the case
2018-06-22 00:59:59,030 WARN    [main] [liquibase] modifyDataType will lose primary key/autoincrement/not null settings for mysql.  Use <sql> and re-specify all configuration if this is the case
2018-06-22 01:00:04,279 INFO    [main] [ConsoleStatus] DB migration done
2018-06-22 01:00:05,019 INFO    [main] [ConsoleStatus] Cluster membership changed [127.0.0.1:9345]
2018-06-22 01:00:05,023 INFO    [main] [ConsoleStatus] Checking cluster state on start-up
2018-06-22 01:00:07,642 INFO    [main] [ConsoleStatus] Loading processes
2018-06-22 01:00:08,698 INFO    [main] [ConsoleStatus] Starting [1/93]: LockDelegatorImpl
2018-06-22 01:00:08,705 INFO    [main] [ConsoleStatus] Starting [2/93]: AnnotatedListenerRegistration
2018-06-22 01:00:08,718 INFO    [main] [ConsoleStatus] Starting [3/93]: EventService
2018-06-22 01:00:08,718 INFO    [main] [ConsoleStatus] Starting [4/93]: DefaultObjectMetaDataManager
2018-06-22 01:00:10,406 INFO    [main] [ConsoleStatus] Starting [5/93]: JsonDefaultsProvider
2018-06-22 01:00:10,692 INFO    [main] [ConsoleStatus] Starting [6/93]: ObjectDefaultsPostInstantiationHandler
2018-06-22 01:00:10,692 INFO    [main] [ConsoleStatus] Starting [7/93]: DefaultProcessManager
2018-06-22 01:00:10,693 INFO    [main] [ConsoleStatus] Starting [8/93]: SampleDataStartupV3
2018-06-22 01:00:11,472 INFO    [main] [ConsoleStatus] Starting [9/93]: TaskManagerImpl
2018-06-22 01:00:11,576 INFO    [main] [ConsoleStatus] Starting [10/93]: ServiceAccountCreateStartup
2018-06-22 01:00:13,592 INFO    [main] [ConsoleStatus] Starting [11/93]: WebsocketProxyLauncher
2018-06-22 01:00:13,592 INFO    [main] [ConsoleStatus] Starting [12/93]: SampleDataStartupV15
2018-06-22 01:00:13,599 INFO    [main] [ConsoleStatus] Starting [13/93]: SchemaFactory:v1-admin
2018-06-22 01:00:14,020 INFO    [main] [ConsoleStatus] Starting [14/93]: SchemaFactory:v1-agent
2018-06-22 01:00:14,040 INFO    [main] [ConsoleStatus] Starting [15/93]: SchemaFactory:v1-agentRegister
2018-06-22 01:00:14,044 INFO    [main] [ConsoleStatus] Starting [16/93]: SchemaFactory:v1-base
2018-06-22 01:00:14,516 INFO    [main] [ConsoleStatus] Starting [17/93]: SchemaFactory:v1-member
2018-06-22 01:00:14,763 INFO    [main] [ConsoleStatus] Starting [18/93]: SchemaFactory:v1-owner
2018-06-22 01:00:15,076 INFO    [main] [ConsoleStatus] Starting [19/93]: SchemaFactory:v1-project
2018-06-22 01:00:15,215 INFO    [main] [ConsoleStatus] Starting [20/93]: SchemaFactory:v1-projectadmin
2018-06-22 01:00:15,370 INFO    [main] [ConsoleStatus] Starting [21/93]: SchemaFactory:v1-readAdmin
2018-06-22 01:00:15,637 INFO    [main] [ConsoleStatus] Starting [22/93]: SchemaFactory:v1-readonly
time="2018-06-22T01:00:15Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:00:15Z" level=fatal msg="Error getting config." error="Invalid key content"
2018-06-22 01:00:15,906 INFO    [main] [ConsoleStatus] Starting [23/93]: SchemaFactory:v1-register
2018-06-22 01:00:15,924 INFO    [main] [ConsoleStatus] Starting [24/93]: SchemaFactory:v1-restricted
2018-06-22 01:00:16,118 INFO    [main] [ConsoleStatus] Starting [25/93]: SchemaFactory:v1-service
2018-06-22 01:00:16,369 INFO    [main] [ConsoleStatus] Starting [26/93]: SchemaFactory:v1-token
2018-06-22 01:00:16,372 INFO    [main] [ConsoleStatus] Starting [27/93]: SchemaFactory:v1-user
2018-06-22 01:00:16,512 INFO    [main] [ConsoleStatus] Starting [28/93]: AgentBasedProcessHandler
2018-06-22 01:00:16,513 INFO    [main] [ConsoleStatus] Starting [29/93]: AgentHostStateUpdate
2018-06-22 01:00:16,513 INFO    [main] [ConsoleStatus] Starting [30/93]: AgentManager
2018-06-22 01:00:16,513 INFO    [main] [ConsoleStatus] Starting [31/93]: AuthServiceLauncher
2018-06-22 01:00:16,514 INFO    [main] [ConsoleStatus] Starting [32/93]: BackupCreate
2018-06-22 01:00:16,516 INFO    [main] [ConsoleStatus] Starting [33/93]: BackupRemove
2018-06-22 01:00:16,522 INFO    [main] [ConsoleStatus] Starting [34/93]: CatalogLauncher
2018-06-22 01:00:16,523 INFO    [main] [ConsoleStatus] Starting [35/93]: ComposeExecutorLauncher
2018-06-22 01:00:16,523 INFO    [main] [ConsoleStatus] Starting [36/93]: ConfigItemRegistryImpl
2018-06-22 01:00:16,818 INFO    [main] [ConsoleStatus] Starting [37/93]: ConfigItemServerImpl
time="2018-06-22T01:00:17Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:00:17Z" level=fatal msg="Error getting config." error="Invalid key content"
2018-06-22 01:00:18,156 INFO    [main] [ConsoleStatus] Starting [38/93]: ConfigUpdatePublisher
2018-06-22 01:00:18,156 INFO    [main] [ConsoleStatus] Starting [39/93]: DataManager
2018-06-22 01:00:18,156 INFO    [main] [ConsoleStatus] Starting [40/93]: DefaultAuthorizationProvider
time="2018-06-22T01:00:18Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:00:18Z" level=fatal msg="Unable to create event router" error="Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
time="2018-06-22T01:00:18Z" level=warning msg="Couldn't load install uuid: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
time="2018-06-22T01:00:18Z" level=info msg="Starting Catalog Service (port 8088, refresh interval 300 seconds)"
time="2018-06-22T01:00:18Z" level=fatal msg="Failed to configure cattle client: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: connect: connection refused"
time="2018-06-22T01:00:19Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:00:19Z" level=fatal msg="Error getting config." error="Invalid key content"
time="2018-06-22T01:00:20Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:00:20Z" level=fatal msg="Unable to create event router" error="Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
time="2018-06-22T01:00:20Z" level=fatal msg="Failed to configure cattle client: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: connect: connection refused"
time="2018-06-22T01:00:21Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:00:21Z" level=fatal msg="Error getting config." error="Invalid key content"
2018-06-22 01:00:22,032 INFO    [main] [ConsoleStatus] Starting [41/93]: DefaultJooqResourceManager
2018-06-22 01:00:22,033 INFO    [main] [ConsoleStatus] Starting [42/93]: DefaultObjectSerializerFactoryImpl
2018-06-22 01:00:22,034 INFO    [main] [ConsoleStatus] Starting [43/93]: DockerComposeStackHandler
2018-06-22 01:00:22,035 INFO    [main] [ConsoleStatus] Starting [44/93]: DynamicExtensionManager
2018-06-22 01:00:22,035 INFO    [main] [ConsoleStatus] Starting [45/93]: ExtensionResourceManagerLocator
2018-06-22 01:00:22,035 INFO    [main] [ConsoleStatus] Starting [46/93]: HostApiRSAKeyProvider
2018-06-22 01:00:22,035 INFO    [main] [ConsoleStatus] Starting [47/93]: HostTemplateManager
2018-06-22 01:00:22,035 INFO    [main] [ConsoleStatus] Starting [48/93]: ImageStoragePoolMapActivate
2018-06-22 01:00:22,039 INFO    [main] [ConsoleStatus] Starting [49/93]: InstanceHostMapActivate
2018-06-22 01:00:22,040 INFO    [main] [ConsoleStatus] Starting [50/93]: InstanceHostMapDeactivate
2018-06-22 01:00:22,041 INFO    [main] [ConsoleStatus] Starting [51/93]: InstanceManager
2018-06-22 01:00:22,042 INFO    [main] [ConsoleStatus] Starting [52/93]: LoadBalancerServiceInstanceStopPreListener
2018-06-22 01:00:22,043 INFO    [main] [ConsoleStatus] Starting [53/93]: MachineDriverLoader
2018-06-22 01:00:22,046 INFO    [main] [ConsoleStatus] Starting [54/93]: MachineLauncher
2018-06-22 01:00:22,046 INFO    [main] [ConsoleStatus] Starting [55/93]: MetadataConfigItemFactory
2018-06-22 01:00:22,054 INFO    [main] [ConsoleStatus] Starting [56/93]: MountRemove
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [57/93]: PostInstancePurge
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [58/93]: PostStartLabelsProviders
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [59/93]: ProjectMemberResourceManager
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [60/93]: ProjectResourceManager
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [61/93]: PullTaskCreate
2018-06-22 01:00:22,055 INFO    [main] [ConsoleStatus] Starting [62/93]: RestoreFromBackup
2018-06-22 01:00:22,056 INFO    [main] [ConsoleStatus] Starting [63/93]: RevertToSnapshot
2018-06-22 01:00:22,056 INFO    [main] [ConsoleStatus] Starting [64/93]: SampleDataStartupV10
2018-06-22 01:00:22,276 INFO    [main] [ConsoleStatus] Starting [65/93]: SampleDataStartupV11
2018-06-22 01:00:22,285 INFO    [main] [ConsoleStatus] Starting [66/93]: SampleDataStartupV12
2018-06-22 01:00:22,308 INFO    [main] [ConsoleStatus] Starting [67/93]: SampleDataStartupV13
2018-06-22 01:00:22,365 INFO    [main] [ConsoleStatus] Starting [68/93]: SampleDataStartupV14
2018-06-22 01:00:22,371 INFO    [main] [ConsoleStatus] Starting [69/93]: SampleDataStartupV16
2018-06-22 01:00:22,393 INFO    [main] [ConsoleStatus] Starting [70/93]: SampleDataStartupV17
2018-06-22 01:00:22,399 INFO    [main] [ConsoleStatus] Starting [71/93]: SampleDataStartupV5
2018-06-22 01:00:22,409 INFO    [main] [ConsoleStatus] Starting [72/93]: SampleDataStartupV6
2018-06-22 01:00:22,422 INFO    [main] [ConsoleStatus] Starting [73/93]: SampleDataStartupV7
2018-06-22 01:00:22,435 INFO    [main] [ConsoleStatus] Starting [74/93]: SampleDataStartupV8
2018-06-22 01:00:22,447 INFO    [main] [ConsoleStatus] Starting [75/93]: SampleDataStartupV9
2018-06-22 01:00:22,455 INFO    [main] [ConsoleStatus] Starting [76/93]: SecretManager
2018-06-22 01:00:22,455 INFO    [main] [ConsoleStatus] Starting [77/93]: SecretsApiLauncher
2018-06-22 01:00:22,455 INFO    [main] [ConsoleStatus] Starting [78/93]: ServiceManager
2018-06-22 01:00:22,455 INFO    [main] [ConsoleStatus] Starting [79/93]: SettingManager
2018-06-22 01:00:22,456 INFO    [main] [ConsoleStatus] Starting [80/93]: SnapshotCreate
2018-06-22 01:00:22,456 INFO    [main] [ConsoleStatus] Starting [81/93]: SnapshotRemove
2018-06-22 01:00:22,456 INFO    [main] [ConsoleStatus] Starting [82/93]: StackAgentHandler
2018-06-22 01:00:22,456 INFO    [main] [ConsoleStatus] Starting [83/93]: StackAgentHandler
2018-06-22 01:00:22,456 INFO    [main] [ConsoleStatus] Starting [84/93]: StackAgentHandler
2018-06-22 01:00:22,457 INFO    [main] [ConsoleStatus] Starting [85/93]: StackAgentHandler
2018-06-22 01:00:22,457 INFO    [main] [ConsoleStatus] Starting [86/93]: StackAgentHandler
2018-06-22 01:00:22,457 INFO    [main] [ConsoleStatus] Starting [87/93]: TelemetryLauncher
2018-06-22 01:00:22,457 INFO    [main] [ConsoleStatus] Starting [88/93]: VolumeManager
2018-06-22 01:00:22,457 INFO    [main] [ConsoleStatus] Starting [89/93]: VolumeRemove
2018-06-22 01:00:22,458 INFO    [main] [ConsoleStatus] Starting [90/93]: VolumeStoragePoolMapActivate
2018-06-22 01:00:22,458 INFO    [main] [ConsoleStatus] Starting [91/93]: VolumeStoragePoolMapRemove
2018-06-22 01:00:22,458 INFO    [main] [ConsoleStatus] Starting [92/93]: WebhookServiceLauncher
2018-06-22 01:00:22,458 INFO    [main] [ConsoleStatus] Starting [93/93]: project.template.reload
time="2018-06-22T01:00:22Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:00:22Z" level=fatal msg="Unable to create event router" error="Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
2018-06-22 01:00:22,698 INFO    [main] [ConsoleStatus] [DONE ] [42564ms] Startup Succeeded, Listening on port 8081
time="2018-06-22T01:00:22Z" level=fatal msg="Failed to configure cattle client: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: connect: connection refused"
time="2018-06-22T01:00:23Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:00:24Z" level=info msg="Starting websocket proxy. Listening on [:8080], Proxying to cattle API at [localhost:8081], Monitoring parent pid [8]."
time="2018-06-22T01:00:24Z" level=info msg="Configured http API filter"
time="2018-06-22T01:00:24Z" level=info msg="Configured authTokenValidator API filter"
time="2018-06-22T01:00:24Z" level=info msg="Master config file: master.conf"
time="2018-06-22T01:00:24Z" level=info msg="Starting go-machine-service..." gitcommit=v0.39.2 service=gms
time="2018-06-22T01:00:24Z" level=info msg="Waiting for handler registration (1/2)" service=gms
time="2018-06-22T01:00:24Z" level=info msg="Downloading certificate from http://localhost:8081/v1/credentials/1c1/certificate"
time="2018-06-22T01:00:24Z" level=info msg="Webhook service listening on 8085"
time="2018-06-22T01:00:24Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:00:25Z" level=error msg="Failed to perform catalog refresh: [Catalog refresh failed for community (https://git.rancher.io/community-catalog.git): Update failed: exit status 1]"
time="2018-06-22T01:00:27Z" level=info msg="Starting Rancher Auth service"
time="2018-06-22T01:00:28Z" level=info msg="Initializing event router" workerCount=5
time="2018-06-22T01:00:28Z" level=info msg="Connection established"
time="2018-06-22T01:00:28Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:00:28Z" level=info msg="Waiting for handler registration (2/2)" service=gms
time="2018-06-22T01:00:29Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:00:29Z" level=info msg="Connection established"
time="2018-06-22T01:00:29Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:00:29Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:00:29Z" level=info msg="Connection established"
time="2018-06-22T01:00:29Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:00:29Z" level=info msg="No Auth provider configured"
time="2018-06-22T01:00:29Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:00:30Z" level=info msg="Connection established"
time="2018-06-22T01:00:30Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:00:30Z" level=info msg="Installing builtin drivers" service=gms
time="2018-06-22T01:00:30Z" level=info msg="Listening on :8090"
time="2018-06-22T01:00:33Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:34Z" level=info msg="Stack Create Event Received" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:34Z" level=info msg="Stack Create Event Received" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:34Z" level=info msg="Stack Create Event Received" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:34Z" level=info msg="Stack Create Event Received" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:35Z" level=info msg="[scheduler:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:35Z" level=info msg="[scheduler:scheduler]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:35Z" level=info msg="[network-services:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:35Z" level=info msg="[network-services:network-manager]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:35Z" level=info msg="Creating service scheduler"
time="2018-06-22T01:00:35Z" level=info msg="[network-services:metadata]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:35Z" level=info msg="[healthcheck:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:35Z" level=info msg="[healthcheck:healthcheck]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:35Z" level=info msg="Creating service metadata"
time="2018-06-22T01:00:35Z" level=info msg="Creating service network-manager"
time="2018-06-22T01:00:35Z" level=info msg="[ipsec:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:35Z" level=info msg="[ipsec:cni-driver]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:35Z" level=info msg="[ipsec:ipsec]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:35Z" level=info msg="Creating service healthcheck"
time="2018-06-22T01:00:35Z" level=info msg="Creating service cni-driver"
time="2018-06-22T01:00:35Z" level=info msg="Creating service ipsec"
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:healthcheck]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:healthcheck]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:cni-driver]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:healthcheck]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[healthcheck:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="Stack Create Event Done" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st1
time="2018-06-22T01:00:36Z" level=info msg="[network-services:network-manager]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:scheduler]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:scheduler]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:36Z" level=info msg="[network-services:metadata]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:dns]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:dns]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:scheduler]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="[scheduler:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="Stack Create Event Done" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st4
time="2018-06-22T01:00:36Z" level=info msg="[network-services:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:metadata]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:network-manager]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:ipsec]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:router]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:router]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:connectivity-check]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:connectivity-check]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[network-services:network-manager]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:metadata]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:dns]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[network-services:dns]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:]: Creating project " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:cni-driver]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[ipsec:ipsec]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:36Z" level=info msg="[network-services:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:36Z" level=info msg="Stack Create Event Done" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st3
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:ipsec]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:router]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:router]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:connectivity-check]: Creating " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:connectivity-check]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:cni-driver]: Created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="[ipsec:]: Project created " eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:37Z" level=info msg="Stack Create Event Done" eventId=xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx resourceId=1st2
time="2018-06-22T01:00:39Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:42Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:43Z" level=info msg="Stack Create Event Received" eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="Creating volume template mariadb"
time="2018-06-22T01:00:43Z" level=info msg="Creating volume template mongodb"
time="2018-06-22T01:00:43Z" level=info msg="Creating volume template redis"
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:]: Creating project " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:webserver-api]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:webserver-web]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:mariadb]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:redis]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:sass]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:mongodb]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:browserify]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:nginx-web]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:43Z" level=info msg="[mlstack:nginx-api]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:44Z" level=info msg="Creating service webserver-api"
time="2018-06-22T01:00:44Z" level=info msg="Creating service mariadb"
time="2018-06-22T01:00:44Z" level=info msg="Creating service webserver-web"
time="2018-06-22T01:00:44Z" level=info msg="Creating service nginx-api"
time="2018-06-22T01:00:44Z" level=info msg="Creating service mongodb"
time="2018-06-22T01:00:44Z" level=info msg="Creating service browserify"
time="2018-06-22T01:00:44Z" level=info msg="Creating service nginx-web"
time="2018-06-22T01:00:44Z" level=info msg="Creating service sass"
time="2018-06-22T01:00:44Z" level=info msg="Creating service redis"
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-api]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mongodb]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-web]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mariadb]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-api]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-web]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:redis]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:sass]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:browserify]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:]: Project created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:45Z" level=info msg="Existing volume template found for mariadb"
time="2018-06-22T01:00:45Z" level=info msg="Existing volume template found for mongodb"
time="2018-06-22T01:00:45Z" level=info msg="Existing volume template found for redis"
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:]: Creating project " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:browserify]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-web]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mariadb]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-api]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:sass]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mongodb]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-web]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:redis]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-api]: Creating " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:redis]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mariadb]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:browserify]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-web]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:mongodb]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-web]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:nginx-api]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:sass]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:45Z" level=info msg="[mlstack:webserver-api]: Created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:]: Project created " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="Existing volume template found for mariadb"
time="2018-06-22T01:00:46Z" level=info msg="Existing volume template found for mongodb"
time="2018-06-22T01:00:46Z" level=info msg="Existing volume template found for redis"
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:]: Starting project " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:webserver-web]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:mariadb]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:mongodb]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:browserify]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:nginx-api]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:redis]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:sass]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:nginx-web]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:webserver-api]: Starting " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:webserver-web]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:nginx-web]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:sass]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:webserver-api]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:redis]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:mariadb]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:nginx-api]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:browserify]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:46Z" level=info msg="[mlstack:mongodb]: Started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:47Z" level=info msg="[mlstack:]: Project started " eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:47Z" level=info msg="Stack Create Event Done" eventId=9db32014-1f73-4e26-83aa-c3f238fb839b resourceId=1st5
time="2018-06-22T01:00:48Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:51Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:54Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:00:57Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:01:00Z" level=info msg="machinedriver.activate event detected" service=gms
time="2018-06-22T01:01:00Z" level=info msg="Activating driver packet" service=gms
time="2018-06-22T01:01:00Z" level=info msg="Activating driver amazonec2" service=gms
time="2018-06-22T01:01:00Z" level=info msg=Event eventId=07565900-0850-4ef0-abca-552fcb41e530 name="machinedriver.activate;handler=goMachineService-machine" resourceId=1md1 service=gms
time="2018-06-22T01:01:00Z" level=info msg=Event eventId=8d83472b-c4ff-49ce-8d63-5225ed777bfa name="machinedriver.activate;handler=goMachineService-machine" resourceId=1md2 service=gms
time="2018-06-22T01:01:00Z" level=info msg="Activating driver azure" service=gms
time="2018-06-22T01:01:00Z" level=info msg="Download https://github.com/packethost/docker-machine-driver-packet/releases/download/v0.1.2/docker-machine-driver-packet_linux-amd64.zip" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Activating driver digitalocean" service=gms
time="2018-06-22T01:01:01Z" level=info msg=Event eventId=af3e68a7-5176-44b4-b161-bd294d62f3d3 name="machinedriver.activate;handler=goMachineService-machine" resourceId=1md3 service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver exoscale" service=gms
time="2018-06-22T01:01:01Z" level=info msg=Event eventId=2cbe99b5-4741-4d9b-87e7-b85414b272bd name="machinedriver.activate;handler=goMachineService-machine" resourceId=1md4 service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver generic" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver google" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver openstack" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver rackspace" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver softlayer" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver vmwarevcloudair" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Creating schema amazonec2Config, roles [service member owner project admin user readAdmin readonly restricted]" id=1ds1 service=gms
time="2018-06-22T01:01:01Z" level=info msg="Installing builtin driver vmwarevsphere" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Downloading all drivers" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Found driver docker-machine-driver-packet" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Copying /var/lib/cattle/machine-drivers/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx-docker-machine-driver-packet => /usr/local/bin/docker-machine-driver-packet-tmp" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Done downloading all drivers" service=gms
time="2018-06-22T01:01:01Z" level=info msg="Creating schema azureConfig, roles [service member owner project admin user readAdmin readonly restricted]" id=1ds2 service=gms
time="2018-06-22T01:01:02Z" level=info msg="Creating schema digitaloceanConfig, roles [service member owner project admin user readAdmin readonly restricted]" id=1ds3 service=gms
time="2018-06-22T01:01:02Z" level=info msg="Updating machine jsons for  [amazonec2 packet amazonec2 azure digitalocean]" service=gms
time="2018-06-22T01:01:02Z" level=info msg="Creating schema machine, roles [service]" id=1ds4 service=gms
time="2018-06-22T01:01:02Z" level=info msg="Creating schema host, roles [service]" id=1ds5 service=gms
time="2018-06-22T01:01:03Z" level=info msg="Creating schema machine, roles [project member owner]" id=1ds6 service=gms
time="2018-06-22T01:01:03Z" level=info msg="Creating schema host, roles [project member owner]" id=1ds7 service=gms
time="2018-06-22T01:01:03Z" level=info msg="Creating schema machine, roles [admin user readAdmin]" id=1ds8 service=gms
time="2018-06-22T01:01:03Z" level=info msg="Creating schema host, roles [admin user readAdmin]" id=1ds9 service=gms
time="2018-06-22T01:01:04Z" level=info msg="Creating schema machine, roles [readonly]" id=1ds10 service=gms
time="2018-06-22T01:01:04Z" level=info msg="Creating schema host, roles [readonly]" id=1ds11 service=gms
time="2018-06-22T01:01:04Z" level=info msg="Creating schema packetConfig, roles [service member owner project admin user readAdmin readonly restricted]" id=1ds12 service=gms
time="2018-06-22T01:01:04Z" level=info msg="Updating machine jsons for  [azure packet amazonec2 azure digitalocean]" service=gms
time="2018-06-22T01:01:05Z" level=info msg="Creating schema machine, roles [service]" id=1ds13 service=gms
time="2018-06-22T01:01:06Z" level=info msg="Creating schema host, roles [service]" id=1ds14 service=gms
time="2018-06-22T01:01:06Z" level=info msg="Creating schema machine, roles [project member owner]" id=1ds15 service=gms
2018-06-22 01:01:06,732 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [3]
time="2018-06-22T01:01:06Z" level=info msg="Creating schema host, roles [project member owner]" id=1ds16 service=gms
time="2018-06-22T01:01:07Z" level=info msg="Creating schema machine, roles [admin user readAdmin]" id=1ds17 service=gms
time="2018-06-22T01:01:07Z" level=info msg="Creating schema host, roles [admin user readAdmin]" id=1ds18 service=gms
time="2018-06-22T01:01:07Z" level=info msg="Creating schema machine, roles [readonly]" id=1ds19 service=gms
time="2018-06-22T01:01:07Z" level=info msg="Creating schema host, roles [readonly]" id=1ds20 service=gms
time="2018-06-22T01:01:07Z" level=info msg="Updating machine jsons for  [digitalocean packet amazonec2 azure digitalocean]" service=gms
time="2018-06-22T01:01:08Z" level=info msg="Creating schema machine, roles [service]" id=1ds21 service=gms
time="2018-06-22T01:01:09Z" level=info msg="Creating schema host, roles [service]" id=1ds22 service=gms
time="2018-06-22T01:01:09Z" level=info msg="Creating schema machine, roles [project member owner]" id=1ds23 service=gms
time="2018-06-22T01:01:09Z" level=info msg="Creating schema host, roles [project member owner]" id=1ds24 service=gms
time="2018-06-22T01:01:10Z" level=info msg="Creating schema machine, roles [admin user readAdmin]" id=1ds25 service=gms
time="2018-06-22T01:01:10Z" level=info msg="Creating schema host, roles [admin user readAdmin]" id=1ds26 service=gms
time="2018-06-22T01:01:10Z" level=info msg="Creating schema machine, roles [readonly]" id=1ds27 service=gms
time="2018-06-22T01:01:10Z" level=info msg="Creating schema host, roles [readonly]" id=1ds28 service=gms
time="2018-06-22T01:01:10Z" level=info msg="Updating machine jsons for  [packet packet amazonec2 azure digitalocean]" service=gms
time="2018-06-22T01:01:11Z" level=info msg="Creating schema machine, roles [service]" id=1ds29 service=gms
2018-06-22 01:01:11,734 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [4]
time="2018-06-22T01:01:12Z" level=info msg="Creating schema host, roles [service]" id=1ds30 service=gms
time="2018-06-22T01:01:12Z" level=info msg="Creating schema machine, roles [project member owner]" id=1ds31 service=gms
time="2018-06-22T01:01:12Z" level=info msg="Creating schema host, roles [project member owner]" id=1ds32 service=gms
time="2018-06-22T01:01:12Z" level=info msg="Creating schema machine, roles [admin user readAdmin]" id=1ds33 service=gms
time="2018-06-22T01:01:13Z" level=info msg="Creating schema host, roles [admin user readAdmin]" id=1ds34 service=gms
time="2018-06-22T01:01:13Z" level=info msg="Creating schema machine, roles [readonly]" id=1ds35 service=gms
time="2018-06-22T01:01:13Z" level=info msg="Creating schema host, roles [readonly]" id=1ds36 service=gms
2018-06-22 01:01:16,739 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [5]
2018-06-22 01:01:21,741 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [6]
2018-06-22 01:01:21,742 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Scheduling reconnect for agent [1] count [6]
2018-06-22 01:01:26,757 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [7]
2018-06-22 01:01:31,760 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [8]
2018-06-22 01:01:36,763 ERROR [:] [] [] [] [TaskScheduler-2] [i.c.p.a.s.ping.impl.PingMonitorImpl ] Failed to get ping from agent [1] count [9]
180622  1:29:24 [Note] /usr/sbin/mysqld (mysqld 5.5.59-0ubuntu0.14.04.1) starting as process 24 ...
Uptime: 2  Threads: 1  Questions: 2  Slow queries: 0  Opens: 35  Flush tables: 1  Open tables: 26  Queries per second avg: 1.000
Setting up database
CATTLE_AGENT_PACKAGE_HOST_API_URL=/usr/share/cattle/artifacts/host-api.tar.gz
CATTLE_AGENT_PACKAGE_PER_HOST_SUBNET_URL=/usr/share/cattle/artifacts/rancher-per-host-subnet.zip
CATTLE_AGENT_PACKAGE_PYTHON_AGENT_URL=/usr/share/cattle/artifacts/go-agent.tar.gz
CATTLE_AGENT_PACKAGE_WINDOWS_AGENT_URL=/usr/share/cattle/artifacts/go-agent.zip
CATTLE_API_UI_URL=//releases.rancher.com/api-ui/1.0.8
CATTLE_CATTLE_VERSION=v0.183.52
CATTLE_DB_CATTLE_DATABASE=mysql
CATTLE_DB_CATTLE_MYSQL_HOST=localhost
CATTLE_DB_CATTLE_MYSQL_NAME=cattle
CATTLE_DB_CATTLE_MYSQL_PORT=3306
CATTLE_DB_CATTLE_USERNAME=cattle
CATTLE_GRAPHITE_HOST=
CATTLE_GRAPHITE_PORT=
CATTLE_HOME=/var/lib/cattle
CATTLE_HOST_API_PROXY_MODE=embedded
CATTLE_LOGBACK_OUTPUT_GELF_HOST=
CATTLE_LOGBACK_OUTPUT_GELF_PORT=
CATTLE_RANCHER_CLI_VERSION=v0.6.10
CATTLE_RANCHER_COMPOSE_VERSION=v0.12.5
CATTLE_RANCHER_SERVER_IMAGE=rancher/server
CATTLE_RANCHER_SERVER_VERSION=v1.6.18
CATTLE_USE_LOCAL_ARTIFACTS=true
DEFAULT_CATTLE_API_UI_CSS_URL=/api-ui/ui.min.css
DEFAULT_CATTLE_API_UI_INDEX=//releases.rancher.com/ui/1.6.43
DEFAULT_CATTLE_API_UI_JS_URL=/api-ui/ui.min.js
DEFAULT_CATTLE_AUTH_SERVICE_EXECUTE=true
DEFAULT_CATTLE_CATALOG_EXECUTE=true
DEFAULT_CATTLE_CATALOG_URL={"catalogs":{"community":{"url":"https://git.rancher.io/community-catalog.git","branch":"master"},"library":{"url":"https://git.rancher.io/rancher-catalog.git","branch":"${RELEASE}"}}}
DEFAULT_CATTLE_COMPOSE_EXECUTOR_EXECUTE=true
DEFAULT_CATTLE_MACHINE_EXECUTE=true
DEFAULT_CATTLE_RANCHER_CLI_DARWIN_URL=https://releases.rancher.com/cli/v0.6.10/rancher-darwin-amd64-v0.6.10.tar.gz
DEFAULT_CATTLE_RANCHER_CLI_LINUX_URL=https://releases.rancher.com/cli/v0.6.10/rancher-linux-amd64-v0.6.10.tar.gz
DEFAULT_CATTLE_RANCHER_CLI_WINDOWS_URL=https://releases.rancher.com/cli/v0.6.10/rancher-windows-386-v0.6.10.zip
DEFAULT_CATTLE_RANCHER_COMPOSE_DARWIN_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-darwin-amd64-v0.12.5.tar.gz
DEFAULT_CATTLE_RANCHER_COMPOSE_LINUX_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-linux-amd64-v0.12.5.tar.gz
DEFAULT_CATTLE_RANCHER_COMPOSE_WINDOWS_URL=https://releases.rancher.com/compose/v0.12.5/rancher-compose-windows-386-v0.12.5.zip
DEFAULT_CATTLE_SECRETS_API_EXECUTE=true
DEFAULT_CATTLE_WEBHOOK_SERVICE_EXECUTE=true
01:29:36.040 [main] INFO  ConsoleStatus - Loading configuration
2018-06-22 01:29:44,952 INFO    [main] [ConsoleStatus] Starting DB migration
2018-06-22 01:29:48,712 INFO    [main] [ConsoleStatus] DB migration done
2018-06-22 01:29:49,491 INFO    [main] [ConsoleStatus] Cluster membership changed [127.0.0.1:9345]
2018-06-22 01:29:49,492 INFO    [main] [ConsoleStatus] Checking cluster state on start-up
2018-06-22 01:29:52,017 INFO    [main] [ConsoleStatus] Loading processes
2018-06-22 01:29:52,982 INFO    [main] [ConsoleStatus] Starting [1/93]: LockDelegatorImpl
2018-06-22 01:29:52,987 INFO    [main] [ConsoleStatus] Starting [2/93]: AnnotatedListenerRegistration
2018-06-22 01:29:53,007 INFO    [main] [ConsoleStatus] Starting [3/93]: EventService
2018-06-22 01:29:53,007 INFO    [main] [ConsoleStatus] Starting [4/93]: DefaultObjectMetaDataManager
2018-06-22 01:29:54,671 INFO    [main] [ConsoleStatus] Starting [5/93]: JsonDefaultsProvider
2018-06-22 01:29:54,796 INFO    [main] [ConsoleStatus] Starting [6/93]: ObjectDefaultsPostInstantiationHandler
2018-06-22 01:29:54,803 INFO    [main] [ConsoleStatus] Starting [7/93]: DefaultProcessManager
2018-06-22 01:29:54,806 INFO    [main] [ConsoleStatus] Starting [8/93]: SampleDataStartupV3
2018-06-22 01:29:54,826 INFO    [main] [ConsoleStatus] Starting [9/93]: TaskManagerImpl
2018-06-22 01:29:54,883 INFO    [main] [ConsoleStatus] Starting [10/93]: ServiceAccountCreateStartup
2018-06-22 01:29:54,923 INFO    [main] [ConsoleStatus] Starting [11/93]: WebsocketProxyLauncher
2018-06-22 01:29:54,924 INFO    [main] [ConsoleStatus] Starting [12/93]: SampleDataStartupV15
2018-06-22 01:29:54,926 INFO    [main] [ConsoleStatus] Starting [13/93]: SchemaFactory:v1-admin
2018-06-22 01:29:55,628 INFO    [main] [ConsoleStatus] Starting [14/93]: SchemaFactory:v1-agent
2018-06-22 01:29:55,810 INFO    [main] [ConsoleStatus] Starting [15/93]: SchemaFactory:v1-agentRegister
2018-06-22 01:29:55,814 INFO    [main] [ConsoleStatus] Starting [16/93]: SchemaFactory:v1-base
2018-06-22 01:29:56,557 INFO    [main] [ConsoleStatus] Starting [17/93]: SchemaFactory:v1-member
2018-06-22 01:29:56,851 INFO    [main] [ConsoleStatus] Starting [18/93]: SchemaFactory:v1-owner
time="2018-06-22T01:29:57Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:29:57Z" level=fatal msg="Error getting config." error="Invalid key content"
2018-06-22 01:29:57,214 INFO    [main] [ConsoleStatus] Starting [19/93]: SchemaFactory:v1-project
2018-06-22 01:29:57,508 INFO    [main] [ConsoleStatus] Starting [20/93]: SchemaFactory:v1-projectadmin
2018-06-22 01:29:57,811 INFO    [main] [ConsoleStatus] Starting [21/93]: SchemaFactory:v1-readAdmin
2018-06-22 01:29:58,193 INFO    [main] [ConsoleStatus] Starting [22/93]: SchemaFactory:v1-readonly
2018-06-22 01:29:58,467 INFO    [main] [ConsoleStatus] Starting [23/93]: SchemaFactory:v1-register
2018-06-22 01:29:58,477 INFO    [main] [ConsoleStatus] Starting [24/93]: SchemaFactory:v1-restricted
2018-06-22 01:29:58,762 INFO    [main] [ConsoleStatus] Starting [25/93]: SchemaFactory:v1-service
time="2018-06-22T01:29:59Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:29:59Z" level=fatal msg="Error getting config." error="Invalid key content"
2018-06-22 01:29:59,169 INFO    [main] [ConsoleStatus] Starting [26/93]: SchemaFactory:v1-token
2018-06-22 01:29:59,172 INFO    [main] [ConsoleStatus] Starting [27/93]: SchemaFactory:v1-user
2018-06-22 01:29:59,452 INFO    [main] [ConsoleStatus] Starting [28/93]: AgentBasedProcessHandler
2018-06-22 01:29:59,453 INFO    [main] [ConsoleStatus] Starting [29/93]: AgentHostStateUpdate
2018-06-22 01:29:59,453 INFO    [main] [ConsoleStatus] Starting [30/93]: AgentManager
2018-06-22 01:29:59,454 INFO    [main] [ConsoleStatus] Starting [31/93]: AuthServiceLauncher
2018-06-22 01:29:59,454 INFO    [main] [ConsoleStatus] Starting [32/93]: BackupCreate
2018-06-22 01:29:59,456 INFO    [main] [ConsoleStatus] Starting [33/93]: BackupRemove
2018-06-22 01:29:59,456 INFO    [main] [ConsoleStatus] Starting [34/93]: CatalogLauncher
2018-06-22 01:29:59,456 INFO    [main] [ConsoleStatus] Starting [35/93]: ComposeExecutorLauncher
2018-06-22 01:29:59,457 INFO    [main] [ConsoleStatus] Starting [36/93]: ConfigItemRegistryImpl
2018-06-22 01:29:59,671 INFO    [main] [ConsoleStatus] Starting [37/93]: ConfigItemServerImpl
2018-06-22 01:29:59,979 INFO    [main] [ConsoleStatus] Starting [38/93]: ConfigUpdatePublisher
2018-06-22 01:29:59,979 INFO    [main] [ConsoleStatus] Starting [39/93]: DataManager
2018-06-22 01:29:59,979 INFO    [main] [ConsoleStatus] Starting [40/93]: DefaultAuthorizationProvider
time="2018-06-22T01:30:01Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:30:01Z" level=fatal msg="Error getting config." error="Invalid key content"
time="2018-06-22T01:30:01Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:30:01Z" level=fatal msg="Unable to create event router" error="Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
time="2018-06-22T01:30:01Z" level=fatal msg="Failed to configure cattle client: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: connect: connection refused"
time="2018-06-22T01:30:01Z" level=warning msg="Couldn't load install uuid: Get http://localhost:8080/v2-beta: dial tcp 127.0.0.1:8080: getsockopt: connection refused"
time="2018-06-22T01:30:01Z" level=info msg="Starting Catalog Service (port 8088, refresh interval 300 seconds)"
2018-06-22 01:30:02,523 INFO    [main] [ConsoleStatus] Starting [41/93]: DefaultJooqResourceManager
2018-06-22 01:30:02,523 INFO    [main] [ConsoleStatus] Starting [42/93]: DefaultObjectSerializerFactoryImpl
2018-06-22 01:30:02,523 INFO    [main] [ConsoleStatus] Starting [43/93]: DockerComposeStackHandler
2018-06-22 01:30:02,524 INFO    [main] [ConsoleStatus] Starting [44/93]: DynamicExtensionManager
2018-06-22 01:30:02,524 INFO    [main] [ConsoleStatus] Starting [45/93]: ExtensionResourceManagerLocator
2018-06-22 01:30:02,526 INFO    [main] [ConsoleStatus] Starting [46/93]: HostApiRSAKeyProvider
2018-06-22 01:30:02,527 INFO    [main] [ConsoleStatus] Starting [47/93]: HostTemplateManager
2018-06-22 01:30:02,527 INFO    [main] [ConsoleStatus] Starting [48/93]: ImageStoragePoolMapActivate
2018-06-22 01:30:02,528 INFO    [main] [ConsoleStatus] Starting [49/93]: InstanceHostMapActivate
2018-06-22 01:30:02,529 INFO    [main] [ConsoleStatus] Starting [50/93]: InstanceHostMapDeactivate
2018-06-22 01:30:02,531 INFO    [main] [ConsoleStatus] Starting [51/93]: InstanceManager
2018-06-22 01:30:02,535 INFO    [main] [ConsoleStatus] Starting [52/93]: LoadBalancerServiceInstanceStopPreListener
2018-06-22 01:30:02,535 INFO    [main] [ConsoleStatus] Starting [53/93]: MachineDriverLoader
2018-06-22 01:30:02,539 INFO    [main] [ConsoleStatus] Starting [54/93]: MachineLauncher
2018-06-22 01:30:02,539 INFO    [main] [ConsoleStatus] Starting [55/93]: MetadataConfigItemFactory
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [56/93]: MountRemove
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [57/93]: PostInstancePurge
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [58/93]: PostStartLabelsProviders
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [59/93]: ProjectMemberResourceManager
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [60/93]: ProjectResourceManager
2018-06-22 01:30:02,544 INFO    [main] [ConsoleStatus] Starting [61/93]: PullTaskCreate
2018-06-22 01:30:02,545 INFO    [main] [ConsoleStatus] Starting [62/93]: RestoreFromBackup
2018-06-22 01:30:02,545 INFO    [main] [ConsoleStatus] Starting [63/93]: RevertToSnapshot
2018-06-22 01:30:02,545 INFO    [main] [ConsoleStatus] Starting [64/93]: SampleDataStartupV10
2018-06-22 01:30:02,549 INFO    [main] [ConsoleStatus] Starting [65/93]: SampleDataStartupV11
2018-06-22 01:30:02,550 INFO    [main] [ConsoleStatus] Starting [66/93]: SampleDataStartupV12
2018-06-22 01:30:02,558 INFO    [main] [ConsoleStatus] Starting [67/93]: SampleDataStartupV13
2018-06-22 01:30:02,559 INFO    [main] [ConsoleStatus] Starting [68/93]: SampleDataStartupV14
2018-06-22 01:30:02,560 INFO    [main] [ConsoleStatus] Starting [69/93]: SampleDataStartupV16
2018-06-22 01:30:02,563 INFO    [main] [ConsoleStatus] Starting [70/93]: SampleDataStartupV17
2018-06-22 01:30:02,563 INFO    [main] [ConsoleStatus] Starting [71/93]: SampleDataStartupV5
2018-06-22 01:30:02,564 INFO    [main] [ConsoleStatus] Starting [72/93]: SampleDataStartupV6
2018-06-22 01:30:02,565 INFO    [main] [ConsoleStatus] Starting [73/93]: SampleDataStartupV7
2018-06-22 01:30:02,565 INFO    [main] [ConsoleStatus] Starting [74/93]: SampleDataStartupV8
2018-06-22 01:30:02,569 INFO    [main] [ConsoleStatus] Starting [75/93]: SampleDataStartupV9
2018-06-22 01:30:02,569 INFO    [main] [ConsoleStatus] Starting [76/93]: SecretManager
2018-06-22 01:30:02,569 INFO    [main] [ConsoleStatus] Starting [77/93]: SecretsApiLauncher
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [78/93]: ServiceManager
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [79/93]: SettingManager
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [80/93]: SnapshotCreate
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [81/93]: SnapshotRemove
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [82/93]: StackAgentHandler
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [83/93]: StackAgentHandler
2018-06-22 01:30:02,570 INFO    [main] [ConsoleStatus] Starting [84/93]: StackAgentHandler
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [85/93]: StackAgentHandler
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [86/93]: StackAgentHandler
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [87/93]: TelemetryLauncher
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [88/93]: VolumeManager
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [89/93]: VolumeRemove
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [90/93]: VolumeStoragePoolMapActivate
2018-06-22 01:30:02,571 INFO    [main] [ConsoleStatus] Starting [91/93]: VolumeStoragePoolMapRemove
2018-06-22 01:30:02,572 INFO    [main] [ConsoleStatus] Starting [92/93]: WebhookServiceLauncher
2018-06-22 01:30:02,572 INFO    [main] [ConsoleStatus] Starting [93/93]: project.template.reload
2018-06-22 01:30:02,680 INFO    [main] [ConsoleStatus] [DONE ] [34468ms] Startup Succeeded, Listening on port 8081
time="2018-06-22T01:30:03Z" level=info msg="Downloading key from http://localhost:8081/v1/scripts/api.crt"
time="2018-06-22T01:30:03Z" level=info msg="Starting websocket proxy. Listening on [:8080], Proxying to cattle API at [localhost:8081], Monitoring parent pid [8]."
time="2018-06-22T01:30:03Z" level=info msg="Configured http API filter"
time="2018-06-22T01:30:03Z" level=info msg="Configured authTokenValidator API filter"
time="2018-06-22T01:30:03Z" level=info msg="Master config file: master.conf"
time="2018-06-22T01:30:03Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T01:30:03Z" level=info msg="Downloading certificate from http://localhost:8081/v1/credentials/1c1/certificate"
time="2018-06-22T01:30:04Z" level=info msg="Starting go-machine-service..." gitcommit=v0.39.2 service=gms
time="2018-06-22T01:30:04Z" level=info msg="Waiting for handler registration (1/2)" service=gms
time="2018-06-22T01:30:04Z" level=info msg="Webhook service listening on 8085"
time="2018-06-22T01:30:05Z" level=info msg="Starting Rancher Auth service"
time="2018-06-22T01:30:06Z" level=info msg="Initializing event router" workerCount=5
time="2018-06-22T01:30:06Z" level=info msg="Connection established"
time="2018-06-22T01:30:06Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:30:06Z" level=info msg="Waiting for handler registration (2/2)" service=gms
time="2018-06-22T01:30:07Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:30:07Z" level=info msg="Connection established"
time="2018-06-22T01:30:07Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:30:07Z" level=info msg="No Auth provider configured"
time="2018-06-22T01:30:07Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:30:07Z" level=info msg="Connection established"
time="2018-06-22T01:30:07Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:30:07Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T01:30:07Z" level=info msg="Connection established"
time="2018-06-22T01:30:07Z" level=info msg="Starting websocket pings"
time="2018-06-22T01:30:07Z" level=info msg="Installing builtin drivers" service=gms
time="2018-06-22T01:30:07Z" level=info msg="Listening on :8090"
time="2018-06-22T01:30:10Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:13Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:16Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:19Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:22Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:25Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:28Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:31Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:34Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T01:30:37Z" level=info msg="machinedriver.activate event detected" service=gms
time="2018-06-22T01:30:37Z" level=info msg="Downloading all drivers" service=gms
time="2018-06-22T01:30:38Z" level=info msg="Copying /var/lib/cattle/machine-drivers/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx-docker-machine-driver-packet => /usr/local/bin/docker-machine-driver-packet-tmp" service=gms
time="2018-06-22T01:30:38Z" level=info msg="Done downloading all drivers" service=gms
time="2018-06-22T13:30:14Z" level=info msg="Exiting go-machine-service" service=gms
time="2018-06-22T13:30:14Z" level=info msg="Starting go-machine-service..." gitcommit=v0.39.2 service=gms
time="2018-06-22T13:30:14Z" level=info msg="Waiting for handler registration (1/2)" service=gms
time="2018-06-22T13:30:16Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T13:30:16Z" level=info msg="Initializing event router" workerCount=5
time="2018-06-22T13:30:16Z" level=info msg="Connection established"
time="2018-06-22T13:30:16Z" level=info msg="Starting websocket pings"
time="2018-06-22T13:30:16Z" level=info msg="Waiting for handler registration (2/2)" service=gms
time="2018-06-22T13:30:16Z" level=info msg="Connection established"
time="2018-06-22T13:30:16Z" level=info msg="Starting websocket pings"
time="2018-06-22T13:30:16Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T13:30:16Z" level=info msg="Connection established"
time="2018-06-22T13:30:16Z" level=info msg="Starting websocket pings"
time="2018-06-22T13:30:16Z" level=info msg="Installing builtin drivers" service=gms
time="2018-06-22T13:30:18Z" level=info msg="Exiting rancher-compose-executor" version=v0.14.28
time="2018-06-22T13:30:19Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-22T13:30:19Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:20Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-22T13:30:20Z" level=info msg="Connection established"
time="2018-06-22T13:30:20Z" level=info msg="Starting websocket pings"
time="2018-06-22T13:30:22Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:25Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:28Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:31Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:34Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:37Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:40Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:43Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-22T13:30:46Z" level=info msg="machinedriver.activate event detected" service=gms
time="2018-06-22T13:30:46Z" level=info msg="Downloading all drivers" service=gms
time="2018-06-22T13:30:46Z" level=info msg="Copying /var/lib/cattle/machine-drivers/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx-docker-machine-driver-packet => /usr/local/bin/docker-machine-driver-packet-tmp" service=gms
time="2018-06-22T13:30:47Z" level=info msg="Done downloading all drivers" service=gms
time="2018-06-23T01:30:23Z" level=info msg="Exiting go-machine-service" service=gms
time="2018-06-23T01:30:25Z" level=info msg="Starting go-machine-service..." gitcommit=v0.39.2 service=gms
time="2018-06-23T01:30:25Z" level=info msg="Waiting for handler registration (1/2)" service=gms
time="2018-06-23T01:30:26Z" level=info msg="Initializing event router" workerCount=5
time="2018-06-23T01:30:26Z" level=info msg="Connection established"
time="2018-06-23T01:30:26Z" level=info msg="Starting websocket pings"
time="2018-06-23T01:30:26Z" level=info msg="Waiting for handler registration (2/2)" service=gms
time="2018-06-23T01:30:26Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T01:30:26Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T01:30:26Z" level=info msg="Connection established"
time="2018-06-23T01:30:26Z" level=info msg="Starting websocket pings"
time="2018-06-23T01:30:26Z" level=info msg="Connection established"
time="2018-06-23T01:30:26Z" level=info msg="Starting websocket pings"
time="2018-06-23T01:30:26Z" level=info msg="Installing builtin drivers" service=gms
time="2018-06-23T01:30:29Z" level=info msg="Exiting rancher-compose-executor" version=v0.14.28
time="2018-06-23T01:30:30Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:30Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-23T01:30:30Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T01:30:31Z" level=info msg="Connection established"
time="2018-06-23T01:30:31Z" level=info msg="Starting websocket pings"
time="2018-06-23T01:30:33Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:36Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:39Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:42Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:45Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:48Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:51Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:54Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T01:30:57Z" level=info msg="machinedriver.activate event detected" service=gms
time="2018-06-23T01:30:57Z" level=info msg="Downloading all drivers" service=gms
time="2018-06-23T01:30:57Z" level=info msg="Copying /var/lib/cattle/machine-drivers/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx-docker-machine-driver-packet => /usr/local/bin/docker-machine-driver-packet-tmp" service=gms
time="2018-06-23T01:30:57Z" level=info msg="Done downloading all drivers" service=gms
time="2018-06-23T13:30:34Z" level=info msg="Exiting go-machine-service" service=gms
time="2018-06-23T13:30:35Z" level=info msg="Starting go-machine-service..." gitcommit=v0.39.2 service=gms
time="2018-06-23T13:30:35Z" level=info msg="Waiting for handler registration (1/2)" service=gms
time="2018-06-23T13:30:36Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T13:30:36Z" level=info msg="Connection established"
time="2018-06-23T13:30:36Z" level=info msg="Starting websocket pings"
time="2018-06-23T13:30:36Z" level=info msg="Waiting for handler registration (2/2)" service=gms
time="2018-06-23T13:30:36Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T13:30:36Z" level=info msg="Connection established"
time="2018-06-23T13:30:36Z" level=info msg="Starting websocket pings"
time="2018-06-23T13:30:37Z" level=info msg="Installing builtin drivers" service=gms
time="2018-06-23T13:30:37Z" level=info msg="Initializing event router" workerCount=5
time="2018-06-23T13:30:37Z" level=info msg="Connection established"
time="2018-06-23T13:30:37Z" level=info msg="Starting websocket pings"
time="2018-06-23T13:30:39Z" level=info msg="Exiting rancher-compose-executor" version=v0.14.28
time="2018-06-23T13:30:40Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:40Z" level=info msg="Starting rancher-compose-executor" version=v0.14.28
time="2018-06-23T13:30:41Z" level=info msg="Initializing event router" workerCount=250
time="2018-06-23T13:30:41Z" level=info msg="Connection established"
time="2018-06-23T13:30:41Z" level=info msg="Starting websocket pings"
time="2018-06-23T13:30:43Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:46Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:49Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:52Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:55Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:30:58Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:31:01Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:31:04Z" level=info msg="Waiting for machinedriver.activate event" service=gms
time="2018-06-23T13:31:07Z" level=info msg="machinedriver.activate event detected" service=gms
time="2018-06-23T13:31:07Z" level=info msg="Downloading all drivers" service=gms
time="2018-06-23T13:31:07Z" level=info msg="Copying /var/lib/cattle/machine-drivers/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx-docker-machine-driver-packet => /usr/local/bin/docker-machine-driver-packet-tmp" service=gms
time="2018-06-23T13:31:07Z" level=info msg="Done downloading all drivers" service=gms