[Pkg-xen-devel] Bug#682202: Bug#682202: xcp-squeezed not started on boot

Ian Campbell ijc at hellion.org.uk
Fri Jul 20 09:29:48 UTC 2012


On Fri, 2012-07-20 at 10:13 +0100, Ian Campbell wrote:
> In /var/log/daemon.log I find:

I rebooted to confirm and indeed I find that xapi isn't working and the
logs (syslog this time, because it has a reboot marker in it) have:
        Jul 20 09:19:38 h09 xapi: [ info|h09|0 thread_zero||watchdog] (Re)starting xapi...
        Jul 20 09:19:40 h09 ntpd[2061]: Deleting interface #5 xenbr0, fe80::216:76ff:fec8:1185#123, interface stats: received=0, sent=0, dropped=0, active_time=7 secs
        Jul 20 09:19:40 h09 ntpd[2061]: Deleting interface #4 xenbr0, fd35:5ff5:dd19:cdf1:216:76ff:fec8:1185#123, interface stats: received=0, sent=0, dropped=0, active_time=7 secs
        Jul 20 09:19:40 h09 ntpd[2061]: peers refreshed
        Jul 20 09:19:40 h09 xapi: [error|h09|0 thread_zero|Registering SR plugins D:52e9b96f3d1a|sm_exec] Not scanning /var/lib/xcp/sm for SM backends: directory does not exist
        Jul 20 09:19:40 h09 xapi: [20120720T09:19:40.792Z| info|h09|11 UNIX /var/lib/xcp/xapi|host.sync_pif_currently_attached D:5bc035fb4df1|audit] ('trackid=0fd34796721d426010fdcd14e6af0a4a' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'host.sync_pif_currently_attached' (('host' 'h09' '872a4103-a7f3-e9a1-1dc3-316d46437e7e' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3')))
        Jul 20 09:19:41 h09 stunnel: LOG5[2645:139655476086528]: stunnel 4.53 on x86_64-pc-linux-gnu platform
        Jul 20 09:19:41 h09 stunnel: LOG5[2645:139655476086528]: Compiled/running with OpenSSL 1.0.1c 10 May 2012
        Jul 20 09:19:41 h09 stunnel: LOG5[2645:139655476086528]: Threading:PTHREAD SSL:+ENGINE+OCSP Auth:LIBWRAP Sockets:POLL+IPv6
        Jul 20 09:19:41 h09 stunnel: LOG5[2645:139655476086528]: Reading configuration from file /etc/xcp/xapi-ssl.conf
        Jul 20 09:19:41 h09 stunnel: LOG5[2645:139655476086528]: Configuration successful
        Jul 20 09:19:41 h09 xapi: [20120720T09:19:41.603Z| info|h09|23 UNIX /var/lib/xcp/xapi|host.set_license_params R:cda9b5acb30d|audit] ('trackid=cad495710b5006332ee675f205b38d77' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'host.set_license_params' (('self' 'h09' '872a4103-a7f3-e9a1-1dc3-316d46437e7e' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3')))
        Jul 20 09:19:41 h09 xapi: [ warn|h09|26 heartbeat|heartbeat thread D:a741003e0836|startup] thread [heartbeat thread] died
        Jul 20 09:19:41 h09 xapi: [20120720T09:19:41.686Z| info|h09|33 UNIX /var/lib/xcp/xapi|VM.set_memory_dynamic_range R:04b1a17271da|audit] ('trackid=442ebe59d287eb9da125e14acc316422' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'VM.set_memory_dynamic_range' (('self' 'Control domain on host: h09' '7365e47c-a9dd-af7c-59ea-db2cfbebccb0' 'OpaqueRef:8b9ebf07-350a-6d47-a8dd-50f8c5e0da28')))
        Jul 20 09:19:41 h09 xcp-fe: 2676 (/etc/xcp/master.d/01-example start) exitted with code 2
        Jul 20 09:19:41 h09 xapi: [ warn|h09|25|control domain memory D:1bf14e46bb06|startup] thread [control domain memory] died
        Jul 20 09:19:41 h09 xcp-fe: 2681 (/etc/xcp/master.d/02-vhdcleanup start) exitted with code 2
        Jul 20 09:19:41 h09 xcp-fe: 2684 (/etc/xcp/master.d/03-mpathalert-daemon start) exitted with code 2
        Jul 20 09:19:41 h09 xapi: [20120720T09:19:41.751Z| info|h09|38 UNIX /var/lib/xcp/xapi|host.call_plugin R:2da238b88de8|audit] ('trackid=f9bb73c47109096ae4c4299b749d7ed5' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'ERROR:XENAPI_MISSING_PLUGIN: [ openvswitch-cfg-update ]' 'API' 'host.call_plugin' (('host' 'h09' '872a4103-a7f3-e9a1-1dc3-316d46437e7e' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3')))
        Jul 20 09:19:41 h09 kernel: [   27.207078] ADDRCONF(NETDEV_UP): brvif4.0: link is not ready
        Jul 20 09:19:41 h09 xcp-fe: 2713 (/sbin/ip link set vif4.0 up) exitted with code 1
        Jul 20 09:19:41 h09 xapi: [error|h09|0 thread_zero|Bringing up physical PIFs D:31d89da0761c|xapi] Network configuration error: SCRIPT_ERROR [script = /sbin/ip, args = link set vif4.0 up, code = 1, stdout = , stderr = Cannot find device "vif4.0"#012]
        Jul 20 09:19:42 h09 xapi: [20120720T09:19:42.165Z| info|h09|54 UNIX /var/lib/xcp/xapi|SR.add_to_other_config D:3301923db284|audit] ('trackid=31b3faa38cf81b281779e6575bb2e0e6' 'LOCAL_SUPERUSER' '' 'ALLOWED' 'OK' 'API' 'SR.add_to_other_config' (('self' 'XenServer Tools' 'd736a5b6-cf01-f8f5-7f01-17090102d547' 'OpaqueRef:1055b402-2754-ac48-45a7-548914b45961')))
        Jul 20 09:19:42 h09 xapi: [20120720T09:19:42.192Z| info|h09|48 UNIX /var/lib/xcp/xapi|PBD.plug R:44108457ca05|audit] ('trackid=cfd9b8a58d2c304ab37ac898b7079661' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'PBD.plug' (('self' '' '08dded6c-5bab-2d7f-2758-fbe3c831c056' 'OpaqueRef:a705ac4b-6668-a1c4-5f0f-6a77d7f2e80d')))
        Jul 20 09:19:42 h09 xapi: [20120720T09:19:42.451Z| info|h09|63 UNIX /var/lib/xcp/xapi|PIF.scan R:e271b6384272|audit] ('trackid=75d6ef13047f96c4127da079f2f1631c' 'LOCAL_SUPERUSER' 'root' 'ALLOWED' 'OK' 'API' 'PIF.scan' (('host' 'h09' '872a4103-a7f3-e9a1-1dc3-316d46437e7e' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3')))
        Jul 20 09:19:42 h09 xapi: [20120720T09:19:42.505Z| info|h09|73 UNIX /var/lib/xcp/xapi|SR.add_to_other_config D:9d12204ddf63|audit] ('trackid=5bd7dea475470f7213b7a9a3a1ed533d' 'LOCAL_SUPERUSER' '' 'ALLOWED' 'OK' 'API' 'SR.add_to_other_config' (('self' 'SR0' 'fde9d8d6-0a6d-2d28-cf02-71e3728350fe' 'OpaqueRef:cf4f972f-ba10-2c78-c202-42f793403ea4')))
        Jul 20 09:19:42 h09 xapi: [20120720T09:19:42.537Z| info|h09|59 UNIX /var/lib/xcp/xapi|SR.scan R:4fa6c43e16c6|audit] ('trackid=c8811e1a3a7846f1e7d1da29c30d9478' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'SR.scan' (('sr' 'XenServer Tools' 'd736a5b6-cf01-f8f5-7f01-17090102d547' 'OpaqueRef:1055b402-2754-ac48-45a7-548914b45961')))
        Jul 20 09:19:42 h09 xapi: [ info|h09|0 thread_zero||watchdog] (Re)starting xapi...
        Jul 20 09:19:46 h09 xapi: [error|h09|0 thread_zero|Registering SR plugins D:d8808cff1d9e|sm_exec] Not scanning /var/lib/xcp/sm for SM backends: directory does not exist
        Jul 20 09:19:46 h09 kernel: [   31.828421] kjournald starting.  Commit interval 5 seconds
        Jul 20 09:19:46 h09 kernel: [   31.828659] EXT3-fs (dm-3): using internal journal
        Jul 20 09:19:46 h09 kernel: [   31.828665] EXT3-fs (dm-3): mounted filesystem with ordered data mode
        Jul 20 09:19:46 h09 xapi: [20120720T09:19:46.540Z| info|h09|56 UNIX /var/lib/xcp/xapi|PBD.plug R:195db831978a|audit] ('trackid=cfd9b8a58d2c304ab37ac898b7079661' 'LOCAL_SUPERUSER' 'OpaqueRef:025c4f70-8ad8-0c04-c6db-dbf9088cc8e3' 'ALLOWED' 'OK' 'API' 'PBD.plug' (('self' '' '49921d63-7d69-abfc-0d54-36538998c782' 'OpaqueRef:71b192ba-8cdf-eeca-bdfc-868db5f5263e')))
        Jul 20 09:19:46 h09 xapi: [error|h09|75|scan one D:8031b6fb2551|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Not_found ]
        Jul 20 09:19:46 h09 xapi: [ warn|h09|0 thread_zero|server_init D:86061b85dc2b|startup] task [initialising storage] exception: Api_errors.Server_error("SESSION_INVALID", _)
        Jul 20 09:19:46 h09 xapi: [ warn|h09|0 thread_zero|server_init D:86061b85dc2b|startup] task [wait management interface to come up] exception: Api_errors.Server_error("INTERNAL_ERROR", _)
        Jul 20 09:19:46 h09 xapi: [ warn|h09|79|Calling on_xapi_initialize event hook in the external authentication plugin D:36d7515305f7|startup] thread [Calling on_xapi_initialize event hook in the external authentication plugin] died
        Jul 20 09:20:16 h09 xapi: [ warn|h09|0 thread_zero|server_init D:10d4e0297738|startup] task [Listening localhost] exception: Failure("Repeatedly failed to bind: INET 127.0.0.1:80")
        Jul 20 09:20:16 h09 xapi: [error|h09|0 thread_zero||xapi] Caught exception at toplevel: 'Failure("Repeatedly failed to bind: INET 127.0.0.1:80")'
        Jul 20 09:20:16 h09 xcp-fe: 2784 (/usr/sbin/xapi -nowatchdog list) exitted with code 2
        Jul 20 09:20:16 h09 xapi: [ info|h09|0 thread_zero||watchdog] received exit code 2
        Jul 20 09:20:16 h09 xapi: [ info|h09|0 thread_zero||watchdog] Received bad exit, retrying
        Jul 20 09:20:16 h09 xapi: [ info|h09|0 thread_zero||watchdog] (Re)starting xapi...
        Jul 20 09:20:16 h09 xapi: [error|h09|80|scan one D:242c7c87c07c|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:20:16 h09 xapi: [error|h09|0 thread_zero|Registering SR plugins D:685df4652fb5|sm_exec] Not scanning /var/lib/xcp/sm for SM backends: directory does not exist
        Jul 20 09:20:46 h09 xapi: [error|h09|81|scan one D:37c1d02fe6d5|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Not_found ]
        Jul 20 09:20:46 h09 xapi: [ warn|h09|0 thread_zero|server_init D:6bdc405ec77f|startup] task [Listening localhost] exception: Failure("Repeatedly failed to bind: INET 127.0.0.1:80")
        Jul 20 09:20:46 h09 xapi: [error|h09|0 thread_zero||xapi] Caught exception at toplevel: 'Failure("Repeatedly failed to bind: INET 127.0.0.1:80")'
        Jul 20 09:20:46 h09 xcp-fe: 2828 (/usr/sbin/xapi -nowatchdog list) exitted with code 2
        Jul 20 09:20:46 h09 xapi: [ info|h09|0 thread_zero||watchdog] received exit code 2
        Jul 20 09:20:46 h09 xapi: [ info|h09|0 thread_zero||watchdog] Received 2 bad exits within no-retry-interval. Giving up.
        Jul 20 09:21:16 h09 xapi: [error|h09|82|scan one D:3efa0fb09140|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:21:46 h09 xapi: [error|h09|83|scan one D:8316588ba76f|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:22:16 h09 xapi: [error|h09|84|scan one D:7cb233fbcec5|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:22:46 h09 xapi: [error|h09|85|scan one D:35c7819cb22c|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:23:16 h09 xapi: [error|h09|86|scan one D:0fef5fc456e0|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:23:46 h09 xapi: [error|h09|88|scan one D:f74423320754|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:24:16 h09 xapi: [error|h09|89|scan one D:e9b1ba02c50d|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        Jul 20 09:24:46 h09 xapi: [error|h09|90|scan one D:c98415df41d8|xapi] Caught exception attempting an SR.scan: INTERNAL_ERROR: [ Unix.Unix_error(63, "connect", "") ]
        
"netstat -nap" says:
        # netstat -nap | grep -E xcp\|xapi
        tcp        0      0 10.80.226.105:80        0.0.0.0:*               LISTEN      2574/xapi       
        tcp        0      0 127.0.0.1:80            0.0.0.0:*               LISTEN      2574/xapi       
        unix  2      [ ACC ]     STREAM     LISTENING     6057     2379/xcp-fe         /var/lib/xcp/forker/main
        unix  2      [ ACC ]     STREAM     LISTENING     7192     2485/v6d            /var/lib/xcp/v6
        unix  2      [ ACC ]     STREAM     LISTENING     6707     2459/xcp-networkd   /var/lib/xcp/xcp-networkd
        unix  2      [ ACC ]     STREAM     LISTENING     6804     2574/xapi           /var/lib/xcp/storage
        unix  2      [ ACC ]     STREAM     LISTENING     6806     2574/xapi           /var/lib/xcp/xapi
        unix  3      [ ]         STREAM     CONNECTED     8315     2574/xapi           
        unix  2      [ ]         DGRAM                    6803     2574/xapi           
        unix  3      [ ]         STREAM     CONNECTED     6705     2573/xcp-fe         /var/lib/xcp/forker/main
        unix  3      [ ]         STREAM     CONNECTED     6765     2570/xapi           
        unix  2      [ ]         DGRAM                    6764     2570/xapi           
        
So it doesn't seem to be the case that it has actually failed to bind
127.0.0.1:80 (perhaps it is trying to do it twice?
-- 
Ian Campbell
Current Noise: Death - Flattening Of Emotions

Not intended to diagnose, treat, cure or prevent any disease.



More information about the Pkg-xen-devel mailing list