Vouchers getting Expired before remaining Time
-
I have one new production system working since 20 Days with up to 2500 Captive Portal users. I am facing strange problem first time in 2.5 Stable release. vouchers getting expired before the time. 5-10 people daily complaining for voucher expiring.
as example today got one person need to disconnect his device as first one broken and to enter same voucher on new device. as we disconnected this user next device it says voucher expired and still 6 Days left for this voucher to expire.
Apr 5 17:51:45 logportalauth 58051 Zone: platinum - 1152682738 (6/47) already used and expired Apr 5 17:51:27 logportalauth 58051 Zone: platinum - DISCONNECT: 1152682738, 30:aa:e4:db:7b:0c, 10.20.6.43
-
Hi,
First things first : your lcoal system time is ok ?
Next : you can test vouchers codes here : Diagnostics > Authentication
When you create a bunch of vouchers that last 2 hours, and you test them, do you find "120 minutes of unused time", or less ?
-
I can confirm System time is correct there is no issue with it.
secondly its Voucher so i cannot see any option under Diagnostics--->Authentication to test voucher but local DB with username and password. I instead tested with Status--->Captive Portal ----> Test Vouchers and it showed expired.
While creating vouchers ( 1 Month " 43200 Minutes ) when person activate the voucher remaining time shows correctly
-
Hello @wazim4u ,
That's strange...
one question, could you open the file/var/db/voucher_{$cpzone}_active_{$roll}.db
& check what's inside?The format of this file is
{voucher_number},{timestamp_of_activation_time},{allowed_time_in_minutes}
.Could you specifically check :
- For "in use vouchers", do the allowed time in minutes & the activation timestamp correspond to the reality ?
- Is there any expired voucher still inside? (It should not be the case, but just in case, could you check?)
Here is (in simplified version, the exact code can be found here) how the voucher expiration is performed in pfSense :
// This code is executed automatically every minute // and manually for some rare events (pfSense shudown, submit on the voucher edit page of the GUI, HA Sync between 2 pfSense, etc...) $roll = '5'; // The voucher roll $cpzone = 'myCpZone'; // The Captive Portal zone $file = fopen("/var/db/voucher_{$cpzone}_active_{$roll}.db", "r"); while (!feof($file)) { $line = trim(fgets($file)); list($voucher, $timestamp, $minutes) = explode(",", $line); // voucher,timestamp,allowed time if ((($timestamp + (60*$minutes)) - time()) =< 0) { // (The maximum int on PHP is 9223372036854775807, which mean an integer overflow is not possible here) $expired = True; } }
That's why I see two possibilities :
- The timestamp / allowed time is not correct in the file
- or the time() function of PHP does not give correct results
Honestly, my bet on this issue is that the allowed time in the file are somehow not correct.
Could you confirm me that ? -
@free4
Here is the output of active voucher roll as requested. roll no.1 having only 6 active vouchers and output of file is given belowcat /var/db/voucher_platinum_active_1.db 793338274,1616951824,14400 474432784,1617051821,14400 82728594,1617125331,14400 1434727374,1617193376,14400 723599534,1617209155,14400 9883922256,1617692216,14400
I am unable to understand timestamp format but voucher and given time is fine. all expired voucher roll shows nothing it means no active voucher remain in roll.
as i mentioned almost 2500 active users few of them getting this issue. yesterday active voucher we disconnected because mobile was broken and as we entered this code in other device it shows expired even 6 days still to go we seen while disconnecting.
-
The timestamp (also called epoch) is the number of seconds that have elapsed since January 1, 1970 at midnight UTC.
You can convert a timestamp to date on website like https://www.epochconverter.com/
I'm not seeing anything wrong in the 6 active vouchers...
-
Hello,
I am having a similar strange problem: We operate around 170 sites with a wide variety of HW and PFSense releases. The following problem appears ONLY for one site with stable version of 2.5.1 on APU1D4 hardware: A voucher roll of 50.000 vouchers has been created, validity is 43.200 minutes = 30 days. The system has gone live on April 7. So far around 80 voucher have been activated over the course of April. When I look into the Captive Portal now it says 272 vouchers already expired. How can that be? I am getting complaints from users that their vouchers expired earlier that 30 days. And they are right: Today is May 1st, the system has gone live on April 6. This is certainly less than 30 days ... Any idea? We are operating the same config (50.000 vouchers in the local db) in many sites with release 2.4 oder even 2.3.x without any problem.
Any idea is appreciated. My customer hotline folks are somewhat annoyed...
BR,
Volker
-
@refugeesonline hi,
Same reply as before : could you open the file
/var/db/voucher_{$cpzone}_active_{$roll}.db
& check what's inside?The format of this file is
{voucher_number},{timestamp_of_activation_time},{allowed_time_in_minutes}
.Could you specifically check :
- For "in use vouchers", do the allowed time in minutes & the activation timestamp correspond to the reality ?
- Is there any expired voucher still inside? (It should not be the case, but just in case, could you check?)
- Is the time on the pfSense appliance is correct?
Also, are you in an "High Avaliability" configuration (two pfSense appliances, one master & one backup) ? or that's not the case?
-
Hi!
I checked the file and inserted my answers to your questions below:
For "in use vouchers", do the allowed time in minutes & the activation timestamp correspond to the reality ?
Volker: The allowed time in minutes is fine (43200), however, the activation timestamp is not. It seems all vouchers have been activated between May 1st and May 2nd. This is weired and nonsense.
Is there any expired voucher still inside? (It should not be the case, but just in case, could you check?)
Volker: No, none of the expired voucher is inside this file.
Is the time on the pfSense appliance is correct?
Volker: Yes, it is.
Also, are you in an "High Avaliability" configuration (two pfSense appliances, one master & one backup) ? or that's not the case?
Volker: No high availabilty config.
I tried to find the differences between the appliances working fine (ie pfSense 2.3.5_2) and the APU1D4 running 2.5.1. The older versions have all created voucher rolls represented by files in /var/db/voucher_zone_xyz_active_roll#.db and /var/db/voucher_zone_xyz_used_roll#.db. The one running 2.5.1. only has the file corresponding to the voucher roll in use.
Best,
Volker
-
2.4 & 2.5 Development have no issue. only facing this issue with 2.5 Stable & now 2.5.1 Stable. everyday people coming with expired voucher complaints. One month voucher is getting expire in few days ( not specific time )
another issue there is no reporting for expired vouchers only from LOGS you can trace which is not convenient for clients.
-
Hi!
I tried to investigate this a little deeper. Here is what I suspect: If voucher rolls are created running 2.4.x the upgrade to 2.5.x deletes the db-files in /var/db. On the first login of an existing voucher, the respective db-files will be re-created, but with wrong activation time stamps. (No evidence. just a thought!)
What helps:
Delete all voucher rolls. Upgrade to 2.5.x. Create all voucher rolls again. Check if all corresponding db-files are present in /var/db.
However, there is a BIG disadvantage: All voucher history gets lost, especially vouchers which were expired will be valid again unless you manually expire them!!!
BR,
Volker
-
You might be right
I can't / didn't test an upgrade, as I'm on 2.5.1 already. I'm not using voucher neither.
DB files ate filled with the time info, when vouchers are used or activated.But :
With the option set, DB files are backed up ....
-
I have Fresh Install and everything created from Scratch. I have two site still running development version of 2.5 and there is no issue
I planned to upgrade them to 2.5 stable but facing problem with vouchers early expiring in two new deployments ( Built on FEB-2021 ). so Postponed it.
There is some kind of bug unable to trace yet.
-
@wazim4u said in Vouchers getting Expired before remaining Time:
I have Fresh Install and everything created from Scratch. I have two site still running development version of 2.5 and there is no issue
What is the actual snapshot date?
Could you provide more information and create a bugreport?
https://docs.netgate.com/pfsense/en/latest/development/bug-reports.htmlMay be related to https://redmine.pfsense.org/issues/97
-
Voucher system working perfectly on this snapshot
2.5.0.a.20210107.2142 ( Development )
up to 2500 captive portal users renew monthly basis and there is not a single issue reported about voucher's early expiry.
-
Aaargghhh. It happended again. Even the way I though will work (delete vouchers, upgrade to 2.5.1, create vouchers again) is failing. Around 280 vouchers expired way before the end of its validity period. And we have a lot of happy customers on our hotline ... :-(
The system was rebooted due to a power outage and this reboot may have caused the corruption of the voucher db. Just a thought ...
I am going to roll back all the respective sites to 2.4.5 now. This bug is severe - at least if vouchers are being used.
Regards,
Volker
-
Please create a bugreport:
https://docs.netgate.com/pfsense/en/latest/development/bug-reports.html -
Done!
https://redmine.pfsense.org/issues/11894
-
Hello!
Are you using RAM disks?
John
-
@refugeesonline said in Vouchers getting Expired before remaining Time:
Aaargghhh. It happended again. Even the way I though will work (delete vouchers, upgrade to 2.5.1, create vouchers again) is failing. Around 280 vouchers expired way before the end of its validity period. And we have a lot of happy customers on our hotline ... :-(
The system was rebooted due to a power outage and this reboot may have caused the corruption of the voucher db. Just a thought ...
I am going to roll back all the respective sites to 2.4.5 now. This bug is severe - at least if vouchers are being used.
Regards,
Volker
What is your complete configuration?
Are you using RAM disks or Captive Portal HA sync?
Please provide more info -
I can prove now that there is serious bug in system . given below are details for two vouchers showing expired today.
Voucher : 976522494 ( Expired after 2 days )
May 6 01:14:49 logportalauth 14356 Zone: smg_camp - FAILURE: 976522494, 6c:c7:ec:4b:11:c3, 172.17.228.225, voucher expired May 6 01:14:49 logportalauth 14356 Zone: smg_camp - 976522494 (6/50) already used and expired May 4 04:28:01 smg logportalauth[24061]: Zone: smg_camp - Voucher login good for 516420 min.: 976522494, 6c:c7:ec:4b:11:c3, 172.17.228.225
Voucher : 7929393872 ( Expired after 6 days )
May 6 08:04:05 logportalauth 61082 Zone: smg_camp - FAILURE: 7929393872, 2e:64:bd:c8:d3:4f, 172.17.120.210, voucher expired May 6 08:04:05 logportalauth 61082 Zone: smg_camp - 7929393872 (6/18) already used and expired Apr 29 12:03:47 smg logportalauth[46095]: Zone: smg_camp - Voucher login good for 517452 min.: 7929393872, 52:62:b0:80:78:00, 172.17.230.152
-
@serbus
Yes, /tmp and /var are RAM disks -
@viktor_g
Yes, /tmp and /var are RAM disks. No Captive Portal HA sync, only local dbs.What I noticed: System has been upgraded, all voucher rolls were deleted by the admin. No db-files in /var/db. Then the admin created 3 voucher rolls and the corresponding db-files are present in /var/db.
Then reboot. All of the sudden 286 vouchers expired (which is weird as only around 70 were active at that time). In /var/db only the db-file for one roll (the one containing active vouchers) is present - the others disappeared. Even more strange: All remaining active vouchers were set back to original validity (43.200 mins). It looks like the reboot has had a severe impact on the /var/db contents ...
Two things are a pain in the neck: Active vouchers are expired way earlier before the nominal validity (consequently, our hotline has a lot of calls). Secondly, the remaining vouchers start again with full validity. (consequently, we are giving access for free as active vouchers are kind of reset to square one). -
Tried to switch off RAM disks.
Result: Captive Portal does not work anymore ....May 6 15:11:51 logportalauth 360 Zone: zone_01 - Trying to modify DB returned error: table captiveportal has no column named traffic_quota
May 6 15:11:51 logportalauth 360 Zone: zone_01 - Trying to modify DB returned error: table captiveportal has no column named traffic_quotaI am closed to give up on this ....
-
@refugeesonline said in Vouchers getting Expired before remaining Time:
Yes, /tmp and /var are RAM disks
and then :
@refugeesonline said in Vouchers getting Expired before remaining Time:
It looks like the reboot has had a severe impact on the /var/db contents ...
True : RAM disks are lost during reboot.
edit : I presume that's a common knowledge .... Am I wrong ?When I read all this :
I do not have the confirmation that the captive data base files are retained.
Data (files) that are kept between reboots are mentioned !
The captive portal database files are NOT mentioned ....
So ..... I vote for : they are lost.
edit : the manual confirmed this.There is probably an issue, but using RAM disks and the using the captive portal - and using vouchers == asking for another issue.
@refugeesonline said in Vouchers getting Expired before remaining Time:
All remaining active vouchers were set back to original validity (43.200 mins).
Yep - this seems normal to me. These data base files - per portal and per role - are created when at least one of the vouchers of a roll is activated. The voucher code and the time stamp of their activation is recorded.
Loosing these file makes the voucher 'available' again with the original duration. -
@gertjan
I do not understand your comment. We are operating 170 sites and the problems I described ONLY appear on systems running 2.5.1 .... -
@refugeesonline said in Vouchers getting Expired before remaining Time:
and the problems I described ONLY appear on systems running 2.5.1 ...
== the systems you upgraded. This will zap de ram disk.
Or : the other system never reboot ( ? ) .... so the RAM disk stays valid.Also :
See https://github.com/pfsense/pfsense/commits/master/src/etc/inc/voucher.incThe last time this file changed was may 2020. That's before 2.4.5-p1 ...
And that code decides if the log message "already used and expired" is thrown out :May 6 08:04:05 logportalauth 61082 Zone: smg_camp - 7929393872 (6/18) already used and expired
I've created some vouchers and roles myself, and play with them.
I can't really create vouchers with a "517452 minutes " == one year ( !!!! ) and test them.Btw : the voucher code could change tomorrow, and break the bit-nitting** of of the expiration test, so making vouchers "517452 " will always give troubles. The unknown factor is just "when".
** Just look - for the fun - at the function voucher_expire() and voucher_auth() in
/etc/inc/voucher.inc -
@gertjan said in Vouchers getting Expired before remaining Time:
@refugeesonline said in Vouchers getting Expired before remaining Time:
Yes, /tmp and /var are RAM disks
and then :
@refugeesonline said in Vouchers getting Expired before remaining Time:
It looks like the reboot has had a severe impact on the /var/db contents ...
True : RAM disks are lost during reboot.
edit : I presume that's a common knowledge .... Am I wrong ?When I read all this :
I do not have the confirmation that the captive data base files are retained.
Data (files) that are kept between reboots are mentioned !
The captive portal database files are NOT mentioned ....
So ..... I vote for : they are lost.
edit : the manual confirmed this.There is probably an issue, but using RAM disks and the using the captive portal - and using vouchers == asking for another issue.
Please create a feature request for storing captive portal / voucher data:
https://docs.netgate.com/pfsense/en/latest/development/feature-requests.html -
@gertjan
None of the reporters of this "bug" (wazim4u and refugeesonline=me) is using a validity period of one year, we are using 43.200 mins = 30 days.
I am sorry I don't have the time to look in GitHub (although I would love to be able to contribute), I am just an operator of 170 appliances.
And concerning reboots: All our sites are refugee camps, power outages (and consequently reboots) are daily business. We never had this problem before. I can't judge whether this is a bug or a configuration problem. All I am saying: I did NOT change the configuration, I just did an upgrade to 2.5.1. and ran into problems. And I had to notice that the configuration had to be changed, too. 2.5.1 has a totally different handling of concurrent logins (which I figured by accident as many customers were complaining). So my conclusion is: For my case the upgrade caused the problem. I will have to physically visit al lot of sites and do the roll-back to 2.4.5. (Else, I am open for any advice how to do this remotely ....) -
Hello!
A cursory look through some of the code indicates that some voucher info is stored in the config during a graceful shutdown/reboot. Even that wont help with ram disks, or if there is a power loss.
Check on the requirements that forced you to move from 2.4.5 to 2.5.x and see if any of those can be worked around.
Try building a fresh 2.5.x without ram disks and see how it works.
Moving back to "no ram disks" after initially using them might work with a little scripting.
Using the current rc.backup* and rc.restore* scripts as a template for manually saving and restoring the /var/db data...
While ram disks are still on...
rc.backup_db#!/bin/sh # : ${DBPATH:=/var/db} : ${CF_CONF_PATH:=/cf/conf} : ${RAM_Disk_Store:=${CF_CONF_PATH}/RAM_Disk_Store} # Save the logs database to the RAM disk store. if [ -d "${DBPATH}" ]; then echo -n "Saving DB to RAM disk store..."; [ -f "${RAM_Disk_Store}/db.tgz" ] && /bin/rm -f "${RAM_Disk_Store}/db.tgz" if [ ! -d "${RAM_Disk_Store}" ]; then mkdir -p "${RAM_Disk_Store}" fi /usr/bin/tar -czf "${RAM_Disk_Store}/db.tgz" -C / "${DBPATH#/}/" echo "done."; fi
Turn off ram disks, reboot, manually run...
rc.restore_db#!/bin/sh # : ${CF_CONF_PATH:=/cf/conf} : ${RAM_Disk_Store:=${CF_CONF_PATH}/RAM_Disk_Store} /usr/bin/tar -xzf "${RAM_Disk_Store}/db.tgz" -C / 2>&1
Restart captive portal and see if it picks up your newly restored /var/db
The standard system rc.restore_ramdisk_store might even catch & restore the db.tgz you created if it runs when rams disks are off (???).
This is a highly experimental process with lots of unknowns. Use at your own risk.
Maybe someone with more/better knowledge of the startup/shutdown and ram disk operations could chime in.John
-
My Issue is different than @refugeesonline. We are facing random voucher expiry before remaining time. Almost 2500+ voucher active and few of them having this behavior.
vouchers are 7 Days, 15 Days & also 30 Days. Expiry happening randomly with different rolls , one client created 1 Year voucher which I also not recommend and suggested him to use Radius authentication ( PfSense Radius ) for long terms users.
We have fresh install of 2.5 stable system. NO RAM DISK, NO HA setup. All installations on SSD 480G. We have no issue with System reboots we did it few times and all is well.