Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Ubuntu 14.04: cd eject not working #603

Open
scpcom opened this issue Jan 19, 2015 · 2 comments
Open

Ubuntu 14.04: cd eject not working #603

scpcom opened this issue Jan 19, 2015 · 2 comments
Labels
deb

Comments

@scpcom
Copy link

scpcom commented Jan 19, 2015

I built and installed xenserver-core with buildroot 9cbc74f on Ubuntu 14.04 amd64.
Then did a simple test setup: LVM Local Storage, NFS ISO Storage, Windows 7 VM (one 64 bit, one 32 bit), separate Windows 7 Client with XenCenter.
Install went fine but while using I found some issues:
Attaching a cd always works but If I try to eject it while vm is running I get errors like this:

Jan 19 21:42:40 us-xenasr stunnel: LOG5[2858:140410270922496]: Service [xapi] accepted connection from 192.168.2.2:49531
Jan 19 21:42:40 us-xenasr stunnel: LOG5[2858:140410270922496]: connect_blocking: connected 127.0.0.1:80
Jan 19 21:42:40 us-xenasr stunnel: LOG5[2858:140410270922496]: Service [xapi] connected remote server from 127.0.0.1:57583
Jan 19 21:42:40 us-xenasr xapi: message repeated 864 times: [ [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping]
Jan 19 21:42:40 us-xenasr xapi: [ info|us-xenasr|696|Async.VBD.eject R:5ddd3d2fbdcf|dispatcher] spawning a new thread to handle the current task (trackid=5f4732ca8e6286f83e47d5b8167f5d09)
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|696|Async.VBD.eject R:5ddd3d2fbdcf|audit] VBD.eject: VBD = 'eed22bb3-076b-7e53-29ce-a8cad5ad0d51'
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|83|Async.VBD.eject R:5ddd3d2fbdcf|xenops_server] VM.stat b65f2b2a-9037-18a4-4a30-33760c7f55ad
Jan 19 21:42:40 us-xenasr xapi: message repeated 2 times: [ [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping]
Jan 19 21:42:40 us-xenasr xapi: [ info|us-xenasr|696|Async.VBD.eject R:5ddd3d2fbdcf|xenops] xenops: VBD.eject b65f2b2a-9037-18a4-4a30-33760c7f55ad.xvdd
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|84|queue|xenops_server] Queue.push ["Atomic", ["VBD_eject", ["b65f2b2a-9037-18a4-4a30-33760c7f55ad", "xvdd"]]] onto b65f2b2a-9037-18a4-4a30-33760c7f55ad:[  ]
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15||xenops_server] Queue.pop returned ["Atomic", ["VBD_eject", ["b65f2b2a-9037-18a4-4a30-33760c7f55ad", "xvdd"]]]
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|xenops_server] Task 20 reference Async.VBD.eject R:5ddd3d2fbdcf: ["Atomic", ["VBD_eject", ["b65f2b2a-9037-18a4-4a30-33760c7f55ad", "xvdd"]]]
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|xenops_server] VBD.eject b65f2b2a-9037-18a4-4a30-33760c7f55ad.xvdd
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|10||scheduler] Scheduler sleep until 1421700184 (another 23 seconds)
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|xenops] Calling Xenlight.Device_disk.insert
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl.c:2463:libxl_cdrom_insert: ao 0x7fa86c0024b0: create: how=(nil) callback=(nil) poller=0x7fa87c043550
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=xvdd spec.backend=phy
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_device.c:189:disk_try_backend: Disk vdev=xvdd, uses script=... assuming phy backend
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-1
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:296:qmp_handle_response: message type: qmp
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{#012    "execute": "qmp_capabilities",#012    "id": 1#012}#012'
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:296:qmp_handle_response: message type: return
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{#012    "execute": "eject",#012    "id": 2,#012    "arguments": {#012        "device": "ide-51760"#012    }#012}#012'
Jan 19 21:42:40 us-xenasr xapi: message repeated 2 times: [ [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping]
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|695 INET :::80|dispatch:task.add_to_other_config D:4f3efdf63e7e|api_effect] task.add_to_other_config
Jan 19 21:42:40 us-xenasr xapi: [20150119T20:42:40.634Z|audit|us-xenasr|695 INET :::80|task.add_to_other_config D:27f984fe9ed9|audit] ('trackid=5f4732ca8e6286f83e47d5b8167f5d09' 'LOCAL_SUPERUSER' 'root' 'ALLOWED' 'OK' 'API' 'task.add_to_other_config' (('self' 'Async.VBD.eject' 'afb853a5-9bde-1eec-ecfe-26b70a7eaea0' 'OpaqueRef:5ddd3d2f-bdcf-da63-f8fe-f37964d8550c')))
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:296:qmp_handle_response: message type: event
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_qmp.c:296:qmp_handle_response: message type: return
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_event.c:1591:libxl__ao_complete: ao 0x7fa86c0024b0: complete, rc=0
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|7||xenops] Watch on backend domid: 0 kind: vbd -> frontend domid: 1 devid: 51760
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|3|events|xenops_server] Received an event on managed VBD b65f2b2a-9037-18a4-4a30-33760c7f55ad.xvdd
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|3|queue|xenops_server] Queue.push ["VBD_check_state", ["b65f2b2a-9037-18a4-4a30-33760c7f55ad", "xvdd"]] onto redirected b65f2b2a-9037-18a4-4a30-33760c7f55ad:[  ]
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl.c:2569:libxl_cdrom_insert: ao 0x7fa86c0024b0: inprogress: poller=0x7fa87c043550, flags=ic
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|libxl] libxl: libxl_event.c:1563:libxl__ao__destroy: ao 0x7fa86c0024b0: destroy
Jan 19 21:42:40 us-xenasr xenopsd-xenlight: [debug|us-xenasr|15|Async.VBD.eject R:5ddd3d2fbdcf|xenops] xenstore-rm /local/domain/0/backend/vbd/1/51760/vdi
Jan 19 21:42:40 us-xenasr xapi: message repeated 8 times: [ [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping]
Jan 19 21:42:40 us-xenasr xapi: [ info|us-xenasr|697||storage_impl] DP.destroy dbg:dp_destroy dp:vbd/b65f2b2a-9037-18a4-4a30-33760c7f55ad/xvdd allow_leak:false
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|698||dummytaskhelper] task VDI.deactivate D:1c1f0530aef5 created by task dp_destroy
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|698|VDI.deactivate D:1c1f0530aef5|dummytaskhelper] task VDI.deactivate D:ca427d9146f7 created by task dp_destroy
Jan 19 21:42:40 us-xenasr xapi: [ info|us-xenasr|698|VDI.deactivate D:1c1f0530aef5|storage_access] vbd/b65f2b2a-9037-18a4-4a30-33760c7f55ad/xvdd sr:OpaqueRef:a5248086-4464-cf87-a9dc-4a1862d4bb2e does not support vdi_deactivate: doing nothing
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|695 INET :::80|dispatch:task.add_to_other_config D:47d0456ce6ed|api_effect] task.add_to_other_config
Jan 19 21:42:40 us-xenasr xapi: [20150119T20:42:40.674Z|audit|us-xenasr|695 INET :::80|task.add_to_other_config D:9226d2fa64aa|audit] ('trackid=5f4732ca8e6286f83e47d5b8167f5d09' 'LOCAL_SUPERUSER' 'root' 'ALLOWED' 'OK' 'API' 'task.add_to_other_config' (('self' 'Async.VBD.eject' 'afb853a5-9bde-1eec-ecfe-26b70a7eaea0' 'OpaqueRef:5ddd3d2f-bdcf-da63-f8fe-f37964d8550c') ('value' '' '' 'OpaqueRef:3ba59b8f-d150-447b-09b1-d0585cbfafb3,OpaqueRef:3ba59b8f-d150-447b-09b1-d0585cbfafb3,OpaqueRef:6003aea2-6f45-d263-a776-386518509760,OpaqueRef:3ba59b8f-d150-447b-09b1-d0585cbfafb3,OpaqueRef:6003aea2-6f45-d263-a776-386518509760,OpaqueRef:e51f8de7-cf3e-ca25-fe44-def56949bdd8')))
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|697||storage_impl] dbg:dp_destroy dp:vbd/b65f2b2a-9037-18a4-4a30-33760c7f55ad/xvdd sr:94341a79-e4a5-d4fd-22f8-b2f9863d1181 vdi:Win7aio-201408.iso superstate:attached  RO
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|699||dummytaskhelper] task VDI.detach D:fbabdfd90ef6 created by task dp_destroy
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|699|VDI.detach D:fbabdfd90ef6|sm] SM iso vdi_detach sr=OpaqueRef:a5248086-4464-cf87-a9dc-4a1862d4bb2e vdi=OpaqueRef:c159e5b9-6d7f-98c1-f8d3-7e9369bde6c6
Jan 19 21:42:40 us-xenasr xapi: [ info|us-xenasr|699|sm_exec D:108c11352805|xapi] Session.create trackid=628474a5564545c368940cc6337157e8 pool=false uname= originator= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|699|sm_exec D:108c11352805|mscgen] xapi=>xapi [label="session.get_uuid"];
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|700 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid D:b929c1e30df6 created by task D:108c11352805
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|699|sm_exec D:108c11352805|mscgen] smapiv2=>smapiv1 [label="vdi_detach"];
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr xapi: message repeated 19 times: [ [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping]
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|701 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:host.get_other_config D:f943209fcc78 created by task D:fbabdfd90ef6
Jan 19 21:42:40 us-xenasr SM: [29021] vdi_detach {'sr_uuid': '94341a79-e4a5-d4fd-22f8-b2f9863d1181', 'subtask_of': 'DummyRef:|fbabdfd9-0ef6-53ad-d874-85c5b182b2ca|VDI.detach', 'vdi_ref': 'OpaqueRef:c159e5b9-6d7f-98c1-f8d3-7e9369bde6c6', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': 'Win7aio-201408.iso', 'host_ref': 'OpaqueRef:6003aea2-6f45-d263-a776-386518509760', 'session_ref': 'OpaqueRef:e2995390-a148-acfe-b6fb-4d779327ff91', 'device_config': {'type': 'nfs_iso', 'SRmaster': 'true', 'location': '192.168.2.234:/nfs/data/WinOSISOs'}, 'command': 'vdi_detach', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:a5248086-4464-cf87-a9dc-4a1862d4bb2e', 'vdi_uuid': 'cb51c1b3-2a11-4391-9f21-f1324ad9100c'}
Jan 19 21:42:40 us-xenasr SM: [29021] lock: opening lock file /var/lock/sm/cb51c1b3-2a11-4391-9f21-f1324ad9100c/vdi
Jan 19 21:42:40 us-xenasr SM: [29021] Deactivate & detach
Jan 19 21:42:40 us-xenasr xapi: [debug|us-xenasr|134||xapi_stats] rrdd says next reading is overdue by inf seconds; not sleeping
Jan 19 21:42:40 us-xenasr SM: [29021] ['/usr/lib/blktap/sbin/tap-ctl', 'close', '-p', '12164', '-m', '1']
Jan 19 21:42:40 us-xenasr tapdisk[12164]: received 'close' message (uuid = 1)
Jan 19 21:42:40 us-xenasr tapdisk[12164]: nbd: NBD server pause(0xf28020)
Jan 19 21:42:40 us-xenasr tapdisk[12164]: tap-err:tapdisk_control_close_image: device aio:/var/run/sr-mount/94341a79-e4a5-d4fd-22f8-b2f9863d1181/Win7aio-201408.iso still open

The task is stuck then and you can not control the VM anymore from outside, even force shutdown does not work.
Inside the VM you still can work normally.
@scpcom
Copy link
Author

scpcom commented Jan 24, 2015

Used current buildroot d239153 and ejecting works now.

@scpcom scpcom closed this as completed Jan 24, 2015
@scpcom
Copy link
Author

scpcom commented Jan 25, 2015

I was false. Sometimes ejecting works, but hanging eject tasks still happen.

@scpcom scpcom reopened this Jan 25, 2015
@euanh euanh added the deb label Apr 23, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
deb
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@euanh @scpcom