Index: /anuga_validation/automated_validation_tests/patong_beach_validation/validate.py
===================================================================
--- /anuga_validation/automated_validation_tests/patong_beach_validation/validate.py	(revision 6890)
+++ /anuga_validation/automated_validation_tests/patong_beach_validation/validate.py	(revision 6891)
@@ -106,16 +106,15 @@
         # try each mirror when getting file
         for mirror in mirrors:
-            log.info('Fetching remote file %s from mirror %s'
-                     % (remote, mirror))
+            log.debug('Fetching remote file %s from mirror %s'
+                      % (remote, mirror))
 
             remote_url = mirror + remote + cache_defeat
-            log.debug('Trying to fetching file %s' % remote_url)
-            new_auth = get_web_file(remote_url, local, auth=auth)
-            if new_auth != False and not is_html(local):
+            (result, auth) = get_web_file(remote_url, local, auth=auth)
+            if result and is_html(local)==False:
                 log.debug('Success fetching file %s' % remote_url)
-                return new_auth
-
-        log.info('Could not fetch file %s' % remote_url)
-        return None            
+                return (True, auth)
+
+        log.info('Could not fetch file %s' % local)
+        return (False, auth)            
                 
 
@@ -139,5 +138,6 @@
         '''Update object 'obj' using authentication tuple 'auth'.
         
-        Return updated auth object (success) or None (failure).
+        Return (True, <updated_auth>) if all went well,
+        else (False, <updated_auth>).
         '''
 
@@ -156,18 +156,18 @@
         if not os.path.exists(local_digest) or not os.path.exists(local_file):
             # no digest or no object, download both digest and object
-            auth = get_remote_from_mirrors(obj_digest, local_digest, auth, mirrors)
-            if auth:
-                auth = get_remote_from_mirrors(obj, local_file, auth, mirrors)
+            (res, auth) = get_remote_from_mirrors(obj_digest, local_digest, auth, mirrors)
+            if res:
+                (res, auth) = get_remote_from_mirrors(obj, local_file, auth, mirrors)
         else:
             # download object digest to remote data directory
-            auth = get_remote_from_mirrors(obj_digest, remote_digest, auth, mirrors)
-            if auth:
+            (res, auth) = get_remote_from_mirrors(obj_digest, remote_digest, auth, mirrors)
+            if res:
                 if not files_same(local_data_digest, remote_data_digest):
                     # digests differ, refresh object
-                    log.info('Local file %s is out of date' % obj)
+                    log.info('Local file %s is out of date, refreshing ...' % obj)
                     shutil.move(remote_digest, local_digest)
-                    auth = get_remote_from_mirrors(obj, local_file, auth, mirrors)
+                    (res, auth) = get_remote_from_mirrors(obj, local_file, auth, mirrors)
                 
-        return auth
+        return (res, auth)
 
     # create local data directory if required
@@ -183,17 +183,17 @@
     # success, refresh local files
     auth = None
-    for data_object in Mandatory_Data_Objects:
-        auth = refresh_object(data_object, auth, mirrors)
-        if auth is None:
-            log.debug('Failed fetching %s, returning None' % data_object)
-            return None
-    for data_object in Optional_Data_Objects:
-        auth = refresh_object(data_object, auth, mirrors)
-        if auth is None:
-            log.debug('Failed fetching %s, returning None' % data_object)
-            return None
-
-    log.info('Local data has been refreshed.')
-    return True
+    result = True
+    for data_object in data_objects:
+        log.debug('refresh_local_data: getting %s from mirrors, auth=%s'
+                  % (data_object, str(auth)))
+        (res, auth) = refresh_object(data_object, auth, mirrors)
+        log.debug('refresh_local_data: returned (res,auth)=%s,%s'
+                  % (str(res), str(auth)))
+        if res == False:
+            log.debug('Failed fetching %s, returning False' % data_object)
+            result = False
+
+    log.info('Local data has been refreshed, result=%s.' % str(result))
+    return result
 
 
@@ -208,5 +208,5 @@
     log.critical('Checking if you have the required files to run:')
 
-    have_mandatory_files = True
+    # get max width of object name string
     max_width = 0
     for obj in Mandatory_Data_Objects:
@@ -215,5 +215,6 @@
         max_width = max(len(obj), max_width)
 
-    # if we don't have all mandatory object, can't run
+    # if we don't have *all* mandatory object, can't run
+    have_mandatory_files = True
     for obj in Mandatory_Data_Objects:
         obj_path = os.path.join(Local_Data_Directory, obj)
@@ -224,13 +225,13 @@
             have_mandatory_files = False
 
-    # one or more of these must exist
-    have_optional_files = True
+    # at least *one* of these must exist
+    have_optional_files = False
     for obj in Optional_Data_Objects:
         obj_path = os.path.join(Local_Data_Directory, obj)
         if os.path.exists(obj_path):
+            have_optional_files = True
             log.info('\t%s  found' % obj.ljust(max_width))
         else:
             log.info('\t%s  MISSING!' % obj.ljust(max_width))
-            have_optional_files = False
 
     if not have_mandatory_files or not have_optional_files:
@@ -244,20 +245,5 @@
 
 
-def run_simulation(vtype, sim_obj):
-    '''Run the Patong simulation.'''
-    
-    # now untar file/directory objects
-    for obj in Mandatory_Data_Objects:
-        tar_path = os.path.join(Local_Data_Directory, obj)
-        log.info('Untarring %s in directory %s ...'
-                 % (tar_path, Local_Data_Directory))
-        untar_file(tar_path, target_dir=Local_Data_Directory)
-
-    # untar the vtype object
-    tar_path = os.path.join(Local_Data_Directory, sim_obj)
-    log.info('Untarring %s in directory %s ...'
-             % (tar_path, Local_Data_Directory))
-    untar_file(tar_path, target_dir=Local_Data_Directory)
-
+def set_environment():
     # modify environment so we use the local data
     new_inundationhome = os.path.join(Local_Data_Directory, '')
@@ -265,4 +251,17 @@
     new_muxhome = os.path.join(Local_Data_Directory, 'data')
     os.environ['MUXHOME'] = new_muxhome
+
+
+def run_simulation(vtype, sim_obj):
+    '''Run a simulation.
+
+    Returns True if all went well, else False.
+    '''
+    
+    # untar the object
+    tar_path = os.path.join(Local_Data_Directory, sim_obj)
+    log.info('Untarring %s in directory %s ...'
+             % (tar_path, Local_Data_Directory))
+    untar_file(tar_path, target_dir=Local_Data_Directory)
 
     # modify project.py template
@@ -279,5 +278,5 @@
     fd.close()
     
-    # We import here, _after_ environment variables are set
+    # import new project.py
     import project
 
@@ -285,6 +284,16 @@
     log.critical('Running Patong simulation ...')
     cmd = 'python run_model.py > %s' % RUNMODEL_STDOUT
+    log.debug("run_simulation: doing '%s'" % cmd)
     res = os.system(cmd)
-    assert res == 0
+    log.debug("run_simulation: res=%d" % res)
+
+    # 'unimport' project.py
+    del project
+
+    # check result
+    if res != 0:
+        log.critical('Simulation failed, check log')
+
+    return res == 0
 
 def check_that_output_is_as_expected():
@@ -316,8 +325,13 @@
         return 1
 
+    log.debug('check_that_output_is_as_expected: output_directory=%s'
+              % output_directory)
+    
     # compare SWW files here and there
     new_output_sww = os.path.join(output_directory, OUTPUT_SWW)
     cmd = 'python cmpsww.py %s %s > cmpsww.stdout' % (local_sww, new_output_sww)
+    log.debug("check_that_output_is_as_expected: doing '%s'" % cmd)
     res = os.system(cmd)
+    log.debug("check_that_output_is_as_expected: res=%d" % res)
     if res == 0:
         log.info('Simulation results are as expected.')
@@ -332,12 +346,14 @@
 def teardown():
     '''Clean up after validation run.'''
-    
-    # clear all data objects from local data directory
-    for data_object in Local_Data_Objects:
-        obj_path = os.path.join(Local_Data_Directory, data_object)
-        if os.path.isfile(obj_path):
-            os.remove(obj_path)
-        else:
-            shutil.rmtree(obj_path, ignore_errors=True)
+
+    log.debug('teardown: called')
+    
+##    # clear all data objects from local data directory
+##    for data_object in Local_Data_Objects:
+##        obj_path = os.path.join(Local_Data_Directory, data_object)
+##        if os.path.isfile(obj_path):
+##            os.remove(obj_path)
+##        else:
+##            shutil.rmtree(obj_path, ignore_errors=True)
 
     # remove remote directory and stdout capture file
@@ -355,4 +371,5 @@
 # set logging levels
 log.console_logging_level = log.INFO
+log.log_logging_level = log.DEBUG
 setup()
 
@@ -377,11 +394,6 @@
 
 # make sure local data is up to date
-data_objects = []
-for o in Mandatory_Data_Objects:
-    data_objects.append(o)
-for o in Optional_Data_Objects:
-    data_objects.append(o)
-    
-if not refresh_local_data(data_objects, Local_Data_Directory, MIRRORS):
+all_objects = Mandatory_Data_Objects + Optional_Data_Objects
+if not refresh_local_data(all_objects, Local_Data_Directory, MIRRORS):
     if not can_we_run():
         log.critical("Can't refresh via the internet and you don't have the "
@@ -395,12 +407,22 @@
         sys.exit(10)
 
+# now untar mandatory objects
+for obj in Mandatory_Data_Objects:
+    tar_path = os.path.join(Local_Data_Directory, obj)
+    log.info('Untarring %s in directory %s ...'
+             % (tar_path, Local_Data_Directory))
+    untar_file(tar_path, target_dir=Local_Data_Directory)
+
+# set required environment variables
+set_environment()
+
 # now run what simulations we can and check output is as expected
 for odo in Optional_Data_Objects:
     (_, vtype, _) = odo.rsplit('.', 2)
     vtype = vtype.lower()
-    print "Running Patong '%s' validation" % vtype
-    run_simulation(vtype, odo)
-    check_that_output_is_as_expected(vtype, odo)
+    log.critical("Running Patong '%s' validation ..." % vtype)
+    if run_simulation(vtype, odo):
+        check_that_output_is_as_expected(vtype, odo)
 
 # clean up
-#teardown()
+teardown()
