Xen project Mailing List

Re: [Xen-API] XCP 1.6 BETA problem with pool-dump-database

From: Black Bird <blackbird1758@xxxxxxxxx>

Date: Wed, 7 Nov 2012 23:48:18 +1100

Delivery-date: Wed, 07 Nov 2012 12:48:36 +0000

List-id: User and development list for XCP and XAPI <xen-api.lists.xen.org>

I have another update. I have ejected a slave from the 3-host pool (xe pool-eject). In the process, the ejected host is rebooted and becomes a master of a new pool. I tried to execute the xe pool-dump-database command on the ejected host, and a correctly formatted file containing real metadata (uuids, cpuid masks etc) was generated. The same command on my (now 2-host) pool still fails with the Db_ref.Database_not_in_memory error as before. It's strange as the pool seemingly functions normally - vm creation, startup/shutdown, migrations etc work perfectly. All hosts had passed through an XCP1.1 to XCP1.6 Beta2 upgrade, including the now-new standalone host, so there seems to be something in the condition of the pool database which is causing this. I'd welcome any ideas. On Wed, Nov 7, 2012 at 3:05 PM, Black Bird <blackbird1758@xxxxxxxxx> wrote: > Hi all > > just to give you an update of where things are on this issue. > > I noticed that the master host was still making reference to two old > hosts when triggering a backup, resulting in a > RESTORE_INCOMPATIBLE_VERSION error. So at that point I wondered if > xenserver was still thinking the rolling pool upgrade was not actually > complete and preventing the pool database backup. > > So I deleted the old host references using xe host-forget, rebooted > the pool hosts, and retried the xe pool-dump-database command. > > The command still failed, but is now giving a different error: > > -------------------- > The server failed to handle your request, due to an internal error. > The given message may give details useful for debugging the problem. > message: Db_ref.Database_not_in_memory > -------------------- > > The xensource.log on the host on which the command is undertaken > (slave xen2) gives: > > --------------------- > Nov 7 14:44:31 xen2 xapi: [ info|xen2|504 UNIX /var/xapi/xapi||cli] > xe pool-dump-database password=null > file-name=pool-dump-database.20121107144425 username=root > Nov 7 14:44:31 xen2 xapi: [ info|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|xapi] > Session.create trackid=60a04d6d6f460d6c8f2c1c00c8f069a7 pool=false > uname=root is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|mscgen] > xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:9813569e-9094-a8e7-5fbd-89abe227eac8</value></param><param><value>OpaqueRef:9813569e-9094-a8e7-5fbd-89abe227eac8</value></param></params></methodCall>"]; > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|stunnel_cache] Cache contents: [ 192.168.121.10:443 ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|stunnel] > get_reusable_stunnel: stunnel cache is empty; creating a fresh > connection to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|stunnel] > Using commandline: /usr/sbin/stunnel -fd > dac06082-92b5-802c-29e0-611c5678d176 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|stunnel] > stunnel has pidty: (FEFork (29,13921)) > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password D:9b4111dbd467|stunnel] > stunnel start: Log from stunnel: [] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|xmlrpc_client] stunnel pid: 13921 (cached = true) > connected to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13921 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|stunnel_cache] Adding stunnel id 619 (idle 0.00) to the > cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 619 / idle 0.00 age 0.05) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi|session.login_with_password > D:9b4111dbd467|xmlrpc_client] stunnel pid: 13921 (cached = true) > returned stunnel to cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] Using commandline: /usr/sbin/stunnel -fd > 72fc6af9-b415-665b-26cb-d5874ee453eb > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] stunnel has pidty: (FEFork (31,13925)) > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] stunnel start > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||xmlrpc_client] stunnel pid: 13925 (cached = false) > connected to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13925 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|mscgen] > xapi=>xapi > [label="<methodCall><methodName>session.slave_login</methodName><params><param><value>OpaqueRef:aad7ff52-803c-74cb-4ba3-dd041a39264b</value></param><param><value>6a8c9f39-fed2-c11e-763e-422694050b72/52c37cbe-8fbb-54a0-8651-a49c8898bfb6/781dda96-d641-12a6-07f7-6a1bf6b3dbd0</value></param></params></methodCall>"]; > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 619 / idle 0.06 age 0.12) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Removing stunnel id 619 (idle 0.06) from > the cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > check_reusable: caught exception Unix.Unix_error(31, "write", ""); > assuming not reusable > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: Found non-reusable stunnel in the cache. > disconnecting from 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: stunnel cache is empty; creating a fresh > connection to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > Using commandline: /usr/sbin/stunnel -fd > 7f26fe61-69fc-ca57-29c3-e3d58879985a > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel has pidty: (FEFork (34,13930)) > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel start: Log from stunnel: [] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13930 (cached = true) > connected to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13930 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Adding stunnel id 621 (idle 0.00) to the > cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 621 / idle 0.00 age 0.06) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13930 (cached = true) > returned stunnel to cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|mscgen] > xapi=>xapi > [label="<methodCall><methodName>pool.audit_log_append</methodName><params><param><value>OpaqueRef:e7ae57f2-6f0b-672b-bf1a-265847b2dcd3</value></param><param><value>[20121107T03:44:31.849Z|audit|xen2|505 > INET 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|audit] ('trackid=60a04d6d6f460d6c8f2c1c00c8f069a7' > 'LOCAL_SUPERUSER' 'root' 'ALLOWED' 'OK' 'HTTP' > 'http/get_pool_xml_db_sync' (('task_id' '' '' > 'OpaqueRef:1eae2a82-7ba2-f4f6-c390-813470e5d50c')))</value></param></params></methodCall>"]; > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 621 / idle 0.00 age 0.06) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Removing stunnel id 621 (idle 0.00) from > the cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > check_reusable: caught exception Unix.Unix_error(31, "write", ""); > assuming not reusable > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: Found non-reusable stunnel in the cache. > disconnecting from 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: stunnel cache is empty; creating a fresh > connection to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > Using commandline: /usr/sbin/stunnel -fd > 1ca50d09-cab0-a715-cb90-b716e30ff95a > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel has pidty: (FEFork (34,13934)) > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel start: Log from stunnel: [] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13934 (cached = true) > connected to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13934 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Adding stunnel id 622 (idle 0.00) to the > cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 622 / idle 0.00 age 0.06) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13934 (cached = true) > returned stunnel to cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|mscgen] > xapi=>xapi > [label="<methodCall><methodName>session.logout</methodName><params><param><value>OpaqueRef:e7ae57f2-6f0b-672b-bf1a-265847b2dcd3</value></param></params></methodCall>"]; > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 622 / idle 0.00 age 0.06) ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Removing stunnel id 622 (idle 0.00) from > the cache > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > check_reusable: caught exception Unix.Unix_error(31, "write", ""); > assuming not reusable > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: Found non-reusable stunnel in the cache. > disconnecting from 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 ] > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > get_reusable_stunnel: stunnel cache is empty; creating a fresh > connection to 192.168.121.10:443 > Nov 7 14:44:31 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > Using commandline: /usr/sbin/stunnel -fd > 1d722fed-3f2a-2342-0c46-ff2844c67362 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel has pidty: (FEFork (34,13938)) > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync D:4ef05f4246f3|stunnel] > stunnel start: Log from stunnel: [] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13938 (cached = true) > connected to 192.168.121.10:443 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13938 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Adding stunnel id 623 (idle 0.00) to the > cache > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|stunnel_cache] Cache contents: [ 192.168.121.10:443 (id > 623 / idle 0.00 age 0.06) ] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80|handler:http/get_pool_xml_db_sync > D:4ef05f4246f3|xmlrpc_client] stunnel pid: 13938 (cached = true) > returned stunnel to cache > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80||pool_db_sync] received request to write out db as xml > Nov 7 14:44:32 xen2 xapi: [ info|xen2|505 INET > 0.0.0.0:80||taskhelper] task dump database R:1eae2a827ba2 forwarded > (trackid=60a04d6d6f460d6c8f2c1c00c8f069a7) > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|pool_db_sync] sending headers > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|pool_db_sync] writing database xml > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|backtrace] Raised at db_ref.ml:25.19-41 -> > pool_db_backup.ml:41.17-70 -> pool_db_backup.ml:172.6-33 -> > server_helpers.ml:72.10-22 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|dispatcher] Server_helpers.exec > exception_handler: Got exception INTERNAL_ERROR: [ > Db_ref.Database_not_in_memory ] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|dispatcher] Raised at string.ml:150.25-34 -> > stringext.ml:108.13-29 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|backtrace] Raised at string.ml:150.25-34 -> > stringext.ml:108.13-29 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|xapi] Raised at server_helpers.ml:94.14-15 -> > pervasiveext.ml:22.2-9 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|taskhelper] forwarded task destroyed > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80|dump > database R:1eae2a827ba2|xapi] Raised at pervasiveext.ml:26.22-25 -> > pervasiveext.ml:22.2-9 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80||xapi] > Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET 0.0.0.0:80||xapi] > Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|505 INET > 0.0.0.0:80||http_critical] Unhandled exception: > Db_ref.Database_not_in_memory > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||mscgen] xapi=>xapi > [label="<methodCall><methodName>session.logout</methodName><params><param><value>OpaqueRef:9813569e-9094-a8e7-5fbd-89abe227eac8</value></param></params></methodCall>"]; > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel_cache] Cache contents: [ 192.168.121.10:443 > (id 623 / idle 0.06 age 0.12) ] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel_cache] Removing stunnel id 623 (idle 0.06) > from the cache > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] check_reusable: caught exception > Unix.Unix_error(31, "write", ""); assuming not reusable > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] get_reusable_stunnel: Found non-reusable > stunnel in the cache. disconnecting from 192.168.121.10:443 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel_cache] Cache contents: [ 192.168.121.10:443 ] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] get_reusable_stunnel: stunnel cache is empty; > creating a fresh connection to 192.168.121.10:443 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] Using commandline: /usr/sbin/stunnel -fd > e5c76fc4-3cdd-39d6-ed02-c9320c055945 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] stunnel has pidty: (FEFork (29,13942)) > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel] stunnel start: Log from stunnel: [] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||xmlrpc_client] stunnel pid: 13942 (cached = true) > connected to 192.168.121.10:443 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||xmlrpc_client] with_recorded_stunnelpid task_opt=None > s_pid=13942 > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel_cache] Adding stunnel id 624 (idle 0.00) to > the cache > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||stunnel_cache] Cache contents: [ 192.168.121.10:443 > (id 624 / idle 0.00 age 0.06) ] > Nov 7 14:44:32 xen2 xapi: [debug|xen2|504 UNIX > /var/xapi/xapi||xmlrpc_client] stunnel pid: 13942 (cached = true) > returned stunnel to cache > ^C > ---------------------------------------- > > The file generated by the 'xe pool-dump-database' command contains: > > ---------------------------------------- > HTTP/1.0 500 Internal Error > content-length: 260 > content-type:text/html > connection:close > cache-control:no-cache, no-store > > <html><body><h1>HTTP 500 internal server error</h1>An unexpected error > occurred; please wait a while and try again. If the problem persists, > please contact your support representative.<h1> Additional information > </h1>Db_ref.Database_not_in_memory</body></html> > ----------------------------------------- > > On the pool master (xen1), xensource.log contains the same error: > > ----------------------------------------- > ov 7 14:45:46 xen1 xapi: [ info|xen1|13840 INET > 0.0.0.0:80|session.slave_login D:3df1ce0ef0bb|xapi] Session.create > trackid=55e0a455930d14ff5e91dee99d37ce76 pool=true uname= > is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:45:46 xen1 xapi: [debug|xen1|13840 INET > 0.0.0.0:80|session.slave_login D:3df1ce0ef0bb|mscgen] xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:779ee625-7ecd-aded-0331-1cc2a7857718</value></param><param><value>OpaqueRef:779ee625-7ecd-aded-0331-1cc2a7857718</value></param></params></methodCall>"]; > Nov 7 14:45:46 xen1 xapi: [debug|xen1|13841 UNIX > /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid > D:d11b5add1990 created by task D:3df1ce0ef0bb > Nov 7 14:45:46 xen1 xapi: [debug|xen1|13841 UNIX > /var/xapi/xapi|dispatch:session.get_uuid D:d11b5add1990|api_readonly] > session.get_uuid > Nov 7 14:45:46 xen1 xapi: [debug|xen1|13842 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:pool.audit_log_append > D:752d9da999fc created by task D:fcf47a112b06 > Nov 7 14:45:46 xen1 xapi: [ info|xen1|13842 INET > 0.0.0.0:80|dispatch:pool.audit_log_append D:752d9da999fc|taskhelper] > task pool.audit_log_append R:3a8c22a88cd8 > (uuid:3141f88c-f323-29bf-50d1-afa163cbde9c) created > (trackid=55e0a455930d14ff5e91dee99d37ce76) by task D:fcf47a112b06 > Nov 7 14:45:46 xen1 xapi: [debug|xen1|13843 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.logout > D:b02236e33ba8 created by task D:fcf47a112b06 > Nov 7 14:45:46 xen1 xapi: [ info|xen1|13843 INET > 0.0.0.0:80|session.logout D:ab1fb525f616|xapi] Session.destroy > trackid=55e0a455930d14ff5e91dee99d37ce76 > Nov 7 14:45:47 xen1 xapi: [debug|xen1|13844 INET > 0.0.0.0:80|dispatch:logout D:2b0cecc4a19f|dispatcher] Unknown rpc > "logout" > Nov 7 14:45:47 xen1 xapi: [debug|xen1|13845 INET > 0.0.0.0:80|dispatch:VM_guest_metrics.get_record > D:27946ce5858c|api_readonly] VM_guest_metrics.get_record > Nov 7 14:45:53 xen1 xapi: [debug|xen1|13846 INET > 0.0.0.0:80|dispatch:VM.get_all_records D:0338041bac4a|api_readonly] > VM.get_all_records > Nov 7 14:45:53 xen1 xapi: [debug|xen1|13847 INET > 0.0.0.0:80|dispatch:VM.get_record D:533628367428|api_readonly] > VM.get_record > Nov 7 14:45:53 xen1 xapi: [debug|xen1|13848 INET > 0.0.0.0:80|dispatch:VM.get_record D:cc0d962258b1|api_readonly] > VM.get_record > Nov 7 14:45:53 xen1 xapi: [debug|xen1|13850 INET > 0.0.0.0:80|dispatch:VM.get_record D:62de826cc00a|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13851 INET > 0.0.0.0:80|dispatch:VM.get_record D:b623aee8c757|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13852 INET > 0.0.0.0:80|dispatch:VM.get_record D:2de2cfa551de|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13853 INET > 0.0.0.0:80|dispatch:VM.get_record D:134bbce3d936|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13854 INET > 0.0.0.0:80|dispatch:VM.get_record D:085acdb4c33b|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13855 INET > 0.0.0.0:80|dispatch:VM.get_record D:5c043839cb4e|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13857 INET > 0.0.0.0:80|dispatch:VM.get_record D:1d25e4468526|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13858 INET > 0.0.0.0:80|dispatch:VM.get_record D:d2ec5ef9e151|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13859 INET > 0.0.0.0:80|dispatch:VM.get_record D:c912cb2990a9|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13860 INET > 0.0.0.0:80|dispatch:VM.get_record D:fc52adfa9296|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13861 INET > 0.0.0.0:80|dispatch:VM.get_record D:e2ad8d9ae581|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13862 INET > 0.0.0.0:80|dispatch:VM.get_record D:7c2555699ded|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13863 INET > 0.0.0.0:80|dispatch:VM.get_record D:a365a27326b7|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13864 INET > 0.0.0.0:80|dispatch:VM.get_record D:6ce01ada04b7|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13865 INET > 0.0.0.0:80|dispatch:VM.get_record D:be39949ca7bf|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13866 INET > 0.0.0.0:80|dispatch:VM.get_record D:63e387e8d5df|api_readonly] > VM.get_record > Nov 7 14:45:54 xen1 xapi: [debug|xen1|13867 INET > 0.0.0.0:80|dispatch:VM.get_record D:0ecb470c57d5|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13868 INET > 0.0.0.0:80|dispatch:VM.get_record D:c31b7cc2b001|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13869 INET > 0.0.0.0:80|dispatch:VM.get_record D:c043589a8afc|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13870 INET > 0.0.0.0:80|dispatch:VM.get_record D:f53416c19906|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13871 INET > 0.0.0.0:80|dispatch:VM.get_record D:fae668041392|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13872 INET > 0.0.0.0:80|dispatch:VM.get_record D:4a4a28acf513|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13873 INET > 0.0.0.0:80|dispatch:VM.get_record D:6fc4e8542706|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13874 INET > 0.0.0.0:80|dispatch:VM.get_record D:c2087d38a1c7|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13875 INET > 0.0.0.0:80|dispatch:VM.get_record D:ea35d0183955|api_readonly] > VM.get_record > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13876 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.get_uuid > D:aa4b314625f7 created by task D:065a66d31a2d > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13876 INET > 0.0.0.0:80|dispatch:session.get_uuid D:aa4b314625f7|api_readonly] > session.get_uuid > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13877 INET > 0.0.0.0:80|dispatch:pool.get_all D:2bbcfe3d503c|api_readonly] > pool.get_all > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13878 INET > 0.0.0.0:80|dispatch:pool.get_master D:90c5e62d5a96|api_readonly] > pool.get_master > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13879 INET > 0.0.0.0:80|dispatch:host.get_API_version_major > D:1d024edd546a|api_readonly] host.get_API_version_major > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13880 INET > 0.0.0.0:80|dispatch:host.get_API_version_minor > D:2917266d9d72|api_readonly] host.get_API_version_minor > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13881 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.slave_login > D:d24a1edfb101 created by task D:18d83df5bfb8 > Nov 7 14:45:55 xen1 xapi: [ info|xen1|13881 INET > 0.0.0.0:80|session.slave_login D:6a99af0f4ac5|xapi] Session.create > trackid=340f2010a4b2a44bac6ff0da38651b14 pool=true uname= > is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13881 INET > 0.0.0.0:80|session.slave_login D:6a99af0f4ac5|mscgen] xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:bc27e362-6eb2-1a0c-dae2-1aa999ac8a49</value></param><param><value>OpaqueRef:bc27e362-6eb2-1a0c-dae2-1aa999ac8a49</value></param></params></methodCall>"]; > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13882 UNIX > /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid > D:1cdc8759c2dd created by task D:6a99af0f4ac5 > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13882 UNIX > /var/xapi/xapi|dispatch:session.get_uuid D:1cdc8759c2dd|api_readonly] > session.get_uuid > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13883 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:pool.audit_log_append > D:2548baf67ff3 created by task D:18d83df5bfb8 > Nov 7 14:45:55 xen1 xapi: [ info|xen1|13883 INET > 0.0.0.0:80|dispatch:pool.audit_log_append D:2548baf67ff3|taskhelper] > task pool.audit_log_append R:5add4b87e17b > (uuid:ba8cd81b-0427-d60a-24c1-e9ec588a193e) created > (trackid=340f2010a4b2a44bac6ff0da38651b14) by task D:18d83df5bfb8 > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13884 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.logout > D:86d9ae2ddce5 created by task D:18d83df5bfb8 > Nov 7 14:45:55 xen1 xapi: [ info|xen1|13884 INET > 0.0.0.0:80|session.logout D:8320517da32d|xapi] Session.destroy > trackid=340f2010a4b2a44bac6ff0da38651b14 > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13885 INET > 0.0.0.0:80|dispatch:logout D:414cfb7f1368|dispatcher] Unknown rpc > "logout" > Nov 7 14:45:55 xen1 xapi: [debug|xen1|13886 INET > 0.0.0.0:80|dispatch:VM_guest_metrics.get_record > D:ef0614b29579|api_readonly] VM_guest_metrics.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13887 INET > 0.0.0.0:80|dispatch:VM.get_all_records D:d60af399eefc|api_readonly] > VM.get_all_records > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13888 INET > 0.0.0.0:80|dispatch:VM.get_record D:a74fea05b168|api_readonly] > VM.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13889 INET > 0.0.0.0:80|dispatch:VM.get_record D:c95353e0ab21|api_readonly] > VM.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13890 INET > 0.0.0.0:80|dispatch:VM.get_record D:eadfc437c60a|api_readonly] > VM.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13891 INET > 0.0.0.0:80|dispatch:VM.get_record D:e0e616a7ed28|api_readonly] > VM.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13892 INET > 0.0.0.0:80|dispatch:VM.get_record D:a296db554c0b|api_readonly] > VM.get_record > Nov 7 14:46:02 xen1 xapi: [debug|xen1|13893 INET > 0.0.0.0:80|dispatch:VM.get_record D:626b4bd00df3|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13894 INET > 0.0.0.0:80|dispatch:VM.get_record D:43456200b956|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13895 INET > 0.0.0.0:80|dispatch:VM.get_record D:2eab21d01431|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13896 INET > 0.0.0.0:80|dispatch:VM.get_record D:eeef42ac8459|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13897 INET > 0.0.0.0:80|dispatch:VM.get_record D:6e77e0467455|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13898 INET > 0.0.0.0:80|dispatch:VM.get_record D:33b8a0c691f9|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13899 INET > 0.0.0.0:80|dispatch:VM.get_record D:e227641004ec|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13900 INET > 0.0.0.0:80|dispatch:VM.get_record D:6f51ea87310a|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13901 INET > 0.0.0.0:80|dispatch:VM.get_record D:161826adc935|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13902 INET > 0.0.0.0:80|dispatch:VM.get_record D:d272fb55990a|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13903 INET > 0.0.0.0:80|dispatch:VM.get_record D:8dea0e8922b6|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13904 INET > 0.0.0.0:80|dispatch:VM.get_record D:df870316ab04|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13905 INET > 0.0.0.0:80|dispatch:VM.get_record D:249344ce0d0e|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13906 INET > 0.0.0.0:80|dispatch:VM.get_record D:c946a9733370|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13907 INET > 0.0.0.0:80|dispatch:VM.get_record D:b24910c84a3b|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13908 INET > 0.0.0.0:80|dispatch:VM.get_record D:11e8975ad5b9|api_readonly] > VM.get_record > Nov 7 14:46:03 xen1 xapi: [debug|xen1|13909 INET > 0.0.0.0:80|dispatch:VM.get_record D:af15bdb90e68|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13910 INET > 0.0.0.0:80|dispatch:VM.get_record D:de1b4b49226c|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13911 INET > 0.0.0.0:80|dispatch:VM.get_record D:73f9e4821afd|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13912 INET > 0.0.0.0:80|dispatch:VM.get_record D:63d93d432ede|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13913 INET > 0.0.0.0:80|dispatch:VM.get_record D:c0185b8fa647|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13914 INET > 0.0.0.0:80|dispatch:VM.get_record D:c20655dce5ec|api_readonly] > VM.get_record > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13915 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.get_uuid > D:2b47c4291b7f created by task D:de45345be245 > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13915 INET > 0.0.0.0:80|dispatch:session.get_uuid D:2b47c4291b7f|api_readonly] > session.get_uuid > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13916 INET > 0.0.0.0:80|dispatch:pool.get_all D:cfaca7a81830|api_readonly] > pool.get_all > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13917 INET > 0.0.0.0:80|dispatch:pool.get_master D:1246c7b5a766|api_readonly] > pool.get_master > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13918 INET > 0.0.0.0:80|dispatch:host.get_API_version_major > D:e262961170aa|api_readonly] host.get_API_version_major > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13919 INET > 0.0.0.0:80|dispatch:host.get_API_version_minor > D:ccd380cb5b72|api_readonly] host.get_API_version_minor > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13920 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.slave_login > D:02ec87b22cba created by task D:1119ebe735bb > Nov 7 14:46:04 xen1 xapi: [ info|xen1|13920 INET > 0.0.0.0:80|session.slave_login D:57bff11f5ed5|xapi] Session.create > trackid=a07205817100a477a7baca3fdb09488b pool=true uname= > is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13920 INET > 0.0.0.0:80|session.slave_login D:57bff11f5ed5|mscgen] xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:62d1099a-67b2-6025-8dc8-abd0fcc03456</value></param><param><value>OpaqueRef:62d1099a-67b2-6025-8dc8-abd0fcc03456</value></param></params></methodCall>"]; > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13921 UNIX > /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid > D:c330d6048025 created by task D:57bff11f5ed5 > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13921 UNIX > /var/xapi/xapi|dispatch:session.get_uuid D:c330d6048025|api_readonly] > session.get_uuid > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13922 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:pool.audit_log_append > D:2e729dc848f0 created by task D:1119ebe735bb > Nov 7 14:46:04 xen1 xapi: [ info|xen1|13922 INET > 0.0.0.0:80|dispatch:pool.audit_log_append D:2e729dc848f0|taskhelper] > task pool.audit_log_append R:49874ae07289 > (uuid:ad0c2e0c-793b-a6b0-a4f2-cfd6843bb67c) created > (trackid=a07205817100a477a7baca3fdb09488b) by task D:1119ebe735bb > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13923 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.logout > D:1e6da0481d75 created by task D:1119ebe735bb > Nov 7 14:46:04 xen1 xapi: [ info|xen1|13923 INET > 0.0.0.0:80|session.logout D:344e2953c365|xapi] Session.destroy > trackid=a07205817100a477a7baca3fdb09488b > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13924 INET > 0.0.0.0:80|dispatch:logout D:3b5d17b28b16|dispatcher] Unknown rpc > "logout" > Nov 7 14:46:04 xen1 xapi: [debug|xen1|13925 INET > 0.0.0.0:80|dispatch:VM_guest_metrics.get_record > D:0c225a0dc27e|api_readonly] VM_guest_metrics.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13926 INET > 0.0.0.0:80|dispatch:VM.get_all_records D:cc51c83cb6f3|api_readonly] > VM.get_all_records > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13927 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.get_uuid > D:4ffb7d3454c7 created by task D:9b4111dbd467 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13927 INET > 0.0.0.0:80|dispatch:session.get_uuid D:4ffb7d3454c7|api_readonly] > session.get_uuid > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13928 INET 0.0.0.0:80||cli] xe > pool-dump-database password=null > file-name=pool-dump-database.20121107144425 username=root > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13928 INET > 0.0.0.0:80|task.create D:0788add19199|taskhelper] task dump database > R:1eae2a827ba2 (uuid:68684032-1de5-534e-2360-de861b3d583a) created > (trackid=60a04d6d6f460d6c8f2c1c00c8f069a7) by task D:0788add19199 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||cli] > /pool/xmldbdump?session_id=OpaqueRef:9813569e-9094-a8e7-5fbd-89abe227eac8&task_id=OpaqueRef:1eae2a82-7ba2-f4f6-c390-813470e5d50c > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13929 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.slave_login > D:0b351897942c created by task D:4ef05f4246f3 > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13929 INET > 0.0.0.0:80|session.slave_login D:35711e5c164b|xapi] Session.create > trackid=02591f0492e0d3ac10210204662e4ded pool=true uname= > is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13929 INET > 0.0.0.0:80|session.slave_login D:35711e5c164b|mscgen] xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:e7ae57f2-6f0b-672b-bf1a-265847b2dcd3</value></param><param><value>OpaqueRef:e7ae57f2-6f0b-672b-bf1a-265847b2dcd3</value></param></params></methodCall>"]; > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13930 UNIX > /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid > D:7b84433e0f1e created by task D:35711e5c164b > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13930 UNIX > /var/xapi/xapi|dispatch:session.get_uuid D:7b84433e0f1e|api_readonly] > session.get_uuid > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13931 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:pool.audit_log_append > D:911676d9acf2 created by task D:4ef05f4246f3 > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13931 INET > 0.0.0.0:80|dispatch:pool.audit_log_append D:911676d9acf2|taskhelper] > task pool.audit_log_append R:5816d9c22abc > (uuid:1d37bc03-6e37-655d-fac7-63a17049812c) created > (trackid=02591f0492e0d3ac10210204662e4ded) by task D:4ef05f4246f3 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13932 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.logout > D:0b21aa50561a created by task D:4ef05f4246f3 > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13932 INET > 0.0.0.0:80|session.logout D:4e3331bf22e5|xapi] Session.destroy > trackid=02591f0492e0d3ac10210204662e4ded > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||cli] > Waiting for the task to be completed > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET > 0.0.0.0:80|dispatch:task.get_status D:16e2395900f3|api_readonly] > task.get_status > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET > 0.0.0.0:80|dispatch:task.get_status D:71c85b8fd22b|api_readonly] > task.get_status > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET > 0.0.0.0:80|dispatch:task.get_error_info D:7bec975792b1|api_readonly] > task.get_error_info > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||xapi] > Raised at cli_util.ml:106.10-67 -> pervasiveext.ml:22.2-9 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||xapi] > Raised at pervasiveext.ml:26.22-25 -> cli_operations.ml:3757.7-76 -> > xapi_cli.ml:119.18-58 -> pervasiveext.ml:22.2-9 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET > 0.0.0.0:80||backtrace] Raised at pervasiveext.ml:26.22-25 -> > xapi_cli.ml:118.2-139 -> xapi_cli.ml:205.7-44 -> xapi_cli.ml:257.4-23 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||cli] > Xapi_cli.exception_handler: Got exception INTERNAL_ERROR: [ > Db_ref.Database_not_in_memory ] > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13928 INET 0.0.0.0:80||cli] > Raised at string.ml:150.25-34 -> stringext.ml:108.13-29 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13933 INET > 0.0.0.0:80|dispatch:VM.get_record D:f03b23bad6b6|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [ info|xen1|13934 INET > 0.0.0.0:80|session.logout D:cf09aa98e5dc|xapi] Session.destroy > trackid=60a04d6d6f460d6c8f2c1c00c8f069a7 > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13935 INET > 0.0.0.0:80|dispatch:VM.get_record D:b9eb168f26a4|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13936 INET > 0.0.0.0:80|dispatch:VM.get_record D:713691686122|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13937 INET > 0.0.0.0:80|dispatch:VM.get_record D:73f061875e4e|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13938 INET > 0.0.0.0:80|dispatch:VM.get_record D:42e791d5962b|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13939 INET > 0.0.0.0:80|dispatch:VM.get_record D:4a6a7d1655f5|api_readonly] > VM.get_record > Nov 7 14:46:11 xen1 xapi: [debug|xen1|13940 INET > 0.0.0.0:80|dispatch:VM.get_record D:16e512082807|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13941 INET > 0.0.0.0:80|dispatch:VM.get_record D:5c146ed4ea8b|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13942 INET > 0.0.0.0:80|dispatch:VM.get_record D:59cb99cbdceb|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13943 INET > 0.0.0.0:80|dispatch:VM.get_record D:b36dd82f1478|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13944 INET > 0.0.0.0:80|dispatch:VM.get_record D:bdbd494896aa|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13945 INET > 0.0.0.0:80|dispatch:VM.get_record D:b9172b69138e|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13946 INET > 0.0.0.0:80|dispatch:VM.get_record D:33469df191d6|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13947 INET > 0.0.0.0:80|dispatch:VM.get_record D:6aed4c449cf1|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13948 INET > 0.0.0.0:80|dispatch:VM.get_record D:b2ec4321c916|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13949 INET > 0.0.0.0:80|dispatch:VM.get_record D:baa48ac2457f|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13950 INET > 0.0.0.0:80|dispatch:VM.get_record D:4fe25c5217ce|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13951 INET > 0.0.0.0:80|dispatch:VM.get_record D:6c767da69c84|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13952 INET > 0.0.0.0:80|dispatch:VM.get_record D:dad77badb864|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13953 INET > 0.0.0.0:80|dispatch:VM.get_record D:6acf38a1bd38|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13954 INET > 0.0.0.0:80|dispatch:VM.get_record D:90f517be987b|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13955 INET > 0.0.0.0:80|dispatch:VM.get_record D:720fb2733fa3|api_readonly] > VM.get_record > Nov 7 14:46:12 xen1 xapi: [debug|xen1|13956 INET > 0.0.0.0:80|dispatch:VM.get_record D:d82fa678d2a9|api_readonly] > VM.get_record > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13957 INET > 0.0.0.0:80|dispatch:VM.get_record D:faeb7c57c4f8|api_readonly] > VM.get_record > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13958 INET > 0.0.0.0:80|dispatch:VM.get_record D:1cc910085cc9|api_readonly] > VM.get_record > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13959 INET > 0.0.0.0:80|dispatch:VM.get_record D:411aaa6784d7|api_readonly] > VM.get_record > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13960 INET > 0.0.0.0:80|dispatch:VM.get_record D:37a43f973239|api_readonly] > VM.get_record > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13961 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.get_uuid > D:f95405f31dd9 created by task D:7ed26affbb25 > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13961 INET > 0.0.0.0:80|dispatch:session.get_uuid D:f95405f31dd9|api_readonly] > session.get_uuid > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13962 INET > 0.0.0.0:80|dispatch:pool.get_all D:4afea9bf1de2|api_readonly] > pool.get_all > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13963 INET > 0.0.0.0:80|dispatch:pool.get_master D:fe753d7d10af|api_readonly] > pool.get_master > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13964 INET > 0.0.0.0:80|dispatch:host.get_API_version_major > D:d2f967c3bace|api_readonly] host.get_API_version_major > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13965 INET > 0.0.0.0:80|dispatch:host.get_API_version_minor > D:beced6e7caca|api_readonly] host.get_API_version_minor > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13966 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.slave_login > D:a1977abd7e46 created by task D:b9d1f4a4f863 > Nov 7 14:46:13 xen1 xapi: [ info|xen1|13966 INET > 0.0.0.0:80|session.slave_login D:063c4a96ece4|xapi] Session.create > trackid=f50bb8c52a8b0745cf7252aab720200f pool=true uname= > is_local_superuser=true auth_user_sid= > parent=trackid=9834f5af41c964e225f24279aefe4e49 > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13966 INET > 0.0.0.0:80|session.slave_login D:063c4a96ece4|mscgen] xapi=>xapi > [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:e07df1ae-dcec-e652-0a31-50f5412c97e5</value></param><param><value>OpaqueRef:e07df1ae-dcec-e652-0a31-50f5412c97e5</value></param></params></methodCall>"]; > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13967 UNIX > /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid > D:e13457a845ee created by task D:063c4a96ece4 > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13967 UNIX > /var/xapi/xapi|dispatch:session.get_uuid D:e13457a845ee|api_readonly] > session.get_uuid > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13968 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:pool.audit_log_append > D:8923bcda4e15 created by task D:b9d1f4a4f863 > Nov 7 14:46:13 xen1 xapi: [ info|xen1|13968 INET > 0.0.0.0:80|dispatch:pool.audit_log_append D:8923bcda4e15|taskhelper] > task pool.audit_log_append R:4e346e04368d > (uuid:9cfde04f-3d76-078a-22b1-9dfbdacd7890) created > (trackid=f50bb8c52a8b0745cf7252aab720200f) by task D:b9d1f4a4f863 > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13969 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:session.logout > D:70bdaa293a99 created by task D:b9d1f4a4f863 > Nov 7 14:46:13 xen1 xapi: [ info|xen1|13969 INET > 0.0.0.0:80|session.logout D:cc170f8f7016|xapi] Session.destroy > trackid=f50bb8c52a8b0745cf7252aab720200f > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13970 INET > 0.0.0.0:80|dispatch:logout D:647456547b72|dispatcher] Unknown rpc > "logout" > Nov 7 14:46:13 xen1 xapi: [debug|xen1|13971 INET > 0.0.0.0:80|dispatch:VM_guest_metrics.get_record > D:99008281eb5e|api_readonly] VM_guest_metrics.get_record > Nov 7 14:46:14 xen1 xapi: [debug|xen1|13972 INET > 0.0.0.0:80||dummytaskhelper] task dispatch:event.from D:7217e8b4fed9 > created by task D:1d65cc2b0012 > --------------------------------------------------------- > > Has anyone had any luck with dumping the pool database with XCP1.6, > any Beta version, or encountered the error > Db_ref.Database_not_in_memory > > > > On Tue, Nov 6, 2012 at 11:29 AM, Black Bird <blackbird1758@xxxxxxxxx> wrote: >> (discreet bump) >> >> I'd be grateful if anyone could point me in the right direction. >> >> On Wed, Oct 31, 2012 at 12:56 PM, Black Bird <blackbird1758@xxxxxxxxx> wrote: >>> Hi all >>> >>> I have a pool of 3 hosts which I have upgraded from XCP1.1 to XCP Beta >>> 2. I have attempted to run a database backup using 'xe >>> pool-dump-database file-name=xxxx' on the pool master. The command >>> runs and finishes successfully without returning an error. A file is >>> also generated which is non-zero in length. However when opening the >>> file, I don't see any metadata I would be expecting (host uuids, vifs, >>> vm uuids etc), but only some generic definitions. >>> >>> I do have a previous pool database dump file taken on the master with >>> the old XCP version 1.1 and the file clearly contains all the metadata >>> and is 617KB long. >>> >>> Following is a dump of the new file generated on the master with XCP >>> Beta 2, 864 bytes long. >>> >>> >>> <database><manifest><pair key="schema_major_vsn" value="5"/><pair >>> key="schema_minor_vsn" value="35"/><pair key="generation_count" >>> value="103"/></manifest><table name="SR" /><table name="pool" /><table >>> name="VBD_metrics"/><table name="console" /><table name="host" >>> /><table name="VIF_metrics"/><table name="user" /><table name="PBD" >>> /><table name="pool_patch" /><table name="host_metrics" /><table >>> name="VLAN" /><table name="Bond" /><table name="VTPM" /><table >>> name="event"/><table name="VBD" /><table name="VM_guest_metrics" >>> /><table name="VDI" /><table name="VM_metrics"/><table >>> name="task"/><table name="VM" /><table name="crashdump"/><table >>> name="network" /><table name="PIF" /><table name="host_patch"/><table >>> name="host_crashdump"/><table name="SM" /><table name="host_cpu" >>> /><table name="VIF" /><table name="session" /><table >>> name="PIF_metrics" /></database> >>> >>> A dump on the other hosts produces exactly the same file, as expected >>> as the database is replicated from the master to the slaves as a >>> matter of course. >>> >>> Following is a dump of the portion of xensource.log taken during >>> execution of the pool database dump: >>> >>> >>> Oct 31 12:37:45 xen1 xapi: [ info|xen1|24112 UNIX /var/xapi/xapi||cli] >>> xe pool-dump-database password=null file-name=pool-dump-database >>> username=root >>> Oct 31 12:37:45 xen1 xapi: [ info|xen1|24112 UNIX >>> /var/xapi/xapi|session.login_with_password D:6a0b6a3b5be0|xapi] >>> Session.create trackid=949de24d97b7ebe26d4b555dd6509e0b pool=false >>> uname=root is_local_superuser=true auth_user_sid= >>> parent=trackid=9834f5af41c964e225f24279aefe4e49 >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX >>> /var/xapi/xapi|session.login_with_password D:6a0b6a3b5be0|mscgen] >>> xapi=>xapi >>> [label="<methodCall><methodName>session.get_uuid</methodName><params><param><value>OpaqueRef:69e50c5a-725e-a27d-b80e-cda7ce7d6a46</value></param><param><value>OpaqueRef:69e50c5a-725e-a27d-b80e-cda7ce7d6a46</value></param></params></methodCall>"]; >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24113 UNIX >>> /var/xapi/xapi||dummytaskhelper] task dispatch:session.get_uuid >>> D:d53ec83a4add created by task D:6a0b6a3b5be0 >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24113 UNIX >>> /var/xapi/xapi|dispatch:session.get_uuid D:d53ec83a4add|api_readonly] >>> session.get_uuid >>> Oct 31 12:37:45 xen1 xapi: [ info|xen1|24112 UNIX >>> /var/xapi/xapi|task.create D:ed79e10f9da2|taskhelper] task dump >>> database R:8a999bbaa423 (uuid:635e0674-1f79-5c22-b0ab-243ade6f6fca) >>> created (trackid=949de24d97b7ebe26d4b555dd6509e0b) by task >>> D:ed79e10f9da2 >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX /var/xapi/xapi||cli] >>> /pool/xmldbdump?session_id=OpaqueRef:69e50c5a-725e-a27d-b80e-cda7ce7d6a46&task_id=OpaqueRef:8a999bba-a423-c4a7-6173-6bade5afca8a >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24114 INET >>> 0.0.0.0:80||pool_db_sync] received request to write out db as xml >>> Oct 31 12:37:45 xen1 xapi: [ info|xen1|24114 INET >>> 0.0.0.0:80||taskhelper] task dump database R:8a999bbaa423 forwarded >>> (trackid=949de24d97b7ebe26d4b555dd6509e0b) >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24114 INET 0.0.0.0:80|dump >>> database R:8a999bbaa423|pool_db_sync] sending headers >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24114 INET 0.0.0.0:80|dump >>> database R:8a999bbaa423|pool_db_sync] writing database xml >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24114 INET 0.0.0.0:80|dump >>> database R:8a999bbaa423|pool_db_sync] finished writing database xml >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24114 INET 0.0.0.0:80|dump >>> database R:8a999bbaa423|taskhelper] forwarded task destroyed >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX /var/xapi/xapi||cli] >>> Waiting for the task to be completed >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX >>> /var/xapi/xapi|dispatch:task.get_status D:9c36942a54e7|api_readonly] >>> task.get_status >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX >>> /var/xapi/xapi|dispatch:task.get_status D:c88da02d77eb|api_readonly] >>> task.get_status >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX >>> /var/xapi/xapi|dispatch:task.get_result D:4b68c1120f7c|api_readonly] >>> task.get_result >>> Oct 31 12:37:45 xen1 xapi: [debug|xen1|24112 UNIX /var/xapi/xapi||cli] >>> result was [] >>> Oct 31 12:37:45 xen1 xapi: [ info|xen1|24112 UNIX >>> /var/xapi/xapi|session.logout D:0a377b2fbab2|xapi] Session.destroy >>> trackid=949de24d97b7ebe26d4b555dd6509e0b >>> >>> Can anyone give an idea of what may be happening? >>> >>> I do hope this is a specific configuration issue, as if it were a bug >>> it would probably be considered a showstopper for production use. _______________________________________________ Xen-api mailing list Xen-api@xxxxxxxxxxxxx http://lists.xen.org/cgi-bin/mailman/listinfo/xen-api

©2013 Xen Project, A Linux Foundation Collaborative Project. All Rights Reserved.
Linux Foundation is a registered trademark of The Linux Foundation.
Xen Project is a trademark of The Linux Foundation.