Invalid license message - I've verified the server is able to lookup DNS

192 views
Skip to first unread message

Dave Benham

unread,
Jan 13, 2021, 7:59:23 AM1/13/21
to NxFilter

I'm running the free version of NxFilter and I'm seeing invalid license messages on my dashboard and in my logs.  I've read the other threads on disabling systemd-resolved, creating a new resolve.conf, etc. and I have done all that.  DNS is functioning on the server and it is able to reach the internet on ports TCP 80, 443 and UDP 123 (nothing is being blocked for this server).

It's an Ubuntu 18.04 server (two of them, actually, setup as a redundant pair) running NxFilter 4.3.8.8.  Everything is working except classification, which worked when I initially setup the server (and had no license messages).  These invalid license messages are new, but I'm not sure what changed to cause them.  Any ideas on what I can check?  Thanks in advance!

root@ipam3:/nxfilter# systemctl status systemd-resolved
● systemd-resolved.service - Network Name Resolution
   Loaded: loaded (/lib/systemd/system/systemd-resolved.service; disabled; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:systemd-resolved.service(8)
           https://www.freedesktop.org/wiki/Software/systemd/resolved
           https://www.freedesktop.org/wiki/Software/systemd/writing-network-configuration-managers
           https://www.freedesktop.org/wiki/Software/systemd/writing-resolver-clients


root@ipam3:/nxfilter# ls -alF /etc/resolv.conf
-rw-r--r-- 1 root root 38 Jan 11 14:52 /etc/resolv.conf
root@ipam3:/nxfilter# cat /etc/resolv.conf
nameserver 8.8.8.8
nameserver 4.2.2.1


root@ipam3:/nxfilter# telnet www.nxfilter.org 80
Trying 182.50.159.27...
Connected to nxfilter.org.
Escape character is '^]'.
^]
telnet> quit
Connection closed.


root@ipam3:/nxfilter# ntpdate -u pool.ntp.org
13 Jan 07:50:20 ntpdate[24401]: adjust time server 138.236.128.36 offset 0.003919 sec


root@ipam3:/nxfilter# nslookup www.nxfilter.org
Server:         8.8.8.8
Address:        8.8.8.8#53

Non-authoritative answer:
www.nxfilter.org        canonical name = nxfilter.org.
Name:   nxfilter.org
Address: 182.50.159.27

Jahastech

unread,
Jan 13, 2021, 8:08:19 AM1/13/21
to NxFilter
Did you look into your log file. It's /nxfilter/log/nxfilter.log. There might the reason for your problem. If it's about Invalid License, there must a log contains '.. blocked by ...'. So try to find that or show me your log file.

Dave Benham

unread,
Jan 13, 2021, 8:15:41 AM1/13/21
to NxFilter
Thank you for the quick response!  I don't see many interesting messages in the logs...

The only messages I see with the word "blocked" in them are these:
root@ipam3:/nxfilter/log# grep -i blocked *
nxfilter.log: INFO [01-12 09:00:23] - RHiAD, Blocked by category (Phishing/Malware), x.bidswitch.net.
nxfilter.log: INFO [01-12 09:01:35] - RHiAD, Blocked by category (Phishing/Malware), p.adsymptotic.com.
nxfilter.log: INFO [01-12 09:01:47] - RHiAD, Blocked by category (Phishing/Malware), c.betrad.com.
nxfilter.log: INFO [01-12 09:39:49] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 09:54:55] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 10:56:24] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 10:59:29] - RHiAD, Blocked by category (Phishing/Malware), ad-delivery.net.
nxfilter.log: INFO [01-12 11:10:07] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 11:38:30] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 11:47:53] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.
nxfilter.log: INFO [01-12 11:58:34] - RHiAD, Blocked by category (Phishing/Malware), https://app-measurement.com/sdk-exp.


And the only messages I see with the word "license" in them are these:
nxfilter.log.2: INFO [01-11 14:29:35] - MM, License serial = 20210126-100000-0-NXFREE06
nxfilter.log.2: INFO [01-11 14:29:35] - MM, LicenseChecker started.
nxfilter.log.2: INFO [01-11 14:50:43] - MM, License serial = 20210126-100000-0-NXFREE06
nxfilter.log.2: INFO [01-11 14:50:43] - MM, LicenseChecker started.
nxfilter.log.2: INFO [01-11 15:08:35] - MM, License serial = 20210126-100000-0-NXFREE06
nxfilter.log.2: INFO [01-11 15:08:35] - MM, LicenseChecker started.
nxfilter.log.2: INFO [01-11 19:00:00] - PBsE, An email discarded as the alert email setup inactive! - NxFilter, License expiration warning!
nxfilter.log.2: INFO [01-11 19:00:00] - PostBox.addEmail, An email added, NxFilter, License expiration warning!
nxfilter.log.7: INFO [01-09 16:13:40] - MM, License serial = 20210126-100000-0-NXFREE06
nxfilter.log.7: INFO [01-09 16:13:40] - MM, LicenseChecker started.


A bit more of the log file, surrounding the word License:
 INFO [01-11 14:29:33] - CLlPP, Loading policy_cxblock.
 INFO [01-11 14:29:33] - CLlPP, Loading policy_nxproxy.
 INFO [01-11 14:29:33] - CLlPP, Loading policy_nxrelay.
 INFO [01-11 14:29:33] - CLlPA, Loading policy_globlist.
 INFO [01-11 14:29:33] - CLcLC, Copying config into local DB.
 INFO [01-11 14:29:33] - CLcLAP, Copying admin_pw into local DB.
 INFO [01-11 14:29:33] - CLcLBP, Copying block_page into local cacle.
 INFO [01-11 14:29:33] - MM, ConfigLoader started.
 INFO [01-11 14:29:35] - MM, License serial = 20210126-100000-0-NXFREE06
 INFO [01-11 14:29:35] - MM, LicenseChecker started.
 INFO [01-11 14:29:35] - MM, JahasDic started.
 INFO [01-11 14:29:33] - CLcLAP, Copying admin_pw into local DB.
 INFO [01-11 14:29:33] - CLcLBP, Copying block_page into local cacle.
 INFO [01-11 14:29:33] - MM, ConfigLoader started.
 INFO [01-11 14:29:35] - MM, License serial = 20210126-100000-0-NXFREE06
 INFO [01-11 14:29:35] - MM, LicenseChecker started.
 INFO [01-11 14:29:35] - MM, JahasDic started.
 INFO [01-11 14:29:35] - MM, NxClassifier started.
 INFO [01-11 14:29:35] - MM, BlockDomainResolver started.
 INFO [01-11 14:29:35] - UADUAD, initiated.
 INFO [01-11 14:29:35] - LFLF, LogWriter started.
 INFO [01-11 14:29:35] - MM, LogFacade started.
 INFO [01-11 14:29:35] - LCLC, Loading data from log_domain.
 INFO [01-11 14:29:36] - MM, AlertMan started.
 INFO [01-11 14:29:36] - MM, PostBox started.
 INFO [01-11 14:29:36] - MM, LdapUpdater started.
 INFO [01-11 14:29:36] - MM, LocalListener started.
 INFO [01-11 14:29:36] - MM, LoginListener started.
 INFO [01-11 14:29:36] - MM, HandyMan started.
 INFO [01-11 14:29:36] - Main.HandyMan.deleteOld, Started.
 INFO [01-11 14:29:36] - MM, ReportMan started.
 INFO [01-11 14:29:36] - QDi, Reset user_quota.
 INFO [01-11 14:29:36] - QDi, Loading user_quota.
 INFO [01-11 14:29:36] - MM, NodeListener started.
 INFO [01-11 14:29:36] - MM, DynDomainMapper started.
 INFO [01-11 14:29:36] - MM, ZoneTransfer started.
 INFO [01-11 14:29:36] - DUlR, Loading resolvers.
 INFO [01-11 14:29:36] - MM, RecatMan started.
 INFO [01-11 14:29:36] - RMcR, Resolving DNS server : [1.1.1.1, 8.8.8.8, 75.75.75.75]
 INFO [01-11 14:29:36] - MM, RequestHandler started.
 INFO [01-11 14:29:36] - MM, UdpServer started.
 WARN [01-11 14:29:36] - ReducedLog > RequestQueue.add, Invalid udp request, unicodeDomain = , cltIp = 10.0.0.9.
 WARN [01-11 14:29:36] - ReducedLog > UdpServer.run, Couldn't add a request, cltIp = 10.0.0.9.
 INFO [01-11 14:29:36] - MM, RecatMan started.
 INFO [01-11 14:29:36] - RMcR, Resolving DNS server : [1.1.1.1, 8.8.8.8, 75.75.75.75]
 INFO [01-11 14:29:36] - MM, RequestHandler started.
 INFO [01-11 14:29:36] - MM, UdpServer started.
 WARN [01-11 14:29:36] - ReducedLog > RequestQueue.add, Invalid udp request, unicodeDomain = , cltIp = 10.0.0.9.
 WARN [01-11 14:29:36] - ReducedLog > UdpServer.run, Couldn't add a request, cltIp = 10.0.0.9.
 INFO [01-11 14:29:39] - MM, Starting TCP DB.
 INFO [01-11 14:29:39] - MM, Radius server started.
 INFO [01-11 14:29:39] - MM, Starting Tomcat.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_clt_ip.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_user.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_policy.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_category.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_grp.
 INFO [01-11 14:29:39] - LCLC, Loading data from log_detail.
 INFO [01-11 14:29:41] - NxClassifier.addQueue, Domain added. - landscape.my.house, domainQueue.size() = 1.
 INFO [01-11 14:29:41] - NxClassifier.run, MyClassifier - 0, Started working on landscape.my.house.
 INFO [01-11 14:29:42] - HandyMan.deleteOld, Don't need to delete old traffic data at the moment.
 INFO [01-11 14:29:42] - MHMrU, Doing remote update for Jahaslist.
 INFO [01-11 14:29:42] - JahasUpdate.remoteRecatOne, Processing /nxfilter/tmp/www_nxfilter_org_jahaslist_random_php/random.php
 INFO [01-11 14:29:42] - NxClassifier.run, MyClassifier - 0, Domain not exist! - landscape.my.house.
 INFO [01-11 14:29:43] - NLSHr, workCnt = 1
 INFO [01-11 14:29:43] - JahasUpdate.remoteRecatOne, oldVer = 1399, newVer = 1399.
 INFO [01-11 14:29:43] - JahasUpdate.remoteRecatOne, Nothing to update.
 INFO [01-11 14:29:43] - MHMrU, Jahaslist has been updated.
 INFO [01-11 14:29:44] - NxClassifier.addQueue, Domain added. - device-gateway.capenetworks.io, domainQueue.size() = 1.
 INFO [01-11 14:29:44] - NxClassifier.run, MyClassifier - 0, Started working on device-gateway.capenetworks.io.
 WARN [01-11 14:29:48] - ReducedLog > RequestQueue.add, Invalid udp request, unicodeDomain = , cltIp = 10.0.0.9.
 WARN [01-11 14:29:48] - ReducedLog > UdpServer.run, Couldn't add a request, cltIp = 10.0.0.9.
 WARN [01-11 14:29:54] - ReducedLog > RequestQueue.add, Invalid udp request, unicodeDomain = , cltIp = 10.0.0.9.
 WARN [01-11 14:29:54] - ReducedLog > UdpServer.run, Couldn't add a request, cltIp = 10.0.0.9.
 INFO [01-11 14:29:58] - ALDl, Login attempt for admin from 10.0.4.103.

Jahastech

unread,
Jan 13, 2021, 8:23:58 AM1/13/21
to NxFilter
Can you send me your log files. Zip /nxfilter/log and send it to 'support @ nxfilter.org'.

Dave Benham

unread,
Jan 13, 2021, 8:24:45 AM1/13/21
to NxFilter
Absolutely!  Thank you for offering to help.  I'll zip/send them shortly.

Dave

Jahastech

unread,
Jan 13, 2021, 8:43:15 AM1/13/21
to NxFilter
I don't see anything in your log. If it's for Invalid License message, you should get log contains 'License blocked by..' . Do you sill get that message? If it's from connection problem, it could be temporary.

Anyway, there's no connection problem in your log files.

Jahastech

unread,
Jan 13, 2021, 8:45:42 AM1/13/21
to NxFilter
I think your clustering should be OK with free license. However, did you check both nodes with your connection test and log files?

Dave Benham

unread,
Jan 13, 2021, 8:50:30 AM1/13/21
to NxFilter
I did run the connection tests on the backup box as well, and it succeeds.  However, there are more licensing error messages in the log on that box:

nxfilter.log.2:ERROR [01-11 10:13:17] - JDcL, No Jahaslist license!
nxfilter.log.2:ERROR [01-11 10:13:26] - RHiAD, License blocked by endDate!
nxfilter.log.2: INFO [01-11 10:13:26] - License info : endDate = , curDate = 20210111, maxUser = 0, user = 5, ip = 2, requestCount = 0
nxfilter.log.2:ERROR [01-11 10:13:28] - RHiAD, License blocked by endDate!
nxfilter.log.2: INFO [01-11 10:13:28] - License info : endDate = , curDate = 20210111, maxUser = 0, user = 5, ip = 2, requestCount = 0
nxfilter.log.2:ERROR [01-11 10:14:01] - RHiAD, License blocked by endDate!
nxfilter.log.2: INFO [01-11 10:14:01] - License info : endDate = , curDate = 20210111, maxUser = 0, user = 5, ip = 2, requestCount = 0
nxfilter.log.2:ERROR [01-11 10:14:04] - RHiAD, License blocked by endDate!
nxfilter.log.2: INFO [01-11 10:14:04] - License info : endDate = , curDate = 20210111, maxUser = 0, user = 5, ip = 2, requestCount = 0
nxfilter.log.2:ERROR [01-11 10:14:17] - JDcL, No Jahaslist license!
nxfilter.log.2:ERROR [01-11 10:14:21] - RHiAD, License

nxfilter.log.9:ERROR [12-29 06:17:58] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:18:08] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:18:30] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:18:31] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:18:34] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:19:08] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:19:17] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:19:31] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:19:39] - RHiAD, License blocked by endDate!
nxfilter.log.9:ERROR [12-29 06:19:47] - RHiAD, License blocked by endDate!

Jahastech

unread,
Jan 13, 2021, 8:54:49 AM1/13/21
to NxFilter
Try to start your slave node again and see that endDate info after it restarted.

Dave Benham

unread,
Jan 13, 2021, 8:55:00 AM1/13/21
to NxFilter
I just restarted the nxfilter services on the backup box, and i think the license messages on the primary box may have stopped showing up (I haven't seen any errors in 3 minutes and I used to see several a minute).  Is there a way for me to force a check to see if it is happy with the license?  It's possible my backup box booted before my internet connection was back up (I did some network maintenance last week).  I was focusing on the primary box because that's where I was seeing the errors in the dashboard.  It appears the issue may have been on the backup box all along.  I didn't realize the primary would complain about the license on the secondary.

Dave Benham

unread,
Jan 13, 2021, 8:56:23 AM1/13/21
to NxFilter
I don't see those license errors in the slave node.  I think restarting the slave node fixed it.  Sorry for the wild goose chase!  I was focusing on the primary because that's where I was seeing the messages in the dashboard.

Dave Benham

unread,
Jan 13, 2021, 8:58:14 AM1/13/21
to NxFilter
Thanks for your help!

Dave Benham

unread,
Jan 13, 2021, 9:01:08 AM1/13/21
to NxFilter
I am getting classifications/blocks instead of license errors now.  Looks like it's all fixed!

Jahastech

unread,
Jan 13, 2021, 9:01:11 AM1/13/21
to NxFilter
When there's no license file on your slave node, it tries to share the license from your master node. In that case, you always have to start it while your master node running.

Next time, use our Reddit forum. We are trying to move away from Google forum.
  https://www.reddit.com/r/nxfilter/

Dave Benham

unread,
Jan 13, 2021, 9:03:28 AM1/13/21
to NxFilter
Thanks for that info.  I'll place a startup delay on the backup VM so that it waits for the primary to be online before it boots.  It's on a different VM host, and it boots a lot faster than the primary.  I'm sure that's where the problem stemmed from.  I will use reddit next time.  Thanks again for your help!
Reply all
Reply to author
Forward
0 new messages