cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Thomas O'Dowd (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-3229) Object_Store_Refactor - Snapshot fails due to an internal error
Date Fri, 16 Aug 2013 00:29:52 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-3229?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13741716#comment-13741716
] 

Thomas O'Dowd commented on CLOUDSTACK-3229:
-------------------------------------------

Hi Min,

I don't see a VMOPs exit deleteSnapshotBackup line in my SMlog at all.

Here is a bigger chunk of the file:

[28048] 2013-08-15 08:02:32.786841      #### VMOPS enter  deleteSnapshotBackup ####
[28048] 2013-08-15 08:02:32.786931      Calling deleteSnapshotBackup with {'localMountPoint':
'/var/run/cloud_mount/49ab0a32-3113-3ee2-bb24-3e65acb96ce9', 'backupUUID': 'eff7d9fd-2690-4dc2-b212-389b46b009e6',
'secondaryStorageMountPath': '192.168.56.10:/opt/storage/cache/', 'path': 'snapshots/2/3'}
[28055] 2013-08-15 08:02:32.924172      lock: acquired /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/sr
[28055] 2013-08-15 08:02:32.924277      sr_detach {'sr_uuid': 'd3056da5-257b-daee-a6b9-ec06e386f12b',
'subtask_of': 'DummyRef:|acb005fe-df7e-8640-4202-8d29e34ddb39|SR.detach', 'args': [], 'host_ref':
'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:c5af76bc-99a5-46d4-debd-c6292edc4040',
'device_config': {'SRmaster': 'true', 'serverpath': '/opt/storage/cache/snapshots/2/3', 'server':
'192.168.56.10'}, 'command': 'sr_detach', 'sr_ref': 'OpaqueRef:bba51bd6-2abc-46f0-9053-816e6d50e8f1'}
[28055] 2013-08-15 08:02:32.924543      Aborting GC/coalesce
<28055> 2013-08-15 08:02:32.924604      === SR d3056da5-257b-daee-a6b9-ec06e386f12b:
abort ===
[28055] 2013-08-15 08:02:32.924713      lock: tried lock /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/running,
acquired: True (exists: True)
<28055> 2013-08-15 08:02:32.924758      abort: releasing the process lock
[28055] 2013-08-15 08:02:32.924816      lock: released /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/running
[28055] 2013-08-15 08:02:32.924880      ['umount', '/var/run/sr-mount/d3056da5-257b-daee-a6b9-ec06e386f12b']
[28055] 2013-08-15 08:02:32.935278      SUCCESS
[28055] 2013-08-15 08:02:32.935517      lock: released /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/sr
[28055] 2013-08-15 08:02:32.935896      lock: closed /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/sr
[28055] 2013-08-15 08:02:32.939484      lock: closed /var/lock/sm/d3056da5-257b-daee-a6b9-ec06e386f12b/running
[28068] 2013-08-15 08:02:43.413216      lock: acquired /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[28068] 2013-08-15 08:02:43.413336      sr_scan {'sr_uuid': '9f3f9262-3f77-09cc-2df7-0d8475676260',
'subtask_of': 'DummyRef:|6a514ab5-313a-8269-6731-feb43e19a222|SR.scan', 'args': [], 'host_ref':
'OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c', 'session_ref': 'OpaqueRef:a17247e3-9968-d0aa-c508-974a7df4c77f',
'device_config': {'SRmaster': 'true', 'location': '/opt/storage/primary'}, 'command': 'sr_scan',
'sr_ref': 'OpaqueRef:75f9feeb-8309-b7b7-8455-9a1021a3baa4'}
[28068] 2013-08-15 08:02:43.413482      ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/opt/storage/primary/*.vhd']
[28068] 2013-08-15 08:02:43.433203      SUCCESS
[28068] 2013-08-15 08:02:43.442297      ['ls', '/opt/storage/primary', '-1', '--color=never']
[28068] 2013-08-15 08:02:43.448646      SUCCESS
[28068] 2013-08-15 08:02:43.449105      Scan found hidden leaf (36708802-17a9-4f35-90c6-b199d752c753),
ignoring
[28068] 2013-08-15 08:02:43.449185      Scan found hidden leaf (bb43ddcb-517d-41aa-ad80-49c05b4b92df),
ignoring
[28068] 2013-08-15 08:02:43.449240      Scan found hidden leaf (925f411c-c6dc-42b5-b2f2-95282bb61422),
ignoring
[28068] 2013-08-15 08:02:43.449291      Scan found hidden leaf (1a61e080-c99c-4b03-8bb3-f0f9cee855f0),
ignoring
[28068] 2013-08-15 08:02:43.449345      Scan found hidden leaf (111f7a34-eee5-4415-8690-7408b293704a),
ignoring
[28068] 2013-08-15 08:02:43.449392      Scan found hidden leaf (73e00559-5004-463b-9a16-b5f8e8fedf05),
ignoring
[28068] 2013-08-15 08:02:43.449439      Scan found hidden leaf (66492c77-a43a-443f-9dff-de1f2445c9bb),
ignoring
[28068] 2013-08-15 08:02:43.449488      Scan found hidden leaf (ff54b6f9-d644-4fcf-a095-124309100b66),
ignoring
[28068] 2013-08-15 08:02:43.449540      Scan found hidden leaf (f6da5f3f-5ed5-4977-a897-4933ae421e6b),
ignoring
[28068] 2013-08-15 08:02:43.449598      Scan found hidden leaf (96691965-efdd-4d03-a386-0e44c4b63b06),
ignoring
[28068] 2013-08-15 08:02:43.449648      Scan found hidden leaf (4bb4316d-efe3-418a-8ca0-22d63579a3b6),
ignoring
[28068] 2013-08-15 08:02:43.449699      Scan found hidden leaf (c10443c5-5887-40b5-afdd-5a237c80124c),
ignoring
[28068] 2013-08-15 08:02:43.449751      Scan found hidden leaf (bb348e40-c1b5-4bbe-864e-66aab1e4c05c),
ignoring
[28068] 2013-08-15 08:02:43.450093      lock: tried lock /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running,
acquired: True (exists: True)
[28068] 2013-08-15 08:02:43.450166      lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
[28068] 2013-08-15 08:02:43.450210      Kicking GC
<28068> 2013-08-15 08:02:43.450280      === SR 9f3f9262-3f77-09cc-2df7-0d8475676260:
gc ===
<28072> 2013-08-15 08:02:43.453476      Will finish as PID [28073]
<28068> 2013-08-15 08:02:43.454127      New PID [28072]
[28068] 2013-08-15 08:02:43.454455      lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/running
<28073> 2013-08-15 08:02:43.529110      *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<28073> 2013-08-15 08:02:43.529225               ***********************
<28073> 2013-08-15 08:02:43.529273               *  E X C E P T I O N  *
<28073> 2013-08-15 08:02:43.529319               ***********************
<28073> 2013-08-15 08:02:43.529395      gc: EXCEPTION <type 'exceptions.OSError'>,
[Errno 2] No such file or directory: '/var/run/sr-mount/9f3f9262-3f77-09cc-2df7-0d8475676260'
<28073> 2013-08-15 08:02:43.529442        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))

<28073> 2013-08-15 08:02:43.529489      *~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*~*
<28073> 2013-08-15 08:02:43.529536      * * * * * SR 9f3f9262-3f77-09cc-2df7-0d8475676260:
ERROR

[28068] 2013-08-15 08:02:43.554741      lock: released /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[28068] 2013-08-15 08:02:43.557226      lock: closed /var/lock/sm/9f3f9262-3f77-09cc-2df7-0d8475676260/sr
[28106] 2013-08-15 08:03:19.472907      #### VMOPS enter  gethostvmstats ####
[28106] 2013-08-15 08:03:19.477241      #### VMOPS exit  gethostvmstats ####
[28115] 2013-08-15 08:03:25.396622      #### VMOPS enter  gethostvmstats ####
[28115] 2013-08-15 08:03:25.401232      #### VMOPS exit  gethostvmstats ####

I tried searching around for other instances of the PID 28048 after the top two lines but
I don't see any. I notice that your log output has more lines for the same PID. Mine does
not have that. Is there perhaps some other tool (like s3xen) that I am missing from my devcloud
install?

Thanks,

Tom.
                
> Object_Store_Refactor - Snapshot fails due to an internal error
> ---------------------------------------------------------------
>
>                 Key: CLOUDSTACK-3229
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3229
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>    Affects Versions: 4.2.0
>         Environment: chrome on linux 
> devcloud 
> Cloudian or Amazon S3 Object store
>            Reporter: Thomas O'Dowd
>            Assignee: Min Chen
>            Priority: Blocker
>             Fix For: 4.2.0
>
>         Attachments: SMlog, SMlog.last_5000_lines.txt
>
>
> Assuming initial devcloud state... 
> I added a cache for the S3 storage like this. 
> on devcloud machine as root: 
> # mkdir /opt/storage/cache 
> # vi /etc/exports (and append this line) 
> /opt/storage/cache *(rw,no_subtree_check,no_root_squash,fsid=9999) 
> # exportfs -a 
> On Mgmt server GUI: 
> 1. navigate to infrastructure -> secondary storage 
> 2. delete the NFS SS. 
> 3. add S3 storage for Cloudian (I used 60000 as the timeouts - assuming millis). I used
the /opt/storage/cache thing as the s3 cache.
> 4. nav to templates 
> 5. register a new template (I uploaded tinyLinux again as "mytiny" (5.3 64bit)). 
> 6. confirm with s3cmd that 2 objects are now on S3. 
> --------- s3 objects ------- 
> template/tmpl/1/1/routing-1/acton-systemvm-02062012.vhd.bz2 2013-06-27T03:01:46.203Z
None 140616708 "b533e7b65219439ee7fca0146ddd7ffa-27" 
> template/tmpl/2/201/201-2-ae9e9409-4c8e-3ad8-a62f-abec7a35fe26/tinylinux.vhd 2013-06-27T03:04:06.730Z
None 50430464 "4afac316e865adf74ca1a8039fae7399-10" 
> --------- s3 objects ------- 
> 7. I restarted the management server at this point which actually resulted in another
object on S3. 
> --------- the new s3 object ------- 
> template/tmpl/1/5/tiny Linux/ttylinux_pv.vhd 2013-06-27T03:43:26.494Z None 50430464 "4afac316e865adf74ca1a8039fae7399-10"

> --------- the new s3 object ------- 
> 8. Go to instance and create a new choosing the "mytiny" template which we registered.

> 9. launch it after selecting all defaults. 
> 10. wait until it starts.
> 11. nav to storage. I see ROOT-8. Click on this to open.
> 12. click the camera to take the snapshot.
> after a pause I get a popup
>      "Failed to create snapshot due to an internal error creating snapshot for volume
8"
> Also on the mgmt terminal I get the following log entry (only 1):
>     INFO  [user.snapshot.CreateSnapshotCmd] (Job-Executor-8:job-16) VOLSS: createSnapshotCmd
starts:1372321251009
> If I check the "view snapshots" button under storage, I can however see the snapshot.
It says its on primary. I'm expecting it to go to secondary storage though. Nothing is in
the S3 logs and no snapshots.
> If I try to delete that snapshot from here I get this error in the logs:
> ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-12:job-20) Unexpected exception
while executing org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd
> com.cloud.utils.exception.CloudRuntimeException: Failed to delete snapshot:com.cloud.exception.InvalidParameterValueException:
Can't delete snapshotshot 4 due to it is not in BackedUp Status
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.deleteSnapshot(SnapshotManagerImpl.java:513)
>         at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>         at org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd.execute(DeleteSnapshotCmd.java:96)
>         at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
>         at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
>         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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:722)
> If I navigate to instance, my instance, and try to take a vm snapshot from here, I get
a different pop-up which says:
>    "There is other active volume snapshot tasks on the instance to which the volume is
attached, please try again later"
> And I get an exception:
> ERROR [cloud.api.ApiServer] (352129314@qtp-2110413789-32:) unhandled exception executing
api command: createVMSnapshot
> com.cloud.utils.exception.CloudRuntimeException: There is other active volume snapshot
tasks on the instance to which the volume is attached, please try again later.
>         at com.cloud.vm.snapshot.VMSnapshotManagerImpl.allocVMSnapshot(VMSnapshotManagerImpl.java:299)
>         at org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd.create(CreateVMSnapshotCmd.java:78)
>         at com.cloud.api.ApiDispatcher.dispatchCreateCmd(ApiDispatcher.java:101)
>         at com.cloud.api.ApiServer.queueCommand(ApiServer.java:475)
>         at com.cloud.api.ApiServer.handleRequest(ApiServer.java:371)
>         at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:304)
>         at com.cloud.api.ApiServlet.doGet(ApiServlet.java:66)
>         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)
> There are no requests going to the S3 storage for the snap-shotting that I can see and
its the only secondary storage that I have setup.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message