Guest User!

You are not Sophos Staff.

Thread Info
  • State Not Answered
  • Replies 25 replies
  • Subscribers 0 subscribers
  • Views 8895 views
  • Users 0 members are here
Options
Suggested

[8.270][BUG][NOT A BUG] frequent restarts of IM/P2P classifier

brk
I upgraded 3 days ago and have recieved this message 4 times.
 

Subject: [***.***.com][INFO-149] IM/P2P classifier not running - restarted
Message-Id: 
To: ***@***.com
From: "Firewall Notification System" 
Auto-Submitted: yes
Precedence: bulk
X-Mailer: Firewall Notification System

IM/P2P classifier not running - restarted
-- 
System Uptime      : 1 day 18 hours 0 minutes
System Load        : 0.03
System Version     : Astaro Security Gateway 8.270
Parents
  • 0 
    Astaro Beta Report
    --------------------------------
    Version: 8.270
    Type: BUG
    State: CLOSED/NOT A BUG
    Reporter: brk
    Contributor: ReD-MaN
    MantisID: 19637
    Target version: 
    Fixed in version: 
    --------------------------------

  • 0 in reply to Astaro Beta Bot
    I did a clean install, and then restored from my backup file.

    I get the exact same thing, so I had to disable all the snort related processes.
  • 0 in reply to ReD-MaN
    I did a clean install, and then restored from my backup file.

    I get the exact same thing, so I had to disable all the snort related processes.


    could you clarify if this is a snort or application control issue?
    (snort is not related to im/p2p/application control).

    You could run the following command:
    cat /var/pattern/appctrl/TA/version

    IFF the output starts with "a94", then just wait until u2d
    pull in updated patterns, or,
    run
    rm /usr/lib/netview/plugins/logmanagement.plg

    which should fix it.
    If you already have a different pattern version, and the problem
    persists, then please try
    ls -lt /var/storage/cores

    and see if that brings up any files named 'afcd.***x' (where *** is some number).

    If so, please us know and i'll pm you an email address to send those files to.
  • 0 in reply to 67ef1d
    Still having this..

    I have verified my pattern version is different than a94..

    asgbeta:/root # cat /var/pattern/appctrl/TA/version
    e5765d999da88e3016324422466f5238e2895571

    The subject of the emails says: [asgbeta.******.net][INFO-149] IM/P2P classifier not running - restarted

    I did the rm /usr/lib/netview/plugins/logmanagement.plg , and it has not helped...

    I have no files in cores dir either..

    asgbeta:/root # ls -lt /var/storage/cores/
    total 0
  • 0 in reply to ReD-MaN

    I have no files in cores dir either..
    asgbeta:/root # ls -lt /var/storage/cores/
    total 0


    Makes me wonder why you get those messages, then.
    Does "zgrep afcd /var/log/kernel/2011/*/*gz" yield any output (if yes, what)?

    If no, could you please post the afc.log file from one of the days where a restart was reported? You can filter the output via "grep afc /var/log/afc.log" ; this will remove messages
    from packet blocking, which is not relevant here.
  • 0 in reply to 67ef1d
    Makes me wonder why you get those messages, then.
    Does "zgrep afcd /var/log/kernel/2011/*/*gz" yield any output (if yes, what)?

    If no, could you please post the afc.log file from one of the days where a restart was reported? You can filter the output via "grep afc /var/log/afc.log" ; this will remove messages
    from packet blocking, which is not relevant here.


    The first step yeilds nothing.

    asgbeta:/root # zgrep afcd /var/log/kernel/2011/*/*gz
    asgbeta:/root #

    Here is some of the log, had to cut out over half of it, but it has been the same thing over and over since midnight.

    2011:11:21-09:18:43 asgbeta afcd[3816]: STATUS: alert_lvl="GREEN" run_time=840 num_cts=14 pktps_avg=0.00 pktps_avg_max=83.84 skipped_pktps_avg=0.00 skipped_pktps_avg_max=1.79 connps_avg=0.00 connps_avg_max=41.12 rusage_sys=0.360 rusage_usr=0.332
    2011:11:21-09:18:43 asgbeta afcd[3816]:      DNS (nfmark 0000007C):   1173 packets, 595 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:    EPMAP (nfmark 0000008B):      1 packets,   0 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:     HTTP (nfmark 000000D3):     57 packets,   3 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:  NETBIOS (nfmark 00000146):    271 packets,   0 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:      NTP (nfmark 0000015D):     12 packets,   0 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:  OPENVPN (nfmark 0000016A):      3 packets,   3 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:     SMTP (nfmark 000001CA):      6 packets,   1 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:      SSL (nfmark 000001D9):     16 packets,   2 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]:   TELNET (nfmark 000001EE):      1 packets,   0 connections
    2011:11:21-09:18:43 asgbeta afcd[3816]: packets: 1756 (1746 inspected, 9 skipped)
    2011:11:21-09:18:43 asgbeta afcd[3816]: connections: 693 (604 classified)
    2011:11:21-09:18:58 asgbeta afcd[5564]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:19:00 asgbeta afcd[5564]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-09:19:00 asgbeta afcd[5564]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:19:00 asgbeta afcd[5611]: AFC ready.
    2011:11:21-09:19:17 asgbeta afcd[5611]: STATUS: alert_lvl="GREEN" run_time=17 num_cts=0 pktps_avg=0.00 pktps_avg_max=0.00 skipped_pktps_avg=0.00 skipped_pktps_avg_max=0.00 connps_avg=0.00 connps_avg_max=0.00 rusage_sys=0.002 rusage_usr=0.008
    2011:11:21-09:19:17 asgbeta afcd[5611]: packets: 0 (0 inspected, 0 skipped)
    2011:11:21-09:19:17 asgbeta afcd[5611]: connections: 0 (0 classified)
    2011:11:21-09:19:20 asgbeta afcd[5959]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:19:23 asgbeta afcd[5959]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-09:19:23 asgbeta afcd[5959]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:19:23 asgbeta afcd[6113]: AFC ready.
    2011:11:21-09:36:33 asgbeta afcd[6113]: STATUS: alert_lvl="GREEN" run_time=1029 num_cts=12 pktps_avg=0.00 pktps_avg_max=79.23 skipped_pktps_avg=0.00 skipped_pktps_avg_max=0.40 connps_avg=0.00 connps_avg_max=39.71 rusage_sys=0.388 rusage_usr=0.314
    2011:11:21-09:36:33 asgbeta afcd[6113]:      DNS (nfmark 0000007C):   1112 packets, 565 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:    EPMAP (nfmark 0000008B):      2 packets,   0 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:     HTTP (nfmark 000000D3):     57 packets,   2 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:  NETBIOS (nfmark 00000146):    281 packets,   0 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:      NTP (nfmark 0000015D):     12 packets,   0 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:  OPENVPN (nfmark 0000016A):      3 packets,   3 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:     SMTP (nfmark 000001CA):      6 packets,   1 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:      SSL (nfmark 000001D9):      8 packets,   1 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]:   TELNET (nfmark 000001EE):      1 packets,   0 connections
    2011:11:21-09:36:33 asgbeta afcd[6113]: packets: 1753 (1750 inspected, 3 skipped)
    2011:11:21-09:36:33 asgbeta afcd[6113]: connections: 655 (572 classified)
    2011:11:21-09:36:48 asgbeta afcd[7815]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:36:50 asgbeta afcd[7815]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-09:36:50 asgbeta afcd[7815]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:36:50 asgbeta afcd[7867]: AFC ready.
    2011:11:21-09:37:07 asgbeta afcd[7867]: STATUS: alert_lvl="GREEN" run_time=16 num_cts=0 pktps_avg=0.00 pktps_avg_max=0.00 skipped_pktps_avg=0.00 skipped_pktps_avg_max=0.00 connps_avg=0.00 connps_avg_max=0.00 rusage_sys=0.002 rusage_usr=0.008
    2011:11:21-09:37:07 asgbeta afcd[7867]: packets: 0 (0 inspected, 0 skipped)
    2011:11:21-09:37:07 asgbeta afcd[7867]: connections: 0 (0 classified)
    2011:11:21-09:37:08 asgbeta afcd[8182]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:39:50 asgbeta afcd[8182]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-09:39:50 asgbeta afcd[8182]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:39:50 asgbeta afcd[8205]: AFC ready.
    2011:11:21-09:56:53 asgbeta afcd[8205]: STATUS: alert_lvl="GREEN" run_time=1023 num_cts=15 pktps_avg=0.00 pktps_avg_max=80.97 skipped_pktps_avg=0.00 skipped_pktps_avg_max=1.20 connps_avg=0.00 connps_avg_max=40.29 rusage_sys=0.398 rusage_usr=0.339
    2011:11:21-09:56:53 asgbeta afcd[8205]:      DNS (nfmark 0000007C):   1158 packets, 587 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:    EPMAP (nfmark 0000008B):      1 packets,   0 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:     HTTP (nfmark 000000D3):     55 packets,   1 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:  NETBIOS (nfmark 00000146):    248 packets,   0 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:      NTP (nfmark 0000015D):      8 packets,   0 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:  OPENVPN (nfmark 0000016A):      2 packets,   2 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:     SMTP (nfmark 000001CA):      6 packets,   1 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:      SSL (nfmark 000001D9):      8 packets,   1 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]:   TELNET (nfmark 000001EE):      2 packets,   0 connections
    2011:11:21-09:56:53 asgbeta afcd[8205]: packets: 1788 (1776 inspected, 12 skipped)
    2011:11:21-09:56:53 asgbeta afcd[8205]: connections: 715 (592 classified)
    2011:11:21-09:59:49 asgbeta afcd[10090]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:59:51 asgbeta afcd[10090]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-09:59:51 asgbeta afcd[10090]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-09:59:51 asgbeta afcd[10143]: AFC ready.
    2011:11:21-10:00:08 asgbeta afcd[10143]: STATUS: alert_lvl="GREEN" run_time=16 num_cts=0 pktps_avg=0.00 pktps_avg_max=0.00 skipped_pktps_avg=0.00 skipped_pktps_avg_max=0.00 connps_avg=0.00 connps_avg_max=0.00 rusage_sys=0.002 rusage_usr=0.008
    2011:11:21-10:00:08 asgbeta afcd[10143]: packets: 0 (0 inspected, 0 skipped)
    2011:11:21-10:00:08 asgbeta afcd[10143]: connections: 0 (0 classified)
    2011:11:21-10:00:11 asgbeta afcd[10478]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-10:00:13 asgbeta afcd[10478]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
    2011:11:21-10:00:13 asgbeta afcd[10478]: _afc_cfg_file_plugin_parse: 549 protocols registered
    2011:11:21-10:00:14 asgbeta afcd[10632]: AFC ready.
    2011:11:21-10:18:58 asgbeta afcd[10632]: STATUS: alert_lvl="GREEN" run_time=1125 num_cts=9 pktps_avg=1.40 pktps_avg_max=84.02 skipped_pktps_avg=0.00 skipped_pktps_avg_max=2.19 connps_avg=0.00 connps_avg_max=43.51 rusage_sys=0.379 rusage_usr=0.323
    2011:11:21-10:18:58 asgbeta afcd[10632]:      DNS (nfmark 0000007C):   1057 packets, 538 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:    EPMAP (nfmark 0000008B):      1 packets,   0 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:     HTTP (nfmark 000000D3):     56 packets,   2 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:  NETBIOS (nfmark 00000146):    252 packets,   0 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:      NTP (nfmark 0000015D):      8 packets,   0 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:  OPENVPN (nfmark 0000016A):      2 packets,   2 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:     SMTP (nfmark 000001CA):      6 packets,   1 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:      SSL (nfmark 000001D9):     16 packets,   2 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]:   TELNET (nfmark 000001EE):      2 packets,   0 connections
    2011:11:21-10:18:58 asgbeta afcd[10632]: packets: 1686 (1673 inspected, 12 skipped)
    2011:11:21-10:18:58 asgbeta afcd[10632]: connections: 661 (545 classified)
  • 0 in reply to ReD-MaN
    More on this.. just checked the kernel.log, and found lots of link up/down, correlating in time to when afc restarts. This is a vmware ESX virtual machine, and the actual physical links are not going up/down like this..

    2011:11:21-09:01:23 asgbeta kernel: [62713.835862] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:01:23 asgbeta kernel: [62713.839887] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:01:24 asgbeta kernel: [62713.843750] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:01:24 asgbeta kernel: [62714.219521] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:01:24 asgbeta kernel: [62714.224109] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:01:24 asgbeta kernel: [62714.227968] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:18:45 asgbeta kernel: [63749.984906] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:18:45 asgbeta kernel: [63749.988933] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:18:45 asgbeta kernel: [63749.992785] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:18:46 asgbeta kernel: [63750.389141] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:18:46 asgbeta kernel: [63750.393874] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:18:46 asgbeta kernel: [63750.397961] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.308938] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:36:35 asgbeta kernel: [64814.312808] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.316650] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.715217] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:36:35 asgbeta kernel: [64814.719311] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.723027] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:56:56 asgbeta kernel: [66029.943993] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:56:56 asgbeta kernel: [66029.963220] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:56:56 asgbeta kernel: [66029.967593] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:56:56 asgbeta kernel: [66030.525499] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:56:56 asgbeta kernel: [66030.530036] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:56:56 asgbeta kernel: [66030.533941] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-10:17:18 asgbeta kernel: [67246.300124] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-10:17:18 asgbeta kernel: [67246.319225] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-10:17:18 asgbeta kernel: [67246.323231] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-10:17:18 asgbeta kernel: [67247.067316] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-10:17:18 asgbeta kernel: [67247.088220] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-10:17:18 asgbeta kernel: [67247.092293] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Reply
  • 0 in reply to ReD-MaN
    More on this.. just checked the kernel.log, and found lots of link up/down, correlating in time to when afc restarts. This is a vmware ESX virtual machine, and the actual physical links are not going up/down like this..

    2011:11:21-09:01:23 asgbeta kernel: [62713.835862] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:01:23 asgbeta kernel: [62713.839887] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:01:24 asgbeta kernel: [62713.843750] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:01:24 asgbeta kernel: [62714.219521] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:01:24 asgbeta kernel: [62714.224109] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:01:24 asgbeta kernel: [62714.227968] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:18:45 asgbeta kernel: [63749.984906] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:18:45 asgbeta kernel: [63749.988933] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:18:45 asgbeta kernel: [63749.992785] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:18:46 asgbeta kernel: [63750.389141] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:18:46 asgbeta kernel: [63750.393874] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:18:46 asgbeta kernel: [63750.397961] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.308938] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:36:35 asgbeta kernel: [64814.312808] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.316650] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.715217] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:36:35 asgbeta kernel: [64814.719311] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:36:35 asgbeta kernel: [64814.723027] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-09:56:56 asgbeta kernel: [66029.943993] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:56:56 asgbeta kernel: [66029.963220] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-09:56:56 asgbeta kernel: [66029.967593] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-09:56:56 asgbeta kernel: [66030.525499] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-09:56:56 asgbeta kernel: [66030.530036] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-09:56:56 asgbeta kernel: [66030.533941] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
    2011:11:21-10:17:18 asgbeta kernel: [67246.300124] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-10:17:18 asgbeta kernel: [67246.319225] ADDRCONF(NETDEV_UP): eth0: link is not ready
    2011:11:21-10:17:18 asgbeta kernel: [67246.323231] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    2011:11:21-10:17:18 asgbeta kernel: [67247.067316] e1000: eth1: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
    2011:11:21-10:17:18 asgbeta kernel: [67247.088220] ADDRCONF(NETDEV_UP): eth1: link is not ready
    2011:11:21-10:17:18 asgbeta kernel: [67247.092293] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Children
  • 0 in reply to ReD-MaN
    More on this.. just checked the kernel.log, and found lots of link up/down, correlating in time to when afc restarts. This is a vmware ESX virtual machine, and the actual physical links are not going up/down like this..

    2011:11:21-09:01:23 asgbeta kernel: [62713.835862] e1000: eth0: e1000_watchdog_task: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None


    Any entries in mdw.log that would correlate with those?
    If yes, you might also want to look at confd.log.
  • 0 in reply to 67ef1d
    Here is the mdw.log for some of the same time periods today:


    2011:11:21-09:36:20 asgbeta middleware[7240]: T main::top-level:62() => MiddleWare starting
    2011:11:21-09:36:24 asgbeta middleware[7240]: T main::top-level:188() => starting cycle 0, caught 0 signals
    2011:11:21-09:36:24 asgbeta middleware[7240]: T core::Config::Changed:132() => configversion=0
    2011:11:21-09:36:24 asgbeta middleware[7240]: T core::Config::Changed:232() => configversion=65
    2011:11:21-09:36:24 asgbeta middleware[7240]: T core::Config::load:266() => modules=157,134
    2011:11:21-09:40:11 asgbeta middleware[7240]: >=========================================================================
    2011:11:21-09:40:11 asgbeta middleware[7240]: E Failed: /sbin/ip -f inet route add table 252 to local default/0 dev lo
    2011:11:21-09:40:11 asgbeta middleware[7240]: 
    2011:11:21-09:40:11 asgbeta middleware[7240]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  3. ASG::Adapters::tproxy::setAll:234() /ASG/Adapters/tproxy.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  5. main::top-level:199() mdw.pl
    2011:11:21-09:40:11 asgbeta middleware[7240]: >=========================================================================
    2011:11:21-09:40:11 asgbeta middleware[7240]: E Failed: /sbin/ip -f inet6 route add table 252 to local default/0 dev lo
    2011:11:21-09:40:11 asgbeta middleware[7240]: 
    2011:11:21-09:40:11 asgbeta middleware[7240]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  3. ASG::Adapters::tproxy::setAll:246() /ASG/Adapters/tproxy.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-09:40:11 asgbeta middleware[7240]:  5. main::top-level:199() mdw.pl
    2011:11:21-09:40:26 asgbeta middleware[7240]: T main::top-level:235() => ending cycle 0, caught 1 signals, 0 children still running
    2011:11:21-09:40:26 asgbeta middleware[7240]: T main::top-level:188() => starting cycle 1, caught 1 signals
    2011:11:21-09:40:27 asgbeta middleware[7240]: T core::Config::Changed:132() => configversion=66
    2011:11:21-09:40:27 asgbeta middleware[7240]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
    2011:11:21-09:40:27 asgbeta middleware[7240]: T core::Config::load:266() => modules=2,4
    2011:11:21-09:40:29 asgbeta middleware[7240]: T main::top-level:235() => ending cycle 1, caught 0 signals, 0 children still running
    2011:11:21-09:56:40 asgbeta middleware[9502]: T main::top-level:62() => MiddleWare starting
    2011:11:21-09:56:44 asgbeta middleware[9502]: T main::top-level:188() => starting cycle 0, caught 0 signals
    2011:11:21-09:56:44 asgbeta middleware[9502]: T core::Config::Changed:132() => configversion=0
    2011:11:21-09:56:44 asgbeta middleware[9502]: T core::Config::Changed:232() => configversion=66
    2011:11:21-09:56:44 asgbeta middleware[9502]: T core::Config::load:266() => modules=157,134
    2011:11:21-10:00:32 asgbeta middleware[9502]: >=========================================================================
    2011:11:21-10:00:32 asgbeta middleware[9502]: E Failed: /sbin/ip -f inet route add table 252 to local default/0 dev lo
    2011:11:21-10:00:32 asgbeta middleware[9502]: 
    2011:11:21-10:00:32 asgbeta middleware[9502]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  3. ASG::Adapters::tproxy::setAll:234() /ASG/Adapters/tproxy.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  5. main::top-level:199() mdw.pl
    2011:11:21-10:00:32 asgbeta middleware[9502]: >=========================================================================
    2011:11:21-10:00:32 asgbeta middleware[9502]: E Failed: /sbin/ip -f inet6 route add table 252 to local default/0 dev lo
    2011:11:21-10:00:32 asgbeta middleware[9502]: 
    2011:11:21-10:00:32 asgbeta middleware[9502]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  3. ASG::Adapters::tproxy::setAll:246() /ASG/Adapters/tproxy.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-10:00:32 asgbeta middleware[9502]:  5. main::top-level:199() mdw.pl
    2011:11:21-10:00:51 asgbeta middleware[9502]: T main::top-level:235() => ending cycle 0, caught 1 signals, 0 children still running
    2011:11:21-10:00:51 asgbeta middleware[9502]: T main::top-level:188() => starting cycle 1, caught 1 signals
    2011:11:21-10:00:51 asgbeta middleware[9502]: T core::Config::Changed:132() => configversion=67
    2011:11:21-10:00:51 asgbeta middleware[9502]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
    2011:11:21-10:00:51 asgbeta middleware[9502]: T core::Config::load:266() => modules=2,4
    2011:11:21-10:00:52 asgbeta middleware[9502]: T main::top-level:235() => ending cycle 1, caught 0 signals, 0 children still running
    2011:11:21-10:18:57 asgbeta middleware[9502]: T main::top-level:188() => starting cycle 2, caught 1 signals
    2011:11:21-10:18:57 asgbeta middleware[9502]: T core::Config::Changed:132() => configversion=68
    2011:11:21-10:18:57 asgbeta middleware[9502]: T core::Config::Changed:142() => nodes=1 objects=0 triggers=0
    2011:11:21-10:18:57 asgbeta middleware[9502]: T core::Config::load:266() => modules=1,8
    2011:11:21-10:19:01 asgbeta middleware[9502]: T main::top-level:235() => ending cycle 2, caught 0 signals, 0 children still running
    2011:11:21-10:17:01 asgbeta middleware[12137]: T main::top-level:62() => MiddleWare starting
    2011:11:21-10:17:06 asgbeta middleware[12137]: T main::top-level:188() => starting cycle 0, caught 0 signals
    2011:11:21-10:17:07 asgbeta middleware[12137]: T core::Config::Changed:132() => configversion=0
    2011:11:21-10:17:07 asgbeta middleware[12137]: T core::Config::Changed:232() => configversion=68
    2011:11:21-10:17:07 asgbeta middleware[12137]: T core::Config::load:266() => modules=157,134
    2011:11:21-10:20:51 asgbeta middleware[12137]: >=========================================================================
    2011:11:21-10:20:51 asgbeta middleware[12137]: E Failed: /sbin/ip -f inet route add table 252 to local default/0 dev lo
    2011:11:21-10:20:51 asgbeta middleware[12137]: 
    2011:11:21-10:20:51 asgbeta middleware[12137]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  3. ASG::Adapters::tproxy::setAll:234() /ASG/Adapters/tproxy.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  5. main::top-level:199() mdw.pl
    2011:11:21-10:20:51 asgbeta middleware[12137]: >=========================================================================
    2011:11:21-10:20:51 asgbeta middleware[12137]: E Failed: /sbin/ip -f inet6 route add table 252 to local default/0 dev lo
    2011:11:21-10:20:51 asgbeta middleware[12137]: 
    2011:11:21-10:20:51 asgbeta middleware[12137]:  1. utils::IPRoute::ip_route_cmd:791() /utils/IPRoute.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  3. ASG::Adapters::tproxy::setAll:246() /ASG/Adapters/tproxy.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  4. core::Config::load:277() /core/Config.pm
    2011:11:21-10:20:51 asgbeta middleware[12137]:  5. main::top-level:199() mdw.pl
    2011:11:21-10:21:04 asgbeta middleware[12137]: T main::top-level:235() => ending cycle 0, caught 0 signals, 0 children still running
    2011:11:21-10:21:07 asgbeta middleware[12137]: T main::top-level:188() => starting cycle 1, caught 1 signals
    2011:11:21-10:21:08 asgbeta middleware[12137]: T core::Config::Changed:132() => configversion=69
    2011:11:21-10:21:08 asgbeta middleware[12137]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
    2011:11:21-10:21:08 asgbeta middleware[12137]: T core::Config::load:266() => modules=2,4
    2011:11:21-10:21:10 asgbeta middleware[12137]: T main::top-level:235() => ending cycle 1, caught 0 signals, 0 children still running
  • 0 in reply to ReD-MaN
    Here is the mdw.log for some of the same time periods today:
    2011:11:21-09:40:27 asgbeta middleware[7240]: T core::Config::load:266() => modules=2,4
    2011:11:21-09:40:29 asgbeta middleware[7240]: T main::top-level:235() => ending cycle 1, caught 0 signals, 0 children still running
    2011:11:21-09:56:40 asgbeta middleware[9502]: T main::top-level:62() => MiddleWare starting
    2011:11:21-09:56:44 asgbeta middleware[9502]: T main::top-level:188() => starting cycle 0, caught 0 signals
    [..]
    2011:11:21-09:56:44 asgbeta middleware[9502]: T core::Config::Changed:132() => 
    2011:11:21-10:19:01 asgbeta middleware[9502]: T main::top-level:235() => ending cycle 2, caught 0 signals, 0 children still running
    2011:11:21-10:17:01 asgbeta middleware[12137]: T main::top-level:62() => MiddleWare starting


    mdw restarts repeatedly, but the log files do not show why this is happening.
    Are there any "segfault" messages in kernel.log ?
Unfiltered HTML