[BUG][9.004] RED50 starts over and over again after 1 minute

The red50 worked in the first place after some time now it starts again and again after 1 minute. A connect to the utm is possible:

2012:10:31-14:33:50 asg-cluster-1 red_server[8520]: SELF: New connection from 1.2.3.4 with ID A340077F21A7426 (cipher AES256-SHA), rev1
2012:10:31-14:33:50 asg-cluster-1 red_server[11258]: SELF: Starting REDv2 protocol
2012:10:31-14:33:50 asg-cluster-1 red_server[11258]: A340077F21A7426: connected OK, pushing config
2012:10:31-14:33:50 asg-cluster-1 red_server[11258]: A340077F21A7426: Sending PEERS+1.2.3.198+192.168.0.3+1.2.3.198
2012:10:31-14:33:53 asg-cluster-1 red_server[11258]: A340077F21A7426: command 'PING 0'
2012:10:31-14:33:54 asg-cluster-1 red_server[11258]: A340077F21A7426: PING remote_tx=0 local_rx=0 diff=0
2012:10:31-14:33:54 asg-cluster-1 red_server[11258]: A340077F21A7426: PONG local_tx=0
2012:10:31-14:33:57 asg-cluster-1 red2ctl[8472]: Received keepalive from reds1:1, enabling peer 1.2.3.4
2012:10:31-14:34:10 asg-cluster-1 red_server[11258]: A340077F21A7426: command 'PING 0'
2012:10:31-14:34:10 asg-cluster-1 red_server[11258]: A340077F21A7426: PING remote_tx=0 local_rx=0 diff=0
2012:10:31-14:34:10 asg-cluster-1 red_server[11258]: A340077F21A7426: PONG local_tx=0
2012:10:31-14:34:21 asg-cluster-1 red_server[8520]: SELF: (Re-)loading device configurations
2012:10:31-14:34:27 asg-cluster-1 red_server[11258]: A340077F21A7426: command 'PING 0'
2012:10:31-14:34:27 asg-cluster-1 red_server[11258]: A340077F21A7426: PING remote_tx=0 local_rx=0 diff=0
2012:10:31-14:34:27 asg-cluster-1 red_server[11258]: A340077F21A7426: PONG local_tx=0
2012:10:31-14:34:47 asg-cluster-1 red2ctl[8472]: Missing keepalive from reds1:1, disabling peer 1.2.3.4
2012:10:31-14:34:58 asg-cluster-1 red_server[11258]: A340077F21A7426: No ping for 30 seconds, exiting.
2012:10:31-14:34:58 asg-cluster-1 red_server[8520]: A340077F21A7426: disconnecting

My setup is:

red50 - firewall (also an ASG V8) - internet - sophos utm 9.004

At the ASG V8 I see that the red50 at first connects to the utm but after that it conntacts the provisioning server again and restarts. Any ideas?

Regards,
Marco

0 hschaa over 11 years ago

Is this behavior new in 9.004?
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 asg_user over 11 years ago

Hi Helmut,

yes this exact behavior is new in 9.004 but with 9.003 there was no traffic flow from clients behind the red to the utm. That's why I updated the utm to 9.004.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 hschaa over 11 years ago

Ah, very good, that means the RED50 at least detects that no traffic flows and thus reboots. Please check on your v8 if port 3410 frames are dropped ...
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 asg_user over 11 years ago

No unfortunately not. All packets which the red50 sends to port 3400 or port 3410 reached the utm. I have a serial console to the red50 attached. The last messages before the reboot are:

[   11.157935] USB Serial support registered for pl2303
[   11.163070] usbcore: registered new interface driver pl2303
[   11.168675] pl2303: Prolific PL2303 USB to serial adaptor driver
[   11.833880] PowerPC Book-E Watchdog Timer Enabled (wdt_period=38)
[   23.986776] 88E1111
[   24.618761] device eth0 entered promiscuous mode
[   24.633871] br-lan: port 1(eth0) entering forwarding state
[   24.639418] br-lan: port 1(eth0) entering forwarding state
[   24.756005] 88E1111
[   24.848994] 88E1111
[   25.347259] 88E1111
[   25.891734] device redc0 entered promiscuous mode
[   25.896666] br-lan: port 2(redc0) entering forwarding state
[   25.902276] br-lan: port 2(redc0) entering forwarding state
[   25.907895] no peer
[   26.355269] PHY: mdio@ffe24000:12 - Link is Up - 1000/Half
[   26.574868] PHY: 0:10 - Link is Up - 1000/Full
[   27.102882] PHY: 0:02 - Link is Up - 1000/Full
[   57.162863] no peer
[   68.022879] br-lan: port 2(redc0) entering forwarding state
[   68.028518] br-lan: port 1(eth0) entering forwarding state
[   68.078178] device redc0 left promiscuous mode
[   68.082684] br-lan: port 2(redc0) entering disabled state
[   68.088181] device eth0 left promiscuous mode
[   68.092579] br-lan: port 1(eth0) entering disabled state
[   69.851440] 88E1111
[   70.459427] device eth0 entered promiscuous mode
[   70.474839] br-lan: port 1(eth0) entering forwarding state
[   70.480394] br-lan: port 1(eth0) entering forwarding state
[   70.556660] device redc0 entered promiscuous mode
[   70.561546] br-lan: port 2(redc0) entering forwarding state
[   70.567154] br-lan: port 2(redc0) entering forwarding state
[   70.572769] no peer
[   70.645230] 88E1111
[   70.740151] 88E1111
[   71.750961] PHY: mdio@ffe24000:12 - Link is Up - 1000/Half
[   72.135446] 88E1111
[   72.414873] PHY: 0:10 - Link is Up - 1000/Full
[   72.954870] PHY: 0:02 - Link is Up - 1000/Full
[   73.143157] PHY: mdio@ffe24000:12 - Link is Up - 1000/Half
[   85.766900] br-lan: port 2(redc0) entering forwarding state
[   85.772524] br-lan: port 1(eth0) entering forwarding state
[   85.809950] device redc0 left promiscuous mode
[   85.814464] br-lan: port 2(redc0) entering disabled state
[   85.819950] device eth0 left promiscuous mode
[   85.824333] br-lan: port 1(eth0) entering disabled state
[   90.322485] Restarting system.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 hschaa over 11 years ago in reply to asg_user

Can you see port 3410 frames going in both directions? RED -> ASG and ASG -> RED.
Helmut
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 asg_user over 11 years ago

No only from red to the utm. The utm doesn't reply to these packets on port 3410.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 hschaa over 11 years ago

Or they are dropped on the way somewhere?
red_server restart?
ASG reboot?
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 asg_user over 11 years ago

They are not sent from the utm back to the red. I did a tcpdump on the outgoing interface of the utm with the red_server:

09:20:36.898635 IP 1.2.3.4.52528 > 1.2.3.198.3400: S 3200970350:3200970350(0) win 14600
09:20:36.898770 IP 1.2.3.198.3400 > 1.2.3.4.52528: S 2467682879:2467682879(0) ack 3200970351 win 14600
09:20:36.899964 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 1 win 457
09:20:36.899976 IP 1.2.3.4.52528 > 1.2.3.198.3400: P 1:102(101) ack 1 win 457
09:20:36.900074 IP 1.2.3.198.3400 > 1.2.3.4.52528: . ack 102 win 115
09:20:36.900760 IP 1.2.3.198.3400 > 1.2.3.4.52528: . 1:1461(1460) ack 102 win 115
09:20:36.900874 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 1461:1756(295) ack 102 win 115
09:20:36.901424 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 1756 win 639
09:20:36.901440 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 1461 win 548
09:20:36.941542 IP 1.2.3.4.52528 > 1.2.3.198.3400: . 102:1562(1460) ack 1756 win 639
09:20:36.941558 IP 1.2.3.4.52528 > 1.2.3.198.3400: P 1562:2175(613) ack 1756 win 639
09:20:36.941636 IP 1.2.3.198.3400 > 1.2.3.4.52528: . ack 2175 win 160
09:20:36.946759 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 1756:2966(1210) ack 2175 win 160
09:20:36.968237 IP 1.2.3.198.3400 > 1.2.3.4.52528: . 2966:4426(1460) ack 2175 win 160
09:20:36.968867 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 4426 win 822
09:20:36.968996 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 4426:5467(1041) ack 2175 win 160
09:20:37.010077 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 5467 win 913
09:20:37.010204 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 5467:5520(53) ack 2175 win 160
09:20:37.010440 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 5520 win 913
09:20:39.701632 IP 1.2.3.4.52528 > 1.2.3.198.3400: P 2175:2265(90) ack 5520 win 913
09:20:39.725820 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:20:39.740547 IP 1.2.3.198.3400 > 1.2.3.4.52528: . ack 2265 win 160
09:20:39.992374 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 5520:5557(37) ack 2265 win 160
09:20:39.992693 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 5557 win 913
09:20:44.734627 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:20:49.742260 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:20:54.750518 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:20:56.134900 IP 1.2.3.4.52528 > 1.2.3.198.3400: P 2265:2339(74) ack 5557 win 913
09:20:56.134998 IP 1.2.3.198.3400 > 1.2.3.4.52528: . ack 2339 win 160
09:20:56.517200 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 5557:5594(37) ack 2339 win 160
09:20:56.517545 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 5594 win 913
09:20:59.759451 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:21:04.767083 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:21:09.775367 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:21:12.566644 IP 1.2.3.4.52528 > 1.2.3.198.3400: P 2339:2413(74) ack 5594 win 913
09:21:12.566767 IP 1.2.3.198.3400 > 1.2.3.4.52528: . ack 2413 win 160
09:21:13.046897 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 5594:5631(37) ack 2413 win 160
09:21:13.047219 IP 1.2.3.4.52528 > 1.2.3.198.3400: . ack 5631 win 913
09:21:14.783622 IP 1.2.3.4.3410 > 1.2.3.198.3410: UDP, length 68
09:21:44.081470 IP 1.2.3.198.3400 > 1.2.3.4.52528: P 5631:5668(37) ack 2413 win 160
09:21:44.081933 IP 1.2.3.198.3400 > 1.2.3.4.52528: F 5668:5668(0) ack 2413 win 160

At this time the red reboots again. I restarted the red_server and also the utm but the behavior stays the same. Any ideas?
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 hschaa over 11 years ago in reply to asg_user

Maybe the RED is configured as RED10?
Helmut
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 asg_user over 11 years ago

Hi Helmut,

the type is red50:

127.0.0.1 OBJS itfhw red_server > REF_ItfRedReds1Red50[reds1 (red50),itfhw,red_server]
Logged into object 'REF_ItfRedReds1Red50'. Use 'w' to write eventual changes.
{
          'activate_modem' => 0,
          'apn' => '',
          'comment' => '',
          'description' => 'Remote Ethernet Server Device',
          'dial_string' => '*99#',
          'failover_direct' => 0,
          'fullbr_dns' => '',
          'fullbr_domains' => [],
          'hardware' => 'reds1',
          'hub2_hostname' => '',
          'hub_hostname' => '*********XX',
          'mac' => '00:26[:D]e:44:97:9c',
          'manual2_address' => '0.0.0.0',
          'manual2_defgw' => '0.0.0.0',
          'manual2_dns' => '0.0.0.0',
          'manual2_netmask' => 24,
          'manual_address' => '*********XX',
          'manual_defgw' => '*********XX',
          'manual_dns' => '*********XX',
          'manual_netmask' => 22,
          'mobile_network' => 'gsm',
          'name' => 'reds1 (red50)',
          'password' => '',
          'pin' => '',
          'protocol_version' => 1,
          'red_id' => 'A340077F21A7426',
          'remote_cert' => 'REF_CaHosRedclA3400',
          'route_mode' => 'default',
          'split_networks' => [],
          'tunnel_id' => 1,
          'type' => 'red50',
          'unlock_code' => '*********XX',
          'uplink2_mode' => 'dhcp',
          'uplink_mode' => 'manual',
          'username' => ''
        }

Is it possible to create more debug information for the red_server service?

Regards,
Marco
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel