I have a very strange problem with two UTMs on custom hardware. First a brief overview of my setups and the history:
Location A
- Interface 1/2: 100/10 Mbit/s Private Customer VDSL-fiber line
- Interface 2/2: 18/1 Mbit/s Private Customer ADSL line
Location B
- Interface 1/1: 100/10 Mbit/s Private Customer VDSL-fiber line
The UTMs on both locations are running on totally different hardware. Before this issue, both locations didn't have any problems at all and were running for several months (Location A even since 2010).
The VDSL-Lines are provided by our local ISP NetCologne (http://www.netcologne.de/) and the way from ISPs wall jack to the UTM looks like this:
1) Wall jack (the socket is called TAE here)
2) Zyxel VDSL-Model
3) NetCologne Premium Router (running in PPPoE Pass-through mode and is splitting/providing phone signal)
4) Sophos UTM
The inferface configuration on both locations looks like this: https://www.dropbox.com/s/ohdblfq3wbd91m8/Interface_Configuration.png.
The interface #2 on location A has a little different setup since this is an ADSL line but until now there weren't any problems with this interface.
All three interfaces have static ip addresses assigned by the ISP.
On October 3, 2013 I decided to upgrade both UTMs from [9.105-9] to [9.106-17] at the same time (being located in location B) since previous updates via webadmin passed without any problems.
After waiting a couple of minutes the UTM in my current location (location B) came back online and connected successfully to the VDSL-Line. I waited another 60 minutes but failed to reach interface #1 on location A. At some point I figured out that interface #2 is still reachable but I had no VPN configuration for this interface so I had to wait until the next day to investigate this issue further.
On October 4, 2013 I was in location A and had a look at the PPPoE logs. The following excerpt is from today but the content was the same:
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: Plugin rp-pppoe.so loaded.
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.6
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: pppd 2.4.6 started by root, uid 0
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:27:16 gateway pppd-pppoe[5675]: [service-name] [host-uniq 2b 16 00 00]
2013:10:10-09:27:21 gateway pppd-pppoe[5675]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:27:21 gateway pppd-pppoe[5675]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:27:21 gateway pppd-pppoe[5675]: [service-name] [host-uniq 2b 16 00 00]
2013:10:10-09:27:31 gateway pppd-pppoe[5675]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:27:31 gateway pppd-pppoe[5675]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:27:31 gateway pppd-pppoe[5675]: [service-name] [host-uniq 2b 16 00 00]
2013:10:10-09:27:51 gateway pppd-pppoe[5675]: Timeout waiting for PADO packets
2013:10:10-09:27:51 gateway pppd-pppoe[5675]: Unable to complete PPPoE Discovery
2013:10:10-09:27:51 gateway pppd-pppoe[5675]: Exit.
2013:10:10-09:27:51 gateway pppoe-sh: DSL connection time shorter then 60 seconds (35 sec): Error? - wait 5 seconds
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: Plugin rp-pppoe.so loaded.
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.6
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: pppd 2.4.6 started by root, uid 0
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:27:56 gateway pppd-pppoe[5714]: [service-name] [host-uniq 52 16 00 00]
2013:10:10-09:28:01 gateway pppd-pppoe[5714]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:28:01 gateway pppd-pppoe[5714]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:28:01 gateway pppd-pppoe[5714]: [service-name] [host-uniq 52 16 00 00]
2013:10:10-09:28:11 gateway pppd-pppoe[5714]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:28:11 gateway pppd-pppoe[5714]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:28:11 gateway pppd-pppoe[5714]: [service-name] [host-uniq 52 16 00 00]
2013:10:10-09:28:31 gateway pppd-pppoe[5714]: Timeout waiting for PADO packets
2013:10:10-09:28:31 gateway pppd-pppoe[5714]: Unable to complete PPPoE Discovery
2013:10:10-09:28:31 gateway pppd-pppoe[5714]: Exit.
2013:10:10-09:28:31 gateway pppoe-sh: DSL connection time shorter then 60 seconds (35 sec): Error? - wait 5 seconds
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: Plugin rp-pppoe.so loaded.
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.6
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: pppd 2.4.6 started by root, uid 0
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:28:36 gateway pppd-pppoe[5749]: [service-name] [host-uniq 75 16 00 00]
2013:10:10-09:28:41 gateway pppd-pppoe[5749]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:28:41 gateway pppd-pppoe[5749]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:28:41 gateway pppd-pppoe[5749]: [service-name] [host-uniq 75 16 00 00]
2013:10:10-09:28:51 gateway pppd-pppoe[5749]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:28:51 gateway pppd-pppoe[5749]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:28:51 gateway pppd-pppoe[5749]: [service-name] [host-uniq 75 16 00 00]
2013:10:10-09:29:11 gateway pppd-pppoe[5749]: Timeout waiting for PADO packets
2013:10:10-09:29:11 gateway pppd-pppoe[5749]: Unable to complete PPPoE Discovery
2013:10:10-09:29:11 gateway pppd-pppoe[5749]: Exit.
2013:10:10-09:29:11 gateway pppoe-sh: DSL connection time shorter then 60 seconds (35 sec): Error? - wait 5 seconds
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: Plugin rp-pppoe.so loaded.
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.6
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: pppd 2.4.6 started by root, uid 0
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:29:16 gateway pppd-pppoe[5780]: [service-name] [host-uniq 94 16 00 00]
2013:10:10-09:29:21 gateway pppd-pppoe[5780]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:29:21 gateway pppd-pppoe[5780]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:29:21 gateway pppd-pppoe[5780]: [service-name] [host-uniq 94 16 00 00]
2013:10:10-09:29:31 gateway pppd-pppoe[5780]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:29:31 gateway pppd-pppoe[5780]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:29:31 gateway pppd-pppoe[5780]: [service-name] [host-uniq 94 16 00 00]
2013:10:10-09:29:51 gateway pppd-pppoe[5780]: Timeout waiting for PADO packets
2013:10:10-09:29:51 gateway pppd-pppoe[5780]: Unable to complete PPPoE Discovery
2013:10:10-09:29:51 gateway pppd-pppoe[5780]: Exit.
2013:10:10-09:29:51 gateway pppoe-sh: DSL connection time shorter then 60 seconds (35 sec): Error? - wait 5 seconds
These blocks were repeating and in between the connection dial-up seems to work, at least a little bit:
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Plugin rp-pppoe.so loaded.
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.6
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: pppd 2.4.6 started by root, uid 0
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: dst ff:ff:ff:ff:ff:ff src 90:2b:34[:D]8:70:aa
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: [service-name] [host-uniq 9d 16 00 00]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: dst 90:2b:34[:D]8:70:aa src 0:90:1a:a2:b4:c4
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: [AC-name netdsl] [host-uniq 9d 16 00 00] [service-name] [AC-cookie be 02 e0 9c 39 f1 ed 69 8f fa bd 91 67 a3 2a 3e]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: dst 0:90:1a:a2:b4:c4 src 90:2b:34[:D]8:70:aa
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: [service-name] [host-uniq 9d 16 00 00] [AC-cookie be 02 e0 9c 39 f1 ed 69 8f fa bd 91 67 a3 2a 3e]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Recv PPPOE Discovery V1T1 PADS session 0x2e9c length 12
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: dst 90:2b:34[:D]8:70:aa src 0:90:1a:a2:b4:c4
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: [service-name] [host-uniq 9d 16 00 00]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: PADS: Service-Name: ''
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: PPP session is 11932
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Connected to 00:90:1a:a2:b4:c4 via interface eth1
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: using channel 1
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Using interface ppp0
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: Connect: ppp0 eth1
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: sent [LCP ConfReq id=0x1 ]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: rcvd [LCP ConfReq id=0x1a ]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: sent [LCP ConfAck id=0x1a ]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: rcvd [LCP ConfAck id=0x1 ]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: sent [LCP EchoReq id=0x0 magic=0x92b1922e]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: sent [PAP AuthReq id=0x1 user="******@netcologne.de" password=]
2013:10:10-09:29:56 gateway pppd-pppoe[5789]: rcvd [LCP EchoRep id=0x0 magic=0x5b6ddf9e]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [LCP ConfReq id=0x72 ]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [LCP ConfReq id=0x2 ]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [LCP ConfAck id=0x72 ]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [LCP ConfAck id=0x2 ]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [LCP EchoReq id=0x0 magic=0xed4eadbe]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [PAP AuthReq id=0x2 user="******@netcologne.de" password=]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [LCP EchoRep id=0x0 magic=0x61828759]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [PAP AuthNak id=0x2 "duplicate address detected"]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: Remote message: duplicate address detected
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: PAP authentication failed
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [LCP TermReq id=0x3 "Failed to authenticate ourselves to peer"]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [LCP TermReq id=0x73]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: sent [LCP TermAck id=0x73]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: rcvd [LCP TermAck id=0x3]
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: Connection terminated.
2013:10:10-09:29:57 gateway pppd-pppoe[5789]: Exit.
2013:10:10-09:29:57 gateway pppoe-sh: DSL connection time shorter then 60 seconds (1 sec): Error? - wait 5 seconds
So the message "duplicate address detected" made me wonder and since location B still had no problems I assumed the cause of this issue has to do with my ISP NetCologne.
I called the hotline and the supporter confirmed, that there is an open connection but initiated from my house, so it must be the UTM which had a connection but failed to recognise this so it initiates a second one which results in the message "duplicate address detected". The supporter told me that there was no change in configuration on ISP-side.
I rebooted every hardware component involved but without success. After that I googled and found several threads:
- https://community.sophos.com/products/unified-threat-management/astaroorg/f/68/t/61845
- https://community.sophos.com/products/unified-threat-management/astaroorg/f/53/t/33732
- https://community.sophos.com/products/unified-threat-management/astaroorg/f/52/t/29079
Unfortunately none of their workaround helped (reliable) and their log messages didn't match my second excerpt. so I decided to roll back to [9.105-9] and restore from backup. I did that but without any success. This is weird since I didn't have this problem with [9.105-9]. I can't rollback to older versions because [9.105-9] is the oldest version I could find on the public ftp server. Because the problem appeared on that version too, I upgraded the UTM to the latest version again.
In desperation I deleted the inferface several times, rebooted the UTM and the other components, changed NICs etc. and suddenly the interface came back online...
This was on October 4, 2013. Till then location B was not affected so I thought this outage was caused by an anomaly which in turn was caused by the reboot after the UTMs update and not by the update itself.
Far wrong. On the next day October 5, 2013 location B got affected too. Same messages in PPPoE Log.
Except the rollback I repeated the procedure and after several interface deletions, restarts etc. interface #1 on location B came back too.
So, two outages but both UTMs are back online. Hoping this problem is related to the mentioned threads and to Sophos Bug ID 26850 I thought I have no other options than waiting for the next UTM-Version.
But today at 6 am the UTM on location B has failed again. I had only 30 Minutes to try the ususal procedure before I had to leave the location but failed to bring it back online.
This is why I decided to start another thread for probably the same issue. Because I don't know if this problem is already reported to Sophos and if there is any working and reliable workaround until then...
Thanks for feedback
Cheers
Adrian
This thread was automatically locked due to age.