Your browser was unable to load all of the resources. They may have been blocked by your firewall, proxy or browser configuration.
Press Ctrl+F5 or Ctrl+Shift+R to have your browser try again.

Do these Mysql logs look bad? #9

#1

Iwas watching the rompr log and aI see these, not sure if they are bad or not. I do not know much about Sql stuff so sorry for being verbose about this stuff.

thanks

02:25:10 :    24653 : MYSQL               Tidying Metadata                                                                                                                            [3/1888]
02:25:10 :    24653 : MYSQL               Updating Track Stats
02:25:10 :    24653 : USERRATING          ---------------------------END----------------------
02:26:25 :    30081 : SQL_QUERY           Command Failed : DELETE FROM Albumtable WHERE Albumindex NOT IN (SELECT DISTINCT Albumindex FROM Tracktable WHERE Albumindex IS NOT NULL)
02:26:25 :    30081 : MYSQL                   MYSQL Error:  : 1213 : Deadlock found when trying to get lock; try restarting transaction
02:26:25 :    30081 : MYSQL               Removing orphaned artists
02:26:51 :    30081 : SQL_QUERY           Command Failed : CREATE TEMPORARY TABLE Croft(Artistindex INT UNSIGNED NOT NULL UNIQUE, PRIMARY KEY(Artistindex)) AS SELECT Artistindex FROM Trackta
ble UNION SELECT AlbumArtistindex FROM Albumtable
02:26:51 :    30081 : MYSQL                   MYSQL Error:  : 1213 : Deadlock found when trying to get lock; try restarting transaction
02:26:51 :    30081 : SQL_QUERY           Command Failed : CREATE TEMPORARY TABLE Cruft(Artistindex INT UNSIGNED NOT NULL UNIQUE, PRIMARY KEY(Artistindex)) AS SELECT Artistindex FROM Artistt
able WHERE Artistindex NOT IN (SELECT Artistindex FROM Croft)
02:26:51 :    30081 : MYSQL                   MYSQL Error:  : 1146 : Table 'romprdb.Croft' doesn't exist
02:26:51 :    30081 : SQL_QUERY           Command Failed : DELETE Artisttable FROM Artisttable INNER JOIN Cruft ON Artisttable.Artistindex = Cruft.Artistindex
02:26:51 :    30081 : MYSQL                   MYSQL Error:  : 1146 : Table 'romprdb.Cruft' doesn't exist
02:26:51 :    30081 : MYSQL               Tidying Metadata
02:27:11 :    30081 : MYSQL               Updating Track Stats
02:27:11 :    30081 : TIMINGS             Cruft Removal Took 02:31
02:27:11 :    30081 : TIMINGS             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
02:27:11 :    30081 : DUMPALBUMS          Generating artist aartistroot from database
02:27:11 :    30081 : TIMTINGS            == Time Spent Reading Socket Data                      : 0
02:27:11 :    30081 : TIMTINGS            == Time Spent Parsing Socket Data                      : 0
02:27:11 :    30081 : TIMTINGS            == Time Spent Checking/Writing to Database             : 0
02:27:11 :    30081 : TIMTINGS            == Time Spent Putting Stuff into Collection Structures : 0
02:27:11 :    30081 : TIMTINGS            == Time Spent Sorting Collection Structures            : 9.5367431640625E-7
02:27:11 :    30081 : TIMINGS             == Collection Update And Send took 06:42
02:27:11 :    30081 : COLLECTION          Peak Memory Used Was 4,195,240 bytes  - meaning we used 3,801,600 bytes.
02:27:11 :    30081 : TIMINGS             ======================================================================
02:27:43 :     2143 : DIRBROWSER          Browsing Beets library
  • replies 14
  • views 10.3K
  • likes 1
gerroon · Author

Here is ano0ther one, all I did was to open the ratings bar, I am still waiting it to open after 15 mins "Loadist List..."

It has log thousnds of sthese I think, and still logging....

03:51:57 :     8602 : USERRATINGS           Artist 39707 has modified albums
03:51:57 :     8602 : USERRATINGS             Creating Artist Header
03:51:57 :     8602 : DUMPALBUMS          Generating artist aartist39707 from database
03:51:57 :     4723 : USERRATINGS           Artist 41574 has modified albums
03:51:57 :     4723 : USERRATINGS             Creating Artist Header
03:51:57 :     4723 : DUMPALBUMS          Generating artist aartist41574 from database
03:51:58 :     8602 : USERRATINGS           Artist 39708 has modified albums
03:51:58 :     8602 : USERRATINGS             Creating Artist Header
03:51:58 :     8602 : DUMPALBUMS          Generating artist aartist39708 from database
03:51:58 :     4723 : USERRATINGS           Artist 41575 has modified albums
03:51:58 :     4723 : USERRATINGS             Creating Artist Header
03:51:58 :     4723 : DUMPALBUMS          Generating artist aartist41575 from database
03:51:58 :     8602 : USERRATINGS           Artist 39709 has modified albums
03:51:58 :     8602 : USERRATINGS             Creating Artist Header
03:51:58 :     8602 : DUMPALBUMS          Generating artist aartist39709 from database
03:51:59 :     4723 : USERRATINGS           Artist 41576 has modified albums
03:51:59 :     4723 : USERRATINGS             Creating Artist Header
03:51:59 :     4723 : DUMPALBUMS          Generating artist aartist41576 from database
03:51:59 :     8602 : USERRATINGS           Artist 39710 has modified albums
03:51:59 :     8602 : USERRATINGS             Creating Artist Header
03:51:59 :     8602 : DUMPALBUMS          Generating artist aartist39710 from database
03:51:59 :     8602 : USERRATINGS           Artist 39711 has modified albums
03:51:59 :     8602 : USERRATINGS             Creating Artist Header
03:51:59 :     8602 : DUMPALBUMS          Generating artist aartist39711 from database
03:52:00 :     4723 : USERRATINGS           Artist 41577 has modified albums
03:52:00 :     4723 : USERRATINGS             Creating Artist Header
03:52:00 :     4723 : DUMPALBUMS          Generating artist aartist41577 from database
#3

The second is probably an effect of the first. I do not know what is going on with your database, I have never seen issues like this come up, but I would suggest it is definitely corrupt again.

If it happens again, send me the entire log. I need to see what was going on before, it appears things are occurring simultaneously that are blocking each other but I have tested this very thoroughly indeed.

#4

What machine are you running your apache server on? Are you using Rompr's SQLite or MySQL database? Were you by any chance trying to add ratings to a track while you were updating your database?

gerroon · Author
#5

I am using Debian Testing with

Apache/2.4.33 (Debian)
    Database client version: libmysql - mysqlnd 5.0.12-dev - 20150407 - $Id: 38fea24f2847fa7519001be390c98ae0acafe387 $
    PHP extension: mysqliDocumentation curlDocumentation mbstringDocumentation
    PHP version: 7.1.16-1+b2

I am not sure if I was doing database update while trying to open rating pane;l. It never opened btw, was trying to open.

I just wiped my database and started from scratch. It was set to ut8_general_ci, I am trying ut8mb4_general_ci now,

#6

I meant for the first log, it looks like you were updating the collection and tried to add a rating to a track while that was happening. That will cause breakage. I'm working on a fix for that.

gerroon · Author

I also get this (and was geting this), even after completely wiping my database and recreating in mysql. This happens when I am using Mopidy and updating database. This is just after first ever update in the new database.

I have no idea:(

in my mopidy.conf file and local if it is related to this issue.
scan_timeout = 1000

Meanwhile it is still printing stuff in the log (after spitting that line in the picture). So far the log is not done, is it updating or not?

17:31:37 :    12164 : COLLECTION          Finding AlbumArtist for album The Future Sound of Jazz
17:31:37 :    12164 : COLLECTION            Album The Future Sound of Jazz has too few tracks to determine album artist
17:31:37 :    12164 : COLLECTION            ... Setting artist to nightmareonwax
17:31:37 :    12164 : COLLECTION          Finding AlbumArtist for album The Future Sound of Jazz
17:31:37 :    12164 : COLLECTION            Album The Future Sound of Jazz has too few tracks to determine album artist
17:31:37 :    12164 : COLLECTION            ... Setting artist to Fauna Flash
17:31:37 :    12164 : COLLECTION          Finding AlbumArtist for album The Future Sound of Jazz
17:31:37 :    12164 : COLLECTION            Album The Future Sound of Jazz has too few tracks to determine album artist
17:31:37 :    12164 : COLLECTION            ... Setting artist to B low
17:31:37 :    18106 : USERRATINGS           Artist 232 has modified albums
17:31:37 :    18106 : USERRATINGS             Creating Artist Header
17:31:37 :    18106 : DUMPALBUMS          Generating artist aartist232 from database
17:31:37 :    12164 : COLLECTION          Finding AlbumArtist for album The Genie - Themes and Variations from the TV series Taxi
17:31:37 :    12164 : COLLECTION            Album The Genie - Themes and Variations from the TV series Taxi has too few tracks to determine album artist
17:31:37 :    12164 : COLLECTION            ... Setting artist to Bob James
17:31:37 :    18106 : USERRATINGS           Artist 233 has modified albums
17:31:37 :    18106 : USERRATINGS             Creating Artist Header
17:31:37 :    18106 : DUMPALBUMS          Generating artist aartist233 from database
17:31:37 :    12164 : COLLECTION          Finding AlbumArtist for album The Genius of Ustad Vilayat Khan
17:31:37 :    12164 : COLLECTION            Album The Genius of Ustad Vilayat Khan has too few tracks to determine album artist
17:31:37 :    12164 : COLLECTION            ... Setting artist to Vilayat Khan
17:31:37 :    18106 : USERRATINGS           Artist 234 has modified albums
17:31:37 :    18106 : USERRATINGS             Creating Artist Header
17:31:37 :    18106 : DUMPALBUMS          Generating artist aartist234 from database
#8

Read the Toubleshooting docs. You're getting a webserver timeout because the update is taking longer than your webserver allows a process to run for.

gerroon · Author
#9

thanks I will

gerroon · Author
#10

Ok I did the changes in php still testing but I get these in the rompr log

14:45:27 :     6556 : USERRATING          --------------------------START---------------------


19:46:24 :     6556 : SQL_QUERY           Command Failed : UPDATE Tracktable SET justAdded = 0 WHERE justAdded = 1
19:46:24 :     6556 : MYSQL                   MYSQL Error:  : 1205 : Lock wait timeout exceeded; try restarting transaction
19:47:15 :     6556 : SQL_QUERY           Command Failed : UPDATE Albumtable SET justUpdated = 0 WHERE justUpdated = 1
19:47:15 :     6556 : MYSQL                   MYSQL Error:  : 1205 : Lock wait timeout exceeded; try restarting transaction
14:47:15 :    11857 : USERRATING          --------------------------START---------------------
19:48:13 :    11857 : SQL_QUERY           Command Failed : UPDATE Tracktable SET justAdded = 0 WHERE justAdded = 1
19:48:13 :    11857 : MYSQL                   MYSQL Error:  : 1205 : Lock wait timeout exceeded; try restarting transaction
19:49:04 :    11857 : SQL_QUERY           Command Failed : UPDATE Albumtable SET justUpdated = 0 WHERE justUpdated = 1
19:49:04 :    11857 : MYSQL                   MYSQL Error:  : 1205 : Lock wait timeout exceeded; try restarting transaction
19:49:04 :    11857 : MYSQL               Looking for item Chaim
19:49:04 :    11857 : MYSQL                 Trying by artist Transitions (2018-06-15) Part 2 Uri NOT NULL and title Chaim
19:49:04 :    11857 : MYSQL                 Trying by (wishlist) artist Transitions (2018-06-15) Part 2 and title Chaim
19:49:04 :    11857 : USERRATING          ---------------------------END----------------------

I was looking for an idea what this is, this page recommends something on the dev page

thanks

#11

This is all because your Music Collection update is timing out and then you try to start it again while it is still running. This will cause database corruption.

You are the first person to experience this. What hardware is your apache server running on? A clockwork watch?

gerroon · Author

Well, I am using it on a Quad core intel 7 with 12 gb ram, the database is on a ssd so the system.

I am probably trying to index about close to 100.000 files. Although Beets is trying to index the same media around the same time, not sure of cpu would affect it. I am running Beets with the lowest priority.

If you can give me some tips on this timing out mysql stuff, I can try it. I am not a dev so I do not know all this stuff in depth, and Iw as not getting much from what I could find online about it before posting it here.

I already recreated the database from scratch by deleting and recreting it.

gerroon · Author

Btw I had the exact issue of "Failed to generate Collection: Undefined timeout" with Sqlite too, so I am really not sure.

Screenshot

The only issue I can see is that, the Mopidy is not running on the Apache server pc. The browser session is on where Mopidy is. Apache and Mysql is running on the Quadi7 one I mentioned. Mopidy is running on another computer in my room.

The Mopidy media files are all local, but the mopidy pc (so the browser session) is conected to the apache server via 120mbs wifi.

#14

100,000 tracks is a very large amount, but if you are seeing the timeout error then your update is taking more than 12 minutes. For comparison, my Quad core iMac scans 40,000 tracks in 48 seconds so I suggest you may have other, underlying issues. The communication with Mopidy across the WiFi will be a large factor in this, and you must let Beets finish its scan first - otherwise the Beets database will not be complete. Do one thing at a time, take it step by step, don't be impatient.

The troubleshooting docs contain the info you need to increase the webserver timeout values so I won't repeat them here. However, this may not be sufficient to solve this problem.

However, if you start the update running and you get the timeout error, just leave it. Do nothing. Don't play any music, don't use the UI at all. The update process will keep running; attempting to do anything else with the database while this is happening will cause the errors you are seeing and the database corruption. I am looking into that but for now you must be patient and let the process complete.
You can monitor whether the update is still running by monitoring the log. You'll see info pouring out while it is scanning tracks.

gerroon · Author

Hi

Thanks for the detail follow up on this. I now have a better guide to go through this. I will wait until all this isdone , and maybe follow up here in case other people who check the forum might have similar issues.

Btw I already did the php.ini settings so that did not seemed to help with the issue.