Hi all,
I spent sometime: firstly in a multi nodes installation to finally try the single node. Inf fact I face a very disturbing Rancher behavior. I was not able to start a container via Rancher. The Network Agent does not start too !
In Cattle logs I found this main issue : SQLSyntaxErrorException: ‘cattle.host_0.name’ isn’t in GROUP BY.
I leave here some logs, and hope that could help to understand this problem.
Network Agent logs
16/2/2016 06:56:35[config.sh:15] return 0
16/2/2016 06:56:35INFO: Getting hosts
16/2/2016 06:56:35[apply.sh:19] for i in '$(cat ${CATTLE_HOME}/services | grep -vE '\''^(services|agent-instance-startup|configscripts)$'\'')'
16/2/2016 06:56:35[apply.sh:20] info Getting hosts
16/2/2016 06:56:35[scripts.sh:19] echo INFO: Getting hosts
16/2/2016 06:56:35[apply.sh:21] get_config --force hosts
16/2/2016 06:56:35[scripts.sh:63] /var/lib/cattle/config.sh --force hosts
16/2/2016 06:56:35[[scripts.sh:184] script_env
16/2/2016 06:56:35[[scripts.sh:109] '[' -n http://xxx.xxx.xxx.xxx:8080/v1 ']'
16/2/2016 06:56:35[[scripts.sh:110] return
16/2/2016 06:56:35[[scripts.sh:186] export CATTLE_HOME=/var/lib/cattle
16/2/2016 06:56:35[[scripts.sh:186] CATTLE_HOME=/var/lib/cattle
16/2/2016 06:56:35[[scripts.sh:187] export CATTLE_CONFIG_URL=http://xxx.xxx.xxx.xxx:8080/v1
16/2/2016 06:56:35[[scripts.sh:187] CATTLE_CONFIG_URL=http://xxx.xxx.xxx.xxx:8080/v1
16/2/2016 06:56:35[[scripts.sh:188] export CATTLE_STORAGE_URL=http://xxx.xxx.xxx.xxx:8080/v1
16/2/2016 06:56:35[[scripts.sh:188] CATTLE_STORAGE_URL=http://xxx.xxx.xxx.xxx:8080/v1
16/2/2016 06:56:35[config.sh:18] trap cleanup EXIT
16/2/2016 06:56:35[config.sh:20] LOCK_DIR=/var/lib/cattle/locks
16/2/2016 06:56:35[config.sh:21] LOCK=/var/lib/cattle/locks/config.lock
16/2/2016 06:56:35[config.sh:22] DOWNLOAD=/var/lib/cattle/download
16/2/2016 06:56:35[config.sh:23] UPTODATE=false
16/2/2016 06:56:35[config.sh:25] URL=http://xxx.xxx.xxx.xxx:8080/v1
16/2/2016 06:56:35[config.sh:26] AUTH=A36F074A53D0A63749C3:N24hnHvNbi4N8KVjAq8J5qeoikvtMW4fZRCPdjSP
16/2/2016 06:56:35[config.sh:27] URL_SUFFIX=/configcontent/
16/2/2016 06:56:35[config.sh:29] '[' '!' -x /var/lib/cattle/config.sh ']'
16/2/2016 06:56:35[config.sh:33] '[' '!' -d /var/lib/cattle/locks ']'
16/2/2016 06:56:35[config.sh:37] '[' true '!=' true ']'
16/2/2016 06:56:35[config.sh:52] '[' /var/lib/cattle/locks/config.lock '!=' /var/lib/cattle/locks/config.lock ']'
16/2/2016 06:56:35[config.sh:239] mkdir -p /var/lib/cattle
16/2/2016 06:56:35[config.sh:240] mkdir -p /var/lib/cattle/download
16/2/2016 06:56:35INFO: Updating hosts
16/2/2016 06:56:35[config.sh:242] opts=()
16/2/2016 06:56:35[config.sh:243] '[' 2 -gt 0 ']'
16/2/2016 06:56:35[config.sh:244] case $1 in
16/2/2016 06:56:35[config.sh:246] FORCE=true
16/2/2016 06:56:35[config.sh:274] shift 1
16/2/2016 06:56:35[config.sh:243] '[' 1 -gt 0 ']'
16/2/2016 06:56:35[config.sh:244] case $1 in
16/2/2016 06:56:35[config.sh:263] info Updating hosts
16/2/2016 06:56:35[scripts.sh:19] echo INFO: Updating hosts
16/2/2016 06:56:35[config.sh:264] UPTODATE=false
16/2/2016 06:56:35[config.sh:265] download hosts
16/2/2016 06:56:35[config.sh:82] cleanup
16/2/2016 06:56:35[config.sh:9] EXIT=0
16/2/2016 06:56:35[config.sh:11] '[' -e '' ']'
16/2/2016 06:56:35[config.sh:15] return 0
16/2/2016 06:56:35[[config.sh:84] mktemp -d /var/lib/cattle/download.XXXXXXX
16/2/2016 06:56:35INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts current=
16/2/2016 06:56:35[config.sh:84] DOWNLOAD_TEMP=/var/lib/cattle/download.28CZQzm
16/2/2016 06:56:35[config.sh:86] '[' -z http://xxx.xxx.xxx.xxx:8080/v1 ']'
16/2/2016 06:56:35[config.sh:86] '[' -z A36F074A53D0A63749C3:N24hnHvNbi4N8KVjAq8J5qeoikvtMW4fZRCPdjSP ']'
16/2/2016 06:56:35[config.sh:92] local name=hosts
16/2/2016 06:56:35[config.sh:93] local current
16/2/2016 06:56:35[config.sh:94] local archive_version
16/2/2016 06:56:35[config.sh:96] purge_old /var/lib/cattle/download/hosts
16/2/2016 06:56:35[config.sh:63] local exclude=current
16/2/2016 06:56:35[config.sh:64] local dir=/var/lib/cattle/download/hosts
16/2/2016 06:56:35[config.sh:66] '[' '!' -d /var/lib/cattle/download/hosts ']'
16/2/2016 06:56:35[config.sh:67] return 0
16/2/2016 06:56:35[config.sh:98] '[' true '!=' true ']'
16/2/2016 06:56:35[config.sh:102] DOWNLOAD_URL=http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts
16/2/2016 06:56:35[config.sh:104] local get_opts
16/2/2016 06:56:35[config.sh:105] local archive_version
16/2/2016 06:56:35[config.sh:106] '[' -n '' ']'
16/2/2016 06:56:35[config.sh:118] info Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts current=
16/2/2016 06:56:35[scripts.sh:19] echo INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts current=
16/2/2016 06:56:35[config.sh:120] get 'http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts?current='
16/2/2016 06:56:35[scripts.sh:43] '[' 'http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts?current=' = --no-auth ']'
16/2/2016 06:56:35[scripts.sh:47] call_curl -L 'http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts?current='
16/2/2016 06:56:35[scripts.sh:29] local 'curl=curl -s --connect-timeout 20'
16/2/2016 06:56:35[scripts.sh:30] '[' '' = false ']'
16/2/2016 06:56:35[scripts.sh:32] '[' -n 'Basic QTM2RjA3NEE1M0QwQTYzNzQ5QzM6TjI0aG5Idk5iaTROOEtWakFxOEo1cWVvaWt2dE1XNGZaUkNQZGpTUA==' ']'
16/2/2016 06:56:35[scripts.sh:33] curl -s --connect-timeout 20 -H 'Authorization: Basic QTM2RjA3NEE1M0QwQTYzNzQ5QzM6TjI0aG5Idk5iaTROOEtWakFxOEo1cWVvaWt2dE1XNGZaUkNQZGpTUA==' -L 'http://xxx.xxx.xxx.xxx:8080/v1//configcontent//hosts?current='
16/2/2016 06:56:35[[config.sh:121] cat /var/lib/cattle/download.28CZQzm/download
16/2/2016 06:56:35[[config.sh:121] head -n1
16/2/2016 06:56:35[config.sh:121] HEADER='���
�Om7��7��'\''('
16/2/2016 06:56:35[config.sh:122] [[ ���
�Om7��7��'( =~ version:* ]]
16/2/2016 06:56:35[config.sh:126] tar xzf /var/lib/cattle/download.28CZQzm/download -C /var/lib/cattle/download.28CZQzm
16/2/2016 06:56:35[config.sh:135] rm /var/lib/cattle/download.28CZQzm/download
16/2/2016 06:56:35[[[config.sh:137] ls -1 /var/lib/cattle/download.28CZQzm
16/2/2016 06:56:35[[config.sh:137] basename
16/2/2016 06:56:35basename: missing operand
16/2/2016 06:56:35Try 'basename --help' for more information.
16/2/2016 06:56:35[config.sh:137] local dir=
16/2/2016 06:56:35[config.sh:138] '[' '!' -e /var/lib/cattle/download.28CZQzm/ ']'
16/2/2016 06:56:35[config.sh:145] cd /var/lib/cattle/download.28CZQzm
16/2/2016 06:56:35[config.sh:147] '[' '!' -e /SHA1SUMSSUM ']'
16/2/2016 06:56:35[config.sh:148] error 'Missing SHA1SUMS files, invalid download'
16/2/2016 06:56:35[scripts.sh:24] echo ERROR: 'Missing SHA1SUMS files, invalid download'
16/2/2016 06:56:35ERROR: Missing SHA1SUMS files, invalid download
16/2/2016 06:56:35[config.sh:149] exit 1
16/2/2016 06:56:35[config.sh:1] cleanup
16/2/2016 06:56:35[config.sh:9] EXIT=1
16/2/2016 06:56:35[config.sh:11] '[' -e /var/lib/cattle/download.28CZQzm ']'
16/2/2016 06:56:35[config.sh:12] rm -rf /var/lib/cattle/download.28CZQzm
16/2/2016 06:56:35[config.sh:15] return 1
16/2/2016 06:56:35
The system is going down NOW!
16/2/2016 06:56:35
Sent SIGTERM to all processes
16/2/2016 06:56:36
Sent SIGKILL to all processes
16/2/2016 06:56:36
Requesting system reboot
Agent logs
INFO: Starting agent for 106EC9B4B04EDD35E677
INFO: Access Key: 106EC9B4B04EDD35E677
INFO: Config URL: http://xxx.xxx.xxx.xxx:8080/v1
INFO: Storage URL: http://xxx.xxx.xxx.xxx:8080/v1
INFO: API URL: http://xxx.xxx.xxx.xxx:8080/v1
INFO: IP: yyy.yyy.yyy.yyy
INFO: Port:
INFO: Required Image: rancher/agent:v0.9.2
INFO: Current Image: rancher/agent:v0.9.2
INFO: Using image rancher/agent:v0.9.2
INFO: Downloading agent http://xxx.xxx.xxx.xxx:8080/v1/configcontent/configscripts
INFO: Updating configscripts
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//configscripts current=
INFO: Running /var/lib/cattle/download/configscripts/configscripts-1-f0f3fb2e1110b5ada7c441705981f93a480313a324294321cff467f0c3e12319/apply.sh
INFO: Sending configscripts applied 1-f0f3fb2e1110b5ada7c441705981f93a480313a324294321cff467f0c3e12319
INFO: Updating pyagent
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//pyagent current=
INFO: Running /var/lib/cattle/download/pyagent/pyagent-1-9e3dcab12585149a65d818082279708965cd826df1937a55b24f48428f8f0c06069547103e24f5f4562a2db5d4805d60/apply.sh
INFO: Updating host-api
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//host-api current=
INFO: Running /var/lib/cattle/download/host-api/1-1dcc85d77415faddc4d6d204d2bd622d835de4b5ee4b472651419b58189c474a/apply.sh
INFO: Sending host-api applied 1-1dcc85d77415faddc4d6d204d2bd622d835de4b5ee4b472651419b58189c474a
INFO: Updating agent-binaries
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//agent-binaries current=
INFO: Running /var/lib/cattle/download/agent-binaries/1-4200f9b686342da8e941359211b1d8c5f98877ae293d0ead231d43507f1c9eae/apply.sh
INFO: Sending agent-binaries applied 1-4200f9b686342da8e941359211b1d8c5f98877ae293d0ead231d43507f1c9eae
INFO: Updating python-agent
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//python-agent current=
INFO: Running /var/lib/cattle/download/python-agent/1-946e369f594bb9d9e197c1a5af16a46a046f96066b7f3e52b1c9ba1ac3384338/apply.sh
INFO: Sending python-agent applied 1-946e369f594bb9d9e197c1a5af16a46a046f96066b7f3e52b1c9ba1ac3384338
INFO: Updating cadvisor
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//cadvisor current=
INFO: Running /var/lib/cattle/download/cadvisor/1-4d2b4356ab14bc1fa7ec7cd83f35b7e975a16cea01634683b577c9498c98de25/apply.sh
INFO: HOME -> ./
INFO: HOME -> ./bin/
INFO: HOME -> ./bin/cadvisor
INFO: HOME -> ./bin/cadvisor.sh
INFO: Sending cadvisor applied 1-4d2b4356ab14bc1fa7ec7cd83f35b7e975a16cea01634683b577c9498c98de25
INFO: Updating volmgr
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//volmgr current=
INFO: Running /var/lib/cattle/download/volmgr/1-c813690c24ae9a12f0792378c78a48f447b243517233d7969b99baefbea5af15/apply.sh
INFO: Sending volmgr applied 1-c813690c24ae9a12f0792378c78a48f447b243517233d7969b99baefbea5af15
INFO: Sending pyagent applied 1-9e3dcab12585149a65d818082279708965cd826df1937a55b24f48428f8f0c06069547103e24f5f4562a2db5d4805d60
INFO: Starting agent /var/lib/cattle/pyagent/apply.sh
INFO: Executing /var/lib/cattle/pyagent/main.py
INFO: Updating host-config
INFO: Downloading http://xxx.xxx.xxx.xxx:8080/v1//configcontent//host-config current=
INFO: Running /var/lib/cattle/download/host-config/host-config-1-956253b73a6d7a412d5ae096b9ecbadad8d97bf26f0b43d3afaf825faf1dbbf4/apply.sh
INFO: HOME -> ./
INFO: HOME -> ./etc/
INFO: HOME -> ./etc/cattle/
INFO: HOME -> ./etc/cattle/api.crt
INFO: Sending host-config applied 1-956253b73a6d7a412d5ae096b9ecbadad8d97bf26f0b43d3afaf825faf1dbbf4
time="2016-02-16T05:24:50Z" level="info" msg="Starting event router."
time="2016-02-16T05:24:50Z" level="info" msg="Watching state directory: /var/lib/rancher/state/containers"
I0216 05:24:50.323142 28901 storagedriver.go:132] No backend storage selected
I0216 05:24:50.323192 28901 storagedriver.go:134] Caching stats in memory for 2m0s
I0216 05:24:50.323253 28901 manager.go:128] cAdvisor running in container: "/system.slice/docker-6073f563d885405c73d9f8eba3708f2793231de41f192938c55296c2f531417a.scope"
I0216 05:24:50.448688 28901 fs.go:108] Filesystem partitions: map[/dev/vda1:{mountpoint:/ major:253 minor:1 fsType: blockSize:0} docker-253:1-262178-pool:{mountpoint: major:7 minor:0 fsType:devicemapper blockSize:128}]
I0216 05:24:50.483445 28901 manager.go:163] Machine: {NumCores:2 CpuFrequency:2394442 MemoryCapacity:8173395968 MachineID:2d406ad2c45e4e1b86f11fa56e394d32 SystemUUID:8F4B78CC-12FD-43F8-8391-CFCC262D7DE1 BootID:9578c2c1-02cb-4b40-b455-8bee468b1b91 Filesystems:[{Device:/dev/vda1 Capacity:42206281728} {Device:docker-253:1-262178-pool Capacity:107374182400}] DiskMap:map[252:2:{Name:dm-2 Major:252 Minor:2 Size:107374182400 Scheduler:none} 252:3:{Name:dm-3 Major:252 Minor:3 Size:107374182400 Scheduler:none} 252:4:{Name:dm-4 Major:252 Minor:4 Size:107374182400 Scheduler:none} 252:5:{Name:dm-5 Major:252 Minor:5 Size:107374182400 Scheduler:none} 252:6:{Name:dm-6 Major:252 Minor:6 Size:107374182400 Scheduler:none} 253:0:{Name:vda Major:253 Minor:0 Size:42949672960 Scheduler:none} 252:0:{Name:dm-0 Major:252 Minor:0 Size:107374182400 Scheduler:none} 252:1:{Name:dm-1 Major:252 Minor:1 Size:107374182400 Scheduler:none}] NetworkDevices:[{Name:eth0 MacAddress:fa:16:3e:fe:40:a5 Speed:0 Mtu:1500}] Topology:[{Id:0 Memory:8388198400 Cores:[{Id:0 Threads:[0] Caches:[{Size:32768 Type:Data Level:1} {Size:32768 Type:Instruction Level:1} {Size:4194304 Type:Unified Level:2}]}] Caches:[]} {Id:1 Memory:0 Cores:[{Id:0 Threads:[1] Caches:[{Size:32768 Type:Data Level:1} {Size:32768 Type:Instruction Level:1} {Size:4194304 Type:Unified Level:2}]}] Caches:[]}] CloudProvider:Unknown InstanceType:Unknown}
I0216 05:24:50.484942 28901 manager.go:169] Version: {KernelVersion:3.10.0-229.1.2.el7.x86_64 ContainerOsVersion:CentOS Linux 7 (Core) DockerVersion:1.9.1 CadvisorVersion: CadvisorRevision:}
I0216 05:24:50.486209 28901 factory.go:194] System is using systemd
I0216 05:24:50.607560 28901 factory.go:236] Registering Docker factory
I0216 05:24:50.608598 28901 factory.go:93] Registering Raw factory
I0216 05:24:50.755927 28901 manager.go:1006] Started watching for new ooms in manager
I0216 05:24:50.755988 28901 oomparser.go:199] OOM parser using kernel log file: "/var/log/messages"
I0216 05:24:50.758140 28901 manager.go:250] Starting recovery of all containers
I0216 05:24:50.815272 28901 manager.go:255] Recovery completed
I0216 05:24:50.852373 28901 cadvisor.go:96] Starting cAdvisor version: - on port 9344
2016-02-16 05:25:00,538 ERROR agent [140698234459952] [event.py:112] Error in request : a5281443-dfd0-4a7d-9649-ce207dd93591
Traceback (most recent call last):
File "/var/lib/cattle/pyagent/cattle/agent/event.py", line 95, in _worker_main
resp = agent.execute(req)
File "/var/lib/cattle/pyagent/cattle/agent/__init__.py", line 15, in execute
return self._router.route(req)
File "/var/lib/cattle/pyagent/cattle/plugins/core/event_router.py", line 13, in route
resp = handler.execute(req)
File "/var/lib/cattle/pyagent/cattle/plugins/core/event_handlers.py", line 32, in execute
type.on_ping(event, resp)
File "/var/lib/cattle/pyagent/cattle/plugins/docker/compute.py", line 126, in on_ping
self._add_instances(ping, pong)
File "/var/lib/cattle/pyagent/cattle/plugins/docker/compute.py", line 138, in _add_instances
running, nonrunning = self._get_all_containers_by_state()
File "/var/lib/cattle/pyagent/cattle/plugins/docker/compute.py", line 171, in _get_all_containers_by_state
for c in client.containers(all=True):
File "/var/lib/cattle/pyagent/dist/docker/api/container.py", line 67, in containers
res = self._result(self._get(u, params=params), True)
File "/var/lib/cattle/pyagent/dist/docker/client.py", line 110, in _get
return self.get(url, **self._set_request_timeout(kwargs))
File "/var/lib/cattle/pyagent/dist/requests/sessions.py", line 480, in get
return self.request('GET', url, **kwargs)
File "/var/lib/cattle/pyagent/dist/requests/sessions.py", line 468, in request
resp = self.send(prep, **send_kwargs)
File "/var/lib/cattle/pyagent/dist/requests/sessions.py", line 576, in send
r = adapter.send(request, **kwargs)
File "/var/lib/cattle/pyagent/dist/requests/adapters.py", line 449, in send
raise ReadTimeout(e, request=request)
ReadTimeout: UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=2)
time="2016-02-16T05:25:06Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"6073f563d885405c73d9f8eba3708f2793231de41f192938c55296c2f531417a\", From:\"-simulated-\", Time:0}"
time="2016-02-16T05:25:06Z" level="info" msg="Connecting to proxy." url="ws://xxx.xxx.xxx.xxx:8080/v1/connectbackend?token=eyJhbGciOiJSUzI1NiJ9.eyJleHAiOjE0NTU2MDA2MDcsInN1YiI6ImNhdHRsZSIsImlzcyI6Imh0dHA6XC9cL2NhdHRsZS5pbyIsInJlcG9ydGVkVXVpZCI6IjRjMzBlMTQ4LWJiMDctNGU4ZC1hMjc2LWVhNjVhOWZlNTBhZCIsImlhdCI6MTQ1NTYwMDMwNywia2lkIjoiZGVmYXVsdCJ9.ZKp5DnvLqxHzMTG40mCi0whFEcSTMKNrUSsEdogk4sH5O2UEfEu61khBUsVCpFebQLcPTQmhYEpaZ1x6aLRva0TcaUEO1oehPXjFbCWFQBZtJj3K2h8hw1PCnJdNAxfnYuss1OnaKTIp1GhI3XFcNE4o_RIKrg7v91UNgR-J2VsMVBN9QWthnQ_sRuaOJ5_UJ4ih_t4bpjYe0Sr0VVXMU1_EVWjQ_XZnPzhNKPhvCLfJRIkU0_ZH1nArcLCI5WP4jqNPHjiUaDZh5sNQsU-URs9l7zSEMbndmTt0jXnTJTFB2u9Yul5x6rjpVnRaWDMWijWCxl_fPjO_KFkog_ldGw"
time="2016-02-16T05:27:12Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600432}"
time="2016-02-16T05:27:12Z" level="info" msg="Assigning IP [10.42.245.172/16], ContainerId [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76], Pid [29968]"
time="2016-02-16T05:27:12Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"-simulated-\", Time:0}"
time="2016-02-16T05:27:12Z" level="info" msg="Container locked. Can't run StartHandler. ID: [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76]"
time="2016-02-16T05:27:20Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"die\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600440}"
2016-02-16 05:27:20,848 ERROR docker [140698234459952] [delegate.py:104] Can not call [5b6dd2f0-d56d-4799-ad24-b329176e038b], container is not running
time="2016-02-16T05:27:31Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600451}"
time="2016-02-16T05:27:31Z" level="info" msg="Assigning IP [10.42.245.172/16], ContainerId [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76], Pid [31171]"
time="2016-02-16T05:27:31Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"-simulated-\", Time:0}"
time="2016-02-16T05:27:31Z" level="info" msg="Container locked. Can't run StartHandler. ID: [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76]"
time="2016-02-16T05:27:37Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"die\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600457}"
time="2016-02-16T05:27:45Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600465}"
time="2016-02-16T05:27:45Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"-simulated-\", Time:0}"
time="2016-02-16T05:27:45Z" level="info" msg="Container locked. Can't run StartHandler. ID: [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76]"
time="2016-02-16T05:27:45Z" level="info" msg="Assigning IP [10.42.245.172/16], ContainerId [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76], Pid [32273]"
nsenter: cannot open /proc/32273/ns/ipc: No such file or directory
time="2016-02-16T05:27:51Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"die\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600471}"
nsenter: cannot open /proc/32273/ns/ipc: No such file or directory
nsenter: cannot open /proc/32273/ns/ipc: No such file or directory
time="2016-02-16T05:28:00Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600480}"
time="2016-02-16T05:28:00Z" level="info" msg="Assigning IP [10.42.245.172/16], ContainerId [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76], Pid [910]"
time="2016-02-16T05:28:00Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"-simulated-\", Time:0}"
time="2016-02-16T05:28:00Z" level="info" msg="Container locked. Can't run StartHandler. ID: [f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76]"
time="2016-02-16T05:28:06Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"die\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\", Time:1455600486}"
2016-02-16 05:28:06,856 ERROR docker [140698233645328] [delegate.py:104] Can not call [5b6dd2f0-d56d-4799-ad24-b329176e038b], container is not running
2016-02-16 05:28:14,862 ERROR docker [140698233251472] [delegate.py:104] Can not call [5b6dd2f0-d56d-4799-ad24-b329176e038b], container is not running
time="2016-02-16T05:28:15Z" level="info" msg="Processing event: &docker.APIEvents{Status:\"start\", ID:\"f8645111cd67bf5bee05cddaba0934049f8831b3c3210f61e8437eabfdf8fe76\", From:\"rancher/agent-instance:v0.8.0\",
Cattle logs
2016-02-16 05:47:35,964 ERROR [:] [] [] [] [qtp423436977-13] [i.g.i.g.r.handler.ExceptionHandler ] Exception in API for request [io.github.ibuildthecloud.gdapi.request.ApiRequest@6e3c77d7] org.jooq.exception.DataAccessException: SQL [select `host_0`.`id` as `host_0_id`, `host_0`.`name` as `host_0_name`, `host_0`.`account_id` as `host_0_account_id`, `host_0`.`kind` as `host_0_kind`, `host_0`.`uuid` as `host_0_uuid`, `host_0`.`description` as `host_0_description`, `host_0`.`state` as `host_0_state`, `host_0`.`created` as `host_0_created`, `host_0`.`removed` as `host_0_removed`, `host_0`.`remove_time` as `host_0_remove_time`, `host_0`.`data` as `host_0_data`, `host_0`.`uri` as `host_0_uri`, `host_0`.`compute_free` as `host_0_compute_free`, `host_0`.`compute_total` as `host_0_compute_total`, `host_0`.`agent_id` as `host_0_agent_id`, `host_0`.`zone_id` as `host_0_zone_id`, `host_0`.`physical_host_id` as `host_0_physical_host_id`, `host_0`.`is_public` as `host_0_is_public`, `host_0`.`agent_state` as `host_0_agent_state`, `ip_address_1`.`id` as `ip_address_1_id`, `ip_address_1`.`name` as `ip_address_1_name`, `ip_address_1`.`account_id` as `ip_address_1_account_id`, `ip_address_1`.`kind` as `ip_address_1_kind`, `ip_address_1`.`uuid` as `ip_address_1_uuid`, `ip_address_1`.`description` as `ip_address_1_description`, `ip_address_1`.`state` as `ip_address_1_state`, `ip_address_1`.`created` as `ip_address_1_created`, `ip_address_1`.`removed` as `ip_address_1_removed`, `ip_address_1`.`remove_time` as `ip_address_1_remove_time`, `ip_address_1`.`data` as `ip_address_1_data`, `ip_address_1`.`address` as `ip_address_1_address`, `ip_address_1`.`subnet_id` as `ip_address_1_subnet_id`, `ip_address_1`.`network_id` as `ip_address_1_network_id`, `ip_address_1`.`is_public` as `ip_address_1_is_public`, `ip_address_1`.`role` as `ip_address_1_role`, `ip_address_1`.`hostname` as `ip_address_1_hostname`, `ip_address_1`.`ip_pool_id` as `ip_address_1_ip_pool_id` from `ip_address` as `ip_address_1` join `host_ip_address_map` on `host_ip_address_map`.`ip_address_id` = `ip_address_1`.`id` join `host` as `host_0` on `host_0`.`id` = `host_ip_address_map`.`host_id` left outer join `instance_host_map` on `host_0`.`id` = `instance_host_map`.`host_id` where (`host_0`.`removed` is null and `host_0`.`state` not in (?, ?) and 1 = 1 and `ip_address_1`.`removed` is null and `host_0`.`account_id` = ?) group by `host_0`.`id`]; 'cattle.host_0.name' isn't in GROUP BY
at org.jooq.impl.Utils.translate(Utils.java:1287) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.DefaultExecuteContext.sqlException(DefaultExecuteContext.java:495) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:326) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.AbstractResultQuery.fetch(AbstractResultQuery.java:330) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.SelectImpl.fetch(SelectImpl.java:2256) ~[jooq-3.3.0.jar:na]
at io.cattle.platform.configitem.context.dao.impl.MetaDataInfoDaoImpl.getInstanceHostMetaData(MetaDataInfoDaoImpl.java:135) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.context.impl.ServiceMetadataInfoFactory.getFullMetaData(ServiceMetadataInfoFactory.java:121) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.context.impl.ServiceMetadataInfoFactory.populateContext(ServiceMetadataInfoFactory.java:75) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.context.impl.AbstractAgentBaseContextFactory.populateContext(AbstractAgentBaseContextFactory.java:69) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.server.model.impl.AbstractArchiveBasedConfigItem.handleRequest(AbstractArchiveBasedConfigItem.java:56) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.server.impl.ConfigItemServerImpl.handleDownload(ConfigItemServerImpl.java:97) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.server.impl.ConfigItemServerImpl.handleRequest(ConfigItemServerImpl.java:40) ~[cattle-config-item-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.api.manager.ConfigContentManager.handle(ConfigContentManager.java:80) ~[cattle-config-item-api-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.configitem.api.manager.ConfigContentManager.getByIdInternal(ConfigContentManager.java:49) ~[cattle-config-item-api-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.resource.impl.AbstractBaseResourceManager.getById(AbstractBaseResourceManager.java:61) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.ResourceManagerRequestHandler.generate(ResourceManagerRequestHandler.java:49) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.AbstractResponseGenerator.handle(AbstractResponseGenerator.java:14) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.DefaultReadWriteApiDelegate.handle(DefaultReadWriteApiDelegate.java:27) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.DefaultReadWriteApiDelegate.read(DefaultReadWriteApiDelegate.java:17) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor423.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_95]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_95]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96) ~[spring-tx-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260) ~[spring-tx-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94) ~[spring-tx-3.2.4.RELEASE.jar:3.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) ~[spring-aop-3.2.5.RELEASE.jar:3.2.5.RELEASE]
at com.sun.proxy.$Proxy45.read(Unknown Source) ~[na:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.ReadWriteApiHandler.handle(ReadWriteApiHandler.java:21) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.servlet.ApiRequestFilterDelegate.doFilter(ApiRequestFilterDelegate.java:86) ~[cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.api.servlet.ApiRequestFilter$1.runInContext(ApiRequestFilter.java:90) [cattle-framework-api-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:108) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.api.servlet.ApiRequestFilter.doFilter(ApiRequestFilter.java:83) [cattle-framework-api-0.5.0-SNAPSHOT.jar:na]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83) [jetty-servlets-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:364) [jetty-servlets-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) [jetty-security-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.Server.handle(Server.java:499) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) [jetty-util-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) [jetty-util-9.2.11.v20150529.jar:9.2.11.v20150529]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_95]
Caused by: java.sql.SQLSyntaxErrorException: 'cattle.host_0.name' isn't in GROUP BY
at org.mariadb.jdbc.internal.util.ExceptionMapper.get(ExceptionMapper.java:125) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.internal.util.ExceptionMapper.throwException(ExceptionMapper.java:69) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.MariaDbStatement.executeQueryEpilog(MariaDbStatement.java:261) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.MariaDbStatement.execute(MariaDbStatement.java:290) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.MariaDbClientPreparedStatement.execute(MariaDbClientPreparedStatement.java:148) ~[mariadb-java-client-1.3.4.jar:na]
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172) ~[commons-dbcp-1.4.jar:1.4]
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172) ~[commons-dbcp-1.4.jar:1.4]
at org.jooq.tools.jdbc.DefaultPreparedStatement.execute(DefaultPreparedStatement.java:194) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.AbstractResultQuery.execute(AbstractResultQuery.java:261) ~[jooq-3.3.0.jar:na]
at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:322) ~[jooq-3.3.0.jar:na]
... 60 common frames omitted
Caused by: org.mariadb.jdbc.internal.util.dao.QueryException: 'cattle.host_0.name' isn't in GROUP BY
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:475) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.result(AbstractQueryProtocol.java:396) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:378) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:334) ~[mariadb-java-client-1.3.4.jar:na]
at org.mariadb.jdbc.MariaDbStatement.execute(MariaDbStatement.java:280) ~[mariadb-java-client-1.3.4.jar:na]
... 66 common frames omitted
Cheers.