Bug 1399647

Summary: Nodes are not initialized
Product: Red Hat Storage Console Reporter: Martin Kudlej <mkudlej>
Component: coreAssignee: Nishanth Thomas <nthomas>
core sub component: provisioning QA Contact: sds-qe-bugs
Status: CLOSED WONTFIX Docs Contact:
Severity: high    
Priority: unspecified    
Version: 2   
Target Milestone: ---   
Target Release: 3   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-03-23 04:04:18 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Martin Kudlej 2016-11-29 13:50:43 UTC
Description of problem:
Node was not initialized even if it has similar log output as successful initialized node and also node has all required attributes for initialization.

I see from logs that initialization ends with critical error on this test:
apps/skyring/util.go:
   if storage_node, ok := saltnodemanager.GetStorageNodeInstance(node, sProfiles, ctxt); ok {
backend/salt/python/skyring/saltwrapper.py
   if !storage_node.NodeId.IsZero() && len(storage_node.NetworkInfo.Subnet) != 0 && len(storage_node.StorageDisks) != 0 {

but I see in logs that salt commands called for both nodes are the same and results are valid for both. So this test should pass because:
1) machine-id are valid and different for both nodes
2) subnets are correct for both nodes
3) also output for both nodes about disks are similar and correct

Version-Release number of selected component (if applicable):
Server:
ceph-ansible-1.0.5-45.el7scon.noarch
ceph-installer-1.0.15-2.el7scon.noarch
rhscon-ceph-0.0.43-1.el7scon.x86_64
rhscon-core-0.0.45-1.el7scon.x86_64
rhscon-core-selinux-0.0.45-1.el7scon.noarch
rhscon-ui-0.0.60-1.el7scon.noarch
Node:
ceph-base-10.2.2-41.el7cp.x86_64
ceph-common-10.2.2-41.el7cp.x86_64
ceph-mon-10.2.2-41.el7cp.x86_64
ceph-osd-10.2.2-41.el7cp.x86_64
ceph-radosgw-10.2.2-41.el7cp.x86_64
ceph-selinux-10.2.2-41.el7cp.x86_64
libcephfs1-10.2.2-41.el7cp.x86_64
puppet-ceph-2.2.1-3.el7ost.noarch
python-cephfs-10.2.2-41.el7cp.x86_64
rhscon-agent-0.0.19-1.el7scon.noarch
rhscon-core-selinux-0.0.45-1.el7scon.noarch

How reproducible:
90%

Log for not initialized node:
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['machine_id']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'machine_id': 'd6362b19392f4517893ce3f6c6176afq'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], ['grains.item', 'network.subnets'], [['ipv4', 'ipv6'], []]), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'grains.item': {'ipv4': ['10.0.0.111', '10.0.0.38', '127.0.0.1', '172.16.0.51', '172.17.1.16', '172.17.1.23', '172.17.2.20', '172.17.3.22', '172.17.4.16', '192.0.2.17'], 'ipv6': ['::1', 'fe80::5054:ff:fe0f:3795', 'fe80::5054:ff:fecf:d9c1', 'fe80::5054:ff:fed5:8468', 'fe80::64f3:84ff:fe2c:ed1', 'fe80::852:adff:fe65:cd59', 'fe80::a022:17ff:fe07:6061', 'fe80::c013:bfff:fe6c:78f8']}, 'network.subnets': ['172.17.1.0/24', '172.17.1.16/32', '172.17.3.0/24', '10.0.0.0/24', '172.17.2.0/24', '172.17.4.0/24', '10.0.0.0/24', '172.16.0.0/24', '192.0.2.0/24']}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, 'controller-2.localdomain', 'test.ping'), kwargs={}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': True}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ["lsblk --all --bytes --noheadings --output='NAME,KNAME,FSTYPE,MOUNTPOINT,UUID,PARTUUID,MODEL,SIZE,TYPE,PKNAME,VENDOR' --path --raw"]), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': '/dev/vda /dev/vda      42949672960 disk  0x1af4\n/dev/vda1 /dev/vda1 iso9660  2016-11-02-13-40-30-00   1048576 part /dev/vda \n/dev/vda2 /dev/vda2 xfs / 79eab0c0-2933-41fe-9ffd-b04788121bd2   42947411968 part /dev/vda'}
INFO     saltwrapper.py:250 saltwrapper.GetNodeDisk] {'controller-2.localdomain': [{'Name': '/dev/vda2', 'StorageProfile': '', 'DevName': '/dev/vda2', 'MountPoint': ['/'], 'Model': '', 'Type': 'part', 'Used': True, 'Vendor': '', 'Parent': '/dev/vda', 'FSUUID': [121, 234, 176, 192, 41, 51, 65, 254, 159, 253, 176, 71, 136, 18, 27, 210], 'FSType': 'xfs', 'SSD': False, 'DiskId': [121, 234, 176, 192, 41, 51, 65, 254, 159, 253, 176, 71, 136, 18, 27, 210], 'Size': 42947411968L}, {'Name': '/dev/vda1', 'StorageProfile': '', 'DevName': '/dev/vda1', 'MountPoint': [''], 'Model': '', 'Type': 'part', 'Used': True, 'Vendor': '', 'Parent': '/dev/vda', 'FSUUID': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'FSType': 'iso9660', 'SSD': False, 'DiskId': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'Size': 1048576L}]}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['lscpu']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Architecture:          x86_64\nCPU op-mode(s):        32-bit, 64-bit\nByte Order:            Little Endian\nCPU(s):                4\nOn-line CPU(s) list:   0-3\nThread(s) per core:    1\nCore(s) per socket:    1\nSocket(s):             4\nNUMA node(s):          1\nVendor ID:             GenuineIntel\nCPU family:            6\nModel:                 58\nModel name:            Intel Xeon E3-12xx v2 (Ivy Bridge)\nStepping:              9\nCPU MHz:               2799.996\nBogoMIPS:              5599.99\nVirtualization:        VT-x\nHypervisor vendor:     KVM\nVirtualization type:   full\nL1d cache:             32K\nL1i cache:             32K\nL2 cache:              4096K\nNUMA node0 CPU(s):     0-3'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['osfullname']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'osfullname': 'Red Hat Enterprise Linux Server'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['osrelease']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'osrelease': '7.3'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['uname --all']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Linux controller-2.localdomain 3.10.0-513.el7.x86_64 #1 SMP Wed Oct 12 09:41:28 EDT 2016 x86_64 x86_64 x86_64 GNU/Linux'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['getenforce']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Enforcing'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['cat /proc/meminfo']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'MemTotal:       16267968 kB\nMemFree:         3729284 kB\nMemAvailable:    6577172 kB\nBuffers:             884 kB\nCached:          2898268 kB\nSwapCached:            0 kB\nActive:         10394756 kB\nInactive:        1301148 kB\nActive(anon):    8814912 kB\nInactive(anon):    33248 kB\nActive(file):    1579844 kB\nInactive(file):  1267900 kB\nUnevictable:       55992 kB\nMlocked:           55992 kB\nSwapTotal:             0 kB\nSwapFree:              0 kB\nDirty:              1312 kB\nWriteback:             0 kB\nAnonPages:       8850556 kB\nMapped:           430940 kB\nShmem:             40808 kB\nSlab:             452100 kB\nSReclaimable:     338484 kB\nSUnreclaim:       113616 kB\nKernelStack:       16048 kB\nPageTables:       101268 kB\nNFS_Unstable:          0 kB\nBounce:                0 kB\nWritebackTmp:          0 kB\nCommitLimit:     8133984 kB\nCommitted_AS:   22807296 kB\nVmallocTotal:   34359738367 kB\nVmallocUsed:       35460 kB\nVmallocChunk:   34359652824 kB\nHardwareCorrupted:     0 kB\nAnonHugePages:   2473984 kB\nHugePages_Total:       0\nHugePages_Free:        0\nHugePages_Rsvd:        0\nHugePages_Surp:        0\nHugepagesize:       2048 kB\nDirectMap4k:      282492 kB\nDirectMap2M:    11251712 kB\nDirectMap1G:     7340032 kB'}
CRITICAL util.go:458 initializeStorageNode] skyring:d9d865d5-21e4-4575-9de8-699d529f7ec8-Error getting the details for node: controller-2.localdomain


Log for not initialized node:
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['machine_id']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'machine_id': 'd6362b19392f4517893ce3f6c6176a41'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], ['grains.item', 'network.subnets'], [['ipv4', 'ipv6'], []]), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'grains.item': {'ipv4': ['10.0.0.108', '127.0.0.1', '172.17.1.11', '172.17.1.17', '172.17.2.15', '172.17.3.12', '172.17.4.13', '192.0.2.15', '192.0.2.20'], 'ipv6': ['::1', 'fe80::242f:b2ff:fe98:35ec', 'fe80::5054:ff:fe32:83bb', 'fe80::5054:ff:fe34:3793', 'fe80::5054:ff:fe5b:99fc', 'fe80::d0a9:94ff:fe39:5ef2', 'fe80::d835:1aff:fe12:d47b', 'fe80::d87c:d6ff:fece:a3c8']}, 'network.subnets': ['172.17.1.0/24', '172.17.1.17/32', '172.17.4.0/24', '172.17.2.0/24', '192.0.2.0/24', '192.0.2.15/32', '172.17.3.0/24', '10.0.0.0/24']}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, 'controller-2.localdomain', 'test.ping'), kwargs={}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': True}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ["lsblk --all --bytes --noheadings --output='NAME,KNAME,FSTYPE,MOUNTPOINT,UUID,PARTUUID,MODEL,SIZE,TYPE,PKNAME,VENDOR' --path --raw"]), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': '/dev/vda /dev/vda      42949672960 disk  0x1af4\n/dev/vda1 /dev/vda1 iso9660  2016-11-02-13-40-39-00   1048576 part /dev/vda \n/dev/vda2 /dev/vda2 xfs / 79eab0c0-2933-41fe-9ffd-b04788121bd2   42947411968 part /dev/vda'}
INFO     saltwrapper.py:250 saltwrapper.GetNodeDisk] {'controller-2.localdomain': [{'Name': '/dev/vda2', 'StorageProfile': '', 'DevName': '/dev/vda2', 'MountPoint': ['/'], 'Model': '', 'Type': 'part', 'Used': True, 'Vendor': '', 'Parent': '/dev/vda', 'FSUUID': [121, 234, 176, 192, 41, 51, 65, 254, 159, 253, 176, 71, 136, 18, 27, 210], 'FSType': 'xfs', 'SSD': False, 'DiskId': [121, 234, 176, 192, 41, 51, 65, 254, 159, 253, 176, 71, 136, 18, 27, 210], 'Size': 42947411968L}, {'Name': '/dev/vda1', 'StorageProfile': '', 'DevName': '/dev/vda1', 'MountPoint': [''], 'Model': '', 'Type': 'part', 'Used': True, 'Vendor': '', 'Parent': '/dev/vda', 'FSUUID': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'FSType': 'iso9660', 'SSD': False, 'DiskId': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'Size': 1048576L}]}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['lscpu']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Architecture:          x86_64\nCPU op-mode(s):        32-bit, 64-bit\nByte Order:            Little Endian\nCPU(s):                4\nOn-line CPU(s) list:   0-3\nThread(s) per core:    1\nCore(s) per socket:    1\nSocket(s):             4\nNUMA node(s):          1\nVendor ID:             GenuineIntel\nCPU family:            6\nModel:                 58\nModel name:            Intel Xeon E3-12xx v2 (Ivy Bridge)\nStepping:              9\nCPU MHz:               2799.996\nBogoMIPS:              5599.99\nVirtualization:        VT-x\nHypervisor vendor:     KVM\nVirtualization type:   full\nL1d cache:             32K\nL1i cache:             32K\nL2 cache:              4096K\nNUMA node0 CPU(s):     0-3'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['osfullname']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'osfullname': 'Red Hat Enterprise Linux Server'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'grains.item', ['osrelease']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'osrelease': '7.3'}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['uname --all']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Linux controller-2.localdomain 3.10.0-514.el7.x86_64 #1 SMP Wed Oct 19 11:24:13 EDT 2016 x86_64 x86_64 x86_64 GNU/Linux'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['getenforce']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'Enforcing'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['cat /proc/meminfo']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': 'MemTotal:       16267968 kB\nMemFree:         1660244 kB\nMemAvailable:    7032328 kB\nBuffers:             868 kB\nCached:          5293992 kB\nSwapCached:            0 kB\nActive:         11167800 kB\nInactive:        2283604 kB\nActive(anon):    8177184 kB\nInactive(anon):    55088 kB\nActive(file):    2990616 kB\nInactive(file):  2228516 kB\nUnevictable:       54988 kB\nMlocked:           54988 kB\nSwapTotal:             0 kB\nSwapFree:              0 kB\nDirty:              1768 kB\nWriteback:             0 kB\nAnonPages:       8209372 kB\nMapped:           409688 kB\nShmem:             65128 kB\nSlab:             637304 kB\nSReclaimable:     491292 kB\nSUnreclaim:       146012 kB\nKernelStack:      116624 kB\nPageTables:       127380 kB\nNFS_Unstable:          0 kB\nBounce:                0 kB\nWritebackTmp:          0 kB\nCommitLimit:     8133984 kB\nCommitted_AS:   69864960 kB\nVmallocTotal:   34359738367 kB\nVmallocUsed:       35380 kB\nVmallocChunk:   34359695100 kB\nHardwareCorrupted:     0 kB\nAnonHugePages:   2404352 kB\nHugePages_Total:       0\nHugePages_Free:        0\nHugePages_Rsvd:        0\nHugePages_Surp:        0\nHugepagesize:       2048 kB\nDirectMap4k:      180092 kB\nDirectMap2M:     7159808 kB\nDirectMap1G:    11534336 kB'}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ('controller-2.localdomain',), 'state.sls', ['collectd.df,collectd.memory,collectd.cpu,collectd.disk,collectd.network,collectd.swap,collectd.dbpush']), kwargs={'kwarg': {'pillar': {'collectd': {'thresholds': {'df': {'WarningMax': '80', 'FailureMax': '90'}, 'memory': {'WarningMax': '80', 'FailureMax': '90'}, 'swap': {'WarningMax': '50', 'FailureMax': '70'}, 'cpu': {'WarningMax': '80', 'FailureMax': '90'}}, 'master_name': 'sdsqe-0'}}}, 'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'file_|-/etc/collectd.d/dbpush.conf_|-/etc/collectd.d/dbpush.conf_|-managed': {'comment': 'File /etc/collectd.d/dbpush.conf is in the correct state', 'name': '/etc/collectd.d/dbpush.conf', 'start_time': '12:54:04.315687', 'result': True, 'duration': 12.623, '__run_num__': 4, 'changes': {}}, 'file_|-/etc/collectd.d/cpu.conf_|-/etc/collectd.d/cpu.conf_|-managed': {'comment': 'File /etc/collectd.d/cpu.conf is in the correct state', 'name': '/etc/collectd.d/cpu.conf', 'start_time': '12:54:04.348794', 'result': True, 'duration': 11.166, '__run_num__': 7, 'changes': {}}, 'file_|-/etc/collectd.d_|-/etc/collectd.d_|-directory': {'comment': 'Directory /etc/collectd.d is in the correct state', 'name': '/etc/collectd.d', 'start_time': '12:54:04.286478', 'result': True, 'duration': 0.879, '__run_num__': 1, 'changes': {}}, 'file_|-/etc/collectd.d/disk.conf_|-/etc/collectd.d/disk.conf_|-managed': {'comment': 'File /etc/collectd.d/disk.conf is in the correct state', 'name': '/etc/collectd.d/disk.conf', 'start_time': '12:54:04.328429', 'result': True, 'duration': 8.665, '__run_num__': 5, 'changes': {}}, 'service_|-collectd-service_|-collectd_|-running': {'comment': 'Service collectd is already enabled, and is in the desired state', 'name': 'collectd', 'start_time': '12:54:04.442511', 'result': True, 'duration': 1809.052, '__run_num__': 10, 'changes': {}}, 'file_|-/etc/collectd.d/swap.conf_|-/etc/collectd.d/swap.conf_|-managed': {'comment': 'File /etc/collectd.d/swap.conf is in the correct state', 'name': '/etc/collectd.d/swap.conf', 'start_time': '12:54:04.304167', 'result': True, 'duration': 11.398, '__run_num__': 3, 'changes': {}}, 'file_|-/etc/collectd.conf_|-/etc/collectd.conf_|-managed': {'comment': 'File /etc/collectd.conf is in the correct state', 'name': '/etc/collectd.conf', 'start_time': '12:54:04.360082', 'result': True, 'duration': 58.663, '__run_num__': 8, 'changes': {}}, 'pkg_|-collectd_|-collectd_|-installed': {'comment': 'Package collectd is already installed.', 'name': 'collectd', 'start_time': '12:54:02.225360', 'result': True, 'duration': 2056.997, '__run_num__': 0, 'changes': {}}, 'file_|-/etc/collectd.d/df.conf_|-/etc/collectd.d/df.conf_|-managed': {'comment': 'File /etc/collectd.d/df.conf is in the correct state', 'name': '/etc/collectd.d/df.conf', 'start_time': '12:54:04.287454', 'result': True, 'duration': 16.598, '__run_num__': 2, 'changes': {}}, 'file_|-/etc/collectd.d/network.conf_|-/etc/collectd.d/network.conf_|-managed': {'comment': 'File /etc/collectd.d/network.conf is in the correct state', 'name': '/etc/collectd.d/network.conf', 'start_time': '12:54:04.418967', 'result': True, 'duration': 18.103, '__run_num__': 9, 'changes': {}}, 'file_|-/etc/collectd.d/memory.conf_|-/etc/collectd.d/memory.conf_|-managed': {'comment': 'File /etc/collectd.d/memory.conf is in the correct state', 'name': '/etc/collectd.d/memory.conf', 'start_time': '12:54:04.337202', 'result': True, 'duration': 11.487, '__run_num__': 6, 'changes': {}}}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, 'controller-2.localdomain', 'saltutil.sync_all'), kwargs={}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': {'outputters': [], 'grains': [], 'beacons': [], 'utils': [], 'returners': [], 'modules': [], 'renderers': [], 'states': []}}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'service.restart', ['skynetd']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': True}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, ['controller-2.localdomain'], 'cmd.run', ['dbus-send --system --type=method_call --dest=org.storaged.Storaged /org/storaged/Storaged/Manager org.storaged.Storaged.Manager.EnableModules boolean:true']), kwargs={'expr_form': 'list'}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': ''}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, 'controller-2.localdomain', 'service.enable', ['collectd']), kwargs={}
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': True}
INFO     saltwrapper.py:30 saltwrapper.wrapper] args=(<salt.client.LocalClient object at >, 'controller-2.localdomain', 'service.start', ['collectd']), kwargs={}
ERROR    listener.go:116 RouteEvent] skyring:6493d92a-d83f-464e-a3f1-de4baac519b3-Event:skyring/dbus/node/controller-2.localdomain/generic/service/salt_minion could not be handled for node: controller-2.localdomain. error: Error getting provider for cluster: 00000000-0000-0000-0000-000000000000
INFO     saltwrapper.py:32 saltwrapper.wrapper] rv={'controller-2.localdomain': True}