04-30 20:02:52.538: D/Provider(8030): Integrity check OK
04-30 20:02:52.568: D/dalvikvm(8030): GC_FOR_ALLOC freed 1886K, 18% free 13019K/15752K, paused 29ms, total 29ms
04-30 20:02:53.568: D/TransactionManager(8030): ThreadSerializer exiting
04-30 20:02:53.568: D/TransactionManager(8030): releaseWakeLock
04-30 20:02:53.578: I/TransactionManager(8030): ThreadSerializer exit
04-30 20:03:01.868: D/StorageObserverService(8030): Stop observers
04-30 20:03:01.868: D/MediaStoreSyncObserver(8030): Stop
04-30 20:03:01.868: D/StorageObserverService(8030): DelayedDatabaseCopyHandler: Call PublishDatabase start
04-30 20:03:01.868: D/RemoteDatabaseObserver(8030): Storage event: 32768 - null
04-30 20:03:01.878: D/MediaMonkeyStoreProvider 1(8030): Insert: /publish_database,Values:null
04-30 20:03:01.878: I/TransactionManager(8030): PublishDatabase put OperationRequest
04-30 20:03:01.878: W/TransactionManager(8030): UI thread is putting request to TM!
04-30 20:03:01.878: W/TransactionManager(8030): 	at dalvik.system.VMStack.getThreadStackTrace(Native Method)
04-30 20:03:01.878: W/TransactionManager(8030): 	at java.lang.Thread.getStackTrace(Thread.java:579)
04-30 20:03:01.888: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.TransactionManager$Request.<init>(TransactionManager.java:693)
04-30 20:03:01.888: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.TransactionManager$OperationRequest.<init>(TransactionManager.java:640)
04-30 20:03:01.888: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.TransactionManager$OperationRequest.<init>(TransactionManager.java:658)
04-30 20:03:01.888: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.TransactionManager.publishDatabase(TransactionManager.java:2013)
04-30 20:03:01.898: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.MediaMonkeyStoreProvider.insert(MediaMonkeyStoreProvider.java:502)
04-30 20:03:01.898: W/TransactionManager(8030): 	at android.content.ContentProvider$Transport.insert(ContentProvider.java:220)
04-30 20:03:01.898: W/TransactionManager(8030): 	at android.content.ContentResolver.insert(ContentResolver.java:1190)
04-30 20:03:01.898: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.dao.Dao.publishDatabase(Dao.java:316)
04-30 20:03:01.898: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.db.dao.Dao.publishDatabase(Dao.java:305)
04-30 20:03:01.908: W/TransactionManager(8030): 	at com.ventismedia.android.mediamonkey.storage.StorageObserverService$DelayedDatabaseCopyHandler.handleMessage(StorageObserverService.java:120)
04-30 20:03:01.908: W/TransactionManager(8030): 	at android.os.Handler.dispatchMessage(Handler.java:102)
04-30 20:03:01.908: W/TransactionManager(8030): 	at android.os.Looper.loop(Looper.java:136)
04-30 20:03:01.908: W/TransactionManager(8030): 	at android.app.ActivityThread.main(ActivityThread.java:5017)
04-30 20:03:01.908: W/TransactionManager(8030): 	at java.lang.reflect.Method.invokeNative(Native Method)
04-30 20:03:01.908: W/TransactionManager(8030): 	at java.lang.reflect.Method.invoke(Method.java:515)
04-30 20:03:01.918: W/TransactionManager(8030): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:779)
04-30 20:03:01.918: W/TransactionManager(8030): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:595)
04-30 20:03:01.918: W/TransactionManager(8030): 	at dalvik.system.NativeStart.main(Native Method)
04-30 20:03:01.918: D/TransactionManager 13(8030): ThreadSerializer is turning off, starting new one...
04-30 20:03:01.928: D/StorageObserverService(8030): DelayedDatabaseCopyHandler: Call PublishDatabase end
04-30 20:03:01.928: D/StorageObserverService(8030): Start observers
04-30 20:03:01.928: D/MediaStoreSyncObserver(8030): Start
04-30 20:03:01.938: D/TransactionManager(8030): acquireWakeLock
04-30 20:03:01.948: W/TransactionManager(8030): New ThreadSerializer id from -1 to 3594
04-30 20:03:01.948: I/TransactionManager(8030): Command: PublishDatabase
04-30 20:03:01.978: D/ExternalSQLiteOpenHelper(8030): Checkpoint result:0,4,4
04-30 20:03:01.988: D/DbUtils(8030): Creating DB copy 
04-30 20:03:01.988: D/DbUtils(8030): isMainStorageAvailable? true
04-30 20:03:01.988: W/StorageUtils(8030): Delete file: /storage/emulated/0/MediaMonkey/files/mmstore.db-wal
04-30 20:03:01.988: W/StorageUtils(8030): Delete file: /storage/emulated/0/MediaMonkey/files/mmstore.db-shm
04-30 20:03:01.998: W/StorageUtils(8030): Delete file: /storage/emulated/0/MediaMonkey/files/mmstore.db-journal
04-30 20:03:01.998: W/StorageUtils(8030): Delete file: /storage/emulated/0/MediaMonkey/files/mmstore.db
04-30 20:03:01.998: D/RemoteDatabaseObserver(8030): Storage event: DELETE - mmstore.db
04-30 20:03:01.998: W/FilesMsDao(8030): Delete file from MediaStore: /storage/emulated/0/MediaMonkey/files/mmstore.db
04-30 20:03:02.078: D/StorageUtils(8030): Scan files: [/storage/emulated/0/MediaMonkey/files]
04-30 20:03:02.088: D/RemoteDatabaseObserver(8030): Storage event: CREATE - mmstore.db
04-30 20:03:02.098: D/RemoteDatabaseObserver(8030): Storage event: OPEN - mmstore.db
04-30 20:03:02.118: D/RemoteDatabaseObserver(8030): Storage event: MODIFY - mmstore.db
04-30 20:03:02.118: D/RemoteDatabaseObserver(8030): Storage event: CLOSE WRITE - mmstore.db
04-30 20:03:02.128: D/DbUtils(8030): DB copy created
04-30 20:03:02.128: D/StorageUtils(8030): Scan files: [/storage/emulated/0/MediaMonkey/files/mmstore.db]
04-30 20:03:02.418: D/StorageUtils(8030): Scanned /storage/emulated/0/MediaMonkey/files, uri=content://media/external/file/2907
04-30 20:03:02.478: D/StorageUtils(8030): Scanned /storage/emulated/0/MediaMonkey/files/mmstore.db, uri=content://media/external/file/17006
04-30 20:03:03.138: D/TransactionManager(8030): ThreadSerializer exiting
04-30 20:03:03.138: D/TransactionManager(8030): releaseWakeLock
04-30 20:03:03.138: I/TransactionManager(8030): ThreadSerializer exit
04-30 20:03:09.248: D/RemoteDatabaseObserver(8030): Storage event: 1073741856 - null
04-30 20:03:09.248: D/RemoteDatabaseObserver(8030): Storage event: 1073741840 - null
04-30 20:03:11.308: D/PlaybackService(8030): onCompletion
04-30 20:03:11.308: D/PlaybackService(8030): currentPlayerPosition:19435
04-30 20:03:11.318: D/AudioPlayer(8030): isCompletion:true
04-30 20:03:11.318: D/AudioPlayer(8030): updateTimePlayedInSession from 0 LastCurrentPosition:19435 currentPosition:19435 mStartPosition:0
04-30 20:03:11.318: D/AudioPlayer(8030): old method increment:19435
04-30 20:03:11.318: D/AudioPlayer(8030): TPS updated: 19435
04-30 20:03:11.318: D/PlaybackService(8030): updatePlaycount
04-30 20:03:11.318: D/AudioPlayer(8030): isCompletion:true
04-30 20:03:11.328: D/AudioPlayer(8030): updateTimePlayedInSession from 19435 LastCurrentPosition:19435 currentPosition:19435 mStartPosition:19435
04-30 20:03:11.328: D/AudioPlayer(8030): old method increment:0
04-30 20:03:11.358: D/dalvikvm(8030): GC_FOR_ALLOC freed 1806K, 18% free 12988K/15752K, paused 31ms, total 32ms
04-30 20:03:11.358: D/AudioPlayer(8030): TPS updated: 19435
04-30 20:03:11.368: D/MediaMonkeyStoreDbTrack(8030): calculateAndUpdatePlaycount:18 Unknown
04-30 20:03:11.368: D/MediaMonkeyStoreDbTrack(8030): Track is shorter than 3 minutes, update playcount to ...1
04-30 20:03:11.368: V/TEST(8030): updateLoggedAsync last_time_played=1398880991 playcount=1
04-30 20:03:11.368: I/Dao(8030): Atomic operation start
04-30 20:03:11.368: D/TransactionManager(8030): UI thread is putting request to TM asynchronously!
04-30 20:03:11.368: D/TransactionManager 13(8030): ThreadSerializer is turning off, starting new one...
04-30 20:03:11.368: I/Dao(8030): Atomic operation end
04-30 20:03:11.368: D/TransactionManager(8030): acquireWakeLock
04-30 20:03:11.368: D/PlaybackService(8030): TrackList is loaded.
04-30 20:03:11.368: W/TransactionManager(8030): New ThreadSerializer id from -1 to 3596
04-30 20:03:11.378: D/PlaybackService(8030): nextTrack
04-30 20:03:11.378: I/TrackList(8030): nextTrack
04-30 20:03:11.378: D/TrackList(8030): Current track position 7 tracklist size:42
04-30 20:03:11.378: I/TrackList(8030): setCurrentTrack: AudioTrack storeToPreferences:true
04-30 20:03:11.378: D/TrackList(8030): clearTrackIndexes
04-30 20:03:11.378: D/TrackListModel(8030): Store current track to preferences: De-Sci-Fer-4 Hero (Two Pages)
04-30 20:03:11.378: D/TrackListModel(8030):  storeCurrentTrack pos:8 list.size:42
04-30 20:03:11.378: D/TrackListModel(8030): storeCurrentTrackInfo: InfoTrack: De-Sci-Fer-4 Hero (Two Pages)
04-30 20:03:11.378: D/TrackListModel(8030): storeCurrentTrackInfo: InfoTrack: De-Sci-Fer-4 Hero (Two Pages)
04-30 20:03:11.388: D/PlaybackService(8030): play
04-30 20:03:11.388: W/PlaybackService(8030): gainAudioFocus()
04-30 20:03:11.388: W/PlaybackService(8030): registerMediaButtonEventReceiver  on checkRemoteControlClientCompact
04-30 20:03:11.388: I/PlaybackService(8030): registerMediaButtonEventReceiver
04-30 20:03:11.388: D/PlaybackService(8030): mPlayer.setNormalVolume
04-30 20:03:11.398: D/PlaybackService(8030): Track can be played AudioTrack
04-30 20:03:11.398: D/TrackList(8030): playCurrentTrack
04-30 20:03:11.418: V/TEST(8030): Updating track
04-30 20:03:11.418: D/AllMediaDao(8030): existsDirect?
04-30 20:03:11.418: D/MediaMonkeyStoreProvider 1(8030): Query: /query;Projection:null;Selection:SELECT _ID FROM media WHERE _id=?;Args:[8]
04-30 20:03:11.448: D/AudioPlayer(8030): setPlayerState to: PLAYING
04-30 20:03:11.458: D/AudioPlayer(8030): initTimePlayedInSession
04-30 20:03:11.458: D/PlaybackService(8030): enableEqualizerIfNeeded
04-30 20:03:11.458: D/EqualizerModel(8030): isEnabledEqualizer:false
04-30 20:03:11.458: D/PlaybackService(8030): updateRemoteMetadata(supported:true) - TrackInfo:De-Sci-Fer
04-30 20:03:11.458: W/PlaybackService(8030): updating RemoteControl state!
04-30 20:03:11.458: D/PlaybackService(8030): updateRemotePlaybackPosition
04-30 20:03:11.458: V/PlaybackService(8030): updateRemoteMetadata: De-Sci-Fer
04-30 20:03:11.458: D/PlaybackService 3(8030):  currentTrack.getAlbumArt: file:///storage/emulated/0/Android/data/com.android.providers.media/albumthumbs/1356021195608
04-30 20:03:11.468: D/PlaybackService(8030): RemoteControlClientCompat available: true
04-30 20:03:11.468: D/PlaybackService(8030): albumArt width:320 height:294
04-30 20:03:11.478: D/PlaybackService 3(8030):  currentTrack.getAlbumArt is not null true
04-30 20:03:11.498: D/dalvikvm(8030): GC_FOR_ALLOC freed 1405K, 16% free 13360K/15752K, paused 28ms, total 28ms
04-30 20:03:11.508: D/PlaybackService(8030): updateWidgets immediately
04-30 20:03:11.508: D/PlaybackService(8030): updateWidgets tracklist is loaded
04-30 20:03:11.508: D/PlayerWidgetModel(8030): Loading widget Ids
04-30 20:03:11.508: W/PlaybackService(8030): updateRemotePlaybackState isPlaying:true
04-30 20:03:11.508: I/PlaybackService(8030): refreshSuppressNotificationSounds
04-30 20:03:11.508: D/GlobalPreferences(8030): isSuppressNotificationSounds: false
04-30 20:03:11.508: D/UIUtils(8030): isAppVisible: true
04-30 20:03:11.518: D/PlaybackService(8030): updateNotification app is : in foreground isInKeyguardRestrictedInputMode: false
04-30 20:03:11.518: D/UIUtils(8030): isAppVisible: true
04-30 20:03:11.518: D/PlaybackService(8030): T2 show notification when player is playing
04-30 20:03:11.518: D/PlaybackService(8030): showNotification is Playing: true playerState: PLAYING
04-30 20:03:11.518: D/PlaybackService(8030): mUseLockScreenPlayer false
04-30 20:03:11.518: D/PlaybackService(8030): receiverRegistered false
04-30 20:03:11.518: D/PlaybackService(8030): updateWidgets tracklist is loaded
04-30 20:03:11.518: I/TrackList(8030): hasNextTrack
04-30 20:03:11.518: I/BitmapUtils(8030): albumArt:file:///storage/emulated/0/Android/data/com.android.providers.media/albumthumbs/1356021195608
04-30 20:03:11.558: D/dalvikvm(8030): GC_FOR_ALLOC freed 948K, 17% free 13083K/15752K, paused 30ms, total 31ms
04-30 20:03:11.558: D/PlaybackNotification(8030): prepareStopButton
04-30 20:03:11.568: I/BitmapUtils(8030): albumArt:file:///storage/emulated/0/Android/data/com.android.providers.media/albumthumbs/1356021195608
04-30 20:03:11.588: D/dalvikvm(8030): GC_FOR_ALLOC freed 292K, 15% free 13425K/15752K, paused 26ms, total 26ms
04-30 20:03:11.598: I/dalvikvm-heap(8030): Grow heap (frag case) to 13.501MB for 376336-byte allocation
04-30 20:03:11.628: D/dalvikvm(8030): GC_FOR_ALLOC freed <1K, 15% free 13793K/16120K, paused 31ms, total 31ms
04-30 20:03:11.628: D/PlaybackNotification(8030): prepareStopButton
04-30 20:03:11.648: D/PlaybackService(8030): updateWidgets immediately
04-30 20:03:11.648: D/PlaybackService(8030): updateWidgets tracklist is loaded
04-30 20:03:11.648: D/PlayerWidgetModel(8030): Loading widget Ids
04-30 20:03:11.648: W/PlaybackService(8030): updateRemotePlaybackState isPlaying:true
04-30 20:03:11.648: D/BroadcastSender 1(8030): SEND STATE_CHANGE_ACTION
04-30 20:03:11.658: D/BroadcastSender 1(8030): SEND NEXT_TRACK_START_ACTION is video ?false
04-30 20:03:11.658: D/PlaybackService(8030): onCompletion end
04-30 20:03:11.658: E/Provider(8030): Integrity check failed:
04-30 20:03:11.658: D/MediaStoreSyncService(8030): Service is not running
04-30 20:03:11.658: D/StorageObserverService(8030): Publish database event received.
04-30 20:03:11.658: E/MediaPlayer(8030): Should have subtitle controller already set
04-30 20:03:11.658: E/Provider(8030): rowid 2 missing from index playlist_data_idx
04-30 20:03:11.668: D/NowPlayingFragment(8030): Intent command received
04-30 20:03:11.668: D/NowPlayingFragment(8030): RECEIVE - STATE_CHANGE_ACTION
04-30 20:03:11.668: D/NowPlayingFragment(8030): REFRESH PREVIOUS TRACK INFO
04-30 20:03:11.668: E/Provider(8030): rowid 2 missing from index sqlite_autoindex_playlists_1
04-30 20:03:11.668: I/TrackList(8030): hasNextTrack
04-30 20:03:11.668: E/Provider(8030): rowid 1 missing from index media_title_type_idx
04-30 20:03:11.668: I/TrackList(8030): nextTrack
04-30 20:03:11.668: D/NowPlayingFragment(8030): updating view
04-30 20:03:11.678: E/Provider(8030): rowid 7 missing from index media_title_type_idx
04-30 20:03:11.678: E/Provider(8030): rowid 13 missing from index media_title_type_idx
04-30 20:03:11.678: E/Provider(8030): rowid 15 missing from index media_title_type_idx
04-30 20:03:11.678: D/TrialTimeUtils(8030): com.ventismedia.android.mediamonkey isProVersionInstalled: false signatureMatch:-3
04-30 20:03:11.678: E/Provider(8030): rowid 20 missing from index media_title_type_idx
04-30 20:03:11.678: E/Provider(8030): rowid 23 missing from index media_title_type_idx
04-30 20:03:11.678: D/NowPlayingActivity(8030): Activity onPrepareOptionsMenu
04-30 20:03:11.678: E/Provider(8030): rowid 3 missing from index album_name_type_idx
04-30 20:03:11.678: D/NowPlayingFragment(8030): onPrepareOptionsMenu
04-30 20:03:11.688: E/Provider(8030): rowid 4 missing from index album_name_type_idx