Time Nick Message 01:39 * dcook waves 01:42 dcook Is kohadevbox still the de facto dev tool or is koha-testing-docker rising up to replace it? 03:19 dcook Looks like kohadevbox doesn't work using Hyper-V with Virtualbox 6.0.x. Tempted to see if I could get kohadevbox to use Hyper-V instead of Virtualbox... 03:19 dcook But for now going to use koha-testing-docker instead... 03:47 mtj hiya dcook, i took bug 13193 for a spin... everything looks good, test suite passes 03:47 huginn Bug http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=13193 normal, P3, ---, joonas.kylmala, Needs Signoff , Discussion: strategy for diagnosing memcache issues. 03:47 dcook mtj: Interesting. I am just testing that now and I can't reproduce the problem with the snippet. 03:47 dcook Double-checking that I'm not blind. hehe. 03:49 dcook Joonas's comment perfectly describes the scenario I've encountered in the wild though 03:50 mtj i didnt get round to testing the snippet myself... perhaps bump the loop to 5000 ? 03:50 dcook Actually, there are some errors... there we go. Had to up from 50 to 100 03:50 mtj snap 03:50 dcook Cache for version is 18.1101000 at C4/Context.pm line 420. 03:50 dcook Cache for version is 18.1101000 at C4/Context.pm line 420. 03:50 dcook dcook@kohabackup:/kohawebs/dev/dcook/git> Use of uninitialized value $cached_var in concatenation (.) or string at C4/Context.pm line 420. 03:50 dcook Cache for timeout is at C4/Context.pm line 420. 03:50 dcook Use of uninitialized value $cached_var in concatenation (.) or string at C4/Context.pm line 420. 03:50 dcook Cache for version is at C4/Context.pm line 420. 03:50 dcook Cache for version is 18.1101000 at C4/Context.pm line 420. 03:50 dcook Cache for timeout is 1d at C4/Context.pm line 420. 03:51 dcook When I saw this in the wild, I thought I was going insane... hehe 03:51 dcook I mean I was pretty sure I wasn't insane, but was stumped 03:52 mtj ..might be nice to use the snippet as a test.t file 03:53 mtj a good way to catch similar problems 03:57 dcook Hmm mtj you tested the fix? 03:58 dcook Oh derp I'm doing the wrong dir.. 03:59 dcook Oh beautiful.. 04:00 dcook mtj: It requires some debugging code at the moment though, so I think probably would need to use something else 04:01 mtj i ran the test suite, and confirmed the about.pl was correct/green 04:02 dcook I'll look at signing off really quickly 04:02 dcook Have to leave the office in a few minutes 04:02 dcook I was so happy to discover Joonas's comments this morning though. I think I almost wept for joy hehe 04:05 dcook Signed off :) 04:06 mtj aah yes, re: debugging code.. i see the snippet needs a 'warn' added to context.pm.. 05:34 mtj dcook: i wrote the following snippet to prove the memcache bug, but hit a Schrodinger's cat problem.. 05:34 pastebot "mtj" at 192.168.1.110 pasted "memcache snippet" (17 lines) at http://paste.koha-community.org/14830 05:35 mtj it seems that attempting to fetch the pref values, stops the buggy behaviour, somehow... 05:42 mtj anyhoo.. i'm happy to admit defeat.. :) 06:34 reiveune hello 07:01 alex_a Bonjour 07:44 dcook mtj: It's a hard one. In my case, the buggy behaviour was causing IndependentBranches to return "softno" instead of 0. It had to do with the ordering of the syspref lookup in the code as well. 07:44 dcook I'm guessing that maybe 2 SIP requests came through in close proximity and then one retrieved the 2nd value when it was trying to get the 1st value because of a race condition 07:45 dcook Or rather got the 1st value when it was trying to get the 2nd value because it was getting a value intended for a newer request... 07:45 dcook Debugging concurrency problems is ahhhh 07:45 paxed hm. i think i've seen something similar, with different sysprefs. "solved" it by restarting plack, iirc 07:45 dcook paxed: Sounds about right 07:45 dcook Any time you have a persistent process I reckon 07:46 dcook So Plack, SIP server, maybe something else 07:46 dcook The implications seem pretty massive to me 07:46 paxed indeed 07:46 dcook Looks like it's not too hard to fix in any case 07:46 dcook Hardest part is working out the logistics of packaging a few more extra modules, but that's not uncommon 07:47 paxed wondering if it's due to koha using plack/caches wrong at some place, or if it's due to some module misbehaving 07:47 mtj hi hi, i hit the bug using a non-placked instance too.. 07:50 dcook paxed: yes and yes 07:50 dcook mtj: Whaaaat? Really? 07:50 dcook That's disturbing 07:50 dcook non-placked instance using a fork? 07:50 dcook paxed: see https://metacpan.org/pod/Cache::Memcached::Fast::Safe and https://metacpan.org/pod/Cache::Memcached::Fast 07:51 dcook Specifically the bit about "disconnect_all" 07:52 dcook I can see how file handle inheritance would be a problem with forking, so a preforking server like Starman or SIP server would have the problem.. 07:53 dcook Apache would prefork workers but each one should load up a new copy of Perl and using a single thread use the same socket synchronously.. 07:53 dcook Admittedly, the Koha cache code is a bit terrifying... 07:54 dcook mtj: Ohhh that makes me think.. 07:54 dcook I saw something about that 07:54 dcook In theory, memcached (ie L2 cache) should only be used 1 time to look up a value, and store it in the L1 cache (hash variable) 07:54 dcook This causes a problem in persistent processes... 07:55 dcook trying to think how it would bite you for a non-plack instance though.. 07:55 dcook Koha::Caches->flush_L1_caches(); is what stops the problem in persistent processes like Zebra daemon and Plack.. 07:55 mtj dcook: i ran Joonas' snippent on a non-placked instance, and got the expected corruption 07:56 dcook (still a problem for SIP server though... feel like I've talked about that somewhere..) 07:56 dcook mtj: You're running the snippet on the CLI though, right? 07:56 dcook Not via the web? 07:57 mtj yes, in a koha-shell via cli 07:57 dcook Ahh ok np 07:57 dcook In that case, it doesn't matter if it's plack or not plack 07:57 dcook Because you're creating a persistent process by running that snippet 07:57 dcook Well not persistent exactly.. 07:57 dcook But you create the forking server essentially 07:58 mtj yep, understood 07:58 dcook In any case, I reckon we should just do Joonas's fix hehe 07:59 dcook Hmm I think the L1 cache issue will still be a problem with the SIP server, but I'll have to look at that one another day 08:00 dcook Oh the bug report has been updated.. 08:05 ashimema Mornin' 08:06 ashimema adding a regression test does look challenging 08:08 dcook I was just replying to your comment hehe 08:08 dcook Another reason why? 08:08 dcook First 5 tries I got errors 08:08 dcook Now I'm running the same snippet another 5 times and no errors 08:08 ashimema be interesting to se your reply.. 08:09 dcook I'm going to try a few more things and then finalize that reply 08:09 ashimema I've not looked into testing it in great detail yet.. but I thought it might be challenging.. hense my comment of 'if at all possible'.. hense if people generally think it's not possible that's ok.. but if anyone wants to try I'd be really happy 08:09 ashimema :) 08:10 dcook I really want to haha but I don't think I've got it in me 08:10 dcook I ran into this problem with the SIP server and I was tearing my hair out 08:10 ashimema so the issue is that two processes end up using the same socket connection right.. 08:10 dcook I was praising Joonas from my head to my feet this morning 08:10 ashimema and that leads to protocol errors 08:10 dcook Looks like 08:10 dcook At least in theory 08:10 dcook And I could see that 08:10 dcook Because if you think about it.. 08:11 dcook I mean I've written a number of servers and totally made that mistake 08:11 ashimema it worries me that neither module has been maintained since 2017 08:11 ashimema though.. `if it works why change it` 08:11 dcook Have 2 processes with the same socket connection, and process 1 writes and tries to read, but process 2 reads first and gets the response for proess 1's write 08:11 dcook Yeah, I noticed that too and wondered 08:11 dcook I figure memcached is still a big name, but it's probably lost a lot of ground to redis 08:12 dcook And whatever the other one is 08:12 ashimema mmm, makes total sense that sharing a socket is bad 08:12 dcook In theory, we could re-write our code to still use Cache::Memcached::Fast 08:12 ashimema or rather.. could be bad.. I don't know the innards of the comms protocol used by memcached to be honest.. but yeah.. it rings out as 'could be true' 08:12 dcook But I'd trust Cache::Memcached::Fast::Safe more than us 08:12 ashimema me to 08:13 dcook But scratching my head as to why I can't reproduce this problem now lol 08:13 ashimema also.. I wonder about the santizer stuff in ::Safe.. whether we should have been worrying about that side of things before now too 08:14 dcook ashimema: I swear sometimes we share the same brain 08:14 dcook I was wondering the same thing.. 08:15 dcook And I just had a bit of a brainwave 08:15 ashimema we could plausably roughly copy the forking test from Cache::Memcached::Fast::Safe and adapt it to Koha::Cache I think 08:15 dcook ashimema: I was thinking about that a bit too 08:15 dcook But as for testing... 08:15 ashimema hehe.. it's sort of testing by side effect rather than testing the race condition itself.. but I'm OK with that.. 08:15 dcook Joonas's code reproduces a particular situation by kind of guessing that it'll break 08:16 dcook And I was just thinking... we could probably do a better testing 08:16 dcook better test* 08:16 * dcook ponders 08:17 ashimema it's hard though isn't it.. we need to get the timing just right in the test to cause a certain read/write cross fork scenario.. one which I'm not even sure of the out of order nature yet myself.. 08:17 dcook I was just thinking that 08:17 dcook So I'm looking into the code from the snippet first 08:18 dcook Depending on how low we need to go down, we might be able to simulate the timing 08:19 dcook Although that's probably optimistic 08:19 dcook check_api_auth is... a little over 200 lines of code.. 08:19 ashimema indeed 08:20 dcook Hits Version twice in a row... 08:21 ashimema :( 08:21 magnuse dcook++ for staying late 08:21 dcook Cheers, magnuse 08:22 dcook I had to take a few hours off in the middle of the day, so working late anyway heh 08:22 dcook Got other things I probably should be working on right now, but this particular issue has bothered me for a while, and really keen to solve it 08:22 dcook Also hi ^_^ 08:22 magnuse :-) 08:22 dcook Ok I'm going to try writing a more reliable test.. 08:22 magnuse don't let me interrupt the flow (any more than i alreadu did) 08:25 * ashimema doesn't understand how comparing server_versions before and after a fork actually tests this thing... 08:25 * ashimema is sure he's missing something there.. 08:27 dcook Oop.s Family emergency so I think I might be out again. 08:29 ashimema have a good evening dcook. 08:44 mtj i tried poking at the cache bug a few ways, but it seems very subtle 08:44 paxed heisenbug 08:45 ashimema indeed 08:45 paxed i'm not sure you can conclusively test for (regression of) that kind of bug 08:45 ashimema I believe it's there.. sure I've also seen it very randomly but infrequently enough that I've always put it down to fluke situation 08:45 mtj running the snippet with a perl -d:Trace , seems to slow the execution down enough that the bug does not occur 08:47 mtj also, adding a syspref lookup to the loop, seems to stop the bug occuring too 08:47 mtj http://paste.koha-community.org/14830 08:47 ashimema what we need to do to test it really is to slow down memcached so our perl hits it whilst previous operations are still taking place 08:47 dcook I'm still semi here heh 08:48 dcook mtj: If you take out those two sysprefs lookups, I'd guess the bug might not happen either 08:48 dcook mtj: I can't even reproduce the bug anymore with the original snippet 08:49 mtj dcook: the bug happens as expected, when removing the lookups 08:49 dcook Oooh really? Interesting 08:49 dcook I don't know why it doesn't happen for me anymore :S 08:50 dcook Ha, and now it just happened again 08:50 dcook undef this time instead of the wrong value though 08:51 mtj seems increasing the threads provokes the bug more 08:53 dcook Makes sense 08:54 dcook Although I would quibble and say increasing the child processes provokes the bug more heh 08:54 dcook I think Joonas's use of the $threads variable name is misleading 08:55 dcook I've got to run, but please update the bug report with anything interesting. I'll take another look tomorrow. 08:55 dcook ciao #koha. Missed you folks ;) 09:47 mtj ^ ah yes, a heisenbug is what meant 11:34 oleonard Hi #koha 11:41 huginn News from kohagit: Bug 22037: (QA follow-up) Correct misleading comment <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=766814ffa3c4592b9b7dcde83873ef12e796ae68> 11:41 huginn News from kohagit: Bug 23597: Add missing reserved query parameters to GET /holds <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=410e9bc0e88007cdff850afed83ee55a240a7517> 11:41 huginn News from kohagit: Bug 23575: Template error causes item search to be submitted multiple times <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=075261645e1650629038c9a09e8d9e387bcc5474> 11:41 huginn News from kohagit: Bug 22037: (QA follow-up) Implement use of CHARGES_GUARANTEES <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=9a5e519d70c168bb44cfea2d8a4490fad9049ab8> 11:41 huginn News from kohagit: Bug 22037: Block SIP checkout if guarantees have debt <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=2e91d33381cb29da30bfe16f022f1d07fe2b327f> 11:45 magnuse hiya oleonard 12:04 magnuse kia ora cait 12:15 koha-jenkins Project Koha_Master_D9 build #872: UNSTABLE in 31 min: https://jenkins.koha-community.org/job/Koha_Master_D9/872/ 12:48 koha-jenkins Project Koha_Master_U18 build #356: SUCCESS in 32 min: https://jenkins.koha-community.org/job/Koha_Master_U18/356/ 12:51 * cait waves 13:02 tcohen hi 13:12 oleonard Hi cait and tcohen 13:13 * cait waves 13:20 caroline_crazycatlady Good morning everyone! 13:20 magnuse kia ora caroline_crazycatlady 13:21 cait hi caroline_crazycatlady and magnuse ! 13:22 cait tcohen pm :) 13:49 huginn News from kohagit: Bug 20691: (QA follow-up) Fix self-reg <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=e7a84dacfec76325819e39c5ef0dacf5ff1ffdea> 13:59 huginn News from kohagit: Bug 21390: Send registration verification emails immediately <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=36c734e68438b40401d0eee8ae823ae05da7ce79> 13:59 huginn News from kohagit: Bug 21390: Send registration verification emails immediately <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=957d583d2efce66e31fe05f229fda91c58324bc2> 13:59 huginn News from kohagit: Bug 21852: Add more columns and column configuration to overdues report <http://git.koha-community.org/gitweb/?p=koha.git;a=commitdiff;h=44049ad57e1928f2870abed15e4659f8357c2f19> 14:01 cait tcohen++ ashimema++ 14:01 cait maryse++ 14:02 cait moving bug 21390 14:02 huginn Bug http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=21390 enhancement, P5 - low, ---, koha-bugs, Pushed to master , Send self registration verification emails immediately 14:02 * ashimema is excited to see lots of holds api's happening.. and looking forward to seeing the ux/ui using them 14:02 ashimema :) 14:02 ashimema pleasure 14:02 * ashimema gets his hits from pushing these days.. line 'em up folks ;) 14:03 cait :) 14:04 cait I'll try to feed your queue a bit next week 14:19 wizzyrea hi 14:19 oleonard Hi wizzyrea 14:19 koha-jenkins Yippee, build fixed! 14:19 koha-jenkins Project Koha_Master_D9 build #873: FIXED in 30 min: https://jenkins.koha-community.org/job/Koha_Master_D9/873/ 14:19 wizzyrea why would zebra have stopped understanding mc-ccode as a limit 14:41 lukeG *waves* 14:51 koha-jenkins Project Koha_Master_U18 build #357: SUCCESS in 32 min: https://jenkins.koha-community.org/job/Koha_Master_U18/357/ 14:52 magnuse huh, why would the sip2-server start to say this after a restart: unable to locate Koha configuration file koha-conf.xml at /usr/share/koha/lib/C4/Context.pm line 244, <STDIN> line 1. 14:55 eythian magnuse: a chance for you to fix the error message so it describes the actual filename with path that it's looking for 14:56 magnuse clever! :-) 14:57 magnuse any hunches what it might be looking for? 14:57 eythian not a clue sorry. My guess would be environment weirdness so that it's looking in the wrong place. 14:58 * eythian has developed the religion of supplying verbose error messages with enough information in them to actually diagnose the source of the issue. 14:59 magnuse that does not sound like a stupid idea ;-) 15:05 reiveune bye 15:22 koha-jenkins Project Koha_Master_D9 build #874: SUCCESS in 30 min: https://jenkins.koha-community.org/job/Koha_Master_D9/874/ 15:51 oleonard tcohen still around? 16:07 magnuse soo, as far as I can tell, during the SIP2 Login process, everything is ok until this line: my $dbh = C4::Context->dbh; in C4::Auth::check_api_auth(). then it just dies silently. but why? 16:31 wizzyrea cait about? 16:31 wizzyrea oh, no. 16:44 wizzyrea cait++ 16:49 caroline_crazycatlady any cataloguing geeks around? 16:53 oleonard Maybe you should ask, caroline_crazycatlady, in case people are afraid they're not geeky enough to answer 16:54 caroline_crazycatlady I have questions regarding subdivision authority records (fields 18X), how to use them 16:55 caroline_crazycatlady I know Koha doesn't support that type of authority record, although there seems to be an opening, looking at the code in bug 21697 16:55 huginn Bug http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=21697 enhancement, P5 - low, ---, koha-bugs, NEW , Free-floating subdivision cannot be manage correctly in Koha 18:46 magnuse figured out my SIP2-problem, will submitt a patch after i catch some sleep 19:48 koha-jenkins Project Koha_18.11_D8 build #165: UNSTABLE in 23 min: https://jenkins.koha-community.org/job/Koha_18.11_D8/165/ 20:17 koha-jenkins Project Koha_18.11_U18 build #158: UNSTABLE in 29 min: https://jenkins.koha-community.org/job/Koha_18.11_U18/158/ 20:44 koha-jenkins Project Koha_18.11_D9 build #166: UNSTABLE in 26 min: https://jenkins.koha-community.org/job/Koha_18.11_D9/166/ 20:48 nuentoter o7, question, I'm using koha 19.05.03.000 - I seem to have some random checkouts, that simply don't register in the system. I will checkout a book to someone, and it will show it as checked-out. The next day I will search for that book and it is available with no circulation history. 20:49 nuentoter got my coverflow working well btw, it was a stupid mistake on my end or improper syntax in the plugin options, one too many spaces 20:52 davidnind[m] nuentoter: Excellent! Will make the updates needed to the docs in the next day or so. 20:55 nuentoter any idea of where to start looking for where my missing checkouts are going? 21:01 caroline_crazycatlady nuentoter: The first place I'd look is in the logs (in tools > Log viewer) 21:02 caroline_crazycatlady I had that problem with a client once and I was telling her that she was the one returning the items and it ended up being because she was doing inventory and had checked the box to return items >_< 21:06 nuentoter im looking through logs now and i see nothing abnormal. the books that were checked out but not appearing in system as checked out are completely missing from logs....... I'm gonna have to look over shoulders for a couple days i think to rule out human error 21:08 caroline_crazycatlady so you have no logs of those books being checked out? 21:08 koha-jenkins Project Koha_18.11_D8 build #166: STILL UNSTABLE in 23 min: https://jenkins.koha-community.org/job/Koha_18.11_D8/166/ 21:08 nuentoter only my checking them out then back in today so that they appeared in their circ history to keep statistics correct. but it was returned today after being checked out last tuesday 21:09 nuentoter which was the first checkout. 21:13 caroline_crazycatlady nuentoter: just rephrasing so I understand. The log only show your checkout and checkin from today, but not last tuesday's checkout and today's checkin? 21:20 nuentoter correct 21:21 caroline_crazycatlady huh... so the logs are logging... Do you have any proof that the book was actually checked out at one point last week? 21:31 nuentoter a pretty good employees word lol 21:37 koha-jenkins Project Koha_18.11_U18 build #159: STILL UNSTABLE in 28 min: https://jenkins.koha-community.org/job/Koha_18.11_U18/159/ 22:04 koha-jenkins Project Koha_18.11_D9 build #167: STILL UNSTABLE in 27 min: https://jenkins.koha-community.org/job/Koha_18.11_D9/167/ 22:15 caroline_crazycatlady good night everyone!