Crash when opening the library in a new tab.
7558.New Compressed (zipped) Folder.zip
After several days of stable on 5.2b to rule out my computer as the problem - I decided to go back to the Beta. backed up the library files, uninstalled the live version, installed the beta, Copied the backed up files back in, scanned, and everything seemed to be going well. till today.
I had one tab open - on the right half of my screen I had collections, and on the left, I intended on opening my library to tag a book I'd found in my untagged collection. Right click library icon, left click open in new tab, and crash.
I've been able to repeat this twice now.
2210.New Compressed (zipped) Folder (2).zip
Both of the previous sets of logs are post crash. Going to get a pre-crash set of logs (followed by another post if it happens a third time).
Pre-crash: 1033.pre-crash.zip
Post Crash (#3) 5758.post crash.zip
Edit: I wonder if it has to do with some specific piece of hardware having some weird compatibility issue with some requisite piece of software...
Asus Sabertooth 990x R2.0 motherboard
AMD fx8350 cpu (8 core @ 4ghz x64)
Radeon HD 7770 graphics card
MSI Radeon HD 7770 Graphics Card.
16gb ddr2 (two 8 gb sticks - maybe 6 months old)
SSD x2 - Sandisk and the other is crucial a 120gb and a 240gb (OS lives on the 120gb and Logos on the 240gb).
4 sata drives - 2 1tb and a 1.5 tb in raid 0, 1 1tb and 1 2tb just attached (one in a toaster for backup; but still attached via sata bus)
No cd rom.
4 displays - 2x Benq 24" @ 1900 x 1280, 1 32" tv running at 1360x768, and one 24" HP display running at 1680 x 1050.
trendnet 802.11ac wireless usb nic
Other programs running: Avast antivirus, FIrefox, trendnet management software, amd catalyst graphics management software, msi liveupdate, and Realtek HD audio management suite.
Firefox only has two tabs open - Logos both - IE low memory usage, lots of free system resources.
L2 lvl4 (...) WORDsearch, all the way through L10,
Comments
-
In the next beta, we're going to switch back from using memory-mapped file I/O to regular disk I/O in SQLite. Since this problem is so reproducible on your computer, it would be very interesting to see if the next beta is more stable for you.
In the meantime, to get working, there should be some local DBs you can delete; I'll have to get back to you with the paths.
0 -
Thanks Bradley!Bradley Grainger (Logos) said:In the next beta, we're going to switch back from using memory-mapped file I/O to regular disk I/O in SQLite. Since this problem is so reproducible on your computer, it would be very interesting to see if the next beta is more stable for you.
In the meantime, to get working, there should be some local DBs you can delete; I'll have to get back to you with the paths.
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
Sorry for the delay; try deleting:
\Logos5\Documents\ckti5brq.qdq\UserPreferences2\PreferencesManager.db0 -
Also, if this is a new installation, you're likely to be affected by the Bible Facts resource download bug (see http://community.logos.com/forums/p/89055/626574.aspx#626574) unless you have a working 5.2b installation you can scan the missing files in from.
0 -
No worries.
Is memory mapped io something that may be returning in the future? or is it effectively dead?
Thanks for posting back.L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
abondservant said:
Is memory mapped io something that may be returning in the future? or is it effectively dead?
It's something I'd like to have return in the future (probably in another "Beta 1", since it is a major change).
Like most SQLite problems, it's not something we can reproduce in-house, which makes it very difficult to know why corruption is happening, or even if memory-mapped I/O is contributing to the problem. We also switched to 64-bit and updated the version of SQLite in 5.3 Beta 1, so there were a lot of simultaneous changes. However, memory-mapped I/O is both high-risk and the easiest thing to disable, so we're turning that off to see if the error rate drops down.
0 -
Tried to post this earlier but the site went down.
Deleted the DB, I was up and running again within minutes. But as soon as it tried to update Logos crashed. I tried to re-start, but instant fail. So I deleted the file a second time, restarted Logos, and all was happy again. Till it checked for updates. Then flaming death.
Having deleted the DB file for the third time now I can't help but wonder if its possible to code a more graceful response to corrupt DBS. For instance when this particular DB breaks, could Logos delete and re-build it automatically?L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
abondservant said:
Having deleted the DB file for the third time now I can't help but wonder if its possible to code a more graceful response to corrupt DBS.
If SQLite detects that the database is corrupt, then we automatically rebuild it.
However, if SQLite thinks the DB is OK, but returns truncated data (which is what is happening here), then the application crashes and doesn't recover automatically.
This seems to be a significant new problem in 5.3 and why we are rolling back to regular disk I/O. (Additionally, we are planning to add checks for invalid XML or JSON deserialization from an "OK" database, but that's just a Band-Aid (aka plaster) on top of the problem, not a real solution.)
0 -
I support the return of memory-mapped I/O. Some of us have bedecked our computers with extra memory just for Logos!
In lieu of definite proof that memory-mapped I/O is to blame, why not send abondservant a special debug build, for verbose logging?
0 -
Lee said:
Some of us have bedecked our computers with extra memory just for Logos!
You'll still benefit from the OS' file system cache (which keeps recently-used files in memory as long as applications don't need it); you'll just have to pay the "penalty" of an extra copy from the kernel's file system cache into Logos' user-mode memory.
0 -
Lee said:
In lieu of definite proof that memory-mapped I/O is to blame, why not send abondservant a special debug build, for verbose logging?
We're seeing an increase in errors across the board, not just for one user.
AFAIK, SQLite only supports error and warn logging, which will already log to LogosError.log.
0 -
That makes sense Bradley thanks for the explanation.
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
Bradley Grainger (Logos) said:Lee said:
In lieu of definite proof that memory-mapped I/O is to blame, why not send abondservant a special debug build, for verbose logging?
We're seeing an increase in errors across the board, not just for one user.
AFAIK, SQLite only supports error and warn logging, which will already log to LogosError.log.
I confess I don't understand how memory-mapped I/O and SQLite factor in this.
Bradley Grainger (Logos) said:However, if SQLite thinks the DB is OK, but returns truncated data (which is what is happening here), then the application crashes and doesn't recover automatically.
How can SQLite see a corrupted DB as a valid DB? How does it even know what to think? Would error-checking help? I suggested before that you hash results.
0 -
As I understand it, Memory Mapped IO is a feature of SQLite (which handles the databases). I confess I don't know how much coding is involved, but it may be as simple as checking or unchecking a box.
As to how it can see a corrupt DB as valid, most likely there is a random (or perhaps specific %) sample thats taken, and based upon whether it can read the sample taken it reports back that the DB is valid or invalid. However where the sample is coming from and where the damage to the DB is are apparently in two separate places. Thus the crash.
At least that is how it is making sense in my head.L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
So SQLite is mashing the database.
More about memory-mapping here: http://www.sqlite.org/draft/mmap.html
The following remarks drawn from official sources are germane:
1. So the use of memory mapped I/O does not significantly change the performance of database changes. Memory mapped I/O is mostly a benefit for queries.
2. The developers point out that there are disadvantages to the technique that require coders using the functions be more robust in how they handle pointers and errors and that it is possible to not see performance boosted in certain test cases.
0 -
Memory Mapped IO is a feature of Windows that has been around for quite a while. SQLite has the option to use it in order to access data more efficiently. I don't know the details, but I imagine the SQLite opens a db file and reads a header and metadata describing the db. If it's invalid this is where Logos can repair itself. However, this info can all be correct and thus the DB seems OK while data written in to the tables is not being written or read correctly. SQLite would not detect that because it doesn't try to make sense of what is written to the tables.
There's a lot of assumptions here. I trust that Logos will figure it out.
0 -
The key to the problem lies in
1. how the program lays out and protects the info in user space; and
2. error-checking
0 -
had a blackout with Logos on and running, database(s?) is corrupt. At least I presume as Logos crashes on start. Deleting the user preferences db just delays the crash.
Here are the logs:
7571.New Compressed (zipped) Folder (3).zip
Perhaps I should revert to 5.2b until the next round on this computer. It sounds like a possible solution has been found.L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
abondservant said:
Here are the logs:
It looks as though
\Logos5\Data\ckti5brq.qdq\Updates\Metadata.db is the corrupt DB on this occasion - but you may want to wait for someone from Logos to verify / checkabondservant said:Perhaps I should revert to 5.2b until the next round on this computer
With the number of issues of this type you are having that could be a plan[:)]
0 -
If Logos suggests I stick around and that all these log files are useful, I will. Otherwise I'll revert and try it on this computer next round (keeping my laptop in the beta).
Also thank you for that suggestion. I'll give it a shot.
What do you search for in the Log file to determine whats bad? I've not looked my self. Though I suppose I could search for that DB file in the log and see for my self.L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
abondservant said:
What do you search for in the Log file to determine whats bad?
I'm not the log file guru, but I'm looking for Errors, Warnings, and similar key phrases - normally a reasonable guess, accompanied many times by having seen "something like this before" can lead me to a close answer.
There are others here (*cough*)Dave(*cough*) who seem to understand logs intuitively.
Sarcasm is my love language. Obviously I love you. 0 -
abondservant said:
What do you search for in the Log file to determine whats bad? I've not looked my self. Though I suppose I could search for that DB file in the log and see for my self.
There are many who are better at this than me. But on this occasion I found this towards the end of the logfile
2014-09-10 11:56:32.5833 3 Error ApplicationUtility SQLite Error 11: database corruption at line 64468 of [b1ed4f2a34]
2014-09-10 11:56:32.5853 3 Error ApplicationUtility SQLite Error 11: statement aborts at 14: [delete from Metadata where ResourceId = @ResourceId;] database disk image is malformed
2014-09-10 11:56:32.5883 3 Error ApplicationUtility Will mark database as corrupt due to error executing: delete from Metadata where ResourceId = @ResourceId;
insert into Metadata(ResourceId, MetadataVersion, Status)
values(@ResourceId, @MetadataVersion, 0); ~SQLiteException: database disk image is malformed
2014-09-10 11:56:32.5923 3 Info LocalFileDatabase Setting 'D:\Logos5\Data\ckti5brq.qdq\Updates\Metadata.db' as corrupt in the registry.
2014-09-10 11:56:32.5993 3 Error ApplicationUtility Unhandled exception in async work System.Data.SQLite.SQLiteException (0x0000000B): database disk image is malformed
at System.Data.SQLite.SQLiteDataReader.ReadAsyncCore(CancellationToken cancellationToken)This called out which file was flagged as corrupt on this occasion
0 -
Makes sense. I've scanned it (visually, not by searching) and didn't see anything that jumped out at me. I'll try using the ctrl F search function and see if thats more fruitful.
Also Congrats on 10,000 posts Graham!
Your 10,000th post was a helpful one indeed. Seems to be running again.
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
Nice - so searching "Error" would have gotten me there this time. Thats good to know.Graham Criddle said:abondservant said:What do you search for in the Log file to determine whats bad? I've not looked my self. Though I suppose I could search for that DB file in the log and see for my self.
There are many who are better at this than me. But on this occasion I found this towards the end of the logfile
2014-09-10 11:56:32.5833 3 Error ApplicationUtility SQLite Error 11: database corruption at line 64468 of [b1ed4f2a34]
2014-09-10 11:56:32.5853 3 Error ApplicationUtility SQLite Error 11: statement aborts at 14: [delete from Metadata where ResourceId = @ResourceId;] database disk image is malformed
2014-09-10 11:56:32.5883 3 Error ApplicationUtility Will mark database as corrupt due to error executing: delete from Metadata where ResourceId = @ResourceId;
insert into Metadata(ResourceId, MetadataVersion, Status)
values(@ResourceId, @MetadataVersion, 0); ~SQLiteException: database disk image is malformed
2014-09-10 11:56:32.5923 3 Info LocalFileDatabase Setting 'D:\Logos5\Data\ckti5brq.qdq\Updates\Metadata.db' as corrupt in the registry.
2014-09-10 11:56:32.5993 3 Error ApplicationUtility Unhandled exception in async work System.Data.SQLite.SQLiteException (0x0000000B): database disk image is malformed
at System.Data.SQLite.SQLiteDataReader.ReadAsyncCore(CancellationToken cancellationToken)This called out which file was flagged as corrupt on this occasion
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
abondservant said:
Your 10,000th post was a helpful one indeed. Seems to be running again.
That's good - and appreciate the congrats[:)]
0 -
No problem its quite the milestone!
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
I'm still learning so it's nice to read other's methods. Mostly I've been reading logs, making a guess to myself, and waiting for an expert to state the cause to see if my guess is correct. Still not as confident as I'd like to be in the process.
I usually open the zip file (always preferred) and examine the date stamps. Sometimes logs get posted that are old and not from the most recent crash / error.
I almost always go straight for the Logos.log as it contains the same error/stack trace as other files. If it's a crash (thrown or unhandled exception), I go straight to the end of the file (where the most recent entries are appended, logs are oldest entries at top to most recent at end) and look for the stack trace. If it's an error or anomalous behavior, I'll search for "Error" or "Warn".
Either way, I look at the error and sometimes the preceding lines for context. If it's a stack trace, it's usually the preceding context or something about middle ways in the trace that gives a clue to what module threw the exception (top of the trace is the very low level code, the end is high level code, app startup, etc). The middle of the trace usually contains a reference to the module that is having trouble.
Still have a lot to learn and appreciate the real experts around here.
0 -
@abondservant:
So long as Logos cannot reproduce these errors in-house, your logfiles and specific computer configuration should be very useful to them. Literally anything could be contributing to these errors -- drivers, anti-virus programs, etc...0 -
But how many log files are sufficient is my question, 10,20? After a certain point are they still getting new information from the logs? If so, I keep slogging through, if not, then I'll downgrade.Lee said:@abondservant:
So long as Logos cannot reproduce these errors in-house, your logfiles and specific computer configuration should be very useful to them. Literally anything could be contributing to these errors -- drivers, anti-virus programs, etc...If all they are learning is "db corrupt line 33". Then hearing that 300 times doesn't change anything.
Does that make more sense?
L2 lvl4 (...) WORDsearch, all the way through L10,
0 -
Again, if I were Logos, I would choose to take a very pro-active approach to this, to the point of getting on your computer (with your permission) to get all the metrics.
The aim is to isolate the problem, which usually involves reproducing it predictably.
0 -
They would be welcome to do so if they think it would help.
For what its worth, it doesn't seem to be crashing when I open the library in a new tab anymore. Just tried it again.
Some database or other is getting corrupted nearly every day however.
I would even zip and upload the entirety of the Logos installation if they wantedL2 lvl4 (...) WORDsearch, all the way through L10,
0 -
The problem will come to light faster if Logos knew the precise configuration of the computers having the DB corruption problem.
0 -
Randy W. Sims said:
Either way, I look at the error and sometimes the preceding lines for context. If it's a stack trace, it's usually the preceding context or something about middle ways in the trace that gives a clue to what module threw the exception (top of the trace is the very low level code, the end is high level code, app startup, etc). The middle of the trace usually contains a reference to the module that is having trouble.
2014-09-10 11:56:32.5853 3 Error ApplicationUtility SQLite Error 11: statement aborts at 14: [delete from Metadata where ResourceId = @ResourceId;] database disk image is malformed
has a significant clue with "delete from Metadata". ResourceId will confirm that provided you have an SQLite viewer to see the structure of the Metadata table.
08/26/2013 08:29:09 | ERROR | 25 | ApplicationUtility | SQLite Error 11: statement aborts at 12: [select RecordId , ResourceDriverName, Image, Version, IsAvailable, IsHidden from Records where ResourceId='LLS:HLMNKYBBLWDS';]
I know that Records is a Table in the Catalog.db and the field names confirm that (the stack trace would state LibraryCatalog somewhere!).
Preferences is the most difficult to pin down as there are three databases with that name and two have the same structure.
Dave
===Windows 11 & Android 13
0 -
Thank you for that Dave! I've kinda glossed over the bits of SQL when reading logs, for the most part, thinking there would be enough clues within the log files if I studied them enough. Kind of silly--or just too lazy to browse and become familiar with all the various dbs. Will definitely pay more attention to them now as that definitely resolves some ambiguities when just using the log file alone. This also suggests that a couple of cheat sheets of common tables, their attributes, and the db they belong to; and/or some common errors lines with their verified solution would be useful to keep up for quick searches. Thank you for sharing that.
BTW, Anyone have any recommendations for a good reader for nlog files? One that optionally groups messages by threadid, and highlights lines with Warn or Error.
Here are nlog configs for Legit viewer
0 -
Randy W. Sims said:
Anyone have any recommendations for a good reader for log files?
I, and a few other of the MVP's use Notepad++; I have further added a language filter for logs that highlights the keywords and phrases that make the logs more legible for a quick read. With proper settings you can either highlight a word, or an entire line.
I am currently highlighting the following words:
- Version
- Beta
- Warn
- Error
- Exception
- Unhandled
- Indexer
If you want to set this up in Np++
- Load notepad++ (with a log if you want to check things out)
- Menu: Language >> Define Your Language
- Save As: Logs (or whatever name you want.
- Figure out if you want WORDS or LINES highlighted.
- To highlight WORDS only:
- Click the Keywords List tab.
- Click Styler for any particular group (1st, 2nd, etc)
- Adjust it with a foreground and background color etc. per your liking.
- Type your words in that area.
- e.g. First group is green highlighter (Background color) with the words Version and Beta on separate lines.
- Second group is Yellow Background, red foreground with Warn, Error, Exception,
- Etc. See the words referenced in above posts as worthy of attention.
- To highlight LINES
- Click the Operators and Delimiters tab.
- In Operators & Delimiters, it's the delimiter styles you want (ignore the operators).
- From here the steps are similar. Set your colors with styler,
- Input your words for the start, and the carriage return for the end.
- Once you're satisfied, just close the dialog. AFAIK it autosaves.
If you add "log" as the extension (ext.), the highlighting will be applied automatically.
In fact I just exported my current log filter and attached it to this post.
Sarcasm is my love language. Obviously I love you. 0 -
TCBlack said:Randy W. Sims said:
Anyone have any recommendations for a good reader for log files?
I, and a few other of the MVP's use Notepad++; I have further added a language filter for logs that highlights the keywords and phrases that make the logs more legible for a quick read. With proper settings you can either highlight a word, or an entire line.
Thanks, TC. I love Notepad++. This is very helpful and I'll definitely use it. Notepad++ is my goto for just about everything text these days. If I had this I probably wouldn't have looked at log viewers. But I have to say, after looking at a few, they have a lot to offer that Notepad++ can't match. Separating the fields into columns, quick filters on fields, highlighting. I really like being able to sort by thread id (but would still prefer grouping) to get a better view of what's happening in a thread. That's awesome. With the clearer layout, I see things I've never noticed before. The viewer I mentioned above is the better one of a few that I looked at last night, but after just a few hours I've still got a list of about 10 fixes/enhancements it could use; gonna look around a bit more. Still, it really is a huge improvement over a flat text file.
0 -
I went back and looked at this, does it support highlighting? I can't find it.Randy W. Sims said: Sarcasm is my love language. Obviously I love you. 0 -
It does for the logging Level, on the right side, as indicated below. Custom highlighting for Logger or Message, or really custom highlighting on any field would be ideal.
0
