* [Bridge] MSTPd in RSTP mode is sometimes slow...
@ 2012-10-09 14:23 Rodolfo Giometti
2012-10-09 15:42 ` Vitalii Demianets
2012-10-09 15:47 ` Rodolfo Giometti
0 siblings, 2 replies; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-09 14:23 UTC (permalink / raw)
To: bridge
Hello,
I'm currently using the MSTPd daemon on a custom PowerPC based board
and I notice that when forced in RSTP mode a port trnasition to the
forwarding state, sometimes, needs about 1.2s and, sometimes, needs
about 80ms!
When the transition is quick I get the following log:
1038912050.392513: bridge_bpdu_rcv: ifindex 6, len 60
1038912050.397313: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038912050.431810: PISM_to_UPDATE: br0:mrvl4:0
1038912050.436557: PISM_to_CURRENT: br0:mrvl4:0
1038912050.440949: PISM_to_RECEIVE: br0:mrvl4:0
1038912050.445431: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
1038912050.449905: PISM_to_CURRENT: br0:mrvl4:0
1038912050.468990: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
1038912050.476744: set_port_role: port mrvl4 role 3
1038912050.483704: MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding state
1038912050.488299: set_port_role: port mrvl4 role 3
1038912050.506378: MSTP_OUT_flush_all_fids: br0:mrvl5:0 Flushing forwarding data base
1038912051.199682: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
On the other hand when the transition is slow I get:
1038911701.406963: bridge_bpdu_rcv: ifindex 6, len 60
1038911701.411766: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038911701.446256: PISM_to_RECEIVE: br0:mrvl4:0
1038911701.451015: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
1038911701.455493: PISM_to_CURRENT: br0:mrvl4:0
1038911702.021584: PISM_to_UPDATE: br0:mrvl4:0
1038911702.026330: PISM_to_CURRENT: br0:mrvl4:0
1038911702.204368: PISM_to_UPDATE: br0:mrvl4:0
1038911702.209114: PISM_to_CURRENT: br0:mrvl4:0
1038911703.199645: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
1038911703.224464: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
1038911703.232292: set_port_role: port mrvl4 role 3
1038911703.245552: bridge_bpdu_rcv: ifindex 6, len 60
1038911703.250359: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038911703.284849: PISM_to_RECEIVE: br0:mrvl4:0
1038911703.289604: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
1038911703.294079: PISM_to_CURRENT: br0:mrvl4:0
1038911703.313165: MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding state
Note that my machine is NOT the root bridge and the connection is a
simple ring where I remove the connection between the other two
machines.
Any advice? :)
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-09 14:23 [Bridge] MSTPd in RSTP mode is sometimes slow Rodolfo Giometti
@ 2012-10-09 15:42 ` Vitalii Demianets
2012-10-09 15:58 ` Rodolfo Giometti
2012-10-09 15:47 ` Rodolfo Giometti
1 sibling, 1 reply; 8+ messages in thread
From: Vitalii Demianets @ 2012-10-09 15:42 UTC (permalink / raw)
To: bridge
Hello, Rodolfo!
Please, describe your setup: how many devices do you have and how exactly are
they connected?
Also, please specify which events exactly are you measuring the time interval
between. As I understand, you are measuring the time interval between some
event X not shown in the logs end the event Y = "br0:mrvl4:0 entering
forwarding state". What is event X?
Also see one more question below the quoted text.
On Tuesday 09 October 2012 17:23:37 Rodolfo Giometti wrote:
> Hello,
>
> I'm currently using the MSTPd daemon on a custom PowerPC based board
> and I notice that when forced in RSTP mode a port trnasition to the
> forwarding state, sometimes, needs about 1.2s and, sometimes, needs
> about 80ms!
>
> When the transition is quick I get the following log:
>
> 1038912050.392513: bridge_bpdu_rcv: ifindex 6, len 60
> 1038912050.397313: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
> 1038912050.431810: PISM_to_UPDATE: br0:mrvl4:0
> 1038912050.436557: PISM_to_CURRENT: br0:mrvl4:0
> 1038912050.440949: PISM_to_RECEIVE: br0:mrvl4:0
> 1038912050.445431: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
> 1038912050.449905: PISM_to_CURRENT: br0:mrvl4:0
> 1038912050.468990: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
> 1038912050.476744: set_port_role: port mrvl4 role 3
> 1038912050.483704: MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding
> state 1038912050.488299: set_port_role: port mrvl4 role 3
> 1038912050.506378: MSTP_OUT_flush_all_fids: br0:mrvl5:0 Flushing forwarding
> data base 1038912051.199682: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
>
>
> On the other hand when the transition is slow I get:
>
> 1038911701.406963: bridge_bpdu_rcv: ifindex 6, len 60
> 1038911701.411766: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
> 1038911701.446256: PISM_to_RECEIVE: br0:mrvl4:0
> 1038911701.451015: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
> 1038911701.455493: PISM_to_CURRENT: br0:mrvl4:0
> 1038911702.021584: PISM_to_UPDATE: br0:mrvl4:0
> 1038911702.026330: PISM_to_CURRENT: br0:mrvl4:0
> 1038911702.204368: PISM_to_UPDATE: br0:mrvl4:0
> 1038911702.209114: PISM_to_CURRENT: br0:mrvl4:0
> 1038911703.199645: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
> 1038911703.224464: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
> 1038911703.232292: set_port_role: port mrvl4 role 3
> 1038911703.245552: bridge_bpdu_rcv: ifindex 6, len 60
> 1038911703.250359: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
> 1038911703.284849: PISM_to_RECEIVE: br0:mrvl4:0
> 1038911703.289604: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
> 1038911703.294079: PISM_to_CURRENT: br0:mrvl4:0
> 1038911703.313165: MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding
> state
>
> Note that my machine is NOT the root bridge and the connection is a
> simple ring where I remove the connection between the other two
> machines.
>
I guess you have three devices connected in the ring. If so, is the device
under examination NOT the root bridge before event X, or after event X or in
both cases?
--
With Best Regards,
Vitalii Demianets
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-09 14:23 [Bridge] MSTPd in RSTP mode is sometimes slow Rodolfo Giometti
2012-10-09 15:42 ` Vitalii Demianets
@ 2012-10-09 15:47 ` Rodolfo Giometti
1 sibling, 0 replies; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-09 15:47 UTC (permalink / raw)
To: bridge
On Tue, Oct 09, 2012 at 04:23:37PM +0200, Rodolfo Giometti wrote:
> Hello,
>
> I'm currently using the MSTPd daemon on a custom PowerPC based board
> and I notice that when forced in RSTP mode a port trnasition to the
> forwarding state, sometimes, needs about 1.2s and, sometimes, needs
> about 80ms!
Just to be more complete as possible here a packets dump.
At 17.449146 the ingress BPDU:
0000 01 80 c2 00 00 00 00 0a dc 5a f6 8d 00 27 42 42 .........Z...'BB
0010 03 00 00 02 02 0e 80 00 00 0a dc 5a f6 80 00 00 ...........Z....
0020 00 00 80 00 00 0a dc 5a f6 80 80 0d 00 00 14 00 .......Z........
0030 02 00 10 00 00 31 30 30 4e 43 2d 52 .....100NC-R
At 18.814988 my machine's answer:
0000 01 80 c2 00 00 00 00 02 3e 99 f5 01 00 27 42 42 ........>....'BB
0010 03 00 00 02 02 0e 50 00 00 0a dc 5a e5 20 00 03 ......P....Z. ..
0020 0d 40 80 00 00 02 3e 99 f5 01 80 01 01 00 14 00 .@....>.........
0030 02 00 10 00 00 00 00 00 00 00 00 00 ............
At 18.818471 another ingress BPDU:
0000 01 80 c2 00 00 00 00 0a dc 5a f6 8d 00 27 42 42 .........Z...'BB
0010 03 00 00 02 02 78 50 00 00 0a dc 5a e5 20 00 03 .....xP....Z. ..
0020 0d 53 80 00 00 0a dc 5a f6 80 80 0d 01 00 14 00 .S.....Z........
0030 02 00 10 00 00 31 30 30 4e 43 2d 52 .....100NC-R
And at 19.183731 my machine's answer:
0000 01 80 c2 00 00 00 00 02 3e 99 f5 01 00 27 42 42 ........>....'BB
0010 03 00 00 02 02 3d 50 00 00 0a dc 5a e5 20 00 03 .....=P....Z. ..
0020 0d 40 80 00 00 02 3e 99 f5 01 80 01 01 00 14 00 .@....>.........
0030 02 00 10 00 00 00 00 00 00 00 00 00 ............
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-09 15:42 ` Vitalii Demianets
@ 2012-10-09 15:58 ` Rodolfo Giometti
2012-10-12 9:37 ` Rodolfo Giometti
0 siblings, 1 reply; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-09 15:58 UTC (permalink / raw)
To: Vitalii Demianets; +Cc: bridge
On Tue, Oct 09, 2012 at 06:42:36PM +0300, Vitalii Demianets wrote:
> Hello, Rodolfo!
>
> Please, describe your setup: how many devices do you have and how exactly are
> they connected?
ASCII Art:
+------------+
| my machine |----+
+------------+ |
| +------------+
| | |
| +------------+
+------------+ |
| root |----+ <----[A]
+------------+
The "Event" is: the ring is opened in [A]
> Also, please specify which events exactly are you measuring the time interval
> between. As I understand, you are measuring the time interval between some
> event X not shown in the logs end the event Y = "br0:mrvl4:0 entering
> forwarding state". What is event X?
Since I receive the external BPDU related with the Event (see
"bridge_bpdu_rcv: ifindex 6, len 60") to the message
"MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding".
> I guess you have three devices connected in the ring. If so, is the device
> under examination NOT the root bridge before event X, or after event X or in
> both cases?
My device is not the root bridge and it never becomes the root bridge
nor before and after the Event.
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-09 15:58 ` Rodolfo Giometti
@ 2012-10-12 9:37 ` Rodolfo Giometti
2012-10-15 15:24 ` Rodolfo Giometti
0 siblings, 1 reply; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-12 9:37 UTC (permalink / raw)
To: Vitalii Demianets; +Cc: bridge
On Tue, Oct 09, 2012 at 05:58:01PM +0200, Rodolfo Giometti wrote:
> On Tue, Oct 09, 2012 at 06:42:36PM +0300, Vitalii Demianets wrote:
> > Hello, Rodolfo!
> >
> > Please, describe your setup: how many devices do you have and how exactly are
> > they connected?
>
> ASCII Art:
>
> +------------+
> | my machine |----+
> +------------+ |
> | +------------+
> | | |
> | +------------+
> +------------+ |
> | root |----+ <----[A]
> +------------+
>
> The "Event" is: the ring is opened in [A]
Here another useful packets dump!
As you can see, when the Event occours, I see:
11:10:32.775132 STP 802.1w, Rapid STP, Flags [Proposal], bridge-id 8000.00:0a:dc:5a:f6:80.800d, length 43
message-age 0.00s, max-age 20.00s, hello-time 2.00s, forwarding-delay 16.00s
root-id 8000.00:0a:dc:5a:f6:80, root-pathcost 0, port-role Designated
0x0000: 0180 c200 0000 000a dc5a f68d 0027 4242 .........Z...'BB
0x0010: 0300 0002 020e 8000 000a dc5a f680 0000 ...........Z....
0x0020: 0000 8000 000a dc5a f680 800d 0000 1400 .......Z........
0x0030: 0200 1000 0031 3030 4e43 2d52 .....100NC-R
Here the other bridge says to my machine: «Ehi! Something happens. Can
I be the new root?»
11:10:34.107952 STP 802.1w, Rapid STP, Flags [Proposal], bridge-id 8000.00:02:3e:99:f5:01.8001, length 43
message-age 1.00s, max-age 20.00s, hello-time 2.00s, forwarding-delay 16.00s
root-id 5000.00:0a:dc:5a:e5:20, root-pathcost 200000, port-role Designated
0x0000: 0180 c200 0000 0002 3e99 f501 0027 4242 ........>....'BB
0x0010: 0300 0002 020e 5000 000a dc5a e520 0003 ......P....Z....
0x0020: 0d40 8000 0002 3e99 f501 8001 0100 1400 .@....>.........
0x0030: 0200 1000 0000 0000 0000 0000 ............
But my machine answers after ~1.3s! :'(
__This__ is a very loooong delay...
Here the internal state machine evolution:
1038910509.154586: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038910509.186205: PISM_to_RECEIVE: br0:mrvl4:0
1038910509.190962: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
1038910509.195441: PISM_to_CURRENT: br0:mrvl4:0
1038910509.290554: bridge_bpdu_rcv: ifindex 7, len 60
1038910509.293467: MSTP_IN_rx_bpdu: br0:mrvl5 received RST BPDU
1038910509.325087: PISM_to_UPDATE: br0:mrvl4:0
1038910509.329836: PISM_to_CURRENT: br0:mrvl4:0
1038910509.334226: PISM_to_RECEIVE: br0:mrvl5:0
1038910509.338713: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl5:0
1038910509.343204: PISM_to_CURRENT: br0:mrvl5:0
1038910509.484400: PISM_to_UPDATE: br0:mrvl4:0
1038910509.489145: PISM_to_CURRENT: br0:mrvl4:0
1038910510.479677: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
1038910510.504499: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
1038910510.512247: set_port_role: port mrvl4 role 3
1038910510.525581: bridge_bpdu_rcv: ifindex 6, len 60
1038910510.530389: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038910510.564881: PISM_to_RECEIVE: br0:mrvl4:0
1038910510.569636: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
1038910510.574111: PISM_to_CURRENT: br0:mrvl4:0
1038910510.593195: MSTP_OUT_set_state: br0:mrvl4:0 entering forwarding state
As you can see we receive the first BPDU at 1038910509.154586 and only
after ~1.3s we send our reply at 1038910510.479677
Why we need all this state transitions?
1038910509.154586: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038910509.186205: PISM_to_RECEIVE: br0:mrvl4:0
1038910509.190962: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
1038910509.195441: PISM_to_CURRENT: br0:mrvl4:0
1038910509.325087: PISM_to_UPDATE: br0:mrvl4:0
1038910509.329836: PISM_to_CURRENT: br0:mrvl4:0
1038910509.484400: PISM_to_UPDATE: br0:mrvl4:0
1038910509.489145: PISM_to_CURRENT: br0:mrvl4:0
1038910510.479677: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
Thanks in advance,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-12 9:37 ` Rodolfo Giometti
@ 2012-10-15 15:24 ` Rodolfo Giometti
2012-10-15 15:45 ` Rodolfo Giometti
0 siblings, 1 reply; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-15 15:24 UTC (permalink / raw)
To: Vitalii Demianets; +Cc: bridge
On Fri, Oct 12, 2012 at 11:37:00AM +0200, Rodolfo Giometti wrote:
Looking better my tests here:
> 1038910509.489145: PISM_to_CURRENT: br0:mrvl4:0
> 1038910510.479677: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
I noticed that we need ~1s from PISM_to_CURRENT to send out the BPDU!
How is it possible? =:-o
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-15 15:24 ` Rodolfo Giometti
@ 2012-10-15 15:45 ` Rodolfo Giometti
2012-10-15 16:39 ` Rodolfo Giometti
0 siblings, 1 reply; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-15 15:45 UTC (permalink / raw)
To: Vitalii Demianets; +Cc: bridge
On Mon, Oct 15, 2012 at 05:24:49PM +0200, Rodolfo Giometti wrote:
> On Fri, Oct 12, 2012 at 11:37:00AM +0200, Rodolfo Giometti wrote:
>
> Looking better my tests here:
>
> > 1038910509.489145: PISM_to_CURRENT: br0:mrvl4:0
> > 1038910510.479677: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
>
> I noticed that we need ~1s from PISM_to_CURRENT to send out the BPDU!
>
> How is it possible? =:-o
Let's take a look at this new test.
I modified the br_state_machines_run function as follow:
static void br_state_machines_run(bridge_t *br)
{
port_t *prt;
per_tree_port_t *ptp;
tree_t *tree;
LOG("------> 0");
if(!br->bridgeEnabled)
return;
/* 13.28 Port Receive state machine */
LOG("------> 1");
FOREACH_PORT_IN_BRIDGE(prt, br)
PRSM_run(prt);
/* 13.29 Port Protocol Migration state machine */
LOG("------> 2");
FOREACH_PORT_IN_BRIDGE(prt, br)
PPMSM_run(prt);
/* 13.30 Bridge Detection state machine */
LOG("------> 3");
FOREACH_PORT_IN_BRIDGE(prt, br)
BDSM_run(prt);
/* 13.31 Port Transmit state machine */
LOG("------> 4");
FOREACH_PORT_IN_BRIDGE(prt, br)
PTSM_run(prt);
/* 13.32 Port Information state machine */
LOG("------> 5");
FOREACH_PORT_IN_BRIDGE(prt, br)
{
FOREACH_PTP_IN_PORT(ptp, prt)
PISM_run(ptp);
}
/* 13.33 Port Role Selection state machine */
LOG("------> 6");
FOREACH_TREE_IN_BRIDGE(tree, br)
PRSSM_run(tree);
/* 13.34 Port Role Transitions state machine */
LOG("------> 7");
FOREACH_PORT_IN_BRIDGE(prt, br)
{
FOREACH_PTP_IN_PORT(ptp, prt)
PRTSM_run(ptp);
}
/* 13.35 Port State Transition state machine */
LOG("------> 8");
FOREACH_PORT_IN_BRIDGE(prt, br)
{
FOREACH_PTP_IN_PORT(ptp, prt)
PSTSM_run(ptp);
}
/* 13.36 Topology Change state machine */
LOG("------> 9");
FOREACH_PORT_IN_BRIDGE(prt, br)
{
FOREACH_PTP_IN_PORT(ptp, prt)
TCSM_run(ptp);
}
LOG("------> 10");
}
And rerun my test with the following outout:
1038910178.371891: bridge_bpdu_rcv: ifindex 6, len 60
1038910178.374841: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038910178.376916: br_state_machines_run: ------> 0
1038910178.382722: br_state_machines_run: ------> 1
1038910178.387469: br_state_machines_run: ------> 2
1038910178.392215: br_state_machines_run: ------> 3
1038910178.396962: br_state_machines_run: ------> 4
1038910178.401717: br_state_machines_run: ------> 5
1038910178.406460: PISM_to_RECEIVE: br0:mrvl4:0
1038910178.411217: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
1038910178.415696: PISM_to_CURRENT: br0:mrvl4:0
1038910178.421251: br_state_machines_run: ------> 6
1038910178.425740: br_state_machines_run: ------> 7
1038910178.430479: br_state_machines_run: ------> 8
1038910178.435221: br_state_machines_run: ------> 9
1038910178.439971: br_state_machines_run: ------> 10
1038910178.660628: br_state_machines_run: ------> 0
1038910178.663528: br_state_machines_run: ------> 1
1038910178.665404: br_state_machines_run: ------> 2
1038910178.670153: br_state_machines_run: ------> 3
1038910178.674901: br_state_machines_run: ------> 4
1038910178.679651: br_state_machines_run: ------> 5
1038910178.684405: PISM_to_UPDATE: br0:mrvl4:0
1038910178.689151: PISM_to_CURRENT: br0:mrvl4:0
1038910178.693541: br_state_machines_run: ------> 6
1038910178.698018: br_state_machines_run: ------> 7
1038910178.702782: br_state_machines_run: ------> 8
1038910178.707516: br_state_machines_run: ------> 9
1038910178.712266: br_state_machines_run: ------> 10
1038910179.406118: bridge_bpdu_rcv: ifindex 7, len 60
1038910179.409005: MSTP_IN_rx_bpdu: br0:mrvl5 received RST BPDU
1038910179.411081: br_state_machines_run: ------> 0
1038910179.416878: br_state_machines_run: ------> 1
1038910179.421636: br_state_machines_run: ------> 2
1038910179.426377: br_state_machines_run: ------> 3
1038910179.431126: br_state_machines_run: ------> 4
1038910179.435881: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
1038910179.448880: br_state_machines_run: ------> 5
1038910179.452019: PISM_to_RECEIVE: br0:mrvl5:0
1038910179.453895: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl5:0
1038910179.458373: PISM_to_CURRENT: br0:mrvl5:0
1038910179.463925: br_state_machines_run: ------> 6
1038910179.468415: br_state_machines_run: ------> 7
1038910179.473154: br_state_machines_run: ------> 8
1038910179.477896: br_state_machines_run: ------> 9
1038910179.482652: br_state_machines_run: ------> 10
1038910179.487435: bridge_bpdu_rcv: ifindex 6, len 60
1038910179.492237: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038910179.497183: br_state_machines_run: ------> 0
1038910179.502991: br_state_machines_run: ------> 1
1038910179.507737: br_state_machines_run: ------> 2
1038910179.512483: br_state_machines_run: ------> 3
1038910179.517231: br_state_machines_run: ------> 4
1038910179.521986: br_state_machines_run: ------> 5
1038910179.526729: PISM_to_UPDATE: br0:mrvl4:0
1038910179.531484: PISM_to_CURRENT: br0:mrvl4:0
1038910179.535868: PISM_to_RECEIVE: br0:mrvl4:0
1038910179.540788: PISM_to_NOT_DESIGNATED: br0:mrvl4:0
1038910179.544830: PISM_to_CURRENT: br0:mrvl4:0
1038910179.549936: br_state_machines_run: ------> 6
1038910179.554416: br_state_machines_run: ------> 7
1038910179.559174: br_state_machines_run: ------> 8
1038910179.563919: MSTP_OUT_set_state: br0:mrvl4:0 entering learning state
Look here:
1038910178.712266: br_state_machines_run: ------> 10
1038910179.406118: bridge_bpdu_rcv: ifindex 7, len 60
1038910179.409005: MSTP_IN_rx_bpdu: br0:mrvl5 received RST BPDU
1038910179.411081: br_state_machines_run: ------> 0
The mstpd daemon needs ~0.7s to rerun the function! =:-/
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Bridge] MSTPd in RSTP mode is sometimes slow...
2012-10-15 15:45 ` Rodolfo Giometti
@ 2012-10-15 16:39 ` Rodolfo Giometti
0 siblings, 0 replies; 8+ messages in thread
From: Rodolfo Giometti @ 2012-10-15 16:39 UTC (permalink / raw)
To: Vitalii Demianets; +Cc: bridge
On Mon, Oct 15, 2012 at 05:45:28PM +0200, Rodolfo Giometti wrote:
>
> The mstpd daemon needs ~0.7s to rerun the function! =:-/
I discovered why... I modified these funtions:
static inline void run_timeouts(void)
{
LOG("------> 0");
bridge_one_second();
++(nexttimeout.tv_sec);
LOG("------> 10");
}
int epoll_main_loop(void)
{
gettimeofday(&nexttimeout, NULL);
++(nexttimeout.tv_sec);
#define EV_SIZE 8
struct epoll_event ev[EV_SIZE];
while(1)
{
int r, i;
int timeout;
struct timeval tv;
LOG("------> 0");
gettimeofday(&tv, NULL);
timeout = time_diff(&nexttimeout, &tv);
if(timeout < 0)
{
run_timeouts();
timeout = 0;
}
LOG("------> 1");
r = epoll_wait(epoll_fd, ev, EV_SIZE, timeout);
if(r < 0 && errno != EINTR)
{
fprintf(stderr, "epoll_wait: %m\n");
return -1;
}
LOG("------> 2");
for(i = 0; i < r; ++i)
{
struct epoll_event_handler *p = ev[i].data.ptr;
if(p != NULL)
p->ref_ev = &ev[i];
}
LOG("------> 3");
for (i = 0; i < r; ++i)
{
struct epoll_event_handler *p = ev[i].data.ptr;
if(p && p->handler)
p->handler(ev[i].events, p);
}
LOG("------> 4");
for (i = 0; i < r; ++i)
{
struct epoll_event_handler *p = ev[i].data.ptr;
if(p != NULL)
p->ref_ev = NULL;
}
LOG("------> 10");
}
return 0;
}
and I get:
1038909843.937476: bridge_bpdu_rcv: ifindex 6, len 60
1038909843.941673: MSTP_IN_rx_bpdu: br0:mrvl4 received RST BPDU
1038909843.946618: br_state_machines_run: ------> 0
1038909843.952425: br_state_machines_run: ------> 1
1038909843.957172: br_state_machines_run: ------> 2
1038909843.961917: br_state_machines_run: ------> 3
1038909843.966664: br_state_machines_run: ------> 4
1038909843.971420: br_state_machines_run: ------> 5
1038909843.976163: PISM_to_RECEIVE: br0:mrvl4:0
1038909843.980921: PISM_to_SUPERIOR_DESIGNATED: br0:mrvl4:0
1038909843.985399: PISM_to_CURRENT: br0:mrvl4:0
1038909843.990954: br_state_machines_run: ------> 6
1038909843.995443: br_state_machines_run: ------> 7
1038909844.000183: br_state_machines_run: ------> 8
1038909844.004924: br_state_machines_run: ------> 9
1038909844.009673: br_state_machines_run: ------> 10
1038909844.014428: epoll_main_loop: ------> 4
1038909844.019259: epoll_main_loop: ------> 10
1038909844.023471: epoll_main_loop: ------> 0
1038909844.027772: epoll_main_loop: ------> 1
1038909844.050699: epoll_main_loop: ------> 2
1038909844.053582: epoll_main_loop: ------> 3
1038909844.054920: epoll_main_loop: ------> 4
1038909844.059130: epoll_main_loop: ------> 10
1038909844.063343: epoll_main_loop: ------> 0
1038909844.067644: run_timeouts: ------> 0
1038909844.071868: br_state_machines_run: ------> 0
1038909844.075796: br_state_machines_run: ------> 1
1038909844.080549: br_state_machines_run: ------> 2
1038909844.085295: br_state_machines_run: ------> 3
1038909844.090675: br_state_machines_run: ------> 4
1038909844.094796: br_state_machines_run: ------> 5
1038909844.099543: PISM_to_UPDATE: br0:mrvl4:0
1038909844.104295: PISM_to_CURRENT: br0:mrvl4:0
1038909844.108681: br_state_machines_run: ------> 6
1038909844.113167: br_state_machines_run: ------> 7
1038909844.117920: br_state_machines_run: ------> 8
1038909844.122659: br_state_machines_run: ------> 9
1038909844.127408: br_state_machines_run: ------> 10
1038909844.132162: run_timeouts: ------> 10
1038909844.136993: epoll_main_loop: ------> 1
1038909844.141032: epoll_main_loop: ------> 2
1038909844.145236: epoll_main_loop: ------> 3
1038909844.149447: epoll_main_loop: ------> 4
1038909844.153668: epoll_main_loop: ------> 10
1038909844.157870: epoll_main_loop: ------> 0
1038909844.162174: epoll_main_loop: ------> 1
1038909845.040037: epoll_main_loop: ------> 2
1038909845.042945: epoll_main_loop: ------> 3
1038909845.044283: epoll_main_loop: ------> 4
1038909845.048494: epoll_main_loop: ------> 10
1038909845.052714: epoll_main_loop: ------> 0
1038909845.057008: run_timeouts: ------> 0
1038909845.061226: br_state_machines_run: ------> 0
1038909845.065160: br_state_machines_run: ------> 1
1038909845.069910: br_state_machines_run: ------> 2
1038909845.074665: br_state_machines_run: ------> 3
1038909845.079407: br_state_machines_run: ------> 4
1038909845.084165: MSTP_OUT_tx_bpdu: br0:mrvl4 sending RST BPDU
As you can see the daemon changes its internal state only when
run_timeouts() is executed!
I suppose this is not right...
Ciao,
Rodolfo
--
GNU/Linux Solutions e-mail: giometti@enneenne.com
Linux Device Driver giometti@linux.it
Embedded Systems phone: +39 349 2432127
UNIX programming skype: rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2012-10-15 16:39 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-10-09 14:23 [Bridge] MSTPd in RSTP mode is sometimes slow Rodolfo Giometti
2012-10-09 15:42 ` Vitalii Demianets
2012-10-09 15:58 ` Rodolfo Giometti
2012-10-12 9:37 ` Rodolfo Giometti
2012-10-15 15:24 ` Rodolfo Giometti
2012-10-15 15:45 ` Rodolfo Giometti
2012-10-15 16:39 ` Rodolfo Giometti
2012-10-09 15:47 ` Rodolfo Giometti
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.