so_cal
asked on
Linux VM running slow, receiving INFO: task : blocked for more than 120 seconds errors
Oracle Linux 7.1 Running on VMware vSphere 5.5.
“INFO: task [process]:xxxxx blocked for more than 120 seconds.” Seems like out of memory issues, resource starvation often around disk access. It might be a kernel setting. I don't know.
Here is some logging from the machine:
root@nas01abcxyz001 log]# less /var/log/messages
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811a6554>] mnt_want_write+0x24/0x50
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8119691f>] do_last+0xbaf/0x10c0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81196ee2>] path_openat+0xb2/0x4b0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81192c79>] ? putname+0x29/0x40
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811978cf>] ? user_path_at_empty+0x5f/0x 90
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81197a28>] do_filp_open+0x38/0x80
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157dc9e>] ? _raw_spin_lock+0xe/0x20
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811a453f>] ? __alloc_fd+0xaf/0x140
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81186ef4>] do_sys_open+0xe4/0x1c0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81186ff1>] sys_open+0x21/0x30
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81586239>] system_call_fastpath+0x16/ 0x1b
Jul 19 07:07:33 nas01abcxyz001 kernel: INFO: task oracle:28959 blocked for more than 120 seconds.
Jul 19 07:07:33 nas01abcxyz001 kernel: "echo 0 > /proc/sys/kernel/hung_task _timeout_s ecs" disables this message.
Jul 19 07:07:33 nas01abcxyz001 kernel: oracle D ffff88042fc13100 0 28959 1 0x00000080
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff8802ad2adc38 0000000000000082 ffff880427df2540 ffff8802ad2adfd8
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff8802ad2adfd8 ffff8802ad2adfd8 ffff880427df2540 ffff88082a0d4000
Jul 19 07:07:33 nas01abcxyz001 kernel: 0000000000000001 0000000000000001 0000000000000000 ffff88082a0d4308
Jul 19 07:07:33 nas01abcxyz001 kernel: Call Trace:
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157c839>] schedule+0x29/0x70
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81189a82>] __sb_start_write+0xb2/0x10 0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81081d10>] ? wake_up_bit+0x30/0x30
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8112ab1a>] generic_file_write_iter+0x 4a/0xd0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffffa0802fed>] ext4_file_write_iter+0x7d/ 0x310 [ext4]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8120f349>] ? sys_semtimedop+0x489/0xac0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811873b2>] do_aio_write+0xa2/0xd0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811875ad>] do_sync_write+0x9d/0xd0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81187c06>] vfs_write+0xa6/0x180
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81187f42>] sys_pwrite64+0x72/0xb0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81586239>] system_call_fastpath+0x16/ 0x1b
Jul 19 07:07:33 nas01abcxyz001 kernel: INFO: task oracle:28961 blocked for more than 120 seconds.
Jul 19 07:07:33 nas01abcxyz001 kernel: "echo 0 > /proc/sys/kernel/hung_task _timeout_s ecs" disables this message.
Jul 19 07:07:33 nas01abcxyz001 kernel: oracle D ffff88042fd13100 0 28961 1 0x00000080
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff880822769c38 0000000000000082 ffff880822698380 ffff880822769fd8
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff880822769fd8 ffff880822769fd8 ffff880822698380 ffff88082a0d4000
Jul 19 07:07:33 nas01abcxyz001 kernel: 0000000000000001 0000000000000001 0000000000000000 ffff88082a0d4308
Jul 19 07:07:33 nas01abcxyz001 kernel: Call Trace:
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157c839>] schedule+0x29/0x70
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81189a82>] __sb_start_write+0xb2/0x10 0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81081d10>] ? wake_up_bit+0x30/0x30
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8112ab1a>] generic_file_write_iter+0x 4a/0xd0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffffa0802fed>] ext4_file_write_iter+0x7d/ 0x310 [ext4]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8120f0cc>] ? sys_semtimedop+0x20c/0xac0
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811873b2>] do_aio_write+0xa2/0xd0
I don't know how to resolve this. Please let me know what additional information you need to hep assist me in this. Thanks.
“INFO: task [process]:xxxxx blocked for more than 120 seconds.” Seems like out of memory issues, resource starvation often around disk access. It might be a kernel setting. I don't know.
Here is some logging from the machine:
root@nas01abcxyz001 log]# less /var/log/messages
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811a6554>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8119691f>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81196ee2>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81192c79>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811978cf>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81197a28>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157dc9e>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811a453f>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81186ef4>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81186ff1>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81586239>]
Jul 19 07:07:33 nas01abcxyz001 kernel: INFO: task oracle:28959 blocked for more than 120 seconds.
Jul 19 07:07:33 nas01abcxyz001 kernel: "echo 0 > /proc/sys/kernel/hung_task
Jul 19 07:07:33 nas01abcxyz001 kernel: oracle D ffff88042fc13100 0 28959 1 0x00000080
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff8802ad2adc38 0000000000000082 ffff880427df2540 ffff8802ad2adfd8
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff8802ad2adfd8 ffff8802ad2adfd8 ffff880427df2540 ffff88082a0d4000
Jul 19 07:07:33 nas01abcxyz001 kernel: 0000000000000001 0000000000000001 0000000000000000 ffff88082a0d4308
Jul 19 07:07:33 nas01abcxyz001 kernel: Call Trace:
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157c839>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81189a82>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81081d10>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8112ab1a>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffffa0802fed>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8120f349>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811873b2>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811875ad>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81187c06>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81187f42>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81586239>]
Jul 19 07:07:33 nas01abcxyz001 kernel: INFO: task oracle:28961 blocked for more than 120 seconds.
Jul 19 07:07:33 nas01abcxyz001 kernel: "echo 0 > /proc/sys/kernel/hung_task
Jul 19 07:07:33 nas01abcxyz001 kernel: oracle D ffff88042fd13100 0 28961 1 0x00000080
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff880822769c38 0000000000000082 ffff880822698380 ffff880822769fd8
Jul 19 07:07:33 nas01abcxyz001 kernel: ffff880822769fd8 ffff880822769fd8 ffff880822698380 ffff88082a0d4000
Jul 19 07:07:33 nas01abcxyz001 kernel: 0000000000000001 0000000000000001 0000000000000000 ffff88082a0d4308
Jul 19 07:07:33 nas01abcxyz001 kernel: Call Trace:
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8157c839>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81189a82>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff81081d10>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8112ab1a>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffffa0802fed>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff8120f0cc>]
Jul 19 07:07:33 nas01abcxyz001 kernel: [<ffffffff811873b2>]
I don't know how to resolve this. Please let me know what additional information you need to hep assist me in this. Thanks.
you will have to look in the VM folder on the datastore which contains this VM
I think your problem is with the whole virtual machine rather than Oracle.
How do you have such a high level of logging from VMWare? That is likely to slow down your VM. especially it will slow it down if you have configured syslogd to sync log messages to disk (which is the default). To avoid syncing to disk, preface the log file path with a minus sign in /etc/syslogd.conf or whatever your system uses. Example
How do you have such a high level of logging from VMWare? That is likely to slow down your VM. especially it will slow it down if you have configured syslogd to sync log messages to disk (which is the default). To avoid syncing to disk, preface the log file path with a minus sign in /etc/syslogd.conf or whatever your system uses. Example
# Everything is logged here.
*.debug -/var/log/debug
there must be another folder on datastore because that folder is missing config files
Are the log entries in the original Q from the VM or the host? Either way, there will be config files, usually in or somewhere below /etc on the system concerned. This is in the Linux file system - you need to get an xterm and investigate. The datastore is just for Oracle, right?
ASKER
Duncan, I don't see a syslogd.conf, but I do see a sysctl.conf. Should I use that one?
Andrew, I've looked through the Datastores above, didn't see one that contains config files.
Duncan, the log entries are from the VM. There are four VMs on the host machine. Here is what's in /etc
Yes, the datastore is just for Oracle. Should I use any xterm? Why do I need it. How would I use it? How is it going to help?
Andrew, I've looked through the Datastores above, didn't see one that contains config files.
Duncan, the log entries are from the VM. There are four VMs on the host machine. Here is what's in /etc
[root@nas01abcxyz001 etc]# ls
adjtime idmapd.conf rc0.d
aliases init.d rc1.d
aliases.db inittab rc2.d
alternatives inputrc rc3.d
anacrontab iproute2 rc4.d
asound.conf iscsi rc5.d
audisp issue rc6.d
audit issue.net rc.d
avahi java rc.local
bash_completion.d jvm rcS.d
bashrc jvm-commmon rdma
binfmt.d kdump.conf redhat-release
chkconfig.d kernel request-key.conf
cron.d krb5.conf request-key.d
cron.daily kshrc resolv.conf
cron.deny ld.so.cache rpc
cron.hourly ld.so.conf rpm
cron.monthly ld.so.conf.d rsyncd.conf
crontab libaudit.conf rsyslog.conf
cron.weekly libnl rsyslog.d
crypttab libuser.conf rwtab
csh.cshrc locale.conf rwtab.d
csh.login localtime samba
cups login.defs sasl2
datto logrotate.conf securetty
dbus-1 logrotate.d security
default lvm selinux
depmod.d machine-id services
dhcp magic sestatus.conf
DIR_COLORS mailcap shadow
DIR_COLORS.256color makedumpfile.conf.sample shadow-
DIR_COLORS.lightbgcolor man_db.conf shells
dkms maven skel
dnsmasq.conf mime.types ssh
dnsmasq.d mke2fs.conf ssl
dracut.conf modprobe.d statetab
dracut.conf.d modules-load.d statetab.d
e2fsck.conf motd subversion
environment mtab sudo.conf
ethertypes multipath sudoers
exports netconfig sudoers.d
exports.d NetworkManager sudo-ldap.conf
favicon.png networks sysconfig
filesystems nfsmount.conf sysctl.conf
firewalld nsswitch.conf sysctl.confe
fonts nsswitch.conf.bak sysctl.d
fstab openldap systemd
gconf opt system-release
gcrypt oracle-release system-release-cpe
gdbinit oraInst.loc tcsd.conf
gdbinit.d oratab terminfo
ghostscript os-release tmpfiles.d
gnupg pam.d trusted-key.key
GREP_COLORS passwd tuned
groff passwd- udev
group pkcs11 vconsole.conf
group- pki virc
grub2.cfg plymouth vmware-tools
grub.d pm webmin
gshadow polkit-1 wgetrc
gshadow- popt.d wpa_supplicant
gss postfix X11
gssproxy ppp xdg
host.conf prelink.conf.d xinetd.d
hostname printcap yum
HOSTNAME profile yum.conf
hosts profile.d yum.repos.d
hosts.allow protocols
hosts.deny pulse
Yes, the datastore is just for Oracle. Should I use any xterm? Why do I need it. How would I use it? How is it going to help?
SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
ASKER
So which one do I put a - (minus sign) in front of?:
# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.* /dev/console
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages
# The authpriv file has restricted access.
authpriv.* /var/log/secure
# Log all the mail messages in one place.
mail.* -/var/log/maillog
# Log cron stuff
cron.* /var/log/cron
# Everybody gets emergency messages
*.emerg :omusrmsg:*
# Save news errors of level crit and higher in a special file.
uucp,news.crit /var/log/spooler
# Save boot messages also to boot.log
local7.* /var/log/boot.log
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
ASKER
Ok, done. We'll see if this improves the performance of this VM.
Hey so_cal,
Any progress?
Any progress?
ASKER
It seems to have helped. I think I'm going to close this thread now. Thanks Duncan.
ASKER
Thank you, it helped.
screenshot of the datastore folder, and I can check.