Location-specific load times

Feel free to post bug reports here. I need exact, detailed steps showing me how I can re-create the bug on my machine, so give as much info and detail as possible.
DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Location-specific load times

Post by DeusExMachina »

As per e-mail, and PM, loading times on launch for the database was extraordinarily long for big venues, but it looked like we had that licked, if only coincidentally. However, while live today, and after numerous crashes in a row, one thing became apparent: when I am at home, and relaunch, the db scans in in about 30-45 seconds. At the venue, it can take as long as five minutes (or sometimes more!). This is very odd. Any idea what location-spcific issues might be causing this?

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Back home and back to 2 minute+ loads, so location was not the issue. Back to testing.

dave
Site Admin
Posts: 6684
Joined: Sun Sep 18, 2005 8:02 am
Location: Seattle
Contact:

Re: Location-specific load times

Post by dave »

watch the log file in the console, as it loads, see at what point it stalls?

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Good idea.
Stalled here for three minutes:
--------------
Creating Que: Push Meta Que
0: Spawning new Que: Push Meta Que
0: Installing event handlers
2: Entering thread: Push Meta Que
0: Getting App Res Folder
0: Dialog windType: -1, ID: 131
0: Should be NIB: Yes
0: Success getting NIB: Yes
0: Creating task manager
0: Loading Icons
0: Loading Icons: stop_sign
0: Loading Icons: speaker_on
0: Loading Icons: speaker_off
0: Loading Icons: singer_speaker_on
0: Loading Icons: singer_speaker_off
0: Loading Icons: playlist
0: Loading Icons: singers
0: Loading Icons: singer
0: Loading Icons: tricera
0: Loading Icons: vj
0: Loading Icons: cb
0: Loading Icons: kc
0: Loading Icons: general
0: Loading Icons: audio
0: Loading Icons: importing
0: Loading Icons: burn
0: Loading Icons: advanced
0: Loading Icons: freedb
0: Loading Icons: quicktime
0: Loading Icons: tags
0: Loading Icons: sharing
0: Loading Icons: libraries
0: Loading Icons: kJams
0: Loading Icons: producer
0: Loading Icons: store
0: Loading Icons: kj_pro
0: Loading Database
0: Loading Library
0: Loading songs into Database…
0: Songs In Library: 70096
0: Biggest record: 2.3 K
0:
--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
0: Time To Load (Binary): 00:8.027
3: Entering thread: Deletion Que

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

On another run:

--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
3: Entering thread: Deletion Que
0: Time To Load (Binary): 00:9.280
0: Dialog windType: -1, ID: 131
0: Should be NIB: Yes
0: Success getting NIB: Yes
0: Counting: 4000
So it is getting hung up somewhere in creating the Deletion Que [sic].

dave
Site Admin
Posts: 6684
Joined: Sun Sep 18, 2005 8:02 am
Location: Seattle
Contact:

Re: Location-specific load times

Post by dave »

okay the next rogue will have more logging in that area.. so run that, then tell me where THAT log file stalls...

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

When is it up?

dave
Site Admin
Posts: 6684
Joined: Sun Sep 18, 2005 8:02 am
Location: Seattle
Contact:

Re: Location-specific load times

Post by dave »

maybe an hour from now

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Well, I assume that all I need do is launch, so I will report momentarily.
And… we're back. Now it no longer gets stuck at the loading DB section of the progress window but at the loading Playlists portion:
Loading Playlists
Loading Playlists
for several minutes, with a corresponding Console entry of:


--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
0: Time To Load (Binary): 00:7.253
3: Entering thread: Deletion Que
0: Loading Playlists

Followed several minutes later (2:35 later, I presume) by:

0: Time To Load (Playlists): 02:35.587
0: Building Playlist: Library
2: $$ pushing “Breaking the Girl”
2: $$ no file type. volume offline? file missing?
2: SafeSave name: <<Breaking the Girl2.xml>>
2: Type: <CFURL>, Value: <<CFURL 0x29be7280 [0xa05f8bd0]>{string = file://localhost/private/var/folders/42/pmz8j87j399cyccm2_2v40ww0000gp/T/TemporaryItems/kJams%20Temp/16842740675630858240/Breaking%20the%20Girl2.xml, encoding = 134217984, base = (null)}>
0: ** Database dirty because: pushing but could not write meta
0: Calculating Playlist durations…
0: Finalizing Playlists…
0: rebuilding (KJ) Rotation
0: rebuilding (audience) Rotation
0: Total Database Load time: 02:49.653
0: Allocating CDPedia
0: Initializing GraceNote
etc..

Not sure that extra info is all that useful, but there it is.

A second launch yielded the somewhat different:

0: -------------------- New kJams Log --------------------
0: ### Error eWeb_InstallEngineFromPath: The latest engine is already installed.
0: kJams 2 2.0d67r05
0: Date/Time: 2015-01-28 5:37:11.605 -0500
0: OS X 10.10.1 (14B25)
0: SystemVers: 0x10a1
0: Intel Core i7, Cores: 4
0: Clock Speed: 2.0 GHz
0: Total RAM: 8 GB
0: Encoding: Western (Mac OS Roman)
0: Locale: en
0: Locale ID: en_US
0: QuickTime Version 7.7.3
0: Thread Manager Initted
0: Loading authorization server
0: Loading version tracker
0: Initting Object Tracker
0: Loading Plugins
0: Loaded: kJams Burning Plugin, v1.0f3
0: Loaded: kJams Producer Plugin, v1.0b4
0: Loaded: LAME MP3 Encoder Version 3.97
0: Initializing Undo System
0: Allocating MetaData Traits Database
0: Creating Song Database
0: creating overlay <Messenger>
0:
--------------
Creating Que: Push Meta Que
0: Spawning new Que: Push Meta Que
0: Installing event handlers
2: Entering thread: Push Meta Que
0: Getting App Res Folder
0: Dialog windType: -1, ID: 131
0: Should be NIB: Yes
0: Success getting NIB: Yes
0: Creating task manager
0: Loading Icons
0: Loading Icons: stop_sign
0: Loading Icons: speaker_on
0: Loading Icons: speaker_off
0: Loading Icons: singer_speaker_on
0: Loading Icons: singer_speaker_off
0: Loading Icons: playlist
0: Loading Icons: singers
0: Loading Icons: singer
0: Loading Icons: tricera
0: Loading Icons: vj
0: Loading Icons: cb
0: Loading Icons: kc
0: Loading Icons: general
0: Loading Icons: audio
0: Loading Icons: importing
0: Loading Icons: burn
0: Loading Icons: advanced
0: Loading Icons: freedb
0: Loading Icons: quicktime
0: Loading Icons: tags
0: Loading Icons: sharing
0: Loading Icons: libraries
0: Loading Icons: kJams
0: Loading Icons: producer
0: Loading Icons: store
0: Loading Icons: kj_pro
0: Loading Database
0: Loading Library
0: Loading songs into Database…
0: Songs In Library: 70096
0: Biggest record: 2.3 K
0: Time To Load (Binary): 00:7.667
0: Loading Playlists
Note the lack of the deletion que [sic]

followed by:

0: Time To Load (Playlists): 01:13.920
0: Building Playlist: Library
0: Calculating Playlist durations…
0: Finalizing Playlists…
0: rebuilding (KJ) Rotation
0: rebuilding (audience) Rotation
0: Total Database Load time: 01:28.293
0: Allocating CDPedia
0: Initializing GraceNote

etc..

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

One more data point:


0: Loading Database
0: Loading Library
0: Loading songs into Database…
0: Songs In Library: 70096
0: Biggest record: 2.3 K
0:
--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
0: Time To Load (Binary): 00:7.480
3: Entering thread: Deletion Que
0: Loading Playlists
0: Time To Load (Playlists): 01:30.053
0: Building Playlist: Library
2: $$ pushing “Breaking the Girl”
2: $$ no file type. volume offline? file missing?
2: SafeSave name: <<Breaking the Girl2.xml>>
2: Type: <CFURL>, Value: <<CFURL 0x28f44650 [0xa05f8bd0]>{string = file://localhost/private/var/folders/42/pmz8j87j399cyccm2_2v40ww0000gp/T/TemporaryItems/kJams%20Temp/1158406317010845696/Breaking%20the%20Girl2.xml, encoding = 134217984, base = (null)}>
0: ** Database dirty because: pushing but could not write meta
0: Calculating Playlist durations…
0: Finalizing Playlists…
0: rebuilding (KJ) Rotation
0: rebuilding (audience) Rotation
0: Total Database Load time: 01:44.147
0: Allocating CDPedia
0: Initializing GraceNote

dave
Site Admin
Posts: 6684
Joined: Sun Sep 18, 2005 8:02 am
Location: Seattle
Contact:

Re: Location-specific load times

Post by dave »

so playlist loading is slow, and on the last one, GraceNote load is slow?

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Yes and no.
Yes, playlist loading is slow, though not as slow as it had been (but again, this can be variable, between 30-40 seconds and up to 6 minutes!) so I am not sure that means much.
And no, Gracenote is fine, I just chose to cut the Console text at that point, since the rest of the log didn't seem relevant.

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Note:
this is now significantly different on my other machine, with an older, much smaller (50%) venue.
So I guess the next step is to transfer my library from my work machine to that machine and see if the load times move along with it.
0: Loading Database
0: Loading Library
0: Loading songs into Database…
0: Songs In Library: 69194
0: Biggest record: 3.5 K
0: Time To Load (Binary): 00:5.747
0: Loading Playlists
0: Time To Load (Playlists): 00:7.867 <---------------- !!!!!!

dave
Site Admin
Posts: 6684
Joined: Sun Sep 18, 2005 8:02 am
Location: Seattle
Contact:

Re: Location-specific load times

Post by dave »

okay the NEXT update will time the duration it takes for each singer, and all singers
maybe it's just one singer that's bogging you down?

DeusExMachina
Posts: 1293
Joined: Sun Apr 20, 2008 9:57 am
Location: Pittsburgh, PA
Contact:

Re: Location-specific load times

Post by DeusExMachina »

Here is more Console log entries after copying the Library from th work machine to this machine:
0: Loading songs into Database…
0: Songs In Library: 70096
0: Biggest record: 2.3 K
0:
--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
3: Entering thread: Deletion Que
0: Time To Load (Binary): 00:5.920
0: Loading Playlists
0: Time To Load (Playlists): 00:27.840
0: Building Playlist: Library

Much shorter than on the work machine (30% more or less) but longer than the old Library (~400%).

And another:
0: Loading Icons: libraries
0: Loading Icons: kJams
0: Loading Icons: producer
0: Loading Icons: store
0: Loading Icons: kj_pro
0: Loading Database
0: Loading Library
0: Loading songs into Database…
0: Songs In Library: 70096
0: Biggest record: 2.3 K
0:
--------------
Creating Que: Deletion Que
0: Spawning new Que: Deletion Que
0: Time To Load (Binary): 00:5.667
3: Entering thread: Deletion Que
0: Loading Playlists
0: Time To Load (Playlists): 00:15.347
0: Building Playlist: Library
2: $$ pushing “Breaking the Girl”

Post Reply