Hello OVS team,

 

I have a ovs-vswitched crash of ovs version 2.8.2. I don't have the flow
which has lead to this crash, but from the backtrace I could see that the
crash is because of double locking. The ofproto_mutex lock is acquired in
handle_packet_out() and the same lock is being tried to acquire in
ofproto_flow_mod_learn().  I have the following questions?

1.  Can we have a flow which can have both OFPACT_OUTPUT and OFPACT_LEARN to
the same packet? If yes then we will a case of double lock issue.

 

2.  I have not seen any such issue reported in upstream yet and this is a
general case of controller to ovs communication. 

 

3.  Ofproto_muxtex locking in ofproto_flow_mod_learn() is obvious because,
the pmd thread will be performing the actions. 

 

4.  Any usecase where we might hit this kind of open flow actions.

 

 

root@ubuntu16:/home/sdn/openvswitch# ovs-vsctl --version

ovs-vsctl (Open vSwitch) 2.8.2

DB Schema 7.15.0

 

root@ubuntu16:/home/sdn/openvswitch# gdb /usr/sbin/ovs-vswitchd
../../core.compute-0-7.domain.tld.1552010169.ovs-vswitchd.66327

GNU gdb (Ubuntu 7.11.1-0ubuntu1~16.5) 7.11.1

Copyright (C) 2016 Free Software Foundation, Inc.

License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>

This is free software: you are free to change and redistribute it.

There is NO WARRANTY, to the extent permitted by law.  Type "show copying"

and "show warranty" for details.

This GDB was configured as "x86_64-linux-gnu".

Type "show configuration" for configuration details.

For bug reporting instructions, please see:

<http://www.gnu.org/software/gdb/bugs/>.

Find the GDB manual and other documentation resources online at:

<http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".

Type "apropos word" to search for commands related to "word"...

Reading symbols from /usr/sbin/ovs-vswitchd...Reading symbols from
/usr/lib/debug/.build-id/34/7e6150fd3a987639b05b2c297955d248b4d624.debug...d
one.

done.

[New LWP 66327]

[New LWP 66340]

[New LWP 66339]

[New LWP 66341]

[New LWP 66342]

[New LWP 66328]

[New LWP 66332]

[New LWP 66333]

[New LWP 66334]

[New LWP 66343]

[New LWP 66344]

[New LWP 66371]

[New LWP 66335]

[New LWP 66372]

[Thread debugging using libthread_db enabled]

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Core was generated by `ovs-vswitchd unix:/var/run/openvswitch/db.sock
-vconsole:emer -vsyslog:err -vfi'.

Program terminated with signal SIGABRT, Aborted.

#0  0x00007f2f021e7428 in __GI_raise (sig=sig@entry=6) at
../sysdeps/unix/sysv/linux/raise.c:54

54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.

[Current thread is 1 (Thread 0x7f2f0397cb00 (LWP 66327))]

(gdb) bt

#0  0x00007f2f021e7428 in __GI_raise (sig=sig@entry=6) at
../sysdeps/unix/sysv/linux/raise.c:54

#1  0x00007f2f021e902a in __GI_abort () at abort.c:89

#2  0x000000000078de4e in ovs_abort_valist (err_no=<optimized out>,
format=<optimized out>, args=args@entry=0x7ffc2630db28) at lib/util.c:347

#3  0x000000000078ded7 in ovs_abort (err_no=<optimized out>,
format=format@entry=0x8cd4e9 "%s: pthread_%s_%s failed") at lib/util.c:339

#4  0x000000000075f439 in ovs_mutex_lock_at (l_=l_@entry=0xbc3c80
<ofproto_mutex>, where=where@entry=0x8a1cd3 "ofproto/ofproto.c:5117") at
lib/ovs-thread.c:76

#5  0x00000000006a155f in ofproto_flow_mod_learn
(ofm=ofm@entry=0x7ffc2630eab0, keep_ref=<optimized out>, limit=<optimized
out>, below_limitp=below_limitp@entry=0x7ffc2630ea50) at
ofproto/ofproto.c:5117

#6  0x00000000006bd704 in xlate_learn_action (ctx=ctx@entry=0x7ffc26311f00,
learn=learn@entry=0x32eab58) at ofproto/ofproto-dpif-xlate.c:5216

#7  0x00000000006c06e3 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6580

#8  0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x32ea9b0,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#9  xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#10 0x00000000006bfdb1 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#11 0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x31ae620,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#12 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#13 0x00000000006bfdb1 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#14 0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x330e350,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#15 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#16 0x00000000006bfdb1 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#17 0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x30af050,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#18 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#19 0x00000000006bfdb1 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#20 0x00000000006c1f70 in xlate_recursively (deepens=true, rule=0x3477640,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#21 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#22 0x00000000006c00d3 in xlate_ofpact_resubmit (resubmit=0x31156e8,
resubmit=0x31156e8, resubmit=0x31156e8, ctx=0x7ffc26311f00) at
ofproto/ofproto-dpif-xlate.c:4434

#23 do_xlate_actions (ofpacts=<optimized out>, ofpacts_len=<optimized out>,
ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false) at
ofproto/ofproto-dpif-xlate.c:6460

#24 0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x3115510,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#25 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#26 0x00000000006bfdb1 in do_xlate_actions (ofpacts=<optimized out>,
ofpacts_len=<optimized out>, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#27 0x00000000006c1f70 in xlate_recursively (deepens=false, rule=0x316af70,
ctx=0x7ffc26311f00) at ofproto/ofproto-dpif-xlate.c:4005

#28 xlate_table_action (ctx=0x7ffc26311f00, in_port=<optimized out>,
table_id=<optimized out>, may_packet_in=<optimized out>,
honor_table_miss=<optimized out>, with_ct_orig=<optimized out>)

    at ofproto/ofproto-dpif-xlate.c:4131

#29 0x00000000006bfdb1 in do_xlate_actions (ofpacts=ofpacts@entry=0x2da2258,
ofpacts_len=ofpacts_len@entry=8, ctx=ctx@entry=0x7ffc26311f00,
group_bucket_action=group_bucket_action@entry=false)

    at ofproto/ofproto-dpif-xlate.c:6631

#30 0x00000000006c7be0 in xlate_actions (xin=xin@entry=0x7ffc26312990,
xout=xout@entry=0x7ffc26312d90) at ofproto/ofproto-dpif-xlate.c:7234

#31 0x00000000006b8f20 in upcall_xlate (wc=0x7ffc26313f98,
odp_actions=0x7ffc26313760, upcall=0x7ffc26312d30, udpif=0x13f2a50) at
ofproto/ofproto-dpif-upcall.c:1153

#32 process_upcall (udpif=udpif@entry=0x13f2a50,
upcall=upcall@entry=0x7ffc26312d30,
odp_actions=odp_actions@entry=0x7ffc26313760, wc=wc@entry=0x7ffc26313f98) at
ofproto/ofproto-dpif-upcall.c:1347

#33 0x00000000006b9f93 in upcall_cb (packet=<optimized out>,
flow=0x7ffc26313d00, ufid=<optimized out>, pmd_id=<optimized out>,
type=<optimized out>, userdata=<optimized out>, actions=0x7ffc26313760,

    wc=0x7ffc26313f98, put_actions=0x7ffc263137a0, aux=0x13f2a50) at
ofproto/ofproto-dpif-upcall.c:1251

#34 0x00000000006e2a56 in dp_netdev_upcall (packet_=packet_@entry=0x34b13c0,
flow=flow@entry=0x7ffc26313d00, wc=wc@entry=0x7ffc26313f98,
ufid=ufid@entry=0x7ffc26313730, type=type@entry=DPIF_UC_MISS,

    userdata=userdata@entry=0x0, actions=actions@entry=0x7ffc26313760,
put_actions=put_actions@entry=0x7ffc263137a0, pmd=<optimized out>,
pmd=<optimized out>) at lib/dpif-netdev.c:4736

#35 0x00000000006e8c29 in handle_packet_upcall (now=235845924,
lost_cnt=<synthetic pointer>, put_actions=0x7ffc263137a0,
actions=0x7ffc26313760, key=0x7ffc26314c00, packet=0x34b13c0, pmd=0x14a24f0)

    at lib/dpif-netdev.c:4945

#36 fast_path_processing (pmd=pmd@entry=0x14a24f0,
packets_=packets_@entry=0x7ffc26315180, keys=keys@entry=0x7ffc26314c00,
flow_map=flow_map@entry=0x7ffc26314a98,

    index_map=index_map@entry=0x7ffc26314a88 "", in_port=<optimized out>,
now=now@entry=235845924) at lib/dpif-netdev.c:5067

#37 0x00000000006e95f6 in dp_netdev_input__ (pmd=pmd@entry=0x14a24f0,
packets=packets@entry=0x7ffc26315180, md_is_valid=md_is_valid@entry=true,
port_no=port_no@entry=0) at lib/dpif-netdev.c:5148

#38 0x00000000006eaf90 in dp_netdev_recirculate (packets=0x7ffc26315180,
pmd=0x14a24f0) at lib/dpif-netdev.c:5193

#39 dp_execute_cb (aux_=aux_@entry=0x7ffc26315a10, packets_=0x7ffc26315180,
packets_@entry=0x7ffc26315a30, a=a@entry=0x3309884, may_steal=<optimized
out>) at lib/dpif-netdev.c:5488

#40 0x0000000000717378 in odp_execute_actions (dp=dp@entry=0x7ffc26315a10,
batch=batch@entry=0x7ffc26315a30, steal=steal@entry=false,
actions=<optimized out>, actions_len=<optimized out>,

---Type <return> to continue, or q <return> to quit---

    dp_execute_action=dp_execute_action@entry=0x6eac20 <dp_execute_cb>) at
lib/odp-execute.c:699

#41 0x00000000006e3b81 in dp_netdev_execute_actions (now=<optimized out>,
actions_len=<optimized out>, actions=<optimized out>, flow=<optimized out>,
may_steal=false, packets=0x7ffc26315a30, pmd=0x14a24f0)

    at lib/dpif-netdev.c:5660

#42 dpif_netdev_execute (dpif=dpif@entry=0x13f25d0,
execute=execute@entry=0x7ffc26315c88) at lib/dpif-netdev.c:2968

#43 0x00000000006ec51c in dpif_netdev_operate (dpif=0x13f25d0,
ops=0x7ffc26315c78, n_ops=1) at lib/dpif-netdev.c:2998

#44 0x00000000006eecd3 in dpif_operate (dpif=0x13f25d0,
ops=ops@entry=0x7ffc26315c78, n_ops=n_ops@entry=1) at lib/dpif.c:1342

#45 0x00000000006ef411 in dpif_execute (dpif=<optimized out>,
execute=execute@entry=0x7ffc26315d20) at lib/dpif.c:1307

#46 0x00000000006a5e8d in packet_execute (ofproto_=0x197d9b0,
opo=0x7ffc26315da0) at ofproto/ofproto-dpif.c:4717

#47 0x000000000069c1f3 in ofproto_packet_out_finish (opo=0x7ffc26315da0,
ofproto=0x197d9b0) at ofproto/ofproto.c:3548

#48 handle_packet_out (ofconn=ofconn@entry=0x2d1adf0, oh=oh@entry=0x2cc7eb0)
at ofproto/ofproto.c:3589

#49 0x00000000006a025b in handle_openflow__ (msg=0x2ccec50,
ofconn=0x2d1adf0) at ofproto/ofproto.c:8071

#50 handle_openflow (ofconn=0x2d1adf0, ofp_msg=0x2ccec50) at
ofproto/ofproto.c:8246

#51 0x00000000006cdacb in ofconn_run (handle_openflow=0x69f980
<handle_openflow>, ofconn=0x2d1adf0) at ofproto/connmgr.c:1451

#52 connmgr_run (mgr=0x197df00,
handle_openflow=handle_openflow@entry=0x69f980 <handle_openflow>) at
ofproto/connmgr.c:365

#53 0x0000000000699fb6 in ofproto_run (p=0x197d9b0) at
ofproto/ofproto.c:1821

#54 0x0000000000688674 in bridge_run__ () at vswitchd/bridge.c:2927

#55 0x000000000068e168 in bridge_run () at vswitchd/bridge.c:2985

#56 0x0000000000414de5 in main (argc=11, argv=0x7ffc263175c8) at
vswitchd/ovs-vswitchd.c:119

 

(gdb) f 5

#5  0x00000000006a155f in ofproto_flow_mod_learn
(ofm=ofm@entry=0x7ffc2630eab0, keep_ref=<optimized out>, limit=<optimized
out>, below_limitp=below_limitp@entry=0x7ffc2630ea50) at
ofproto/ofproto.c:5117

warning: Source file is more recent than executable.

5117            ovs_mutex_lock(&ofproto_mutex);

(gdb) p ofproto_mutex

$1 = {lock = {__data = {__lock = 1, __count = 0, __owner = 66327, __nusers =
1, __kind = 2, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next =
0x0}},

    __size =
"\001\000\000\000\000\000\000\000\027\003\001\000\001\000\000\000\002",
'\000' <repeats 22 times>, __align = 1}, where = 0x8a1910
"ofproto/ofproto.c:3585"}

 

3551 static enum ofperr

3552 handle_packet_out(struct ofconn *ofconn, const struct ofp_header *oh)

3553     OVS_EXCLUDED(ofproto_mutex)

3554 {

3555     struct ofproto *p = ofconn_get_ofproto(ofconn);

3556     struct ofputil_packet_out po;

         .......

3577

3578     po.ofpacts = ofpbuf_steal_data(&ofpacts);   /* Move to heap. */

3579     error = ofproto_packet_out_init(p, ofconn, &opo, &po);

3580     if (error) {

3581         free(po.ofpacts);

3582         return error;

3583     }

3584

3585     ovs_mutex_lock(&ofproto_mutex);

3586     opo.version = p->tables_version;

3587     error = ofproto_packet_out_start(p, &opo);

3588     if (!error) {

3589         ofproto_packet_out_finish(p, &opo);

3590     }

3591     ovs_mutex_unlock(&ofproto_mutex);

3592

3593     ofproto_packet_out_uninit(&opo);

3594     return error;

3595 }

 

 

 

In handle_packet_out frame

 

#48 handle_packet_out (ofconn=ofconn@entry=0x2d1adf0, oh=oh@entry=0x2cc7eb0)

at ofproto/ofproto.c:3589

warning: Source file is more recent than executable.

3589            ofproto_packet_out_finish(p, &opo);

(gdb) p opo

$15 = {version = 11668, packet = 0x348a0b0, flow = 0x34a1850, ofpacts =

0x34d2a80, ofpacts_len = 48, aux = 0x2f0b2d0}

(gdb) p opo->ofpacts

$16 = (struct ofpact *) 0x34d2a80

(gdb) p *opo->ofpacts

$17 = {type = OFPACT_SET_FIELD, raw = 255 '\377', len = 32}

(gdb) p *(struct ofpact *) (0x34d2a80 +32)

$19 = {type = OFPACT_OUTPUT, raw = 255 '\377', len = 16}

(gdb) p /x (0x34d2a80 +32)

$20 = 0x34d2aa0

(gdb)  p *((struct ofpact_output *) (void *)(0x34d2aa0))

$21 = {ofpact = {type = OFPACT_OUTPUT, raw = 255 '\377', len = 16}, port =

65529, max_len = 0}

 

 

In frame 8 

(gdb) f 8

(gdb) p rule

$8 = (struct rule_dpif *) 0x32ea9b0

(gdb) p rule->up

$9 = {ofproto = 0x197d9b0, cr = {node = {prev = 0x32ea4b8, next = {p =

0x32eaeb8}}, priority = 5, cls_match = {p = 0x35d7a90},

    match = {{{flow = 0x32ea940, mask = 0x32ea970}, flows = {0x32ea940,

0x32ea970}}}}, table_id = 46 '.', state = RULE_INSERTED,

  mutex = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers

= 0, __kind = 2, __spins = 0, __elision = 0, __list = {

          __prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 16 times>,

"\002", '\000' <repeats 22 times>, __align = 0},

    where = 0x89f95a "<unlocked>"}, ref_count = {count = 1}, flow_cookie =

18196532644982816768, cookie_node = {hash = 632857159,

    d = 0x7f2dd8034cf0, s = 0x0}, flags = (unknown: 0), hard_timeout = 0,

idle_timeout = 0, importance = 0,

  removed_reason = 6 '\006', eviction_group = 0x0, evg_node = {idx = 0,

priority = 0}, actions = 0x32eab40, meter_list_node = {

    prev = 0x32eaa78, next = 0x32eaa78}, monitor_flags = (unknown: 0),

add_seqno = 5717, modify_seqno = 5717, expirable = {

    prev = 0x32eaaa0, next = 0x32eaaa0}, created = 234914519, modified =

234914519, match_tlv_bitmap = 0, ofpacts_tlv_bitmap = 0}

(gdb) p rule->up->actions

$10 = (const struct rule_actions * const) 0x32eab40

(gdb) p *rule->up->actions

$11 = {has_meter = false, has_learn_with_delete = false, has_groups = false,

ofpacts_len = 360, ofpacts = 0x32eab48}

(gdb) p *rule->up->actions->ofpacts

$12 = {type = OFPACT_OUTPUT, raw = 255 '\377', len = 16}

(gdb) p *((struct ofpact_output *) (void *)(0x32eab48))

$13 = {ofpact = {type = OFPACT_OUTPUT, raw = 255 '\377', len = 16}, port =

65533, max_len = 65535}

(gdb) p *(struct ofpact *) (0x32eab48 +16)

$6 = {type = OFPACT_LEARN, raw = 48 '0', len = 344}

 

 

 

Thanks & Regards,

Anil Kumar

 

Attachment: smime.p7s
Description: S/MIME cryptographic signature

_______________________________________________
discuss mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-discuss

Reply via email to