(*) full support for database caching, including SliceAttributes
[plcapi.git] / TestPeers.ref
index a9b4525..6e68d4f 100644 (file)
@@ -27,7 +27,7 @@ Attempting to set passwd for person_id=4 in DB1UPDATE 1
  -> system returns 0
 Attempting to set passwd for person_id=4 in DB2UPDATE 1
  -> system returns 0
-+++ 13.24 seconds ellapsed (13.24)
++++ 12.97 seconds ellapsed (12.97)
 01:== Created site 2 with max_slices=4
 02:== Created site 2 with max_slices=4
 01:== Created site 3 with max_slices=4
@@ -37,18 +37,18 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01:== Created site 5 with max_slices=4
 02:== Created site 5 with max_slices=4
 === refresh after site creation
-+++ 24.84 seconds ellapsed (11.61)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 4, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 1, 'new_nodes': 0}
-+++ 27.08 seconds ellapsed (2.24)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 4, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 1, 'new_nodes': 0}
-+++ 28.53 seconds ellapsed (1.45)
-+++ 28.53 seconds ellapsed (0.00)
++++ 24.55 seconds ellapsed (11.58)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 4, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 1, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 26.83 seconds ellapsed (2.28)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 4, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 1, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 28.41 seconds ellapsed (1.58)
++++ 28.41 seconds ellapsed (0.00)
 === refresh before persons&keys creation
-+++ 32.29 seconds ellapsed (3.76)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 34.52 seconds ellapsed (2.23)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 36.07 seconds ellapsed (1.55)
++++ 32.17 seconds ellapsed (3.76)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 34.42 seconds ellapsed (2.25)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 36.00 seconds ellapsed (1.58)
 01: Checking keys: got 0 local (e=0) & 0 foreign (e=0)
 02: Checking keys: got 0 local (e=0) & 0 foreign (e=0)
 01: Checking persons: got 4 local (e=4) & 1 foreign (e=1)
@@ -100,25 +100,25 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: Checking persons: got 8 local (e=8) & 1 foreign (e=1)
 02: Checking persons: got 8 local (e=8) & 1 foreign (e=1)
 === refresh after persons&keys creation
-+++ 58.93 seconds ellapsed (22.86)
-01:== Refreshing peer got  {'new_keys': 8, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 4, 'new_nodes': 0}
-+++ 61.32 seconds ellapsed (2.39)
-02:== Refreshing peer got  {'new_keys': 8, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 4, 'new_nodes': 0}
-+++ 63.01 seconds ellapsed (1.70)
++++ 58.79 seconds ellapsed (22.79)
+01:== Refreshing peer got  {'new_keys': 8, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 4, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 61.16 seconds ellapsed (2.37)
+02:== Refreshing peer got  {'new_keys': 8, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 4, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 62.89 seconds ellapsed (1.73)
 01: Checking keys: got 8 local (e=8) & 8 foreign (e=8)
 02: Checking keys: got 8 local (e=8) & 8 foreign (e=8)
 01: Checking persons: got 8 local (e=8) & 5 foreign (e=5)
 02: Checking persons: got 8 local (e=8) & 5 foreign (e=5)
-+++ 65.41 seconds ellapsed (2.40)
++++ 65.30 seconds ellapsed (2.41)
 ==================== ('RESETTING NODES',)
 01:== Cleaning all nodes
 02:== Cleaning all nodes
 === refresh cleaned nodes
-+++ 66.35 seconds ellapsed (0.94)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 68.67 seconds ellapsed (2.32)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 70.77 seconds ellapsed (2.10)
++++ 66.24 seconds ellapsed (0.94)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 68.67 seconds ellapsed (2.43)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 70.39 seconds ellapsed (1.72)
 01: Checking nodes: got 0 local (e=0) & 0 foreign (e=0)
 02: Checking nodes: got 0 local (e=0) & 0 foreign (e=0)
 ==================== ('CREATING NODES',)
@@ -135,11 +135,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: Checking nodes: got 5 local (e=5) & 0 foreign (e=0)
 02: Checking nodes: got 5 local (e=5) & 0 foreign (e=0)
 === refresh after node creation
-+++ 82.39 seconds ellapsed (11.63)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5}
-+++ 84.92 seconds ellapsed (2.53)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5}
-+++ 86.84 seconds ellapsed (1.92)
++++ 82.05 seconds ellapsed (11.65)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5, 'new_slice_attribute_types': 0}
++++ 84.59 seconds ellapsed (2.54)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5, 'new_slice_attribute_types': 0}
++++ 86.50 seconds ellapsed (1.91)
 01: Checking nodes: got 5 local (e=5) & 5 foreign (e=5)
 02: Checking nodes: got 5 local (e=5) & 5 foreign (e=5)
 02:== Deleted node 1, returns 1
@@ -170,11 +170,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02:== Deleted node 20, returns 1
 02: Checking nodes: got 0 local (e=0) & 5 foreign (e=5)
 === refresh after deletion on plc2
-+++ 94.94 seconds ellapsed (8.09)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': -5}
-+++ 97.35 seconds ellapsed (2.42)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 99.28 seconds ellapsed (1.93)
++++ 94.56 seconds ellapsed (8.06)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': -5, 'new_slice_attribute_types': 0}
++++ 97.09 seconds ellapsed (2.53)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 98.99 seconds ellapsed (1.90)
 01: Checking nodes: got 5 local (e=5) & 0 foreign (e=0)
 02: Checking nodes: got 0 local (e=0) & 5 foreign (e=5)
 ==================== ('ADD on plc2 for different indexes',)
@@ -186,14 +186,14 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: Checking nodes: got 5 local (e=5) & 0 foreign (e=0)
 02: Checking nodes: got 5 local (e=5) & 5 foreign (e=5)
 === refresh after re-creation on plc2
-+++ 102.83 seconds ellapsed (3.54)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5}
-+++ 105.35 seconds ellapsed (2.52)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 107.23 seconds ellapsed (1.88)
++++ 102.53 seconds ellapsed (3.54)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 5, 'new_slice_attribute_types': 0}
++++ 105.07 seconds ellapsed (2.54)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 106.99 seconds ellapsed (1.91)
 01: Checking nodes: got 5 local (e=5) & 5 foreign (e=5)
 02: Checking nodes: got 5 local (e=5) & 5 foreign (e=5)
-+++ 108.51 seconds ellapsed (1.28)
++++ 108.26 seconds ellapsed (1.28)
 ==================== ('RESETTING SLICES TEST',)
 01:== Cleaning all nodes
 01:==== Cleaning node 1
@@ -222,11 +222,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02:== Cleaning all slices
 02:==== Cleaning slice 3
 === refresh After slices init
-+++ 125.98 seconds ellapsed (17.47)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 128.52 seconds ellapsed (2.54)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 130.38 seconds ellapsed (1.85)
++++ 125.63 seconds ellapsed (17.37)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 128.18 seconds ellapsed (2.55)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 130.06 seconds ellapsed (1.88)
 ==================== ('CREATING SLICES on plc1',)
 01:== created slice 4 - max nodes=5
 01:== Attached person user1-1@plc1.org to slice oneone_slice1
@@ -251,11 +251,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: Checking slices: got 6 local (e=6) & 0 foreign (e=0)
 02: Checking slices: got 2 local (e=2) & 0 foreign (e=0)
 === refresh after slice created on plc1
-+++ 152.20 seconds ellapsed (21.82)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 154.71 seconds ellapsed (2.51)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 4, 'new_persons': 0, 'new_nodes': 0}
-+++ 156.64 seconds ellapsed (1.93)
++++ 151.77 seconds ellapsed (21.71)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 154.32 seconds ellapsed (2.56)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 4, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 156.32 seconds ellapsed (1.99)
 01: Checking slices: got 6 local (e=6) & 0 foreign (e=0)
 02: Checking slices: got 2 local (e=2) & 4 foreign (e=4)
 01: local slice oneone_slice1 (e=0)  on nodes  []
@@ -267,10 +267,10 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onethree_slice3 (e=0)  on nodes  []
 02: foreign slice onefour_slice4 (e=0)  on nodes  []
 ==================== ('ADDING LOCAL NODES IN SLICES',)
-01:== added in slice 4 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== added in slice 5 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== added in slice 6 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== added in slice 7 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== added in slice oneone_slice1 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== added in slice onetwo_slice2 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== added in slice onethree_slice3 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== added in slice onefour_slice4 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
 01: local slice oneone_slice1 (e=5)  on nodes  [16, 17, 18, 19, 20]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 01: local slice onetwo_slice2 (e=5)  on nodes  [16, 17, 18, 19, 20]
@@ -284,11 +284,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onethree_slice3 (e=0)  on nodes  []
 02: foreign slice onefour_slice4 (e=0)  on nodes  []
 === refresh After local nodes were added on plc1
-+++ 181.07 seconds ellapsed (24.44)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 183.59 seconds ellapsed (2.52)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 185.52 seconds ellapsed (1.93)
++++ 177.39 seconds ellapsed (21.08)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 179.93 seconds ellapsed (2.54)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 181.91 seconds ellapsed (1.99)
 01: local slice oneone_slice1 (e=5)  on nodes  [16, 17, 18, 19, 20]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 01: local slice onetwo_slice2 (e=5)  on nodes  [16, 17, 18, 19, 20]
@@ -306,10 +306,10 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onefour_slice4 (e=5)  on nodes  [8, 9, 10, 6, 7]
 [FOR:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 ==================== ('ADDING FOREIGN NODES IN SLICES',)
-01:== added in slice 4 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== added in slice 5 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== added in slice 6 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== added in slice 7 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== added in slice oneone_slice1 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== added in slice onetwo_slice2 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== added in slice onethree_slice3 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== added in slice onefour_slice4 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
 01: local slice oneone_slice1 (e=10)  on nodes  [16, 17, 18, 19, 20, 11, 12, 13, 14, 15]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 [FOR:5] :  n201.plc2.org  n202.plc2.org  n203.plc2.org  n204.plc2.org  n205.plc2.org  
@@ -331,11 +331,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onefour_slice4 (e=5)  on nodes  [8, 9, 10, 6, 7]
 [FOR:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 === refresh After foreign nodes were added in plc1
-+++ 209.31 seconds ellapsed (23.79)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 211.86 seconds ellapsed (2.55)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 213.88 seconds ellapsed (2.02)
++++ 202.35 seconds ellapsed (20.44)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 204.93 seconds ellapsed (2.58)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 206.96 seconds ellapsed (2.03)
 01: local slice oneone_slice1 (e=10)  on nodes  [16, 17, 18, 19, 20, 11, 12, 13, 14, 15]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 [FOR:5] :  n201.plc2.org  n202.plc2.org  n203.plc2.org  n204.plc2.org  n205.plc2.org  
@@ -363,7 +363,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: 4 slivers (exp. 4) in GetSlivers for node n101.plc1.org
 >>slivername =  oneone_slice1
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839729,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -385,7 +385,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 4}
 >>slivername =  onetwo_slice2
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839727,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -407,7 +407,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 5}
 >>slivername =  onethree_slice3
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839739,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -429,7 +429,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 6}
 >>slivername =  onefour_slice4
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839744,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -452,7 +452,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: 4 slivers (exp. 4) in GetSlivers for node n201.plc2.org
 >>slivername =  oneone_slice1
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839729,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user3-key1',
                  'key_type': 'ssh'},
@@ -474,7 +474,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 4}
 >>slivername =  onetwo_slice2
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839727,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user3-key1',
                  'key_type': 'ssh'},
@@ -496,7 +496,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 5}
 >>slivername =  onethree_slice3
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839739,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user3-key1',
                  'key_type': 'ssh'},
@@ -518,7 +518,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 6}
 >>slivername =  onefour_slice4
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839744,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user3-key1',
                  'key_type': 'ssh'},
@@ -539,10 +539,10 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'name': 'onefour_slice4',
    'slice_id': 7}
 ==================== ('DELETING FOREIGN NODES FROM SLICES',)
-01:== deleted in slice 4 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== deleted in slice 5 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== deleted in slice 6 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
-01:== deleted in slice 7 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== deleted in slice oneone_slice1 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== deleted in slice onetwo_slice2 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== deleted in slice onethree_slice3 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
+01:== deleted in slice onefour_slice4 foreign  ['n201.plc2.org', 'n202.plc2.org', 'n203.plc2.org', 'n204.plc2.org', 'n205.plc2.org']
 01: local slice oneone_slice1 (e=5)  on nodes  [16, 17, 18, 19, 20]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 01: local slice onetwo_slice2 (e=5)  on nodes  [16, 17, 18, 19, 20]
@@ -566,7 +566,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: 4 slivers (exp. 4) in GetSlivers for node n101.plc1.org
 >>slivername =  oneone_slice1
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839729,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -588,7 +588,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 4}
 >>slivername =  onetwo_slice2
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839727,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -610,7 +610,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 5}
 >>slivername =  onethree_slice3
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839739,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -632,7 +632,7 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'slice_id': 6}
 >>slivername =  onefour_slice4
 {  'attributes': [],
-   'expires': normalized,
+   'expires': 1165839744,
    'instantiation': 'plc-instantiated',
    'keys': [  {  'key': 'ssh-rsa 1111111111111111 user1-key1',
                  'key_type': 'ssh'},
@@ -653,11 +653,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
    'name': 'onefour_slice4',
    'slice_id': 7}
 === refresh After foreign nodes were removed on plc1
-+++ 240.71 seconds ellapsed (26.83)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 243.24 seconds ellapsed (2.53)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 245.17 seconds ellapsed (1.93)
++++ 230.50 seconds ellapsed (23.55)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 233.03 seconds ellapsed (2.53)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 234.97 seconds ellapsed (1.94)
 01: local slice oneone_slice1 (e=5)  on nodes  [16, 17, 18, 19, 20]
 [LOC:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 01: local slice onetwo_slice2 (e=5)  on nodes  [16, 17, 18, 19, 20]
@@ -675,10 +675,10 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onefour_slice4 (e=5)  on nodes  [8, 9, 10, 6, 7]
 [FOR:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 ==================== ('DELETING LOCAL NODES FROM SLICES',)
-01:== deleted in slice 4 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== deleted in slice 5 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== deleted in slice 6 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
-01:== deleted in slice 7 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== deleted in slice oneone_slice1 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== deleted in slice onetwo_slice2 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== deleted in slice onethree_slice3 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
+01:== deleted in slice onefour_slice4 local  ['n101.plc1.org', 'n102.plc1.org', 'n103.plc1.org', 'n104.plc1.org', 'n105.plc1.org']
 01: local slice oneone_slice1 (e=0)  on nodes  []
 01: local slice onetwo_slice2 (e=0)  on nodes  []
 01: local slice onethree_slice3 (e=0)  on nodes  []
@@ -692,11 +692,11 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 02: foreign slice onefour_slice4 (e=5)  on nodes  [8, 9, 10, 6, 7]
 [FOR:5] :  n101.plc1.org  n102.plc1.org  n103.plc1.org  n104.plc1.org  n105.plc1.org  
 === refresh After local nodes were removed on plc1
-+++ 267.60 seconds ellapsed (22.43)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 270.09 seconds ellapsed (2.49)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 272.02 seconds ellapsed (1.92)
++++ 254.14 seconds ellapsed (19.17)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 256.67 seconds ellapsed (2.52)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 258.66 seconds ellapsed (1.99)
 01: local slice oneone_slice1 (e=0)  on nodes  []
 01: local slice onetwo_slice2 (e=0)  on nodes  []
 01: local slice onethree_slice3 (e=0)  on nodes  []
@@ -714,12 +714,21 @@ Attempting to set passwd for person_id=4 in DB2UPDATE 1
 01: Checking slices: got 2 local (e=2) & 0 foreign (e=0)
 02: Checking slices: got 2 local (e=2) & 4 foreign (e=4)
 === refresh After slices clenaup
-+++ 286.11 seconds ellapsed (14.09)
-01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0}
-+++ 288.65 seconds ellapsed (2.54)
-02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': -4, 'new_persons': 0, 'new_nodes': 0}
-+++ 290.56 seconds ellapsed (1.91)
++++ 272.37 seconds ellapsed (13.71)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 274.90 seconds ellapsed (2.53)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': -4, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 0}
++++ 276.84 seconds ellapsed (1.94)
 01: Checking slices: got 2 local (e=2) & 0 foreign (e=0)
 02: Checking slices: got 2 local (e=2) & 0 foreign (e=0)
-+++ 292.44 seconds ellapsed (1.88)
++++ 278.73 seconds ellapsed (1.89)
+01:== created SliceAttributeType = 20
+02:== created SliceAttributeType = 20
+=== refresh after SliceAttributeType creation
++++ 280.62 seconds ellapsed (1.90)
+01:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc1', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 1}
++++ 283.18 seconds ellapsed (2.56)
+02:== Refreshing peer got  {'new_keys': 0, 'new_sites': 0, 'plcname': 'Thierry plc2 on devbox', 'new_slices': 0, 'new_persons': 0, 'new_nodes': 0, 'new_slice_attribute_types': 1}
++++ 285.12 seconds ellapsed (1.93)
++++ 285.12 seconds ellapsed (0.00)
 ==================== ('END',)