Finding the source of disk write
-
Hi,
I'm running pfSense in a virtual machine environment. The install is given its own partition as if it were a disk, and monitoring disk writes the the partition, it appears 200-500KB are being written once every 20s or so. How can I find out what is causing the writes from inside pfSense?
Cheers,
Yax
-
Probably monitoring stuff RRD and such. I run embedded installs usually though, those shouldn't do that.
-
Login to the console and drop to the shell (option 8).
run top -a
then press "m" to switch to toggle IO mode.
-
Hi,
Cheers for the responses.
top -a (m) shows that apinger is doing I/O most frequently, but that does not correlate with what I see when I run ls -lt in /var/log
[2.0.1-RELEASE][root@pfsense]/var/log(9): ls -lt total 2010 -rw------- 1 root wheel 511488 Aug 21 12:24 filter.log -rw------- 1 root wheel 512144 Aug 21 12:18 system.log -rw-r--r-- 1 root wheel 56028 Aug 21 12:15 lastlog -rw------- 1 root wheel 65535 Aug 21 12:03 apinger.log -rw------- 1 root wheel 65535 Aug 21 07:53 dhcpd.log -rw-r--r-- 1 root wheel 3573 Aug 16 23:43 lighttpd.error.log -rw------- 1 root wheel 65535 Aug 11 12:47 openvpn.log -rw------- 1 root wheel 568 Aug 11 12:47 userlog -rw-r--r-- 1 root wheel 5004 Aug 11 12:47 dmesg.boot -rw------- 1 root wheel 65535 Aug 11 12:47 ipsec.log -rw------- 1 root wheel 50688 Aug 11 12:47 l2tps.log -rw------- 1 root wheel 65535 Aug 11 12:47 lighttpd.log -rw------- 1 root wheel 65535 Aug 11 12:47 ntpd.log -rw------- 1 root wheel 50688 Aug 11 12:47 poes.log -rw------- 1 root wheel 65535 Aug 11 12:47 portalauth.log -rw------- 1 root wheel 65535 Aug 11 12:47 ppp.log -rw------- 1 root wheel 50688 Aug 11 12:47 pptps.log -rw------- 1 root wheel 65535 Aug 11 12:47 relayd.log -rw------- 1 root wheel 65535 Aug 11 12:47 slbd.log -rw------- 1 root wheel 65535 Aug 11 12:47 vpn.log -rw------- 1 root wheel 65535 Aug 11 12:47 wireless.log [2.0.1-RELEASE][root@pfsense]/var/log(10):It appears filter.log is being written most frequently. It is not RRD graphs, because I have have disabled it. Is there any way to disable writes to filter.log? Most of what I see are lines like this:
Aug 20 20:19:45 pfsense pf: 00:00:53.137812 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 12887, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 20 20:19:45 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 20 20:20:57 pfsense pf: 00:01:12.301496 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 20 20:20:57 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 20 20:21:50 pfsense pf: 00:00:52.695957 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 12905, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 20 20:21:50 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 20 20:23:03 pfsense pf: 00:01:12.743444 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 20 20:23:03 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 20 20:23:55 pfsense pf: 00:00:52.254273 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 12912, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 20 20:23:55 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 20 20:25:08 pfsense pf: 00:01:13.184872 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 20 20:25:08 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 20 20:26:00 pfsense pf: 00:00:51.812918 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 12919, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 20 20:26:00 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s]But even this does not appear to be that frequent, or a few hundred KB of data.
I am concerned because this is an SSD install in a virtual machine. While the SSD does have plenty of space, iostat from linux tells me pfSense has written far more data than anything else (approx 4GB, not sure if this is since last boot or not, if so, thats in 9 days).
avg-cpu: %user %nice %system %iowait %steal %idle 0.00 0.00 0.63 0.00 0.02 99.35 Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn sda 0.40 0.36 6.17 312197 5323758 sda1 0.00 0.00 0.00 732 0 sda2 0.00 0.00 0.00 1712 9 sda3 0.04 0.21 0.47 178966 409280 sda4 0.31 0.08 5.40 68716 4664924 sda5 0.03 0.07 0.29 61339 249545It might also explain the apparent increase CPU activity of the pfSense machine compared to the others:
Name ID Mem VCPUs State Time(s) Domain-0 0 15267 8 r----- 6634.8 jumpBox 1 512 1 -b---- 804.3 pfSense 2 256 1 -b---- 273107.2For completeness, a capture of top -a (m)
last pid: 48049; load averages: 0.00, 0.00, 0.00 up 9+23:48:08 12:34:35 56 processes: 1 running, 55 sleeping CPU: 0.4% user, 0.0% nice, 0.0% system, 0.0% interrupt, 99.6% idle Mem: 65M Active, 21M Inact, 49M Wired, 396K Cache, 24M Buf, 92M Free Swap: PID USERNAME VCSW IVCSW READ WRITE FAULT TOTAL PERCENT COMMAND 10979 root 10 4 0 1 0 1 100.00% /usr/local/sbin/apinger -c /var/etc/apinger.conf 29304 root 6 6 0 0 0 0 0.00% /usr/local/sbin/openvpn --config /var/etc/openvpn/server1.conf 47754 dhcpd 4 0 0 0 0 0 0.00% /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dh 24525 root 2 0 0 0 0 0 0.00% /usr/sbin/tcpdump -s 256 -v -l -n -e -ttt -i pflog0 59643 root 2 0 0 0 0 0 0.00% /usr/local/sbin/lighttpd -f /var/etc/lighty-webConfigurator.co 15857 root 0 0 0 0 0 0 0.00% /usr/local/sbin/miniupnpd -f /var/etc/miniupnpd.conf -P /var/r 50054 root 0 0 0 0 0 0 0.00% /usr/local/bin/php 49606 root 0 0 0 0 0 0 0.00% /usr/local/bin/php 49891 root 0 0 0 0 0 0 0.00% /usr/local/bin/php 61667 root 0 0 0 0 0 0 0.00% /usr/sbin/syslogd -c -c -l /var/dhcpd/var/run/log -f /var/etc/ 10289 _ntp 0 0 0 0 0 0 0.00% ntpd: ntp engine (ntpd) 10617 root 0 0 0 0 0 0 0.00% ntpd: [priv] (ntpd) 43080 nobody 0 0 0 0 0 0 0.00% /usr/local/sbin/dnsmasq --local-ttl 1 --all-servers --rebind-l 24722 root 0 0 0 0 0 0 0.00% logger -t pf -p local0.info 56631 root 0 0 0 0 0 0 0.00% /usr/local/bin/rrdtool - 32563 root 0 0 0 0 0 0 0.00% /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local 49536 root 0 0 0 0 0 0 0.00% /usr/sbin/cron -s 9369 root 0 0 0 0 0 0 0.00% dhclient: em0 [priv] (dhclient) 14920 _dhcp 0 0 0 0 0 0 0.00% dhclient: em0 (dhclient) 30913 root 0 0 0 0 0 0 0.00% /usr/sbin/inetd -wW -R 0 -a 127.0.0.1 /var/etc/inetd.conf 243 root 0 0 0 0 0 0 0.00% /usr/local/sbin/check_reload_status 21031 root 1 0 0 0 0 0 0.00% top -aI'll be honest, I don't really know how to interpret the columns for the above, but I observed that apinger was frequently hitting 100% in the PERCENT column.
Regards,
Yax
-
The apinger is the gateway monitoring, you can disable that under System::Routing per gateway.
The other is the firewall logs under Status: System logs: Settingsas far as I know, both should be on a ramdisk on the embedded install.
-
Hi,
Cheers for the response. I disabled gateway monitoring and the amount being written appears to have reduced, but I don't see where in status->system logs->settings I can disable filter logging. (log packets blocked by the default rule was already unchecked) I can see an option which says "disable writing log files to local ram disk" which is unchecked. If I look in the firewall tab, it shows no entries "Last 0 firewall log entries. Max(50) " - I have not clicked the clear log button and I have no filter. top -a(m) now does not show any I/O activity at all, but I still have considerable writes to the disk:
[root@domain0 ~]# iostat -p sda 10 | grep sda4 sda4 0.31 0.07 5.38 68800 5108040 sda4 0.00 0.00 0.00 0 0 sda4 0.90 0.00 20.80 0 208 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.60 0.00 13.60 0 136 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.80 0.00 20.40 0 204 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.30 0.00 6.00 0 60 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 1.10 0.00 35.20 0 352 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 1.10 0.00 30.40 0 304 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.50 0.00 11.60 0 116 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.80 0.00 18.80 0 188 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.40 0.00 11.20 0 112 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.10 0.00 2.00 0 20 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 1.20 0.00 26.80 0 268 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0I am also still seeing writes to filter.log:
[2.0.1-RELEASE][root@pfsense]/var/log(21): ls -lt total 2010 -rw------- 1 root wheel 511488 Aug 22 12:46 filter.log -rw------- 1 root wheel 512144 Aug 22 12:21 system.log -rw-r--r-- 1 root wheel 56028 Aug 22 12:20 lastlog -rw------- 1 root wheel 65535 Aug 22 12:13 apinger.log -rw------- 1 root wheel 65535 Aug 22 10:58 dhcpd.log -rw-r--r-- 1 root wheel 4031 Aug 22 08:14 lighttpd.error.log -rw------- 1 root wheel 65535 Aug 11 12:47 openvpn.log -rw------- 1 root wheel 568 Aug 11 12:47 userlog -rw-r--r-- 1 root wheel 5004 Aug 11 12:47 dmesg.boot -rw------- 1 root wheel 65535 Aug 11 12:47 ipsec.log -rw------- 1 root wheel 50688 Aug 11 12:47 l2tps.log -rw------- 1 root wheel 65535 Aug 11 12:47 lighttpd.log -rw------- 1 root wheel 65535 Aug 11 12:47 ntpd.log -rw------- 1 root wheel 50688 Aug 11 12:47 poes.log -rw------- 1 root wheel 65535 Aug 11 12:47 portalauth.log -rw------- 1 root wheel 65535 Aug 11 12:47 ppp.log -rw------- 1 root wheel 50688 Aug 11 12:47 pptps.log -rw------- 1 root wheel 65535 Aug 11 12:47 relayd.log -rw------- 1 root wheel 65535 Aug 11 12:47 slbd.log -rw------- 1 root wheel 65535 Aug 11 12:47 vpn.log -rw------- 1 root wheel 65535 Aug 11 12:47 wireless.logWrites look like this:
Aug 22 12:31:44 pfsense pf: 00:00:14.178134 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24167, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:31:44 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:33:35 pfsense pf: 00:01:51.261149 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:33:35 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:33:49 pfsense pf: 00:00:13.736819 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24188, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:33:49 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:35:41 pfsense pf: 00:01:51.702464 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:35:41 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:35:54 pfsense pf: 00:00:13.295136 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24194, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:35:54 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:37:46 pfsense pf: 00:01:52.144122 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:37:46 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:37:59 pfsense pf: 00:00:12.853590 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24199, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:37:59 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:39:51 pfsense pf: 00:01:52.585662 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:39:51 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:40:04 pfsense pf: 00:00:12.412132 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24206, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:40:04 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:41:57 pfsense pf: 00:01:53.027084 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:41:57 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:42:09 pfsense pf: 00:00:11.970590 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24227, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:42:09 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:44:02 pfsense pf: 00:01:53.468705 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:44:02 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:44:14 pfsense pf: 00:00:11.529038 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24234, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:44:14 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] Aug 22 12:46:08 pfsense pf: 00:01:53.910163 rule 36/8(ip-option): pass in on em1: (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) Aug 22 12:46:08 pfsense pf: 0.0.0.0 > 224.0.0.1: igmp query v2 Aug 22 12:46:19 pfsense pf: 00:00:11.087591 rule 35/8(ip-option): pass in on em0: (tos 0xc0, ttl 1, id 24241, offset 0, flags [DF], proto IGMP (2), length 36, options (RA)) Aug 22 12:46:19 pfsense pf: 192.168.1.254 > 224.0.0.1: igmp query v3 [max resp time 24s] ength 32, options (RA))What does "rules 35/8" mean? All my filter rules have logging disabled.
I am not running embedded install, but I am running full install.
Cheers,
Yax
-
The first thing top shows is average activity for each process, is that correct?
top -I -a -mio -s40 last pid: 23779; load averages: 0.00, 0.00, 0.00 up 1+22:02:42 11:56:09 60 processes: 2 running, 58 sleeping CPU: % user, % nice, % system, % interrupt, % idle Mem: 66M Active, 21M Inact, 47M Wired, 144K Cache, 24M Buf, 94M Free Swap: PID USERNAME VCSW IVCSW READ WRITE FAULT TOTAL PERCENT COMMAND 30770 root 59296 22873 1 0 0 1 0.08% /usr/local/sbin/openvpn --config /var/etc/openvpn/server1.conf 44997 root 166905 10202 81 156 67 304 23.90% /usr/local/sbin/lighttpd -f /var/etc/lighty-webConfigurator.co 24801 root 165740 166 3 0 12 15 1.18% /usr/sbin/tcpdump -s 256 -v -l -n -e -ttt -i pflog0 52956 root 1556 2218 13 294 1 308 24.21% /usr/local/bin/php 21923 root 6656 5198 0 2 0 2 0.16% /usr/local/sbin/miniupnpd -f /var/etc/miniupnpd.conf -P /var/r 52464 root 1083 1982 51 96 2 149 11.71% /usr/local/bin/php 52603 root 711 1764 40 286 3 329 25.86% /usr/local/bin/php 625 root 2444 28 0 7 0 7 0.55% /usr/sbin/syslogd -c -c -l /var/dhcpd/var/run/log -f /var/etc/ 43542 root 1384 6 0 2 0 2 0.16% /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local 15695 _dhcp 1461 525 0 12 0 12 0.94% dhclient: em0 (dhclient) 33101 _dhcp 842 688 0 12 0 12 0.94% dhclient: em0 (dhclient) 243 root 657 260 0 2 1 3 0.24% /usr/local/sbin/check_reload_status 32986 root 184 70 1 0 0 1 0.08% /usr/sbin/inetd -wW -R 0 -a 127.0.0.1 /var/etc/inetd.conf 49566 root 16 156 0 15 0 15 1.18% /usr/local/bin/php 52249 root 16 142 0 15 0 15 1.18% /usr/local/bin/php 45365 root 16 77 0 15 0 15 1.18% /usr/local/bin/php 42213 nobody 120 44 0 1 0 1 0.08% /usr/local/sbin/dnsmasq --local-ttl 1 --all-servers --rebind-l 44117 root 96 0 0 3 0 3 0.24% /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /etc 50571 root 20 15 16 0 1 17 1.34% login [pam] (login) 8660 root 22 9 0 2 0 2 0.16% /usr/sbin/sshd 51262 root 8 10 2 0 1 3 0.24% -sh (sh) 41571 root 57 4 0 53 0 53 4.17% /usr/local/sbin/dhcpleases -l /var/dhcpd/var/db/dhcpd.leases - 44546 root 5 0 0 2 0 2 0.16% /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.p 46882 dhcpd 2 6 0 1 0 1 0.08% /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhBut if I leave that top update after 40s, top shows nothing. In fact, I cannot trace any activity via top now, even though
iostat -I -d -x -z 30 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 3090.0 88099.0 44093.0 1432770.0 0 1.5 0 md0 54.0 15280.0 196.5 233674.5 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 13.0 0.0 208.0 0 3.3 0 md0 0.0 1.0 0.0 16.0 0 0.5 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.8 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 2.0 0.0 32.0 0 0.6 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.6 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 51.0 0.0 634.0 0 5.1 0 md0 0.0 2.0 0.0 28.0 0 0.4 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 5.0 0.0 80.0 0 1.1 0 md0 0.0 1.0 0.0 16.0 0 0.4 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 3.0 0.0 48.0 0 1.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 12.0 0.0 192.0 0 2.9 0 md0 0.0 1.0 0.0 16.0 0 0.5 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 2.0 0.0 32.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 5.0 0.0 80.0 0 1.5 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 2.0 0.0 32.0 0 0.8 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 1.1 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 2.0 0.0 32.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 15.0 0.0 240.0 0 3.9 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 9.0 0.0 144.0 0 2.5 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 3.0 0.0 48.0 0 0.6 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 3.0 0.0 48.0 0 0.8 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 2.0 0.0 32.0 0 0.6 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 3.0 0.0 48.0 0 0.7 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 36.0 0.0 436.0 0 2.8 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 15.0 0.0 212.0 0 3.1 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 7.0 0.0 112.0 0 1.5 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 8.0 0.0 128.0 0 1.7 0 md0 0.0 1.0 0.0 16.0 0 0.0 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 3.0 0.0 48.0 0 0.9 0 extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b extended device statistics device r/i w/i kr/i kw/i wait svc_t %b ad0 0.0 1.0 0.0 16.0 0 0.7 0iostat shows considerable activity in some 30s intervals (and sometimes none). Does anybody have any idea what is generating this activity?
-
So a considerable source of disk writes were coming from igmp logging (which I wasn't able to stop through the web UI, but I have a workaround, details here http://forum.pfsense.org/index.php/topic,52887.0.html)
However, a lot of disk writes are still coming from somewhere. I appreciate I could just install nanoBSD-VGA version, but I would actually rather find the source of disk writes. I also feel that there shouldn't be unexplained disk activity occurring on the system.Sep 14 08:14:50 pfsense dhclient: RENEW Sep 14 08:14:50 pfsense dhclient: Creating resolv.conf Sep 14 08:14:57 pfsense dhclient: RENEW Sep 14 08:14:57 pfsense dhclient: Creating resolv.conf Sep 14 08:44:20 pfsense dhclient: RENEW Sep 14 08:44:20 pfsense dhclient: Creating resolv.conf Sep 14 08:44:27 pfsense dhclient: RENEW Sep 14 08:44:27 pfsense dhclient: Creating resolv.conf Sep 14 09:13:50 pfsense dhclient: RENEW Sep 14 09:13:50 pfsense dhclient: Creating resolv.conf Sep 14 09:13:57 pfsense dhclient: RENEW Sep 14 09:13:57 pfsense dhclient: Creating resolv.conf Sep 14 09:43:20 pfsense dhclient: RENEW Sep 14 09:43:20 pfsense dhclient: Creating resolv.conf Sep 14 09:43:27 pfsense dhclient: RENEW Sep 14 09:43:27 pfsense dhclient: Creating resolv.conf Sep 14 10:12:50 pfsense dhclient: RENEW Sep 14 10:12:50 pfsense dhclient: Creating resolv.conf Sep 14 10:12:57 pfsense dhclient: RENEW Sep 14 10:12:57 pfsense dhclient: Creating resolv.conf Sep 14 10:42:20 pfsense dhclient: RENEW Sep 14 10:42:20 pfsense dhclient: Creating resolv.conf Sep 14 10:42:27 pfsense dhclient: RENEW Sep 14 10:42:27 pfsense dhclient: Creating resolv.conf Sep 14 11:07:52 pfsense sshd[43374]: Accepted keyboard-interactive/pam for root from #### port 37867 ssh2 Sep 14 11:11:51 pfsense dhclient: RENEW Sep 14 11:11:51 pfsense dhclient: Creating resolv.conf Sep 14 11:11:57 pfsense dhclient: RENEW Sep 14 11:11:57 pfsense dhclient: Creating resolv.conf Sep 14 11:14:28 pfsense php: /index.php: Successful webConfigurator login for user #### Sep 14 11:14:28 pfsense php: /index.php: Successful webConfigurator login for user #### Sep 14 11:28:18 pfsense sshd[47927]: Accepted keyboard-interactive/pam for root from #### port 37956 ssh2The above are contents of system.log - based on this, I am confident this is not being written to frequently enough to show the disk activity I am seeing.
[2.0.1-RELEASE][root@pfsense]/var/log(8): ls -lt; date total 1482 -rw------- 1 root wheel 512144 Sep 14 11:28 system.log -rw-r--r-- 1 root wheel 56028 Sep 14 11:28 lastlog -rw------- 1 root wheel 65535 Sep 14 07:46 dhcpd.log -rw-r--r-- 1 root wheel 3075 Sep 14 00:49 lighttpd.error.log -rw------- 1 root wheel 65535 Sep 11 08:06 openvpn.log -rw------- 1 root wheel 65535 Sep 8 02:17 apinger.log -rw------- 1 root wheel 568 Sep 6 12:54 userlog -rw-r--r-- 1 root wheel 5004 Sep 6 12:54 dmesg.boot -rw------- 1 root wheel 65535 Sep 6 12:54 ipsec.log -rw------- 1 root wheel 50688 Sep 6 12:54 l2tps.log -rw------- 1 root wheel 65535 Sep 6 12:54 lighttpd.log -rw------- 1 root wheel 65535 Sep 6 12:54 ntpd.log -rw------- 1 root wheel 50688 Sep 6 12:54 poes.log -rw------- 1 root wheel 65535 Sep 6 12:54 portalauth.log -rw------- 1 root wheel 65535 Sep 6 12:54 ppp.log -rw------- 1 root wheel 50688 Sep 6 12:54 pptps.log -rw------- 1 root wheel 65535 Sep 6 12:54 relayd.log -rw------- 1 root wheel 65535 Sep 6 12:54 slbd.log -rw------- 1 root wheel 65535 Sep 6 12:54 vpn.log -rw------- 1 root wheel 65535 Sep 6 12:54 wireless.log Fri Sep 14 11:34:25 BST 2012 [2.0.1-RELEASE][root@pfsense]/var/log(9):But this is the sort of activity I see at 30s intervals:
[root@host ~]# iostat -p /dev/sda 30 | grep sda4 sda4 0.14 0.10 2.70 69728 1840648 sda4 0.10 0.00 1.33 0 40 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.40 0.00 8.53 0 256 sda4 0.00 0.00 0.00 0 0 sda4 0.13 0.00 2.67 0 80 sda4 0.53 0.00 21.07 0 632 sda4 0.00 0.00 0.00 0 0 sda4 0.33 0.00 8.80 0 264 sda4 0.17 0.00 3.87 0 116 sda4 0.00 0.00 0.00 0 0 sda4 0.40 0.00 8.53 0 256 sda4 0.00 0.00 0.00 0 0 sda4 0.03 0.00 0.67 0 20 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.00 0.00 0.00 0 0 sda4 0.23 0.67 4.93 20 148Which is still far too high in my opinion, particularly when I cannot identify the source.
I would be grateful if any further assistance could be provided in helping me to identify the cause.
-
I've found the following 0 byte files that are being written pretty often (no idea what with, or why the writes are so large)
[2.0.1-RELEASE][root@pfsense]/var/log(33): find / -type f | xargs ls -lt | head -n 2 -rw-r--r-- 1 root wheel 0 Sep 19 17:15 /tmp/tmpHOSTS -rw-r--r-- 1 root wheel 0 Sep 19 17:15 /var/db/currentipsecpinghosts [2.0.1-RELEASE][root@pfsense]/var/log(34):How can I stop these files being written?
Cheers,
Yax