TRACE: 1 12-06-59->0s=0:00:00.000296s status=OK step=show plc=plctest1_vplc02 force=False
TRACE: 1 12-06-59->1s=0:00:01.395671s status=OK step=plcvm_delete plc=plctest1_vplc02 force=False
TRACE: 1 12-07-00->0s=0:00:00.535278s status=OK step=plcvm_timestamp plc=plctest1_vplc02 force=False
TRACE: 1 12-07-00->30s=0:00:30.080257s status=OK step=plcvm_create plc=plctest1_vplc02 force=False
TRACE: 1 12-07-31->40s=0:00:40.501859s status=OK step=plc_install plc=plctest1_vplc02 force=False
TRACE: 1 12-08-11->0s=0:00:00.716037s status=OK step=plc_configure plc=plctest1_vplc02 force=False
TRACE: 1 12-08-12->43s=0:00:43.243834s status=OK step=plc_start plc=plctest1_vplc02 force=False
TRACE: 1 12-08-55->0s=0:00:00.535294s status=OK step=keys_fetch plc=plctest1_vplc02 force=False
TRACE: 1 12-08-56->0s=0:00:00.008730s status=OK step=keys_store plc=plctest1_vplc02 force=False
TRACE: 1 12-08-56->0s=0:00:00.009590s status=OK step=keys_clear_known_hosts plc=plctest1_vplc02 force=False
TRACE: 1 12-08-56->0s=0:00:00.763175s status=OK step=plcapi_urls plc=plctest1_vplc02 force=False
TRACE: 1 12-08-56->0s=0:00:00.609177s status=OK step=speed_up_slices plc=plctest1_vplc02 force=False
TRACE: 1 12-08-57->0s=0:00:00.031651s status=OK step=initscripts plc=plctest1_vplc02 force=False
TRACE: 1 12-08-57->1s=0:00:01.381979s status=OK step=sites plc=plctest1_vplc02 force=False
TRACE: 1 12-08-58->0s=0:00:00.147085s status=OK step=nodes plc=plctest1_vplc02 force=False
TRACE: 1 12-08-58->0s=0:00:00.759600s status=OK step=slices plc=plctest1_vplc02 force=False
TRACE: 1 12-08-59->0s=0:00:00.176661s status=OK step=nodegroups plc=plctest1_vplc02 force=False
TRACE: 1 12-08-59->0s=0:00:00.023928s status=OK step=leases plc=plctest1_vplc02 force=False
TRACE: 1 12-08-59->0s=0:00:00.103021s status=OK[I] step=check_vsys_defaults_ignore plc=plctest1_vplc02 force=False
TRACE: 1 12-09-00->0s=0:00:00.638053s status=OK step=qemu_kill_mine plc=plctest1_vplc02 force=False
TRACE: 1 12-09-00->0s=0:00:00.045299s status=OK step=nodestate_reinstall plc=plctest1_vplc02 force=False
TRACE: 1 12-09-00->0s=0:00:00.084222s status=OK step=qemu_local_init plc=plctest1_vplc02 force=False
TRACE: 1 12-09-00->3s=0:00:03.802432s status=OK step=bootcd plc=plctest1_vplc02 force=False
TRACE: 1 12-09-04->0s=0:00:00.032333s status=OK step=qemu_local_config plc=plctest1_vplc02 force=False
TRACE: 1 12-09-04->0s=0:00:00.318817s status=OK step=qemu_clean_mine plc=plctest1_vplc02 force=False
TRACE: 1 12-09-04->1s=0:00:01.540488s status=OK step=qemu_export plc=plctest1_vplc02 force=False
TRACE: 1 12-09-06->0s=0:00:00.638116s status=OK step=qemu_cleanlog plc=plctest1_vplc02 force=False
TRACE: 1 12-09-07->4s=0:00:04.667775s status=OK step=qemu_start plc=plctest1_vplc02 force=False
TRACE: 1 12-09-11->0s=0:00:00.813547s status=OK step=qemu_timestamp plc=plctest1_vplc02 force=False
TRACE: 1 12-09-12->0s=0:00:00.621887s status=OK step=qemu_nodefamily plc=plctest1_vplc02 force=False
TRACE: 1 12-09-13->10s=0:00:10.532744s status=OK step=sfa_install_all plc=plctest1_vplc02 force=False
TRACE: 1 12-09-23->0s=0:00:00.538663s status=OK step=sfa_configure plc=plctest1_vplc02 force=False
TRACE: 1 12-09-24->0s=0:00:00.000154s status=OK step=cross_sfa_configure plc=plctest1_vplc02 force=False
TRACE: 1 12-09-24->6s=0:00:06.151615s status=OK step=sfa_start plc=plctest1_vplc02 force=False
TRACE: 1 12-09-30->3s=0:00:03.625817s status=OK step=sfa_import plc=plctest1_vplc02 force=False
TRACE: 1 12-09-34->0s=0:00:00.554965s status=OK step=sfi_configure plc=plctest1_vplc02 force=False
TRACE: 1 12-09-34->0s=0:00:00.919705s status=OK step=sfa_register_site plc=plctest1_vplc02 force=False
TRACE: 1 12-09-35->1s=0:00:01.791341s status=OK step=sfa_register_pi plc=plctest1_vplc02 force=False
TRACE: 1 12-09-37->1s=0:00:01.573543s status=OK step=sfa_register_user plc=plctest1_vplc02 force=False
TRACE: 1 12-09-38->0s=0:00:00.670482s status=OK step=sfa_update_user plc=plctest1_vplc02 force=False
TRACE: 1 12-09-39->0s=0:00:00.970080s status=OK step=sfa_register_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-09-40->3s=0:00:03.389571s status=OK step=sfa_renew_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-09-43->0s=0:00:00.870206s status=OK step=sfa_remove_user_from_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-09-44->0s=0:00:00.669748s status=OK step=sfi_show_slice_researchers plc=plctest1_vplc02 force=False
TRACE: 1 12-09-45->0s=0:00:00.719947s status=OK step=sfa_insert_user_in_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-09-46->0s=0:00:00.619359s status=OK step=sfi_show_slice_researchers plc=plctest1_vplc02 force=False
TRACE: 1 12-09-46->0s=0:00:00.719785s status=OK step=sfa_discover plc=plctest1_vplc02 force=False
TRACE: 1 12-09-47->0s=0:00:00.937938s status=OK step=sfa_rspec plc=plctest1_vplc02 force=False
TRACE: 1 12-09-48->1s=0:00:01.020630s status=OK step=sfa_allocate plc=plctest1_vplc02 force=False
TRACE: 1 12-09-49->1s=0:00:01.020743s status=OK step=sfa_provision plc=plctest1_vplc02 force=False
TRACE: 1 12-09-50->0s=0:00:00.719940s status=OK step=sfa_describe plc=plctest1_vplc02 force=False
TRACE: 1 12-09-51->0s=0:00:00.064730s status=OK step=sfa_check_slice_plc plc=plctest1_vplc02 force=False
TRACE: 1 12-09-51->2s=0:00:02.042237s status=OK step=sfa_update_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-09-53->1s=0:00:01.439330s status=OK step=sfi_list plc=plctest1_vplc02 force=False
TRACE: 1 12-09-54->0s=0:00:00.669367s status=OK step=sfi_show_site plc=plctest1_vplc02 force=False
TRACE: 1 12-09-55->3s=0:00:03.162435s status=OK step=sfa_utest plc=plctest1_vplc02 force=False
TRACE: 1 12-09-58->5s=0:00:05.030096s status=OK step=probe_kvm_iptables plc=plctest1_vplc02 force=False
TRACE: 1 12-10-03->0s=0:00:00.018233s status=OK step=ping_node plc=plctest1_vplc02 force=False
TRACE: 1 12-10-03->0s=0:00:00.117583s status=OK step=ssh_node_debug plc=plctest1_vplc02 force=False
TRACE: 1 12-10-03->1s=0:00:01.989510s status=OK step=plcsh_stress_test plc=plctest1_vplc02 force=False
TRACE: 1 12-10-05->194s=0:03:14.296988s status=OK step=ssh_node_boot plc=plctest1_vplc02 force=False
TRACE: 1 12-13-20->0s=0:00:00.368620s status=OK step=node_bmlogs plc=plctest1_vplc02 force=False
TRACE: 1 12-13-20->16s=0:00:16.336762s status=OK step=ssh_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-13-36->3s=0:00:03.632040s status=OK step=ssh_slice_basics plc=plctest1_vplc02 force=False
TRACE: 1 12-13-40->0s=0:00:00.435568s status=OK step=check_initscripts plc=plctest1_vplc02 force=False
TRACE: 1 12-13-40->0s=0:00:00.217721s status=OK step=ssh_slice_sfa plc=plctest1_vplc02 force=False
TRACE: 1 12-13-41->0s=0:00:00.267315s status=OK step=sfa_rspec_empty plc=plctest1_vplc02 force=False
TRACE: 1 12-13-41->0s=0:00:00.970638s status=OK step=sfa_allocate_empty plc=plctest1_vplc02 force=False
TRACE: 1 12-13-42->0s=0:00:00.920278s status=OK step=sfa_provision_empty plc=plctest1_vplc02 force=False
TRACE: 1 12-13-43->0s=0:00:00.031208s status=OK step=sfa_check_slice_plc_empty plc=plctest1_vplc02 force=False
TRACE: 1 12-13-43->1s=0:00:01.388994s status=OK step=sfa_delete_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-13-44->0s=0:00:00.669615s status=OK step=sfa_delete_user plc=plctest1_vplc02 force=False
TRACE: 1 12-13-45->2s=0:00:02.996018s status=OK step=cross_check_tcp plc=plctest1_vplc02 force=False
TRACE: 1 12-13-48->0s=0:00:00.382774s status=OK step=check_system_slice plc=plctest1_vplc02 force=False
TRACE: 1 12-13-48->0s=0:00:00.267974s status=OK step=debug_nodemanager plc=plctest1_vplc02 force=False
TRACE: 1 12-13-48->0s=0:00:00.205731s status=OK step=empty_slices plc=plctest1_vplc02 force=False
TRACE: 1 12-13-49->47s=0:00:47.279587s status=OK step=ssh_slice_off plc=plctest1_vplc02 force=False
TRACE: 1 12-14-36->0s=0:00:00.351285s status=OK[I] step=slice_fs_deleted_ignore plc=plctest1_vplc02 force=False
TRACE: 1 12-14-36->0s=0:00:00.122850s status=OK step=fill_slices plc=plctest1_vplc02 force=False
TRACE: 1 12-14-36->31s=0:00:31.836722s status=OK step=ssh_slice_again plc=plctest1_vplc02 force=False
TRACE: 1 12-15-08->2s=0:00:02.267670s status=OK step=gather_logs plc=plctest1_vplc02 force=True