kytos-ng / kytos-end-to-end-tests

Kytos End-to-End Tests
0 stars 10 forks source link

End-to-end tests running in a overloaded environment can leads to delayed Kytos startup and timeout on switch connection #118

Closed italovalcy closed 2 years ago

italovalcy commented 2 years ago

Hi,

In an overloaded execution environment, the Kytos startup process can be severely impacted and Kytos can take a couple of seconds to finish starting up. As a consequence, the switches will also take longer to connect and the end-to-end tests will fail with a Timeout exception, such as the one shown below:

___________ ERROR at setup of TestE2ETopology.test_005_list_topology ___________

cls = <class 'tests.test_e2e_05_topology.TestE2ETopology'>

    @classmethod
    def setup_class(cls):
        syslog.syslog("setup_class started for %s" % (__file__))
        cls.net = NetworkTest(CONTROLLER)
        cls.net.start()
>       cls.net.wait_switches_connect()

tests/test_e2e_05_topology.py:30:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <tests.helpers.NetworkTest object at 0x7f4b6ea79d90>

    def wait_switches_connect(self):
        syslog.syslog("wait_switches_connect started")
        max_wait = 0
        while any(not sw.connected() for sw in self.net.switches):
            time.sleep(1)
            max_wait += 1
            if max_wait > 30:
>               raise Exception("Timeout: timed out waiting switches reconnect.")
E               Exception: Timeout: timed out waiting switches reconnect.

tests/helpers.py:200: Exception

Looking at all restarts done during a sequence of tests, we can see that Kytos takes more to 40s in some cases (first column is the duration between kytos stop and finishing starting the last Napp which is maintenance in my scenario -- we have to subtract 5 seconds from the duration which is the interval between stop and start):

# awk '{if ($0 ~/Stopping Kytos controller/) {stop=$1" "$2" "$3}; if ($0 ~ /Loading NApp kytos\/maintenance/) {print stop,$1,$2,$3}}' /var/log/syslog| awk -F "[ :]" '{dur=$8*60*60+$9*60+$10 - ($3*60*60+$4*60+$5); print dur" --- "$0}' | sort -n
8 --- Jan 18 06:12:12 Jan 18 06:12:20
9 --- Jan 18 05:56:31 Jan 18 05:56:40
10 --- Jan 18 06:04:06 Jan 18 06:04:16
10 --- Jan 18 06:10:16 Jan 18 06:10:26
10 --- Jan 18 06:10:26 Jan 18 06:10:36
10 --- Jan 18 06:11:07 Jan 18 06:11:17
12 --- Jan 18 06:13:16 Jan 18 06:13:28
13 --- Jan 18 06:11:41 Jan 18 06:11:54
14 --- Jan 18 06:06:11 Jan 18 06:06:25
14 --- Jan 18 06:12:47 Jan 18 06:13:01
15 --- Jan 18 06:07:11 Jan 18 06:07:26
16 --- Jan 18 05:57:16 Jan 18 05:57:32
16 --- Jan 18 05:58:16 Jan 18 05:58:32
17 --- Jan 18 02:26:57 Jan 18 02:27:14
17 --- Jan 18 02:39:57 Jan 18 02:40:14
17 --- Jan 18 04:49:24 Jan 18 04:49:41
18 --- Jan 18 05:51:31 Jan 18 05:51:49
18 --- Jan 18 06:05:21 Jan 18 06:05:39
18 --- Jan 18 06:08:12 Jan 18 06:08:30
19 --- Jan 18 02:33:27 Jan 18 02:33:46
19 --- Jan 18 02:34:07 Jan 18 02:34:26
19 --- Jan 18 02:50:04 Jan 18 02:50:23
20 --- Jan 18 04:01:38 Jan 18 04:01:58
20 --- Jan 18 05:13:12 Jan 18 05:13:32
20 --- Jan 18 05:54:30 Jan 18 05:54:50
21 --- Jan 18 02:26:17 Jan 18 02:26:38
21 --- Jan 18 02:39:18 Jan 18 02:39:39
21 --- Jan 18 04:55:40 Jan 18 04:56:01
21 --- Jan 18 05:53:31 Jan 18 05:53:52
21 --- Jan 18 05:59:16 Jan 18 05:59:37
22 --- Jan 18 02:32:47 Jan 18 02:33:09
22 --- Jan 18 02:50:44 Jan 18 02:51:06
22 --- Jan 18 04:14:38 Jan 18 04:15:00
22 --- Jan 18 04:30:21 Jan 18 04:30:43
22 --- Jan 18 05:55:30 Jan 18 05:55:52
23 --- Jan 18 05:52:31 Jan 18 05:52:54
23 --- Jan 18 06:00:41 Jan 18 06:01:04
23 --- Jan 18 06:09:06 Jan 18 06:09:29
24 --- Jan 18 02:27:36 Jan 18 02:28:00
24 --- Jan 18 02:36:17 Jan 18 02:36:41
24 --- Jan 18 05:04:41 Jan 18 05:05:05
24 --- Jan 18 06:03:11 Jan 18 06:03:35
25 --- Jan 18 02:22:15 Jan 18 02:22:40
25 --- Jan 18 02:29:03 Jan 18 02:29:28
25 --- Jan 18 02:29:47 Jan 18 02:30:12
25 --- Jan 18 02:35:33 Jan 18 02:35:58
25 --- Jan 18 02:42:09 Jan 18 02:42:34
25 --- Jan 18 02:42:54 Jan 18 02:43:19
25 --- Jan 18 05:50:25 Jan 18 05:50:50
26 --- Jan 18 02:24:01 Jan 18 02:24:27
26 --- Jan 18 02:24:47 Jan 18 02:25:13
26 --- Jan 18 02:30:32 Jan 18 02:30:58
26 --- Jan 18 02:31:18 Jan 18 02:31:44
26 --- Jan 18 02:32:02 Jan 18 02:32:28
26 --- Jan 18 02:38:32 Jan 18 02:38:58
26 --- Jan 18 02:41:24 Jan 18 02:41:50
26 --- Jan 18 02:49:15 Jan 18 02:49:41
26 --- Jan 18 03:04:16 Jan 18 03:04:42
26 --- Jan 18 03:05:29 Jan 18 03:05:55
26 --- Jan 18 03:06:06 Jan 18 03:06:32
26 --- Jan 18 04:31:24 Jan 18 04:31:50
26 --- Jan 18 04:59:56 Jan 18 05:00:22
26 --- Jan 18 05:01:00 Jan 18 05:01:26
26 --- Jan 18 05:16:31 Jan 18 05:16:57
27 --- Jan 18 02:25:31 Jan 18 02:25:58
27 --- Jan 18 02:28:17 Jan 18 02:28:44
27 --- Jan 18 02:34:48 Jan 18 02:35:15
27 --- Jan 18 05:02:52 Jan 18 05:03:19
28 --- Jan 18 02:36:57 Jan 18 02:37:25
28 --- Jan 18 02:37:43 Jan 18 02:38:11
28 --- Jan 18 02:45:19 Jan 18 02:45:47
28 --- Jan 18 04:02:20 Jan 18 04:02:48
28 --- Jan 18 04:55:00 Jan 18 04:55:28
28 --- Jan 18 05:15:32 Jan 18 05:16:00
29 --- Jan 18 02:40:34 Jan 18 02:41:03
29 --- Jan 18 02:46:03 Jan 18 02:46:32
29 --- Jan 18 02:52:10 Jan 18 02:52:39
29 --- Jan 18 04:32:13 Jan 18 04:32:42
29 --- Jan 18 05:12:29 Jan 18 05:12:58
29 --- Jan 18 06:01:36 Jan 18 06:02:05
30 --- Jan 18 02:43:40 Jan 18 02:44:10
30 --- Jan 18 02:47:44 Jan 18 02:48:14
30 --- Jan 18 02:55:39 Jan 18 02:56:09
30 --- Jan 18 02:59:07 Jan 18 02:59:37
30 --- Jan 18 03:03:37 Jan 18 03:04:07
30 --- Jan 18 04:59:13 Jan 18 04:59:43
31 --- Jan 18 02:51:25 Jan 18 02:51:56
31 --- Jan 18 03:00:52 Jan 18 03:01:23
31 --- Jan 18 03:59:46 Jan 18 04:00:17
31 --- Jan 18 04:00:50 Jan 18 04:01:21
31 --- Jan 18 04:27:22 Jan 18 04:27:53
31 --- Jan 18 05:14:46 Jan 18 05:15:17
31 --- Jan 18 05:48:05 Jan 18 05:48:36
32 --- Jan 18 02:44:29 Jan 18 02:45:01
32 --- Jan 18 02:48:29 Jan 18 02:49:01
32 --- Jan 18 03:02:36 Jan 18 03:03:08
32 --- Jan 18 03:09:17 Jan 18 03:09:49
32 --- Jan 18 04:16:29 Jan 18 04:17:01
32 --- Jan 18 04:29:20 Jan 18 04:29:52
33 --- Jan 18 02:21:23 Jan 18 02:21:56
33 --- Jan 18 02:46:50 Jan 18 02:47:23
33 --- Jan 18 02:52:50 Jan 18 02:53:23
33 --- Jan 18 02:56:20 Jan 18 02:56:53
33 --- Jan 18 03:07:11 Jan 18 03:07:44
33 --- Jan 18 03:08:33 Jan 18 03:09:06
33 --- Jan 18 03:10:31 Jan 18 03:11:04
33 --- Jan 18 04:03:10 Jan 18 04:03:43
33 --- Jan 18 04:19:32 Jan 18 04:20:05
33 --- Jan 18 04:28:25 Jan 18 04:28:58
33 --- Jan 18 04:33:57 Jan 18 04:34:30
33 --- Jan 18 04:48:32 Jan 18 04:49:05
33 --- Jan 18 05:01:58 Jan 18 05:02:31
34 --- Jan 18 02:53:39 Jan 18 02:54:13
34 --- Jan 18 02:55:04 Jan 18 02:55:38
34 --- Jan 18 02:58:20 Jan 18 02:58:54
34 --- Jan 18 03:00:07 Jan 18 03:00:41
34 --- Jan 18 03:01:51 Jan 18 03:02:25
34 --- Jan 18 03:11:23 Jan 18 03:11:57
34 --- Jan 18 03:32:42 Jan 18 03:33:16
34 --- Jan 18 04:10:50 Jan 18 04:11:24
34 --- Jan 18 04:23:39 Jan 18 04:24:13
34 --- Jan 18 04:34:48 Jan 18 04:35:22
34 --- Jan 18 04:52:26 Jan 18 04:53:00
34 --- Jan 18 05:08:12 Jan 18 05:08:46
34 --- Jan 18 05:30:26 Jan 18 05:31:00
34 --- Jan 18 05:46:51 Jan 18 05:47:25
35 --- Jan 18 02:22:52 Jan 18 02:23:27
35 --- Jan 18 02:57:15 Jan 18 02:57:50
35 --- Jan 18 03:12:58 Jan 18 03:13:33
35 --- Jan 18 03:34:50 Jan 18 03:35:25
35 --- Jan 18 04:09:01 Jan 18 04:09:36
35 --- Jan 18 04:13:42 Jan 18 04:14:17
35 --- Jan 18 04:17:25 Jan 18 04:18:00
35 --- Jan 18 04:20:31 Jan 18 04:21:06
35 --- Jan 18 04:22:30 Jan 18 04:23:05
35 --- Jan 18 04:33:01 Jan 18 04:33:36
35 --- Jan 18 04:39:29 Jan 18 04:40:04
35 --- Jan 18 05:10:23 Jan 18 05:10:58
35 --- Jan 18 05:49:11 Jan 18 05:49:46
36 --- Jan 18 03:12:09 Jan 18 03:12:45
36 --- Jan 18 03:40:12 Jan 18 03:40:48
36 --- Jan 18 03:42:48 Jan 18 03:43:24
36 --- Jan 18 04:06:00 Jan 18 04:06:36
36 --- Jan 18 04:09:52 Jan 18 04:10:28
36 --- Jan 18 04:11:49 Jan 18 04:12:25
36 --- Jan 18 04:21:24 Jan 18 04:22:00
36 --- Jan 18 04:24:36 Jan 18 04:25:12
36 --- Jan 18 04:25:31 Jan 18 04:26:07
36 --- Jan 18 04:36:43 Jan 18 04:37:19
36 --- Jan 18 04:38:34 Jan 18 04:39:10
37 --- Jan 18 03:13:47 Jan 18 03:14:24
37 --- Jan 18 03:39:19 Jan 18 03:39:56
37 --- Jan 18 03:41:32 Jan 18 03:42:09
37 --- Jan 18 03:48:41 Jan 18 03:49:18
37 --- Jan 18 04:04:58 Jan 18 04:05:35
37 --- Jan 18 04:07:00 Jan 18 04:07:37
37 --- Jan 18 04:12:43 Jan 18 04:13:20
37 --- Jan 18 04:18:22 Jan 18 04:18:59
37 --- Jan 18 04:26:27 Jan 18 04:27:04
37 --- Jan 18 04:37:38 Jan 18 04:38:15
37 --- Jan 18 05:27:36 Jan 18 05:28:13
38 --- Jan 18 03:31:35 Jan 18 03:32:13
38 --- Jan 18 03:35:53 Jan 18 03:36:31
38 --- Jan 18 03:45:18 Jan 18 03:45:56
38 --- Jan 18 03:55:12 Jan 18 03:55:50
38 --- Jan 18 03:56:46 Jan 18 03:57:24
38 --- Jan 18 04:03:59 Jan 18 04:04:37
38 --- Jan 18 04:08:01 Jan 18 04:08:39
38 --- Jan 18 04:40:24 Jan 18 04:41:02
38 --- Jan 18 04:47:53 Jan 18 04:48:31
38 --- Jan 18 04:54:09 Jan 18 04:54:47
38 --- Jan 18 05:35:22 Jan 18 05:36:00
38 --- Jan 18 05:38:31 Jan 18 05:39:09
38 --- Jan 18 05:43:08 Jan 18 05:43:46
38 --- Jan 18 05:45:34 Jan 18 05:46:12
39 --- Jan 18 03:44:03 Jan 18 03:44:42
39 --- Jan 18 03:46:13 Jan 18 03:46:52
39 --- Jan 18 03:48:01 Jan 18 03:48:40
39 --- Jan 18 03:51:09 Jan 18 03:51:48
39 --- Jan 18 03:58:15 Jan 18 03:58:54
39 --- Jan 18 04:15:24 Jan 18 04:16:03
39 --- Jan 18 04:35:44 Jan 18 04:36:23
39 --- Jan 18 04:53:18 Jan 18 04:53:57
39 --- Jan 18 05:20:10 Jan 18 05:20:49
40 --- Jan 18 03:30:27 Jan 18 03:31:07
40 --- Jan 18 03:37:00 Jan 18 03:37:40
40 --- Jan 18 03:49:41 Jan 18 03:50:21
40 --- Jan 18 03:53:58 Jan 18 03:54:38
40 --- Jan 18 04:42:53 Jan 18 04:43:33
40 --- Jan 18 04:43:34 Jan 18 04:44:14
40 --- Jan 18 05:44:39 Jan 18 05:45:19
41 --- Jan 18 03:38:10 Jan 18 03:38:51
41 --- Jan 18 03:52:31 Jan 18 03:53:12
41 --- Jan 18 03:58:55 Jan 18 03:59:36
41 --- Jan 18 05:32:07 Jan 18 05:32:48
41 --- Jan 18 05:33:12 Jan 18 05:33:53
41 --- Jan 18 05:34:17 Jan 18 05:34:58
41 --- Jan 18 05:40:37 Jan 18 05:41:18
42 --- Jan 18 05:21:29 Jan 18 05:22:11
42 --- Jan 18 05:22:13 Jan 18 05:22:55
42 --- Jan 18 05:24:23 Jan 18 05:25:05
42 --- Jan 18 05:25:47 Jan 18 05:26:29
42 --- Jan 18 05:29:20 Jan 18 05:30:02
42 --- Jan 18 05:42:25 Jan 18 05:43:07
43 --- Jan 18 03:29:13 Jan 18 03:29:56
43 --- Jan 18 05:26:52 Jan 18 05:27:35
43 --- Jan 18 05:39:33 Jan 18 05:40:16
44 --- Jan 18 05:31:22 Jan 18 05:32:06
44 --- Jan 18 05:36:16 Jan 18 05:37:00
44 --- Jan 18 05:37:01 Jan 18 05:37:45
44 --- Jan 18 05:37:46 Jan 18 05:38:30
45 --- Jan 18 04:44:48 Jan 18 04:45:33
45 --- Jan 18 05:41:39 Jan 18 05:42:24
46 --- Jan 18 03:28:26 Jan 18 03:29:12
47 --- Jan 18 05:22:56 Jan 18 05:23:43

One way to reduce the probability of a test error due to this longer startup would be adding a wait time right after starting Kytos, so that we can wait until Kytos be really ready.