This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

UP2Date failing because of Authentication servers failed

I am running 9.004-34 and I have tried to check for updates packages, but am getting the following in the up2date log.
 
2013:04:12-14:34:58 ASG auisys[6004]: Unpacking installation instructions
2013:04:12-14:34:58 ASG auisys[6004]: >=========================================================================
2013:04:12-14:34:58 ASG auisys[6004]: id="371J" severity="error" sys="system" sub="up2date" name="Fatal: Version conflict: required version: 9.005015  current version: 9.004034" status="failed" action="install" package="sys"
2013:04:12-14:34:58 ASG auisys[6004]:
2013:04:12-14:34:58 ASG auisys[6004]: 1. main::alf:68() auisys.pl
2013:04:12-14:34:58 ASG auisys[6004]: 2. main:[:P]erform_work:1010() auisys.pl
2013:04:12-14:34:58 ASG auisys[6004]: 3. main::auisys_prepare_and_work:554() auisys.pl
2013:04:12-14:34:58 ASG auisys[6004]: 4. main::top-level:30() auisys.pl
2013:04:12-14:35:45 ASG audld[6311]: Starting Up2Date Package Downloader
2013:04:12-14:35:45 ASG audld[6311]: patch up2date possible
2013:04:12-14:36:31 ASG audld[6311]: Could not connect to Authentication Server 184.72.238.199:443 (code=500).
2013:04:12-14:37:16 ASG audld[6311]: Could not connect to Authentication Server 184.72.238.199:443 (code=500).
2013:04:12-14:38:01 ASG audld[6311]: Could not connect to Authentication Server 79.125.21.244:443 (code=500).
2013:04:12-14:38:35 ASG auisys[6965]: Starting Up2Date Package Installer
2013:04:12-14:38:35 ASG auisys[6965]: >=========================================================================
2013:04:12-14:38:35 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:38:35 ASG auisys[6965]:
2013:04:12-14:38:35 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:38:35 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:38:35 ASG auisys[6965]: =========================================================================
2013:04:12-14:38:40 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:38:40 ASG auisys[6965]:
2013:04:12-14:38:40 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:38:40 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:38:40 ASG auisys[6965]: =========================================================================
2013:04:12-14:38:46 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:38:46 ASG auisys[6965]:
2013:04:12-14:38:46 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:38:46 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:38:46 ASG auisys[6965]: =========================================================================
2013:04:12-14:38:51 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:38:51 ASG auisys[6965]:
2013:04:12-14:38:51 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:38:51 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:38:51 ASG auisys[6965]: =========================================================================
2013:04:12-14:38:56 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:38:56 ASG auisys[6965]:
2013:04:12-14:38:56 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:38:56 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:38:56 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:01 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:01 ASG auisys[6965]:
2013:04:12-14:39:01 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:01 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:01 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:04 ASG audld[7569]: Another instance of this process is already running, exiting
2013:04:12-14:39:04 ASG audld[7569]: pids currently running: 6311 7569 (my pid: 7569, parent pid: 1)
2013:04:12-14:39:04 ASG audld[7569]:
2013:04:12-14:39:04 ASG audld[7569]: 1. main::run:194() audld.pl
2013:04:12-14:39:04 ASG audld[7569]: 2. main::top-level:27() audld.pl
2013:04:12-14:39:07 ASG auisys[6965]: >=========================================================================
2013:04:12-14:39:07 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:07 ASG auisys[6965]:
2013:04:12-14:39:07 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:07 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:07 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:12 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:12 ASG auisys[6965]:
2013:04:12-14:39:12 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:12 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:12 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:17 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:17 ASG auisys[6965]:
2013:04:12-14:39:17 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:17 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:17 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:12 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:12 ASG auisys[6965]:
2013:04:12-14:39:12 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:12 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:12 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:17 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:17 ASG auisys[6965]:
2013:04:12-14:39:17 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:17 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:17 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:22 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:22 ASG auisys[6965]:
2013:04:12-14:39:22 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:22 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:22 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:28 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:28 ASG auisys[6965]:
2013:04:12-14:39:28 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:28 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:28 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:33 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:33 ASG auisys[6965]:
2013:04:12-14:39:33 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:33 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:33 ASG auisys[6965]: =========================================================================
2013:04:12-14:39:38 ASG auisys[6965]: can't open pattern revision file '/var/up2date//global_revision': No such file or directory
2013:04:12-14:39:38 ASG auisys[6965]:
2013:04:12-14:39:38 ASG auisys[6965]: 1. main::auisys_prepare_and_work:471() auisys.pl
2013:04:12-14:39:38 ASG auisys[6965]: 2. main::top-level:30() auisys.pl
2013:04:12-14:39:38 ASG auisys[6965]: =========================================================================
2013:04:12-14:40:16 ASG audld[6311]: All 6 Authentication Servers failed
2013:04:12-14:40:16 ASG audld[6311]: '175.41.132.12:443' Code: '500'
2013:04:12-14:40:16 ASG audld[6311]: '184.72.238.199:443' Code: '500'
2013:04:12-14:40:16 ASG audld[6311]: '79.125.21.244:443' Code: '500'
2013:04:12-14:40:16 ASG audld[6311]:
2013:04:12-14:40:16 ASG audld[6311]: 1. Modules::Trad_Get_Filelist::contact:1524() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 2. main::authenticate:574() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 3. main::run:378() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 4. main::top-level:27() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: |=========================================================================
2013:04:12-14:40:16 ASG audld[6311]: id="3703" severity="error" sys="system" sub="up2date" name="Authentication failed, no valid answer from Authentication Servers"
2013:04:12-14:40:16 ASG audld[6311]:
2013:04:12-14:40:16 ASG audld[6311]: 1. main::alf:841() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 2. main::authenticate:578() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 3. main::run:378() audld.pl
2013:04:12-14:40:16 ASG audld[6311]: 4. main::top-level:27() audld.pl


This thread was automatically locked due to age.
Parents
  • I double checked my license and even uploaded a new copy of it and still have the same problem.  I just rebuilt the server a few months ago and never had this problem before the rebuild.
  • Ahaaa, found it.
    I was just digging through the logfiles and there aren't that much because this machine had it's first start at April, 11th.
    IMHO this is a side effect when a freshly installed machine runs with the same license as it's predecessor. A guess - every machine has an ID which is used to authenticate at the up2date servers. And it looks like the IP address which was used before counts, too.
    My up2date logfile at the first start:

    2013:04:11-14:21:01 mail audld[13677]: Starting Up2Date Package Downloader
    2013:04:11-14:21:02 mail audld[13677]: patch up2date possible
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: >=========================================================================
    2013:04:11-14:21:03 mail audld[13677]: All 3 Authentication Servers failed
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                   Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                   Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                    Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: 
    2013:04:11-14:21:03 mail audld[13677]:  1. Modules::Trad_Get_Filelist::contact:1534() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  2. main::authenticate:584() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  3. main::run:388() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  4. main::top-level:27() audld.pl
    2013:04:11-14:21:03 mail audld[13677]: |=========================================================================
    2013:04:11-14:21:03 mail audld[13677]: id="3703" severity="error" sys="system" sub="up2date" name="Authentication failed, no valid answer from Authentication Servers"
    2013:04:11-14:21:03 mail audld[13677]: 
    2013:04:11-14:21:03 mail audld[13677]:  1. main::alf:851() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  2. main::authenticate:588() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  3. main::run:388() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  4. main::top-level:27() audld.pl

    Looks like your log.
    A little later in the Web Filtering Log:

    2013:04:11-14:32:21 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:32:41 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:01 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:21 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:41 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:01 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:22 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:42 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"

    The DNS log shows a lot of errors, too. At 15:50 I gave up, the machine did not allow surfing and other services did not work, too.
    The whole story: https://community.sophos.com/products/unified-threat-management/astaroorg/f/52/t/28856

    Next try on Monday, April 15th, start again at 18:10 with the same errors. At 18:13 I changed the IP of the IF I have configured for surfing and after that everything was allright.
    No more DNS or Web or up2date errors and without any changes except the external IP.

    The up2date log after the change:
    2013:04:15-18:22:01 mail audld[6964]: Starting Up2Date Package Downloader
    2013:04:15-18:22:02 mail audld[6964]: patch up2date possible
    2013:04:15-18:22:03 mail audld[6964]: id="3701" severity="info" sys="system" sub="up2date" name="Authentication successful"
    2013:04:15-19:38:01 mail audld[12405]: Starting Up2Date Package Downloader
    2013:04:15-19:38:01 mail audld[12405]: patch up2date possible
    2013:04:15-19:38:01 mail audld[12405]: id="3701" severity="info" sys="system" sub="up2date" name="Authentication successful"

    If you have the chance to change the external IP for surfing, give it a shot.
Reply
  • Ahaaa, found it.
    I was just digging through the logfiles and there aren't that much because this machine had it's first start at April, 11th.
    IMHO this is a side effect when a freshly installed machine runs with the same license as it's predecessor. A guess - every machine has an ID which is used to authenticate at the up2date servers. And it looks like the IP address which was used before counts, too.
    My up2date logfile at the first start:

    2013:04:11-14:21:01 mail audld[13677]: Starting Up2Date Package Downloader
    2013:04:11-14:21:02 mail audld[13677]: patch up2date possible
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: Could not connect to Authentication Server ***.xx.***.xx:443 (code=500).
    2013:04:11-14:21:03 mail audld[13677]: >=========================================================================
    2013:04:11-14:21:03 mail audld[13677]: All 3 Authentication Servers failed
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                   Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                   Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: '***.xx.***.xx:443'                    Code: '500'
    2013:04:11-14:21:03 mail audld[13677]: 
    2013:04:11-14:21:03 mail audld[13677]:  1. Modules::Trad_Get_Filelist::contact:1534() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  2. main::authenticate:584() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  3. main::run:388() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  4. main::top-level:27() audld.pl
    2013:04:11-14:21:03 mail audld[13677]: |=========================================================================
    2013:04:11-14:21:03 mail audld[13677]: id="3703" severity="error" sys="system" sub="up2date" name="Authentication failed, no valid answer from Authentication Servers"
    2013:04:11-14:21:03 mail audld[13677]: 
    2013:04:11-14:21:03 mail audld[13677]:  1. main::alf:851() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  2. main::authenticate:588() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  3. main::run:388() audld.pl
    2013:04:11-14:21:03 mail audld[13677]:  4. main::top-level:27() audld.pl

    Looks like your log.
    A little later in the Web Filtering Log:

    2013:04:11-14:32:21 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:32:41 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:01 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:21 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:33:41 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:01 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:22 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"
    2013:04:11-14:34:42 mail httpproxy[14996]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_resolve_server" file="scr_scanner.c" line="350" message="DNS: ******.astaro.com: Name or service not known"

    The DNS log shows a lot of errors, too. At 15:50 I gave up, the machine did not allow surfing and other services did not work, too.
    The whole story: https://community.sophos.com/products/unified-threat-management/astaroorg/f/52/t/28856

    Next try on Monday, April 15th, start again at 18:10 with the same errors. At 18:13 I changed the IP of the IF I have configured for surfing and after that everything was allright.
    No more DNS or Web or up2date errors and without any changes except the external IP.

    The up2date log after the change:
    2013:04:15-18:22:01 mail audld[6964]: Starting Up2Date Package Downloader
    2013:04:15-18:22:02 mail audld[6964]: patch up2date possible
    2013:04:15-18:22:03 mail audld[6964]: id="3701" severity="info" sys="system" sub="up2date" name="Authentication successful"
    2013:04:15-19:38:01 mail audld[12405]: Starting Up2Date Package Downloader
    2013:04:15-19:38:01 mail audld[12405]: patch up2date possible
    2013:04:15-19:38:01 mail audld[12405]: id="3701" severity="info" sys="system" sub="up2date" name="Authentication successful"

    If you have the chance to change the external IP for surfing, give it a shot.
Children
No Data