Bug 1475865 - GuestAgentLinux2::380::root::Error retrieving disks usages.
GuestAgentLinux2::380::root::Error retrieving disks usages.
Status: CLOSED NEXTRELEASE
Product: ovirt-guest-agent
Classification: oVirt
Component: Core (Show other bugs)
1.0.13
x86_64 Linux
unspecified Severity low (vote)
: ---
: ---
Assigned To: Tomáš Golembiovský
Pavel Stehlik
: Reopened
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-07-27 09:40 EDT by marciofoz
Modified: 2017-11-12 18:01 EST (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-11-12 18:01:16 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Virt
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
oVirt gerrit 83813 None None None 2017-11-10 10:25 EST

  None (edit)
Description marciofoz 2017-07-27 09:40:06 EDT
Description of problem:

-guest agent does not show any disk usage in the log but there's error:

Dummy-2::ERROR::2017-07-27 10:16:20,060::GuestAgentLinux2::380::root::Error retrieving disks usages.
Traceback (most recent call last):
  File "/usr/share/ovirt-guest-agent/GuestAgentLinux2.py", line 372, in getDisksUsage
    statvfs = os.statvfs(path)
OSError: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'

Version-Release number of selected component (if applicable):
ovirt-guest-agent-common-1.0.13-2.fc25.noarch
fedora 4.11.12-200.fc25.x86_64

How reproducible:
100%

Steps to Reproduce:
1.check log file
2.
3.

Actual results:
permission error

Expected results:


Additional info:

#
# ovirt-guest-agent.conf
#

[general]

# heart_beat_rate = 5
# report_user_rate = 10
# report_num_cpu_rate = 60
# report_application_rate = 120
# report_disk_usage = 300

## Generic:              ovirt-guest-agent
## RHEL/Fedora Packages: kernel ovirt-guest-agent-common xorg-x11-drv-qxl
## Debian Packages:      linux-image xserver-xorg-video-qxl
## openSUSE Packages:    xf86-video-qxl kernel-desktop kernel-default kernel-trace kernel-vanilla kernel-debug kernel-ec2 kernel-xen kernel-ppc64
# applications_list = kernel ovirt-guest-agent ovirt-guest-agent-common xorg-x11-drv-qxl linux-image xserver-xorg-video-qxl xf86-video-qxl kernel-desktop kernel-default kernel-trace kernel-vanilla kernel-debug kernel-ec2 kernel-xen kernel-ppc64 cloud-init
# ignored_fs = rootfs tmpfs autofs cgroup selinuxfs udev mqueue nfsd proc sysfs devtmpfs hugetlbfs rpc_pipefs devpts securityfs debugfs binfmt_misc fuse.gvfsd-fuse fuse.gvfs-fuse-daemon fusectl usbfs
# ignore_zero_size_fs = true

applications_list = bacula-common kernel ovirt-guest-agent ovirt-guest-agent-common puppet-agent zabbix-agent

[virtio]
# device = /dev/virtio-ports/com.redhat.rhevm.vdsm

#[loggers]
#keys=root

#[handlers]
#keys=console,syslog,logfile

#[formatters]
#keys=long,simple,none,sysform

#[logger_root]
#level=INFO
#handlers=logfile
#propagate=0

#[handler_syslog]
#class=handlers.SysLogHandler
#formatter=sysform
#args=(('localhost', handlers.SYSLOG_UDP_PORT), handlers.SysLogHandler.LOG_USER)

#[handler_logfile]
#class=handlers.RotatingFileHandler
#args=('/var/log/ovirt-guest-agent/ovirt-guest-agent.log', 'a+', 100*1024, 5)
#formatter=long

#[handler_console]
#class: StreamHandler
#args: []
#formatter: none

#[formatter_simple]
#format: %(name)s:%(levelname)s:  %(message)s

#[formatter_none]
#format: %(message)s

#[formatter_long]
#format: %(threadName)s::%(levelname)s::%(asctime)s::%(module)s::%(lineno)d::%(name)s::%(message)s

#[formatter_sysform]
#format= %(asctime)s %(levelname)s %(message)s
#datefmt=
Comment 1 Tomáš Golembiovský 2017-10-04 08:03:55 EDT
The error should be harmless. How did you check that the disk usage is not sent?

Still I belive we could do better here. Could you please provide the content of /proc/mounts from the affected system?
Comment 2 marciofoz 2017-10-04 10:01:32 EDT
Hi Tomas:

cat /proc/mounts 
sysfs /sys sysfs rw,seclabel,nosuid,nodev,noexec,relatime 0 0
proc /proc proc rw,nosuid,nodev,noexec,relatime 0 0
devtmpfs /dev devtmpfs rw,seclabel,nosuid,size=2008860k,nr_inodes=502215,mode=755 0 0
securityfs /sys/kernel/security securityfs rw,nosuid,nodev,noexec,relatime 0 0
tmpfs /dev/shm tmpfs rw,seclabel,nosuid,nodev 0 0
devpts /dev/pts devpts rw,seclabel,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0
tmpfs /run tmpfs rw,seclabel,nosuid,nodev,mode=755 0 0
tmpfs /sys/fs/cgroup tmpfs ro,seclabel,nosuid,nodev,noexec,mode=755 0 0
cgroup /sys/fs/cgroup/systemd cgroup rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/usr/lib/systemd/systemd-cgroups-agent,name=systemd 0 0
pstore /sys/fs/pstore pstore rw,seclabel,nosuid,nodev,noexec,relatime 0 0
cgroup /sys/fs/cgroup/devices cgroup rw,nosuid,nodev,noexec,relatime,devices 0 0
cgroup /sys/fs/cgroup/pids cgroup rw,nosuid,nodev,noexec,relatime,pids 0 0
cgroup /sys/fs/cgroup/hugetlb cgroup rw,nosuid,nodev,noexec,relatime,hugetlb 0 0
cgroup /sys/fs/cgroup/cpu,cpuacct cgroup rw,nosuid,nodev,noexec,relatime,cpu,cpuacct 0 0
cgroup /sys/fs/cgroup/perf_event cgroup rw,nosuid,nodev,noexec,relatime,perf_event 0 0
cgroup /sys/fs/cgroup/blkio cgroup rw,nosuid,nodev,noexec,relatime,blkio 0 0
cgroup /sys/fs/cgroup/memory cgroup rw,nosuid,nodev,noexec,relatime,memory 0 0
cgroup /sys/fs/cgroup/net_cls,net_prio cgroup rw,nosuid,nodev,noexec,relatime,net_cls,net_prio 0 0
cgroup /sys/fs/cgroup/freezer cgroup rw,nosuid,nodev,noexec,relatime,freezer 0 0
cgroup /sys/fs/cgroup/cpuset cgroup rw,nosuid,nodev,noexec,relatime,cpuset 0 0
configfs /sys/kernel/config configfs rw,relatime 0 0
/dev/mapper/fedora_teste--bacula-root / xfs rw,seclabel,relatime,attr2,inode64,noquota 0 0
selinuxfs /sys/fs/selinux selinuxfs rw,relatime 0 0
systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=27,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=17800 0 0
mqueue /dev/mqueue mqueue rw,seclabel,relatime 0 0
debugfs /sys/kernel/debug debugfs rw,seclabel,relatime 0 0
hugetlbfs /dev/hugepages hugetlbfs rw,seclabel,relatime 0 0
/dev/vda1 /boot ext4 rw,seclabel,relatime,data=ordered 0 0
tmpfs /tmp tmpfs rw,seclabel,nosuid,nodev 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0
10.45.0.51:/vol/bacula2 /home/bacula nfs rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=10.45.0.51,mountvers=3,mountport=4046,mountproto=udp,local_lock=none,addr=10.45.0.51 0 0
tmpfs /run/user/0 tmpfs rw,seclabel,nosuid,nodev,relatime,size=404204k,mode=700 0 0
Comment 3 Tomáš Golembiovský 2017-10-04 18:08:42 EDT
Unfortunately this gives no clue about the origin of the error. The content looks as expected.

Can you confirm, that you are still experiencing the issue and see the errors in the log? Note that the error should be repeated every five minutes (which is the default period for the operation).
Comment 4 marciofoz 2017-10-17 06:27:46 EDT
Hello Tomas

I employed more time to check it again and do some steps; after the steps the agent back working.

-remove & reinstall agent (still with error);
-update os;

I believe the problem was solved after os update, no after remove & install agent.., but the packages in this server is updated weekly.

Best regards.
Comment 5 Tomáš Golembiovský 2017-10-17 07:36:19 EDT
(In reply to marciofoz from comment #4)
> Hello Tomas
> 
> I employed more time to check it again and do some steps; after the steps
> the agent back working.

I'm glad to hear that

> I believe the problem was solved after os update

That was probably it. Unfortunately now we'll never know the origin of the error.

I'm going to close this bug now. Feel free to reopen it should the problem appear again.
Comment 6 Ross 2017-11-07 16:17:31 EST
I'll add additional data here since i just ran into this issue on a relatively fresh/new debian 9.2 install and doing apt install ovirt-guest-agent package.

The error log/report is correct:
=start
Dummy-3::ERROR::2017-11-07 15:53:03,054::GuestAgentLinux2::383::root::Error retrieving disks usages.
Traceback (most recent call last):
  File "/usr/share/ovirt-guest-agent/GuestAgentLinux2.py", line 375, in getDisksUsage
    statvfs = os.statvfs(path)
OSError: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
=end

And here's the permissions of the folder.  Note the directory (in this case "tracing") was created as 700 at some point (probably OS install).

Additionally the /sys/kernel/debug directory is also missing group/other read+execute permissions (ie: was created 0x700 as well).

So the guest agent is unable to read anything from it as it's executing as uid=ovirtagent.

Doing a "sudo chmod ga+rw /sys/kernel/debug /sys/kernel/debug/tracing" fixed the error.

Not sure if this is an error on how OGA drops privs, or an OS level bug/setting.

=start 
root@server:/# ls -la /sys/kernel/debug/tracing/
total 0
drwx------  6 root root 0 Oct 31 10:38 .
drwx------ 23 root root 0 Oct 31 10:38 ..
-r--r--r--  1 root root 0 Oct 31 10:38 available_events
-r--r--r--  1 root root 0 Oct 31 10:38 available_filter_functions
-r--r--r--  1 root root 0 Oct 31 10:38 available_tracers
-rw-r--r--  1 root root 0 Oct 31 10:38 buffer_size_kb
-r--r--r--  1 root root 0 Oct 31 10:38 buffer_total_size_kb
-rw-r--r--  1 root root 0 Oct 31 10:38 current_tracer
-r--r--r--  1 root root 0 Oct 31 10:38 dyn_ftrace_total_info
-r--r--r--  1 root root 0 Oct 31 10:38 enabled_functions
drwxr-xr-x 63 root root 0 Oct 31 10:38 events
--w-------  1 root root 0 Oct 31 10:38 free_buffer
drwxr-xr-x  2 root root 0 Oct 31 10:38 instances
-rw-r--r--  1 root root 0 Oct 31 10:38 kprobe_events
-r--r--r--  1 root root 0 Oct 31 10:38 kprobe_profile
-rw-r--r--  1 root root 0 Oct 31 10:38 max_graph_depth
drwxr-xr-x  2 root root 0 Oct 31 10:38 options
drwxr-xr-x 18 root root 0 Oct 31 10:38 per_cpu
-r--r--r--  1 root root 0 Oct 31 10:38 printk_formats
-r--r--r--  1 root root 0 Oct 31 10:38 README
-r--r--r--  1 root root 0 Oct 31 10:38 saved_cmdlines
-rw-r--r--  1 root root 0 Oct 31 10:38 saved_cmdlines_size
-rw-r--r--  1 root root 0 Oct 31 10:38 set_event
-rw-r--r--  1 root root 0 Oct 31 10:38 set_event_pid
-rw-r--r--  1 root root 0 Oct 31 10:38 set_ftrace_filter
-rw-r--r--  1 root root 0 Oct 31 10:38 set_ftrace_notrace
-rw-r--r--  1 root root 0 Oct 31 10:38 set_ftrace_pid
-r--r--r--  1 root root 0 Oct 31 10:38 set_graph_function
-r--r--r--  1 root root 0 Oct 31 10:38 set_graph_notrace
-rw-r--r--  1 root root 0 Oct 31 10:38 snapshot
-rw-r--r--  1 root root 0 Oct 31 10:38 stack_max_size
-r--r--r--  1 root root 0 Oct 31 10:38 stack_trace
-r--r--r--  1 root root 0 Oct 31 10:38 stack_trace_filter
-rw-r--r--  1 root root 0 Oct 31 10:38 trace
-rw-r--r--  1 root root 0 Oct 31 10:38 trace_clock
--w--w----  1 root root 0 Oct 31 10:38 trace_marker
-rw-r--r--  1 root root 0 Oct 31 10:38 trace_options
-r--r--r--  1 root root 0 Oct 31 10:38 trace_pipe
-rw-r--r--  1 root root 0 Oct 31 10:38 tracing_cpumask
-rw-r--r--  1 root root 0 Oct 31 10:38 tracing_max_latency
-rw-r--r--  1 root root 0 Oct 31 10:38 tracing_on
-rw-r--r--  1 root root 0 Oct 31 10:38 tracing_thresh
-rw-r--r--  1 root root 0 Oct 31 10:38 uprobe_events
-r--r--r--  1 root root 0 Oct 31 10:38 uprobe_profile
=end
Comment 7 Tomáš Golembiovský 2017-11-08 04:00:44 EST
(In reply to Ross from comment #6)
> I'll add additional data here since i just ran into this issue on a
> relatively fresh/new debian 9.2 install and doing apt install
> ovirt-guest-agent package.

Thanks!
> 
> Not sure if this is an error on how OGA drops privs, or an OS level
> bug/setting.

We have to figure out why is OGA even trying to access that 

Could you also share the content of /proc/mounts, if you have the VM still available?
Comment 8 Ross 2017-11-08 13:08:10 EST
(In reply to Tomáš Golembiovský from comment #7)
> Could you also share the content of /proc/mounts, if you have the VM still
> available?

Sure - here you go:

-= start
sysfs /sys sysfs rw,nosuid,nodev,noexec,relatime 0 0
proc /proc proc rw,nosuid,nodev,noexec,relatime 0 0
udev /dev devtmpfs rw,nosuid,relatime,size=465044k,nr_inodes=116261,mode=755 0 0
devpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0
tmpfs /run tmpfs rw,nosuid,noexec,relatime,size=95232k,mode=755 0 0
/dev/sda1 / ext4 rw,relatime,errors=remount-ro,data=ordered 0 0
securityfs /sys/kernel/security securityfs rw,nosuid,nodev,noexec,relatime 0 0
tmpfs /dev/shm tmpfs rw,nosuid,nodev 0 0
tmpfs /run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0
tmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,mode=755 0 0
cgroup /sys/fs/cgroup/systemd cgroup rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd 0 0
pstore /sys/fs/pstore pstore rw,nosuid,nodev,noexec,relatime 0 0
cgroup /sys/fs/cgroup/blkio cgroup rw,nosuid,nodev,noexec,relatime,blkio 0 0
cgroup /sys/fs/cgroup/cpuset cgroup rw,nosuid,nodev,noexec,relatime,cpuset 0 0
cgroup /sys/fs/cgroup/perf_event cgroup rw,nosuid,nodev,noexec,relatime,perf_event 0 0
cgroup /sys/fs/cgroup/net_cls,net_prio cgroup rw,nosuid,nodev,noexec,relatime,net_cls,net_prio 0 0
cgroup /sys/fs/cgroup/memory cgroup rw,nosuid,nodev,noexec,relatime,memory 0 0
cgroup /sys/fs/cgroup/cpu,cpuacct cgroup rw,nosuid,nodev,noexec,relatime,cpu,cpuacct 0 0
cgroup /sys/fs/cgroup/devices cgroup rw,nosuid,nodev,noexec,relatime,devices 0 0
cgroup /sys/fs/cgroup/pids cgroup rw,nosuid,nodev,noexec,relatime,pids 0 0
cgroup /sys/fs/cgroup/freezer cgroup rw,nosuid,nodev,noexec,relatime,freezer 0 0
debugfs /sys/kernel/debug debugfs rw,relatime 0 0
hugetlbfs /dev/hugepages hugetlbfs rw,relatime 0 0
mqueue /dev/mqueue mqueue rw,relatime 0 0
systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=37,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=9363 0 0
configfs /sys/kernel/config configfs rw,relatime 0 0
/dev/sdb1 /data ext4 rw,relatime,errors=remount-ro,data=ordered 0 0
tracefs /sys/kernel/debug/tracing tracefs rw,relatime 0 0
binfmt_misc /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
tmpfs /run/user/1000 tmpfs rw,nosuid,nodev,relatime,size=95228k,mode=700,uid=1000,gid=1000 0 0
-=end

And here's a "df -h" just in case:

-=start
Filesystem      Size  Used Avail Use% Mounted on
udev            455M     0  455M   0% /dev
tmpfs            93M   11M   83M  12% /run
/dev/sda1       8.8G  2.7G  5.7G  32% /
tmpfs           465M     0  465M   0% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           465M     0  465M   0% /sys/fs/cgroup
/dev/sdb1        49G  5.1G   42G  11% /data
tmpfs            93M     0   93M   0% /run/user/1000
-=end
Comment 9 Tomáš Golembiovský 2017-11-08 13:39:30 EST
(In reply to Ross from comment #8)

> tracefs /sys/kernel/debug/tracing tracefs rw,relatime 0 0

This is our source of trouble. We should ignore tracefs. Thanks Ross.
Comment 10 Ross 2017-11-08 13:47:11 EST
Yeah, just noticed that as well.

For anyone else hitting this via google searches:

Quick fix is to add "tracefs" to your ovirt-guest-agent.conf "ignored_fs" line.
Comment 11 Tomáš Golembiovský 2017-11-12 18:01:16 EST
Will be in 1.0.15

Note You need to log in before you can comment on or make changes to this bug.