4.0c beta 7: Trying to get to the bottom of the mysterious performance bug
Like some other users, I've having major performance issues opening some resources. In my case, the problem occurs when opening any Westminster Theological Journal.
Looking through my logs, the problem appears to be syncing. When opening a WTJ resource SyncManager uploaded or downloaded four items, taking 2820, 1026, 3595 and 1320milliseconds respectively (a total of nearly 9 seconds).
However, these stats do not adequately reflect what actually happened because was a considerable delay of several seconds before this sync was requested during which time Logos appeared to hang. This can be seen in the log by a gap of 10 seconds in the logging. There is another gap of 2.5 seconds later in the logs.
The attached log shows all this information. Opening a 'good' resources occurs at lines 692, 723, 890, 912, 934, 1030, 1052, 1072, 1092, 1745, 1806, 1844, 1875. Opening a 'bad' resource occurs at lines 804, 829, 983, 1769, 1908.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
Comments
-
Mark. I dont use those resources normally
2010-04-29 10:56:47.4081 18 Info LibraryCatalogIndex Searching for all records matching: westm
2010-04-29 10:56:47.6411 1 Info IsWorkingControl Hiding IsWorkingControl (name id 18270010)
2010-04-29 10:56:58.5831 1 Info LDLS4.AppModel Converting navigation request for library catalog record 2448 to request for resource
2010-04-29 10:56:58.5831 1 Info LDLS4.AppModel Converting navigation request for resource LLS:gs_wtj_05 to request for resource panel.
2010-04-29 10:56:58.5871 1 Info PanelViewModel Applying panel settings for Preferences: Contents=false|Locator=false|ReverseInterlinear=false
2010-04-29 10:56:58.5871 1 Info PanelViewModel Navigating panel to: Id=LLS:gs_wtj_05
2010-04-29 10:56:58.5871 1 Info PanelViewModel Applying panel settings for Bookmark: Id=LLS:gs_wtj_05
2010-04-29 10:56:58.5871 1 Info PanelViewModel Got panel settings for Preferences: Contents=false|Locator=false|ReverseInterlinear=false
2010-04-29 10:57:02.1621 1 Info PanelViewModel Applying panel settings for Preferences:
2010-04-29 10:57:02.4851 1 Info PanelViewModel Applying panel settings for Preferences:
2010-04-29 10:57:02.4851 1 Info PanelViewModel Got panel settings for LocalHistory: Id=LLS:gs_wtj_05|Position=Article%3dTITLE%7cArticleLength%3d23%7cContext%3dWTJ%25205:1%2520(N%7cOffset%3d0%7cOffsetInContext%3d0%7cResource%3dLLS:gs_wtj_05%7cVersion%3d2009-12-14T00:24:02Z|ReverseInterlinear=false
2010-04-29 10:57:02.4851 1 Info PanelViewModel Got panel settings for Bookmark: Id=LLS:gs_wtj_05|Position=Article%3dTITLE%7cArticleLength%3d23%7cContext%3dWTJ%25205:1%2520(N%7cOffset%3d0%7cOffsetInContext%3d0%7cResource%3dLLS:gs_wtj_05%7cVersion%3d2009-12-14T00:24:02Z|ReverseInterlinear=falseI had no syncing happening at time
Peculiar..
My Log 5633.Logos4.zip
Never Deprive Anyone of Hope.. It Might Be ALL They Have
0 -
Just to make it even clearer, here's a comparison of two resources being opened, from lines 804 and 889 of the above log. You'll see when I open the WTJ resource there's not only a 2.5s sync, but a 10s delay before the sync, and a 16s delay after the sync.
The timestamp shows min:sec:millisec (i.e. the hours have been cut off).
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Also to add that the only other resource (apart from WTJ) that seems to exhibit this problem is the Philippians volume of Anchor Bible Commentary.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
Also to add that the only other resource (apart from WTJ) that seems to exhibit this problem is the Philippians volume of Anchor Bible Commentary.
Hi Mark, I am having issues with this and my resource is Spurgeon's Lecture to Students Vol 1. See http://community.logos.com/forums/p/16252/123297.aspx#123297 for screen cast and logs.
john
0 -
John: I think our problems are different. Once the resource is open, I have no problems. The only delay appears to be in opening the resource.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
If you turn "Use Internet" and restart Logos 4, does the behavior improve?
0 -
Melissa Snyder said:
If you turn "Use Internet" and restart Logos 4, does the behavior improve?
No it doesn't. Attached is a new log with internet off. WTJ 8 took 56 seconds to open (lines 751f)!
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Thanks, I'll submit your logs.
0 -
Just to update that this problem no longer occurs with some of the resources it was occurring with earlier, but it is still a problem with others. But I've noticed the issue is not restricted to opening resources from the library. The attached log shows one resource taking 21.44 seconds to open, this time from the search window (lines 1298-1317 of the attached log).
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
Just to update that this problem no longer occurs with some of the resources it was occurring with earlier, but it is still a problem with others. But I've noticed the issue is not restricted to opening resources from the library. The attached log shows one resource taking 21.44 seconds to open, this time from the search window (lines 1298-1317 of the attached log).
These are Galaxie resources, which were created with very long articles. We have been able to resolve these delays with other resources by shortening articles, however, we don't have the same control with Galaxie's. We will continue to work on this issue.
0 -
Thanks for the update. Something really does need to be done. The attached log (look at the last 50 lines or so) shows one WTJ article taking 4 minutes 34.4 seconds to open, and a further eight minutes adding the visual filter for a current search (during which one of my cores is at 100% usage and Logos is completely unusable). This is on a pretty fast machine, and is obviously completely unacceptable. What on earth is Logos doing during that time? I can't afford to lose 12½ minutes of my life just because I had the misfortune to click on a link.
If you're unable to fix it in the short term, I would appreciate advice as to what appears to be exacerbating the problem on my computer. Too many resources? Complex collections? Too many resources in my prioritisation list? Something else?
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
If you're unable to fix it in the short term, I would appreciate advice as to what appears to be exacerbating the problem on my computer. Too many resources? Complex collections? Too many resources in my prioritisation list? Something else?
It's just the Galaxie resources. According to the Galaxie site "We've been fixing typos and rebuilding all the journal files to take
advantage of the Logos 4 engine. ... If you have Logos 4, it will automatically download the newest files
because we are uploading them to their servers as we finish"! I don't know what to make of that one in light of this open problem http://wiki.logos.com/Bug$3a_Various_issues_with_downloading_of_Galaxie_filesDave
===Windows 11 & Android 13
0 -
Dave Hooton said:
It's just the Galaxie resources.
But it doesn't happen with anyone else's Galaxie resources. Why?
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:Dave Hooton said:
It's just the Galaxie resources.
But it doesn't happen with anyone else's Galaxie resources. Why?
I don't have the problem because I don't have Galaxie journals! From where did you source yours? If they are lbxlls files would it be worthwhile replacing them from the Logos FTP server, where the (uppercase) GS_WTJ files are dated 14/12/09 (but it might provoke an identity crisis as per the wiki problem report)?
Dave
===Windows 11 & Android 13
0 -
Mark Barnes said:
But it doesn't happen with anyone else's Galaxie resources. Why?
FWIW my times look like this. I clicked on the title in Library and timed how long each took to open in seconds. (I do have the updates files for each of these.)
WTJ SR-2 Beta 6 Beta 7 Logos 3.0g
66 34 38 31 4
70 40 41 45 8
The problem with this sort of testing is not isolating the program from whatever might be going on in the background. I can say that there were long intervals where my hard drive was not being accessed by 4.0 when these were opening.
Just for fun I timed the opening of the Daily Study Bible volumes on Daniel and Deuteronomy and got times in SR-2 of 20-21 seconds to open and in Beta 6 of 24-25 seconds. I did not try them in beta 7. In Logos 3.0g it took 4 and 2 seconds to open the DSB volumes.
Overall opening a resource in Logos 4 is significantly slower than in 3.0. Whatever causes this needs to be addressed. It is hard to imagine that it takes about 5-8 times as long to open a resource in 4.0 than in 3.0 for good reason.
Pastor, North Park Baptist Church
Bridgeport, CT USA
0 -
Mark,
It appears that Galaxie has rebuilt all their journal files and they are dated 4-18-2010. You may want to go to Galaxies ftp site and download the new files and see if that helps.
ftp.bible.org/galaxie/libronix/TJL
0 -
Mark A. Smith said:
Overall opening a resource in Logos 4 is significantly slower than in 3.0. Whatever causes this needs to be addressed. It is hard to imagine that it takes about 5-8 times as long to open a resource in 4.0 than in 3.0 for good reason.
Thanks for doing this testing. It does confirm there is an issue, though I'm getting better figures than you. In beta 7, WTJ66 opens in 17s for me, and WTJ70 in 12s.
Would you also mind trying WTJ 23? That's my worst resource by miles. I have opening times of around 9 minutes for that resource!
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
BobbyTerhune said:
It appears that Galaxie has rebuilt all their journal files and they are dated 4-18-2010
Thanks, I'd not noticed this. I'll try downloading them all again (I'm using ones dated 2009-12-14).
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
Would you also mind trying WTJ 23? That's my worst resource by miles. I have opening times of around 9 minutes for that resource!
Wow. I got 33 seconds in Beta 7.
All my resources are dated 2/17/10 12/14/09 except for WTJ 70 which is dated 12/5/09 12/27/09. They are not in Logos 4 format.
Glad your overall times are better than mine. I hate the wait compared to what we had in 3.0.
Pastor, North Park Baptist Church
Bridgeport, CT USA
0 -
Mark A. Smith said:
FWIW my times look like this.
...
Overall opening a resource in Logos 4 is significantly slower than in 3.0. Whatever causes this needs to be addressed. It is hard to imagine that it takes about 5-8 times as long to open a resource in 4.0 than in 3.0 for good reason.
Thanks for posting the comparison of times with 4.0b. At the moment, it doesn't look to me like 4.0c introduces a significant regression in this area, so I'll create a case to investigate this for 4.0d. (Trying to optimise this might require major changes, and it's too late in the 4.0c cycle to risk introducing any major new bugs.)
0 -
Bradley Grainger said:
I'll create a case to investigate this for 4.0d
Thanks, Brad. Hopefully this will address the issues Mark Barnes has pointed out.
Pastor, North Park Baptist Church
Bridgeport, CT USA
0 -
I can't prove there's regresssion, but I'm pretty sure performance wasn't this bad in earlier versions. I'm experiencing a terrible delay both when opening some resources and when applying a search highlight. Look at these log entries for opening resources:
2010-05-04 21:36:42.2961 1 Info AppCommand (3m 43.8s) Executing command: Resource|Id=LLS:gs_atj_31|Position=Article%3dTITLE10%7cArticleLength%3d341752%7cContext%3dament%2520and%2520Hellenisti%7cOffset%3d185977%7cOffsetInContext%3d10%7cResource%3dLLS:gs_atj_31%7cVersion%3d2009-12-24T06:12:32Z
2010-05-04 22:26:28.4279 1 Info AppCommand (3m 48.2s) Executing command: Resource|Id=LLS:gs_jets_40|Position=Article%3dTITLE33%7cArticleLength%3d254749%7cContext%3d%2520Zimbabwe%250aGod’s%2520Empo%7cOffset%3d64820%7cOffsetInContext%3d10%7cResource%3dLLS:gs_jets_40%7cVersion%3d2009-12-13T23:49:41ZThose aren't logs I've stored up to show you how bad things are. That's just my experience whilst I'm trying to use Logos tonight to do my work! Unfortunately the log doesn't record the times for applying the search highlight, but it's similar: 3-5 minutes during which time one of my cores is at 100% utilisation. This is on a 3.3Ghz Core 2 Duo processor.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Sorry to hog the thread, but I managed to get a screenshot of what happens in the second part of the problem. To be clear, the two delays are (1) Opening the resource, (2) Applying the visual filters (I only have page numbers and search highlighting turned on). During the second delay, I get a mysterious black window appearing over the cover thumbnail.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
I wanted to update this thread, because I'm getting exactly the same problems with another machine on my account. Clearly there's something about my shared configuration or account that's causing these problems:
2010-05-06 19:42:26.0808 1 Info AppCommand (5m 0.8s) Executing command: Resource|Id=LLS:gs_jets_40
Remember that this delay is only the first of two delays I get. The second delay isn't timed exactly in the logs, but was an additional 4minutes 57 seconds. Total time to open this resource almost 10 minutes.
(This second machine is a 2.5GHz Core2 Quad. The first is a 3.2GHz Core2 Duo.)
I'm happy to send my .db files, create videos with process monitors open, or anything else you'd like, but I do need to get to the bottom of this! Thanks.
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
2010-05-06 19:42:26.0808 1 Info AppCommand (5m 0.8s) Executing command: Resource|Id=LLS:gs_jets_40
This resource takes 13 seconds to open on my system. This isn't great, of course, but your system shouldn't be twenty times slower. I'll do some more research.
0 -
I've discovered the problem is with the page numbers visual filter. With the filter turned off, I get:
- 2010-05-07 19:20:44.4081 1 Info AppCommand (10.48s) Executing command: Resource|Id=LLS:gs_jets_40
With the visual filter turned on, I get:
- 2010-05-07 19:29:32.1602 1 Info AppCommand (3m 46.5s) Executing command: Resource|Id=LLS:gs_jets_40
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
A further update. Following Dave's advice earlier in the thread, I've manually downloaded all the TLJ journals from their FTP site, and SCANned them into Logos. That seems to have solved the problem. I guess that leaves two questions.
- What was it about the old resources that caused the problem (mine were dated dated 2009-12-14)
- Why didn't my copy of Logos automatically download the newer versions?
This is my personal Faithlife account. On 1 March 2022, I started working for Faithlife, and have a new 'official' user account. Posts on this account shouldn't be taken as official Faithlife views!
0 -
Mark Barnes said:
- What was it about the old resources that caused the problem (mine were dated dated 2009-12-14)
- Why didn't my copy of Logos automatically download the newer versions?
- I'm not sure what about the resources has changed. My own copy is dated 2009-12-13T23:49:41Z, FWIW.
- The Galaxie files have been built two different ways over the years. Some users have the files built one way, other users have the files built the other way. The resources have been pulled to stop an immediate problem with perpetual resource downloads (see http://wiki.logos.com/Bug$3a_Various_issues_with_downloading_of_Galaxie_files).
0 -
To update on my experience:
I also downloaded and scanned into my SR-2 installation the most recent Galaxie files. The time it takes to open these has dramatically improved:
WTJ Volume Older version time to open in SR-2 New vesrion time to open in SR-2
70 40 sec 15 sec
66 34 sec 9 sec
So I'd recommend getting the newest files if speed of opening seems to be an issue. Both Mark Barnes and I have improved Logos' responsiveness by doing this.
Pastor, North Park Baptist Church
Bridgeport, CT USA
0
