Guest User!

You are not Sophos Staff.

Middleware restart

Since upgrading to 8.200 from 8.103 I am seeing a e-mail message with the following
Middle ware not running - restarted
-- 
System Uptime      : 2 days 16 hours 0 minutes
System Load        : 0.07
System Version     : Astaro Security Gateway 8.200

Please refer to the manual for detailed instructions.

and then

Dyndns daemon not running - restarted
-- 
System Uptime      : 2 days 16 hours 0 minutes
System Load        : 0.11
System Version     : Astaro Security Gateway 8.200

Please refer to the manual for detailed instructions.


Around the same time here is the middleware log for that time frame. This has happened now 3 times since the release was made available and installed.


2011:07:26-02:38:38 edge middleware[27064]: T core::Config::load:266() => modules=1,1
2011:07:26-02:38:38 edge middleware[27064]: T main::top-level:246() => cycle 1037 waiting for 1 children
2011:07:26-02:42:40 edge middleware[27064]: T main::top-level:235() => ending cycle 1037, caught 1 signals, 1 children still running
2011:07:26-02:42:40 edge middleware[27064]: T main::top-level:188() => starting cycle 1038, caught 1 signals
2011:07:26-02:42:40 edge middleware[27064]: T core::Config::Changed:132() => configversion=1168
2011:07:26-02:42:40 edge middleware[27064]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:42:40 edge middleware[27064]: T core::Config::load:266() => modules=1,1
2011:07:26-02:42:40 edge middleware[27064]: T main::top-level:246() => cycle 1038 waiting for 1 children
2011:07:26-02:46:42 edge middleware[27064]: T main::top-level:235() => ending cycle 1038, caught 1 signals, 1 children still running
2011:07:26-02:46:42 edge middleware[27064]: T main::top-level:188() => starting cycle 1039, caught 1 signals
2011:07:26-02:46:43 edge middleware[27064]: T core::Config::Changed:132() => configversion=1169
2011:07:26-02:46:43 edge middleware[27064]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:46:43 edge middleware[27064]: T core::Config::load:266() => modules=1,1
2011:07:26-02:46:43 edge middleware[27064]: T main::top-level:246() => cycle 1039 waiting for 1 children
2011:07:26-02:48:44 edge middleware[27064]: T main::top-level:235() => ending cycle 1039, caught 1 signals, 1 children still running
2011:07:26-02:48:44 edge middleware[27064]: T main::top-level:188() => starting cycle 1040, caught 1 signals
2011:07:26-02:48:44 edge middleware[27064]: T core::Config::Changed:132() => configversion=1170
2011:07:26-02:48:44 edge middleware[27064]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:48:45 edge middleware[27064]: T core::Config::load:266() => modules=4,9
2011:07:26-02:48:45 edge middleware[27064]: T main::top-level:246() => cycle 1040 waiting for 1 children
2011:07:26-02:51:46 edge middleware[27064]: T main::top-level:235() => ending cycle 1040, caught 1 signals, 1 children still running
2011:07:26-02:51:46 edge middleware[27064]: T main::top-level:188() => starting cycle 1041, caught 1 signals
2011:07:26-02:51:46 edge middleware[27064]: T core::Config::Changed:132() => configversion=1171
2011:07:26-02:51:46 edge middleware[27064]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:51:47 edge middleware[27064]: T core::Config::load:266() => modules=4,9
2011:07:26-02:51:47 edge middleware[27064]: >=========================================================================
2011:07:26-02:51:47 edge middleware[27064]: E Bizarre copy of ARRAY in aassign at /utils/File.pm line 149,  line 1.
2011:07:26-02:51:47 edge middleware[27064]: 
2011:07:26-02:51:47 edge middleware[27064]:  1. main::_warn:150() mdw.pl
2011:07:26-02:51:47 edge middleware[27064]:  2. main::_die:147() mdw.pl
2011:07:26-02:51:47 edge middleware[27064]:  3. utils::File::Read:149() /utils/File.pm
2011:07:26-02:51:47 edge middleware[27064]:  4. utils::File::WriteCrontab:456() /utils/File.pm
2011:07:26-02:51:47 edge middleware[27064]:  5. modules::executive_report::_set_crontab:97() /modules/executive_report.pm
2011:07:26-02:51:47 edge middleware[27064]:  6. modules::executive_report::setAll:182() /modules/executive_report.pm
2011:07:26-02:51:47 edge middleware[27064]:  7. core::Config::load:277() /core/Config.pm
2011:07:26-02:51:47 edge middleware[27064]:  8. main::top-level:199() mdw.pl
2011:07:26-02:52:06 edge middleware[3760]: T main::top-level:62() => MiddleWare starting
2011:07:26-02:52:08 edge middleware[3760]: T main::top-level:188() => starting cycle 0, caught 0 signals
2011:07:26-02:52:08 edge middleware[3760]: T core::Config::Changed:132() => configversion=0
2011:07:26-02:52:08 edge middleware[3760]: T core::Config::Changed:232() => configversion=1171
2011:07:26-02:52:08 edge middleware[3760]: T core::Config::load:266() => modules=154,133
2011:07:26-02:53:10 edge middleware[3760]: >=========================================================================
2011:07:26-02:53:10 edge middleware[3760]: E Failed: /sbin/ip -f inet route add table 252 to local default/0 dev lo
2011:07:26-02:53:10 edge middleware[3760]: 
2011:07:26-02:53:10 edge middleware[3760]:  1. utils::IPRoute::ip_route_cmd:790() /utils/IPRoute.pm
2011:07:26-02:53:10 edge middleware[3760]:  2. utils::IPRoute::ip_route_add:746() /utils/IPRoute.pm
2011:07:26-02:53:10 edge middleware[3760]:  3. ASG::Adapters::tproxy::setAll:234() /ASG/Adapters/tproxy.pm
2011:07:26-02:53:10 edge middleware[3760]:  4. core::Config::load:277() /core/Config.pm
2011:07:26-02:53:10 edge middleware[3760]:  5. main::top-level:199() mdw.pl
2011:07:26-02:53:14 edge middleware[3760]: T main::top-level:235() => ending cycle 0, caught 2 signals, 2 children still running
2011:07:26-02:53:14 edge middleware[3760]: T main::top-level:188() => starting cycle 1, caught 2 signals
2011:07:26-02:53:15 edge middleware[3760]: T core::Config::Changed:132() => configversion=1173
2011:07:26-02:53:15 edge middleware[3760]: T core::Config::Changed:142() => nodes=1 objects=0 triggers=0
2011:07:26-02:53:15 edge middleware[3760]: T core::Config::load:266() => modules=1,4
2011:07:26-02:53:15 edge middleware[3760]: T main::top-level:246() => cycle 1 waiting for 3 children
2011:07:26-02:53:15 edge middleware[3760]: T main::top-level:246() => cycle 1 waiting for 2 children
2011:07:26-02:53:44 edge middleware[3760]: T main::top-level:246() => cycle 1 waiting for 1 children
2011:07:26-02:53:47 edge middleware[3760]: T main::top-level:235() => ending cycle 1, caught 1 signals, 1 children still running
2011:07:26-02:53:47 edge middleware[3760]: T main::top-level:188() => starting cycle 2, caught 1 signals
2011:07:26-02:53:47 edge middleware[3760]: T core::Config::Changed:132() => configversion=1174
2011:07:26-02:53:47 edge middleware[3760]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:53:48 edge middleware[3760]: T core::Config::load:266() => modules=4,9
2011:07:26-02:53:50 edge middleware[3760]: T main::top-level:235() => ending cycle 2, caught 1 signals, 1 children still running
2011:07:26-02:53:50 edge middleware[3760]: T main::top-level:188() => starting cycle 3, caught 1 signals
2011:07:26-02:53:50 edge middleware[3760]: T core::Config::Changed:132() => configversion=1175
2011:07:26-02:53:50 edge middleware[3760]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:53:50 edge middleware[3760]: T core::Config::load:266() => modules=2,4
2011:07:26-02:53:51 edge middleware[3760]: T main::top-level:246() => cycle 3 waiting for 2 children
2011:07:26-02:53:51 edge middleware[3760]: T main::top-level:246() => cycle 3 waiting for 1 children
2011:07:26-02:56:56 edge middleware[3760]: T main::top-level:235() => ending cycle 3, caught 1 signals, 1 children still running
2011:07:26-02:56:56 edge middleware[3760]: T main::top-level:188() => starting cycle 4, caught 1 signals
2011:07:26-02:56:57 edge middleware[3760]: T core::Config::Changed:132() => configversion=1176
2011:07:26-02:56:57 edge middleware[3760]: T core::Config::Changed:142() => nodes=0 objects=1 triggers=0
2011:07:26-02:56:57 edge middleware[3760]: T core::Config::load:266() => modules=4,9
2011:07:26-02:56:58 edge middleware[3760]: T main::top-level:246() => cycle 4 waiting for 2 children
2011:07:26-02:56:58 edge middleware[3760]: T main::top-level:246() => cycle 4 waiting for 1 children
2011:07:26-03:02:00 edge middleware[3760]: T main::top-level:235() => ending cycle 4, caught 1 signals, 1 children still running
Parents
  • The Middleware process is one of those core components of the ASG that are really crucial for the whole system. When we test those components, we do it even more thorough than usual, because it needs to be rock solid. And, as you said, under normal circumstances, the Middleware runs for years without problems.

    The error messages you posted above indicate an HD issue because the affected code deals with reading a file from disk. The result of that read operation is obviously broken (the runtime system even calls it "bizarre"), even though the hardware itself doesn't signal an error.
    Even though it may seem hard to believe that hardware can break without showing an error message, i've seen such a behavior numerous times before.

    I'd suggest that you replace the HD and re-install the ASG.
Reply
  • The Middleware process is one of those core components of the ASG that are really crucial for the whole system. When we test those components, we do it even more thorough than usual, because it needs to be rock solid. And, as you said, under normal circumstances, the Middleware runs for years without problems.

    The error messages you posted above indicate an HD issue because the affected code deals with reading a file from disk. The result of that read operation is obviously broken (the runtime system even calls it "bizarre"), even though the hardware itself doesn't signal an error.
    Even though it may seem hard to believe that hardware can break without showing an error message, i've seen such a behavior numerous times before.

    I'd suggest that you replace the HD and re-install the ASG.
Children
No Data