Advisory: Support Portal Maintenance. Login is currently unavailable, more info available here.

[9.705-3] Access Points go Inactive

Hi Community!

our Access Points are going Inactive twice per day.
They still react to a Ping, but the UTM ist listing them as Inactive. A Reboot of the HA-Master reactivates the Access Points. I don't have a clue what causes this behaviour, so any ideas are welcomed!

We have arount 20 Access Points, from AP10 to APX320

Kind Regards
Michael

  • Hello Michael,

    Thank you for contacting the Sohos Community!

    When this issue happens, what does the /var/log/wireless.log says? anything under fallback.log, confd-debug.log

    Regards,


     
    Emmanuel (EmmoSophos)
    Community Support Engineer | Sophos Technical Support
    Sophos Support VideosProduct Documentation  |  @SophosSupport  | Sign up for SMS Alerts
    If a post solves your question use the 'Verify Answer' link.
  • Hi Emmanuel,

    thank you for your reply!
    I don't know what errors should look like, so i posted the wireless.log:

    wireless.log 

    2020:11:28-01:09:42 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-01:09:43 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-03:28:02 192.168.2.128 netifd: lan (763): Sending renew...
    2020:11:28-03:28:02 192.168.2.128 netifd: lan (763): Lease of 192.168.2.128 obtained, lease time 86400
    2020:11:28-04:09:49 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-04:09:50 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-05:27:44 A40039023B1A3FF netifd: lan (969): Sending renew...
    2020:11:28-05:27:44 A40039023B1A3FF netifd: lan (969): Lease of 192.168.2.131 obtained, lease time 86400
    2020:11:28-05:27:49 A4003982651BE34 netifd: lan (968): Sending renew...
    2020:11:28-05:27:49 A4003982651BE34 netifd: lan (968): Lease of 192.168.2.132 obtained, lease time 86400
    2020:11:28-05:34:41 A4003945F9874DB netifd: lan (968): Sending renew...
    2020:11:28-05:34:41 A4003945F9874DB netifd: lan (968): Lease of 192.168.2.244 obtained, lease time 86400
    2020:11:28-07:09:56 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-07:09:57 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-07:38:58 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: authenticated
    2020:11:28-07:38:58 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: associated (aid 1)
    2020:11:28-07:38:58 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae RADIUS: starting accounting session 5FC08BDD-00000003
    2020:11:28-07:38:58 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae WPA: pairwise key handshake completed (RSN)
    2020:11:28-07:38:58 A4003945F9874DB awelogger[5358]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-07:38:58 A4003945F9874DB awelogger[5358]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-07:38:58 A4003945F9874DB awelogger[5358]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-07:40:47 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: disassociated
    2020:11:28-07:40:47 A4003945F9874DB awelogger[5358]: id="4102" severity="info" sys="System" sub="WiFi" name="STA disconnected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-07:40:48 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
    2020:11:28-09:12:48 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: authenticated
    2020:11:28-09:12:48 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: associated (aid 1)
    2020:11:28-09:12:48 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae RADIUS: starting accounting session 5FC08BDD-00000004
    2020:11:28-09:12:48 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae WPA: pairwise key handshake completed (RSN)
    2020:11:28-09:12:48 A4003945F9874DB awelogger[5358]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-09:12:48 A4003945F9874DB awelogger[5358]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-09:12:48 A4003945F9874DB awelogger[5358]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-09:14:39 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: disassociated
    2020:11:28-09:14:39 A4003945F9874DB awelogger[5358]: id="4102" severity="info" sys="System" sub="WiFi" name="STA disconnected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-09:14:40 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
    2020:11:28-09:26:08 192.168.2.128 kernel: [186717.110000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-09:26:26 192.168.2.128 kernel: [186735.450000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-09:34:37 192.168.2.128 kernel: [187225.620000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-09:37:46 192.168.2.128 kernel: [187415.420000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-09:38:47 192.168.2.128 kernel: [187476.120000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:00:11 192.168.2.128 kernel: [188760.490000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:03:42 192.168.2.128 kernel: [188971.260000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:06:34 192.168.2.128 kernel: [189142.570000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:07:36 192.168.2.128 kernel: [189205.550000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:07:52 192.168.2.128 kernel: [189221.010000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:09:40 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-10:09:41 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-10:25:36 192.168.2.128 kernel: [190285.250000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:28:19 192.168.2.128 kernel: [190448.040000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:29:25 192.168.2.128 kernel: [190513.430000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-10:34:23 192.168.2.128 kernel: [190811.720000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:09:41 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-13:09:42 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-13:10:37 192.168.2.128 kernel: [200186.040000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:10:56 192.168.2.128 kernel: [200204.520000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:14:07 192.168.2.128 kernel: [200395.230000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:18:31 192.168.2.128 kernel: [200659.590000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:19:00 192.168.2.128 kernel: [200689.030000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:19:06 192.168.2.128 kernel: [200694.600000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:36:44 192.168.2.128 kernel: [201752.740000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:44:50 192.168.2.128 kernel: [202238.480000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-13:57:22 192.168.2.128 kernel: [202991.500000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:03:52 192.168.2.128 kernel: [203381.030000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:10:42 192.168.2.128 kernel: [203790.780000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:10:48 192.168.2.128 kernel: [203796.890000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:35:06 192.168.2.128 kernel: [205254.990000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:35:26 192.168.2.128 kernel: [205275.060000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:35:38 192.168.2.128 kernel: [205286.570000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:39:24 192.168.2.128 kernel: [205512.020000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:39:40 192.168.2.128 kernel: [205529.060000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-14:39:55 192.168.2.128 kernel: [205544.380000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-15:13:17 192.168.2.128 kernel: [207546.240000] rt305x-esw 10110000.esw: link changed 0x01
    2020:11:28-15:28:04 192.168.2.128 netifd: lan (763): Sending renew...
    2020:11:28-15:28:04 192.168.2.128 netifd: lan (763): Lease of 192.168.2.128 obtained, lease time 86400
    2020:11:28-16:09:44 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-16:09:45 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-17:27:44 A40039023B1A3FF netifd: lan (969): Sending renew...
    2020:11:28-17:27:45 A40039023B1A3FF netifd: lan (969): Lease of 192.168.2.131 obtained, lease time 86400
    2020:11:28-17:27:49 A4003982651BE34 netifd: lan (968): Sending renew...
    2020:11:28-17:27:49 A4003982651BE34 netifd: lan (968): Lease of 192.168.2.132 obtained, lease time 86400
    2020:11:28-17:34:41 A4003945F9874DB netifd: lan (968): Sending renew...
    2020:11:28-17:34:41 A4003945F9874DB netifd: lan (968): Lease of 192.168.2.244 obtained, lease time 86400
    2020:11:28-19:09:44 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-19:09:44 vpn-2 awed[11089]: [MASTER] end processing configuration change
    2020:11:28-19:24:17 A4003945F9874DB kernel: [222603.060000] eth0: link up (1000Mbps/Full duplex)
    2020:11:28-19:24:17 A4003945F9874DB kernel: [222603.060000] br-lan: port 1(eth0) entered forwarding state
    2020:11:28-19:24:17 A4003945F9874DB kernel: [222603.070000] br-lan: port 1(eth0) entered forwarding state
    2020:11:28-19:24:17 A4003945F9874DB netifd: Network device 'eth0' link is up
    2020:11:28-19:24:19 A4003945F9874DB kernel: [222605.070000] br-lan: port 1(eth0) entered forwarding state
    2020:11:28-21:12:47 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: authenticated
    2020:11:28-21:12:47 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: associated (aid 1)
    2020:11:28-21:12:47 A4003945F9874DB awelogger[5358]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-21:12:47 A4003945F9874DB awelogger[5358]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae" status_code="0"
    2020:11:28-21:12:47 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae RADIUS: starting accounting session 5FC08BDD-00000005
    2020:11:28-21:12:47 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae WPA: pairwise key handshake completed (RSN)
    2020:11:28-21:12:47 A4003945F9874DB awelogger[5358]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-21:14:39 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: disassociated
    2020:11:28-21:14:39 A4003945F9874DB awelogger[5358]: id="4102" severity="info" sys="System" sub="WiFi" name="STA disconnected" ssid="KMintern" ssid_id="WLAN1.0" bssid="00:1a:8c:99:c8:10" sta="00:17:23:27:72:ae"
    2020:11:28-21:14:40 A4003945F9874DB hostapd: wlan1: STA 00:17:23:27:72:ae IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
    2020:11:28-22:09:57 vpn-2 awed[11089]: [MASTER] start processing configuration change
    2020:11:28-22:09:57 vpn-2 awed[11089]: [MASTER] end processing configuration change

    The Access Points go Offline somewhere in the night and at around 13:00h.

    Thanks! 

    Kind Regards Michael

  • Hallo Michael and welcome to the UTM Community!

    Do these outages occur at the same times every day?  When you say "Inactive" above, do you mean they appear in 'Inactive Access Points' in 'Wireless Protection >> Access Points' or just that all WiFi Networks are deactivated?

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Hello Michael,

    Thank you for the logs.

    Is there anything under

    # l/var/storage/cores

    I just see the configuration change gets triggered.

    Do the logs are the same in the other device?

    Regards,


     
    Emmanuel (EmmoSophos)
    Community Support Engineer | Sophos Technical Support
    Sophos Support VideosProduct Documentation  |  @SophosSupport  | Sign up for SMS Alerts
    If a post solves your question use the 'Verify Answer' link.