Applied, thank you!
On Fri, May 02, 2014 at 04:25:03PM -0700, Alex Wang wrote:
> All four patches look good to me,
>
> Acked-by: Alex Wang <al...@nicira.com>
>
>
> On Wed, Apr 30, 2014 at 10:51 AM, Ben Pfaff <b...@nicira.com> wrote:
>
> > I've had a number of requests for more specific logging of flow_mod
> > information. It is useful for troubleshooting.
> >
> > Signed-off-by: Ben Pfaff <b...@nicira.com>
> > ---
> > ofproto/connmgr.c | 98
> > ++++++++++++++++++++++++++++++++++++++++++++
> > ofproto/connmgr.h | 3 ++
> > ofproto/ofproto-provider.h | 6 ---
> > ofproto/ofproto.c | 68 +-----------------------------
> > 4 files changed, 102 insertions(+), 73 deletions(-)
> >
> > diff --git a/ofproto/connmgr.c b/ofproto/connmgr.c
> > index 9a5167d..0cf9e2d 100644
> > --- a/ofproto/connmgr.c
> > +++ b/ofproto/connmgr.c
> > @@ -22,6 +22,7 @@
> > #include <stdlib.h>
> >
> > #include "coverage.h"
> > +#include "dynamic-string.h"
> > #include "fail-open.h"
> > #include "in-band.h"
> > #include "odp-util.h"
> > @@ -99,6 +100,12 @@ struct ofconn {
> > uint32_t master_async_config[OAM_N_TYPES]; /* master, other */
> > uint32_t slave_async_config[OAM_N_TYPES]; /* slave */
> >
> > + /* Flow table operation logging. */
> > + int n_add, n_delete, n_modify; /* Number of unreported ops of each
> > kind. */
> > + long long int first_op, last_op; /* Range of times for unreported
> > ops. */
> > + long long int next_op_report; /* Time to report ops, or LLONG_MAX.
> > */
> > + long long int op_backoff; /* Earliest time to report ops
> > again. */
> > +
> > /* Flow monitors (e.g. NXST_FLOW_MONITOR). */
> >
> > /* Configuration. Contains "struct ofmonitor"s. */
> > @@ -145,6 +152,8 @@ static void ofconn_run(struct ofconn *,
> > const struct ofpbuf
> > *ofp_msg));
> > static void ofconn_wait(struct ofconn *, bool handling_openflow);
> >
> > +static void ofconn_log_flow_mods(struct ofconn *);
> > +
> > static const char *ofconn_get_target(const struct ofconn *);
> > static char *ofconn_make_name(const struct connmgr *, const char *target);
> >
> > @@ -1115,6 +1124,39 @@ ofconn_pktbuf_retrieve(struct ofconn *ofconn,
> > uint32_t id,
> > return pktbuf_retrieve(ofconn->pktbuf, id, bufferp, in_port);
> > }
> >
> > +/* Reports that a flow_mod operation of the type specified by 'command'
> > was
> > + * successfully executed by 'ofconn', so that the connmgr can log it. */
> > +void
> > +ofconn_report_flow_mod(struct ofconn *ofconn,
> > + enum ofp_flow_mod_command command)
> > +{
> > + long long int now;
> > +
> > + switch (command) {
> > + case OFPFC_ADD:
> > + ofconn->n_add++;
> > + break;
> > +
> > + case OFPFC_MODIFY:
> > + case OFPFC_MODIFY_STRICT:
> > + ofconn->n_modify++;
> > + break;
> > +
> > + case OFPFC_DELETE:
> > + case OFPFC_DELETE_STRICT:
> > + ofconn->n_delete++;
> > + break;
> > + }
> > +
> > + now = time_msec();
> > + if (ofconn->next_op_report == LLONG_MAX) {
> > + ofconn->first_op = now;
> > + ofconn->next_op_report = MAX(now + 10 * 1000, ofconn->op_backoff);
> > + ofconn->op_backoff = ofconn->next_op_report + 60 * 1000;
> > + }
> > + ofconn->last_op = now;
> > +}
> > +
> > /* Returns true if 'ofconn' has any pending opgroups. */
> > bool
> > ofconn_has_pending_opgroups(const struct ofconn *ofconn)
> > @@ -1177,6 +1219,8 @@ ofconn_flush(struct ofconn *ofconn)
> > struct ofmonitor *monitor, *next_monitor;
> > int i;
> >
> > + ofconn_log_flow_mods(ofconn);
> > +
> > ofconn->role = OFPCR12_ROLE_EQUAL;
> > ofconn_set_protocol(ofconn, OFPUTIL_P_NONE);
> > ofconn->packet_in_format = NXPIF_OPENFLOW10;
> > @@ -1244,6 +1288,11 @@ ofconn_flush(struct ofconn *ofconn)
> > sizeof ofconn->slave_async_config);
> > }
> >
> > + ofconn->n_add = ofconn->n_delete = ofconn->n_modify = 0;
> > + ofconn->first_op = ofconn->last_op = LLONG_MIN;
> > + ofconn->next_op_report = LLONG_MAX;
> > + ofconn->op_backoff = LLONG_MIN;
> > +
> > HMAP_FOR_EACH_SAFE (monitor, next_monitor, ofconn_node,
> > &ofconn->monitors) {
> > ofmonitor_destroy(monitor);
> > @@ -1348,6 +1397,11 @@ ofconn_run(struct ofconn *ofconn,
> > }
> > }
> >
> > +
> > + if (time_msec() >= ofconn->next_op_report) {
> > + ofconn_log_flow_mods(ofconn);
> > + }
> > +
> > ovs_mutex_lock(&ofproto_mutex);
> > if (!rconn_is_alive(ofconn->rconn)) {
> > ofconn_destroy(ofconn);
> > @@ -1369,6 +1423,50 @@ ofconn_wait(struct ofconn *ofconn, bool
> > handling_openflow)
> > if (handling_openflow && ofconn_may_recv(ofconn)) {
> > rconn_recv_wait(ofconn->rconn);
> > }
> > + if (ofconn->next_op_report != LLONG_MAX) {
> > + poll_timer_wait_until(ofconn->next_op_report);
> > + }
> > +}
> > +
> > +static void
> > +ofconn_log_flow_mods(struct ofconn *ofconn)
> > +{
> > + int n_flow_mods = ofconn->n_add + ofconn->n_delete + ofconn->n_modify;
> > + if (n_flow_mods) {
> > + long long int ago = (time_msec() - ofconn->first_op) / 1000;
> > + long long int interval = (ofconn->last_op - ofconn->first_op) /
> > 1000;
> > + struct ds s;
> > +
> > + ds_init(&s);
> > + ds_put_format(&s, "%d flow_mods ", n_flow_mods);
> > + if (interval == ago) {
> > + ds_put_format(&s, "in the last %lld s", ago);
> > + } else if (interval) {
> > + ds_put_format(&s, "in the %lld s starting %lld s ago",
> > + interval, ago);
> > + } else {
> > + ds_put_format(&s, "%lld s ago", ago);
> > + }
> > +
> > + ds_put_cstr(&s, " (");
> > + if (ofconn->n_add) {
> > + ds_put_format(&s, "%d adds, ", ofconn->n_add);
> > + }
> > + if (ofconn->n_delete) {
> > + ds_put_format(&s, "%d deletes, ", ofconn->n_delete);
> > + }
> > + if (ofconn->n_modify) {
> > + ds_put_format(&s, "%d modifications, ", ofconn->n_modify);
> > + }
> > + s.length -= 2;
> > + ds_put_char(&s, ')');
> > +
> > + VLOG_INFO("%s: %s", rconn_get_name(ofconn->rconn), ds_cstr(&s));
> > + ds_destroy(&s);
> > +
> > + ofconn->n_add = ofconn->n_delete = ofconn->n_modify = 0;
> > + }
> > + ofconn->next_op_report = LLONG_MAX;
> > }
> >
> > /* Returns true if 'ofconn' should receive asynchronous messages of the
> > given
> > diff --git a/ofproto/connmgr.h b/ofproto/connmgr.h
> > index c09c80f..036d125 100644
> > --- a/ofproto/connmgr.h
> > +++ b/ofproto/connmgr.h
> > @@ -159,6 +159,9 @@ enum ofperr ofconn_pktbuf_retrieve(struct ofconn *,
> > uint32_t id,
> > bool ofconn_has_pending_opgroups(const struct ofconn *);
> > void ofconn_add_opgroup(struct ofconn *, struct list *);
> >
> > +/* Logging flow_mod summaries. */
> > +void ofconn_report_flow_mod(struct ofconn *, enum ofp_flow_mod_command);
> > +
> > /* Sending asynchronous messages. */
> > bool connmgr_wants_packet_in_on_miss(struct connmgr *mgr);
> > void connmgr_send_port_status(struct connmgr *, struct ofconn *source,
> > diff --git a/ofproto/ofproto-provider.h b/ofproto/ofproto-provider.h
> > index 8f4f41e..141adec 100644
> > --- a/ofproto/ofproto-provider.h
> > +++ b/ofproto/ofproto-provider.h
> > @@ -133,12 +133,6 @@ struct ofproto {
> > * the flow table and reacquire the global lock. */
> > struct guarded_list rule_executes; /* Contains "struct
> > rule_execute"s. */
> >
> > - /* Flow table operation logging. */
> > - int n_add, n_delete, n_modify; /* Number of unreported ops of each
> > kind. */
> > - long long int first_op, last_op; /* Range of times for unreported
> > ops. */
> > - long long int next_op_report; /* Time to report ops, or LLONG_MAX.
> > */
> > - long long int op_backoff; /* Earliest time to report ops
> > again. */
> > -
> > /* Linux VLAN device support (e.g. "eth0.10" for VLAN 10.)
> > *
> > * This is deprecated. It is only for compatibility with broken
> > device
> > diff --git a/ofproto/ofproto.c b/ofproto/ofproto.c
> > index 3d788a6..7f5f792 100644
> > --- a/ofproto/ofproto.c
> > +++ b/ofproto/ofproto.c
> > @@ -529,10 +529,6 @@ ofproto_create(const char *datapath_name, const char
> > *datapath_type,
> > ofproto->n_pending = 0;
> > hmap_init(&ofproto->deletions);
> > guarded_list_init(&ofproto->rule_executes);
> > - ofproto->n_add = ofproto->n_delete = ofproto->n_modify = 0;
> > - ofproto->first_op = ofproto->last_op = LLONG_MIN;
> > - ofproto->next_op_report = LLONG_MAX;
> > - ofproto->op_backoff = LLONG_MIN;
> > ofproto->vlan_bitmap = NULL;
> > ofproto->vlans_changed = false;
> > ofproto->min_mtu = INT_MAX;
> > @@ -1561,43 +1557,6 @@ ofproto_run(struct ofproto *p)
> > OVS_NOT_REACHED();
> > }
> >
> > - if (time_msec() >= p->next_op_report) {
> > - long long int ago = (time_msec() - p->first_op) / 1000;
> > - long long int interval = (p->last_op - p->first_op) / 1000;
> > - struct ds s;
> > -
> > - ds_init(&s);
> > - ds_put_format(&s, "%d flow_mods ",
> > - p->n_add + p->n_delete + p->n_modify);
> > - if (interval == ago) {
> > - ds_put_format(&s, "in the last %lld s", ago);
> > - } else if (interval) {
> > - ds_put_format(&s, "in the %lld s starting %lld s ago",
> > - interval, ago);
> > - } else {
> > - ds_put_format(&s, "%lld s ago", ago);
> > - }
> > -
> > - ds_put_cstr(&s, " (");
> > - if (p->n_add) {
> > - ds_put_format(&s, "%d adds, ", p->n_add);
> > - }
> > - if (p->n_delete) {
> > - ds_put_format(&s, "%d deletes, ", p->n_delete);
> > - }
> > - if (p->n_modify) {
> > - ds_put_format(&s, "%d modifications, ", p->n_modify);
> > - }
> > - s.length -= 2;
> > - ds_put_char(&s, ')');
> > -
> > - VLOG_INFO("%s: %s", p->name, ds_cstr(&s));
> > - ds_destroy(&s);
> > -
> > - p->n_add = p->n_delete = p->n_modify = 0;
> > - p->next_op_report = LLONG_MAX;
> > - }
> > -
> > return error;
> > }
> >
> > @@ -4513,7 +4472,6 @@ handle_flow_mod(struct ofconn *ofconn, const struct
> > ofp_header *oh)
> > uint64_t ofpacts_stub[1024 / 8];
> > struct ofpbuf ofpacts;
> > enum ofperr error;
> > - long long int now;
> >
> > error = reject_slave_controller(ofconn);
> > if (error) {
> > @@ -4535,31 +4493,7 @@ handle_flow_mod(struct ofconn *ofconn, const struct
> > ofp_header *oh)
> > goto exit_free_ofpacts;
> > }
> >
> > - /* Record the operation for logging a summary report. */
> > - switch (fm.command) {
> > - case OFPFC_ADD:
> > - ofproto->n_add++;
> > - break;
> > -
> > - case OFPFC_MODIFY:
> > - case OFPFC_MODIFY_STRICT:
> > - ofproto->n_modify++;
> > - break;
> > -
> > - case OFPFC_DELETE:
> > - case OFPFC_DELETE_STRICT:
> > - ofproto->n_delete++;
> > - break;
> > - }
> > -
> > - now = time_msec();
> > - if (ofproto->next_op_report == LLONG_MAX) {
> > - ofproto->first_op = now;
> > - ofproto->next_op_report = MAX(now + 10 * 1000,
> > - ofproto->op_backoff);
> > - ofproto->op_backoff = ofproto->next_op_report + 60 * 1000;
> > - }
> > - ofproto->last_op = now;
> > + ofconn_report_flow_mod(ofconn, fm.command);
> >
> > exit_free_ofpacts:
> > ofpbuf_uninit(&ofpacts);
> > --
> > 1.7.10.4
> >
> > _______________________________________________
> > dev mailing list
> > dev@openvswitch.org
> > http://openvswitch.org/mailman/listinfo/dev
> >
_______________________________________________
dev mailing list
dev@openvswitch.org
http://openvswitch.org/mailman/listinfo/dev
