PFSense creates crash report on voucher save


  • Hello,

    I'm using PFSense as Router for our wireless environment for about two years. Runs fine most of the time.
    PFSense is running as a VM in VMWare ESX-Cluster.
    Updated to 2.3 last weekend.
    Now I ran into a problem when the machine autosaves his voucher-db. Think this issue is not related with the update. It was there before from time to time, but I had no time to figure out the reason.

    This is what the crashdump says:

    [02-May-2016 08:55:44 Europe/Berlin] PHP Stack trace:
    [02-May-2016 08:55:44 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [02-May-2016 08:55:44 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [02-May-2016 08:55:44 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [02-May-2016 08:55:44 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [02-May-2016 08:55:44 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [02-May-2016 08:55:44 Europe/Berlin] PHP  6. copy() /etc/inc/config.lib.inc:920
    [02-May-2016 08:55:44 Europe/Berlin] PHP Stack trace:
    [02-May-2016 08:55:44 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [02-May-2016 08:55:44 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [02-May-2016 08:55:44 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [02-May-2016 08:55:44 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [02-May-2016 08:55:44 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [02-May-2016 08:55:44 Europe/Berlin] PHP  6. fopen() /etc/inc/config.lib.inc:928
    [02-May-2016 08:55:44 Europe/Berlin] PHP Stack trace:
    [02-May-2016 08:55:44 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [02-May-2016 08:55:44 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [02-May-2016 08:55:44 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [02-May-2016 08:55:44 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [02-May-2016 08:55:44 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [02-May-2016 08:55:44 Europe/Berlin] PHP  6. fwrite() /etc/inc/config.lib.inc:929
    [02-May-2016 08:55:44 Europe/Berlin] PHP Stack trace:
    [02-May-2016 08:55:44 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [02-May-2016 08:55:44 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [02-May-2016 08:55:44 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [02-May-2016 08:55:44 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [02-May-2016 08:55:44 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [02-May-2016 08:55:44 Europe/Berlin] PHP  6. fclose() /etc/inc/config.lib.inc:930

    Does anyone know what may be the cause of the issue?
    After all PFSense does not reboot or anything like that. Just seems as if it cannot save voucher db correctly, right!?

    Thx

    Update:
    This night I receive a message from our system monitoring tool, that filesystem is dirty.
    "php-cgi: rc.conf_mount_rw: / File system is dirty"
    I ran fsck but everything seems fine.

    Is it possible that this is because the changes in rw to ro of filesystem? Afaik the fs is set ro usually. When changes are made it is set to rw automatically. What if this change does not work correctly? Perhaps takes to long time or does not work at all.
    How can I figure that out?
    Any ideas?

  • Rebel Alliance Developer Netgate

    Is that system running NanoBSD? Normally it wouldn't/shouldn't be run that way in a VM.

    It looks like: https://redmine.pfsense.org/issues/6184

    Try this to get the disk mounted properly: https://forum.pfsense.org/index.php?topic=109766.msg612108#msg612108


  • Hi,

    thanks for your answer.
    It is based on FreeBSD 10.3. Is that a problem having the system installed in a VM? We did this for HA.
    I saw this mount-issue before. The problem is, whenever I run mount -p in the command line it is shown as -rw.

    like this:
    /dev/ufs/pfsense1 / ufs rw,sync,noatime 1 1
    devfs /dev devfs rw 0 0
    /dev/ufs/cf /cf ufs rw,sync,noatime 1 1
    /dev/md0 /tmp ufs rw 2 2
    /dev/md1 /var ufs rw 2 2
    devfs /var/dhcpd/dev devfs rw 0 0

    The command named in the linked threat runs without problems.
    Did I understand something wrong?


  • Are you set to permanent rw under Diag>NanoBSD? If not, you should set that. Looks like you are rw though. The CP database would be in RAM anyway.

    The grep on the PHP errors log excludes the PHP warning message. If you can paste the full output of /tmp/PHP_errors.log that may be more telling.


  • Hi,

    thanks for your explanation!
    It was not set rw permanently. I changed that. Think this may make the difference. Seems as if the system could not change to rw on its own.

    Here is the part of the php.log of today:

    [12-May-2016 11:30:00 Europe/Berlin] PHP Warning:  copy(/cf/conf/backup/config-1463045400.xml): failed to open stream: Read-only file system in /etc/inc/config.lib.inc on line 920
    [12-May-2016 11:30:00 Europe/Berlin] PHP Stack trace:
    [12-May-2016 11:30:00 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [12-May-2016 11:30:00 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [12-May-2016 11:30:00 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [12-May-2016 11:30:00 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [12-May-2016 11:30:00 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [12-May-2016 11:30:00 Europe/Berlin] PHP  6. copy() /etc/inc/config.lib.inc:920
    [12-May-2016 11:30:00 Europe/Berlin] PHP Warning:  filesize(): stat failed for /cf/conf/backup/config-1463045400.xml in /etc/inc/config.lib.inc on line 927
    [12-May-2016 11:30:00 Europe/Berlin] PHP Stack trace:
    [12-May-2016 11:30:00 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [12-May-2016 11:30:00 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [12-May-2016 11:30:00 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [12-May-2016 11:30:00 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [12-May-2016 11:30:00 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [12-May-2016 11:30:00 Europe/Berlin] PHP  6. filesize() /etc/inc/config.lib.inc:927
    [12-May-2016 11:30:00 Europe/Berlin] PHP Warning:  fopen(/cf/conf/backup/backup.cache): failed to open stream: Read-only file system in /etc/inc/config.lib.inc on line 928
    [12-May-2016 11:30:00 Europe/Berlin] PHP Stack trace:
    [12-May-2016 11:30:00 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [12-May-2016 11:30:00 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [12-May-2016 11:30:00 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [12-May-2016 11:30:00 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [12-May-2016 11:30:00 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [12-May-2016 11:30:00 Europe/Berlin] PHP  6. fopen() /etc/inc/config.lib.inc:928
    [12-May-2016 11:30:00 Europe/Berlin] PHP Warning:  fwrite() expects parameter 1 to be resource, boolean given in /etc/inc/config.lib.inc on line 929
    [12-May-2016 11:30:00 Europe/Berlin] PHP Stack trace:
    [12-May-2016 11:30:00 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [12-May-2016 11:30:00 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [12-May-2016 11:30:00 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [12-May-2016 11:30:00 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [12-May-2016 11:30:00 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [12-May-2016 11:30:00 Europe/Berlin] PHP  6. fwrite() /etc/inc/config.lib.inc:929
    [12-May-2016 11:30:00 Europe/Berlin] PHP Warning:  fclose() expects parameter 1 to be resource, boolean given in /etc/inc/config.lib.inc on line 930
    [12-May-2016 11:30:00 Europe/Berlin] PHP Stack trace:
    [12-May-2016 11:30:00 Europe/Berlin] PHP  1. {main}() /etc/rc.savevoucher:0
    [12-May-2016 11:30:00 Europe/Berlin] PHP  2. voucher_save_db_to_config() /etc/rc.savevoucher:39
    [12-May-2016 11:30:00 Europe/Berlin] PHP  3. voucher_save_db_to_config_zone() /etc/inc/voucher.inc:770
    [12-May-2016 11:30:00 Europe/Berlin] PHP  4. write_config() /etc/inc/voucher.inc:812
    [12-May-2016 11:30:00 Europe/Berlin] PHP  5. backup_config() /etc/inc/config.lib.inc:553
    [12-May-2016 11:30:00 Europe/Berlin] PHP  6. fclose() /etc/inc/config.lib.inc:930


  • Your log could be resumed in a couple of words :
    "Help - can't write !!"

    Did you changed to rw mode afterwards (11h30) ?


  • Hi,

    yes thats what I assumed, too. Thats what is says in the end. Seems to be a "timing problem". I see the messages in the log, but when I run mount -p afterwards, everything is in -rw.
    So perhaps change from ro to rw does no happen in time or something like that.

    Yes, I changed it to permanent rw yesterday after 11:30. I'll keep an eye on that and let you know if the change fixed it (what I think it will).

    Thanks a lot for your help!!


  • Update,

    no more crashes since change to permanent -rw last week. Occured at almost each saving process before the change. So I think it is solved.
    Thanks a lot for your help!

    If problem reoccures, I'll give an update. But don't think so ;)