| 05:32.13 | *** join/#asterisk-dev IgorG (~igorg@109.194.115.162) |
| 08:03.19 | *** join/#asterisk-dev chazzam (~chazz@donutokyo.info) |
| 08:26.57 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 08:26.57 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 15:00.09 | *** join/#asterisk-dev mjordan (mjordan@nat/digium/x-zvhxtwsemysmcujx) |
| 15:00.09 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 15:00.59 | mjordan | file: I think I'm a bit confused about review https://gerrit.asterisk.org/#/c/1855 still. What shared state is being mutated both in the device state callback, as well as in the ast_change_hint call? |
| 15:01.18 | mjordan | Clearly the hint is, but that is locked at the hint level |
| 15:01.39 | file | there is no shared state, however there is nothing to stop both the device state callback and ast_change_hint from using/invoking device state callbacks at the same time |
| 15:02.49 | file | and the device state callback doesn't keep the hint lock for long, so both could give different state |
| 15:05.16 | mjordan | any reason the device state callback can't just hold onto the hint lock? |
| 15:05.41 | file | I'm sure there's a lock inversion waiting there between channel drivers and the PBX core |
| 15:05.57 | mjordan | maybe, but kevin's solution feels worse than the problem we're solving |
| 15:07.46 | file | I'm not sure if I have an alternative, besides letting that race condition... exist |
| 15:07.57 | mjordan | At the very least, state_callbacks_lock feels completely redundant with just locking the entire hints container |
| 15:08.19 | mjordan | I'm not sure this race condition was that harmful, compared to the alternatives |
| 15:08.34 | file | which race condition? the device state callback/ast_change_hint one? |
| 15:08.52 | mjordan | yes |
| 15:09.36 | file | it's a slim chance, the end result shouldn't be a crash - the device state shown on a phone may just not reflect reality, until another device state change occurs |
| 15:09.37 | mjordan | it's not good, don't get me wrong, but if we tank Asterisk's ability to just do a state update in normal operation outside of startup, that's bad |
| 15:09.58 | mjordan | Really, the hint should be locked during the callback |
| 15:10.11 | mjordan | that feels like the real crux of the problem: we unlock it and let something else slip in and mutate the state |
| 15:10.35 | file | well, nothing else previously slipped in and mutated the state to this degree |
| 15:10.37 | file | it's a new condition |
| 15:11.07 | mjordan | what changed? |
| 15:11.29 | file | fixing ast_change_hint to update and propogate state if the underlying devices change |
| 15:12.47 | mjordan | actually. |
| 15:12.49 | mjordan | This may work. |
| 15:13.03 | mjordan | execute_state_callback actually relocks the hint, copies the data off, then calls the callback |
| 15:13.08 | file | yes |
| 15:13.14 | mjordan | really, it appears as if we're just letting go of the lock on the hint too soon |
| 15:13.25 | mjordan | we should let execute_state_callback do that for us |
| 15:13.43 | mjordan | either that, or pull the data off prior to calling that, and let it notify the callbacks |
| 15:14.35 | file | you'd still potentially run into the race condition above, unless you held the hint while invoking the callback - it's just lessened |
| 15:15.13 | file | hum, what would be really nice is if ast_change_hint could actually queue up a device state callback which would get handled normally... |
| 15:16.54 | mjordan | How would you run into the race condition? You're holding onto the hint lock the entire time. |
| 15:17.31 | file | where, and hint or hints? |
| 15:17.32 | mjordan | The only way we'd have a race is if we are trying to execute a state callback and we release the hint lock prior to caching off the information |
| 15:17.44 | mjordan | does not feel like this problem is well understood |
| 15:17.46 | file | that is what currently happens, are you proposing changing that? |
| 15:18.02 | mjordan | no, that isn't what happens |
| 15:18.06 | mjordan | ast_change_hint releases the hint lock |
| 15:18.17 | mjordan | you then go into execute_state_callback, and re-grab the lock |
| 15:18.25 | mjordan | between that period of time, something else can change the state of the hint |
| 15:18.29 | mjordan | such as the device state callback |
| 15:18.35 | mjordan | I presumed that was the actual race condition |
| 15:20.19 | file | would stasis allow multiple simultaneous invocations of the device state callback from separate threads? |
| 15:20.25 | mjordan | yes |
| 15:20.34 | mjordan | sighs |
| 15:20.39 | mjordan | also, we have this warning comment: |
| 15:20.40 | mjordan | /* |
| 15:20.40 | mjordan | <PROTECTED> |
| 15:20.40 | mjordan | <PROTECTED> |
| 15:20.40 | mjordan | <PROTECTED> |
| 15:20.40 | mjordan | <PROTECTED> |
| 15:20.41 | mjordan | <PROTECTED> |
| 15:20.43 | mjordan | <PROTECTED> |
| 15:20.47 | mjordan | what a freaking mess. |
| 15:21.22 | file | I give up on it. |
| 15:22.57 | file | according to the stasis documentation the device_state_callbacks would be serialized |
| 15:23.04 | mjordan | hrm. |
| 15:23.15 | mjordan | is unsure of why |
| 15:23.34 | file | unless we changed that and never updated the documentation |
| 15:23.40 | mjordan | is it a dedicated subscription? |
| 15:23.55 | file | one subscription to the device state all topic using stasis_subscribe |
| 15:23.58 | mjordan | that is, it doesn't get served on the the threadpool? |
| 15:25.30 | file | from a PBX core perspective, no |
| 15:32.58 | file | ponders |
| 15:34.11 | file | mjordan, I have... a thought. |
| 15:37.28 | file | mjordan, a new message type that ast_change_hint can use to publish a hint update message, which is handled in the device and presence state callbacks |
| 15:38.04 | file | that would return things to the exact locking they were previously |
| 15:39.32 | mjordan | I like that. |
| 15:39.44 | mjordan | I'd rather serialize things in a queue then try to keep doing this insane lock the world crap |
| 15:39.47 | file | yeah |
| 15:43.55 | file | oh |
| 15:43.57 | file | oh hell |
| 15:44.27 | mjordan | er |
| 15:44.29 | mjordan | ??? |
| 15:44.32 | file | 11 :P |
| 15:44.40 | file | bit harder there |
| 15:44.40 | mjordan | er |
| 15:44.44 | mjordan | was it even broken there? |
| 15:44.45 | *** join/#asterisk-dev bof22 (~Thunderbi@ARennes-650-1-18-19.w90-32.abo.wanadoo.fr) |
| 15:45.01 | mjordan | file: and only slightly harder there, device state notifications still happen on the event message bus |
| 15:45.15 | file | yeah |
| 15:45.17 | file | to both |
| 15:45.26 | file | why did I do that... |
| 15:59.26 | *** join/#asterisk-dev gtjoseph (~gtj0@unaffiliated/gtj) |
| 16:01.16 | gtjoseph | mjordan: Do you want to update the commit message on 570 to remove the RFC bit and describe the final solution? |
| 16:04.41 | *** join/#asterisk-dev [TK]D-Fender (~joe@64.235.216.2) |
| 16:05.28 | WIMPy | Not sure what condition you're in to there, but I'd call hints rather unreliable. There is ASTERISK-24549 and I haven't dug into why they seem to go out of sync after some time. |
| 16:06.15 | WIMPy | And devicestates as well. They seem be be a little random ar logger, at least the "reachable" ones. |
| 16:06.20 | mjordan | gtjoseph: sure, I was holding off until you'd had a chance to review it |
| 16:06.31 | WIMPy | Thought I had an issue in that as well, but maybe not. |
| 16:07.21 | gtjoseph | mjordan: I'm good with it. Don't want to +1 my own review though. :) |
| 16:07.25 | mjordan | it isn't surprising that a reload causes the state of things to be modified. I would expect things to reach the appropriate state after things have been reloaded and the core has had a chance to requery things. |
| 16:07.35 | mjordan | If that doesn't happen, then yes, that's a bug. |
| 16:07.49 | mjordan | But a reload is an intrusive affair. Asterisk *has* to purge everything, and rebuild the state. |
| 16:11.32 | WIMPy | I just tried it on 11.19 and it only changed one hint back. But what's interesting is that it only seems to happen once. |
| 16:45.39 | *** join/#asterisk-dev Tim_Toady (~fuzzy@snf-33276.vm.okeanos.grnet.gr) |
| 17:14.35 | *** join/#asterisk-dev bof22 (~Thunderbi@ARennes-650-1-18-19.w90-32.abo.wanadoo.fr) |
| 17:56.22 | *** join/#asterisk-dev superscrat (~asanders@173-21-89-217.client.mchsi.com) |
| 18:04.51 | *** join/#asterisk-dev JunK-Y (~junky@pdpc/supporter/active/junk-y) |
| 18:32.57 | *** join/#asterisk-dev oej (~oej@h87-96-134-129.dynamic.se.alltele.net) |
| 18:32.57 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 19:12.09 | superscrat | hello, file |
| 19:12.14 | file | hi |
| 19:54.11 | file | gah race conditions in tests |
| 20:16.15 | file | yay for varying timing characteristics between Jenkins nodes, but boo race conditions in tests |
| 20:30.42 | mjordan | uhm |
| 20:30.52 | mjordan | ast_localtime_wakeup_monitor is only used by the test? |
| 20:31.17 | mjordan | yup. |
| 20:31.20 | mjordan | Great googly moogly. |
| 20:33.28 | file | that is the correct response |
| 20:55.06 | mjordan | file: FYI, if you get a chance, I could use a gander at https://gerrit.asterisk.org/#/c/570/ |
| 20:55.24 | mjordan | both George and myself are sort of out of the running |
| 20:55.52 | file | aye |
| 21:05.08 | file | mjordan, did you touch Jenkins... |
| 21:08.50 | mjordan | nope |
| 21:09.02 | mjordan | up for me |
| 21:09.12 | file | yeah, it's just merging Asterisk stuff now |
| 21:09.35 | file | and doing -1 against stuff it can't merge |
| 21:10.08 | file | zuul, jenkins, gerrit, insert applicable name for the above |
| 21:53.14 | seanbright | i like cross-referencing mjordan's tweets with what is being discussed in #asterisk-dev |
| 21:55.12 | mjordan | twitter: the ultimate spill-over. |