| 101 | | 2016-06-10 04:51:13 DEBUG nodeHandler::AppContext: Starting application 'controller#1' |
| 102 | | 2016-06-10 04:51:13 DEBUG nodeHandler::set::Controllers: Send ('Controllers') - '<EXECUTE><TARGET>Controllers</TARGET><APPID>controller#1< |
| 103 | | /APPID><PATH>/root/wishful/examples/simple/wishful_simple_controller</PATH><ENV></ENV><CMDLINEARGS>--config /root/wishful/examples/simple/ |
| 104 | | controller_config.yaml</CMDLINEARGS></EXECUTE>' |
| 105 | | 2016-06-10 04:51:13 DEBUG nodeHandler::set::Agents: Start all applications |
| 106 | | 2016-06-10 04:51:13 DEBUG nodeHandler::AppContext: Starting application 'agent#1' |
| 107 | | 2016-06-10 04:51:13 DEBUG nodeHandler::set::Agents: Send ('Agents') - '<EXECUTE><TARGET>Agents</TARGET><APPID>agent#1</APPID><PATH>/root/w |
| 108 | | ishful/examples/simple/wishful_simple_agent</PATH><ENV></ENV><CMDLINEARGS>--config /root/wishful/examples/simple/agent_config.yaml</CMDLIN |
| 109 | | EARGS></EXECUTE>' |
| 110 | | 2016-06-10 04:51:13 DEBUG nodeHandler::AgentCommands: APP_EVENT STARTED from: 'controller#1' (node2-1.sb4.orbit-lab.org) - msg: '' |
| 111 | | 2016-06-10 04:51:13 INFO nodeHandler::exp: Both controller and agent are started... |
| 112 | | 2016-06-10 04:51:13 INFO nodeHandler::exp: Request from Experiment Script: Wait for 50s.... |
| 113 | | 2016-06-10 04:51:13 DEBUG nodeHandler::AgentCommands: APP_EVENT STARTED from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '' |
| 114 | | 2016-06-10 04:51:14 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 115 | | 1:14,022 - SimpleModule2.myFunc_1() - INFO - This function is executed on agent start' |
| 116 | | 2016-06-10 04:51:15 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 117 | | 1:15,711 - pyre_discovery_module.main.discovery_task() - INFO - Discovered Controller DL-tcp://10.14.2.1:8990, UL-tcp://10.14.2.1:8989' |
| 118 | | 2016-06-10 04:51:17 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 119 | | 1:17,724 - pyre_discovery_module.main.discovery_task() - INFO - Discovered Controller DL-tcp://10.14.2.1:8990, UL-tcp://10.14.2.1:8989' |
| 120 | | 2016-06-10 04:51:18 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 121 | | 1:18,052 - SimpleModule2.myFunc_3() - INFO - This function is executed on connection to global controller' |
| 122 | | 2016-06-10 04:51:23 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 123 | | 1:23,712 - SimpleModule2.myFunc_5() - INFO - This function is executed before first UPI call to module' |
| 124 | | 2016-06-10 04:51:23 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 125 | | 1:23,719 - SimpleModule2.send_to_module() - WARNING - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; |
| 126 | | error msg: wrong' |
| 127 | | 2016-06-10 04:51:26 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 128 | | 1:26,471 - SimpleModule2.before_set_channel() - INFO - This function is executed before set_channel' |
| 129 | | 2016-06-10 04:51:26 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 130 | | 1:26,471 - SimpleModule2.set_channel() - INFO - Simple Module sets channel: 4 on interface: wlan1' |
| 131 | | 2016-06-10 04:51:26 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 132 | | 1:26,471 - SimpleModule2.after_set_channel() - INFO - This function is executed after set_channel' |
| 133 | | 2016-06-10 04:51:33 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 134 | | 1:33,735 - SimpleModule2.send_to_module() - WARNING - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; |
| 135 | | error msg: wrong' |
| 136 | | 2016-06-10 04:51:36 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:5 |
| 137 | | 1:36,487 - SimpleModule2.before_set_channel() - INFO - This function is executed before set_channel' |
| 138 | | 2016-06-10 04:51:36 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:36,487 - SimpleMod |
| 139 | | ule2.set_channel() - INFO - Simple Module sets channel: 4 on interface: wlan1' |
| 140 | | 2016-06-10 04:51:36 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:36,487 - SimpleMod |
| 141 | | ule2.after_set_channel() - INFO - This function is executed after set_channel' |
| 142 | | 2016-06-10 04:51:43 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:43,743 - SimpleMod |
| 143 | | ule2.send_to_module() - WARNING - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| 144 | | 2016-06-10 04:51:46 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:46,495 - SimpleMod |
| 145 | | ule2.before_set_channel() - INFO - This function is executed before set_channel' |
| 146 | | 2016-06-10 04:51:46 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:46,496 - SimpleMod |
| 147 | | ule2.set_channel() - INFO - Simple Module sets channel: 4 on interface: wlan1' |
| 148 | | 2016-06-10 04:51:46 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:46,496 - SimpleMod |
| 149 | | ule2.after_set_channel() - INFO - This function is executed after set_channel' |
| 150 | | 2016-06-10 04:51:53 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:53,756 - SimpleMod |
| 151 | | ule2.send_to_module() - WARNING - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| 152 | | 2016-06-10 04:51:56 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:56,508 - SimpleMod |
| 153 | | ule2.before_set_channel() - INFO - This function is executed before set_channel' |
| 154 | | 2016-06-10 04:51:56 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:56,508 - SimpleMod |
| 155 | | ule2.set_channel() - INFO - Simple Module sets channel: 4 on interface: wlan1' |
| 156 | | 2016-06-10 04:51:56 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 04:51:56,508 - SimpleMod |
| 157 | | ule2.after_set_channel() - INFO - This function is executed after set_channel' |
| 158 | | |
| | 132 | 2016-06-10 07:29:54 DEBUG nodeHandler::set::Controllers: Start all applications |
| | 133 | 2016-06-10 07:29:54 DEBUG nodeHandler::AppContext: Starting application 'controller#1' |
| | 134 | 2016-06-10 07:29:54 DEBUG nodeHandler::set::Controllers: Send ('Controllers') - '<EXECUTE><TARGET>Controllers</TARGET><APPID>controller#1</APPID><PATH>/root/wishful/examples/simple/wishful_ |
| | 135 | simple_controller</PATH><ENV></ENV><CMDLINEARGS>--config /root/wishful/examples/simple/controller_config.yaml</CMDLINEARGS></EXECUTE>' |
| | 136 | 2016-06-10 07:29:54 DEBUG nodeHandler::set::Agents: Start all applications |
| | 137 | 2016-06-10 07:29:54 DEBUG nodeHandler::AppContext: Starting application 'agent#1' |
| | 138 | 2016-06-10 07:29:54 DEBUG nodeHandler::set::Agents: Send ('Agents') - '<EXECUTE><TARGET>Agents</TARGET><APPID>agent#1</APPID><PATH>/root/wishful/examples/simple/wishful_simple_agent</PATH>< |
| | 139 | ENV></ENV><CMDLINEARGS>--config /root/wishful/examples/simple/agent_config.yaml</CMDLINEARGS></EXECUTE>' |
| | 140 | 2016-06-10 07:29:54 DEBUG nodeHandler::AgentCommands: APP_EVENT STARTED from: 'controller#1' (node2-1.sb4.orbit-lab.org) - msg: '' |
| | 141 | 2016-06-10 07:29:54 INFO nodeHandler::exp: Both controller and agent started... |
| | 142 | 2016-06-10 07:29:54 INFO nodeHandler::exp: Request from Experiment Script: Wait for 60s.... |
| | 143 | 2016-06-10 07:29:54 DEBUG nodeHandler::AgentCommands: APP_EVENT STARTED from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '' |
| | 144 | 2016-06-10 07:29:55 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:29:55,152 - SimpleModule2.myFunc_1() - INFO - This f |
| | 145 | unction is executed on agent start' |
| | 146 | 2016-06-10 07:29:57 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:29:57,030 - pyre_discovery_module.main.discovery_tas |
| | 147 | k() - INFO - Discovered Controller DL-tcp://10.14.2.1:8990, UL-tcp://10.14.2.1:8989' |
| | 148 | 2016-06-10 07:29:59 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:29:59,038 - pyre_discovery_module.main.discovery_tas |
| | 149 | k() - INFO - Discovered Controller DL-tcp://10.14.2.1:8990, UL-tcp://10.14.2.1:8989' |
| | 150 | 2016-06-10 07:29:59 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:29:59,186 - SimpleModule2.myFunc_3() - INFO - This f |
| | 151 | unction is executed on connection to global controller' |
| | 152 | 2016-06-10 07:30:05 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:05,027 - SimpleModule2.myFunc_5() - INFO - This f |
| | 153 | unction is executed before first UPI call to module' |
| | 154 | 2016-06-10 07:30:05 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:05,032 - SimpleModule2.send_to_module() - WARNING |
| | 155 | - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| | 156 | 2016-06-10 07:30:07 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:07,850 - SimpleModule2.before_set_channel() - INF |
| | 157 | O - This function is executed before set_channel' |
| | 158 | 2016-06-10 07:30:07 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:07,851 - SimpleModule2.set_channel() - INFO - Sim |
| | 159 | ple Module sets channel: 4 on interface: wlan1' |
| | 160 | 2016-06-10 07:30:07 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:07,851 - SimpleModule2.after_set_channel() - INFO |
| | 161 | - This function is executed after set_channel' |
| | 162 | 2016-06-10 07:30:15 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:15,045 - SimpleModule2.send_to_module() - WARNING |
| | 163 | - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| | 164 | 2016-06-10 07:30:17 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:17,867 - SimpleModule2.before_set_channel() - INF |
| | 165 | O - This function is executed before set_channel' |
| | 166 | 2016-06-10 07:30:17 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:17,867 - SimpleModule2.set_channel() - INFO - Sim |
| | 167 | ple Module sets channel: 4 on interface: wlan1' |
| | 168 | 2016-06-10 07:30:17 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:17,867 - SimpleModule2.after_set_channel() - INFO |
| | 169 | - This function is executed after set_channel' |
| | 170 | 2016-06-10 07:30:25 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:25,058 - SimpleModule2.send_to_module() - WARNING |
| | 171 | - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| | 172 | 2016-06-10 07:30:27 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:27,879 - SimpleModule2.before_set_channel() - INF |
| | 173 | O - This function is executed before set_channel' |
| | 174 | 2016-06-10 07:30:27 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:27,879 - SimpleModule2.set_channel() - INFO - Sim |
| | 175 | ple Module sets channel: 4 on interface: wlan1' |
| | 176 | 2016-06-10 07:30:27 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:27,879 - SimpleModule2.after_set_channel() - INFO |
| | 177 | - This function is executed after set_channel' |
| | 178 | 2016-06-10 07:30:35 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:35,071 - SimpleModule2.send_to_module() - WARNING |
| | 179 | - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| | 180 | 2016-06-10 07:30:37 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:37,892 - SimpleModule2.before_set_channel() - INF |
| | 181 | O - This function is executed before set_channel' |
| | 182 | 2016-06-10 07:30:37 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:37,892 - SimpleModule2.set_channel() - INFO - Sim |
| | 183 | ple Module sets channel: 4 on interface: wlan1' |
| | 184 | 2016-06-10 07:30:37 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:37,892 - SimpleModule2.after_set_channel() - INFO |
| | 185 | - This function is executed after set_channel' |
| | 186 | 2016-06-10 07:30:45 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:45,083 - SimpleModule2.send_to_module() - WARNING |
| | 187 | - Exception: function radio.clean_per_flow_tx_power_table was not correctly executed; error msg: wrong' |
| | 188 | 2016-06-10 07:30:47 DEBUG nodeHandler::AgentCommands: APP_EVENT STDERR from: 'agent#1' (node1-1.sb4.orbit-lab.org) - msg: '2016-06-10 07:30:47,904 - SimpleModule2.before_set_channel() - INF |
| | 189 | O - This function is executed before set_channel' |