Tutorial: Multi-hop Topology Grid_2007_11_20_18_58_12.log¶
Click here to return to the tutorial.
Shown below is the log file generated from the tut_topo_2.rb script:
1 2007-11-20 18:58:12 INFO nodeHandler::init: NodeHandler Version 4.2.0 (1272)
2 2007-11-20 18:58:12 INFO nodeHandler::init: Experiment ID: grid_2007_11_20_18_58_12
3 2007-11-20 18:58:12 DEBUG nodeHandler::Experiment: command line args: .
4 2007-11-20 18:58:12 INFO nodeHandler::ExecApp: Starting application 'commServer': /opt/nodehandler4-4.2.0/sbin/commServer --logfile /tmp/commServer-grid_2007_11_20_18_58_12.log -d 4 --iface eth1
5 2007-11-20 18:58:12 DEBUG nodeHandler::Communicator: commServer(STARTED): ''
6 2007-11-20 18:58:14 DEBUG nodeHandler::ExecApp: writing 'R' to app 'commServer'
7 2007-11-20 18:58:19 DEBUG nodeHandler::web: Mounting /resource to /opt/nodehandler4-4.2.0/repository/public_html
8 2007-11-20 18:58:19 INFO nodeHandler::Experiment: load system:exp:stdlib
9 2007-11-20 18:58:19 INFO nodeHandler::prop.resetDelay: resetDelay = 210:Fixnum
10 2007-11-20 18:58:19 INFO nodeHandler::prop.resetTries: resetTries = 1:Fixnum
11 2007-11-20 18:58:19 INFO nodeHandler::Experiment: load tut_topo_2
12 2007-11-20 18:58:20 INFO nodeHandler::Topology: Loading topology 'system:topo:active'.
13 2007-11-20 18:58:20 INFO nodeHandler::Topology: Loading topology 'system:topo:active:grid'.
14 2007-11-20 18:58:20 DEBUG nodeHandler::service call: http://cmc:5012/cmc/allStatus?domain=
15 2007-11-20 18:58:21 DEBUG nodeHandler::ExecApp: writing 'a 10.10.19.18 n_19_18' to app 'commServer'
16 2007-11-20 18:58:21 DEBUG nodeHandler::node::n_19_18: Created node 19@18
17 2007-11-20 18:58:21 WARN nodeHandler::system:topo:active:grid: Ignoring missing node '17@4'
18 2007-11-20 18:58:23 WARN nodeHandler::system:topo:active:grid: Ignoring missing node '18@8'
19 ...
20 2007-11-20 18:58:24 DEBUG nodeHandler::ExecApp: writing 'a 10.10.2.8 n_2_8' to app 'commServer'
21 2007-11-20 18:58:24 DEBUG nodeHandler::node::n_2_8: Created node 2@8
22 2007-11-20 18:58:24 DEBUG nodeHandler::ExecApp: writing 'a 10.10.1.7 n_1_7' to app 'commServer'
23 2007-11-20 18:58:24 DEBUG nodeHandler::node::n_1_7: Created node 1@7
24 ..
25 2007-11-20 18:58:24 DEBUG nodeHandler::system:topo:active: select(): number: 4 - name: myNode_%i% - method: random - features: 'mem512btfalsechannelallwifiatheros'
26 2007-11-20 18:58:24 DEBUG nodeHandler::system:topo:active: select(): number: 4 - name: myNode_%i% - method: random - features: ''
27 2007-11-20 18:58:24 DEBUG nodeHandler::system:topo:active: MAP = myNode_1[14,1]myNode_2[8,8]myNode_3[11,19]myNode_4[17,20]
28 2007-11-20 18:58:24 DEBUG nodeHandler::mainTopology: addLink() myNode_1 -> myNode_2 ('rate54per0.1asymmetrictrue')
29 2007-11-20 18:58:24 DEBUG nodeHandler::mainTopology: addLink() myNode_2 -> myNode_3 ('rate12per0.2asymmetrictrue')
30 2007-11-20 18:58:24 DEBUG nodeHandler::mainTopology: addLink() myNode_3 -> myNode_4 ('rate6per0.4asymmetrictrue')
31 2007-11-20 18:58:24 INFO nodeHandler::mainTopology: Associated Graph saved in: grid_2007_11_20_18_58_12-Graph
32 2007-11-20 18:58:24 DEBUG nodeHandler::node::n_14_1: Added to group 'senderGroup'
33 2007-11-20 18:58:24 DEBUG nodeHandler::ExecApp: writing 'A n_14_1 senderGroup' to app 'commServer'
34 2007-11-20 18:58:24 DEBUG nodeHandler::node::n_11_19: Added to group 'senderGroup'
35 2007-11-20 18:58:24 DEBUG nodeHandler::ExecApp: writing 'A n_11_19 senderGroup' to app 'commServer'
36 2007-11-20 18:58:24 DEBUG nodeHandler::node::n_8_8: Added to group 'senderGroup'
37 2007-11-20 18:58:24 DEBUG nodeHandler::ExecApp: writing 'A n_8_8 senderGroup' to app 'commServer'
38 2007-11-20 18:58:24 DEBUG nodeHandler::nodeSetPath: Use prototype test:proto:sender.
39 2007-11-20 18:58:24 DEBUG nodeHandler::Prototype: : Loading prototype "test:proto:sender".
40 2007-11-20 18:58:24 DEBUG nodeHandler::AppDefinition: : Loading app definition "test:app:otg".
41 2007-11-20 18:58:29 DEBUG nodeHandler::node::n_14_1: Add application otg:test:app:otg to n_14_1
42 2007-11-20 18:58:29 DEBUG nodeHandler::node::n_11_19: Add application otg:test:app:otg to n_11_19
43 2007-11-20 18:58:29 DEBUG nodeHandler::node::n_8_8: Add application otg:test:app:otg to n_8_8
44 2007-11-20 18:58:29 DEBUG nodeHandler::node::n_8_8: Added to group 'receiverGroup_2'
45 2007-11-20 18:58:29 DEBUG nodeHandler::ExecApp: writing 'A n_8_8 receiverGroup_2' to app 'commServer'
46 2007-11-20 18:58:29 DEBUG nodeHandler::nodeSetPath: Use prototype test:proto:receiver.
47 2007-11-20 18:58:29 DEBUG nodeHandler::Prototype: : Loading prototype "test:proto:receiver".
48 2007-11-20 18:58:29 DEBUG nodeHandler::AppDefinition: : Loading app definition "test:app:otr".
49 2007-11-20 18:58:34 DEBUG nodeHandler::node::n_8_8: Add application otr:test:app:otr to n_8_8
50 2007-11-20 18:58:34 DEBUG nodeHandler::every: *: fires
51 2007-11-20 18:58:34 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
52 2007-11-20 18:58:34 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
53 2007-11-20 18:58:34 DEBUG nodeHandler::node::n_11_19: Added to group 'receiverGroup_3'
54 2007-11-20 18:58:34 INFO nodeHandler::stdlib: Waiting for nodes (Up/Down/Total): 0/4/4 - (still down: n_8_8,n_14_1,n_11_19)
55 2007-11-20 18:58:34 DEBUG nodeHandler::ExecApp: writing 'A n_11_19 receiverGroup_3' to app 'commServer'
56 2007-11-20 18:58:34 DEBUG nodeHandler::nodeSetPath: Use prototype test:proto:receiver.
57 2007-11-20 18:58:39 DEBUG nodeHandler::node::n_11_19: Add application otr:test:app:otr to n_11_19
58 2007-11-20 18:58:39 DEBUG nodeHandler::node::n_17_20: Added to group 'receiverGroup_4'
59 2007-11-20 18:58:39 DEBUG nodeHandler::ExecApp: writing 'A n_17_20 receiverGroup_4' to app 'commServer'
60 2007-11-20 18:58:39 DEBUG nodeHandler::nodeSetPath: Use prototype test:proto:receiver.
61 2007-11-20 18:58:44 DEBUG nodeHandler::every: *: fires
62 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_17_20: Add application otr:test:app:otr to n_17_20
63 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
64 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath: Testing 'net' => '' : (?-mix:)
65 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
66 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
67 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath: Checking against '(?-mix:)'
68 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
69 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net: Testing 'w0' => 'net' :
70 2007-11-20 18:58:44 INFO nodeHandler::stdlib: Waiting for nodes (Up/Down/Total): 0/6/6 - (still down: n_8_8,n_14_1,n_11_19)
71 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'mode=' => 'net/w0' : (?-mix:net\/[ew][01])
72 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
73 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
74 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
75 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
76 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
77 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/mode#ad-hoc
78 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
79 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Deferred message: CONFIGURE * net/w0/mode ad-hoc
80 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'type=' => 'net/w0' : (?-mix:net\/[ew][01])
81 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
82 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
83 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
84 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
85 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
86 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/type#g
87 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
88 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Deferred message: CONFIGURE * net/w0/type g
89 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'channel=' => 'net/w0' : (?-mix:net\/[ew][01])
90 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
91 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
92 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
93 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
94 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
95 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/channel#6
96 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
97 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Deferred message: CONFIGURE * net/w0/channel 6
98 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'essid=' => 'net/w0' : (?-mix:net\/[ew][01])
99 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
100 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
101 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
102 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
103 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
104 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/essid#exp1234
105 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
106 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Deferred message: CONFIGURE * net/w0/essid exp1234
107 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'ip=' => 'net/w0' : (?-mix:net\/[ew][01])
108 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
109 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
110 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
111 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
112 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
113 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/ip#%192.168.%x.%y
114 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
115 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Deferred message: CONFIGURE * net/w0/ip %192.168.%x.%y
116 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath: Testing 'net' => '' : (?-mix:)
117 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath: Checking against '(?-mix:)'
118 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net: Testing 'w0' => 'net' :
119 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Testing 'enforce_link=' => 'net/w0' : (?-mix:net\/[ew][01])
120 2007-11-20 18:58:44 DEBUG nodeHandler::nodeSetPath::net/w0: Checking against '(?-mix:net\/[ew][01])'
121 2007-11-20 18:58:44 DEBUG nodeHandler::service call: http://cmc:5022/inventory/getMacAddress?x=11&y=19&ifname=ath0&domain=grid
122 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Node: [11,19] - MAC: 00:60:B3:B0:C6:79
123 2007-11-20 18:58:44 DEBUG nodeHandler::service call: http://cmc:5022/inventory/getMacAddress?x=8&y=8&ifname=ath0&domain=grid
124 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Node: [8,8] - MAC: 00:60:B3:AC:2D:55
125 2007-11-20 18:58:44 DEBUG nodeHandler::service call: http://cmc:5022/inventory/getMacAddress?x=17&y=20&ifname=ath0&domain=grid
126 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Node: [17,20] - MAC: 00:60:B3:AC:2B:EA
127 2007-11-20 18:58:44 DEBUG nodeHandler::service call: http://cmc:5022/inventory/getMacAddress?x=14&y=1&ifname=ath0&domain=grid
128 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Node: [14,1] - MAC: 00:60:B3:AC:2B:FB
129 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Link [11,19] -> [17,20] - (rate6per0.4asymmetrictrue)
130 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Link [8,8] -> [11,19] - (rate12per0.2asymmetrictrue)
131 2007-11-20 18:58:44 DEBUG nodeHandler::mainTopology: Link [14,1] -> [8,8] - (rate54per0.1asymmetrictrue)
132 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_14_1: Deferred message: SET_MACTABLE n_14_1 iptable 00:60:B3:B0:C6:79
133 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_14_1: Deferred message: SET_MACTABLE n_14_1 iptable 00:60:B3:AC:2D:55
134 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_14_1: Deferred message: SET_MACTABLE n_14_1 iptable 00:60:B3:AC:2B:EA
135 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_11_19: Deferred message: SET_MACTABLE n_11_19 iptable 00:60:B3:AC:2B:EA
136 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_11_19: Deferred message: SET_MACTABLE n_11_19 iptable 00:60:B3:AC:2B:FB
137 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_8_8: Deferred message: SET_MACTABLE n_8_8 iptable 00:60:B3:B0:C6:79
138 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_8_8: Deferred message: SET_MACTABLE n_8_8 iptable 00:60:B3:AC:2B:EA
139 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_17_20: Deferred message: SET_MACTABLE n_17_20 iptable 00:60:B3:AC:2D:55
140 2007-11-20 18:58:44 DEBUG nodeHandler::node::n_17_20: Deferred message: SET_MACTABLE n_17_20 iptable 00:60:B3:AC:2B:FB
141 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
142 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Running 'eachGroup' in RootGroupNodeSet
143 2007-11-20 18:58:44 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_2
144 2007-11-20 18:58:44 DEBUG nodeHandler::CMC: up http://cmc:5012/cmc/nodeSetOn?nodes=[[8,8]]
145 2007-11-20 18:58:44 DEBUG nodeHandler::service call: http://cmc:5012/cmc/nodeSetOn?nodes=[[8,8]]
146 2007-11-20 18:58:45 DEBUG nodeHandler::set::_ALL_: Call senderGroup
147 2007-11-20 18:58:45 DEBUG nodeHandler::CMC: up http://cmc:5012/cmc/nodeSetOn?nodes=[[8,8],[11,19],[14,1]]
148 2007-11-20 18:58:45 DEBUG nodeHandler::service call: http://cmc:5012/cmc/nodeSetOn?nodes=[[8,8],[11,19],[14,1]]
149 2007-11-20 18:58:45 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_3
150 2007-11-20 18:58:45 DEBUG nodeHandler::CMC: up http://cmc:5012/cmc/nodeSetOn?nodes=[[11,19]]
151 2007-11-20 18:58:45 DEBUG nodeHandler::service call: http://cmc:5012/cmc/nodeSetOn?nodes=[[11,19]]
152 2007-11-20 18:58:45 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_4
153 2007-11-20 18:58:45 DEBUG nodeHandler::CMC: up http://cmc:5012/cmc/nodeSetOn?nodes=[[17,20]]
154 2007-11-20 18:58:45 DEBUG nodeHandler::service call: http://cmc:5012/cmc/nodeSetOn?nodes=[[17,20]]
155 2007-11-20 18:58:49 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
156 2007-11-20 18:58:54 DEBUG nodeHandler::every: *: fires
157 2007-11-20 18:58:54 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
158 2007-11-20 18:58:54 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
159 2007-11-20 18:58:54 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
160 2007-11-20 18:58:54 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
161 2007-11-20 19:00:04 INFO nodeHandler::stdlib: Waiting for nodes (Up/Down/Total): 0/6/6 - (still down: n_8_8,n_14_1,n_11_19)
162 2007-11-20 19:00:05 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
163 2007-11-20 19:00:10 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
164 2007-11-20 19:00:14 DEBUG nodeHandler::every: *: fires
165 2007-11-20 19:00:14 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
166 2007-11-20 19:00:14 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
167 2007-11-20 19:00:14 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
168 2007-11-20 19:00:14 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
169 ...
170 2007-11-20 19:00:14 INFO nodeHandler::stdlib: Waiting for nodes (Up/Down/Total): 0/6/6 - (still down: n_8_8,n_14_1,n_11_19)
171 2007-11-20 19:00:15 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
172 2007-11-20 19:00:20 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
173 2007-11-20 19:00:22 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 ENROLLED'
174 2007-11-20 19:00:22 DEBUG nodeHandler::Communicator: Process message 'n_14_1 ENROLLED'
175 2007-11-20 19:00:22 DEBUG nodeHandler::agentCmd::enrolled: n_14_1: n_14_1 senderId: n_14_1:
176 2007-11-20 19:00:22 DEBUG nodeHandler::set::senderGroup: n_11_19 is not up yet.
177 2007-11-20 19:00:22 DEBUG nodeHandler::node::n_14_1: send_deferred(Array:2):iptable#00:60:B3:B0:C6:79
178 2007-11-20 19:00:22 DEBUG nodeHandler::Communicator: Send message: S n_14_1 SET_MACTABLE iptable 00:60:B3:B0:C6:79
179 2007-11-20 19:00:22 DEBUG nodeHandler::ExecApp: writing 'S n_14_1 SET_MACTABLE iptable 00:60:B3:B0:C6:79' to app 'commServer'
180 2007-11-20 19:00:22 DEBUG nodeHandler::node::n_14_1: send_deferred(Array:2):iptable#00:60:B3:AC:2D:55
181 2007-11-20 19:00:22 DEBUG nodeHandler::Communicator: Send message: S n_14_1 SET_MACTABLE iptable 00:60:B3:AC:2D:55
182 2007-11-20 19:00:22 DEBUG nodeHandler::ExecApp: writing 'S n_14_1 SET_MACTABLE iptable 00:60:B3:AC:2D:55' to app 'commServer'
183 2007-11-20 19:00:22 DEBUG nodeHandler::node::n_14_1: send_deferred(Array:2):iptable#00:60:B3:AC:2B:EA
184 2007-11-20 19:00:22 DEBUG nodeHandler::Communicator: Send message: S n_14_1 SET_MACTABLE iptable 00:60:B3:AC:2B:EA
185 2007-11-20 19:00:22 DEBUG nodeHandler::ExecApp: writing 'S n_14_1 SET_MACTABLE iptable 00:60:B3:AC:2B:EA' to app 'commServer'
186 2007-11-20 19:00:24 DEBUG nodeHandler::every: *: fires
187 2007-11-20 19:00:24 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
188 2007-11-20 19:00:24 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
189 2007-11-20 19:00:24 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
190 2007-11-20 19:00:24 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
191 2007-11-20 19:00:24 INFO nodeHandler::stdlib: Waiting for nodes (Up/Down/Total): 1/5/6 - (still down: n_8_8,n_11_19,n_8_8)
192 2007-11-20 19:00:25 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
193 2007-11-20 19:00:27 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 ENROLLED'
194 2007-11-20 19:00:27 DEBUG nodeHandler::Communicator: Process message 'n_11_19 ENROLLED'
195 2007-11-20 19:00:27 DEBUG nodeHandler::agentCmd::enrolled: n_11_19: n_11_19 senderId: n_11_19:
196 2007-11-20 19:00:27 DEBUG nodeHandler::set::senderGroup: n_8_8 is not up yet.
197 2007-11-20 19:00:27 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
198 2007-11-20 19:00:27 DEBUG nodeHandler::node::n_11_19: send_deferred(Array:2):iptable#00:60:B3:AC:2B:EA
199 2007-11-20 19:00:27 DEBUG nodeHandler::Communicator: Send message: S n_11_19 SET_MACTABLE iptable 00:60:B3:AC:2B:EA
200 2007-11-20 19:00:27 DEBUG nodeHandler::ExecApp: writing 'S n_11_19 SET_MACTABLE iptable 00:60:B3:AC:2B:EA' to app 'commServer'
201 2007-11-20 19:00:27 DEBUG nodeHandler::node::n_11_19: send_deferred(Array:2):iptable#00:60:B3:AC:2B:FB
202 2007-11-20 19:00:27 DEBUG nodeHandler::Communicator: Send message: S n_11_19 SET_MACTABLE iptable 00:60:B3:AC:2B:FB
203 2007-11-20 19:00:27 DEBUG nodeHandler::ExecApp: writing 'S n_11_19 SET_MACTABLE iptable 00:60:B3:AC:2B:FB' to app 'commServer'
204 2007-11-20 19:00:30 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
205 2007-11-20 19:00:31 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_17_20 ENROLLED'
206 2007-11-20 19:00:31 DEBUG nodeHandler::Communicator: Process message 'n_17_20 ENROLLED'
207 2007-11-20 19:00:31 DEBUG nodeHandler::agentCmd::enrolled: n_17_20: n_17_20 senderId: n_17_20:
208 2007-11-20 19:00:31 DEBUG nodeHandler::set::_ALL_: n_8_8 is not up yet.
209 2007-11-20 19:00:31 DEBUG nodeHandler::node::n_17_20: send_deferred(Array:2):iptable#00:60:B3:AC:2D:55
210 2007-11-20 19:00:31 DEBUG nodeHandler::Communicator: Send message: S n_17_20 SET_MACTABLE iptable 00:60:B3:AC:2D:55
211 2007-11-20 19:00:31 DEBUG nodeHandler::ExecApp: writing 'S n_17_20 SET_MACTABLE iptable 00:60:B3:AC:2D:55' to app 'commServer'
212 2007-11-20 19:00:31 DEBUG nodeHandler::node::n_17_20: send_deferred(Array:2):iptable#00:60:B3:AC:2B:FB
213 2007-11-20 19:00:31 DEBUG nodeHandler::Communicator: Send message: S n_17_20 SET_MACTABLE iptable 00:60:B3:AC:2B:FB
214 2007-11-20 19:00:31 DEBUG nodeHandler::ExecApp: writing 'S n_17_20 SET_MACTABLE iptable 00:60:B3:AC:2B:FB' to app 'commServer'
215 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 ENROLLED'
216 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Process message 'n_8_8 ENROLLED'
217 2007-11-20 19:00:33 DEBUG nodeHandler::agentCmd::enrolled: n_8_8: n_8_8 senderId: n_8_8:
218 2007-11-20 19:00:33 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/mode#ad-hoc
219 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S * CONFIGURE net/w0/mode ad-hoc
220 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S * CONFIGURE net/w0/mode ad-hoc' to app 'commServer'
221 2007-11-20 19:00:33 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/type#g
222 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S * CONFIGURE net/w0/type g
223 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S * CONFIGURE net/w0/type g' to app 'commServer'
224 2007-11-20 19:00:33 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/channel#6
225 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S * CONFIGURE net/w0/channel 6
226 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S * CONFIGURE net/w0/channel 6' to app 'commServer'
227 2007-11-20 19:00:33 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/essid#exp1234
228 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S * CONFIGURE net/w0/essid exp1234
229 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S * CONFIGURE net/w0/essid exp1234' to app 'commServer'
230 2007-11-20 19:00:33 DEBUG nodeHandler::set::_ALL_: #send: args(2)'net/w0/ip#%192.168.%x.%y
231 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S * CONFIGURE net/w0/ip %192.168.%x.%y
232 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S * CONFIGURE net/w0/ip %192.168.%x.%y' to app 'commServer'
233 2007-11-20 19:00:33 DEBUG nodeHandler::node::n_8_8: send_deferred(Array:2):iptable#00:60:B3:B0:C6:79
234 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S n_8_8 SET_MACTABLE iptable 00:60:B3:B0:C6:79
235 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S n_8_8 SET_MACTABLE iptable 00:60:B3:B0:C6:79' to app 'commServer'
236 2007-11-20 19:00:33 DEBUG nodeHandler::node::n_8_8: send_deferred(Array:2):iptable#00:60:B3:AC:2B:EA
237 2007-11-20 19:00:33 DEBUG nodeHandler::Communicator: Send message: S n_8_8 SET_MACTABLE iptable 00:60:B3:AC:2B:EA
238 2007-11-20 19:00:33 DEBUG nodeHandler::ExecApp: writing 'S n_8_8 SET_MACTABLE iptable 00:60:B3:AC:2B:EA' to app 'commServer'
239 2007-11-20 19:00:34 DEBUG nodeHandler::every: *: fires
240 2007-11-20 19:00:34 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_2
241 2007-11-20 19:00:34 DEBUG nodeHandler::set::_ALL_: Running each for senderGroup
242 2007-11-20 19:00:34 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_3
243 2007-11-20 19:00:34 DEBUG nodeHandler::set::_ALL_: Running each for receiverGroup_4
244 2007-11-20 19:00:34 DEBUG nodeHandler::every: *: finishes
245 2007-11-20 19:00:35 INFO nodeHandler::whenAll: *: 'apps/app/status[@value='INSTALLED.OK']' fires
246 2007-11-20 19:00:36 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_17_20 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
247 2007-11-20 19:00:36 DEBUG nodeHandler::Communicator: Process message 'n_17_20 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
248 2007-11-20 19:00:36 DEBUG nodeHandler::agentCmd::DEV_EVENT: CELL_ID' from 'net/w0' executing on n_17_20: '65:78:70:31:32:33'
249 2007-11-20 19:00:36 INFO nodeHandler::node::n_17_20: Device 'net/w0' reported 65:78:70:31:32:33
250 2007-11-20 19:00:37 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
251 2007-11-20 19:00:37 DEBUG nodeHandler::Communicator: Process message 'n_11_19 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
252 2007-11-20 19:00:37 DEBUG nodeHandler::agentCmd::DEV_EVENT: CELL_ID' from 'net/w0' executing on n_11_19: '65:78:70:31:32:33'
253 2007-11-20 19:00:37 INFO nodeHandler::node::n_11_19: Device 'net/w0' reported 65:78:70:31:32:33
254 2007-11-20 19:00:39 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
255 2007-11-20 19:00:39 DEBUG nodeHandler::Communicator: Process message 'n_8_8 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
256 2007-11-20 19:00:39 DEBUG nodeHandler::agentCmd::DEV_EVENT: CELL_ID' from 'net/w0' executing on n_8_8: '65:78:70:31:32:33'
257 2007-11-20 19:00:39 INFO nodeHandler::node::n_8_8: Device 'net/w0' reported 65:78:70:31:32:33
258 2007-11-20 19:00:41 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
259 2007-11-20 19:00:41 DEBUG nodeHandler::Communicator: Process message 'n_14_1 DEV_EVENT CELL_ID net/w0 65:78:70:31:32:33'
260 2007-11-20 19:00:41 DEBUG nodeHandler::agentCmd::DEV_EVENT: CELL_ID' from 'net/w0' executing on n_14_1: '65:78:70:31:32:33'
261 2007-11-20 19:00:41 INFO nodeHandler::node::n_14_1: Device 'net/w0' reported 65:78:70:31:32:33
262 2007-11-20 19:00:45 DEBUG nodeHandler::nodeSetPath: Start all applications
263 2007-11-20 19:00:45 DEBUG nodeHandler::set::_ALL_: Start all applications
264 2007-11-20 19:00:45 DEBUG nodeHandler::set::_ALL_: Start all applications
265 2007-11-20 19:00:45 DEBUG nodeHandler::set::_ALL_: Running 'eachGroup' in RootGroupNodeSet
266 2007-11-20 19:00:45 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_2
267 2007-11-20 19:00:45 DEBUG nodeHandler::set::_ALL_: ..... Start applications in receiverGroup_2
268 2007-11-20 19:00:45 DEBUG nodeHandler::set::receiverGroup_2: Start all applications
269 2007-11-20 19:00:45 DEBUG nodeHandler::set::receiverGroup_2: Starting application 'otr'
270 2007-11-20 19:00:45 DEBUG nodeHandler::OmlApp::startCollectionServer post on oml:5022
271 : <?xml version='1.0'?>
272 <experiment id="grid_2007_11_20_18_58_12" domain="grid">
273 <measurement-points>
274 <measurement-point name='senderport' type='time_based' client='oml_senderGroup_otg' id='1' table='senderGroup_otg_senderport'>
275 <properties>
276 <property name='trigger'>
277 <value>1</value>
278 </property>
279 </properties>
280 <metric name='pkt_seqno' type='long' id='pkt_seqno' refid='pkt_seqno'/>
281 <metric name='pkt_size' type='long' id='pkt_size' refid='pkt_size'>
282 <filter idref='sample_sum' returnType='long' refid='sample_sum'/>
283 </metric>
284 <metric name='gen_timestamp' type='float' id='gen_timestamp' refid='gen_timestamp'/>
285 <metric name='tx_timestamp' type='long' id='tx_timestamp' refid='tx_timestamp'/>
286 </measurement-point>
287 <measurement-point name='receiverport' type='time_based' client='oml_receiverGroup_2_otr' id='2' table='receiverGroup_2_otr_receiverport'>
288 <properties>
289 <property name='trigger'>
290 <value>1</value>
291 </property>
292 </properties>
293 <metric name='pkt_seqno' type='long' id='pkt_seqno' refid='pkt_seqno'/>
294 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
295 <metric name='rcvd_pkt_size' type='long' id='rcvd_pkt_size' refid='rcvd_pkt_size'>
296 <filter idref='sample_sum' returnType='long' refid='sample_sum'/>
297 </metric>
298 <metric name='rx_timestamp' type='long' id='rx_timestamp' refid='rx_timestamp'/>
299 <metric name='rssi' type='int' id='rssi' refid='rssi'/>
300 <metric name='xmitrate' type='int' id='xmitrate' refid='xmitrate'/>
301 <metric name='hw_timestamp' type='int' id='hw_timestamp' refid='hw_timestamp'/>
302 </measurement-point>
303 <measurement-point name='flow' type='sample_based' client='oml_receiverGroup_2_otr' id='3' table='receiverGroup_2_otr_flow'>
304 <properties>
305 <property name='trigger'>
306 <value>1</value>
307 </property>
308 </properties>
309 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
310 <metric name='sender_port' type='int' id='sender_port' refid='sender_port'/>
311 </measurement-point>
312 <measurement-point name='receiverport' type='time_based' client='oml_receiverGroup_3_otr' id='4' table='receiverGroup_3_otr_receiverport'>
313 <properties>
314 <property name='trigger'>
315 <value>1</value>
316 </property>
317 </properties>
318 <metric name='pkt_seqno' type='long' id='pkt_seqno' refid='pkt_seqno'/>
319 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
320 <metric name='rcvd_pkt_size' type='long' id='rcvd_pkt_size' refid='rcvd_pkt_size'>
321 <filter idref='sample_sum' returnType='long' refid='sample_sum'/>
322 </metric>
323 <metric name='rx_timestamp' type='long' id='rx_timestamp' refid='rx_timestamp'/>
324 <metric name='rssi' type='int' id='rssi' refid='rssi'/>
325 <metric name='xmitrate' type='int' id='xmitrate' refid='xmitrate'/>
326 <metric name='hw_timestamp' type='int' id='hw_timestamp' refid='hw_timestamp'/>
327 </measurement-point>
328 <measurement-point name='flow' type='sample_based' client='oml_receiverGroup_3_otr' id='5' table='receiverGroup_3_otr_flow'>
329 <properties>
330 <property name='trigger'>
331 <value>1</value>
332 </property>
333 </properties>
334 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
335 <metric name='sender_port' type='int' id='sender_port' refid='sender_port'/>
336 </measurement-point>
337 <measurement-point name='receiverport' type='time_based' client='oml_receiverGroup_4_otr' id='6' table='receiverGroup_4_otr_receiverport'>
338 <properties>
339 <property name='trigger'>
340 <value>1</value>
341 </property>
342 </properties>
343 <metric name='pkt_seqno' type='long' id='pkt_seqno' refid='pkt_seqno'/>
344 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
345 <metric name='rcvd_pkt_size' type='long' id='rcvd_pkt_size' refid='rcvd_pkt_size'>
346 <filter idref='sample_sum' returnType='long' refid='sample_sum'/>
347 </metric>
348 <metric name='rx_timestamp' type='long' id='rx_timestamp' refid='rx_timestamp'/>
349 <metric name='rssi' type='int' id='rssi' refid='rssi'/>
350 <metric name='xmitrate' type='int' id='xmitrate' refid='xmitrate'/>
351 <metric name='hw_timestamp' type='int' id='hw_timestamp' refid='hw_timestamp'/>
352 </measurement-point>
353 <measurement-point name='flow' type='sample_based' client='oml_receiverGroup_4_otr' id='7' table='receiverGroup_4_otr_flow'>
354 <properties>
355 <property name='trigger'>
356 <value>1</value>
357 </property>
358 </properties>
359 <metric name='flow_no' type='int' id='flow_no' refid='flow_no'/>
360 <metric name='sender_port' type='int' id='sender_port' refid='sender_port'/>
361 </measurement-point>
362 </measurement-points>
363 </experiment>
364
365 2007-11-20 19:00:46 DEBUG nodeHandler::OmlApp::startCollectionServer response: <collection_server id='grid_2007_11_20_18_58_12'><multicast-channel port='7600' addr='224.0.0.6' iface='eth2'/></collection_server>
366 2007-11-20 19:00:46 INFO nodeHandler::OML: Started: {"port"=>"7600", "iface"=>"eth2", "addr"=>"224.0.0.6"}
367 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_2: #send: args(13)'app:otr#env#-i#%OML_NAME=node%x-%y#LD_LIBRARY_PATH=/usr/lib/#OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_2_otr#/usr/bin/otr#--hostname#localhost#--port#4000#--protocol#udp
368 2007-11-20 19:00:46 DEBUG nodeHandler::Communicator: Send message: S receiverGroup_2 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_2_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp
369 2007-11-20 19:00:46 DEBUG nodeHandler::ExecApp: writing 'S receiverGroup_2 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_2_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp' to app 'commServer'
370 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: Call senderGroup
371 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: ..... Start applications in senderGroup
372 2007-11-20 19:00:46 DEBUG nodeHandler::set::senderGroup: Start all applications
373 2007-11-20 19:00:46 DEBUG nodeHandler::set::senderGroup: Starting application 'otg'
374 2007-11-20 19:00:46 DEBUG nodeHandler::set::senderGroup: #send: args(21)'app:otg#env#-i#%OML_NAME=node%x-%y#LD_LIBRARY_PATH=/usr/lib/#OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_senderGroup_otg#/usr/bin/otg#--broadcast#on#--dsthostname#192.168.255.255#--generator#cbr#--port#3000#--protocol#udp#--rate#400#--size#512
375 2007-11-20 19:00:46 DEBUG nodeHandler::Communicator: Send message: S senderGroup exec app:otg env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_senderGroup_otg /usr/bin/otg --broadcast on --dsthostname 192.168.255.255 --generator cbr --port 3000 --protocol udp --rate 400 --size 512
376 2007-11-20 19:00:46 DEBUG nodeHandler::ExecApp: writing 'S senderGroup exec app:otg env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_senderGroup_otg /usr/bin/otg --broadcast on --dsthostname 192.168.255.255 --generator cbr --port 3000 --protocol udp --rate 400 --size 512' to app 'commServer'
377 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_3
378 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: ..... Start applications in receiverGroup_3
379 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_3: Start all applications
380 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_3: Starting application 'otr'
381 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_3: #send: args(13)'app:otr#env#-i#%OML_NAME=node%x-%y#LD_LIBRARY_PATH=/usr/lib/#OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_3_otr#/usr/bin/otr#--hostname#localhost#--port#4000#--protocol#udp
382 2007-11-20 19:00:46 DEBUG nodeHandler::Communicator: Send message: S receiverGroup_3 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_3_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp
383 2007-11-20 19:00:46 DEBUG nodeHandler::ExecApp: writing 'S receiverGroup_3 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_3_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp' to app 'commServer'
384 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: Call receiverGroup_4
385 2007-11-20 19:00:46 DEBUG nodeHandler::set::_ALL_: ..... Start applications in receiverGroup_4
386 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_4: Start all applications
387 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_4: Starting application 'otr'
388 2007-11-20 19:00:46 DEBUG nodeHandler::set::receiverGroup_4: #send: args(13)'app:otr#env#-i#%OML_NAME=node%x-%y#LD_LIBRARY_PATH=/usr/lib/#OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_4_otr#/usr/bin/otr#--hostname#localhost#--port#4000#--protocol#udp
389 2007-11-20 19:00:46 DEBUG nodeHandler::Communicator: Send message: S receiverGroup_4 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_4_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp
390 2007-11-20 19:00:46 DEBUG nodeHandler::ExecApp: writing 'S receiverGroup_4 exec app:otr env -i %OML_NAME=node%x-%y LD_LIBRARY_PATH=/usr/lib/ OML_CONFIG=http://10.10.0.10:4000/omlc?id=oml_receiverGroup_4_otr /usr/bin/otr --hostname localhost --port 4000 --protocol udp' to app 'commServer'
391 2007-11-20 19:00:49 DEBUG nodeHandler::web::access: node17-20.grid.orbit-lab.org "GET /omlc?id=oml_receiverGroup_4_otr HTTP/1.0" 200 1530
392 2007-11-20 19:00:49 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_17_20 APP_EVENT STARTED app:otr'
393 2007-11-20 19:00:49 DEBUG nodeHandler::Communicator: Process message 'n_17_20 APP_EVENT STARTED app:otr'
394 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otr' executing on n_17_20: ''
395 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_17_20: Message for app 'app:otr' - ''
396 2007-11-20 19:00:50 DEBUG nodeHandler::web::access: node11-19.grid.orbit-lab.org "GET /omlc?id=oml_senderGroup_otg HTTP/1.0" 200 877
397 2007-11-20 19:00:50 DEBUG nodeHandler::web::access: node14-1.grid.orbit-lab.org "GET /omlc?id=oml_senderGroup_otg HTTP/1.0" 200 877
398 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STARTED app:otg'
399 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STARTED app:otg'
400 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otg' executing on n_11_19: ''
401 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - ''
402 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_17_20 APP_EVENT STDOUT app:otr "PORT Number: 4000"'
403 2007-11-20 19:00:50 DEBUG nodeHandler::web::access: node8-8.grid.orbit-lab.org "GET /omlc?id=oml_receiverGroup_2_otr HTTP/1.0" 200 1530
404 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_17_20 APP_EVENT STDOUT app:otr PORT Number: 4000'
405 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_17_20: 'PORT Number: 4000'
406 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_17_20: Message for app 'app:otr' - 'PORT Number: 4000'
407 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_17_20 APP_EVENT STDOUT app:otr "binding to port: 4000......"'
408 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_17_20 APP_EVENT STDOUT app:otr binding to port: 4000......'
409 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_17_20: 'binding to port: 4000......'
410 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_17_20: Message for app 'app:otr' - 'binding to port: 4000......'
411 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STARTED app:otg'
412 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STARTED app:otg'
413 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otg' executing on n_14_1: ''
414 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - ''
415 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STARTED app:otr'
416 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STARTED app:otr'
417 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otr' executing on n_8_8: ''
418 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otr' - ''
419 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otg "Using UDP broadcast... "'
420 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otg Using UDP broadcast... '
421 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_11_19: 'Using UDP broadcast... '
422 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - 'Using UDP broadcast... '
423 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otg "Destination Hostname: 192.168.255.255"'
424 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otg Destination Hostname: 192.168.255.255'
425 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_11_19: 'Destination Hostname: 192.168.255.255'
426 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - 'Destination Hostname: 192.168.255.255'
427 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otg "PORT Number: 3000"'
428 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otg PORT Number: 3000'
429 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_11_19: 'PORT Number: 3000'
430 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - 'PORT Number: 3000'
431 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otg "Rate is set as 400000bps"'
432 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otg Rate is set as 400000bps'
433 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_11_19: 'Rate is set as 400000bps'
434 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - 'Rate is set as 400000bps'
435 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otg "packet size parameter is set as 512"'
436 2007-11-20 19:00:50 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otg packet size parameter is set as 512'
437 2007-11-20 19:00:50 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_11_19: 'packet size parameter is set as 512'
438 2007-11-20 19:00:50 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otg' - 'packet size parameter is set as 512'
439 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STDOUT app:otg "Using UDP broadcast... "'
440 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STDOUT app:otg Using UDP broadcast... '
441 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_14_1: 'Using UDP broadcast... '
442 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - 'Using UDP broadcast... '
443 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STDOUT app:otg "Destination Hostname: 192.168.255.255"'
444 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STDOUT app:otg Destination Hostname: 192.168.255.255'
445 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_14_1: 'Destination Hostname: 192.168.255.255'
446 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - 'Destination Hostname: 192.168.255.255'
447 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STDOUT app:otg "PORT Number: 3000"'
448 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STDOUT app:otg PORT Number: 3000'
449 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_14_1: 'PORT Number: 3000'
450 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - 'PORT Number: 3000'
451 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STDOUT app:otg "Rate is set as 400000bps"'
452 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STDOUT app:otg Rate is set as 400000bps'
453 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_14_1: 'Rate is set as 400000bps'
454 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - 'Rate is set as 400000bps'
455 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_14_1 APP_EVENT STDOUT app:otg "packet size parameter is set as 512"'
456 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_14_1 APP_EVENT STDOUT app:otg packet size parameter is set as 512'
457 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_14_1: 'packet size parameter is set as 512'
458 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_14_1: Message for app 'app:otg' - 'packet size parameter is set as 512'
459 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otr "PORT Number: 4000"'
460 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otr PORT Number: 4000'
461 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_8_8: 'PORT Number: 4000'
462 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otr' - 'PORT Number: 4000'
463 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otr "binding to port: 4000......"'
464 2007-11-20 19:00:51 DEBUG nodeHandler::web::access: node11-19.grid.orbit-lab.org "GET /omlc?id=oml_receiverGroup_3_otr HTTP/1.0" 200 1530
465 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otr binding to port: 4000......'
466 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_8_8: 'binding to port: 4000......'
467 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otr' - 'binding to port: 4000......'
468 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STARTED app:otr'
469 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STARTED app:otr'
470 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otr' executing on n_11_19: ''
471 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otr' - ''
472 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otr "PORT Number: 4000"'
473 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otr PORT Number: 4000'
474 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_11_19: 'PORT Number: 4000'
475 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otr' - 'PORT Number: 4000'
476 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_11_19 APP_EVENT STDOUT app:otr "binding to port: 4000......"'
477 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_11_19 APP_EVENT STDOUT app:otr binding to port: 4000......'
478 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otr' executing on n_11_19: 'binding to port: 4000......'
479 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_11_19: Message for app 'app:otr' - 'binding to port: 4000......'
480 2007-11-20 19:00:51 DEBUG nodeHandler::web::access: node8-8.grid.orbit-lab.org "GET /omlc?id=oml_senderGroup_otg HTTP/1.0" 200 877
481 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STARTED app:otg'
482 2007-11-20 19:00:51 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STARTED app:otg'
483 2007-11-20 19:00:51 DEBUG nodeHandler::agentCmd::APP_EVENT: STARTED' from 'app:otg' executing on n_8_8: ''
484 2007-11-20 19:00:51 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - ''
485 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otg "Using UDP broadcast... "'
486 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otg Using UDP broadcast... '
487 2007-11-20 19:00:52 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_8_8: 'Using UDP broadcast... '
488 2007-11-20 19:00:52 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - 'Using UDP broadcast... '
489 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otg "Destination Hostname: 192.168.255.255"'
490 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otg Destination Hostname: 192.168.255.255'
491 2007-11-20 19:00:52 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_8_8: 'Destination Hostname: 192.168.255.255'
492 2007-11-20 19:00:52 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - 'Destination Hostname: 192.168.255.255'
493 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otg "PORT Number: 3000"'
494 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otg PORT Number: 3000'
495 2007-11-20 19:00:52 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_8_8: 'PORT Number: 3000'
496 2007-11-20 19:00:52 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - 'PORT Number: 3000'
497 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otg "Rate is set as 400000bps"'
498 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otg Rate is set as 400000bps'
499 2007-11-20 19:00:52 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_8_8: 'Rate is set as 400000bps'
500 2007-11-20 19:00:52 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - 'Rate is set as 400000bps'
501 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: commServer(STDOUT): 'n_8_8 APP_EVENT STDOUT app:otg "packet size parameter is set as 512"'
502 2007-11-20 19:00:52 DEBUG nodeHandler::Communicator: Process message 'n_8_8 APP_EVENT STDOUT app:otg packet size parameter is set as 512'
503 2007-11-20 19:00:52 DEBUG nodeHandler::agentCmd::APP_EVENT: STDOUT' from 'app:otg' executing on n_8_8: 'packet size parameter is set as 512'
504 2007-11-20 19:00:52 DEBUG nodeHandler::node::n_8_8: Message for app 'app:otg' - 'packet size parameter is set as 512'
505 2007-11-20 19:01:46 INFO nodeHandler::Experiment: DONE!
506 2007-11-20 19:01:46 DEBUG nodeHandler::ExecApp: writing 'q' to app 'commServer'
507 2007-11-20 19:01:46 INFO nodeHandler::ExecApp: Application 'commServer' finished
508 2007-11-20 19:01:46 DEBUG nodeHandler::Communicator: commServer(DONE.OK): 'status: 0'
509 2007-11-20 19:01:48 DEBUG nodeHandler::service call: http://oml:5022/oml/stop?id=grid_2007_11_20_18_58_12
510 2007-11-20 19:01:53 INFO nodeHandler::run: Experiment grid_2007_11_20_18_58_12 finished after 3:41
Click here to return to the tutorial.