`The command "pyb install -x run_unit_tests" exited with 0.
$ pyb test --verbose
PyBuilder version 0.11.8
Build started at 2016-06-08 23:10:33
[INFO] Building hydra version 0.1.0
[INFO] Executing build in /home/travis/build/lake-lerna/hydra
[INFO] Going to execute task test
[INFO] Running unit tests
[INFO] Executing unit tests from Python modules in /home/travis/build/lake-lerna/hydra/src/unittest/python
INFO 2016-06-08 23:10:34,340 runtest_local_tests.py:setUp:25 LocalTest initialized
INFO 2016-06-08 23:10:34,341 runtest_local_tests.py:test_ip_block:28 test ip block launched
INFO 2016-06-08 23:10:34,345 runtest_local_tests.py:test_ip_block:94 Waiting for Atleast 5 packets to be received
INFO 2016-06-08 23:10:37,412 runtest_local_tests.py:test_ip_block:103 Atleast 5 packets received, proceeding with putting in iptable rule
INFO 2016-06-08 23:10:37,413 runtestbase.py:block_ip_port_on_node:570 Attempting to block all communication from ip:port [127.0.0.1:5005]
INFO 2016-06-08 23:10:37,413 common.py:execute_local_cmd:41 Executing local command [sudo /sbin/iptables -A INPUT -p tcp --destination-port 5005 -s 127.0.0.1 -j DROP]
INFO 2016-06-08 23:10:37,432 common.py:execute_local_cmd:45 Result:
INFO 2016-06-08 23:10:37,432 runtest_local_tests.py:test_ip_block:106 Waiting for at least 10 dropped packets
INFO 2016-06-08 23:10:40,834 runtest_local_tests.py:test_ip_block:113 Atleast 10 packets dropped successfully, deleting iptable rule
INFO 2016-06-08 23:10:40,834 runtestbase.py:unblock_ip_port_on_node:590 Attempting to UNblock all communication from ip:port [127.0.0.1:5005]
INFO 2016-06-08 23:10:40,834 common.py:execute_local_cmd:41 Executing local command [sudo /sbin/iptables -D INPUT -p tcp --destination-port 5005 -s 127.0.0.1 -j DROP]
INFO 2016-06-08 23:10:40,851 common.py:execute_local_cmd:45 Result:
INFO 2016-06-08 23:10:43,304 runtest_local_tests.py:test_ip_block:121 Successfully deleted iptable rule
INFO 2016-06-08 23:10:43,808 rmq_local_tests.py:setUp:26 RMQLocalTest initated
INFO 2016-06-08 23:10:43,809 rmq_local_tests.py:test1:29 test1 launched
INFO 2016-06-08 23:10:43,809 rmq_local_tests.py:test1:31 CWD = '/home/travis/build/lake-lerna/hydra'
INFO 2016-06-08 23:10:43,810 runtestbase.py:init_appserver_dir:182 Populating the app files into directory:/home/travis/build/lake-lerna/hydra/live
INFO 2016-06-08 23:10:44,093 runtestbase.py:init_mesos:163 Creating Mesos Client
INFO 2016-06-08 23:10:44,093 runtestbase.py:init_mesos:165 Initating MockMesosIF
INFO 2016-06-08 23:10:44,094 mock_backend.py:update_slaves:261 {'localhost': '127.0.0.1'}
INFO 2016-06-08 23:10:44,094 mock_backend.py:init:253 MockMesosIF init
INFO 2016-06-08 23:10:44,094 runtestbase.py:init_marathon:172 Creating Marathon Client
INFO 2016-06-08 23:10:44,094 runtestbase.py:init_marathon:174 Initating MockMarathonIF
INFO 2016-06-08 23:10:44,094 mock_backend.py:init:62 MockMarathonIF init
INFO 2016-06-08 23:10:44,095 runtestbase.py:start_init:191 Delete any pre-existing apps
INFO 2016-06-08 23:10:44,096 runtest.py:delete_all_launched_apps:237 Deleting all launched apps
INFO 2016-06-08 23:10:44,096 runtest.py:delete_all_launched_apps:238 Deleting PUB
INFO 2016-06-08 23:10:44,096 mock_backend.py:get_app:96 No app named [/rmq-pub] exists
INFO 2016-06-08 23:10:44,096 mock_backend.py:get_app:96 No app named [/rmq-pub] exists
INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-pub] exists
INFO 2016-06-08 23:10:44,097 runtest.py:delete_all_launched_apps:240 Deleting SUBs
INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists
INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists
INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists
INFO 2016-06-08 23:10:44,098 runtest.py:launch_rmq_pub:192 Launching the RabbitMQ pub app
INFO 2016-06-08 23:10:44,098 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live'
INFO 2016-06-08 23:10:44,099 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_pub.run', '10', '50', '1000']
INFO 2016-06-08 23:10:44,116 runtest.py:launch_rmq_pub:211 [rmq_pub] RMQ pub server running at [127.0.0.1]
INFO 2016-06-08 23:10:44,116 runtest.py:launch_rmq_pub:212 [rmq_pub] RMQ REP server running at [127.0.0.1:17609]
INFO 2016-06-08 23:10:44,117 runtest.py:launch_rmq_sub:217 Launching the sub app
INFO 2016-06-08 23:10:44,118 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live'
INFO 2016-06-08 23:10:44,119 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_sub.run10', '127.0.0.1']
INFO 2016-06-08 23:10:44,142 runtestbase.py:scale_and_verify_app:320 Scaling /rmq-sub app to [2]
INFO 2016-06-08 23:10:44,143 mock_backend.py:scale_app:234 Mock scale app
INFO 2016-06-08 23:10:44,143 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live'
INFO 2016-06-08 23:10:44,144 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_sub.run10', '127.0.0.1']
INFO 2016-06-08 23:10:44,145 childmgr.py:launch_children:44 job [/rmq-sub] already running
INFO 2016-06-08 23:10:44,194 runtest.py:rerun_test:58 Updating test metrics: test_duration=10, msg_batch=50, msg_rate=1000
INFO 2016-06-08 23:10:46,667 runtest.py:rerun_test:64 PUB server updated
INFO 2016-06-08 23:10:46,696 runtestbase.py:create_app_group:277 Grouping process port info
INFO 2016-06-08 23:10:46,696 runtestbase.py:create_app_group:277 Grouping process port info
INFO 2016-06-08 23:10:46,698 runtestbase.py:create_app_group:277 Grouping process port info
INFO 2016-06-08 23:10:46,699 runtest.py:rerun_test:71 Groups created
INFO 2016-06-08 23:10:46,699 runtestbase.py:ping_all_app_inst:370 Pinging instances of app[/rmq-sub] to make sure they are started....
ERROR 2016-06-08 23:10:56,716 h_analyser.py:do_resp_only:75 Timed out waiting for server at 127.0.0.1:10154
INFO 2016-06-08 23:10:56,716 runtestbase.py:ping_all_app_inst:381 Ping failed to [25986_PORT10154] 127.0.0.1:10154. removing from client list
INFO 2016-06-08 23:10:59,602 runtestbase.py:ping_all_app_inst:387 Done pinging all the clients. Got pong response from 19 out of 20
INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:393 Removing client [25986_PORT10154]
INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group]
INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:398 ['25987_PORT17734', '25987_PORT19238', '25987_PORT17734', '25986_PORT10154', '25986_PORT12981', '25987_PORT17312', '25986_PORT10154', '25986_PORT10154', '25986_PORT14019', '25987_PORT19238']
INFO 2016-06-08 23:10:59,604 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group2]
INFO 2016-06-08 23:10:59,604 runtestbase.py:ping_all_app_inst:398 ['25986_PORT16091', '25986_PORT16091', '25987_PORT12833', '25986_PORT16091', '25987_PORT10056']
INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group3]
INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:398 ['25987_PORT19195', '25987_PORT19195', '25986_PORT15233', '25986_PORT16808', '25987_PORT14924']
INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:402 {'test-group': ['25986_PORT10154'], 'test-group2': [], 'test-group3': []}
INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:405 Removing client [25986_PORT10154] from group [test-group]
[INFO] Executed 13 unit tests
[ERROR] Test has error: rmq_local_tests.RMQLocalTest.test1
Traceback (most recent call last):
File "/home/travis/build/lake-lerna/hydra/src/unittest/python/rmq_local_tests.py", line 46, in test1
res = r.run_test()
File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/rmqtest/runtest.py", line 108, in run_test
res = self.rerun_test(self.options)
File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/rmqtest/runtest.py", line 74, in rerun_test
g1._execute("do_ping")
File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/lib/runtestbase.py", line 76, in _execute
info = self.hydra.apps[self.app_name]['ip_port_map'][task_id]
KeyError: '25986_PORT10154'
Stdout:
Started a http server to serve content form ./live folder at port 9800
Stderr:
Traceback (most recent call last):
File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 872, in emit
msg = self.format(record)
File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 745, in format
return fmt.format(record)
File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 484, in format
record.message = record.getMessage()
File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 348, in getMessage
msg = msg % self.args
TypeError: not enough arguments for format string
Logged from file runtestbase.py, line 400`
Travis CI Build Failing:
`The command "pyb install -x run_unit_tests" exited with 0. $ pyb test --verbose PyBuilder version 0.11.8
Build started at 2016-06-08 23:10:33
[INFO] Building hydra version 0.1.0 [INFO] Executing build in /home/travis/build/lake-lerna/hydra [INFO] Going to execute task test [INFO] Running unit tests [INFO] Executing unit tests from Python modules in /home/travis/build/lake-lerna/hydra/src/unittest/python INFO 2016-06-08 23:10:34,340 runtest_local_tests.py:setUp:25 LocalTest initialized INFO 2016-06-08 23:10:34,341 runtest_local_tests.py:test_ip_block:28 test ip block launched INFO 2016-06-08 23:10:34,345 runtest_local_tests.py:test_ip_block:94 Waiting for Atleast 5 packets to be received INFO 2016-06-08 23:10:37,412 runtest_local_tests.py:test_ip_block:103 Atleast 5 packets received, proceeding with putting in iptable rule INFO 2016-06-08 23:10:37,413 runtestbase.py:block_ip_port_on_node:570 Attempting to block all communication from ip:port [127.0.0.1:5005] INFO 2016-06-08 23:10:37,413 common.py:execute_local_cmd:41 Executing local command [sudo /sbin/iptables -A INPUT -p tcp --destination-port 5005 -s 127.0.0.1 -j DROP] INFO 2016-06-08 23:10:37,432 common.py:execute_local_cmd:45 Result: INFO 2016-06-08 23:10:37,432 runtest_local_tests.py:test_ip_block:106 Waiting for at least 10 dropped packets INFO 2016-06-08 23:10:40,834 runtest_local_tests.py:test_ip_block:113 Atleast 10 packets dropped successfully, deleting iptable rule INFO 2016-06-08 23:10:40,834 runtestbase.py:unblock_ip_port_on_node:590 Attempting to UNblock all communication from ip:port [127.0.0.1:5005] INFO 2016-06-08 23:10:40,834 common.py:execute_local_cmd:41 Executing local command [sudo /sbin/iptables -D INPUT -p tcp --destination-port 5005 -s 127.0.0.1 -j DROP] INFO 2016-06-08 23:10:40,851 common.py:execute_local_cmd:45 Result: INFO 2016-06-08 23:10:43,304 runtest_local_tests.py:test_ip_block:121 Successfully deleted iptable rule INFO 2016-06-08 23:10:43,808 rmq_local_tests.py:setUp:26 RMQLocalTest initated INFO 2016-06-08 23:10:43,809 rmq_local_tests.py:test1:29 test1 launched INFO 2016-06-08 23:10:43,809 rmq_local_tests.py:test1:31 CWD = '/home/travis/build/lake-lerna/hydra' INFO 2016-06-08 23:10:43,810 runtestbase.py:init_appserver_dir:182 Populating the app files into directory:/home/travis/build/lake-lerna/hydra/live INFO 2016-06-08 23:10:44,093 runtestbase.py:init_mesos:163 Creating Mesos Client INFO 2016-06-08 23:10:44,093 runtestbase.py:init_mesos:165 Initating MockMesosIF INFO 2016-06-08 23:10:44,094 mock_backend.py:update_slaves:261 {'localhost': '127.0.0.1'} INFO 2016-06-08 23:10:44,094 mock_backend.py:init:253 MockMesosIF init INFO 2016-06-08 23:10:44,094 runtestbase.py:init_marathon:172 Creating Marathon Client INFO 2016-06-08 23:10:44,094 runtestbase.py:init_marathon:174 Initating MockMarathonIF INFO 2016-06-08 23:10:44,094 mock_backend.py:init:62 MockMarathonIF init INFO 2016-06-08 23:10:44,095 runtestbase.py:start_init:191 Delete any pre-existing apps INFO 2016-06-08 23:10:44,096 runtest.py:delete_all_launched_apps:237 Deleting all launched apps INFO 2016-06-08 23:10:44,096 runtest.py:delete_all_launched_apps:238 Deleting PUB INFO 2016-06-08 23:10:44,096 mock_backend.py:get_app:96 No app named [/rmq-pub] exists INFO 2016-06-08 23:10:44,096 mock_backend.py:get_app:96 No app named [/rmq-pub] exists INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-pub] exists INFO 2016-06-08 23:10:44,097 runtest.py:delete_all_launched_apps:240 Deleting SUBs INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists INFO 2016-06-08 23:10:44,097 mock_backend.py:get_app:96 No app named [/rmq-sub] exists INFO 2016-06-08 23:10:44,098 runtest.py:launch_rmq_pub:192 Launching the RabbitMQ pub app INFO 2016-06-08 23:10:44,098 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live' INFO 2016-06-08 23:10:44,099 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_pub.run', '10', '50', '1000'] INFO 2016-06-08 23:10:44,116 runtest.py:launch_rmq_pub:211 [rmq_pub] RMQ pub server running at [127.0.0.1] INFO 2016-06-08 23:10:44,116 runtest.py:launch_rmq_pub:212 [rmq_pub] RMQ REP server running at [127.0.0.1:17609] INFO 2016-06-08 23:10:44,117 runtest.py:launch_rmq_sub:217 Launching the sub app INFO 2016-06-08 23:10:44,118 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live' INFO 2016-06-08 23:10:44,119 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_sub.run10', '127.0.0.1'] INFO 2016-06-08 23:10:44,142 runtestbase.py:scale_and_verify_app:320 Scaling /rmq-sub app to [2] INFO 2016-06-08 23:10:44,143 mock_backend.py:scale_app:234 Mock scale app INFO 2016-06-08 23:10:44,143 mock_backend.py:create_app:165 CWD = '/home/travis/build/lake-lerna/hydra/live' INFO 2016-06-08 23:10:44,144 mock_backend.py:create_app:166 CMD = ['hydra', 'hydra.rmqtest.rmq_sub.run10', '127.0.0.1'] INFO 2016-06-08 23:10:44,145 childmgr.py:launch_children:44 job [/rmq-sub] already running INFO 2016-06-08 23:10:44,194 runtest.py:rerun_test:58 Updating test metrics: test_duration=10, msg_batch=50, msg_rate=1000 INFO 2016-06-08 23:10:46,667 runtest.py:rerun_test:64 PUB server updated INFO 2016-06-08 23:10:46,696 runtestbase.py:create_app_group:277 Grouping process port info INFO 2016-06-08 23:10:46,696 runtestbase.py:create_app_group:277 Grouping process port info INFO 2016-06-08 23:10:46,698 runtestbase.py:create_app_group:277 Grouping process port info INFO 2016-06-08 23:10:46,699 runtest.py:rerun_test:71 Groups created INFO 2016-06-08 23:10:46,699 runtestbase.py:ping_all_app_inst:370 Pinging instances of app[/rmq-sub] to make sure they are started.... ERROR 2016-06-08 23:10:56,716 h_analyser.py:do_resp_only:75 Timed out waiting for server at 127.0.0.1:10154 INFO 2016-06-08 23:10:56,716 runtestbase.py:ping_all_app_inst:381 Ping failed to [25986_PORT10154] 127.0.0.1:10154. removing from client list INFO 2016-06-08 23:10:59,602 runtestbase.py:ping_all_app_inst:387 Done pinging all the clients. Got pong response from 19 out of 20 INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:393 Removing client [25986_PORT10154] INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group] INFO 2016-06-08 23:10:59,603 runtestbase.py:ping_all_app_inst:398 ['25987_PORT17734', '25987_PORT19238', '25987_PORT17734', '25986_PORT10154', '25986_PORT12981', '25987_PORT17312', '25986_PORT10154', '25986_PORT10154', '25986_PORT14019', '25987_PORT19238'] INFO 2016-06-08 23:10:59,604 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group2] INFO 2016-06-08 23:10:59,604 runtestbase.py:ping_all_app_inst:398 ['25986_PORT16091', '25986_PORT16091', '25987_PORT12833', '25986_PORT16091', '25987_PORT10056'] INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:397 Checking if bad client[25986_PORT10154] is in group[test-group3] INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:398 ['25987_PORT19195', '25987_PORT19195', '25986_PORT15233', '25986_PORT16808', '25987_PORT14924'] INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:402 {'test-group': ['25986_PORT10154'], 'test-group2': [], 'test-group3': []} INFO 2016-06-08 23:10:59,605 runtestbase.py:ping_all_app_inst:405 Removing client [25986_PORT10154] from group [test-group] [INFO] Executed 13 unit tests [ERROR] Test has error: rmq_local_tests.RMQLocalTest.test1 Traceback (most recent call last): File "/home/travis/build/lake-lerna/hydra/src/unittest/python/rmq_local_tests.py", line 46, in test1 res = r.run_test() File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/rmqtest/runtest.py", line 108, in run_test res = self.rerun_test(self.options) File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/rmqtest/runtest.py", line 74, in rerun_test g1._execute("do_ping") File "/home/travis/build/lake-lerna/hydra/src/main/python/hydra/lib/runtestbase.py", line 76, in _execute info = self.hydra.apps[self.app_name]['ip_port_map'][task_id] KeyError: '25986_PORT10154' Stdout: Started a http server to serve content form ./live folder at port 9800 Stderr: Traceback (most recent call last): File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 872, in emit msg = self.format(record) File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 745, in format return fmt.format(record) File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 484, in format record.message = record.getMessage() File "/opt/python/pypy-2.6.1/lib-python/2.7/logging/init.py", line 348, in getMessage msg = msg % self.args TypeError: not enough arguments for format string Logged from file runtestbase.py, line 400`