| 00:16.33 | *** part/#asterisk-dev kharwell (kharwell@nat/digium/x-djmucqoukktlwvuv) |
| 00:35.16 | *** join/#asterisk-dev coreyfarrell (~coreyfarr@24-177-3-44.dhcp.nwtn.ct.charter.com) |
| 01:22.26 | *** join/#asterisk-dev [TK]D-Fender (~joe@64.235.216.2) |
| 02:55.32 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 03:01.32 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 03:26.55 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 03:29.07 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 03:52.39 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 04:38.05 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 05:58.17 | *** join/#asterisk-dev bof22 (~Thunderbi@185.13.183.107) |
| 07:03.01 | *** join/#asterisk-dev goddva (~goddva@77.40.154.242) |
| 07:45.48 | *** join/#asterisk-dev bof23 (~Thunderbi@80.12.35.61) |
| 08:09.25 | *** join/#asterisk-dev tzafrir (~tzafrir@local.xorcom.com) |
| 08:09.26 | *** mode/#asterisk-dev [+o tzafrir] by ChanServ |
| 08:14.31 | *** join/#asterisk-dev bof23 (~Thunderbi@185.13.183.107) |
| 08:36.15 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 08:36.16 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 08:51.28 | *** join/#asterisk-dev bof23 (~Thunderbi@80.12.58.112) |
| 08:59.28 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 08:59.29 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 09:06.41 | *** join/#asterisk-dev bof23 (~Thunderbi@185.13.183.107) |
| 09:42.42 | *** join/#asterisk-dev Tim_Toady (~fuzzy@snf-33276.vm.okeanos.grnet.gr) |
| 10:21.43 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 10:21.43 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 12:25.48 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 12:25.49 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 12:26.06 | *** join/#asterisk-dev matesstar (d4478a32@gateway/web/freenode/ip.212.71.138.50) |
| 13:21.25 | *** join/#asterisk-dev [TK]D-Fender (~chatzilla@216-191-106-163.dedicated.allstream.net) |
| 14:20.57 | *** part/#asterisk-dev russellb (~rustlebee@redhat/russellb) |
| 14:27.11 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 14:27.11 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 15:06.20 | *** join/#asterisk-dev kharwell (kharwell@nat/digium/x-chfqagxncccgqkec) |
| 15:09.38 | *** join/#asterisk-dev leedm777 (leedm777@nat/digium/x-ujrizssdvwvcxhwf) |
| 15:39.33 | *** join/#asterisk-dev DivideBy0 (~DivideBy0@unaffiliated/divideby0x0) |
| 15:43.13 | *** join/#asterisk-dev gtjoseph (~gtj0@unaffiliated/gtj) |
| 15:56.10 | *** join/#asterisk-dev mjordan (mjordan@nat/digium/x-xxsrotjzhvybaexl) |
| 15:56.10 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 16:20.44 | *** join/#asterisk-dev rmudgett (rmudgett@nat/digium/x-bhyxdyhmwllbbdhl) |
| 16:20.50 | *** join/#asterisk-dev rmudgett (rmudgett@nat/digium/x-piblmybigqowihtj) |
| 18:18.32 | gtjoseph | mjordan: you could also stream the SIP messages to a capture server over TZSP for direct read by Wireshark. |
| 18:40.40 | mjordan | gtjoseph: yeah. When I've wished I had this, it was usually a "oh snap, that was weird, run that call again. Oh crap, still didn't capture it." |
| 18:40.57 | gtjoseph | ah, that makes sense |
| 19:27.30 | *** join/#asterisk-dev newtonr (~RustyNewt@173-21-146-94.client.mchsi.com) |
| 19:27.31 | *** mode/#asterisk-dev [+o newtonr] by ChanServ |
| 20:09.36 | kharwell | so in trying to solve the deadlock issue in ASTERISK-25640 I thought one possible solution might be to just unlock the contexts lock right before attempting to grab the context_merge_lock in ast_change_hint. Then of course locking the contexts lock again right after. That should resolve the problem by keeping the locking order correct. |
| 20:09.53 | kharwell | However as file pointed out the contexts lock may not actually be locked at that point. As I traced it back indeed there is a possible path where contexts would not be locked. |
| 20:10.43 | kharwell | But this was traced back to the ast_add_extension2_lockopt function. It seems to me that this should always be called with contexts locked (most cases it does) otherwise it seems like a context could potentially go away in the middle of accessing it. |
| 20:11.16 | kharwell | So if I modify it so that contexts is always locked then the above mentioned solution to the deadlock issue should work. Thoughts? |
| 20:47.20 | mjordan | I think modifying it is potentially dangerous. |
| 20:47.33 | mjordan | Keep in mind the contexts lock can also be held recursively |
| 20:47.44 | mjordan | Which means that you can't count on a single unlock to actually unlock the contexts lock. |
| 20:48.42 | mjordan | Note: this is why the name ast_rdlock_contexts/ast_wrlock_contexts is hilarious |
| 20:49.43 | mjordan | So, even if you locked it in that path - which would be hard to verify that it would not break something else, given that it is called by ast_add_extension2 and friends - you still can't count on context being locked only once |
| 20:49.49 | mjordan | which means that you're still prone to deadlocking. |
| 20:49.59 | mjordan | I don't think we can safely lock the merge lock at all. |
| 20:50.07 | mjordan | At least not that deep into the call stack. |
| 20:55.26 | rmudgett | ast_change_hint() should not be locking context_merge_lock. The scope of the context_merge_lock is the outer most lock in the locking order. |
| 20:55.58 | rmudgett | https://issues.asterisk.org/jira/browse/ASTERISK-25394 needs to be re-fixed as it is the cause of this deadlock. |
| 20:56.34 | kharwell | yeah you'd have to put it before the contexts lock which seems to be impractical here |
| 21:32.05 | kharwell | hrm what about moving the changes made to ast_change_hint to occur after ast_add_extension2_lockopt has been executed and the contexts lock has been released (if it was even previously held)? |
| 21:38.38 | mjordan | er |
| 21:38.49 | mjordan | I don't know. |
| 21:39.14 | mjordan | This is one of those areas of the code that you really can't just lightly move something around in |
| 21:39.32 | mjordan | The contexts lock being released probably means that something else can sneak in and change the value of the hint |
| 21:39.39 | mjordan | so I would suspect that you cannot move it outside of that protection |
| 21:40.16 | mjordan | I guess the first question is: why did we have to hold onto the merge contexts lock in the first place? |
| 21:40.44 | rmudgett | It was because of the issue I linked earlier ASTERISK-25394 |
| 21:41.00 | rmudgett | The initial device state was incorrect. |
| 21:42.30 | mjordan | rmudgett: I'm aware of that. I'm wondering why holding that lock was necessary to fixing that issue. |
| 21:43.10 | kharwell | If I understand it if the merge lock is not held then the context itself can disappear during the merge process as it is either moved or removed. |
| 21:43.30 | mjordan | It shouldn't if the context lock is held |
| 21:43.34 | mjordan | which is the case in ast_change_hint |
| 21:44.02 | kharwell | I think that is the problem. ast_change_hint can sometimes be called without the contexts list being locked |
| 21:44.21 | kharwell | so you have to hold the merge lock |
| 21:44.24 | kharwell | just in case |
| 21:44.25 | mjordan | Even if that were the case, that would mean that holding merge lock is unnecessary. |
| 21:44.27 | mjordan | No you don't :-) |
| 21:44.34 | mjordan | You need to hold that right lock, if that's actually the problem |
| 21:45.01 | kharwell | aah so maybe grab the contexts lock here? |
| 21:45.10 | kharwell | in ast_change_hint that is instead of the merge lock? |
| 21:45.22 | mjordan | I don't know, as I'm not sure why file thought we needed to hold the merge lock |
| 21:46.21 | file | the logic follows the same as the original device state callback function, which also holds the lock - it may be safe not to... |
| 21:47.07 | file | while slim it may be possible, though, to call device state callbacks from different threads at the same time |
| 21:47.39 | kharwell | ast_merge_contexts_and_delete grabs the merge lock first and then contexts lock, so locking the contexts lock and not the merge lock may make sense |
| 21:48.24 | mjordan | well... |
| 21:48.29 | mjordan | it doesn't really grab the context lock. |
| 21:48.34 | mjordan | It does it in a loop, on each extension add |
| 21:48.37 | mjordan | which is kinda screw-ball. |
| 21:49.06 | mjordan | which means it is repeatedly grabbing/releasing the context lock during a merge. |
| 21:49.40 | mjordan | however, if you definitively held the context lock, then yes, I you are at least safe that you won't be nuked while you're doing your update. However, you aren't guaranteed that things will happen atomically |
| 21:49.41 | mjordan | That is |
| 21:49.49 | mjordan | You could copy the hint to the new context with the old state |
| 21:49.53 | mjordan | then update the hint in the old context |
| 21:50.01 | mjordan | and the hint in the new context would have the wrong/stale state |
| 21:50.31 | mjordan | You'd have to hold the context lock around context_merge/during it to guarantee that things happened atomically |
| 21:51.08 | *** join/#asterisk-dev [TK]D-Fender (~joe@64.235.216.2) |
| 21:51.21 | mjordan | This is some spectacularly messed up code. |
| 21:51.23 | kharwell | I must be looking in the wrong place. In ast_merge_contexts_and_delete it calls ast_wrlocks_contexts right after getting the merge lock |
| 21:53.10 | kharwell | locking the context object itself is not the problem it is holding the merge lock while also holding the context container lock |
| 21:53.15 | mjordan | hm |
| 21:53.18 | mjordan | you're right, my bad :-) |
| 21:53.50 | mjordan | kharwell: inverting the order is the problem in ast_change_hint. |
| 21:54.00 | kharwell | correct |
| 21:54.09 | mjordan | I'd just remove the merge lock. |
| 21:54.24 | mjordan | If we're already protected (somewhat) by the contexts lock... I'm not sure what more is really needed. |
| 21:54.41 | kharwell | and add in a contexts lock call then right? |
| 21:54.45 | file | be aware of what I said above though - without that lock there is no guarantee that the device state callback thread and the thread invoking ast_change_hint won't execute state callbacks at the same time |
| 21:54.54 | mjordan | I think all context_merge_lock is *supposed* to do is prevent multiple threads that call ast_merge_contexts_and_delete from all operating at the same time. |
| 21:55.32 | mjordan | which would be ... pointless... given that they already hold the contexts lock |
| 21:55.33 | file | it should probably maybe be fine |
| 21:55.39 | mjordan | kharwell: Yes. I think. |
| 21:56.23 | kharwell | file: rmudgett mentioned doing a try lock. If you can't get the merge lock then just skip the update. I guess that would have the effect though of having the original bug resurface? |
| 21:56.49 | file | yes. |
| 21:57.57 | mjordan | generally hates try locks |
| 21:58.08 | mjordan | try lock: for when you can't figure out the locking order and sort of don't care. |
| 21:58.32 | file | from a chan_sip and res_pjsip it's okay to have two threads do updates, the question is: would they both be the same? would it get the correct value and then the wrong value? |
| 22:00.54 | file | hum |
| 22:01.14 | kharwell | the hint itself is locked in both places |
| 22:01.55 | file | for a brief period of time |
| 22:01.56 | kharwell | that should keep it from being different right? |
| 22:03.03 | file | checks |
| 22:04.13 | file | I don't think you can guarantee it with current locking with the removal of the merge lock |
| 22:04.30 | file | device_state_cb minimally locks the hint |
| 22:07.18 | file | it is possible for device_state_cb to acquire the hint, and then change_hint to acquire/remove/manipulate it |
| 22:07.24 | file | whilst device_state_cb is accessing/modifying it |
| 22:09.33 | kharwell | yeah |
| 22:45.04 | kharwell | what about adding another lock? One to keep change_hint and the callbacks from stepping on each other? |
| 22:47.56 | file | that should work although more locks, more complexity, more fun! |
| 22:50.05 | kharwell | I shall call it yafl...yet another fun lock |
| 22:50.47 | kharwell | file: it is either that or ao2 everything :-D |
| 22:51.05 | file | redirects tornado to kharwell |
| 22:51.47 | seanbright | reads back |
| 22:51.53 | seanbright | you guys say "lock" and "merge" a lot |
| 22:54.03 | kharwell | Locke likes to lock locks a lot |
| 22:55.49 | file | seanbright, SQUIRREL |
| 23:42.09 | *** part/#asterisk-dev kharwell (kharwell@nat/digium/x-chfqagxncccgqkec) |