You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cloudstack.apache.org by Aakash Kumar <ju...@gmail.com> on 2013/11/06 05:26:24 UTC
Exception Occurred adding host
Hello ,
Following exception occurred on running deployDatacenter.py using
devcloud.cfg
INFO [c.c.r.ResourceManagerImpl]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Trying to add a new host at http://192.168.56.10/ in data center 1
INFO [c.c.h.x.d.XcpServerDiscoverer]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Found host devcloud ip=192.168.56.10 product version=1.6.0
INFO [c.c.h.x.r.CitrixResourceBase]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Private Network is Pool-wide network associated with eth0 for host
192.168.56.10
INFO [c.c.h.x.r.CitrixResourceBase]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Guest Network is Pool-wide network associated with eth0 for host
192.168.56.10
INFO [c.c.h.x.r.CitrixResourceBase]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Public Network is Pool-wide network associated with eth0 for host
192.168.56.10
INFO [c.c.h.x.d.XcpServerDiscoverer]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Host: devcloud connected with hypervisor type: XenServer. Checking
CIDR...
INFO [c.c.a.m.DirectAgentAttache]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
StartupAnswer received 1 Interval = 60
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\ovsgre
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\ipassoc.sh
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getDomRVersion.sh
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getRouterStatus.sh
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\networkUsage.sh
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\l2tp_vpn.sh
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\vhd-util
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
callHostPlugin failed for cmd: setIptables with args due to There was
a failure communicating with the plugin.
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
Unable to setup
com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed
for cmd: setIptables with args due to There was a failure
communicating with the plugin.
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:4293)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.setIptables(CitrixResourceBase.java:4305)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:5098)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:547)
at com.cloud.hypervisor.xen.resource.XcpOssResource.executeRequest(XcpOssResource.java:140)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:187)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)
WARN [c.c.h.x.d.XcpServerDiscoverer]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Unable to setup agent 1 due to callHostPlugin failed for cmd:
setIptables with args due to There was a failure communicating with
the plugin.
INFO [c.c.u.e.CSExceptionErrorCode]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Could not find exception: com.cloud.exception.ConnectionException in
error code list for exceptions
WARN [c.c.a.m.AgentManagerImpl]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Monitor XcpServerDiscoverer says there is an error in the connect
process for 1 due to Reinitialize agent after setup.
INFO [c.c.a.m.AgentManagerImpl]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Host 1 is disconnecting with event AgentDisconnected
WARN [c.c.r.ResourceManagerImpl]
(1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
Unable to connect due to
com.cloud.exception.ConnectionException: Reinitialize agent after setup.
at com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer.processConnect(XcpServerDiscoverer.java:665)
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:491)
at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1398)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1802)
at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy146.discoverHosts(Unknown Source)
at org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
at com.cloud.api.ApiServer.queueCommand(ApiServer.java:527)
at com.cloud.api.ApiServer.handleRequest(ApiServer.java:370)
at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:322)
at com.cloud.api.ApiServlet.access$000(ApiServlet.java:52)
at com.cloud.api.ApiServlet$1.run(ApiServlet.java:114)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:111)
at com.cloud.api.ApiServlet.doGet(ApiServlet.java:73)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:401)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
ERROR [c.c.a.ApiServer] (1456585835@qtp-2122825114-0:ctx-2dc342a1
ctx-d1559de5 ctx-fae00876) unhandled exception executing api command:
addHost
com.cloud.utils.exception.CloudRuntimeException: Cannot transit agent
status with event AgentDisconnected for host 1, mangement server id is
8871632142068,Unable to transition to a new state from Creating via
AgentDisconnected
at com.cloud.agent.manager.AgentManagerImpl.agentStatusTransitTo(AgentManagerImpl.java:1330)
at com.cloud.resource.ResourceManagerImpl.markHostAsDisconnected(ResourceManagerImpl.java:1667)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1828)
at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
-Aakash
Re: Exception Occurred adding host
Posted by Jayapal Reddy Uradi <ja...@citrix.com>.
When you are adding the host, observe the SMlog logs.
>From MS there is call to vmops method.
In below logs I could not find call to vmops
Thanks,
Jayapal
On 06-Nov-2013, at 12:03 PM, Aakash Kumar <ju...@gmail.com>>
wrote:
Thanks Jayapal,
This are the contents of SMLog
[2776] 2012-11-27 18:57:13.308162 Warning: vdi_[de]activate present for dummy
[3072] 2012-11-27 18:57:16.147441 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|d4d7f0d6-288d-be05-1a15-f8d3ba8c758e|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:8a93cae9-9dab-de77-a2ae-29d2506fc5cc', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3072] 2012-11-27 18:57:16.147772 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.147906 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.148023 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.148093 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.153252 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3072] 2012-11-27 18:57:16.156107 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.156185 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.156244 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.156297 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.160453 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3094] 2012-11-27 18:57:16.331733 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|9c55c7d9-0bba-1dd0-f178-d2081b730c09|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:be5ffc66-72ec-03c2-eaf9-4380ba2ba7bf', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3748] 2012-11-27 19:07:39.801156 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.801669 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.801918 sr_create {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:db0dd841-c6e6-fa1d-1571-d6e83903348b', 'args': ['0'], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:b808c72d-6d19-8322-a8ce-30c85de05032', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_create', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3748] 2012-11-27 19:07:39.802135 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3748] 2012-11-27 19:07:39.813217 SUCCESS
[3748] 2012-11-27 19:07:39.813590 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.813808 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.970120 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.970245 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|d554e0ef-d365-bbbf-c5e8-45fcb4f63614|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:b6d75fa2-6f95-73d8-005f-b5cc4b0c2ffd', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3757] 2012-11-27 19:07:39.970709 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.971196 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.971306 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.977144 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3757] 2012-11-27 19:07:39.979777 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.979862 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.979923 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.979977 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.987449 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3757] 2012-11-27 19:07:39.987573 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.987774 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.144209 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.144336 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|c1acca96-c591-5349-c122-4862150a580c|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:6edf9b39-15a3-9f2a-9d51-f7fbbfbd7563', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3771] 2012-11-27 19:07:40.144553 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3771] 2012-11-27 19:07:40.153005 SUCCESS
[3771] 2012-11-27 19:07:40.153271 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3771] 2012-11-27 19:07:40.159972 SUCCESS
[3771] 2012-11-27 19:07:40.160453 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3771] 2012-11-27 19:07:40.160549 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3771] 2012-11-27 19:07:40.160598 Kicking GC
<3771> 2012-11-27 19:07:40.160671 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3775> 2012-11-27 19:07:40.164322 Will finish as PID [3776]
<3771> 2012-11-27 19:07:40.165006 New PID [3775]
[3771] 2012-11-27 19:07:40.165259 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3771] 2012-11-27 19:07:40.206452 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.206910 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3776> 2012-11-27 19:07:40.246753 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3776> 2012-11-27 19:07:40.246954 ***********************
<3776> 2012-11-27 19:07:40.247017 * E X C E P T I O N *
<3776> 2012-11-27 19:07:40.247075 ***********************
<3776> 2012-11-27 19:07:40.247167 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3776> 2012-11-27 19:07:40.247216 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3776> 2012-11-27 19:07:40.247263 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3776> 2012-11-27 19:07:40.247310 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2757] 2012-11-27 23:31:09.305319 Warning: vdi_[de]activate present for dummy
[3012] 2012-11-27 23:31:11.154570 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|9ddee2d8-7626-6011-043a-57cdd8ab5a4a|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:278d04fe-0b30-d26f-1196-de7e128e7679', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3012] 2012-11-27 23:31:11.154896 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.155017 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.155137 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.155205 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.160978 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3012] 2012-11-27 23:31:11.167789 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.167888 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.167888 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.167888 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.171944 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3026] 2012-11-27 23:31:11.425591 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.425758 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.425878 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|ddc03fa0-6365-ec15-ea64-e226501fe834|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:e621cbbb-5364-4194-663c-8388507a15c7', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3026] 2012-11-27 23:31:11.426052 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.426227 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.426298 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3030] 2012-11-27 23:31:11.430295 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|67dcd3f9-b485-451b-12f0-b00535e0fff2|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:79343d17-a459-4f14-d4bc-1ac797fd1d0f', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3026] 2012-11-27 23:31:11.440098 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3026] 2012-11-27 23:31:11.445854 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.446001 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.446075 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.446142 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.452270 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3026] 2012-11-27 23:31:11.452413 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.452571 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.664626 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.664771 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|7e247ff0-ddb6-6a6f-c7fb-a37739bcf00d|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:c63ce5c9-0141-b40f-adaf-bd4de17d83c2', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3057] 2012-11-27 23:31:11.664946 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3057] 2012-11-27 23:31:11.672209 SUCCESS
[3057] 2012-11-27 23:31:11.672483 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3057] 2012-11-27 23:31:11.678889 SUCCESS
[3057] 2012-11-27 23:31:11.679386 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3057] 2012-11-27 23:31:11.679490 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2012-11-27 23:31:11.679540 Kicking GC
<3057> 2012-11-27 23:31:11.679616 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3063> 2012-11-27 23:31:11.683450 Will finish as PID [3064]
<3057> 2012-11-27 23:31:11.684281 New PID [3063]
[3057] 2012-11-27 23:31:11.684548 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2012-11-27 23:31:11.738379 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.738829 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3064> 2012-11-27 23:31:11.772234 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3064> 2012-11-27 23:31:11.772347 ***********************
<3064> 2012-11-27 23:31:11.772434 * E X C E P T I O N *
<3064> 2012-11-27 23:31:11.772493 ***********************
<3064> 2012-11-27 23:31:11.772566 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3064> 2012-11-27 23:31:11.772614 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3064> 2012-11-27 23:31:11.772661 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3064> 2012-11-27 23:31:11.772709 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2763] 2012-11-29 05:17:56.038145 Warning: vdi_[de]activate present for dummy
[3019] 2012-11-29 05:17:57.872719 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|d2b6b9fd-c374-5b4e-d0fe-576a13ebebb4|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:9b05f2b9-14e2-f754-7524-ee0d602efd01', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3019] 2012-11-29 05:17:57.873109 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.873241 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.873375 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.873480 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.879289 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3019] 2012-11-29 05:17:57.883487 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.883580 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.883641 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.883695 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.887567 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3036] 2012-11-29 05:17:58.137991 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|a6dc6010-8835-72f4-20e2-26f21a283ebd|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:deb93bb0-9a70-a643-bae3-1419eff3f103', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3037] 2012-11-29 05:17:58.143180 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.143332 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.143432 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|c85abc53-6b28-1146-fd63-8efd47689710|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:cac270c1-4683-711c-598e-12c20eb0f20a', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3037] 2012-11-29 05:17:58.143641 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.143771 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.143837 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.153300 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3037] 2012-11-29 05:17:58.156263 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.156341 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.156399 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.156451 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.160669 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3037] 2012-11-29 05:17:58.161068 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.161222 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.369936 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.370057 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|5ec72ead-1384-9539-97cf-3893eebc81f0|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:070dbec1-2cc2-cc78-b750-196b18fce239', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3066] 2012-11-29 05:17:58.370210 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3066] 2012-11-29 05:17:58.377227 SUCCESS
[3066] 2012-11-29 05:17:58.377481 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3066] 2012-11-29 05:17:58.383303 SUCCESS
[3066] 2012-11-29 05:17:58.383800 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3066] 2012-11-29 05:17:58.383898 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3066] 2012-11-29 05:17:58.383946 Kicking GC
<3066> 2012-11-29 05:17:58.384021 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3070> 2012-11-29 05:17:58.388106 Will finish as PID [3071]
<3066> 2012-11-29 05:17:58.388933 New PID [3070]
[3066] 2012-11-29 05:17:58.389232 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3066] 2012-11-29 05:17:58.429249 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.429689 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3071> 2012-11-29 05:17:58.468419 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3071> 2012-11-29 05:17:58.468551 ***********************
<3071> 2012-11-29 05:17:58.468599 * E X C E P T I O N *
<3071> 2012-11-29 05:17:58.468644 ***********************
<3071> 2012-11-29 05:17:58.468714 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3071> 2012-11-29 05:17:58.468761 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3071> 2012-11-29 05:17:58.468807 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3071> 2012-11-29 05:17:58.468854 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2780] 2012-11-30 14:35:08.613349 Warning: vdi_[de]activate present for dummy
[3035] 2012-11-30 14:35:10.654146 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|9f23f5b4-1ea7-c7e8-40c6-d00c60ccdd72|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:175bb0e2-fd98-0bfd-0038-9883d6fc142a', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3035] 2012-11-30 14:35:10.654457 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.654457 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.654457 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.654497 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.661071 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3035] 2012-11-30 14:35:10.664359 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.664450 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.664831 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.664916 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.668671 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3052] 2012-11-30 14:35:10.933454 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|cbda77a4-117c-b477-9e44-6f17121fed9b|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:a76c3727-0d65-31e0-c066-097b3f9958a9', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3053] 2012-11-30 14:35:10.948276 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.948436 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.948532 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|54fa1853-a4d3-62f0-fe3d-e2c3685e9cd1|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:c7895276-8b0f-339e-e840-6c24b8d34126', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3053] 2012-11-30 14:35:10.948715 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.948848 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.948915 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.962141 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3053] 2012-11-30 14:35:10.968334 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.968448 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.968529 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.968532 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.980672 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3053] 2012-11-30 14:35:10.980828 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.981001 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.274804 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.274900 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|60478f81-a75e-86a6-95c2-c8cc9ba61330|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:d4ad69a3-c17f-a474-2966-6ea2e9b8da47', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3081] 2012-11-30 14:35:11.274900 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3081] 2012-11-30 14:35:11.282524 SUCCESS
[3081] 2012-11-30 14:35:11.282779 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3081] 2012-11-30 14:35:11.289259 SUCCESS
[3081] 2012-11-30 14:35:11.289710 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3081] 2012-11-30 14:35:11.289729 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3081] 2012-11-30 14:35:11.290015 Kicking GC
<3081> 2012-11-30 14:35:11.290139 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3102> 2012-11-30 14:35:11.294652 Will finish as PID [3103]
<3081> 2012-11-30 14:35:11.295398 New PID [3102]
[3081] 2012-11-30 14:35:11.295629 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3081] 2012-11-30 14:35:11.335001 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.335514 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3103> 2012-11-30 14:35:11.378194 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3103> 2012-11-30 14:35:11.378335 ***********************
<3103> 2012-11-30 14:35:11.378393 * E X C E P T I O N *
<3103> 2012-11-30 14:35:11.378439 ***********************
<3103> 2012-11-30 14:35:11.378510 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3103> 2012-11-30 14:35:11.378567 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3103> 2012-11-30 14:35:11.378617 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3103> 2012-11-30 14:35:11.378667 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2942] 2013-11-05 18:58:04.799002 Warning: vdi_[de]activate present for dummy
[3059] 2013-11-05 18:58:06.642494 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|42a495b5-a944-a1f7-adcf-0b3c28d06084|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:784a8ba1-b13c-ae5b-4d9c-e7c8ad65901c', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3059] 2013-11-05 18:58:06.642788 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.642921 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.643034 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.643101 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.648901 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3059] 2013-11-05 18:58:06.654142 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.654222 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.655032 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.655091 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.658665 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3076] 2013-11-05 18:58:06.916713 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|64a08806-a315-a766-e248-8c137b0f2ef4|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:b06eb1b1-7547-a733-32fd-35f616afdb0b', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3077] 2013-11-05 18:58:06.926046 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.926201 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.926291 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|5f90c7a4-fc50-9fe7-7c8e-859cb7ee291c|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:a266cdb8-329a-6f0b-fc90-219a2c2a9b2f', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3077] 2013-11-05 18:58:06.926463 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.926582 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.926582 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.932739 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3077] 2013-11-05 18:58:06.935612 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.935690 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.935747 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.935798 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.939464 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3077] 2013-11-05 18:58:06.939464 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.939594 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.248962 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.249129 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|fb11d530-ad3b-8d98-1faf-b5dbc3d8e806|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:5d7f51a4-da82-2adf-79b5-ad9abf614071', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3106] 2013-11-05 18:58:07.249295 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3106] 2013-11-05 18:58:07.346787 SUCCESS
[3106] 2013-11-05 18:58:07.346866 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3106] 2013-11-05 18:58:07.353077 SUCCESS
[3106] 2013-11-05 18:58:07.353544 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3106] 2013-11-05 18:58:07.353639 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3106] 2013-11-05 18:58:07.353687 Kicking GC
<3106> 2013-11-05 18:58:07.353758 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3114> 2013-11-05 18:58:07.356423 Will finish as PID [3115]
<3106> 2013-11-05 18:58:07.357016 New PID [3114]
[3106] 2013-11-05 18:58:07.357247 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3106] 2013-11-05 18:58:07.400075 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.400523 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3115> 2013-11-05 18:58:07.662829 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3115> 2013-11-05 18:58:07.662940 ***********************
<3115> 2013-11-05 18:58:07.663014 * E X C E P T I O N *
<3115> 2013-11-05 18:58:07.663062 ***********************
<3115> 2013-11-05 18:58:07.663132 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3115> 2013-11-05 18:58:07.663178 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3115> 2013-11-05 18:58:07.663224 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3115> 2013-11-05 18:58:07.663270 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3199] 2013-11-05 18:59:28.143057 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3199] 2013-11-05 18:59:28.143208 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|17c76517-b52d-11ca-6e59-1276785fa1f4|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:64958a57-cb86-4556-1e24-c09f165e0899', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3199] 2013-11-05 18:59:28.143391 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3199] 2013-11-05 18:59:28.149237 SUCCESS
[3199] 2013-11-05 18:59:28.149502 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3199] 2013-11-05 18:59:28.155874 SUCCESS
[3199] 2013-11-05 18:59:28.156391 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3199] 2013-11-05 18:59:28.156488 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3199] 2013-11-05 18:59:28.156536 Kicking GC
<3199> 2013-11-05 18:59:28.156625 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3203> 2013-11-05 18:59:28.159661 Will finish as PID [3204]
<3199> 2013-11-05 18:59:28.160322 New PID [3203]
[3199] 2013-11-05 18:59:28.160575 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3199] 2013-11-05 18:59:28.203738 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3199] 2013-11-05 18:59:28.203893 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3204> 2013-11-05 18:59:28.249589 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3204> 2013-11-05 18:59:28.249726 ***********************
<3204> 2013-11-05 18:59:28.249796 * E X C E P T I O N *
<3204> 2013-11-05 18:59:28.249852 ***********************
<3204> 2013-11-05 18:59:28.249932 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3204> 2013-11-05 18:59:28.249989 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3204> 2013-11-05 18:59:28.250045 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3204> 2013-11-05 18:59:28.250101 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3228] 2013-11-05 18:59:28.371665 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:8a8c62ac-0b03-1bc3-b52a-2e7592e8db84', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:bdeed438-155f-bb09-5645-232088c82fdd', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3228] 2013-11-05 18:59:28.388489 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3242] 2013-11-05 18:59:28.561834 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:194e3593-f349-65cf-8a82-b7cbc7e9125d', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:b604e220-9d10-366c-58ef-a2548a044c16', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3242] 2013-11-05 18:59:28.586611 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.723296 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.723446 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|e7000bcb-e66d-d044-969d-8cce81cf619e|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:fc254f12-57ee-a108-db51-c1fced6b6326', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3302] 2013-11-05 19:02:58.723552 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3302] 2013-11-05 19:02:58.729536 SUCCESS
[3302] 2013-11-05 19:02:58.729803 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3302] 2013-11-05 19:02:58.736339 SUCCESS
[3302] 2013-11-05 19:02:58.736897 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3302] 2013-11-05 19:02:58.737034 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3302] 2013-11-05 19:02:58.737093 Kicking GC
<3302> 2013-11-05 19:02:58.737173 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3306> 2013-11-05 19:02:58.740562 Will finish as PID [3307]
<3302> 2013-11-05 19:02:58.741298 New PID [3306]
[3302] 2013-11-05 19:02:58.741579 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3302] 2013-11-05 19:02:58.787766 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.788301 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3307> 2013-11-05 19:02:58.841593 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3307> 2013-11-05 19:02:58.841721 ***********************
<3307> 2013-11-05 19:02:58.841779 * E X C E P T I O N *
<3307> 2013-11-05 19:02:58.841835 ***********************
<3307> 2013-11-05 19:02:58.841915 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3307> 2013-11-05 19:02:58.841972 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3307> 2013-11-05 19:02:58.842032 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3307> 2013-11-05 19:02:58.842105 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3331] 2013-11-05 19:02:58.968479 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:48435a82-6ae7-d84b-98d6-81c0829a2057', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:3b329010-1de1-4a14-1e5d-9f523706f04e', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3331] 2013-11-05 19:02:58.987225 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3345] 2013-11-05 19:02:59.137440 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:9f3e9ab8-ca34-372c-54b8-6216e4a86f14', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:91b1177f-83fb-a745-63d0-3f5f484942a5', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3345] 2013-11-05 19:02:59.155342 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.746275 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.746423 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|8832ce63-4453-f199-fee5-03359dcbe22b|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:a1e1c06d-bd91-7dd9-ddba-647116c11d29', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3367] 2013-11-05 19:05:58.746579 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3367] 2013-11-05 19:05:58.751599 SUCCESS
[3367] 2013-11-05 19:05:58.751813 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3367] 2013-11-05 19:05:58.757779 SUCCESS
[3367] 2013-11-05 19:05:58.757937 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3367] 2013-11-05 19:05:58.758037 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3367] 2013-11-05 19:05:58.758101 Kicking GC
<3367> 2013-11-05 19:05:58.758175 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3371> 2013-11-05 19:05:58.761213 Will finish as PID [3372]
<3367> 2013-11-05 19:05:58.761798 New PID [3371]
[3367] 2013-11-05 19:05:58.762057 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3367] 2013-11-05 19:05:58.808554 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.809007 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3372> 2013-11-05 19:05:58.850735 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3372> 2013-11-05 19:05:58.850735 ***********************
<3372> 2013-11-05 19:05:58.850735 * E X C E P T I O N *
<3372> 2013-11-05 19:05:58.850749 ***********************
<3372> 2013-11-05 19:05:58.850853 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3372> 2013-11-05 19:05:58.850903 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3372> 2013-11-05 19:05:58.850954 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3372> 2013-11-05 19:05:58.851001 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3396] 2013-11-05 19:05:58.976703 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:bdb4342c-7b2a-ce00-c407-e3692c66087d', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:755caeee-0f05-4248-2ace-003c4d9a5655', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3396] 2013-11-05 19:05:59.001042 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3410] 2013-11-05 19:05:59.146000 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:a0a33eb3-c9e9-d147-88a9-3ab68192e711', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:66ea51f1-8db3-b1c0-cd1f-e159e77c841e', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3410] 2013-11-05 19:05:59.162665 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[2923] 2013-11-06 06:23:36.768770 Warning: vdi_[de]activate present for dummy
[3040] 2013-11-06 06:23:39.023433 sr_attach {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|fd1f5965-9308-3165-34fc-b632bcaee5e1|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:d22130a9-662f-fed6-f4ba-66f50f75ae24', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3040] 2013-11-06 06:23:39.023784 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.023893 lock: creating lock file /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.023893 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.023893 lock: acquired /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.029867 RESET for SR 33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3040] 2013-11-06 06:23:39.036871 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.036968 lock: released /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.037030 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.037085 lock: closed /var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.041641 set_dirty 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3058] 2013-11-06 06:23:39.312532 sr_scan {'sr_uuid': '33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of': 'DummyRef:|60cb3314-1baa-57dd-257e-60a5c122b571|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:787bc197-4581-dde9-0c8d-2ba0fe9f43da', 'device_config': {'legacy_mode': 'true', 'SRmaster': 'true', 'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3057] 2013-11-06 06:23:39.331836 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.331955 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.332275 sr_attach {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|c40d9dcf-22a4-5331-ed9c-7a8fc3b3a9e4|SR.attach', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:fadcb230-1a37-c4f2-c574-ac5193af5578', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3057] 2013-11-06 06:23:39.332453 lock: creating lock file /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.332608 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.332742 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.340318 RESET for SR 9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3057] 2013-11-06 06:23:39.350050 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.350632 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.351036 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.351248 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.363087 set_dirty 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3057] 2013-11-06 06:23:39.363238 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.363417 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3058] 2013-11-06 06:23:39.399896 new VDIs on disk: set(['systemvm.iso'])
[3058] 2013-11-06 06:23:39.399997 Introducing VDI with location=systemvm.iso
[3058] 2013-11-06 06:23:39.400089 ['uuidgen', '-r']
[3058] 2013-11-06 06:23:39.443527 SUCCESS
[3087] 2013-11-06 06:23:39.660913 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3087] 2013-11-06 06:23:39.661074 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|e7e2856a-2a04-a71f-d94a-d31379b48505|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:bc5228e4-44ad-7575-9612-357c8bbfe047', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3087] 2013-11-06 06:23:39.661292 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3087] 2013-11-06 06:23:39.711489 SUCCESS
[3087] 2013-11-06 06:23:39.711751 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3087] 2013-11-06 06:23:39.717868 SUCCESS
[3087] 2013-11-06 06:23:39.718364 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3087] 2013-11-06 06:23:39.718466 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3087] 2013-11-06 06:23:39.718518 Kicking GC
<3087> 2013-11-06 06:23:39.718607 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3101> 2013-11-06 06:23:39.723942 Will finish as PID [3102]
<3087> 2013-11-06 06:23:39.724563 New PID [3101]
[3087] 2013-11-06 06:23:39.724821 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3087] 2013-11-06 06:23:39.816876 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3087] 2013-11-06 06:23:39.817365 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3102> 2013-11-06 06:23:39.875847 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3102> 2013-11-06 06:23:39.875963 ***********************
<3102> 2013-11-06 06:23:39.876010 * E X C E P T I O N *
<3102> 2013-11-06 06:23:39.876055 ***********************
<3102> 2013-11-06 06:23:39.876138 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3102> 2013-11-06 06:23:39.876186 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3102> 2013-11-06 06:23:39.876237 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3102> 2013-11-06 06:23:39.876283 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3247] 2013-11-06 06:25:37.054286 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3247] 2013-11-06 06:25:37.054406 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|11b454f8-2c87-79d6-6664-944b93609570|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:5df09fbf-3102-a1b1-4c06-01fc4e41ccfb', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3247] 2013-11-06 06:25:37.054553 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3247] 2013-11-06 06:25:37.060465 SUCCESS
[3247] 2013-11-06 06:25:37.060726 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3247] 2013-11-06 06:25:37.065994 SUCCESS
[3247] 2013-11-06 06:25:37.066131 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3247] 2013-11-06 06:25:37.066298 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3247] 2013-11-06 06:25:37.066358 Kicking GC
<3247> 2013-11-06 06:25:37.066433 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3251> 2013-11-06 06:25:37.069550 Will finish as PID [3252]
<3247> 2013-11-06 06:25:37.070846 New PID [3251]
[3247] 2013-11-06 06:25:37.071117 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3247] 2013-11-06 06:25:37.114043 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3247] 2013-11-06 06:25:37.114503 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3252> 2013-11-06 06:25:37.152059 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3252> 2013-11-06 06:25:37.152194 ***********************
<3252> 2013-11-06 06:25:37.152252 * E X C E P T I O N *
<3252> 2013-11-06 06:25:37.152297 ***********************
<3252> 2013-11-06 06:25:37.152364 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3252> 2013-11-06 06:25:37.152409 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3252> 2013-11-06 06:25:37.152455 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3252> 2013-11-06 06:25:37.152500 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3276] 2013-11-06 06:25:37.285531 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:b76ba936-0a4c-a003-f6ed-f49177323aaf', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:ce1ca201-9996-287a-8d60-2a1f358d0cd1', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3276] 2013-11-06 06:25:37.302203 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3290] 2013-11-06 06:25:37.450732 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:39514e11-9afa-dcba-c3b5-6d640141f500', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:172a342f-dcfa-2104-68fb-bad5b079b654', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3290] 2013-11-06 06:25:37.468925 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.703948 lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.703958 sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'DummyRef:|d67b1d33-71dc-1014-0b4f-0fa6a6432585|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:1d495451-1882-ea80-a595-f02be6225b29', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3364] 2013-11-06 06:29:17.704122 ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[3364] 2013-11-06 06:29:17.709129 SUCCESS
[3364] 2013-11-06 06:29:17.709439 ['ls', '/opt/storage/primary', '-1', '--color=never']
[3364] 2013-11-06 06:29:17.715696 SUCCESS
[3364] 2013-11-06 06:29:17.715984 lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired: True (exists: True)
[3364] 2013-11-06 06:29:17.716026 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3364] 2013-11-06 06:29:17.716079 Kicking GC
<3364> 2013-11-06 06:29:17.716176 === SR 9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3368> 2013-11-06 06:29:17.719049 Will finish as PID [3369]
<3364> 2013-11-06 06:29:17.720496 New PID [3368]
[3364] 2013-11-06 06:29:17.720780 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3364] 2013-11-06 06:29:17.764394 lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.764848 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3369> 2013-11-06 06:29:17.805411 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3369> 2013-11-06 06:29:17.805556 ***********************
<3369> 2013-11-06 06:29:17.805620 * E X C E P T I O N *
<3369> 2013-11-06 06:29:17.805679 ***********************
<3369> 2013-11-06 06:29:17.805763 gc: EXCEPTION <type 'exceptions.OSError'>, [Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3369> 2013-11-06 06:29:17.805823 File "/usr/lib/xcp/sm/cleanup.py", line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3369> 2013-11-06 06:29:17.805894 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3369> 2013-11-06 06:29:17.805953 * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3393] 2013-11-06 06:29:17.933726 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:2979ec4e-9b4d-c367-19d7-82b0dc39a201', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:2b13c4c0-086f-1c73-d58b-e92446d531ee', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3393] 2013-11-06 06:29:17.951477 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3407] 2013-11-06 06:29:18.112767 sr_update {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of': 'OpaqueRef:8d12d6b8-68bf-5777-ed3c-0f8cbed778f7', 'args': [], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:68b606cb-1ec1-1ac7-ce2e-dd4613f2385e', 'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3407] 2013-11-06 06:29:18.130718 lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
I'm not able to figure out ,please guide me further
-Aakash
On Wed, Nov 6, 2013 at 10:22 AM, Jayapal Reddy Uradi <ja...@citrix.com>> wrote:
Hi,
>From the logs vmops, setIptables call failed.
for cmd: setIptables with args due to There was a failure
Can you check the xenserver agent log (SMlog) to know more info
Thanks,
Jayapal
On 06-Nov-2013, at 9:56 AM, Aakash Kumar <ju...@gmail.com>>
wrote:
> Hello ,
> Following exception occurred on running deployDatacenter.py using
> devcloud.cfg
>
> INFO [c.c.r.ResourceManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Trying to add a new host at http://192.168.56.10/ in data center 1
> INFO [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Found host devcloud ip=192.168.56.10 product version=1.6.0
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Private Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Guest Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Public Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Host: devcloud connected with hypervisor type: XenServer. Checking
> CIDR...
> INFO [c.c.a.m.DirectAgentAttache]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> StartupAnswer received 1 Interval = 60
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\ovsgre
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\ipassoc.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getDomRVersion.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getRouterStatus.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\networkUsage.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\l2tp_vpn.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\vhd-util
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> callHostPlugin failed for cmd: setIptables with args due to There was
> a failure communicating with the plugin.
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> Unable to setup
> com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed
> for cmd: setIptables with args due to There was a failure
> communicating with the plugin.
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:4293)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.setIptables(CitrixResourceBase.java:4305)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:5098)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:547)
> at com.cloud.hypervisor.xen.resource.XcpOssResource.executeRequest(XcpOssResource.java:140)
> at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:187)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> WARN [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Unable to setup agent 1 due to callHostPlugin failed for cmd:
> setIptables with args due to There was a failure communicating with
> the plugin.
> INFO [c.c.u.e.CSExceptionErrorCode]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Could not find exception: com.cloud.exception.ConnectionException in
> error code list for exceptions
> WARN [c.c.a.m.AgentManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Monitor XcpServerDiscoverer says there is an error in the connect
> process for 1 due to Reinitialize agent after setup.
> INFO [c.c.a.m.AgentManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Host 1 is disconnecting with event AgentDisconnected
> WARN [c.c.r.ResourceManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Unable to connect due to
> com.cloud.exception.ConnectionException: Reinitialize agent after setup.
> at com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer.processConnect(XcpServerDiscoverer.java:665)
> at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:491)
> at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1398)
> at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1802)
> at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy146.discoverHosts(Unknown Source)
> at org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at com.cloud.api.ApiServer.queueCommand(ApiServer.java:527)
> at com.cloud.api.ApiServer.handleRequest(ApiServer.java:370)
> at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:322)
> at com.cloud.api.ApiServlet.access$000(ApiServlet.java:52)
> at com.cloud.api.ApiServlet$1.run(ApiServlet.java:114)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:111)
> at com.cloud.api.ApiServlet.doGet(ApiServlet.java:73)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
> at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:401)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
> ERROR [c.c.a.ApiServer] (1456585835@qtp-2122825114-0:ctx-2dc342a1
> ctx-d1559de5 ctx-fae00876) unhandled exception executing api command:
> addHost
> com.cloud.utils.exception.CloudRuntimeException: Cannot transit agent
> status with event AgentDisconnected for host 1, mangement server id is
> 8871632142068,Unable to transition to a new state from Creating via
> AgentDisconnected
> at com.cloud.agent.manager.AgentManagerImpl.agentStatusTransitTo(AgentManagerImpl.java:1330)
> at com.cloud.resource.ResourceManagerImpl.markHostAsDisconnected(ResourceManagerImpl.java:1667)
> at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1828)
> at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
>
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
>
>
> -Aakash
Re: Exception Occurred adding host
Posted by Aakash Kumar <ju...@gmail.com>.
Thanks Jayapal,
This are the contents of SMLog
[2776] 2012-11-27 18:57:13.308162 Warning: vdi_[de]activate present for dummy
[3072] 2012-11-27 18:57:16.147441 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|d4d7f0d6-288d-be05-1a15-f8d3ba8c758e|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:8a93cae9-9dab-de77-a2ae-29d2506fc5cc',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3072] 2012-11-27 18:57:16.147772 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.147906 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.148023 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.148093 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.153252 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3072] 2012-11-27 18:57:16.156107 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.156185 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.156244 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3072] 2012-11-27 18:57:16.156297 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3072] 2012-11-27 18:57:16.160453 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3094] 2012-11-27 18:57:16.331733 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|9c55c7d9-0bba-1dd0-f178-d2081b730c09|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:be5ffc66-72ec-03c2-eaf9-4380ba2ba7bf',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3748] 2012-11-27 19:07:39.801156 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.801669 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.801918 sr_create {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:db0dd841-c6e6-fa1d-1571-d6e83903348b', 'args': ['0'],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:b808c72d-6d19-8322-a8ce-30c85de05032',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_create', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3748] 2012-11-27 19:07:39.802135 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3748] 2012-11-27 19:07:39.813217 SUCCESS
[3748] 2012-11-27 19:07:39.813590 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3748] 2012-11-27 19:07:39.813808 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.970120 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.970245 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|d554e0ef-d365-bbbf-c5e8-45fcb4f63614|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:b6d75fa2-6f95-73d8-005f-b5cc4b0c2ffd',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3757] 2012-11-27 19:07:39.970709 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.971196 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.971306 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.977144 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3757] 2012-11-27 19:07:39.979777 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.979862 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.979923 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3757] 2012-11-27 19:07:39.979977 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.987449 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3757] 2012-11-27 19:07:39.987573 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3757] 2012-11-27 19:07:39.987774 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.144209 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.144336 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|c1acca96-c591-5349-c122-4862150a580c|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:6edf9b39-15a3-9f2a-9d51-f7fbbfbd7563',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3771] 2012-11-27 19:07:40.144553 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3771] 2012-11-27 19:07:40.153005 SUCCESS
[3771] 2012-11-27 19:07:40.153271 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3771] 2012-11-27 19:07:40.159972 SUCCESS
[3771] 2012-11-27 19:07:40.160453 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3771] 2012-11-27 19:07:40.160549 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3771] 2012-11-27 19:07:40.160598 Kicking GC
<3771> 2012-11-27 19:07:40.160671 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3775> 2012-11-27 19:07:40.164322 Will finish as PID [3776]
<3771> 2012-11-27 19:07:40.165006 New PID [3775]
[3771] 2012-11-27 19:07:40.165259 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3771] 2012-11-27 19:07:40.206452 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3771] 2012-11-27 19:07:40.206910 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3776> 2012-11-27 19:07:40.246753 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3776> 2012-11-27 19:07:40.246954 ***********************
<3776> 2012-11-27 19:07:40.247017 * E X C E P T I O N *
<3776> 2012-11-27 19:07:40.247075 ***********************
<3776> 2012-11-27 19:07:40.247167 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3776> 2012-11-27 19:07:40.247216 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3776> 2012-11-27 19:07:40.247263 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3776> 2012-11-27 19:07:40.247310 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2757] 2012-11-27 23:31:09.305319 Warning: vdi_[de]activate present for dummy
[3012] 2012-11-27 23:31:11.154570 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|9ddee2d8-7626-6011-043a-57cdd8ab5a4a|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:278d04fe-0b30-d26f-1196-de7e128e7679',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3012] 2012-11-27 23:31:11.154896 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.155017 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.155137 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.155205 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.160978 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3012] 2012-11-27 23:31:11.167789 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.167888 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.167888 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3012] 2012-11-27 23:31:11.167888 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3012] 2012-11-27 23:31:11.171944 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3026] 2012-11-27 23:31:11.425591 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.425758 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.425878 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|ddc03fa0-6365-ec15-ea64-e226501fe834|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:e621cbbb-5364-4194-663c-8388507a15c7',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3026] 2012-11-27 23:31:11.426052 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.426227 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.426298 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3030] 2012-11-27 23:31:11.430295 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|67dcd3f9-b485-451b-12f0-b00535e0fff2|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:79343d17-a459-4f14-d4bc-1ac797fd1d0f',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3026] 2012-11-27 23:31:11.440098 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3026] 2012-11-27 23:31:11.445854 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.446001 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.446075 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3026] 2012-11-27 23:31:11.446142 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.452270 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3026] 2012-11-27 23:31:11.452413 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3026] 2012-11-27 23:31:11.452571 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.664626 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.664771 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|7e247ff0-ddb6-6a6f-c7fb-a37739bcf00d|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:c63ce5c9-0141-b40f-adaf-bd4de17d83c2',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3057] 2012-11-27 23:31:11.664946 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3057] 2012-11-27 23:31:11.672209 SUCCESS
[3057] 2012-11-27 23:31:11.672483 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3057] 2012-11-27 23:31:11.678889 SUCCESS
[3057] 2012-11-27 23:31:11.679386 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3057] 2012-11-27 23:31:11.679490 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2012-11-27 23:31:11.679540 Kicking GC
<3057> 2012-11-27 23:31:11.679616 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3063> 2012-11-27 23:31:11.683450 Will finish as PID [3064]
<3057> 2012-11-27 23:31:11.684281 New PID [3063]
[3057] 2012-11-27 23:31:11.684548 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2012-11-27 23:31:11.738379 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2012-11-27 23:31:11.738829 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3064> 2012-11-27 23:31:11.772234 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3064> 2012-11-27 23:31:11.772347 ***********************
<3064> 2012-11-27 23:31:11.772434 * E X C E P T I O N *
<3064> 2012-11-27 23:31:11.772493 ***********************
<3064> 2012-11-27 23:31:11.772566 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3064> 2012-11-27 23:31:11.772614 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3064> 2012-11-27 23:31:11.772661 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3064> 2012-11-27 23:31:11.772709 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2763] 2012-11-29 05:17:56.038145 Warning: vdi_[de]activate present for dummy
[3019] 2012-11-29 05:17:57.872719 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|d2b6b9fd-c374-5b4e-d0fe-576a13ebebb4|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:9b05f2b9-14e2-f754-7524-ee0d602efd01',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3019] 2012-11-29 05:17:57.873109 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.873241 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.873375 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.873480 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.879289 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3019] 2012-11-29 05:17:57.883487 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.883580 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.883641 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3019] 2012-11-29 05:17:57.883695 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3019] 2012-11-29 05:17:57.887567 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3036] 2012-11-29 05:17:58.137991 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|a6dc6010-8835-72f4-20e2-26f21a283ebd|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:deb93bb0-9a70-a643-bae3-1419eff3f103',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3037] 2012-11-29 05:17:58.143180 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.143332 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.143432 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|c85abc53-6b28-1146-fd63-8efd47689710|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:cac270c1-4683-711c-598e-12c20eb0f20a',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3037] 2012-11-29 05:17:58.143641 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.143771 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.143837 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.153300 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3037] 2012-11-29 05:17:58.156263 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.156341 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.156399 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3037] 2012-11-29 05:17:58.156451 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.160669 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3037] 2012-11-29 05:17:58.161068 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3037] 2012-11-29 05:17:58.161222 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.369936 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.370057 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|5ec72ead-1384-9539-97cf-3893eebc81f0|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:070dbec1-2cc2-cc78-b750-196b18fce239',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3066] 2012-11-29 05:17:58.370210 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3066] 2012-11-29 05:17:58.377227 SUCCESS
[3066] 2012-11-29 05:17:58.377481 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3066] 2012-11-29 05:17:58.383303 SUCCESS
[3066] 2012-11-29 05:17:58.383800 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3066] 2012-11-29 05:17:58.383898 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3066] 2012-11-29 05:17:58.383946 Kicking GC
<3066> 2012-11-29 05:17:58.384021 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3070> 2012-11-29 05:17:58.388106 Will finish as PID [3071]
<3066> 2012-11-29 05:17:58.388933 New PID [3070]
[3066] 2012-11-29 05:17:58.389232 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3066] 2012-11-29 05:17:58.429249 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3066] 2012-11-29 05:17:58.429689 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3071> 2012-11-29 05:17:58.468419 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3071> 2012-11-29 05:17:58.468551 ***********************
<3071> 2012-11-29 05:17:58.468599 * E X C E P T I O N *
<3071> 2012-11-29 05:17:58.468644 ***********************
<3071> 2012-11-29 05:17:58.468714 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3071> 2012-11-29 05:17:58.468761 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3071> 2012-11-29 05:17:58.468807 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3071> 2012-11-29 05:17:58.468854 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2780] 2012-11-30 14:35:08.613349 Warning: vdi_[de]activate present for dummy
[3035] 2012-11-30 14:35:10.654146 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|9f23f5b4-1ea7-c7e8-40c6-d00c60ccdd72|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:175bb0e2-fd98-0bfd-0038-9883d6fc142a',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3035] 2012-11-30 14:35:10.654457 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.654457 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.654457 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.654497 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.661071 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3035] 2012-11-30 14:35:10.664359 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.664450 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.664831 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3035] 2012-11-30 14:35:10.664916 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3035] 2012-11-30 14:35:10.668671 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3052] 2012-11-30 14:35:10.933454 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|cbda77a4-117c-b477-9e44-6f17121fed9b|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:a76c3727-0d65-31e0-c066-097b3f9958a9',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3053] 2012-11-30 14:35:10.948276 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.948436 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.948532 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|54fa1853-a4d3-62f0-fe3d-e2c3685e9cd1|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:c7895276-8b0f-339e-e840-6c24b8d34126',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3053] 2012-11-30 14:35:10.948715 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.948848 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.948915 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.962141 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3053] 2012-11-30 14:35:10.968334 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.968448 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.968529 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3053] 2012-11-30 14:35:10.968532 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.980672 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3053] 2012-11-30 14:35:10.980828 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3053] 2012-11-30 14:35:10.981001 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.274804 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.274900 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|60478f81-a75e-86a6-95c2-c8cc9ba61330|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:d4ad69a3-c17f-a474-2966-6ea2e9b8da47',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3081] 2012-11-30 14:35:11.274900 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3081] 2012-11-30 14:35:11.282524 SUCCESS
[3081] 2012-11-30 14:35:11.282779 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3081] 2012-11-30 14:35:11.289259 SUCCESS
[3081] 2012-11-30 14:35:11.289710 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3081] 2012-11-30 14:35:11.289729 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3081] 2012-11-30 14:35:11.290015 Kicking GC
<3081> 2012-11-30 14:35:11.290139 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3102> 2012-11-30 14:35:11.294652 Will finish as PID [3103]
<3081> 2012-11-30 14:35:11.295398 New PID [3102]
[3081] 2012-11-30 14:35:11.295629 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3081] 2012-11-30 14:35:11.335001 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3081] 2012-11-30 14:35:11.335514 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3103> 2012-11-30 14:35:11.378194 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3103> 2012-11-30 14:35:11.378335 ***********************
<3103> 2012-11-30 14:35:11.378393 * E X C E P T I O N *
<3103> 2012-11-30 14:35:11.378439 ***********************
<3103> 2012-11-30 14:35:11.378510 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3103> 2012-11-30 14:35:11.378567 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3103> 2012-11-30 14:35:11.378617 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3103> 2012-11-30 14:35:11.378667 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[2942] 2013-11-05 18:58:04.799002 Warning: vdi_[de]activate present for dummy
[3059] 2013-11-05 18:58:06.642494 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|42a495b5-a944-a1f7-adcf-0b3c28d06084|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:784a8ba1-b13c-ae5b-4d9c-e7c8ad65901c',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3059] 2013-11-05 18:58:06.642788 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.642921 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.643034 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.643101 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.648901 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3059] 2013-11-05 18:58:06.654142 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.654222 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.655032 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3059] 2013-11-05 18:58:06.655091 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3059] 2013-11-05 18:58:06.658665 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3076] 2013-11-05 18:58:06.916713 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|64a08806-a315-a766-e248-8c137b0f2ef4|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:b06eb1b1-7547-a733-32fd-35f616afdb0b',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3077] 2013-11-05 18:58:06.926046 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.926201 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.926291 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|5f90c7a4-fc50-9fe7-7c8e-859cb7ee291c|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:a266cdb8-329a-6f0b-fc90-219a2c2a9b2f',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3077] 2013-11-05 18:58:06.926463 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.926582 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.926582 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.932739 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3077] 2013-11-05 18:58:06.935612 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.935690 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.935747 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3077] 2013-11-05 18:58:06.935798 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.939464 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3077] 2013-11-05 18:58:06.939464 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3077] 2013-11-05 18:58:06.939594 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.248962 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.249129 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|fb11d530-ad3b-8d98-1faf-b5dbc3d8e806|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:5d7f51a4-da82-2adf-79b5-ad9abf614071',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3106] 2013-11-05 18:58:07.249295 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3106] 2013-11-05 18:58:07.346787 SUCCESS
[3106] 2013-11-05 18:58:07.346866 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3106] 2013-11-05 18:58:07.353077 SUCCESS
[3106] 2013-11-05 18:58:07.353544 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3106] 2013-11-05 18:58:07.353639 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3106] 2013-11-05 18:58:07.353687 Kicking GC
<3106> 2013-11-05 18:58:07.353758 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3114> 2013-11-05 18:58:07.356423 Will finish as PID [3115]
<3106> 2013-11-05 18:58:07.357016 New PID [3114]
[3106] 2013-11-05 18:58:07.357247 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3106] 2013-11-05 18:58:07.400075 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3106] 2013-11-05 18:58:07.400523 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3115> 2013-11-05 18:58:07.662829 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3115> 2013-11-05 18:58:07.662940 ***********************
<3115> 2013-11-05 18:58:07.663014 * E X C E P T I O N *
<3115> 2013-11-05 18:58:07.663062 ***********************
<3115> 2013-11-05 18:58:07.663132 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3115> 2013-11-05 18:58:07.663178 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3115> 2013-11-05 18:58:07.663224 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3115> 2013-11-05 18:58:07.663270 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3199] 2013-11-05 18:59:28.143057 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3199] 2013-11-05 18:59:28.143208 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|17c76517-b52d-11ca-6e59-1276785fa1f4|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:64958a57-cb86-4556-1e24-c09f165e0899',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3199] 2013-11-05 18:59:28.143391 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3199] 2013-11-05 18:59:28.149237 SUCCESS
[3199] 2013-11-05 18:59:28.149502 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3199] 2013-11-05 18:59:28.155874 SUCCESS
[3199] 2013-11-05 18:59:28.156391 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3199] 2013-11-05 18:59:28.156488 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3199] 2013-11-05 18:59:28.156536 Kicking GC
<3199> 2013-11-05 18:59:28.156625 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3203> 2013-11-05 18:59:28.159661 Will finish as PID [3204]
<3199> 2013-11-05 18:59:28.160322 New PID [3203]
[3199] 2013-11-05 18:59:28.160575 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3199] 2013-11-05 18:59:28.203738 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3199] 2013-11-05 18:59:28.203893 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3204> 2013-11-05 18:59:28.249589 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3204> 2013-11-05 18:59:28.249726 ***********************
<3204> 2013-11-05 18:59:28.249796 * E X C E P T I O N *
<3204> 2013-11-05 18:59:28.249852 ***********************
<3204> 2013-11-05 18:59:28.249932 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3204> 2013-11-05 18:59:28.249989 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3204> 2013-11-05 18:59:28.250045 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3204> 2013-11-05 18:59:28.250101 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3228] 2013-11-05 18:59:28.371665 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:8a8c62ac-0b03-1bc3-b52a-2e7592e8db84', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:bdeed438-155f-bb09-5645-232088c82fdd',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3228] 2013-11-05 18:59:28.388489 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3242] 2013-11-05 18:59:28.561834 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:194e3593-f349-65cf-8a82-b7cbc7e9125d', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:b604e220-9d10-366c-58ef-a2548a044c16',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3242] 2013-11-05 18:59:28.586611 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.723296 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.723446 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|e7000bcb-e66d-d044-969d-8cce81cf619e|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:fc254f12-57ee-a108-db51-c1fced6b6326',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3302] 2013-11-05 19:02:58.723552 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3302] 2013-11-05 19:02:58.729536 SUCCESS
[3302] 2013-11-05 19:02:58.729803 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3302] 2013-11-05 19:02:58.736339 SUCCESS
[3302] 2013-11-05 19:02:58.736897 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3302] 2013-11-05 19:02:58.737034 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3302] 2013-11-05 19:02:58.737093 Kicking GC
<3302> 2013-11-05 19:02:58.737173 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3306> 2013-11-05 19:02:58.740562 Will finish as PID [3307]
<3302> 2013-11-05 19:02:58.741298 New PID [3306]
[3302] 2013-11-05 19:02:58.741579 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3302] 2013-11-05 19:02:58.787766 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3302] 2013-11-05 19:02:58.788301 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3307> 2013-11-05 19:02:58.841593 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3307> 2013-11-05 19:02:58.841721 ***********************
<3307> 2013-11-05 19:02:58.841779 * E X C E P T I O N *
<3307> 2013-11-05 19:02:58.841835 ***********************
<3307> 2013-11-05 19:02:58.841915 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3307> 2013-11-05 19:02:58.841972 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3307> 2013-11-05 19:02:58.842032 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3307> 2013-11-05 19:02:58.842105 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3331] 2013-11-05 19:02:58.968479 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:48435a82-6ae7-d84b-98d6-81c0829a2057', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:3b329010-1de1-4a14-1e5d-9f523706f04e',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3331] 2013-11-05 19:02:58.987225 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3345] 2013-11-05 19:02:59.137440 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:9f3e9ab8-ca34-372c-54b8-6216e4a86f14', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:91b1177f-83fb-a745-63d0-3f5f484942a5',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3345] 2013-11-05 19:02:59.155342 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.746275 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.746423 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|8832ce63-4453-f199-fee5-03359dcbe22b|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:a1e1c06d-bd91-7dd9-ddba-647116c11d29',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3367] 2013-11-05 19:05:58.746579 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3367] 2013-11-05 19:05:58.751599 SUCCESS
[3367] 2013-11-05 19:05:58.751813 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3367] 2013-11-05 19:05:58.757779 SUCCESS
[3367] 2013-11-05 19:05:58.757937 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3367] 2013-11-05 19:05:58.758037 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3367] 2013-11-05 19:05:58.758101 Kicking GC
<3367> 2013-11-05 19:05:58.758175 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3371> 2013-11-05 19:05:58.761213 Will finish as PID [3372]
<3367> 2013-11-05 19:05:58.761798 New PID [3371]
[3367] 2013-11-05 19:05:58.762057 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3367] 2013-11-05 19:05:58.808554 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3367] 2013-11-05 19:05:58.809007 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3372> 2013-11-05 19:05:58.850735 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3372> 2013-11-05 19:05:58.850735 ***********************
<3372> 2013-11-05 19:05:58.850735 * E X C E P T I O N *
<3372> 2013-11-05 19:05:58.850749 ***********************
<3372> 2013-11-05 19:05:58.850853 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3372> 2013-11-05 19:05:58.850903 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3372> 2013-11-05 19:05:58.850954 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3372> 2013-11-05 19:05:58.851001 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3396] 2013-11-05 19:05:58.976703 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:bdb4342c-7b2a-ce00-c407-e3692c66087d', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:755caeee-0f05-4248-2ace-003c4d9a5655',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3396] 2013-11-05 19:05:59.001042 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3410] 2013-11-05 19:05:59.146000 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:a0a33eb3-c9e9-d147-88a9-3ab68192e711', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:66ea51f1-8db3-b1c0-cd1f-e159e77c841e',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3410] 2013-11-05 19:05:59.162665 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[2923] 2013-11-06 06:23:36.768770 Warning: vdi_[de]activate present for dummy
[3040] 2013-11-06 06:23:39.023433 sr_attach {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|fd1f5965-9308-3165-34fc-b632bcaee5e1|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:d22130a9-662f-fed6-f4ba-66f50f75ae24',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_attach',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3040] 2013-11-06 06:23:39.023784 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.023893 lock: creating lock file
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.023893 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.023893 lock: acquired
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.029867 RESET for SR
33323543-741e-a5c5-06a0-cdbdfef2f3bd (master: True)
[3040] 2013-11-06 06:23:39.036871 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.036968 lock: released
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.037030 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/running
[3040] 2013-11-06 06:23:39.037085 lock: closed
/var/lock/sm/33323543-741e-a5c5-06a0-cdbdfef2f3bd/sr
[3040] 2013-11-06 06:23:39.041641 set_dirty
'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71' succeeded
[3058] 2013-11-06 06:23:39.312532 sr_scan {'sr_uuid':
'33323543-741e-a5c5-06a0-cdbdfef2f3bd', 'subtask_of':
'DummyRef:|60cb3314-1baa-57dd-257e-60a5c122b571|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:787bc197-4581-dde9-0c8d-2ba0fe9f43da',
'device_config': {'legacy_mode': 'true', 'SRmaster': 'true',
'location': '/usr/share/xcp/packages/iso'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:26329dd8-dda1-6ec4-a09d-841f3ebb0b71'}
[3057] 2013-11-06 06:23:39.331836 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.331955 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.332275 sr_attach {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|c40d9dcf-22a4-5331-ed9c-7a8fc3b3a9e4|SR.attach', 'args':
[], 'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:fadcb230-1a37-c4f2-c574-ac5193af5578',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_attach', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3057] 2013-11-06 06:23:39.332453 lock: creating lock file
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.332608 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.332742 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.340318 RESET for SR
9f3f9262-3f77-09cc-2df7-0d8475676260 (master: True)
[3057] 2013-11-06 06:23:39.350050 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.350632 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.351036 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3057] 2013-11-06 06:23:39.351248 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.363087 set_dirty
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4' succeeded
[3057] 2013-11-06 06:23:39.363238 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3057] 2013-11-06 06:23:39.363417 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3058] 2013-11-06 06:23:39.399896 new VDIs on disk: set(['systemvm.iso'])
[3058] 2013-11-06 06:23:39.399997 Introducing VDI with location=systemvm.iso
[3058] 2013-11-06 06:23:39.400089 ['uuidgen', '-r']
[3058] 2013-11-06 06:23:39.443527 SUCCESS
[3087] 2013-11-06 06:23:39.660913 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3087] 2013-11-06 06:23:39.661074 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|e7e2856a-2a04-a71f-d94a-d31379b48505|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:bc5228e4-44ad-7575-9612-357c8bbfe047',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3087] 2013-11-06 06:23:39.661292 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3087] 2013-11-06 06:23:39.711489 SUCCESS
[3087] 2013-11-06 06:23:39.711751 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3087] 2013-11-06 06:23:39.717868 SUCCESS
[3087] 2013-11-06 06:23:39.718364 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3087] 2013-11-06 06:23:39.718466 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3087] 2013-11-06 06:23:39.718518 Kicking GC
<3087> 2013-11-06 06:23:39.718607 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3101> 2013-11-06 06:23:39.723942 Will finish as PID [3102]
<3087> 2013-11-06 06:23:39.724563 New PID [3101]
[3087] 2013-11-06 06:23:39.724821 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3087] 2013-11-06 06:23:39.816876 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3087] 2013-11-06 06:23:39.817365 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3102> 2013-11-06 06:23:39.875847 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3102> 2013-11-06 06:23:39.875963 ***********************
<3102> 2013-11-06 06:23:39.876010 * E X C E P T I O N *
<3102> 2013-11-06 06:23:39.876055 ***********************
<3102> 2013-11-06 06:23:39.876138 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3102> 2013-11-06 06:23:39.876186 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3102> 2013-11-06 06:23:39.876237 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3102> 2013-11-06 06:23:39.876283 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3247] 2013-11-06 06:25:37.054286 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3247] 2013-11-06 06:25:37.054406 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|11b454f8-2c87-79d6-6664-944b93609570|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:5df09fbf-3102-a1b1-4c06-01fc4e41ccfb',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3247] 2013-11-06 06:25:37.054553 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3247] 2013-11-06 06:25:37.060465 SUCCESS
[3247] 2013-11-06 06:25:37.060726 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3247] 2013-11-06 06:25:37.065994 SUCCESS
[3247] 2013-11-06 06:25:37.066131 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3247] 2013-11-06 06:25:37.066298 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3247] 2013-11-06 06:25:37.066358 Kicking GC
<3247> 2013-11-06 06:25:37.066433 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3251> 2013-11-06 06:25:37.069550 Will finish as PID [3252]
<3247> 2013-11-06 06:25:37.070846 New PID [3251]
[3247] 2013-11-06 06:25:37.071117 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3247] 2013-11-06 06:25:37.114043 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3247] 2013-11-06 06:25:37.114503 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3252> 2013-11-06 06:25:37.152059 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3252> 2013-11-06 06:25:37.152194 ***********************
<3252> 2013-11-06 06:25:37.152252 * E X C E P T I O N *
<3252> 2013-11-06 06:25:37.152297 ***********************
<3252> 2013-11-06 06:25:37.152364 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3252> 2013-11-06 06:25:37.152409 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3252> 2013-11-06 06:25:37.152455 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3252> 2013-11-06 06:25:37.152500 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3276] 2013-11-06 06:25:37.285531 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:b76ba936-0a4c-a003-f6ed-f49177323aaf', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:ce1ca201-9996-287a-8d60-2a1f358d0cd1',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3276] 2013-11-06 06:25:37.302203 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3290] 2013-11-06 06:25:37.450732 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:39514e11-9afa-dcba-c3b5-6d640141f500', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:172a342f-dcfa-2104-68fb-bad5b079b654',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3290] 2013-11-06 06:25:37.468925 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.703948 lock: acquired
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.703958 sr_scan {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'DummyRef:|d67b1d33-71dc-1014-0b4f-0fa6a6432585|SR.scan', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:1d495451-1882-ea80-a595-f02be6225b29',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_scan', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3364] 2013-11-06 06:29:17.704122 ['/usr/bin/vhd-util', 'scan', '-f',
'-c', '-m', '/opt/storage/primary/*.vhd']
[3364] 2013-11-06 06:29:17.709129 SUCCESS
[3364] 2013-11-06 06:29:17.709439 ['ls', '/opt/storage/primary', '-1',
'--color=never']
[3364] 2013-11-06 06:29:17.715696 SUCCESS
[3364] 2013-11-06 06:29:17.715984 lock: tried lock
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running, acquired:
True (exists: True)
[3364] 2013-11-06 06:29:17.716026 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3364] 2013-11-06 06:29:17.716079 Kicking GC
<3364> 2013-11-06 06:29:17.716176 === SR
9f3f9262-3f77-09cc-2df7-0d8475676260: gc ===
<3368> 2013-11-06 06:29:17.719049 Will finish as PID [3369]
<3364> 2013-11-06 06:29:17.720496 New PID [3368]
[3364] 2013-11-06 06:29:17.720780 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[3364] 2013-11-06 06:29:17.764394 lock: released
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3364] 2013-11-06 06:29:17.764848 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
<3369> 2013-11-06 06:29:17.805411 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3369> 2013-11-06 06:29:17.805556 ***********************
<3369> 2013-11-06 06:29:17.805620 * E X C E P T I O N *
<3369> 2013-11-06 06:29:17.805679 ***********************
<3369> 2013-11-06 06:29:17.805763 gc: EXCEPTION <type
'exceptions.OSError'>, [Errno 2] No such file or directory:
'/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<3369> 2013-11-06 06:29:17.805823 File "/usr/lib/xcp/sm/cleanup.py",
line 2515, in gc
_gc(None, srUuid, dryRun)
File "/usr/lib/xcp/sm/cleanup.py", line 2415, in _gc
sr.cleanupCache()
File "/usr/lib/xcp/sm/cleanup.py", line 1867, in cleanupCache
cacheFiles = filter(self._isCacheFileName, os.listdir(self.path))
<3369> 2013-11-06 06:29:17.805894 *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<3369> 2013-11-06 06:29:17.805953 * * * * * SR
9f3f9262-3f77-09cc-2df7-0d8475676260: ERROR
[3393] 2013-11-06 06:29:17.933726 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:2979ec4e-9b4d-c367-19d7-82b0dc39a201', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:2b13c4c0-086f-1c73-d58b-e92446d531ee',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3393] 2013-11-06 06:29:17.951477 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[3407] 2013-11-06 06:29:18.112767 sr_update {'sr_uuid':
'9f3f9262-3f77-09cc-2df7-0d8475676260', 'subtask_of':
'OpaqueRef:8d12d6b8-68bf-5777-ed3c-0f8cbed778f7', 'args': [],
'host_ref': 'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c',
'session_ref': 'OpaqueRef:68b606cb-1ec1-1ac7-ce2e-dd4613f2385e',
'device_config': {'SRmaster': 'true', 'location':
'/opt/storage/primary'}, 'command': 'sr_update', 'sr_ref':
'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[3407] 2013-11-06 06:29:18.130718 lock: closed
/var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
I'm not able to figure out ,please guide me further
-Aakash
On Wed, Nov 6, 2013 at 10:22 AM, Jayapal Reddy Uradi <
jayapalreddy.uradi@citrix.com> wrote:
> Hi,
>
> From the logs vmops, setIptables call failed.
> for cmd: setIptables with args due to There was a failure
>
> Can you check the xenserver agent log (SMlog) to know more info
>
> Thanks,
> Jayapal
>
>
> On 06-Nov-2013, at 9:56 AM, Aakash Kumar <ju...@gmail.com>
> wrote:
>
> > Hello ,
> > Following exception occurred on running deployDatacenter.py using
> > devcloud.cfg
> >
> > INFO [c.c.r.ResourceManagerImpl]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Trying to add a new host at http://192.168.56.10/ in data center 1
> > INFO [c.c.h.x.d.XcpServerDiscoverer]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Found host devcloud ip=192.168.56.10 product version=1.6.0
> > INFO [c.c.h.x.r.CitrixResourceBase]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Private Network is Pool-wide network associated with eth0 for host
> > 192.168.56.10
> > INFO [c.c.h.x.r.CitrixResourceBase]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Guest Network is Pool-wide network associated with eth0 for host
> > 192.168.56.10
> > INFO [c.c.h.x.r.CitrixResourceBase]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Public Network is Pool-wide network associated with eth0 for host
> > 192.168.56.10
> > INFO [c.c.h.x.d.XcpServerDiscoverer]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Host: devcloud connected with hypervisor type: XenServer. Checking
> > CIDR...
> > INFO [c.c.a.m.DirectAgentAttache]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > StartupAnswer received 1 Interval = 60
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\ovsgre
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\ipassoc.sh
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getDomRVersion.sh
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getRouterStatus.sh
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\networkUsage.sh
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\l2tp_vpn.sh
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> > cannot locate
> E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\vhd-util
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> > callHostPlugin failed for cmd: setIptables with args due to There was
> > a failure communicating with the plugin.
> > WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> > Unable to setup
> > com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed
> > for cmd: setIptables with args due to There was a failure
> > communicating with the plugin.
> > at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:4293)
> > at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.setIptables(CitrixResourceBase.java:4305)
> > at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:5098)
> > at
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:547)
> > at
> com.cloud.hypervisor.xen.resource.XcpOssResource.executeRequest(XcpOssResource.java:140)
> > at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:187)
> > at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> > at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> > at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> > at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> > at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> > at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> > at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> > at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> > at java.lang.Thread.run(Thread.java:722)
> > WARN [c.c.h.x.d.XcpServerDiscoverer]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Unable to setup agent 1 due to callHostPlugin failed for cmd:
> > setIptables with args due to There was a failure communicating with
> > the plugin.
> > INFO [c.c.u.e.CSExceptionErrorCode]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Could not find exception: com.cloud.exception.ConnectionException in
> > error code list for exceptions
> > WARN [c.c.a.m.AgentManagerImpl]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Monitor XcpServerDiscoverer says there is an error in the connect
> > process for 1 due to Reinitialize agent after setup.
> > INFO [c.c.a.m.AgentManagerImpl]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Host 1 is disconnecting with event AgentDisconnected
> > WARN [c.c.r.ResourceManagerImpl]
> > (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> > Unable to connect due to
> > com.cloud.exception.ConnectionException: Reinitialize agent after setup.
> > at
> com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer.processConnect(XcpServerDiscoverer.java:665)
> > at
> com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:491)
> > at
> com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1398)
> > at
> com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1802)
> > at
> com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> > at
> com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> > at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> > at java.lang.reflect.Method.invoke(Method.java:601)
> > at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> > at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> > at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> > at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> > at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> > at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> > at $Proxy146.discoverHosts(Unknown Source)
> > at
> org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143)
> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> > at com.cloud.api.ApiServer.queueCommand(ApiServer.java:527)
> > at com.cloud.api.ApiServer.handleRequest(ApiServer.java:370)
> > at
> com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:322)
> > at com.cloud.api.ApiServlet.access$000(ApiServlet.java:52)
> > at com.cloud.api.ApiServlet$1.run(ApiServlet.java:114)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> > at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> > at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:111)
> > at com.cloud.api.ApiServlet.doGet(ApiServlet.java:73)
> > at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
> > at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
> > at
> org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
> > at
> org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:401)
> > at
> org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> > at
> org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> > at
> org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> > at
> org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> > at
> org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> > at
> org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> > at
> org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> > at org.mortbay.jetty.Server.handle(Server.java:326)
> > at
> org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> > at
> org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> > at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> > at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> > at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> > at
> org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
> > at
> org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
> > ERROR [c.c.a.ApiServer] (1456585835@qtp-2122825114-0:ctx-2dc342a1
> > ctx-d1559de5 ctx-fae00876) unhandled exception executing api command:
> > addHost
> > com.cloud.utils.exception.CloudRuntimeException: Cannot transit agent
> > status with event AgentDisconnected for host 1, mangement server id is
> > 8871632142068,Unable to transition to a new state from Creating via
> > AgentDisconnected
> > at
> com.cloud.agent.manager.AgentManagerImpl.agentStatusTransitTo(AgentManagerImpl.java:1330)
> > at
> com.cloud.resource.ResourceManagerImpl.markHostAsDisconnected(ResourceManagerImpl.java:1667)
> > at
> com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1828)
> > at
> com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> > at
> com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> > at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> > at java.lang.reflect.Method.invoke(Method.java:601)
> > at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> >
> > at
> >
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> >
> >
> > -Aakash
>
>
Re: Exception Occurred adding host
Posted by Jayapal Reddy Uradi <ja...@citrix.com>.
Hi,
>From the logs vmops, setIptables call failed.
for cmd: setIptables with args due to There was a failure
Can you check the xenserver agent log (SMlog) to know more info
Thanks,
Jayapal
On 06-Nov-2013, at 9:56 AM, Aakash Kumar <ju...@gmail.com>
wrote:
> Hello ,
> Following exception occurred on running deployDatacenter.py using
> devcloud.cfg
>
> INFO [c.c.r.ResourceManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Trying to add a new host at http://192.168.56.10/ in data center 1
> INFO [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Found host devcloud ip=192.168.56.10 product version=1.6.0
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Private Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Guest Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.r.CitrixResourceBase]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Public Network is Pool-wide network associated with eth0 for host
> 192.168.56.10
> INFO [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Host: devcloud connected with hypervisor type: XenServer. Checking
> CIDR...
> INFO [c.c.a.m.DirectAgentAttache]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> StartupAnswer received 1 Interval = 60
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\ovsgre
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\ipassoc.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getDomRVersion.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\getRouterStatus.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\networkUsage.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\..\..\..\network\domr\\l2tp_vpn.sh
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e) We
> cannot locate E:\cloudstack\cloudstackworkspace\cloudstack_4.2\client\target\generated-webapp\WEB-INF\classes\scripts\vm\hypervisor\xenserver\xcposs\..\vhd-util
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> callHostPlugin failed for cmd: setIptables with args due to There was
> a failure communicating with the plugin.
> WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24b06a5e)
> Unable to setup
> com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed
> for cmd: setIptables with args due to There was a failure
> communicating with the plugin.
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:4293)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.setIptables(CitrixResourceBase.java:4305)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:5098)
> at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:547)
> at com.cloud.hypervisor.xen.resource.XcpOssResource.executeRequest(XcpOssResource.java:140)
> at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:187)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> WARN [c.c.h.x.d.XcpServerDiscoverer]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Unable to setup agent 1 due to callHostPlugin failed for cmd:
> setIptables with args due to There was a failure communicating with
> the plugin.
> INFO [c.c.u.e.CSExceptionErrorCode]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Could not find exception: com.cloud.exception.ConnectionException in
> error code list for exceptions
> WARN [c.c.a.m.AgentManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Monitor XcpServerDiscoverer says there is an error in the connect
> process for 1 due to Reinitialize agent after setup.
> INFO [c.c.a.m.AgentManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Host 1 is disconnecting with event AgentDisconnected
> WARN [c.c.r.ResourceManagerImpl]
> (1456585835@qtp-2122825114-0:ctx-2dc342a1 ctx-d1559de5 ctx-fae00876)
> Unable to connect due to
> com.cloud.exception.ConnectionException: Reinitialize agent after setup.
> at com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer.processConnect(XcpServerDiscoverer.java:665)
> at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:491)
> at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1398)
> at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1802)
> at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy146.discoverHosts(Unknown Source)
> at org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at com.cloud.api.ApiServer.queueCommand(ApiServer.java:527)
> at com.cloud.api.ApiServer.handleRequest(ApiServer.java:370)
> at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:322)
> at com.cloud.api.ApiServlet.access$000(ApiServlet.java:52)
> at com.cloud.api.ApiServlet$1.run(ApiServlet.java:114)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:111)
> at com.cloud.api.ApiServlet.doGet(ApiServlet.java:73)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
> at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
> at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:401)
> at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
> at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
> at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
> at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
> at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
> at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
> at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
> at org.mortbay.jetty.Server.handle(Server.java:326)
> at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
> at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
> at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
> at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
> at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
> at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
> at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
> ERROR [c.c.a.ApiServer] (1456585835@qtp-2122825114-0:ctx-2dc342a1
> ctx-d1559de5 ctx-fae00876) unhandled exception executing api command:
> addHost
> com.cloud.utils.exception.CloudRuntimeException: Cannot transit agent
> status with event AgentDisconnected for host 1, mangement server id is
> 8871632142068,Unable to transition to a new state from Creating via
> AgentDisconnected
> at com.cloud.agent.manager.AgentManagerImpl.agentStatusTransitTo(AgentManagerImpl.java:1330)
> at com.cloud.resource.ResourceManagerImpl.markHostAsDisconnected(ResourceManagerImpl.java:1667)
> at com.cloud.resource.ResourceManagerImpl.createHostAndAgentDeferred(ResourceManagerImpl.java:1828)
> at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:760)
> at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:575)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
>
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
>
>
> -Aakash