[7.885][BUG][FIXED] AFCD log flooding (contd.)

Well,

this issue: https://community.sophos.com/products/unified-threat-management/astaroorg/f/102/t/69056 should have been fixed in 7.870 according to the status given from the bot.

Actually it is not. It has been reduced by 2/3 of the messages but there are still enough:

2010:03:08-18:43:04 astaro1 afcd[5886]:  Possible Netlink event overrun detected

2010:03:08-18:43:34 astaro1 afcd[5886]:  Possible Netlink event overrun detected
2010:03:08-18:44:04 astaro1 afcd[5886]:  Possible Netlink event overrun detected
2010:03:08-18:44:34 astaro1 afcd[5886]:  Possible Netlink event overrun detected


Best regards,
Bastian
  • Yes, it's enabled! Configuration is still almost the same.

    Regards,
    Bastian
  • One thing in the quoted log is strange; the netlink overflows seem to happen in regular 30 second intervals. Does this happen all the time? In this case, it would be nice to figure out what happens there (maybe you can run "conntrack -E" on console to dump all ct events and post the logs).

    Further details, if you're interested: We cannot reproduce this here, except by forcing insane load on the ASG and then open/closing lots of connections to generate excess conntrack events. However, in itself an netlink event overflow is harmless, and the message does not provide useful information to end users. Therefore we will restrict that overflow message to the debug mode of the AFC.
  • Yes the message is logged every 30 seconds, for the hole day! I don't think my ASG is under heavy load (CPU load in webadmin is at 0% most of the time, this is a *home* installation)

    I'll try conntrack later this evening, have no time at the moment.
  • Astaro Beta Report
    --------------------------------
    Version: 7.885
    Type: BUG
    State: MERGED/FIXED
    Reporter: Monarch
    Contributor:  
    MantisID: 12959
    Target version: 7.890
    Fixed in version: 7.890
    --------------------------------

  • Interestingly: I believe the following error occurs at the same time when the event is logged:

    Perhaps the logs give you some valuable information [;)]

     [UPDATE] tcp      6 120 FIN_WAIT src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58330 dport=4444 src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58330 [ASSURED] mark=65536
     [UPDATE] tcp      6 60 CLOSE_WAIT src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58330 dport=4444 src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58330 [ASSURED] mark=65536
     [UPDATE] tcp      6 10 CLOSE src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58330 dport=4444 src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58330 [ASSURED] mark=65536
        [NEW] tcp      6 120 SYN_SENT src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58331 dport=4444 [UNREPLIED] src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58331 mark=65536
     [UPDATE] tcp      6 60 SYN_RECV src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58331 dport=4444 src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58331 mark=65536
     [UPDATE] tcp      6 86400 ESTABLISHED src=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 dst=2001:5c0:1507[:D]c00::1 sport=58331 dport=4444 src=2001:5c0:1507[:D]c00::1 dst=2001:5c0:1507[:D]c00:1c14:424b:fdc0:63b4 sport=4444 dport=58331 [ASSURED] mark=65536
    [DESTROY] tcp      6 src=91.20.56.205 dst=213.144.15.6 sport=44269 dport=80 packets=6 bytes=997 src=213.144.15.6 dst=91.20.56.205 sport=80 dport=44269 packets=5 bytes=980 [ASSURED] mark=65536
    [DESTROY] tcp      6 src=91.20.56.205 dst=213.144.15.6 sport=44270 dport=80 packets=5 bytes=721 src=213.144.15.6 dst=91.20.56.205 sport=80 dport=44270 packets=5 bytes=756 [ASSURED] mark=65536
    [DESTROY] tcp      6 src=192.168.0.5 dst=87.98.230.68 sport=58274 dport=80 packets=8 bytes=1581 src=192.168.0.99 dst=192.168.0.5 sport=8080 dport=58274 packets=6 bytes=927 [ASSURED]
        [NEW] tcp      6 120 SYN_SENT src=91.20.56.205 dst=212.227.17.177 sport=57893 dport=110 [UNREPLIED] src=212.227.17.177 dst=91.20.56.205 sport=110 dport=57893
     [UPDATE] tcp      6 60 SYN_RECV src=91.20.56.205 dst=212.227.17.177 sport=57893 dport=110 src=212.227.17.177 dst=91.20.56.205 sport=110 dport=57893
     [UPDATE] tcp      6 86400 ESTABLISHED src=91.20.56.205 dst=212.227.17.177 sport=57893 dport=110 src=212.227.17.177 dst=91.20.56.205 sport=110 dport=57893 [ASSURED]
    [DESTROY] tcp      6 src=91.20.56.205 dst=87.98.230.68 sport=44774 dport=80 packets=7 bytes=1577 src=87.98.230.68 dst=91.20.56.205 sport=80 dport=44774 packets=6 bytes=963 [ASSURED] mark=65536
    [DESTROY] tcp      6 src=91.20.56.205 dst=213.144.15.6 sport=44274 dport=80 packets=5 bytes=577 src=213.144.15.6 dst=91.20.56.205 sport=80 dport=44274 packets=5 bytes=644 [ASSURED] mark=65536
    [DESTROY] udp      17 src=192.168.0.90 dst=192.168.0.99 sport=61043 dport=53 packets=1 bytes=66 src=192.168.0.99 dst=192.168.0.90 sport=53 dport=61043 packets=1 bytes=538
    [DESTROY] udp      17 src=91.20.56.205 dst=208.67.222.222 sport=4092 dport=53 packets=1 bytes=77 src=208.67.222.222 dst=91.20.56.205 sport=53 dport=4092 packets=1 bytes=93
    [DESTROY] udp      17 src=91.20.56.205 dst=208.67.222.222 sport=16016 dport=53 packets=1 bytes=77 src=208.67.222.222 dst=91.20.56.205 sport=53 dport=16016 packets=1 bytes=77
    WARNING: We have hit ENOBUFS! We are losing events.
    This message means that the current netlink socket buffer size is too small.
    Please, check --buffer-size in conntrack(8) manpage.
    conntrack v0.9.13 (conntrack-tools): Operation failed: No buffer space available


    Will now update to 7.890

    Regards,
    Bastian