[GH-ISSUE #45] Bug: Zero Input/Output Octets - SQM-scripts conflict #30

Closed
opened 2026-03-04 14:52:30 +03:00 by kerem · 20 comments
Owner

Originally created by @nemesifier on GitHub (Sep 12, 2025).
Original GitHub issue: https://github.com/f00b4r0/uspot/issues/45

I noticed that uspot intermittently reports zero traffic accounting data (input/output octets, packets) for all sessions from affected devices, despite actual network traffic occurring. Issue persists until device reboot, the last time I encountered this it required multiple reboots.

Environment

  • current master of uspot
  • openwrt 24.10
  • freeradius + radsec

Problem Description

Symptoms

  • All traffic accounting metrics report as zero:
    • Acct-Input-Octets = 0
    • Acct-Output-Octets = 0
    • Acct-Input-Packets = 0
    • Acct-Output-Packets = 0
  • Issue affects all sessions from the same device simultaneously
  • Accounting session time continues to increment normally (Acct-Session-Time = 1806)
  • Problem occurs intermittently across different devices (observed 3 times)

Resolution

  • Requires device reboot to restore traffic counting
  • May require multiple reboots in some cases

Debug Information

Configuration

opkg list-installed | grep uspot:

uspot - 2025.08.05~cecd4038-r1
uspot-www - 2025.08.05~cecd4038-r1
uspotfilter - 2025.08.05~cecd4038-r1

uci show uspot:

uspot.captive=uspot
uspot.captive.acct_interval='60'
uspot.captive.acct_port='2083'
uspot.captive.acct_secret='psk@<redacted>@<redacted>'
uspot.captive.acct_server='<redacted>'
uspot.captive.auth_mode='uam'
uspot.captive.auth_port='2083'
uspot.captive.auth_secret='psk@<redacted>@<redacted>'
uspot.captive.auth_server='<redacted>'
uspot.captive.counters='1'
uspot.captive.cpa_venue_url='https://<redacted>/<redacted>/login'
uspot.captive.das_port='3799'
uspot.captive.das_secret='<redacted>'
uspot.captive.debug='1'
uspot.captive.disconnect_delay='0'
uspot.captive.final_redirect_url='uam'
uspot.captive.idle_timeout='600'
uspot.captive.interface='lan'
uspot.captive.location_name='<redacted>'
uspot.captive.mac_auth='0'
uspot.captive.mac_format='AA:BB:CC:DD:EE:FF'
uspot.captive.nasid='uspot'
uspot.captive.nasmac='00:D0:B4:04:5E:48'
uspot.captive.rad_serv_type='tls'
uspot.captive.session_timeout='0'
uspot.captive.setname='uspot'
uspot.captive.swapio='1'
uspot.captive.uam_port='3991'
uspot.captive.uam_server='https://<redacted>/<redacted>/login'
uspot.captive.uam_sslurl='https://<redacted>/<redacted>/login'

uci show network:

network.loopback=interface
network.loopback.device='lo'
network.loopback.proto='static'
network.loopback.ipaddr='127.0.0.1'
network.loopback.netmask='255.0.0.0'
network.globals=globals
network.globals.ula_prefix='fd82:76b2:f73b::/48'
network.device_lan=device
network.device_lan.name='br-lan'
network.device_lan.ports='eth0'
network.device_lan.type='bridge'
network.lan=interface
network.lan.device='br-lan'
network.lan.proto='static'
network.lan.ipaddr='192.168.100.1'
network.lan.netmask='255.255.252.0'
network.lan.ip6assign='60'
network.wan=interface
network.wan.device='eth3'
network.wan.proto='dhcp'
network.wan6=interface
network.wan6.device='eth3'
network.wan6.proto='dhcpv6'
network.lan2=interface
network.lan2.device='br-lan2'
network.lan2.proto='static'
network.lan2.ipaddr='192.168.10.1'
network.lan2.netmask='255.255.254.0'
network.device_lan2=device
network.device_lan2.name='br-lan2'
network.device_lan2.ports='eth1'
network.device_lan2.type='bridge'
network.wan2=interface
network.wan2.device='eth2'
network.wan2.proto='dhcp'
network.wan26=interface
network.wan26.device='eth2'
network.wan26.proto='dhcpv6'
network.wgpeer_wg0=wireguard_wg0
network.wgpeer_wg0.endpoint_host='<redacted>'
network.wgpeer_wg0.endpoint_port='51820'
network.wgpeer_wg0.persistent_keepalive='25'
network.wgpeer_wg0.public_key='<redacted>'
network.wgpeer_wg0.route_allowed_ips='1'
network.wgpeer_wg0.allowed_ips='172.17.0.1/32'
network.wg0=interface
network.wg0.listen_port='51820'
network.wg0.mtu='1280'
network.wg0.nohostroute='1'
network.wg0.private_key='<redacted>'
network.wg0.proto='wireguard'
network.wg0.addresses='172.17.0.13/32'

uci show firewall:

firewall.defaults=defaults
firewall.defaults.forward='REJECT'
firewall.defaults.input='REJECT'
firewall.defaults.output='ACCEPT'
firewall.defaults.syn_flood='1'
firewall.defaults.synflood_protect='1'
firewall.zone1=zone
firewall.zone1.forward='ACCEPT'
firewall.zone1.input='ACCEPT'
firewall.zone1.name='lan'
firewall.zone1.output='ACCEPT'
firewall.zone1.network='lan2' 'wg0' 'tun0'
firewall.zone2=zone
firewall.zone2.forward='REJECT'
firewall.zone2.input='REJECT'
firewall.zone2.masq='1'
firewall.zone2.mtu_fix='1'
firewall.zone2.name='wan'
firewall.zone2.output='ACCEPT'
firewall.zone2.network='wan' 'wan2'  
firewall.forwarding1=forwarding
firewall.forwarding1.dest='wan'
firewall.forwarding1.src='lan'
firewall.rule1=rule
firewall.rule1.dest_port='68'
firewall.rule1.family='ipv4'
firewall.rule1.name='Allow-DHCP-Renew'
firewall.rule1.proto='udp'
firewall.rule1.src='wan'
firewall.rule1.target='ACCEPT'
firewall.rule2=rule
firewall.rule2.family='ipv4'
firewall.rule2.icmp_type='echo-request'
firewall.rule2.name='Allow-Ping'
firewall.rule2.proto='icmp'
firewall.rule2.src='wan'
firewall.rule2.target='ACCEPT'
firewall.rule3=rule
firewall.rule3.family='ipv4'
firewall.rule3.name='Allow-IGMP'
firewall.rule3.proto='igmp'
firewall.rule3.src='wan'
firewall.rule3.target='ACCEPT'
firewall.rule4=rule
firewall.rule4.dest_port='546'
firewall.rule4.family='ipv6'
firewall.rule4.name='Allow-DHCPv6'
firewall.rule4.proto='udp'
firewall.rule4.src='wan'
firewall.rule4.target='ACCEPT'
firewall.rule5=rule
firewall.rule5.family='ipv6'
firewall.rule5.icmp_type='130/0' '131/0' '132/0' '143/0'
firewall.rule5.name='Allow-MLD'
firewall.rule5.proto='icmp'
firewall.rule5.src='wan'
firewall.rule5.src_ip='fe80::/10'
firewall.rule5.target='ACCEPT'
firewall.rule6=rule
firewall.rule6.family='ipv6'
firewall.rule6.icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type' 'router-solicitation' 'neighbour-solicitation' 'router-advertisement' 'neighbour-advertisement'
firewall.rule6.limit='1000/sec'
firewall.rule6.name='Allow-ICMPv6-Input'
firewall.rule6.proto='icmp'
firewall.rule6.src='wan'
firewall.rule6.target='ACCEPT'
firewall.rule7=rule
firewall.rule7.dest='*'
firewall.rule7.family='ipv6'
firewall.rule7.icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type'
firewall.rule7.limit='1000/sec'
firewall.rule7.name='Allow-ICMPv6-Forward'
firewall.rule7.proto='icmp'
firewall.rule7.src='wan'
firewall.rule7.target='ACCEPT'
firewall.rule8=rule
firewall.rule8.dest='lan'
firewall.rule8.name='Allow-IPSec-ESP'
firewall.rule8.proto='esp'
firewall.rule8.src='wan'
firewall.rule8.target='ACCEPT'
firewall.rule9=rule
firewall.rule9.dest='lan'
firewall.rule9.dest_port='500'
firewall.rule9.name='Allow-ISAKMP'
firewall.rule9.proto='udp'
firewall.rule9.src='wan'
firewall.rule9.target='ACCEPT'
firewall.captive_zone=zone
firewall.captive_zone.name='captive'
firewall.captive_zone.input='REJECT'
firewall.captive_zone.output='ACCEPT'
firewall.captive_zone.forward='REJECT'
firewall.captive_zone.network='lan'
firewall.whitelist_ipset=ipset
firewall.whitelist_ipset.name='wlist'
firewall.whitelist_ipset.entry='<redacted>'
firewall.whitelist_ipset.match='dest_ip'
firewall.allow_captive_whitelist=rule
firewall.allow_captive_whitelist.dest='wan'
firewall.allow_captive_whitelist.ipset='wlist'
firewall.allow_captive_whitelist.name='Allow-Captive-Whitelist'
firewall.allow_captive_whitelist.proto='any'
firewall.allow_captive_whitelist.src='captive'
firewall.allow_captive_whitelist.target='ACCEPT'
firewall.allow_captive_http=rule
firewall.allow_captive_http.dest_port='80 443 3990 3991'
firewall.allow_captive_http.name='Allow-captive-CPD-WEB-UAM'
firewall.allow_captive_http.proto='tcp'
firewall.allow_captive_http.src='captive'
firewall.allow_captive_http.target='ACCEPT'
firewall.allow_captive_dhcp=rule
firewall.allow_captive_dhcp.dest_port='67 123'
firewall.allow_captive_dhcp.name='Allow-DHCP-NTP-captive'
firewall.allow_captive_dhcp.proto='udp'
firewall.allow_captive_dhcp.src='captive'
firewall.allow_captive_dhcp.target='ACCEPT'
firewall.uspot_ipset=ipset
firewall.uspot_ipset.name='uspot'
firewall.uspot_ipset.match='src_mac'
firewall.dae=rule
firewall.dae.dest_port='3799'
firewall.dae.family='ipv4'
firewall.dae.name='Allow-captive-DAE-public-ip'
firewall.dae.proto='udp'
firewall.dae.src='wan'
firewall.dae.src_ip='<redacted>'
firewall.dae.target='ACCEPT'
firewall.allow_captive_icmp=rule
firewall.allow_captive_icmp.family='ipv4'
firewall.allow_captive_icmp.name='Allow-ICMP-captive'
firewall.allow_captive_icmp.proto='icmp'
firewall.allow_captive_icmp.src='captive'
firewall.allow_captive_icmp.target='ACCEPT'
firewall.allow_dns_captive=rule
firewall.allow_dns_captive.dest_port='53'
firewall.allow_dns_captive.name='Allow-DNS-captive'
firewall.allow_dns_captive.proto='udp' 'tcp'
firewall.allow_dns_captive.src='captive'
firewall.allow_dns_captive.target='ACCEPT'
firewall.captive_cpd=redirect
firewall.captive_cpd.ipset='!uspot'
firewall.captive_cpd.name='Redirect-unauth-captive-CPD'
firewall.captive_cpd.proto='tcp'
firewall.captive_cpd.reflection='0'
firewall.captive_cpd.src='captive'
firewall.captive_cpd.src_dport='80'
firewall.captive_cpd.target='DNAT'
firewall.block_captive_traffic=rule
firewall.block_captive_traffic.dest_ip='!lan'
firewall.block_captive_traffic.name='Restrict-input-captive'
firewall.block_captive_traffic.src='captive'
firewall.block_captive_traffic.target='DROP'
firewall.forward_auth_captive=rule
firewall.forward_auth_captive.dest='wan'
firewall.forward_auth_captive.ipset='uspot'
firewall.forward_auth_captive.name='Forward-captive-authenticated-users'
firewall.forward_auth_captive.proto='any'
firewall.forward_auth_captive.src='captive'
firewall.forward_auth_captive.target='ACCEPT'

uci show uhttpd:

uhttpd.main=uhttpd
uhttpd.main.redirect_https='1'
uhttpd.main.home='/www'
uhttpd.main.rfc1918_filter='1'
uhttpd.main.max_requests='3'
uhttpd.main.max_connections='100'
uhttpd.main.cert='/etc/uhttpd.crt'
uhttpd.main.key='/etc/uhttpd.key'
uhttpd.main.cgi_prefix='/cgi-bin'
uhttpd.main.lua_prefix='/cgi-bin/luci=/usr/lib/lua/luci/sgi/uhttpd.lua'
uhttpd.main.script_timeout='60'
uhttpd.main.network_timeout='30'
uhttpd.main.http_keepalive='20'
uhttpd.main.tcp_keepalive='1'
uhttpd.main.ubus_prefix='/ubus'
uhttpd.main.listen_http='192.168.10.1:80' '[::]:80'
uhttpd.main.listen_https='192.168.10.1:443' '[::]:443'
uhttpd.defaults=cert
uhttpd.defaults.days='397'
uhttpd.defaults.key_type='ec'
uhttpd.defaults.bits='2048'
uhttpd.defaults.ec_curve='P-256'
uhttpd.defaults.country='ZZ'
uhttpd.defaults.state='Somewhere'
uhttpd.defaults.location='Unknown'
uhttpd.defaults.commonname='OWF'
uhttpd.uam3990=uhttpd
uhttpd.uam3990.cert='/etc/x509/<redacted>/cert.pem'
uhttpd.uam3990.home='/www-uspot'
uhttpd.uam3990.key='/etc/x509/<redacted>/key.pem'
uhttpd.uam3990.max_requests='10'
uhttpd.uam3990.no_dirlists='1'
uhttpd.uam3990.redirect_https='0'
uhttpd.uam3990.ucode_prefix='/logon=/usr/share/uspot/handler-uam.uc' '/logoff=/usr/share/uspot/handler-uam.uc' '/logout=/usr/share/uspot/handler-uam.uc'
uhttpd.uam3990.listen_http='192.168.100.1:3990'
uhttpd.uam3990.listen_https='192.168.100.1:3991'
uhttpd.uspot=uhttpd
uhttpd.uspot.cert='/etc/x509/<redacted>/cert.pem'
uhttpd.uspot.error_page='/cpd'
uhttpd.uspot.home='/www-uspot'
uhttpd.uspot.key='/etc/x509/<redacted>/key.pem'
uhttpd.uspot.max_requests='5'
uhttpd.uspot.no_dirlists='1'
uhttpd.uspot.redirect_https='0'
uhttpd.uspot.ucode_prefix='/hotspot=/usr/share/uspot/handler.uc' '/cpd=/usr/share/uspot/handler-cpd.uc' '/api=/usr/share/uspot/handler-api.uc'
uhttpd.uspot.listen_http='192.168.100.1:80'
uhttpd.uspot.listen_https='192.168.100.1:443'

uci show dhcp:

dhcp.dnsmasq1=dnsmasq
dhcp.dnsmasq1.authoritative='1'
dhcp.dnsmasq1.boguspriv='1'
dhcp.dnsmasq1.cachesize='1000'
dhcp.dnsmasq1.domain='lan'
dhcp.dnsmasq1.domainneeded='1'
dhcp.dnsmasq1.ednspacket_max='1232'
dhcp.dnsmasq1.expandhosts='1'
dhcp.dnsmasq1.filter_a='0'
dhcp.dnsmasq1.filter_aaaa='0'
dhcp.dnsmasq1.filterwin2k='0'
dhcp.dnsmasq1.leasefile='/tmp/dhcp.leases'
dhcp.dnsmasq1.local='/lan/'
dhcp.dnsmasq1.localise_queries='1'
dhcp.dnsmasq1.localservice='1'
dhcp.dnsmasq1.nonegcache='0'
dhcp.dnsmasq1.nonwildcard='1'
dhcp.dnsmasq1.readethers='1'
dhcp.dnsmasq1.rebind_localhost='1'
dhcp.dnsmasq1.rebind_protection='1'
dhcp.dnsmasq1.resolvfile='/tmp/resolv.conf.d/resolv.conf.auto'
dhcp.dnsmasq1.address='/<redacted>/192.168.100.1'
dhcp.lan=dhcp
dhcp.lan.interface='lan'
dhcp.lan.start='10'
dhcp.lan.limit='1010'
dhcp.lan.leasetime='24h'
dhcp.lan.dhcpv4='server'
dhcp.lan.dhcpv6='server'
dhcp.lan.ra='server'
dhcp.lan.ra_slaac='1'
dhcp.lan.ra_flags='managed-config' 'other-config'
dhcp.lan.dhcp_option='114,https://<redacted>/api'
dhcp.lan.dhcp_option_force='42,192.168.100.1'
dhcp.wan=dhcp
dhcp.wan.interface='wan'
dhcp.wan.ignore='1'
dhcp.wan.dhcpv6='disabled'
dhcp.wan.ra='disabled'
dhcp.odhcpd=odhcpd
dhcp.odhcpd.maindhcp='0'
dhcp.odhcpd.leasefile='/tmp/hosts/odhcpd'
dhcp.odhcpd.leasetrigger='/usr/sbin/odhcpd-update'
dhcp.odhcpd.loglevel='4'
dhcp.lan2=dhcp
dhcp.lan2.interface='lan2'
dhcp.lan2.start='10'
dhcp.lan2.limit='250'
dhcp.lan2.leasetime='12h'
dhcp.lan2.dhcpv4='server'
dhcp.lan2.ra_slaac='1'
dhcp.lan2.dhcpv6='server'
dhcp.lan2.ra='server'
dhcp.wan2=dhcp
dhcp.wan2.interface='wan2'
dhcp.wan2.ignore='1'
dhcp.wan2.dhcpv6='disabled'
dhcp.wan2.ra='disabled'
dhcp.ipset1=ipset
dhcp.ipset1.domain='bunch-of-domains-here'
dhcp.ipset1.name='wlist'
dhcp.domain1=domain
dhcp.domain1.ip='192.168.100.1'
dhcp.domain1.name='<redacted>'

FreeRADIUS Accounting Request

(9) Retrieved psk identity: <redacted>
(9) Received Accounting-Request Id 250 from [206.83.109.142:3292](http://206.83.109.142:3292/) to [0.0.0.0:2083](http://0.0.0.0:2083/) length 184
(9)   TLS-PSK-Identity := "<redacted>"
(9)   Acct-Status-Type = Interim-Update
(9)   User-Name = "<redacted>"
(9)   Acct-Session-Id = "e5843bef5f2d3953"
(9)   Framed-IP-Address = 192.168.102.145
(9)   Called-Station-Id = "00:D0:B4:04:5E:48"
(9)   Calling-Station-Id = "B2:9D:20:80:74:2A"
(9)   NAS-Identifier = "uspot"
(9)   Acct-Session-Time = 1806
(9)   Acct-Input-Octets = 0
(9)   Acct-Output-Octets = 0
(9)   Acct-Input-Gigawords = 0
(9)   Acct-Output-Gigawords = 0
(9)   Acct-Input-Packets = 0
(9)   Acct-Output-Packets = 0
(9)   WISPr-Location-Name = "<redacted>"
(9)   NAS-Port = 0
(9)   Acct-Delay-Time = 0
(9)   NAS-IP-Address = 192.168.1.159

uspot Client Status (ubus call uspot client_get)

{
  "sessionid": "e5843bef5f2d3953",
  "username": "<redacted>",
  "client_ip": "192.168.102.145",
  "duration": 2529,
  "packets_in": 0,
  "bytes_in": 0,
  "packets_out": 0,
  "bytes_out": 0,
  "connect": 1757595826,
  "data": {
    "sessionid": "e5843bef5f2d3953",
    "username": "<redacted>",
    "client_ip": "192.168.102.145"
  },
  "radius": {
    "reply": {
      "Message-Authenticator": "<redacted>",
      "ChilliSpot-Max-Total-Octets": "1410065408"
    },
    "request": {
      "User-Name": "<redacted>",
      "Calling-Station-Id": "B2:9D:20:80:74:2A",
      "Called-Station-Id": "00:D0:B4:04:5E:48",
      "Acct-Session-Id": "e5843bef5f2d3953",
      "Framed-IP-Address": "192.168.102.145",
      "WISPr-Logoff-URL": "<redacted>",
      "Password": "<redacted>",
      "serv_type": "tls",
      "acct": false,
      "NAS-Identifier": "uspot",
      "WISPr-Location-Name": "<redacted>"
    }
  },
  "state": 1,
  "interval": 60,
  "session": 0,
  "idle": 600,
  "next_interim": 1757598406,
  "maxdown": 0,
  "maxup": 0,
  "maxtotal": 1410065408,
  "bytes_remaining": 1410065408
}

Questions for Investigation

  1. Traffic Data Source: How does uspot collect input/output accounting data? (iptables, netfilter, kernel counters?)

  2. Debugging Options: What additional logging or debug options are available to trace traffic accounting collection?

  3. Known Issues: Are there known race conditions or timing issues that could cause traffic counters to stop updating?

Additional Context

  • Session management appears functional (duration tracking, authentication)
  • RADIUS communication is working (interim updates being sent)
  • Only traffic accounting metrics are affected
  • Issue appears to be at the openwrt level rather than RADIUS communication

Any guidance on enabling additional debugging or known troubleshooting steps would be appreciated.

Originally created by @nemesifier on GitHub (Sep 12, 2025). Original GitHub issue: https://github.com/f00b4r0/uspot/issues/45 I noticed that uspot intermittently reports zero traffic accounting data (input/output octets, packets) for all sessions from affected devices, despite actual network traffic occurring. Issue persists until device reboot, the last time I encountered this it required multiple reboots. ## Environment - current master of uspot - openwrt 24.10 - freeradius + radsec ## Problem Description ### Symptoms - All traffic accounting metrics report as zero: - `Acct-Input-Octets = 0` - `Acct-Output-Octets = 0` - `Acct-Input-Packets = 0` - `Acct-Output-Packets = 0` - Issue affects all sessions from the same device simultaneously - Accounting session time continues to increment normally (`Acct-Session-Time = 1806`) - Problem occurs intermittently across different devices (observed 3 times) ### Resolution - Requires device reboot to restore traffic counting - May require multiple reboots in some cases ## Debug Information ### Configuration `opkg list-installed | grep uspot`: ``` uspot - 2025.08.05~cecd4038-r1 uspot-www - 2025.08.05~cecd4038-r1 uspotfilter - 2025.08.05~cecd4038-r1 ``` `uci show uspot`: ``` uspot.captive=uspot uspot.captive.acct_interval='60' uspot.captive.acct_port='2083' uspot.captive.acct_secret='psk@<redacted>@<redacted>' uspot.captive.acct_server='<redacted>' uspot.captive.auth_mode='uam' uspot.captive.auth_port='2083' uspot.captive.auth_secret='psk@<redacted>@<redacted>' uspot.captive.auth_server='<redacted>' uspot.captive.counters='1' uspot.captive.cpa_venue_url='https://<redacted>/<redacted>/login' uspot.captive.das_port='3799' uspot.captive.das_secret='<redacted>' uspot.captive.debug='1' uspot.captive.disconnect_delay='0' uspot.captive.final_redirect_url='uam' uspot.captive.idle_timeout='600' uspot.captive.interface='lan' uspot.captive.location_name='<redacted>' uspot.captive.mac_auth='0' uspot.captive.mac_format='AA:BB:CC:DD:EE:FF' uspot.captive.nasid='uspot' uspot.captive.nasmac='00:D0:B4:04:5E:48' uspot.captive.rad_serv_type='tls' uspot.captive.session_timeout='0' uspot.captive.setname='uspot' uspot.captive.swapio='1' uspot.captive.uam_port='3991' uspot.captive.uam_server='https://<redacted>/<redacted>/login' uspot.captive.uam_sslurl='https://<redacted>/<redacted>/login' ``` `uci show network`: ``` network.loopback=interface network.loopback.device='lo' network.loopback.proto='static' network.loopback.ipaddr='127.0.0.1' network.loopback.netmask='255.0.0.0' network.globals=globals network.globals.ula_prefix='fd82:76b2:f73b::/48' network.device_lan=device network.device_lan.name='br-lan' network.device_lan.ports='eth0' network.device_lan.type='bridge' network.lan=interface network.lan.device='br-lan' network.lan.proto='static' network.lan.ipaddr='192.168.100.1' network.lan.netmask='255.255.252.0' network.lan.ip6assign='60' network.wan=interface network.wan.device='eth3' network.wan.proto='dhcp' network.wan6=interface network.wan6.device='eth3' network.wan6.proto='dhcpv6' network.lan2=interface network.lan2.device='br-lan2' network.lan2.proto='static' network.lan2.ipaddr='192.168.10.1' network.lan2.netmask='255.255.254.0' network.device_lan2=device network.device_lan2.name='br-lan2' network.device_lan2.ports='eth1' network.device_lan2.type='bridge' network.wan2=interface network.wan2.device='eth2' network.wan2.proto='dhcp' network.wan26=interface network.wan26.device='eth2' network.wan26.proto='dhcpv6' network.wgpeer_wg0=wireguard_wg0 network.wgpeer_wg0.endpoint_host='<redacted>' network.wgpeer_wg0.endpoint_port='51820' network.wgpeer_wg0.persistent_keepalive='25' network.wgpeer_wg0.public_key='<redacted>' network.wgpeer_wg0.route_allowed_ips='1' network.wgpeer_wg0.allowed_ips='172.17.0.1/32' network.wg0=interface network.wg0.listen_port='51820' network.wg0.mtu='1280' network.wg0.nohostroute='1' network.wg0.private_key='<redacted>' network.wg0.proto='wireguard' network.wg0.addresses='172.17.0.13/32' ``` `uci show firewall`: ``` firewall.defaults=defaults firewall.defaults.forward='REJECT' firewall.defaults.input='REJECT' firewall.defaults.output='ACCEPT' firewall.defaults.syn_flood='1' firewall.defaults.synflood_protect='1' firewall.zone1=zone firewall.zone1.forward='ACCEPT' firewall.zone1.input='ACCEPT' firewall.zone1.name='lan' firewall.zone1.output='ACCEPT' firewall.zone1.network='lan2' 'wg0' 'tun0' firewall.zone2=zone firewall.zone2.forward='REJECT' firewall.zone2.input='REJECT' firewall.zone2.masq='1' firewall.zone2.mtu_fix='1' firewall.zone2.name='wan' firewall.zone2.output='ACCEPT' firewall.zone2.network='wan' 'wan2' firewall.forwarding1=forwarding firewall.forwarding1.dest='wan' firewall.forwarding1.src='lan' firewall.rule1=rule firewall.rule1.dest_port='68' firewall.rule1.family='ipv4' firewall.rule1.name='Allow-DHCP-Renew' firewall.rule1.proto='udp' firewall.rule1.src='wan' firewall.rule1.target='ACCEPT' firewall.rule2=rule firewall.rule2.family='ipv4' firewall.rule2.icmp_type='echo-request' firewall.rule2.name='Allow-Ping' firewall.rule2.proto='icmp' firewall.rule2.src='wan' firewall.rule2.target='ACCEPT' firewall.rule3=rule firewall.rule3.family='ipv4' firewall.rule3.name='Allow-IGMP' firewall.rule3.proto='igmp' firewall.rule3.src='wan' firewall.rule3.target='ACCEPT' firewall.rule4=rule firewall.rule4.dest_port='546' firewall.rule4.family='ipv6' firewall.rule4.name='Allow-DHCPv6' firewall.rule4.proto='udp' firewall.rule4.src='wan' firewall.rule4.target='ACCEPT' firewall.rule5=rule firewall.rule5.family='ipv6' firewall.rule5.icmp_type='130/0' '131/0' '132/0' '143/0' firewall.rule5.name='Allow-MLD' firewall.rule5.proto='icmp' firewall.rule5.src='wan' firewall.rule5.src_ip='fe80::/10' firewall.rule5.target='ACCEPT' firewall.rule6=rule firewall.rule6.family='ipv6' firewall.rule6.icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type' 'router-solicitation' 'neighbour-solicitation' 'router-advertisement' 'neighbour-advertisement' firewall.rule6.limit='1000/sec' firewall.rule6.name='Allow-ICMPv6-Input' firewall.rule6.proto='icmp' firewall.rule6.src='wan' firewall.rule6.target='ACCEPT' firewall.rule7=rule firewall.rule7.dest='*' firewall.rule7.family='ipv6' firewall.rule7.icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type' firewall.rule7.limit='1000/sec' firewall.rule7.name='Allow-ICMPv6-Forward' firewall.rule7.proto='icmp' firewall.rule7.src='wan' firewall.rule7.target='ACCEPT' firewall.rule8=rule firewall.rule8.dest='lan' firewall.rule8.name='Allow-IPSec-ESP' firewall.rule8.proto='esp' firewall.rule8.src='wan' firewall.rule8.target='ACCEPT' firewall.rule9=rule firewall.rule9.dest='lan' firewall.rule9.dest_port='500' firewall.rule9.name='Allow-ISAKMP' firewall.rule9.proto='udp' firewall.rule9.src='wan' firewall.rule9.target='ACCEPT' firewall.captive_zone=zone firewall.captive_zone.name='captive' firewall.captive_zone.input='REJECT' firewall.captive_zone.output='ACCEPT' firewall.captive_zone.forward='REJECT' firewall.captive_zone.network='lan' firewall.whitelist_ipset=ipset firewall.whitelist_ipset.name='wlist' firewall.whitelist_ipset.entry='<redacted>' firewall.whitelist_ipset.match='dest_ip' firewall.allow_captive_whitelist=rule firewall.allow_captive_whitelist.dest='wan' firewall.allow_captive_whitelist.ipset='wlist' firewall.allow_captive_whitelist.name='Allow-Captive-Whitelist' firewall.allow_captive_whitelist.proto='any' firewall.allow_captive_whitelist.src='captive' firewall.allow_captive_whitelist.target='ACCEPT' firewall.allow_captive_http=rule firewall.allow_captive_http.dest_port='80 443 3990 3991' firewall.allow_captive_http.name='Allow-captive-CPD-WEB-UAM' firewall.allow_captive_http.proto='tcp' firewall.allow_captive_http.src='captive' firewall.allow_captive_http.target='ACCEPT' firewall.allow_captive_dhcp=rule firewall.allow_captive_dhcp.dest_port='67 123' firewall.allow_captive_dhcp.name='Allow-DHCP-NTP-captive' firewall.allow_captive_dhcp.proto='udp' firewall.allow_captive_dhcp.src='captive' firewall.allow_captive_dhcp.target='ACCEPT' firewall.uspot_ipset=ipset firewall.uspot_ipset.name='uspot' firewall.uspot_ipset.match='src_mac' firewall.dae=rule firewall.dae.dest_port='3799' firewall.dae.family='ipv4' firewall.dae.name='Allow-captive-DAE-public-ip' firewall.dae.proto='udp' firewall.dae.src='wan' firewall.dae.src_ip='<redacted>' firewall.dae.target='ACCEPT' firewall.allow_captive_icmp=rule firewall.allow_captive_icmp.family='ipv4' firewall.allow_captive_icmp.name='Allow-ICMP-captive' firewall.allow_captive_icmp.proto='icmp' firewall.allow_captive_icmp.src='captive' firewall.allow_captive_icmp.target='ACCEPT' firewall.allow_dns_captive=rule firewall.allow_dns_captive.dest_port='53' firewall.allow_dns_captive.name='Allow-DNS-captive' firewall.allow_dns_captive.proto='udp' 'tcp' firewall.allow_dns_captive.src='captive' firewall.allow_dns_captive.target='ACCEPT' firewall.captive_cpd=redirect firewall.captive_cpd.ipset='!uspot' firewall.captive_cpd.name='Redirect-unauth-captive-CPD' firewall.captive_cpd.proto='tcp' firewall.captive_cpd.reflection='0' firewall.captive_cpd.src='captive' firewall.captive_cpd.src_dport='80' firewall.captive_cpd.target='DNAT' firewall.block_captive_traffic=rule firewall.block_captive_traffic.dest_ip='!lan' firewall.block_captive_traffic.name='Restrict-input-captive' firewall.block_captive_traffic.src='captive' firewall.block_captive_traffic.target='DROP' firewall.forward_auth_captive=rule firewall.forward_auth_captive.dest='wan' firewall.forward_auth_captive.ipset='uspot' firewall.forward_auth_captive.name='Forward-captive-authenticated-users' firewall.forward_auth_captive.proto='any' firewall.forward_auth_captive.src='captive' firewall.forward_auth_captive.target='ACCEPT' ``` `uci show uhttpd`: ``` uhttpd.main=uhttpd uhttpd.main.redirect_https='1' uhttpd.main.home='/www' uhttpd.main.rfc1918_filter='1' uhttpd.main.max_requests='3' uhttpd.main.max_connections='100' uhttpd.main.cert='/etc/uhttpd.crt' uhttpd.main.key='/etc/uhttpd.key' uhttpd.main.cgi_prefix='/cgi-bin' uhttpd.main.lua_prefix='/cgi-bin/luci=/usr/lib/lua/luci/sgi/uhttpd.lua' uhttpd.main.script_timeout='60' uhttpd.main.network_timeout='30' uhttpd.main.http_keepalive='20' uhttpd.main.tcp_keepalive='1' uhttpd.main.ubus_prefix='/ubus' uhttpd.main.listen_http='192.168.10.1:80' '[::]:80' uhttpd.main.listen_https='192.168.10.1:443' '[::]:443' uhttpd.defaults=cert uhttpd.defaults.days='397' uhttpd.defaults.key_type='ec' uhttpd.defaults.bits='2048' uhttpd.defaults.ec_curve='P-256' uhttpd.defaults.country='ZZ' uhttpd.defaults.state='Somewhere' uhttpd.defaults.location='Unknown' uhttpd.defaults.commonname='OWF' uhttpd.uam3990=uhttpd uhttpd.uam3990.cert='/etc/x509/<redacted>/cert.pem' uhttpd.uam3990.home='/www-uspot' uhttpd.uam3990.key='/etc/x509/<redacted>/key.pem' uhttpd.uam3990.max_requests='10' uhttpd.uam3990.no_dirlists='1' uhttpd.uam3990.redirect_https='0' uhttpd.uam3990.ucode_prefix='/logon=/usr/share/uspot/handler-uam.uc' '/logoff=/usr/share/uspot/handler-uam.uc' '/logout=/usr/share/uspot/handler-uam.uc' uhttpd.uam3990.listen_http='192.168.100.1:3990' uhttpd.uam3990.listen_https='192.168.100.1:3991' uhttpd.uspot=uhttpd uhttpd.uspot.cert='/etc/x509/<redacted>/cert.pem' uhttpd.uspot.error_page='/cpd' uhttpd.uspot.home='/www-uspot' uhttpd.uspot.key='/etc/x509/<redacted>/key.pem' uhttpd.uspot.max_requests='5' uhttpd.uspot.no_dirlists='1' uhttpd.uspot.redirect_https='0' uhttpd.uspot.ucode_prefix='/hotspot=/usr/share/uspot/handler.uc' '/cpd=/usr/share/uspot/handler-cpd.uc' '/api=/usr/share/uspot/handler-api.uc' uhttpd.uspot.listen_http='192.168.100.1:80' uhttpd.uspot.listen_https='192.168.100.1:443' ``` `uci show dhcp`: ``` dhcp.dnsmasq1=dnsmasq dhcp.dnsmasq1.authoritative='1' dhcp.dnsmasq1.boguspriv='1' dhcp.dnsmasq1.cachesize='1000' dhcp.dnsmasq1.domain='lan' dhcp.dnsmasq1.domainneeded='1' dhcp.dnsmasq1.ednspacket_max='1232' dhcp.dnsmasq1.expandhosts='1' dhcp.dnsmasq1.filter_a='0' dhcp.dnsmasq1.filter_aaaa='0' dhcp.dnsmasq1.filterwin2k='0' dhcp.dnsmasq1.leasefile='/tmp/dhcp.leases' dhcp.dnsmasq1.local='/lan/' dhcp.dnsmasq1.localise_queries='1' dhcp.dnsmasq1.localservice='1' dhcp.dnsmasq1.nonegcache='0' dhcp.dnsmasq1.nonwildcard='1' dhcp.dnsmasq1.readethers='1' dhcp.dnsmasq1.rebind_localhost='1' dhcp.dnsmasq1.rebind_protection='1' dhcp.dnsmasq1.resolvfile='/tmp/resolv.conf.d/resolv.conf.auto' dhcp.dnsmasq1.address='/<redacted>/192.168.100.1' dhcp.lan=dhcp dhcp.lan.interface='lan' dhcp.lan.start='10' dhcp.lan.limit='1010' dhcp.lan.leasetime='24h' dhcp.lan.dhcpv4='server' dhcp.lan.dhcpv6='server' dhcp.lan.ra='server' dhcp.lan.ra_slaac='1' dhcp.lan.ra_flags='managed-config' 'other-config' dhcp.lan.dhcp_option='114,https://<redacted>/api' dhcp.lan.dhcp_option_force='42,192.168.100.1' dhcp.wan=dhcp dhcp.wan.interface='wan' dhcp.wan.ignore='1' dhcp.wan.dhcpv6='disabled' dhcp.wan.ra='disabled' dhcp.odhcpd=odhcpd dhcp.odhcpd.maindhcp='0' dhcp.odhcpd.leasefile='/tmp/hosts/odhcpd' dhcp.odhcpd.leasetrigger='/usr/sbin/odhcpd-update' dhcp.odhcpd.loglevel='4' dhcp.lan2=dhcp dhcp.lan2.interface='lan2' dhcp.lan2.start='10' dhcp.lan2.limit='250' dhcp.lan2.leasetime='12h' dhcp.lan2.dhcpv4='server' dhcp.lan2.ra_slaac='1' dhcp.lan2.dhcpv6='server' dhcp.lan2.ra='server' dhcp.wan2=dhcp dhcp.wan2.interface='wan2' dhcp.wan2.ignore='1' dhcp.wan2.dhcpv6='disabled' dhcp.wan2.ra='disabled' dhcp.ipset1=ipset dhcp.ipset1.domain='bunch-of-domains-here' dhcp.ipset1.name='wlist' dhcp.domain1=domain dhcp.domain1.ip='192.168.100.1' dhcp.domain1.name='<redacted>' ``` ### FreeRADIUS Accounting Request ``` (9) Retrieved psk identity: <redacted> (9) Received Accounting-Request Id 250 from [206.83.109.142:3292](http://206.83.109.142:3292/) to [0.0.0.0:2083](http://0.0.0.0:2083/) length 184 (9) TLS-PSK-Identity := "<redacted>" (9) Acct-Status-Type = Interim-Update (9) User-Name = "<redacted>" (9) Acct-Session-Id = "e5843bef5f2d3953" (9) Framed-IP-Address = 192.168.102.145 (9) Called-Station-Id = "00:D0:B4:04:5E:48" (9) Calling-Station-Id = "B2:9D:20:80:74:2A" (9) NAS-Identifier = "uspot" (9) Acct-Session-Time = 1806 (9) Acct-Input-Octets = 0 (9) Acct-Output-Octets = 0 (9) Acct-Input-Gigawords = 0 (9) Acct-Output-Gigawords = 0 (9) Acct-Input-Packets = 0 (9) Acct-Output-Packets = 0 (9) WISPr-Location-Name = "<redacted>" (9) NAS-Port = 0 (9) Acct-Delay-Time = 0 (9) NAS-IP-Address = 192.168.1.159 ``` ### uspot Client Status (`ubus call uspot client_get`) ```json { "sessionid": "e5843bef5f2d3953", "username": "<redacted>", "client_ip": "192.168.102.145", "duration": 2529, "packets_in": 0, "bytes_in": 0, "packets_out": 0, "bytes_out": 0, "connect": 1757595826, "data": { "sessionid": "e5843bef5f2d3953", "username": "<redacted>", "client_ip": "192.168.102.145" }, "radius": { "reply": { "Message-Authenticator": "<redacted>", "ChilliSpot-Max-Total-Octets": "1410065408" }, "request": { "User-Name": "<redacted>", "Calling-Station-Id": "B2:9D:20:80:74:2A", "Called-Station-Id": "00:D0:B4:04:5E:48", "Acct-Session-Id": "e5843bef5f2d3953", "Framed-IP-Address": "192.168.102.145", "WISPr-Logoff-URL": "<redacted>", "Password": "<redacted>", "serv_type": "tls", "acct": false, "NAS-Identifier": "uspot", "WISPr-Location-Name": "<redacted>" } }, "state": 1, "interval": 60, "session": 0, "idle": 600, "next_interim": 1757598406, "maxdown": 0, "maxup": 0, "maxtotal": 1410065408, "bytes_remaining": 1410065408 } ``` ## Questions for Investigation 1. **Traffic Data Source**: How does uspot collect input/output accounting data? (iptables, netfilter, kernel counters?) 2. **Debugging Options**: What additional logging or debug options are available to trace traffic accounting collection? 3. **Known Issues**: Are there known race conditions or timing issues that could cause traffic counters to stop updating? ## Additional Context - Session management appears functional (duration tracking, authentication) - RADIUS communication is working (interim updates being sent) - Only traffic accounting metrics are affected - Issue appears to be at the openwrt level rather than RADIUS communication Any guidance on enabling additional debugging or known troubleshooting steps would be appreciated.
kerem 2026-03-04 14:52:30 +03:00
Author
Owner

@f00b4r0 commented on GitHub (Sep 12, 2025):

I see you're attaching uspot to a bridge device, I wonder if there's something at play where the BPF module fails to attach while the bridge is "slow" getting ready. I'll add extra error checking in uspot.

Questions for Investigation

Traffic Data Source: How does uspot collect input/output accounting data? (iptables, netfilter, kernel counters?)

#28 (which you reviewed and sponsored)

Debugging Options: What additional logging or debug options are available to trace traffic accounting collection?

You'll need to install bpftool-minimal in order to investigate the bpf module status (whether it is properly loaded or not) otherwise just hold on until I push the extra error checking / reporting.

Off the top of my head, relevant commands would be:

bpftool prog list
bpftool map list

Known Issues: Are there known race conditions or timing issues that could cause traffic counters to stop updating?

So just to be clear: the traffic counters do not stop updating here, they never started updating at all, right? If so, see my initial comment, otherwise the problem lays elsewhere.

HTH

<!-- gh-comment-id:3286456620 --> @f00b4r0 commented on GitHub (Sep 12, 2025): I see you're attaching uspot to a bridge device, I wonder if there's something at play where the BPF module fails to attach while the bridge is "slow" getting ready. I'll add extra error checking in uspot. > Questions for Investigation > > Traffic Data Source: How does uspot collect input/output accounting data? (iptables, netfilter, kernel counters?) #28 (which you reviewed and sponsored) > Debugging Options: What additional logging or debug options are available to trace traffic accounting collection? You'll need to install `bpftool-minimal` in order to investigate the bpf module status (whether it is properly loaded or not) otherwise just hold on until I push the extra error checking / reporting. Off the top of my head, relevant commands would be: ``` bpftool prog list bpftool map list ``` > Known Issues: Are there known race conditions or timing issues that could cause traffic counters to stop updating? So just to be clear: the traffic counters do not stop updating here, they never *started* updating at all, right? If so, see my initial comment, otherwise the problem lays elsewhere. HTH
Author
Owner

@nemesifier commented on GitHub (Sep 12, 2025):

So just to be clear: the traffic counters do not stop updating here, they never started updating at all, right? If so, see my initial comment, otherwise the problem lays elsewhere.

Correct, when this happens, traffic accounting is never reported and it shows as 0/0 for both input and output.

<!-- gh-comment-id:3287015857 --> @nemesifier commented on GitHub (Sep 12, 2025): > So just to be clear: the traffic counters do not stop updating here, they never started updating at all, right? If so, see my initial comment, otherwise the problem lays elsewhere. Correct, when this happens, traffic accounting is never reported and it shows as 0/0 for both input and output.
Author
Owner

@f00b4r0 commented on GitHub (Sep 13, 2025):

@nemesifier I have added some error reporting that may confirm my hunch above, feel free to test current HEAD.

You don't need to rebuild the package, simply take the current uspot.uc and uspotbpf.uc files in https://github.com/f00b4r0/uspot/tree/next/files/usr/share/uspot and dump them on your test device in /usr/share/uspot/, and restart.

<!-- gh-comment-id:3287879741 --> @f00b4r0 commented on GitHub (Sep 13, 2025): @nemesifier I have added some error reporting that may confirm my hunch above, feel free to test current HEAD. You don't need to rebuild the package, simply take the current `uspot.uc` and `uspotbpf.uc` files in https://github.com/f00b4r0/uspot/tree/next/files/usr/share/uspot and dump them on your test device in `/usr/share/uspot/`, and restart.
Author
Owner

@nemesifier commented on GitHub (Sep 15, 2025):

I have a device where I can replicate this consistently.

This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network.

Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes.

I have done the changes to those two files, what should I look for in the logs?

<!-- gh-comment-id:3293577622 --> @nemesifier commented on GitHub (Sep 15, 2025): I have a device where I can replicate this consistently. This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network. Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes. I have done the changes to those two files, what should I look for in the logs?
Author
Owner

@f00b4r0 commented on GitHub (Sep 15, 2025):

I have a device where I can replicate this consistently.

This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network.

OK but then why do you use a bridge device there?

Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes.

I have done the changes to those two files, what should I look for in the logs?

any error message prefixed with "uspot"

<!-- gh-comment-id:3293584429 --> @f00b4r0 commented on GitHub (Sep 15, 2025): > I have a device where I can replicate this consistently. > > This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network. OK but then why do you use a bridge device there? > Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes. > > I have done the changes to those two files, what should I look for in the logs? any error message prefixed with "uspot"
Author
Owner

@nemesifier commented on GitHub (Sep 15, 2025):

I have a device where I can replicate this consistently.
This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network.

OK but then why do you use a bridge device there?

It's basically the same hardware without WiFi, so we're testing out the same configuration on both.

Let me try changing it to see what happens without the bridge.

Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes.
I have done the changes to those two files, what should I look for in the logs?

any error message prefixed with "uspot"

At the moment I don't see any error:

Mon Sep 15 19:16:55 2025 daemon.debug uspot-radius[7919]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:16:57 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client
Mon Sep 15 19:16:57 2025 daemon.err uhttpd[3388]: uspot: 192.168.101.178 - allowing client
Mon Sep 15 19:16:57 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client
Mon Sep 15 19:16:57 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start
Mon Sep 15 19:16:58 2025 daemon.debug uspot-radius[7933]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:18:04 2025 daemon.debug uspot-radius[8241]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:18:05 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:18:05 2025 authpriv.info dropbear[8252]: Child connection from fe80::b5a1:b643:f4ee:34ad%eth3:49932
Mon Sep 15 19:18:05 2025 authpriv.notice dropbear[8252]: Pubkey auth succeeded for 'root' with ssh-rsa key SHA256:o5vp0hTpdI2DyrE5ylRhcGYNBHsu/bXRFex4y3dgP8A from fe80::b5a1:b643:f4ee:34ad%eth3:49932
Mon Sep 15 19:19:05 2025 daemon.debug uspot-radius[8544]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:19:07 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:19:57 2025 daemon.debug uspot-radius[8783]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:19:58 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:20:59 2025 daemon.debug uspot-radius[9123]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:21:00 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:22:00 2025 daemon.debug uspot-radius[9408]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083
Mon Sep 15 19:22:02 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
<!-- gh-comment-id:3293604526 --> @nemesifier commented on GitHub (Sep 15, 2025): > > I have a device where I can replicate this consistently. > > This device does not have WiFi, only ethernet, the traffic will flow through it via ethernet from other WiFi APs in the network. > > OK but then why do you use a bridge device there? It's basically the same hardware without WiFi, so we're testing out the same configuration on both. Let me try changing it to see what happens without the bridge. > > Rebooting here doesn't seem to work. Accounting traffic always shows zero bytes. > > I have done the changes to those two files, what should I look for in the logs? > > any error message prefixed with "uspot" At the moment I don't see any error: ``` Mon Sep 15 19:16:55 2025 daemon.debug uspot-radius[7919]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:16:57 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client Mon Sep 15 19:16:57 2025 daemon.err uhttpd[3388]: uspot: 192.168.101.178 - allowing client Mon Sep 15 19:16:57 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client Mon Sep 15 19:16:57 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start Mon Sep 15 19:16:58 2025 daemon.debug uspot-radius[7933]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:18:04 2025 daemon.debug uspot-radius[8241]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:18:05 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:18:05 2025 authpriv.info dropbear[8252]: Child connection from fe80::b5a1:b643:f4ee:34ad%eth3:49932 Mon Sep 15 19:18:05 2025 authpriv.notice dropbear[8252]: Pubkey auth succeeded for 'root' with ssh-rsa key SHA256:o5vp0hTpdI2DyrE5ylRhcGYNBHsu/bXRFex4y3dgP8A from fe80::b5a1:b643:f4ee:34ad%eth3:49932 Mon Sep 15 19:19:05 2025 daemon.debug uspot-radius[8544]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:19:07 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:19:57 2025 daemon.debug uspot-radius[8783]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:19:58 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:20:59 2025 daemon.debug uspot-radius[9123]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:21:00 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:22:00 2025 daemon.debug uspot-radius[9408]: radcli: init_session: init_session: performing TLS/DTLS handshake with [nms.keyidea.tech]:2083 Mon Sep 15 19:22:02 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call ```
Author
Owner

@f00b4r0 commented on GitHub (Sep 15, 2025):

Check at the earliest point in logread. The error message would be printed at uspot startup.
Thanks

<!-- gh-comment-id:3293607517 --> @f00b4r0 commented on GitHub (Sep 15, 2025): Check at the earliest point in logread. The error message would be printed at uspot startup. Thanks
Author
Owner

@nemesifier commented on GitHub (Sep 15, 2025):

The problem does not appear if the interface is not a bridge.

I restored the bridge configuration to debug the issue, here's the uspot log lines (logread | grep uspot):

Mon Sep 15 19:31:48 2025 kern.warn kernel: [   16.789927] uspot.uc[4088]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
Mon Sep 15 19:31:53 2025 daemon.err uspot-radius[4240]: radcli: init_session: init_session: cannot resolve <domain-name-redacted>
Mon Sep 15 19:31:53 2025 daemon.crit uspot-radius[4240]: radcli: rc_apply_config: error initializing tls
Mon Sep 15 19:31:53 2025 daemon.err uspot-radius: Failed to apply radcli config!
Mon Sep 15 19:31:53 2025 daemon.debug uspot: captive acct-on call
Mon Sep 15 19:35:16 2025 daemon.err uhttpd[3364]: uspot: 192.168.101.178 - logging client off
Mon Sep 15 19:35:22 2025 daemon.debug uspot-radius[8088]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:35:24 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client
Mon Sep 15 19:35:24 2025 daemon.err uhttpd[3364]: uspot: 192.168.101.178 - allowing client
Mon Sep 15 19:35:24 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client
Mon Sep 15 19:35:24 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start
Mon Sep 15 19:35:25 2025 daemon.debug uspot-radius[8103]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:36:25 2025 daemon.debug uspot-radius[8385]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:36:26 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:37:26 2025 daemon.debug uspot-radius[8681]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:37:28 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:38:28 2025 daemon.debug uspot-radius[9012]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:38:29 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Mon Sep 15 19:39:30 2025 daemon.debug uspot-radius[9303]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083
Mon Sep 15 19:39:31 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
<!-- gh-comment-id:3293671206 --> @nemesifier commented on GitHub (Sep 15, 2025): The problem does not appear if the interface is not a bridge. I restored the bridge configuration to debug the issue, here's the uspot log lines (`logread | grep uspot`): ``` Mon Sep 15 19:31:48 2025 kern.warn kernel: [ 16.789927] uspot.uc[4088]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Mon Sep 15 19:31:53 2025 daemon.err uspot-radius[4240]: radcli: init_session: init_session: cannot resolve <domain-name-redacted> Mon Sep 15 19:31:53 2025 daemon.crit uspot-radius[4240]: radcli: rc_apply_config: error initializing tls Mon Sep 15 19:31:53 2025 daemon.err uspot-radius: Failed to apply radcli config! Mon Sep 15 19:31:53 2025 daemon.debug uspot: captive acct-on call Mon Sep 15 19:35:16 2025 daemon.err uhttpd[3364]: uspot: 192.168.101.178 - logging client off Mon Sep 15 19:35:22 2025 daemon.debug uspot-radius[8088]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:35:24 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client Mon Sep 15 19:35:24 2025 daemon.err uhttpd[3364]: uspot: 192.168.101.178 - allowing client Mon Sep 15 19:35:24 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client Mon Sep 15 19:35:24 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start Mon Sep 15 19:35:25 2025 daemon.debug uspot-radius[8103]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:36:25 2025 daemon.debug uspot-radius[8385]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:36:26 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:37:26 2025 daemon.debug uspot-radius[8681]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:37:28 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:38:28 2025 daemon.debug uspot-radius[9012]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:38:29 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Mon Sep 15 19:39:30 2025 daemon.debug uspot-radius[9303]: radcli: init_session: init_session: performing TLS/DTLS handshake with [<domain-name-redacted>]:2083 Mon Sep 15 19:39:31 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call ```
Author
Owner

@f00b4r0 commented on GitHub (Sep 16, 2025):

Some extra questions:

  • what's the device model?
  • you mention RadSec in the title, do you mean to suggest that the bug doesn't occur when not using RadSec?
<!-- gh-comment-id:3296756047 --> @f00b4r0 commented on GitHub (Sep 16, 2025): Some extra questions: - what's the device model? - you mention RadSec in the title, do you mean to suggest that the bug doesn't occur when not using RadSec?
Author
Owner

@nemesifier commented on GitHub (Sep 16, 2025):

Some extra questions:

  • what's the device model?

x86 target, CWWK Mini PC, (Intel(R) Celeron(R) CPU N2840 @ 2.16GHz)

  • you mention RadSec in the title, do you mean to suggest that the bug doesn't occur when not using RadSec?

I will try without RadSec and come back on this.

<!-- gh-comment-id:3299714506 --> @nemesifier commented on GitHub (Sep 16, 2025): > Some extra questions: > > * what's the device model? x86 target, CWWK Mini PC, (Intel(R) Celeron(R) CPU N2840 @ 2.16GHz) > * you mention RadSec in the title, do you mean to suggest that the bug doesn't occur when not using RadSec? I will try without RadSec and come back on this.
Author
Owner

@nemesifier commented on GitHub (Sep 17, 2025):

Update: it happens also without RadSec, only the uspot config file changes, here's the version without radsec:

uspot.captive=uspot
uspot.captive.acct_interval='60'
uspot.captive.acct_port='1813'
uspot.captive.acct_secret='<redacted>'
uspot.captive.acct_server='<redacted>'
uspot.captive.auth_mode='uam'
uspot.captive.auth_port='1812'
uspot.captive.auth_secret='<redacted>'
uspot.captive.auth_server='<redacted>'
uspot.captive.cpa_venue_url='<redacted>'
uspot.captive.das_port='3799'
uspot.captive.das_secret='<redacted>'
uspot.captive.debug='1'
uspot.captive.disconnect_delay='0'
uspot.captive.final_redirect_url='uam'
uspot.captive.idle_timeout='600'
uspot.captive.interface='lan'
uspot.captive.location_name='<redacted>'
uspot.captive.mac_auth='0'
uspot.captive.mac_format='AA:BB:CC:DD:EE:FF'
uspot.captive.nasid='uspot'
uspot.captive.nasmac='<redacted>'
uspot.captive.session_timeout='0'
uspot.captive.setname='uspot'
uspot.captive.uam_port='3991'
uspot.captive.uam_server='<redacted>'
uspot.captive.uam_sslurl='<redacted>'
uspot.captive.counters='1'
uspot.captive.swapio='1'

Logs:

Wed Sep 17 20:44:16 2025 kern.warn kernel: [   16.736398] uspot.uc[4090]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_get_srcaddr: rc_get_srcaddr: connect: Network unreachable
Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_send_server_ctx: rc_send_server: cannot figure our own address
Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_get_srcaddr: rc_get_srcaddr: connect: Network unreachable
Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_send_server_ctx: rc_send_server: cannot figure our own address
Wed Sep 17 20:44:16 2025 daemon.debug uspot: captive acct-on call
Wed Sep 17 20:53:39 2025 daemon.err uhttpd[3399]: uspot: 192.168.100.172 - start uam flow
Wed Sep 17 20:57:30 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client
Wed Sep 17 20:57:30 2025 daemon.err uhttpd[3398]: uspot: 192.168.100.172 - allowing client
Wed Sep 17 20:57:30 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client
Wed Sep 17 20:57:30 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start
Wed Sep 17 20:58:37 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call
Wed Sep 17 20:59:38 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call

I don't see any log line related to the logging added in github.com/f00b4r0/uspot@46e66c1eb0.

Here's the output of ubus call uspot client_get '{"uspot": "captive"}':

{
	"a0:ce:c8:17:ad:e8": {
		"sessionid": "5cb44f5454b6c4a0",
		"username": "<redacted>",
		"client_ip": "192.168.100.172",
		"duration": 265,
		"packets_in": 0,
		"bytes_in": 0,
		"packets_out": 0,
		"bytes_out": 0,
		"connect": 1758142650,
		"data": {
			"sessionid": "5cb44f5454b6c4a0",
			"username": "<redacted>",
			"client_ip": "192.168.100.172"
		},
		"radius": {
			"reply": {
				"Message-Authenticator": "<redacted>"
			},
			"request": {
				"User-Name": "<redacted>",
				"Calling-Station-Id": "A0:CE:C8:17:AD:E8",
				"Called-Station-Id": "28:B1:33:05:E8:15",
				"Acct-Session-Id": "5cb44f5454b6c4a0",
				"Framed-IP-Address": "192.168.100.172",
				"WISPr-Logoff-URL": "<redacted>",
				"Password": "<redacted>",
				"acct": false,
				"NAS-Identifier": "uspot",
				"WISPr-Location-Name": "<redacted>"
			}
		},
		"state": 1,
		"interval": 60,
		"session": 0,
		"idle": 600,
		"next_interim": 1758142950
	}
}

PS: is there any other log line we can add to get some more info?

<!-- gh-comment-id:3304574056 --> @nemesifier commented on GitHub (Sep 17, 2025): Update: it happens also without RadSec, only the uspot config file changes, here's the version without radsec: ``` uspot.captive=uspot uspot.captive.acct_interval='60' uspot.captive.acct_port='1813' uspot.captive.acct_secret='<redacted>' uspot.captive.acct_server='<redacted>' uspot.captive.auth_mode='uam' uspot.captive.auth_port='1812' uspot.captive.auth_secret='<redacted>' uspot.captive.auth_server='<redacted>' uspot.captive.cpa_venue_url='<redacted>' uspot.captive.das_port='3799' uspot.captive.das_secret='<redacted>' uspot.captive.debug='1' uspot.captive.disconnect_delay='0' uspot.captive.final_redirect_url='uam' uspot.captive.idle_timeout='600' uspot.captive.interface='lan' uspot.captive.location_name='<redacted>' uspot.captive.mac_auth='0' uspot.captive.mac_format='AA:BB:CC:DD:EE:FF' uspot.captive.nasid='uspot' uspot.captive.nasmac='<redacted>' uspot.captive.session_timeout='0' uspot.captive.setname='uspot' uspot.captive.uam_port='3991' uspot.captive.uam_server='<redacted>' uspot.captive.uam_sslurl='<redacted>' uspot.captive.counters='1' uspot.captive.swapio='1' ``` Logs: ``` Wed Sep 17 20:44:16 2025 kern.warn kernel: [ 16.736398] uspot.uc[4090]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_get_srcaddr: rc_get_srcaddr: connect: Network unreachable Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_send_server_ctx: rc_send_server: cannot figure our own address Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_get_srcaddr: rc_get_srcaddr: connect: Network unreachable Wed Sep 17 20:44:16 2025 daemon.err uspot-radius[4206]: radcli: rc_send_server_ctx: rc_send_server: cannot figure our own address Wed Sep 17 20:44:16 2025 daemon.debug uspot: captive acct-on call Wed Sep 17 20:53:39 2025 daemon.err uhttpd[3399]: uspot: 192.168.100.172 - start uam flow Wed Sep 17 20:57:30 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 creating client Wed Sep 17 20:57:30 2025 daemon.err uhttpd[3398]: uspot: 192.168.100.172 - allowing client Wed Sep 17 20:57:30 2025 daemon.info uspot: captive a0:ce:c8:17:ad:e8 adding client Wed Sep 17 20:57:30 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 acct start Wed Sep 17 20:58:37 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call Wed Sep 17 20:59:38 2025 daemon.debug uspot: captive a0:ce:c8:17:ad:e8 interim acct call ``` I don't see any log line related to the logging added in https://github.com/f00b4r0/uspot/commit/46e66c1eb01edc94e6c8461b0136dc6cc7293da2. Here's the output of `ubus call uspot client_get '{"uspot": "captive"}'`: ```json { "a0:ce:c8:17:ad:e8": { "sessionid": "5cb44f5454b6c4a0", "username": "<redacted>", "client_ip": "192.168.100.172", "duration": 265, "packets_in": 0, "bytes_in": 0, "packets_out": 0, "bytes_out": 0, "connect": 1758142650, "data": { "sessionid": "5cb44f5454b6c4a0", "username": "<redacted>", "client_ip": "192.168.100.172" }, "radius": { "reply": { "Message-Authenticator": "<redacted>" }, "request": { "User-Name": "<redacted>", "Calling-Station-Id": "A0:CE:C8:17:AD:E8", "Called-Station-Id": "28:B1:33:05:E8:15", "Acct-Session-Id": "5cb44f5454b6c4a0", "Framed-IP-Address": "192.168.100.172", "WISPr-Logoff-URL": "<redacted>", "Password": "<redacted>", "acct": false, "NAS-Identifier": "uspot", "WISPr-Location-Name": "<redacted>" } }, "state": 1, "interval": 60, "session": 0, "idle": 600, "next_interim": 1758142950 } } ``` PS: is there any other log line we can add to get some more info?
Author
Owner

@f00b4r0 commented on GitHub (Sep 18, 2025):

Can you check the output of the bpftool commands?

<!-- gh-comment-id:3308735255 --> @f00b4r0 commented on GitHub (Sep 18, 2025): Can you check the output of the bpftool commands?
Author
Owner

@nemesifier commented on GitHub (Sep 18, 2025):

Can you check the output of the bpftool commands?

Sure, I am not familiar with this, what commands should I use or how do I get the output? Thx.

<!-- gh-comment-id:3309196976 --> @nemesifier commented on GitHub (Sep 18, 2025): > Can you check the output of the bpftool commands? Sure, I am not familiar with this, what commands should I use or how do I get the output? Thx.
Author
Owner

@f00b4r0 commented on GitHub (Sep 18, 2025):

From https://github.com/f00b4r0/uspot/issues/45#issuecomment-3286456620

bpftool prog list
bpftool map list
<!-- gh-comment-id:3309267553 --> @f00b4r0 commented on GitHub (Sep 18, 2025): From https://github.com/f00b4r0/uspot/issues/45#issuecomment-3286456620 ``` bpftool prog list bpftool map list ```
Author
Owner

@f00b4r0 commented on GitHub (Sep 19, 2025):

Also thinking out loud but instead of a reboot, have you tried restarting just uspot (/etc/init.d/uspot restart)?
This would help narrow down the issue if this works.

<!-- gh-comment-id:3310984006 --> @f00b4r0 commented on GitHub (Sep 19, 2025): Also thinking out loud but instead of a reboot, have you tried restarting *just* uspot (`/etc/init.d/uspot restart`)? This would help narrow down the issue if this works.
Author
Owner

@nemesifier commented on GitHub (Sep 22, 2025):

Also thinking out loud but instead of a reboot, have you tried restarting just uspot (/etc/init.d/uspot restart)? This would help narrow down the issue if this works.

Yes, we did try that. The result is not consistent. Sometimes even rebooting doesn't fix it.

I collected the output of bpftool prog list and bpftool map list on a few devices.

I tried this on a few devices.

2 devices that were showing the problem today:

~ # bpftool prog list
4: sched_cls  name uspotbpf_acct_i  tag 18644c9bad4cd4eb  gpl
	loaded_at 2025-09-22T15:37:55+0000  uid 0
	xlated 232B  jited 140B  memlock 4096B  map_ids 1
	btf_id 10
5: sched_cls  name uspotbpf_acct_o  tag d1fda714f9864b9b  gpl
	loaded_at 2025-09-22T15:37:55+0000  uid 0
	xlated 224B  jited 136B  memlock 4096B  map_ids 1
	btf_id 10
~ # bpftool map list
1: hash  name m_clients  flags 0x1
	key 6B  value 40B  max_entries 10000  memlock 263584B
~ # bpftool prog list
4: sched_cls  name uspotbpf_acct_i  tag 18644c9bad4cd4eb  gpl
	loaded_at 2025-09-22T03:00:32+0000  uid 0
	xlated 232B  jited 140B  memlock 4096B  map_ids 1
	btf_id 10
5: sched_cls  name uspotbpf_acct_o  tag d1fda714f9864b9b  gpl
	loaded_at 2025-09-22T03:00:32+0000  uid 0
	xlated 224B  jited 136B  memlock 4096B  map_ids 1
	btf_id 10
~ # bpftool map list
1: hash  name m_clients  flags 0x1
	key 6B  value 40B  max_entries 10000  memlock 263376B

One device which was working fine:

~ # bpftool prog list
4: sched_cls  name uspotbpf_acct_i  tag 18644c9bad4cd4eb  gpl
	loaded_at 2025-09-22T03:00:32+0000  uid 0
	xlated 232B  jited 140B  memlock 4096B  map_ids 1
	btf_id 10
5: sched_cls  name uspotbpf_acct_o  tag d1fda714f9864b9b  gpl
	loaded_at 2025-09-22T03:00:32+0000  uid 0
	xlated 224B  jited 136B  memlock 4096B  map_ids 1
	btf_id 10
~ # bpftool map list
1: hash  name m_clients  flags 0x1
	key 6B  value 40B  max_entries 10000  memlock 263584B

I kept restarting uspot or rebooting a particular device which was showing the issues until the problem went away (in order: first I reboot, then I restarted uspot without reboot, then I rebooted again, only after this sequence the problem went away). Now I ran the commands again on it:

~ # bpftool prog list
4: sched_cls  name uspotbpf_acct_i  tag 18644c9bad4cd4eb  gpl
	loaded_at 2025-09-22T18:59:56+0000  uid 0
	xlated 232B  jited 140B  memlock 4096B  map_ids 1
	btf_id 10
5: sched_cls  name uspotbpf_acct_o  tag d1fda714f9864b9b  gpl
	loaded_at 2025-09-22T18:59:56+0000  uid 0
	xlated 224B  jited 136B  memlock 4096B  map_ids 1
	btf_id 10
~ # bpftool map list
1: hash  name m_clients  flags 0x1
	key 6B  value 40B  max_entries 10000  memlock 263480B

Do you see any significant difference?

<!-- gh-comment-id:3321054833 --> @nemesifier commented on GitHub (Sep 22, 2025): > Also thinking out loud but instead of a reboot, have you tried restarting _just_ uspot (`/etc/init.d/uspot restart`)? This would help narrow down the issue if this works. Yes, we did try that. The result is not consistent. Sometimes even rebooting doesn't fix it. I collected the output of `bpftool prog list` and `bpftool map list` on a few devices. I tried this on a few devices. 2 devices that were showing the problem today: ``` ~ # bpftool prog list 4: sched_cls name uspotbpf_acct_i tag 18644c9bad4cd4eb gpl loaded_at 2025-09-22T15:37:55+0000 uid 0 xlated 232B jited 140B memlock 4096B map_ids 1 btf_id 10 5: sched_cls name uspotbpf_acct_o tag d1fda714f9864b9b gpl loaded_at 2025-09-22T15:37:55+0000 uid 0 xlated 224B jited 136B memlock 4096B map_ids 1 btf_id 10 ~ # bpftool map list 1: hash name m_clients flags 0x1 key 6B value 40B max_entries 10000 memlock 263584B ``` ``` ~ # bpftool prog list 4: sched_cls name uspotbpf_acct_i tag 18644c9bad4cd4eb gpl loaded_at 2025-09-22T03:00:32+0000 uid 0 xlated 232B jited 140B memlock 4096B map_ids 1 btf_id 10 5: sched_cls name uspotbpf_acct_o tag d1fda714f9864b9b gpl loaded_at 2025-09-22T03:00:32+0000 uid 0 xlated 224B jited 136B memlock 4096B map_ids 1 btf_id 10 ~ # bpftool map list 1: hash name m_clients flags 0x1 key 6B value 40B max_entries 10000 memlock 263376B ``` One device which was working fine: ``` ~ # bpftool prog list 4: sched_cls name uspotbpf_acct_i tag 18644c9bad4cd4eb gpl loaded_at 2025-09-22T03:00:32+0000 uid 0 xlated 232B jited 140B memlock 4096B map_ids 1 btf_id 10 5: sched_cls name uspotbpf_acct_o tag d1fda714f9864b9b gpl loaded_at 2025-09-22T03:00:32+0000 uid 0 xlated 224B jited 136B memlock 4096B map_ids 1 btf_id 10 ~ # bpftool map list 1: hash name m_clients flags 0x1 key 6B value 40B max_entries 10000 memlock 263584B ``` I kept restarting uspot or rebooting a particular device which was showing the issues until the problem went away (in order: first I reboot, then I restarted uspot without reboot, then I rebooted again, only after this sequence the problem went away). Now I ran the commands again on it: ``` ~ # bpftool prog list 4: sched_cls name uspotbpf_acct_i tag 18644c9bad4cd4eb gpl loaded_at 2025-09-22T18:59:56+0000 uid 0 xlated 232B jited 140B memlock 4096B map_ids 1 btf_id 10 5: sched_cls name uspotbpf_acct_o tag d1fda714f9864b9b gpl loaded_at 2025-09-22T18:59:56+0000 uid 0 xlated 224B jited 136B memlock 4096B map_ids 1 btf_id 10 ~ # bpftool map list 1: hash name m_clients flags 0x1 key 6B value 40B max_entries 10000 memlock 263480B ``` Do you see any significant difference?
Author
Owner

@nemesifier commented on GitHub (Sep 22, 2025):

Is there a chance this is an interaction with SQM?

On the device I have with me which only has ethernet and always shows the issue, if I turn off SQM and restart the network stack with /etc/init.d/network restart, then restart uspot and start a new session, accounting works fine.

SQM config triggering this:

~ # cat /etc/config/sqm 
config queue 'sqm_br_lan'
	option debug_logging '0'
	option download '50000'
	option enabled '1'
	option interface 'br-lan'
	option linklayer 'ethernet'
	option qdisc 'cake'
	option script 'piece_of_cake.qos'
	option upload '50000'
	option verbosity '5'
<!-- gh-comment-id:3321598272 --> @nemesifier commented on GitHub (Sep 22, 2025): Is there a chance this is an interaction with [SQM](https://openwrt.org/docs/guide-user/network/traffic-shaping/sqm)? On the device I have with me which only has ethernet and always shows the issue, if I turn off SQM and restart the network stack with `/etc/init.d/network restart`, then restart uspot and start a new session, accounting works fine. SQM config triggering this: ``` ~ # cat /etc/config/sqm config queue 'sqm_br_lan' option debug_logging '0' option download '50000' option enabled '1' option interface 'br-lan' option linklayer 'ethernet' option qdisc 'cake' option script 'piece_of_cake.qos' option upload '50000' option verbosity '5' ```
Author
Owner

@f00b4r0 commented on GitHub (Sep 23, 2025):

Is there a chance this is an interaction with SQM?

Definitely, now that you mention it. Looking at the "piece_of_cake.qos" script you're using, it could certainly interfere with uspot as it deletes root qdiscs upon start. If it restarts after uspot (as it might when the bridge state changes as the bridged interfaces come up), it will wipe the uspot ebpf accounting module. Furthermore it sets a very high priority for the ifb redirection which will also prevent the ebpf module from seeing any inbound traffic.

On the device I have with me which only has ethernet and always shows the issue, if I turn off SQM and restart the network stack with /etc/init.d/network restart, then restart uspot and start a new session, accounting works fine.

Forgive me for asking but why would you attach an SQM instance to a bridge interface, and what's more to a lan bridge interface? I'm afraid it makes no sense to me.

<!-- gh-comment-id:3323639531 --> @f00b4r0 commented on GitHub (Sep 23, 2025): > Is there a chance this is an interaction with [SQM](https://openwrt.org/docs/guide-user/network/traffic-shaping/sqm)? Definitely, now that you mention it. Looking at the "piece_of_cake.qos" script you're using, it could certainly interfere with uspot as it deletes root qdiscs upon start. If it restarts after uspot (as it might when the bridge state changes as the bridged interfaces come up), it will wipe the uspot ebpf accounting module. Furthermore it sets a very high priority for the ifb redirection which will also prevent the ebpf module from seeing any inbound traffic. > On the device I have with me which only has ethernet and always shows the issue, if I turn off SQM and restart the network stack with `/etc/init.d/network restart`, then restart uspot and start a new session, accounting works fine. Forgive me for asking but why would you attach an SQM instance to a *bridge* interface, and what's more to a *lan* bridge interface? I'm afraid it makes no sense to me.
Author
Owner

@nemesifier commented on GitHub (Sep 23, 2025):

We were applying overall bandwidth limits with SQM when the RADIUS attribute weren't working, then we forgot this piece of config here.

<!-- gh-comment-id:3323839934 --> @nemesifier commented on GitHub (Sep 23, 2025): We were applying overall bandwidth limits with SQM when the RADIUS attribute weren't working, then we forgot this piece of config here.
Author
Owner

@f00b4r0 commented on GitHub (Sep 23, 2025):

OK but SQM scripts isn't designed to operate on the LAN side, much less on a bridge device. If you want to enforce bw limits on the LAN side you should use dedicated traffic shaping tools instead. Since it is now clear that this is a bug induced by SQM-scripts interaction, I think it can be safely ignored.

<!-- gh-comment-id:3324619468 --> @f00b4r0 commented on GitHub (Sep 23, 2025): OK but SQM scripts isn't designed to operate on the LAN side, much less on a bridge device. If you want to enforce bw limits on the LAN side you should use dedicated traffic shaping tools instead. Since it is now clear that this is a bug induced by SQM-scripts interaction, I think it can be safely ignored.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/uspot#30
No description provided.