df -h command result to late

S

soolan

Member
Joined
Jan 13, 2023
Messages
66
Reaction score
4
Credits
626
df -h output comes too late. What should I check?

OS oracle linux 7.9

HP gen 9 server

There was an error on the flash disc I connected from ibm storage, it was processed, but the umount operation was not done.
 
Last edited:


hmmm, I think I already asked in another post you made but again you have to tell us what you are using and what constitutes "too late"
 
soolan said:
df -h output comes too late. What should I check?
Click to expand...
Pretty snappy here:
Code: 
[flip@flop ~]$ time df -h

Filesystem      Size  Used Avail Use% Mounted on
udev            7.7G     0  7.7G   0% /dev
tmpfs           1.6G  1.6M  1.6G   1% /run
/dev/nvme0n1p3  443G   11G  409G   3% /
tmpfs           7.7G     0  7.7G   0% /dev/shm
tmpfs           5.0M   12K  5.0M   1% /run/lock
efivarfs        192K   99K   89K  53% /sys/firmware/efi/efivars
/dev/nvme0n1p1  476M  5.9M  470M   2% /boot/efi
tmpfs           1.6G  2.5M  1.6G   1% /run/user/1000

real    0m0.005s
user    0m0.000s
sys     0m0.003s
 
osprey said:
Pretty snappy here:
Code: 
[flip@flop ~]$ time df -h

Filesystem      Size  Used Avail Use% Mounted on
udev            7.7G     0  7.7G   0% /dev
tmpfs           1.6G  1.6M  1.6G   1% /run
/dev/nvme0n1p3  443G   11G  409G   3% /
tmpfs           7.7G     0  7.7G   0% /dev/shm
tmpfs           5.0M   12K  5.0M   1% /run/lock
efivarfs        192K   99K   89K  53% /sys/firmware/efi/efivars
/dev/nvme0n1p1  476M  5.9M  470M   2% /boot/efi
tmpfs           1.6G  2.5M  1.6G   1% /run/user/1000

real    0m0.005s
user    0m0.000s
sys     0m0.003s
Click to expand...
real 0m30.879s
user 0m0.002s
sys 0m0.004s
 
brian@brian-desktop:~$ time df -h
Filesystem Size Used Avail Use% Mounted on
tmpfs 3.2G 1.7M 3.2G 1% /run
/dev/nvme0n1p2 228G 28G 189G 13% /
tmpfs 16G 53M 16G 1% /dev/shm
tmpfs 5.0M 4.0K 5.0M 1% /run/lock
tmpfs 16G 0 16G 0% /run/qemu
/dev/nvme0n1p1 511M 13M 499M 3% /boot/efi
tmpfs 3.2G 116K 3.2G 1% /run/user/1000
/dev/sdc1 920G 291G 583G 34% /media/brian/TV, Zilla,Timesh
/dev/sdc3 928G 37G 892G 4% /media/brian/Important stuff

real 0m0.005s
user 0m0.004s
sys 0m0.000s
brian@brian-desktop:~$
 
Soolan, that output of over 30 seconds shown in post #5 for the df command is quite abnormal in my view ... and likely yours too :) .

To investigate what the delay may be caused by, you can use the strace command to see what is happening with all the system calls that the df command is making, and perhaps find an unusually large time interval which may be explanatory of this anomaly.

With that suggestion in mind, perhaps run strace to track the df command, with an option that records the time it takes to make each system call, on its way to producing the output of the df command. And have strace record its output in a file that you can inspect. For example, run:
Code: 
strace --syscall-times -o dfTraceFile.txt df -h
strace, in this command, will record to the level of "us" (thousandths of a second), the time it takes to make each system call, and lodge the results in the file dfTraceFile.txt.

On this machine here, here is some of the output:
Code: 
1 execve("/usr/bin/df", ["df", "-h"], 0x7ffdc48f6550 /* 39 vars */) = 0 <0.000554>
  2 brk(NULL)                               = 0x56236475c000 <0.000031>
  3 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f3ca7f6e000 <0.000041>
  4 access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory) <0.000020>
  5 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000024>
  6 newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=69335, ...}, AT_EMPTY_PATH) = 0 <0.000020>
  7 mmap(NULL, 69335, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f3ca7f5d000 <0.000025>
  8 close(3)                                = 0 <0.000015>
  9 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000020>
 10 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220x\2\0\0\0\0\0"..., 832) = 832 <0.000018>
<snip>
100 statfs("/tmp/.mount_LibreW1c5Vc7", {f_type=FUSE_SUPER_MAGIC, f_bsize=512, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0    , f_ffree=0, f_fsid={val=[0, 0]}, f_namelen=255, f_frsize=512, f_flags=ST_VALID|ST_RDONLY|ST_NOSUID|ST_NODEV|ST_RELATI    ME}) = 0 <0.000135>
101 newfstatat(1, "", {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0xa), ...}, AT_EMPTY_PATH) = 0 <0.000017>
102 write(1, "Filesystem      Size  Used Avail"..., 49) = 49 <0.000022>
103 write(1, "udev            7.7G     0  7.7G"..., 43) = 43 <0.000016>
104 write(1, "tmpfs           1.6G  1.6M  1.6G"..., 43) = 43 <0.000020>
105 write(1, "/dev/nvme0n1p3  443G   12G  409G"..., 40) = 40 <0.000016>
106 write(1, "tmpfs           7.7G     0  7.7G"..., 47) = 47 <0.000031>
107 write(1, "tmpfs           5.0M   12K  5.0M"..., 48) = 48 <0.000017>
108 write(1, "efivarfs        192K   99K   89K"..., 64) = 64 <0.000024>
109 write(1, "/dev/nvme0n1p1  476M  5.9M  470M"..., 48) = 48 <0.000025>
110 write(1, "tmpfs           1.6G  2.5M  1.6G"..., 53) = 53 <0.000018>
111 close(1)                                = 0 <0.000016>
112 close(2)                                = 0 <0.000015>
113 exit_group(0)                           = ?
114 +++ exited with 0 +++

The lines are numbered so you can see what's been snipped. The file on my machine is printed in colour, and the times for each system call, are highlighted in green, but without colour in the above output, you can see the times at the end of each line that begins with the system call it's timing. For example, 0.000554, is 554 ten-thousandths of a second.

The times of the "write" system calls which produce the actual output text, which starts at line 102, are also given.

This approach is the first one I would try to try and get a handle on that bad time delay. Perhaps see what you can find.
 
Last edited:
osprey said:
Soolan, df komutu için 5. mesajda mevcut 30 saniyenin üzerinde çıktı benim görüşüme göre oldukça anormal... ve muhtemelen sizinki de :) .

Gecikmenin nedeninin ne olduğunu araştırmak için strace imkanını kullanarak df sağladığın tüm sistem çağrılarında neler olup bittiğini görebilir ve belki de bu anormalliği açıklayabilecek düzeyde büyük bir zaman aralığını bulabilirsiniz.

Bu öneriyi akılda tutarak, df miktarının çıkışını üretme yolunda her sistem biriminin yapılması için geçen süreyi kaydeden bir seçenekle birlikte df anaparasını izlemek için strace temelde çalıştırabilirsiniz. Strace'in çıkmasını inceleyebilecek bir dosyaya kaydetmesini sağlayın. Örneğin şunun çalıştırılması:
[kod]
strace --sistem çapı-zamanları -o duTraceFile.txt df -h
[/kod]
strace, bu komutta, her sistem programının yapılması için geçen süreyi "biz" düzeyinde (saniyenin binde biri) kaydedecek ve sonuçları dfTraceFile.txt dosyasına yerleştirecektir.

makinede çıkanların bir kısmı burada:
[kod]
1 execve("/usr/bin/df", ["df", "-h"], 0x7ffdc48f6550 /* 39 değişken */) = 0 <0,000554>
2 brk(BOŞ) = 0x56236475c000 <0,000031>
3 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f3ca7f6e000 <0,000041>
4 erişim("/etc/ld.so.preload", R_OK) = -1 ENOENT (Böyle bir dosya veya dizin yok) <0.000020>
5 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0,000024>
6 newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=69335, ...}, AT_EMPTY_PATH) = 0 <0,000020>
7 mmap(NULL, 69335, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f3ca7f5d000 <0,000025>
8 kapat(3) = 0 <0,000015>
9 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 <0,000020>
10 okuma(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220x\ 2\0\0\0\0\0"..., 832) = 832 <0,000018>
<kesinti>
100 statfs("/tmp/.mount_LibreW1c5Vc7", {f_type=FUSE_SUPER_MAGIC, f_bsize=512, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0 , f_ffree=0, f_fsid={val=[0, 0] }, f_namelen=255, f_frsize=512, f_flags=ST_VALID|ST_RDONLY|ST_NOSUID|ST_NODEV|ST_RELATI ME}) = 0 <0,000135>
101 newfstatat(1, "", {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0xa), ...}, AT_EMPTY_PATH) = 0 <0,000017>
102 write(1, "Kullanılan Dosya Sistemi Boyutu Mevcut"..., 49) = 49 <0.000022>
103 write(1, "udev 7.7G 0 7.7G"..., 43) = 43 <0.000016>
104 write(1, "tmpfs 1.6G 1.6M 1.6G"..., 43) = 43 <0.000020>
105 write(1, "/dev/nvme0n1p3 443G 12G 409G"..., 40) = 40 <0,000016>
106 write(1, "tmpfs 7.7G 0 7.7G"..., 47) = 47 <0.000031>
107 write(1, "tmpfs 5,0M 12K 5,0M"..., 48) = 48 <0,000017>
108 write(1, "efivarfs 192K 99K 89K"..., 64) = 64 <0,000024>
109 write(1, "/dev/nvme0n1p1 476M 5,9M 470M"..., 48) = 48 <0,000025>
110 write(1, "tmpfs 1,6G 2,5M 1,6G"..., 53) = 53 <0,000018>
111 kapat(1) = 0 <0,000016>
112 kapat(2) = 0 <0,000015>
113 çıkış_grubu(0) = ?
114 +++ 0 +++ ile çıkıldı
[/kod]

Satırlar numaralandırılmıştır, böylece nasıl kesildiğini görebilirsiniz. Makinedeki dosya renkli yazdırılıyor ve sistem ekranının saatleri yeşil renkle vurgulanıyor, ancak silindiğinde renk olmadan, sistem ekranıyla başlayan bölümlerinin son saatlerini görebilirsiniz. . Örneğin 0,000554, saniyenin onbinde biri olan 554'tür.

102. satırdan başlayan gerçek çıktı metnini üreten "yazma" sistem çağrılarının konfigürasyonları verilmektedir.

Bu alternatif, bu kötü zaman gecikmesini çözmenin ilk çözümüdür. Belki ne seçebilirsiniz bakın.
Click to expand...
strace --syscall -times -o strace.txt df -h
strace: invalid option -- '-'
Try 'strace -h' for more information.
 
soolan said:
strace --syscall -times -o strace.txt df -h
strace: invalid option -- '-'
Try 'strace -h' for more information.
Click to expand...
I am still not seeing enough information to help you. You finally let me know the delay and yes 30 seconds is pretty bad but if you can show us the actual outpus of the df -h command it would be helpful. It can tell what may be taking time. You may have a communication issue as df -h will give you networked drives also. maybe try df -h -l and see if that is faster if is it is then it is a network drive that is the issue.
You can't be so afraid to share information that will help you. The results of the command will not allow us to hack you.
 
soolan said:
strace --syscall -times -o strace.txt df -h
strace: invalid option -- '-'
Try 'strace -h' for more information.
Click to expand...
There shouldn't be any gap in the option: --syscall-times! It's a long option. Check the manpage for confirmation.
 
soolan said:
There was an error on the flash disc I connected from ibm storage, it was processed, but the umount operation was not done.
Click to expand...
Usually when you run df and hangs for a long time before giving output or returning something it's because of a stale network share. What does your /etc/fstab look like and what type of network storage is it?
 
f33dm3bits said:
Usually when you run df and hangs for a long time before giving output or returning something it's because of a stale network share. What does your /etc/fstab look like and what type of network storage is it?
Click to expand...
That’s a good shout. Also, the OP mentioned something about an error on the drive. A failing disk can increase the time that df takes too. Might be worth checking the SMART data for the drive if it’s a SSD/HDD. If it’s starting to fail, or if there are problems/inconsistencies with the file-system, that could definitely cause issues.

And as that storage device is on a network, is it likely to be dealing with a lot of simultaneous throughput from other users on the network?

If so, and the drive is doing a lot of read/writes at the time you’re running df on it, that could potentially slow things down. If other users/processes are using the drive and it’s under a heavy load, it may take some time for df to be able to get the information from the drive. Because it has to wait for other users processes to finish accessing the drive before it can query it.
 
f33dm3bits said:
Usually when you run df and hangs for a long time before giving output or returning something it's because of a stale network share. What does your /etc/fstab look like and what type of network storage is it?
Click to expand...
Code: 
[root@server1 ~]# cat  /etc/fstab

#
# /etc/fstab
# Created by anaconda on Fri Dec  3 23:44:36 2021
#
# Accessible filesystems, by reference, are maintained under '/dev/disk'
# See man pages fstab(5), findfs(8), mount(8) and/or blkid(8) for more info
#
/dev/mapper/ol-root     /                       xfs     defaults        0 0
UUID=81ebc7e4-31f6-4c9c-ac10-7a9699b57be9 /boot                   ext4    defaults        1 2
UUID=1A7E-D50D          /boot/efi               vfat    umask=0077,shortname=winnt 0 0
/dev/mapper/ol-swap     swap                    swap    defaults        0 0
 
JasKinasis said:
That’s a good shout. Also, the OP mentioned something about an error on the drive. A failing disk can increase the time that df takes too. Might be worth checking the SMART data for the drive if it’s a SSD/HDD. If it’s starting to fail, or if there are problems/inconsistencies with the file-system, that could definitely cause issues.

And as that storage device is on a network, is it likely to be dealing with a lot of simultaneous throughput from other users on the network?

If so, and the drive is doing a lot of read/writes at the time you’re running df on it, that could potentially slow things down. If other users/processes are using the drive and it’s under a heavy load, it may take some time for df to be able to get the information from the drive. Because it has to wait for other users processes to finish accessing the drive before it can query it.
Click to expand...
This!

@soolan You keep creating topics about server stuff and sysadmin stuff, I'm getting the idea this is for your job? Why are you treating a forum like your free support desk, since you a running Enterprise Linux you should be able to figure out these issues together with your colleagues?
 
Likely some sort of filesystem corruption, device failure, or a bad link to a storage device / array. Especially given you noted issues with your ibm storage array.
 
f33dm3bits said:
Bu!

@soolan Sunucu işleri ve sistem yöneticisi işleri hakkında konular oluşturmaya devam ediyorsunuz, bunun işiniz için olduğu fikrine kapılıyorum? Enterprise Linux çalıştıran bir şirket olduğunuza göre bu sorunları meslektaşlarınızla birlikte çözebilmeniz gerektiğine göre neden bir forumu ücretsiz destek masanız gibi görüyorsunuz?
Click to expand...
I thought the forum was for sharing information. Yes, this is a problem I have at work, but I did not know that I was forbidden to post it here as a topic.

Apart from these, I also write the problems that occur on my own devices. I also write the solutions I apply to the topics.

As a result, if this issue is solved here, won't another user who comes here solve his own problem by following this issue?

If it is still prohibited, the topic can be closed. You can also block my account.
 
soolan said:
I thought the forum was for sharing information. Yes, this is a problem I have at work, but I did not know that I was forbidden to post it here as a topic.
Click to expand...
It's not forbidden to post server stuff or work stuff, but in my opinion work related is better solved in the work environment together with your colleagues and if needed with RHEL or Oracle support not on a forum. And so far it seemed to me that you are treating a forum as a support desk because of all your topics being work related so far, but since you are just saying that you are just sharing information I will take your word for it. I'm not sure what others or the mods think about this, just expressing my opinion not here for a fight.
 
Last edited:
I agree with my friend above ^^^, but no, it's not prohibited.

Chris Turner
wizardfromoz
 
You must log in or register to reply here.

Staff online

Members online

Total: 748 (members: 4, guests: 744)

Latest posts

Top