[Top] [All Lists]
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

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

  • To: xen-api@xxxxxxxxxxxxx
  • From: Black Bird <blackbird1758@xxxxxxxxx>
  • Date: Wed, 7 Nov 2012 15:05:09 +1100
  • Delivery-date: Wed, 07 Nov 2012 04:05:32 +0000
  • List-id: User and development list for XCP and XAPI <xen-api.lists.xen.org>
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.

Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.