Oh, that could most definitely be a huge contributing factor to the
slowdown. What's going on there is the backend wants to set the
next/previous comic reference for the comic before returning it. These are
used by the matching buttons on the comic details page (this is only done
when getting a single comic). And if that comic is in a series with a lot
of comics, then it's going to load them all, sort them, and then find the
next and previous comic. That's apparently a very expensive operation. I'll
open a ticket to disable it for now until we can come up with a better
solution.
On Thu, Dec 19, 2019 at 4:42 PM Redacted sender bareheiny for DMARC <
dmarc-noreply@xxxxxxxxxxxxx> wrote:
Huh…that’s a different way of doing it. Usually I watch the network tab,
then save the har file – but Chrome doesn’t seem to be saving the file
properly. I’ll look at the console stuff later.
For now, here’s a brain dump – I haven’t structured this or checked it for
tone….so it may come across as grumpy, but it’s literally a bunch of
semi-related, but unstructured comments / thoughts:
In the meantime, what I’m seeing in the CX log are delays between
actions. Using log extracts for a specific comic:
2019-12-19 09:29:13.469 INFO 4660 --- [nio-7171-exec-1]
o.c.controller.library.ComicController : Getting cover for comic: id=102
2019-12-19 09:29:13.470 DEBUG 4660 --- [nio-7171-exec-1]
o.comixed.service.library.ComicService : Getting comic: id=102
2019-12-19 09:29:13.985 DEBUG 4660 --- [nio-7171-exec-1]
o.comixed.service.library.ComicService : Getting all comics for series:
003 Wonder Woman 008
2019-12-19 09:29:17.205 DEBUG 4660 --- [nio-7171-exec-1]
o.comixed.service.library.ComicService : Searching 1 comic for next and
previous issues
2019-12-19 09:29:17.205 DEBUG 4660 --- [nio-7171-exec-1]
o.c.controller.library.ComicController : Looking for cached image:
hash=F1B8C1A3FB76AFF61E13FD9ECA755525
2019-12-19 09:29:17.245 DEBUG 4660 --- [nio-7171-exec-1]
o.c.service.library.PageCacheService : Loading cached image content:
1431822 bytes
2019-12-19 09:29:17.328 DEBUG 4660 --- [nio-7171-exec-1]
o.c.controller.library.ComicController : Returning comic cover:
filename=Wonder Woman 008 (2007) (digital-Empire) 001.jpg size=1431822
2019-12-19 10:30:46.908 DEBUG 4660 --- [nio-7171-exec-1]
o.comixed.service.library.ComicService : Getting all comics for series:
100 Girls
2019-12-19 10:30:47.663 DEBUG 4660 --- [nio-7171-exec-1]
o.comixed.service.library.ComicService : Searching 7 comics for next and
previous issues
There are 8 log records that contain “Getting all comics for series: 100
Girls”…with one exception, they’re all closely followed by a “Searching 7
comics for next and previous issues” message. The logs for 100 Girls start
at 9.29 and finish at 9.46…that’s close to 10 minutes to get several cover
images.
Why is CX looking for all comics in the series?
CX also seems to be looking for the next and previous issues, although I’m
not sure what series this refers to.
In between the log records above, CX is also getting covers for other
issues…but it’s doing the same actions: getting cover, getting comic id,
getting all comics, looking for next and previous etc., and this will be
repeated 100 times (I’ve set CX to return 100 comics per page).
What’s the difference between getting the cached covers in the library
view, vs. getting covers on the import screen? The import screen returns
100 thumbnails within 10 seconds max (guesstimate…could be quicker or
slower, but definitely nowhere near 1 minute). I can hop from page to page
to page on the import screen with acceptable delays….while the library page
took 1 hour to go from page 1 to 2 to 3 and back to 1.
*From:* comixed-dev-bounce@xxxxxxxxxxxxx <comixed-dev-bounce@xxxxxxxxxxxxx>
*On Behalf Of *Darryl L. Pierce
*Sent:* Thursday, 19 December 2019 3:23 PM
*To:* comixed-dev@xxxxxxxxxxxxx
*Subject:* [comixed-dev] Re: Cover caching.
Here's an article I found for saving the Chrome browser logs to disk:
https://support.shortpoint.com/support/solutions/articles/1000222881-save-google-chrome-browser-s-console-file
On Wed, Dec 18, 2019 at 8:50 PM bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
wrote:
Got a video - is 1 hour and approx 900MB zipped.
That one hour consists of navigating to the library, waiting for page 1 to
render fully (all 100 thumbnails loaded and displayed) navigating to page 2
and waiting for it to render (quicker than 1), then page 3 (slow again) and
back to page 1.
I’ll check the Chrome had logs, and if that saved ok I’ll have a full set
(cx logs, chrome logs and video).
I’ve split off 10k comics, and am importing those into a new database to
see if the number of comics is the problem. I did notice the thumbnails
for the import selection loaded quicker than the cached covers above.
On 18/12/2019, at 15:10, bareheiny <bareheiny@xxxxxxxxx> wrote:
Same behaviour with the surface and the drive directly connected.
Getting a video to accompany logs - what’s the best way to share the link
once I’ve got it all sorted out?
On 18/12/2019, at 10:29, bareheiny (Redacted sender bareheiny for DMARC) <
dmarc-noreply@xxxxxxxxxxxxx> wrote:
No, it’s not a time-out (although I did see one post cancelled)....it
literally takes a good six plus minutes to display the first 100 comics.
CX is set to display 100 comics at minimum size – pn first navigation to
the library page, the first six (or so) covers display within seconds.
Then covers in placeholders 50-60 may display, then the first six
disappear (cover images no longer show, and placeholder size is minimal).
Then the remaining covers are slowly populated...and finally the first six
appear again.
The CX log shows the covers are being requested...but it looks like it’s
in bursts of maybe 10 or so, but the Chrome log shows all 100 content
requests are fired at the same time.
I doubt I’m explaining it properly >_< I may need to grab a video...but
can only do that on my surface, which isn’t recognising external drives at
the moment.
It looks like my har log is corrupt, so I’ll need to try again tonight.
Hardware wise, my library is on a 4TB USB3.0 drive, connected to a
destktop pc running Windows 10 pro. I think it’s an i3 or i4, with 4GB
memory yadda yadda yadda. It’s only used as a media server, so it’s not
doing much at any given time.
Once I get the surface sorted out, I’m going to connect the 4TB drive to
it and see if CX behaves any differently.
*From: *Darryl L. Pierce <mcpierce@xxxxxxxxx>
*Sent: *Wednesday, 18 December 2019 2:41 AM
*To: *comixed-dev@xxxxxxxxxxxxx
*Subject: *[comixed-dev] Re: Cover caching.
A six minute delay would timeout the request and the frontend would
abandon trying to display the image. Is that what you're seeing?
But, still, even with H2 (rather than an external RDBMS like MySQL) and
over 10k comics, I've never seen a delay even close to that. I think the
longest I've seen is about 15-20 seconds between a set of covers being
loaded and then another set rendering all at once. But never on the order
of minutes.
What is the hardware that you're using, specifically? Do you find the
browser behaving sluggishly in other ways? I have a laptop (Dell Inspiron
15 5000) that, when I've been using it for a while, starts drastically
slowing down due to the poor thermal venting from the chassis. It'll be
fast, fast fast, then get hot and go slow (or stop entirely) until it cools
down, then goes fast again. Could there be something similar affecting your
Surface?
Does anybody else see that level of delay?
On Tue, Dec 17, 2019 at 4:45 AM bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
wrote:
As an fyi, I’ve captured some logs - just need to look at them (hopefully
tomorrow).
I’m definitely seeing delays of up to 6 mins between a cached cover being
requested and it being returned to chrome.
On my surface, with a local copy of 400 random comics CX behaves as I’d
expect to - minor delays, but nothing more than a few seconds. I’m
guessing the size of the library plays a part in the load time issues.
On 17/12/2019, at 12:57, bareheiny (Redacted sender bareheiny for DMARC) <
dmarc-noreply@xxxxxxxxxxxxx> wrote:
Back to cover caching – is it likely to by affected by the way the drive
is accessed?
All of my comics are stored on an external drive connected to a desktop
machine. More often than not, I access the drive via network share from my
Surface – I make sure the drive letter is the same, so both the desktop and
network share are accessed via Z.
I’ve noticed that CX running on my Surface (with a local copy of the
database) doesn’t seem to show, or cache, covers.
*From: *bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
*Sent: *Tuesday, 17 December 2019 9:39 AM
*To: *comixed-dev@xxxxxxxxxxxxx
*Subject: *[comixed-dev] Re: Cover caching.
Logging parameter I’m using: --logging.level.org.comixed=DEBUG >
Z:\Comics\.comiXed\comiXed.log
*From: *bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
*Sent: *Tuesday, 17 December 2019 9:37 AM
*To: *comixed-dev@xxxxxxxxxxxxx
*Subject: *[comixed-dev] Re: Cover caching.
I picked up the new pre-release, and as usual have questions.
When logging is enabled, where does it get output to, and would it
override the piping to a file parameter used in the bat file I use to start
CX?
Also, what sort of additional logging should I expect to see?
On 16/12/2019, at 16:50, Darryl L. Pierce <mcpierce@xxxxxxxxx> wrote:
I'm hoping that, with the logging code I put in today, you'll be able to
capture some imperical data from the browser and post it for us to look
over an figure out what's going on.
On Sun, Dec 15, 2019 at 4:08 PM bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
wrote:
Sorting may not be an issue – lack of sleep over the weekend is causing a
few cognitive issues.
Ignoring the donut chart page, I’m still seeing weird behaviour when
navigating library pages.
Starting on page one, the comic count (bottom left of the screen) starts
at 100 and slowly increases...at the same time, covers are loaded
(slowly...which is odd, as they have been cached before).
When navigating to another page of the library (usually page 2), nothing
happens for a period of time...after which the cover panes are cleared
(i.e. the images from page 1 are removed, and the placeholder panes are
shown). The comic count resets to 100 and the covers are slowly loaded.
The upshot of this is that navigating the library is painfully slow ☹
*From: *Darryl L. Pierce <mcpierce@xxxxxxxxx>
*Sent: *Monday, 16 December 2019 2:20 AM
*To: *comixed-dev@xxxxxxxxxxxxx
*Subject: *[comixed-dev] Re: Cover caching.
For the sorting, I'm guessing there's likely still a bug in that code. :-/
On Sun, Dec 15, 2019 at 4:01 AM bareheiny <dmarc-noreply@xxxxxxxxxxxxx>
wrote:
Not sure I’m seeing any increase in load times...but I am seeing odd
behaviour in the library counts.
For example, the count gets up to 48k when fully loaded (on the doughnut
chart page), navigating to the library page changes it to 100....which
slowly increases.
Navigating to page 2 puts the count back to 100....and takes a long time
to load.
I’ll keep digging when I get some time, but can I confirm this is not what
is expected?
I had anticipated the covers to be cached slowly (seems to be happening),
but the decreased load times have t materialised.
I’m also seeing odd behaviour in the library load...I default to sort by
date loaded, but the comics are being loaded in series groups - with log
messages to that effect.
--
Darryl L. Pierce <mcpierce@xxxxxxxxx>
"Le centre du monde est partout." - Blaise Pascal
"Let's try and find some point of transcendence and leap together." - Gord
Downie
--
Darryl L. Pierce <mcpierce@xxxxxxxxx>
"Le centre du monde est partout." - Blaise Pascal
"Let's try and find some point of transcendence and leap together." - Gord
Downie
--
Darryl L. Pierce <mcpierce@xxxxxxxxx>
"Le centre du monde est partout." - Blaise Pascal
"Let's try and find some point of transcendence and leap together." - Gord
Downie
--
Darryl L. Pierce <mcpierce@xxxxxxxxx>
"Le centre du monde est partout." - Blaise Pascal
"Let's try and find some point of transcendence and leap together." - Gord
Downie
