<html><body><div>Hi Chris,</div><div><br data-mce-bogus="1"></div><div>Thank you for the quick answer - very much appreciated.</div><div><br data-mce-bogus="1"></div><div>I have made some further discoveries and actually see the degradation on the Magma server (vs in my client image). I am doing some tests with SSD disk, commit sizes and will update this thread more about this as I progress and write it up on a blog.</div><div>I think this is key to the performance:</div><div><meta http-equiv="content-type" content="text/html; charset=utf-8"><pre class="verbatim" style="font-family: 'Dejavu Sans Mono', Monaco, 'Lucida Console', monospace; background-color: #f3f3f3; padding: 0.5em; white-space: pre-wrap; color: #333333; font-size: 12.8px; font-style: normal; font-variant-ligatures: normal; font-variant-caps: normal; font-weight: 400; letter-spacing: normal; orphans: 2; text-align: start; text-indent: 0px; text-transform: none; widows: 2; word-spacing: 0px; -webkit-text-stroke-width: 0px; text-decoration-style: initial; text-decoration-color: initial;" data-mce-style="font-family: 'Dejavu Sans Mono', Monaco, 'Lucida Console', monospace; background-color: #f3f3f3; padding: 0.5em; white-space: pre-wrap; color: #333333; font-size: 12.8px; font-style: normal; font-variant-ligatures: normal; font-variant-caps: normal; font-weight: 400; letter-spacing: normal; orphans: 2; text-align: start; text-indent: 0px; text-transform: none; widows: 2; word-spacing: 0px; -webkit-text-stroke-width: 0px; text-decoration-style: initial; text-decoration-color: initial;">68.9% {11294ms} [] MaHashIndex>>add:at:
25.1% {4112ms} MaHashIndexRecord>>canAdd:
...
24.2% {3968ms} MaHashIndex>>selectRecord:
24.0% {3931ms} MaHashIndex>>readRecord:at:
...
17.2% {2814ms} MaHashIndex>>writeRecord:
17.1% {2799ms} MaFileRecordBroker>>writeFrom:at:</pre></div><div><br data-mce-bogus="1"></div><div>But this has to wait since I have run into something very annoying (and I cannot understand how my image became corrupted):<br></div><div>Basically, I have a MagmaSession disconnect hanging on (this time I tried primDisconnect, the stack is almost the same on disconnect):</div><div><br data-mce-bogus="1"></div><div>Mutex>>critical:<br>MaNetworkServerLink>>submit:<br>[] in [] in [] in MagmaSession>>submit:to:<br>[] in [] in BlockClosure>>maOn:do:on:do:on:do:<br>BlockClosure>>on:do:<br>[] in BlockClosure>>maOn:do:on:do:on:do:<br>[] in [] in BlockClosure>>maOn:do:on:do:<br>BlockClosure>>on:do:<br>[] in BlockClosure>>maOn:do:on:do:<br>BlockClosure>>on:do:<br>BlockClosure>>maOn:do:on:do:<br>BlockClosure>>maOn:do:on:do:on:do:<br>[] in [] in MagmaSession>>submit:to:<br>BlockClosure>>ensure:<br>CursorWithMask(Cursor)>>showWhile:<br>[] in MagmaSession>>submit:to:<br>Mutex>>critical:<br>MagmaSession>>submit:to:<br>[] in [] in MagmaSession>>primDisconnect<br>MagmaSession>>linksDo:<br></div><div><br data-mce-bogus="1"></div><div>The mutex is held by a suspended Process in Debugger class>>morphicOpenOn:context:label:contents:fullView:</div><div><br data-mce-bogus="1"></div><div>I've tried to resume the process but MethodContext>>cannotReturn: is coming back to me and some poking around tells me that the title of the debugger was: "'MaObjectSerializationUserError: No createProxyBlock specified. See MaObjectSerializer>>toCreateProxies:'"</div><div>Now, how can I break this Mutex to clean up the MagmaSession? </div><div><br></div><div>If I try to terminate the process - it simply goes into suspend.</div><div>Since I am doing changes, testing and ALT-. to break long commits or other vicious cycles - it would be good to know how to drop all Magma tracked objects from memory (i.e. all "Magma state", oids etc) and reset the database? </div><div>What is the best strategy to do this?</div><div><br></div><div>Cheers,</div><div>Tim</div><div><br data-mce-bogus="1"></div><div>Den 22 maj 2018 kl. 15:06 skrev Chris Muller <asqueaker@gmail.com>:<br><br></div><div><blockquote type="cite"><div class="msg-quote"><div class="_stretch"><span class="body-text-content">Hi!<br><br>First, thanks for the great email, the detail and for your deep<br>exploration and usage of the tools provided by Magma in the first<br>place, I'm very impressed!<br><br>To cut to the chase about WriteBarrier: yes. WriteBarrier is meant<br>for stable bulk-load's you want to perform faster. The trade-off of<br>using it is, if you need to do debugging, it's harder to access the<br>instances via, i.e., TKEntry allInstances select: [ : each | .... ],<br>because they're not instances of TKEntry, but of TKEntry*.<br><br>Is this database shared with other real-time users? If not, I would<br>experiment committing at least 500 or 1000 or 2500 or 5000 or 10000<br>per commit.<br><br>There is a logarithmic rate of degradation to adding new objects<br>proportional to the number of unique objects already in a<br>MagmaCollection or MagmaCollectionIndex. The rate of degradation of<br>duplicate objects is *linear*, but it doesn't sound like your model is<br>affected by that.<br><br>You were very smart to override #isImmutableInMagma on your TEEntry's,<br>given how many would be clogging up the readSet unnecessarily due to<br>their archival nature (unchanging).<br><br>Those big Dictionary's of the MaSharedObjectsBroker will still slow<br>down the changed-detection of your commits whenever you didn't add<br>something. Because that means their size won't have changed, and nor<br>will their contents, but the only way Magma could know that is by<br>enumerating them. And, if they DID change, then they have to be<br>committed. So, there is a trade-off there, but this is something I<br>would like to think about further -- a few years ago a made an<br>advanced feature that could help with this, but I need to research it.<br><br>Besides the sizes of those Dictionary caches, you'd want to ensure<br>those objects IN them are not in the readSet, if possible.<br>WriteBarrier can definitely help with that for objects which are not<br>#isImmutableInMagma. Some of the lower level objects don't can't take<br>advantage of the WriteBarrier (see #maAllowsWriteBarrier), but normal<br>objects like the ones from your domain can.<br><br>WbDictionary, et al. no longer apply after Closures were redone a few<br>years ago which disallowed Array's from being made uncompact,<br>something required for the WriteBarrier to be able to swap its class<br>via #primitiveChangeClassTo:.<br><br>I can help you optimize further if you include a MessageTally profile<br>dump next time.<br><br>Cheers!<br> Chris<br><br><br>On Tue, May 22, 2018 at 8:28 AM, Tim Käck <timkack@icloud.com> wrote:<br><blockquote type="cite" class="quoted-plain-text">Hi all,</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">First let me explain how my application works (and excuse this lengthy post):</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">It processes a log file and create TKEntry’s (i.e. smalltalk objects representing the log entry).</blockquote><blockquote type="cite" class="quoted-plain-text">Since several entries contains the same values for several fields (example: paths, userIds etc) I have LRUCache infront of a MaSharedObject broker (Thanks Chris for this!).</blockquote><blockquote type="cite" class="quoted-plain-text">The reasons are two fold:</blockquote><blockquote type="cite" class="quoted-plain-text">1) The LRUCache makes it faster to lookup keys when I have a lot of log data on the heap</blockquote><blockquote type="cite" class="quoted-plain-text">2) The MaSharedObject broker prevents having the same value stored many times and by that use up valuable heap usage.</blockquote><blockquote type="cite" class="quoted-plain-text">Lets call this TKMaLRU<mumble>Cache - and there are several of these depending on their scope and content.</blockquote><blockquote type="cite" class="quoted-plain-text">The <mumble> part is because they have some specialities to what they store (literals, dates, times etc).</blockquote><blockquote type="cite" class="quoted-plain-text">These TKEntry’s are stored in an OrderedCollection but now when I am “magma:fying” the application, I have decided to use a MagmaCollection (because we talk about 4-5 million entries).</blockquote><blockquote type="cite" class="quoted-plain-text">Let call this a TKLog.</blockquote><blockquote type="cite" class="quoted-plain-text">The TKLog is stored in a TKProject, which in turn is stored in my root of my Magma database - in my grand TKProjects singleton object.</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">So, to summarise the architecture somewhat:</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">TKProjects contain TKProject’s, that contain TKLog’s, where each contains a collection of TKEntry’s.</blockquote><blockquote type="cite" class="quoted-plain-text">The TKProjects contain some TKMaLRU<mumble>Caches that are global and shared between projects.</blockquote><blockquote type="cite" class="quoted-plain-text">The TKProject contain some TKMaLRU<mumble>Caches that are shared across all TKLogs</blockquote><blockquote type="cite" class="quoted-plain-text">The TKLog contains some TKMaLRU<mumble>Caches that are only relevant for that specific log.</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">Here is how the commit mechanism work:</blockquote><blockquote type="cite" class="quoted-plain-text">1) MagmaSession begin</blockquote><blockquote type="cite" class="quoted-plain-text">2) Read and process log entry into a TKLog entry (i.e. also lookup or add values to above mentioned MaSharedObject brokered caches)</blockquote><blockquote type="cite" class="quoted-plain-text">3) repeat step 2) X times</blockquote><blockquote type="cite" class="quoted-plain-text">4) MagmaSession commitAndBegin.</blockquote><blockquote type="cite" class="quoted-plain-text">5) Repeat 2 - 4 until all log has been processed.</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">Now, in step 3 - I have tested to commit every TKEntry, every 50 TKEntry and every 150 TKEntry - but the results are somewhat disappointing.</blockquote><blockquote type="cite" class="quoted-plain-text">Looking at the client side report - it seems to suggest that "Time to Download Full Response” is taking longer and longer:</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">Time to Download Full Response</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">End Time Name Count min max sum mean last</blockquote><blockquote type="cite" class="quoted-plain-text">-------- ---- ----- --- --- --- ---- ----</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:24:56.756581+02:00 Time to Download Full Response 98 1439.0 4269.0 197938.0 2019.77551 1703</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:29:56.756864+02:00 Time to Download Full Response 97 1575.0 3388.0 200137.0 2063.26804 1817</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:34:56.759649+02:00 Time to Download Full Response 96 1325.0 3533.0 197440.0 2056.66666 2039</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:39:56.761206+02:00 Time to Download Full Response 95 1134.0 3539.0 193899.0 2041.04210 2061</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:44:56.764136+02:00 Time to Download Full Response 92 1537.0 4060.0 193165.0 2099.61956 1994</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:49:56.772738+02:00 Time to Download Full Response 91 1672.0 4183.0 192310.0 2113.29670 1998</blockquote><blockquote type="cite" class="quoted-plain-text"><…snip…></blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:29:57.823266+02:00 Time to Download Full Response 71 2388.0 5202.0 213569.0 3008.01408 3175</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:34:57.825258+02:00 Time to Download Full Response 61 2829.0 5700.0 211781.0 3471.81967 3197</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:39:57.825924+02:00 Time to Download Full Response 55 2385.0 6392.0 193054.0 3510.07272 2965</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:44:57.828316+02:00 Time to Download Full Response 56 2839.0 6606.0 201693.0 3601.66071 3249</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:49:57.830572+02:00 Time to Download Full Response 62 1870.0 6230.0 207707.0 3350.11290 3543</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:54:57.832358+02:00 Time to Download Full Response 58 2790.0 6422.0 199911.0 3446.74137 3215</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T07:59:57.834803+02:00 Time to Download Full Response 61 2658.0 5832.0 208315.0 3415.0 3839</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:04:57.841518+02:00 Time to Download Full Response 60 2266.0 4742.0 199554.0 3325.9 3122</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:09:57.842645+02:00 Time to Download Full Response 57 2439.0 5669.0 190848.0 3348.21052 3782</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:14:57.843325+02:00 Time to Download Full Response 56 2183.0 5850.0 191640.0 3422.14285 3040</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:19:57.845536+02:00 Time to Download Full Response 56 2803.0 5767.0 196116.0 3502.07142 3225</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:24:57.846522+02:00 Time to Download Full Response 61 2653.0 5717.0 211016.0 3459.27868 3406</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:29:57.9646+02:00 Time to Download Full Response 54 2765.0 5772.0 186693.0 3457.27777 3277</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:34:57.967164+02:00 Time to Download Full Response 54 2970.0 5636.0 193700.0 3587.03703 3401</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:39:57.981221+02:00 Time to Download Full Response 55 2583.0 5411.0 197685.0 3594.27272 3607</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:44:57.981925+02:00 Time to Download Full Response 56 2664.0 5661.0 196917.0 3516.375 3829</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:49:57.982564+02:00 Time to Download Full Response 57 2854.0 6889.0 202831.0 3558.43859 3014</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:54:57.983894+02:00 Time to Download Full Response 63 2761.0 6190.0 214199.0 3399.98412 3226</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T08:59:57.990957+02:00 Time to Download Full Response 63 2796.0 5130.0 216577.0 3437.73015 3066</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:04:57.992464+02:00 Time to Download Full Response 55 2894.0 6478.0 200221.0 3640.38181 3300</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:09:57.994927+02:00 Time to Download Full Response 51 3173.0 5203.0 194755.0 3818.72549 3276</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:14:57.995991+02:00 Time to Download Full Response 55 3167.0 6066.0 205586.0 3737.92727 3432</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:19:57.998695+02:00 Time to Download Full Response 57 2840.0 6339.0 212726.0 3732.03508 3445</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:24:58.010041+02:00 Time to Download Full Response 53 2737.0 5854.0 203695.0 3843.30188 3212</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:29:58.011472+02:00 Time to Download Full Response 55 1893.0 5003.0 193155.0 3511.90909 3311</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:34:58.013342+02:00 Time to Download Full Response 53 2573.0 6791.0 194739.0 3674.32075 3588</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:39:58.016082+02:00 Time to Download Full Response 55 2810.0 5476.0 195984.0 3563.34545 3254</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">I also see a degradation over time on "Time waiting for MaCommitRequest requests"</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">End Time Name Count min max sum mean last</blockquote><blockquote type="cite" class="quoted-plain-text">-------- ---- ----- --- --- --- ---- ----</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:24:56.756627+02:00 Time waiting for MaCommitRequest requ... 98 1443.0 4291.0 199387.0 2034.56122 1706</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:29:56.756915+02:00 Time waiting for MaCommitRequest requ... 97 1583.0 3399.0 201187.0 2074.09278 1821</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:34:56.759692+02:00 Time waiting for MaCommitRequest requ... 96 1333.0 3538.0 199918.0 2082.47916 2047</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:39:56.761261+02:00 Time waiting for MaCommitRequest requ... 95 1143.0 3547.0 196105.0 2064.26315 2070</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:44:56.764175+02:00 Time waiting for MaCommitRequest requ... 92 1540.0 4449.0 195004.0 2119.60869 1999</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:49:56.77278+02:00 Time waiting for MaCommitRequest requ... 91 1678.0 4190.0 194502.0 2137.38461 2008</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:54:56.774304+02:00 Time waiting for MaCommitRequest requ... 89 1389.0 4015.0 190014.0 2134.98876 1858</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T21:59:56.777215+02:00 Time waiting for MaCommitRequest requ... 88 1731.0 4576.0 191360.0 2174.54545 2020</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-08T22:04:56.779026+02:00 Time waiting for MaCommitRequest requ... 88 1705.0 3551.0 191334.0 2174.25 1859</blockquote><blockquote type="cite" class="quoted-plain-text"><…snip…></blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:09:57.99499+02:00 Time waiting for MaCommitRequest requ... 51 3185.0 5210.0 195250.0 3828.43137 3286</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:14:57.996035+02:00 Time waiting for MaCommitRequest requ... 55 3174.0 6073.0 206588.0 3756.14545 3898</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:19:57.998772+02:00 Time waiting for MaCommitRequest requ... 57 2849.0 6346.0 213850.0 3751.75438 3455</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:24:58.010092+02:00 Time waiting for MaCommitRequest requ... 53 2740.0 5856.0 205350.0 3874.52830 3216</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:29:58.011514+02:00 Time waiting for MaCommitRequest requ... 55 1896.0 5259.0 196371.0 3570.38181 3315</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:34:58.013386+02:00 Time waiting for MaCommitRequest requ... 53 2582.0 6796.0 196473.0 3707.03773 3593</blockquote><blockquote type="cite" class="quoted-plain-text">2018-05-09T09:39:58.016132+02:00 Time waiting for MaCommitRequest requ... 55 2818.0 5485.0 196926.0 3580.47272 3268</blockquote><blockquote type="cite" class="quoted-plain-text">nil Time waiting for MaCommitRequest requ... 10 3125.0 4748.0 37967.0 3796.7 3511</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">This has led me to implement isImmutableInMagma on the TKEntry to keep the readSet low, but now I have run into a problem:</blockquote><blockquote type="cite" class="quoted-plain-text">The caches are based on Dictionaries and they can grow to 20000-30000 (or more) entries.</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">After all of this, my question is simple:</blockquote><blockquote type="cite" class="quoted-plain-text">Should I use a WriteBarrier capable object instead (I could not find a WbDictionary unfortunately)?</blockquote><blockquote type="cite" class="quoted-plain-text">In fact - how does WriteBarrier work in the context of Magma? I have set allowWriteBarrier: true when connecting to the Magma DB.</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">Cheers,</blockquote><blockquote type="cite" class="quoted-plain-text">Tim</blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text"><br></blockquote><blockquote type="cite" class="quoted-plain-text">_______________________________________________</blockquote><blockquote type="cite" class="quoted-plain-text">Magma mailing list</blockquote><blockquote type="cite" class="quoted-plain-text"><a href="mailto:Magma@lists.squeakfoundation.org" data-mce-href="mailto:Magma@lists.squeakfoundation.org">Magma@lists.squeakfoundation.org</a></blockquote><blockquote type="cite" class="quoted-plain-text"><a href="http://lists.squeakfoundation.org/mailman/listinfo/magma" data-mce-href="http://lists.squeakfoundation.org/mailman/listinfo/magma">http://lists.squeakfoundation.org/mailman/listinfo/magma</a></blockquote></span></div></div></blockquote></div></body></html>