Upgrade causes php swap error - 2.1 - upgrade-20120925-1207

apmuthu · Sep 26, 2012, 3:57 PM

Downloads from:
http://snapshots.pfsense.org/FreeBSD_RELENG_8_3/i386/pfSense_HEAD/updates/

On a Soekris 4801 with 128 MB RAM with a CF using:
pfSense-2.1-BETA0-4g-i386-nanobsd_vga-20120923-*.img.gz

Upgraded firmware from console with:
pfSense-2.1-BETA0-4g-i386-nanobsd-upgrade-20120925-1207.img.gz

The config is set to upgrade non-signed images.

The dashboard still shows 23rd Sep instead of 25th as the firmware date.

php runs out of swap space with

pid 29444 (php), uid 0, was killed: out of swap space

The following is the crash report:

Crash report begins.  Anonymous machine information:

i386
8.3-RELEASE-p4
FreeBSD 8.3-RELEASE-p4 #0: Sun Sep 23 02:05:26 EDT 2012     root@snapshots-8_3-i386.builders.pfsense.org:/usr/obj./usr/pfSensesrc/src/sys/pfSense_wrap.8.i386

Crash report details:

PHP Errors:
[26-Sep-2012 14:13:03 UTC] PHP Fatal error:  Cannot redeclare file_notice() (previously declared in /etc/inc/notices.inc:55) in /etc/inc/notices.inc on line 91
[26-Sep-2012 14:14:03 UTC] PHP Fatal error:  Cannot redeclare file_notice() (previously declared in /etc/inc/notices.inc:55) in /etc/inc/notices.inc on line 91


# sysctl -a | grep -i memory

Virtual Memory:         (Total: 2264220K Active: 151096K)
Real Memory:            (Total: 89140K Active: 41776K)
Shared Virtual Memory:  (Total: 24324K Active: 18044K)
Shared Real Memory:     (Total: 9508K Active: 7620K)
Free Memory Pages:      9616K
hw.cbb.start_memory: 2281701376
p1003_1b.memory_protection: 0
p1003_1b.shared_memory_objects: 200112

# swapoff -a && swapon -a
# sysctl -a | grep -i memory

Virtual Memory:         (Total: 2257780K Active: 144656K)
Real Memory:            (Total: 83968K Active: 36604K)
Shared Virtual Memory:  (Total: 23212K Active: 16932K)
Shared Real Memory:     (Total: 9276K Active: 7388K)
Free Memory Pages:      14832K
hw.cbb.start_memory: 2281701376
p1003_1b.memory_protection: 0
p1003_1b.shared_memory_objects: 200112

jimp · Sep 26, 2012, 4:29 PM

What packages are you running?

a stock system wouldn't be using nearly that much ram+swap.

apmuthu · Sep 27, 2012, 11:36 AM

Stock system + nano pkg
disabled APC and ACPI
WebConfigurator sessions from 2 -> 3.

jimp · Sep 27, 2012, 12:46 PM

Please show the full output of:

cat /var/log/dmesg.boot

ps uxawww

apmuthu · Sep 27, 2012, 6:47 PM

cat /var/log/dmesg.boot


8

[0;1;33m[[0;1;37m2.1-BETA0[0;1;33m][0;1;33m[1m[[0;1;37mroot[0;1;31m@[0;1;37mfwmachine.fws.local.com[0;1;33m][0;1;32m[m/root[0;1;33m([0;1;37m1[0;1;33m)[0;1;36m[0;1;31m:[0;40;37m cat /var/log/dmesg.boot

Copyright (c) 1992-2012 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.3-RELEASE-p4 #0: Sun Sep 23 02:05:26 EDT 2012
    root@snapshots-8_3-i386.builders.pfsense.org:/usr/obj./usr/pfSensesrc/src/sys/pfSense_wrap.8.i386 i386
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Geode(TM) Integrated Processor by National Semi (266.65-MHz 586-class CPU)
  Origin = "Geode by NSC"  Id = 0x540  Family = 5  Model = 4  Stepping = 0
  Features=0x808131 <fpu,tsc,msr,cx8,cmov,mmx>real memory  = 134217728 (128 MB)
avail memory = 108036096 (103 MB)
wlan: mac acl policy registered
cryptosoft0: <software crypto=""> on motherboard
padlock0: No ACE support.
pcib0: <host to="" pci="" bridge=""> pcibus 0 on motherboard
pci0: <pci bus=""> on pcib0
sis0: <natsemi 10="" dp8381[56]="" 100basetx=""> port 0xe100-0xe1ff mem 0xa0000000-0xa0000fff irq 10 at device 6.0 on pci0
sis0: Silicon Revision: DP83816A
miibus0: <mii bus=""> on sis0
nsphyter0: <dp83815 10="" 100="" media="" interface=""> PHY 0 on miibus0
nsphyter0:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
sis0: [ITHREAD]
sis1: <natsemi 10="" dp8381[56]="" 100basetx=""> port 0xe200-0xe2ff mem 0xa0001000-0xa0001fff irq 10 at device 7.0 on pci0
sis1: Silicon Revision: DP83816A
miibus1: <mii bus=""> on sis1
nsphyter1: <dp83815 10="" 100="" media="" interface=""> PHY 0 on miibus1
nsphyter1:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
sis1: [ITHREAD]
sis2: <natsemi 10="" dp8381[56]="" 100basetx=""> port 0xe300-0xe3ff mem 0xa0002000-0xa0002fff irq 10 at device 8.0 on pci0
sis2: Silicon Revision: DP83816A
miibus2: <mii bus=""> on sis2
nsphyter2: <dp83815 10="" 100="" media="" interface=""> PHY 0 on miibus2
nsphyter2:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
sis2: [ITHREAD]
Geode Soekris net4801 comBIOS ver. 1.33 20080103 Copyright (C) 2000-2007
isab0: <pci-isa bridge=""> port 0x6100-0x613f,0x6200-0x623f at device 18.0 on pci0
isa0: <isa bus=""> on isab0
pci0: <bridge> at device 18.1 (no driver attached)
atapci0: <national geode="" sc1100="" ata33="" controller=""> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xe000-0xe00f at device 18.2 on pci0
ata0: <ata channel=""> at channel 0 on atapci0
ata0: [ITHREAD]
ata1: <ata channel=""> at channel 1 on atapci0
ata1: [ITHREAD]
Timecounter "Geode" frequency 27000000 Hz quality 1000
pci0: <bridge> at device 18.5 (no driver attached)
ohci0: <ohci (generic)="" usb="" controller=""> mem 0xa0003000-0xa0003fff irq 11 at device 19.0 on pci0
ohci0: [ITHREAD]
usbus0: <ohci (generic)="" usb="" controller=""> on ohci0
cpu0 on motherboard
atrtc0: <at real="" time="" clock=""> at port 0x70 irq 8 on isa0
ppc0: parallel port not found.
uart0: <16550 or compatible> at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
uart0: [FILTER]
uart0: console (19200,n,8,1)
uart1: <16550 or compatible> at port 0x2f8-0x2ff irq 3 on isa0
uart1: [FILTER]
Timecounters tick every 10.000 msec
IPsec: Initialized Security Association Processing.
usbus0: 12Mbps Full Speed USB v1.0
ad0: 3811MB <cf card="" 4gb="" ver6.04k=""> at ata0-master PIO4
ugen0.1: <0x0e11> at usbus0
uhub0: <0x0e11 OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
uhub0: 3 ports with 3 removable, self powered
Trying to mount root from ufs:/dev/ufs/pfsense0
WARNING: / was not properly dismounted
[0;1;33m[[0;1;37m2.1-BETA0[0;1;33m][0;1;33m[1m[[0;1;37mroot[0;1;31m@[0;1;37mfwmachine.fws.local.com[0;1;33m][0;1;32m[m/root[0;1;33m([0;1;37m2[0;1;33m)
[/code]

[b]ps uxawww[/b]

[code]
USER     PID %CPU %MEM   VSZ   RSS  TT  STAT STARTED      TIME COMMAND
root      10 100.0  0.0     0     8  ??  RL    1:02AM   2:20.73 [idle]
root       0  0.0  0.1     0    56  ??  DLs   1:02AM   0:00.01 [kernel]
root       1  0.0  0.4  1888   448  ??  ILs   1:02AM   0:00.09 /sbin/init --
root       2  0.0  0.0     0     8  ??  DL    1:02AM   0:00.03 [g_event]
root       3  0.0  0.0     0     8  ??  DL    1:02AM   0:00.89 [g_up]
root       4  0.0  0.0     0     8  ??  DL    1:02AM   0:01.06 [g_down]
root       5  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [crypto]
root       6  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [crypto returns]
root       7  0.0  0.0     0     8  ??  DL    1:02AM   0:00.01 [pfpurge]
root       8  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [xpt_thrd]
root       9  0.0  0.0     0     8  ??  DL    1:02AM   0:01.14 [pagedaemon]
root      11  0.0  0.1     0    96  ??  WL    1:02AM   0:16.77 [intr]
root      12  0.0  0.0     0     8  ??  DL    1:02AM   0:00.01 [ng_queue]
root      13  0.0  0.0     0     8  ??  DL    1:02AM   0:01.55 [yarrow]
root      14  0.0  0.0     0    32  ??  DL    1:02AM   0:00.01 [usb]
root      15  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [vmdaemon]
root      16  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [idlepoll]
root      17  0.0  0.0     0     8  ??  DL    1:02AM   0:00.00 [pagezero]
root      18  0.0  0.0     0     8  ??  DL    1:02AM   0:00.01 [bufdaemon]
root      19  0.0  0.0     0     8  ??  DL    1:02AM   0:00.05 [syncer]
root      20  0.0  0.0     0     8  ??  DL    1:02AM   0:00.01 [vnlru]
root      21  0.0  0.0     0     8  ??  DL    1:02AM   0:00.01 [softdepflush]
root      29  0.0  0.0     0     8  ??  DL    1:02AM   0:00.10 [md0]
root      35  0.0  0.0     0     8  ??  DL    1:02AM   0:01.80 [md1]
root     283  0.0  0.8  3416   900  ??  INs   1:02AM   0:03.13 /usr/local/sbin/check_reload_status
root     286  0.0  0.7  3416   740  ??  IN    1:02AM   0:00.00 check_reload_status: Monitoring daemon of check_reload_status
root     296  0.0  1.7  3936  1924  ??  Is    1:03AM   0:00.04 /sbin/devd
root    5486  0.0  0.7  3328   728  ??  Is    1:03AM   0:00.00 /usr/local/sbin/choparp sis0 auto 202.150.210.171/32 202.150.210.172/32 202.150.210.173/32
root    8911  0.0  1.5  4976  1644  ??  Ss    1:03AM   0:00.34 /usr/sbin/syslogd -c -c -l /var/dhcpd/var/run/log -f /var/etc/syslog.conf
root   10852  0.0  1.0  3448  1088  ??  Is    1:03AM   0:00.03 /usr/sbin/inetd -wW -R 0 -a 127.0.0.1 /var/etc/inetd.conf
root   14020  0.0  1.7  5344  1852  ??  Is    1:03AM   0:00.01 /usr/sbin/sshd
root   14296  0.0  0.8  3544   904  ??  Is    1:03AM   0:00.06 /usr/local/sbin/sshlockout_pf 15
root   15254  0.0  0.9  3328   996  ??  Ss    1:03AM   0:00.28 /usr/local/sbin/apinger -c /var/etc/apinger.conf
root   15528  0.0  1.1  4600  1156  ??  I     1:03AM   0:00.10 rrdtool -
root   19542  0.0  2.5  5712  2712  ??  S     1:03AM   0:00.76 /usr/local/sbin/lighttpd -f /var/etc/lighty-webConfigurator.conf
root   19817  0.0  8.3 20940  9152  ??  I     1:03AM   0:01.03 /usr/local/bin/php
root   20496  0.0  8.3 20940  9156  ??  I     1:03AM   0:01.03 /usr/local/bin/php
root   20674  0.0  9.5 22988 10508  ??  I     1:03AM   0:05.00 /usr/local/bin/php
dhcpd  27493  0.0  3.7  8448  4120  ??  Is    1:03AM   0:00.00 /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpd.conf -pf /var/run/dhcpd.pid sis1
nobody 28429  0.0  1.8  5568  1992  ??  S     1:03AM   0:00.08 /usr/local/sbin/dnsmasq --local-ttl 1 --all-servers --rebind-localhost-ok --stop-dns-rebind --dns-forward-max=5000 --cache-size=10000
root   32031  0.0  2.3  7452  2500  ??  Is    1:04AM   0:00.44 /usr/local/sbin/mpd4 -b -d /var/etc/pptp-vpn -p /var/run/pptp-vpn.pid -s pptps pptps
root   35008  0.0  1.0  3420  1048  ??  Is    1:04AM   0:00.03 /usr/sbin/cron -s
root   36334  0.0  0.7  3328   728  ??  Is    1:04AM   0:00.01 /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local/bin/ping_hosts.sh
root   36544  0.0  0.7  3328   744  ??  I     1:04AM   0:00.00 minicron: helper /usr/local/bin/ping_hosts.sh  (minicron)
root   36832  0.0  0.7  3328   728  ??  Is    1:04AM   0:00.01 /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /etc/rc.expireaccounts
root   37012  0.0  0.7  3328   744  ??  I     1:04AM   0:00.00 minicron: helper /etc/rc.expireaccounts  (minicron)
root   37041  0.0  0.7  3328   728  ??  Is    1:04AM   0:00.01 /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid /etc/rc.update_alias_url_data
root   37305  0.0  0.7  3328   744  ??  I     1:04AM   0:00.00 minicron: helper /etc/rc.update_alias_url_data  (minicron)
root   51243  0.0  0.9  3548  1020  ??  S     1:06AM   0:00.04 /usr/sbin/ntpdate -s -t 5 0.pfsense.pool.ntp.org
root    9153  0.0  1.2  5928  1304  u0- S     1:03AM   0:00.08 /usr/sbin/tcpdump -s 256 -v -l -n -e -ttt -i pflog0
root    9440  0.0  0.6  3328   656  u0- I     1:03AM   0:00.02 logger -t pf -p local0.info
root   21358  0.0  0.9  3708   956  u0- I     1:03AM   0:00.08 /bin/sh /usr/local/sbin/ntpdate_sync_once.sh
root   39998  0.0  1.2  3784  1328  u0  Is    1:04AM   0:00.17 login [pam] (login)
root   45119  0.0  0.9  3708  1028  u0  I     1:04AM   0:00.06 -sh (sh)
root   46638  0.0  0.9  3708  1040  u0  I     1:04AM   0:00.06 /bin/sh /etc/rc.initial
root   49845  0.0  2.0  4760  2152  u0  S     1:05AM   0:00.16 /bin/tcsh
root   51428  0.0  0.9  3468   948  u0  R+    1:06AM   0:00.03 ps uxawww
[0;1;33m[[0;1;37m2.1-BETA0[0;1;33m][0;1;33m[1m[[0;1;37mroot[0;1;31m@[0;1;37mfwmachine.fws.local.com[0;1;33m][0;1;32m[m/root[0;1;33m([0;1;37m3[0;1;33m)[0;1;36m[0;1;31m:[0;40;37m 
[/code]
[/code]</cf></at></ohci></ohci></bridge></ata></ata></national></bridge></isa></pci-isa></dp83815></mii></natsemi></dp83815></mii></natsemi></dp83815></mii></natsemi></pci></host></software></fpu,tsc,msr,cx8,cmov,mmx>

jimp · Sep 27, 2012, 6:50 PM

OK I was initially reading those numbers wrong…

So you've only got 128MB of RAM there... And it's using even more than that in swap.

Is that on a wrap?

I'm not sure any effort is being made to maintain support for such a low power device on 2.1, at least not during an active development phase.

apmuthu · Sep 27, 2012, 8:22 PM

Thought as much!

Thanks for the info.

Checked out m0n0wall v1.8 beta 515 (lacks OpenVPN and does not accept special characters in passwords) and it supports IPv6 quite well and just needs 64MB and the existing 128 MB would be generous for it.

There should be a v2.0.2 now to just bundle in the IPv6 as it is already here in Singapore and other ASEAN countries. Users are now migrating away from pfSense sensing this delay. The php / lighttpd now gets killed after 5 swap errors in the dmesg in a fresh embedded 4g install today (27th).

jimp · Sep 27, 2012, 8:27 PM

2.1 is for IPv6. There is going to be a 2.0.2 but without IPv6, far far too much has changed to simple backport that. The main reason for 2.1 is IPv6.

The WRAP is a many, many years old discontinued device. If you get a larger box to run it on it should work fine.

m0n0wall is great at what it does, so that would probably be a better fit for the WRAP and IPv6 for now.

We may eventually refine the memory usage and such before 2.1 release so it might be worth trying again later. I do have a WRAP here I just don't have it handy to test against. Most WRAPs don't have swap space since they're running NanoBSD images so they're even shorter on RAM.

apmuthu · Sep 27, 2012, 8:38 PM

It's a Soekris 4801 (WRAP's expensive cousin of the same vintage). Ordered the new more powerful (and power consuming) Soekris 65xx for v2.1…..

jimp · Sep 27, 2012, 8:40 PM

net6501 is excellent - I have one at home running my network and it has yet to let me down in any way.