Guest User!

You are not Sophos Staff.

[9.191][BUG] Logfiles growing 7 Gig in 30 minutes

Hi, running Firmware version: 9.191-2 my log disk space of 7.5 Gig got filled up within 30 minutes....

I imported my config from current UTM 9 version and imported it to beta 9.2.


Fallback.log is about 180 MB and shows mostly 
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
2013:12:26-00:44:45 xyz [daemon:info] pfilter-reporter.pl:  INFO - found match: violation found
and so on.
What is PFILTER? No idea where to check my config.


Firewall log is 6.6 Gig. I could not even view or download it...
So I had to delete the file. As you can see on enclosed screenshot, it only took about 30 minutes to fill up the log....
Don't ask me, what I did at that time. I was playing around with user portal and running an update on linux mint 14.

After deleting, firewall log shows normal growth.


SSL-VPN shows some Auth Failed while having established my user portal session.
Using Google OTP Token. Reconnects are quite frequent....

2013:12:26-20:17:16 somewhere34 openvpn[9364]: xx.yy.236.173:57892 SENT CONTROL [REF_AaaUse2]: 'AUTH_FAILED' (status=1)
2013:12:26-20:17:16 somewhere34 openvpn[9364]: xx.yy.236.173:57892 Connection reset, restarting [0]
2013:12:26-20:17:16 somewhere34 openvpn[9364]: xx.yy.236.173:57892 SIGUSR1[soft,connection-reset] received, client-instance restarting
2013:12:26-20:17:26 somewhere34 openvpn[9364]: TCP connection established with [AF_INET]xx.yy.236.173:57893 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:17:27 somewhere34 openvpn[9364]: xx.yy.236.173:57893 TLS: Initial packet from [AF_INET]xx.yy.236.173:57893 (via [AF_INET]88.64.135.99:443), sid=4083ea1d 8e434824
2013:12:26-20:17:28 somewhere34 openvpn[9364]: xx.yy.236.173:57893 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:28 somewhere34 openvpn[9364]: xx.yy.236.173:57893 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:28 somewhere34 openvpn[9364]: xx.yy.236.173:57893 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:28 somewhere34 openvpn[9364]: xx.yy.236.173:57893 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 TLS: Username/Password authentication deferred for username 'REF_AaaUse2' [CN SET]
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Data Channel Encrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Data Channel Decrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
2013:12:26-20:17:29 somewhere34 openvpn[9364]: xx.yy.236.173:57893 [REF_AaaUse2] Peer Connection Initiated with [AF_INET]xx.yy.236.173:57893 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:17:31 somewhere34 openvpn[9364]: xx.yy.236.173:57893 PUSH: Received control message: 'PUSH_REQUEST'
2013:12:26-20:17:31 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Delayed exit in 5 seconds
2013:12:26-20:17:31 somewhere34 openvpn[9364]: xx.yy.236.173:57893 SENT CONTROL [REF_AaaUse2]: 'AUTH_FAILED' (status=1)
2013:12:26-20:17:31 somewhere34 openvpn[9364]: xx.yy.236.173:57893 Connection reset, restarting [0]
2013:12:26-20:17:31 somewhere34 openvpn[9364]: xx.yy.236.173:57893 SIGUSR1[soft,connection-reset] received, client-instance restarting
2013:12:26-20:17:41 somewhere34 openvpn[9364]: TCP connection established with [AF_INET]xx.yy.236.173:57894 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:17:42 somewhere34 openvpn[9364]: xx.yy.236.173:57894 TLS: Initial packet from [AF_INET]xx.yy.236.173:57894 (via [AF_INET]88.64.135.99:443), sid=f656096f d58bcce6
2013:12:26-20:17:43 somewhere34 openvpn[9364]: xx.yy.236.173:57894 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:43 somewhere34 openvpn[9364]: xx.yy.236.173:57894 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:43 somewhere34 openvpn[9364]: xx.yy.236.173:57894 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:43 somewhere34 openvpn[9364]: xx.yy.236.173:57894 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 TLS: Username/Password authentication deferred for username 'REF_AaaUse2' [CN SET]
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Data Channel Encrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Data Channel Decrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
2013:12:26-20:17:44 somewhere34 openvpn[9364]: xx.yy.236.173:57894 [REF_AaaUse2] Peer Connection Initiated with [AF_INET]xx.yy.236.173:57894 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:17:46 somewhere34 openvpn[9364]: xx.yy.236.173:57894 PUSH: Received control message: 'PUSH_REQUEST'
2013:12:26-20:17:46 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Delayed exit in 5 seconds
2013:12:26-20:17:46 somewhere34 openvpn[9364]: xx.yy.236.173:57894 SENT CONTROL [REF_AaaUse2]: 'AUTH_FAILED' (status=1)
2013:12:26-20:17:46 somewhere34 openvpn[9364]: xx.yy.236.173:57894 Connection reset, restarting [0]
2013:12:26-20:17:46 somewhere34 openvpn[9364]: xx.yy.236.173:57894 SIGUSR1[soft,connection-reset] received, client-instance restarting
2013:12:26-20:17:56 somewhere34 openvpn[9364]: TCP connection established with [AF_INET]xx.yy.236.173:57895 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:17:57 somewhere34 openvpn[9364]: xx.yy.236.173:57895 TLS: Initial packet from [AF_INET]xx.yy.236.173:57895 (via [AF_INET]88.64.135.99:443), sid=e3527067 9e27b69e
2013:12:26-20:17:58 somewhere34 openvpn[9364]: xx.yy.236.173:57895 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:58 somewhere34 openvpn[9364]: xx.yy.236.173:57895 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:58 somewhere34 openvpn[9364]: xx.yy.236.173:57895 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:17:58 somewhere34 openvpn[9364]: xx.yy.236.173:57895 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 TLS: Username/Password authentication deferred for username 'REF_AaaUse2' [CN SET]
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Data Channel Encrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Data Channel Decrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
2013:12:26-20:17:59 somewhere34 openvpn[9364]: xx.yy.236.173:57895 [REF_AaaUse2] Peer Connection Initiated with [AF_INET]xx.yy.236.173:57895 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:18:01 somewhere34 openvpn[9364]: xx.yy.236.173:57895 PUSH: Received control message: 'PUSH_REQUEST'
2013:12:26-20:18:01 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Delayed exit in 5 seconds
2013:12:26-20:18:01 somewhere34 openvpn[9364]: xx.yy.236.173:57895 SENT CONTROL [REF_AaaUse2]: 'AUTH_FAILED' (status=1)
2013:12:26-20:18:01 somewhere34 openvpn[9364]: xx.yy.236.173:57895 Connection reset, restarting [0]
2013:12:26-20:18:01 somewhere34 openvpn[9364]: xx.yy.236.173:57895 SIGUSR1[soft,connection-reset] received, client-instance restarting
2013:12:26-20:18:11 somewhere34 openvpn[9364]: TCP connection established with [AF_INET]xx.yy.236.173:57904 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:18:12 somewhere34 openvpn[9364]: xx.yy.236.173:57904 TLS: Initial packet from [AF_INET]xx.yy.236.173:57904 (via [AF_INET]88.64.135.99:443), sid=421c36c3 59d5bda4
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 VERIFY OK: depth=1, C=de, L=jm, O=jm, CN=jm VPN CA, emailAddress=jm@somedomain.de
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 VERIFY OK: depth=0, C=de, L=jm, O=jm, CN=REF_SslSerJmtwFaken2
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 TLS: Username/Password authentication deferred for username 'REF_AaaUse2' [CN SET]
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Data Channel Encrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Data Channel Decrypt: Cipher 'AES-192-CBC' initialized with 192 bit key
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
2013:12:26-20:18:14 somewhere34 openvpn[9364]: xx.yy.236.173:57904 [REF_AaaUse2] Peer Connection Initiated with [AF_INET]xx.yy.236.173:57904 (via [AF_INET]88.64.135.99:443)
2013:12:26-20:18:17 somewhere34 openvpn[9364]: xx.yy.236.173:57904 PUSH: Received control message: 'PUSH_REQUEST'
2013:12:26-20:18:17 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Delayed exit in 5 seconds
2013:12:26-20:18:17 somewhere34 openvpn[9364]: xx.yy.236.173:57904 SENT CONTROL [REF_AaaUse2]: 'AUTH_FAILED' (status=1)
2013:12:26-20:18:17 somewhere34 openvpn[9364]: xx.yy.236.173:57904 Connection reset, restarting [0]
2013:12:26-20:18:17 somewhere34 openvpn[9364]: xx.yy.236.173:57904 SIGUSR1[soft,connection-reset] received, client-instance restarting
Parents
  • Hello, took a while to reproduce again....

    I just had rapid growing firewall log and 99% cpu for httpproxy.
    Switching Web Filterin OFF and after some seconds ON again stopped CPU load and logfile growing.

    So you were on the right track already.

    Tail of packetfilter.log:
    2014:01:16-00:29:02 kronenstr34 ulogd[1760]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth0" srcmac="0:c:29[:D]f:bf:ba" srcip="137.254.120.26" dstip="192.168.40.57" proto="6" length="1500" tos="0x00" prec="0x00" ttl="64" srcport="80" dstport="42215" tcpflags="ACK PSH" 
    2014:01:16-00:29:02 kronenstr34 ulogd[1760]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth0" srcmac="0:c:29[:D]f:bf:ba" srcip="137.254.120.26" dstip="192.168.40.57" proto="6" length="1500" tos="0x00" prec="0x00" ttl="64" srcport="80" dstport="42175" tcpflags="ACK PSH" 

    This seems to be the main content of the file.



    137.254.120.26 seems to belong to Oracle. In fact, I was just trying to install Virtualbox on my Ubuntu 13.04 via Oracle repositories by apt-get install virtualbox-4.3.... Did not succeed.

    137.254.120.26/vp-dlc.oracle.com IP Address Whois | DomainTools.com
    NetRange:       137.254.0.0 - 137.254.255.255
    CIDR:           137.254.0.0/16
    OriginAS:       
    NetName:        ORACLE-BBONET
    NetHandle:      NET-137-254-0-0-1
    Parent:         NET-137-0-0-0-0
    NetType:        Direct Assignment
    RegDate:        1990-01-17
    Updated:        2013-09-10
    Ref:            http://whois.arin.net/rest/net/NET-137-254-0-0-1


    Really nice new Feature in Astaro/Sophos UTM: Policy Test
    Result:
    Request URL: http://137.254.120.26/
    Request Time: 16 Jan, 01:08 (CET)
    Result: Allowed
    URL Category: Uncategorized
    URL Reputation: Unverified
    Policy name: Default content filter profile assignment_1

    So seems to be OK. I added virtualbox.org to AV skiplist.

    Restarting apt-get install virtualbox-4.3 results in 99% CPU load again, so I can't install VBox at the moment....


    @ KOFI:
    rpm -qa | grep ipsbundle shows u2d-ipsbundle-9-114



    Best Regards
    Juergen
Reply
  • Hello, took a while to reproduce again....

    I just had rapid growing firewall log and 99% cpu for httpproxy.
    Switching Web Filterin OFF and after some seconds ON again stopped CPU load and logfile growing.

    So you were on the right track already.

    Tail of packetfilter.log:
    2014:01:16-00:29:02 kronenstr34 ulogd[1760]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth0" srcmac="0:c:29[:D]f:bf:ba" srcip="137.254.120.26" dstip="192.168.40.57" proto="6" length="1500" tos="0x00" prec="0x00" ttl="64" srcport="80" dstport="42215" tcpflags="ACK PSH" 
    2014:01:16-00:29:02 kronenstr34 ulogd[1760]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth0" srcmac="0:c:29[:D]f:bf:ba" srcip="137.254.120.26" dstip="192.168.40.57" proto="6" length="1500" tos="0x00" prec="0x00" ttl="64" srcport="80" dstport="42175" tcpflags="ACK PSH" 

    This seems to be the main content of the file.



    137.254.120.26 seems to belong to Oracle. In fact, I was just trying to install Virtualbox on my Ubuntu 13.04 via Oracle repositories by apt-get install virtualbox-4.3.... Did not succeed.

    137.254.120.26/vp-dlc.oracle.com IP Address Whois | DomainTools.com
    NetRange:       137.254.0.0 - 137.254.255.255
    CIDR:           137.254.0.0/16
    OriginAS:       
    NetName:        ORACLE-BBONET
    NetHandle:      NET-137-254-0-0-1
    Parent:         NET-137-0-0-0-0
    NetType:        Direct Assignment
    RegDate:        1990-01-17
    Updated:        2013-09-10
    Ref:            http://whois.arin.net/rest/net/NET-137-254-0-0-1


    Really nice new Feature in Astaro/Sophos UTM: Policy Test
    Result:
    Request URL: http://137.254.120.26/
    Request Time: 16 Jan, 01:08 (CET)
    Result: Allowed
    URL Category: Uncategorized
    URL Reputation: Unverified
    Policy name: Default content filter profile assignment_1

    So seems to be OK. I added virtualbox.org to AV skiplist.

    Restarting apt-get install virtualbox-4.3 results in 99% CPU load again, so I can't install VBox at the moment....


    @ KOFI:
    rpm -qa | grep ipsbundle shows u2d-ipsbundle-9-114



    Best Regards
    Juergen
Children
No Data