Bug 819911 - [gnome-boxes] Failed to create volume: Requested operation is not valid: storage pool is not active
Summary: [gnome-boxes] Failed to create volume: Requested operation is not valid: stor...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: gnome-boxes
Version: 18
Hardware: Unspecified
OS: Unspecified
unspecified
urgent
Target Milestone: ---
Assignee: Christophe Fergeau
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-05-08 15:29 UTC by Martin
Modified: 2014-09-15 00:03 UTC (History)
8 users (show)

Fixed In Version: 3.6.2
Clone Of:
Environment:
Last Closed: 2013-06-10 18:31:55 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
backtrace g_hash_table_size (13.46 KB, text/plain)
2012-05-09 11:28 UTC, Martin
no flags Details
backtrace g_hash_table_lookup (1.94 KB, text/plain)
2012-05-09 11:44 UTC, Martin
no flags Details
backtrace g_hash_table_remove_internal (6.24 KB, text/plain)
2012-05-09 11:45 UTC, Martin
no flags Details
backtrace on G_LOG_LEVEL_WARNING (17.88 KB, text/plain)
2012-05-09 13:12 UTC, Martin
no flags Details


Links
System ID Private Priority Status Summary Last Updated
GNOME Bugzilla 676340 0 None None None Never

Description Martin 2012-05-08 15:29:01 UTC
Description of problem:
"Box creation failed" error with message "(gnome-boxes:3233): Boxes-WARNING **: wizard.vala:154: Failed to create volume: Requested operation is not valid: storage pool is not active" in console.

Version-Release number of selected component (if applicable):
gnome-boxes-3.4.1-1.fc17.x86_64

How reproducible:
randomly

Steps to Reproduce:
1. Create new box in Gnome Boxes.
  
Actual results:
"Box creation failed" appears.

Expected results:
New box is created and booted.

Console log:

(gnome-boxes:3233): Clutter-WARNING **: No listener with the specified listener id 32

(gnome-boxes:3233): GLib-CRITICAL **: g_hash_table_remove_internal: assertion `hash_table != NULL' failed

(gnome-boxes:3233): Clutter-WARNING **: Not able to remove listener with id 1

(gnome-boxes:3233): GLib-CRITICAL **: g_hash_table_size: assertion `hash_table != NULL' failed

(gnome-boxes:3233): Clutter-WARNING **: The actor 'ClutterBox' is currently inside an allocation cycle; calling clutter_actor_queue_relayout() is not recommended

(gnome-boxes:3233): Boxes-WARNING **: app.vala:183: Unable to refresh storage pool: Requested operation is not valid: storage pool is not active

(gnome-boxes:3233): GLib-CRITICAL **: g_hash_table_lookup: assertion `hash_table != NULL' failed

(gnome-boxes:3233): Boxes-WARNING **: wizard.vala:154: Failed to create volume: Requested operation is not valid: storage pool is not active

Comment 1 Zeeshan Ali 2012-05-08 16:30:26 UTC
(In reply to comment #0)
> Description of problem:
> "Box creation failed" error with message "(gnome-boxes:3233): Boxes-WARNING **:
> wizard.vala:154: Failed to create volume: Requested operation is not valid:
> storage pool is not active" in console.
> 
> Version-Release number of selected component (if applicable):
> gnome-boxes-3.4.1-1.fc17.x86_64
> 
> How reproducible:
> randomly
> 
> Steps to Reproduce:
> 1. Create new box in Gnome Boxes.
> 
> Actual results:
> "Box creation failed" appears.
> 
> Expected results:
> New box is created and booted.
> 
> Console log:
> 
> (gnome-boxes:3233): Clutter-WARNING **: No listener with the specified listener
> id 32
> 
> (gnome-boxes:3233): GLib-CRITICAL **: g_hash_table_remove_internal: assertion
> `hash_table != NULL' failed

These hash_table assertions failing are the first sign of trouble so could you check where we are getting these from (a backtrace for each such critical). My first suspicion would be a libvirt-glib bug as storage pools and volumes are kept in hashtables in there..

Comment 2 Christophe Fergeau 2012-05-09 07:31:00 UTC
virsh -c qemu:///session pool-list --all
and
virsh -c qemu:///session pool-dumpxml gnome-boxes
may be helpful too.

Comment 3 Martin 2012-05-09 10:40:12 UTC
virsh -c qemu:///session pool-list --all
Name                 State      Autostart 
-----------------------------------------
gnome-boxes          inactive   no        

virsh -c qemu:///session pool-dumpxml gnome-boxes
<pool type='dir'>
  <name>gnome-boxes</name>
  <uuid>6a994159-0be4-17e0-d2b6-197f7475f1b1</uuid>
  <capacity unit='bytes'>0</capacity>
  <allocation unit='bytes'>0</allocation>
  <available unit='bytes'>0</available>
  <source>
  </source>
  <target>
    <path>/home/mholec/.local/share/gnome-boxes/images</path>
    <permissions>
      <mode>0744</mode>
      <owner>1000</owner>
      <group>1000</group>
    </permissions>
  </target>
</pool>

Comment 4 Martin 2012-05-09 11:28:55 UTC
Created attachment 583227 [details]
backtrace g_hash_table_size

Attached backtrace.

Comment 5 Martin 2012-05-09 11:44:25 UTC
Created attachment 583231 [details]
backtrace g_hash_table_lookup

Comment 6 Martin 2012-05-09 11:45:22 UTC
Created attachment 583232 [details]
backtrace g_hash_table_remove_internal

Comment 7 Martin 2012-05-09 13:12:33 UTC
Created attachment 583275 [details]
backtrace on G_LOG_LEVEL_WARNING

redo the backtraces using 'break g_log if log_level <= G_LOG_LEVEL_WARNING'

Comment 8 Zeeshan Ali 2012-05-10 01:00:55 UTC
Based on the information so far and our IRC conversation, it seems that we fail to activate the storage pool after creation but don't get error from the 'start' call. Sorry to keep asking you for more and more information but could you provide your libvirt log (~/.libvirt/libvirtd.log)? Its possible that libvirt fails to activate the pool but doesn't error out.

Comment 9 Christophe Fergeau 2012-05-10 09:13:43 UTC
After the "rm -rf .local/share/gnome-boxes/ .cache/gnome-boxes/ .config/gnome-boxes/" suggested by Martin

Breakpoint 1, g_log (log_domain=log_domain@entry=0x4573ee "Boxes", 
    log_level=log_level@entry=G_LOG_LEVEL_WARNING, format=format@entry=
    0x457163 "app.vala:183: %s") at gmessages.c:788
788	{
(gdb) bt
#0  g_log (log_domain=log_domain@entry=0x4573ee "Boxes", 
    log_level=log_level@entry=G_LOG_LEVEL_WARNING, format=format@entry=
    0x457163 "app.vala:183: %s") at gmessages.c:788
#1  0x000000000041c904 in boxes_app_setup_libvirt_co (_data_=0x2b2c070)
    at app.c:1539
#2  0x000000359346ce47 in g_simple_async_result_complete (simple=
    0x2a86b40 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#3  0x000000359346cec8 in complete_in_idle_cb_for_thread (_data=0x2bd1590)
    at gsimpleasyncresult.c:835
#4  0x00000035918475cc in g_main_dispatch (context=0x6d9670) at gmain.c:2515
#5  g_main_context_dispatch (context=context@entry=0x6d9670) at gmain.c:3052
#6  0x00000035918479e8 in g_main_context_iterate (context=context@entry=
    0x6d9670, block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<error reading variable: Unhandled dwarf expression opcode 0xfa>)
    at gmain.c:3123
#7  0x0000003591847aa4 in g_main_context_iteration (context=0x6d9670, 
    context@entry=0x0, may_block=may_block@entry=1) at gmain.c:3184
#8  0x0000003593497cfc in g_application_run (application=
    0x148f760 [GtkApplication], argc=argc@entry=0, argv=argv@entry=0x0)
    at gapplication.c:1496
#9  0x000000000041c576 in boxes_app_run (self=<optimized out>) at app.c:1190
#10 0x0000000000438320 in _vala_main (args=0x7fffffffdff8, args_length1=1)
    at main.c:675
---Type <return> to continue, or q <return> to quit---
#11 0x000000358f821735 in __libc_start_main (main=0x41b630 <main>, argc=1, 
    ubp_av=0x7fffffffdff8, init=<optimized out>, fini=<optimized out>, 
    rtld_fini=<optimized out>, stack_end=0x7fffffffdfe8) at libc-start.c:226
#12 0x000000000041b679 in _start ()
(gdb) c
Continuing.

(gnome-boxes:5546): Boxes-WARNING **: app.vala:183: Unable to refresh storage pool: Requested operation is not valid: storage pool is not active
[Thread 0x7fffe77fe700 (LWP 5577) exited]

so boxes_app_setup_libvirt_co returns with an error. With a few printf I've confirmed that it's yield pool.refresh_async (null); that is returning with an error.
It never goes through VmConfigurator::get_pool_config, dunno if that's intentional.

App::setup_libvirt is called through

#0  boxes_app_setup_libvirt (self=0x70a480, source=0x2a44cc0, 
    _callback_=0x41e337 <boxes_app_add_collection_source_ready>, 
    _user_data_=0x147f580) at app.c:1318
#1  0x000000000041e53e in boxes_app_add_collection_source_co (_data_=0x147f580)
    at app.c:1696
#2  0x000000000041e300 in boxes_app_add_collection_source (self=0x70a480, 
    source=0x2a44cc0, _callback_=0x41e8b9 <boxes_app_setup_sources_ready>, 
    _user_data_=0x15fcd60) at app.c:1639
#3  0x000000000041eddd in boxes_app_setup_sources_co (_data_=0x15fcd60)
    at app.c:1852
#4  0x000000000041e875 in boxes_app_setup_sources (self=0x70a480, 
    _callback_=0x41c03b <___lambda124__gasync_ready_callback>, 
    _user_data_=0x70a480) at app.c:1757
#5  0x000000000041c34e in __lambda115_ (self=0x70a480, app=0x147e720)
    at app.c:1054
#6  0x000000000041c3c7 in ___lambda115__g_application_startup (
    _sender=0x147e720, self=0x70a480) at app.c:1063
#7  0x00007ffff2d6d304 in g_cclosure_marshal_VOID__VOID (closure=0x15702c0, 
    return_value=0x0, n_param_values=1, param_values=0x7fffffffd030, 
    invocation_hint=0x7fffffffcf60, marshal_data=0x0) at gmarshal.c:85
#8  0x00007ffff2d6a280 in g_closure_invoke (closure=0x15702c0, 
    return_value=0x0, n_param_values=1, param_values=0x7fffffffd030, 
    invocation_hint=0x7fffffffcf60) at gclosure.c:777
#9  0x00007ffff2d87cc1 in signal_emit_unlocked_R (node=0x1564de0, detail=0, 
    instance=0x147e720, emission_return=0x0, 
    instance_and_params=0x7fffffffd030) at gsignal.c:3617
#10 0x00007ffff2d86c6c in g_signal_emit_valist (instance=0x147e720, 
    signal_id=151, detail=0, var_args=0x7fffffffd2e8) at gsignal.c:3296
#11 0x00007ffff2d871b4 in g_signal_emit (instance=0x147e720, signal_id=151, 
    detail=0) at gsignal.c:3352
#12 0x00007ffff326d756 in g_application_register (application=0x147e720, 
    cancellable=0x0, error=0x7fffffffd450) at gapplication.c:1273
#13 0x00007ffff326be15 in g_application_real_local_command_line (
    application=0x147e720, arguments=0x7fffffffd4c0, 
    exit_status=0x7fffffffd4bc) at gapplication.c:443
#14 0x00007ffff326dcfd in g_application_run (application=0x147e720, argc=0, 
    argv=0x0) at gapplication.c:1521
#15 0x000000000041ca44 in boxes_app_run (self=0x70a480) at app.c:1189
#16 0x000000000044f568 in _vala_main (args=0x7fffffffd718, args_length1=1)
    at main.c:675
#17 0x000000000044f5d2 in main (argc=1, argv=0x7fffffffd718) at main.c:686


Things are all good after a "virsh pool-undefine gnome-boxes"

Comment 10 Zeeshan Ali 2013-05-24 12:59:57 UTC
This was fixed in 3.7.2.

Comment 11 Zeeshan Ali 2013-05-24 13:03:24 UTC
Was also ported to 3.6.2 apparently.

Comment 12 Cole Robinson 2013-06-10 18:31:55 UTC
3.6.3 in F18 now.


Note You need to log in before you can comment on or make changes to this bug.