[nocturneop15]

Hello,

I used TinyMediaManager for managing both my movies and tv shows.
Storage - SMB share in windows 2012R2 server, mapped as network drive.
Structure like this:

x:\movies\movie1
x:\movies\movie2
etc.

Client - windows 10 x64.

Everything worked for months until I added last four movies, TMM found only one of them. I scraped it, closed TMM and reopened it in hope that new movies will appear in DB after updating datasource. they did not, I decidd to reinitialize DB. Since that, TMM does not see any movies, even if it takes some time to perform "update". "TV Shows" shows only list of shows, but no episodes inside. all the data was scraped before, all nfo files, images etc are stil in place and are read by KODI

What i tried:
- remove newly added movies (to avoid conflict caused by potentionaly bad characters in movie name)
- initialized database (since that, DB stays clean, no movies detected anymore)
- delete TMM, download and set up fresh DB. Tried even nightly builds - remains the same
- tried to create new folder on server with only few movies - no result
- doublechecked permision on all involved folders


I ran out of ideas now. Do you have any suggestion how to fix this situation?

Thanks in avance for any suggestion how to diagnose or solve this issue. Also sorry if there is solution described somewhere in this forum - i tried to find it before I posted, but without success.


EDIT: in log, I found following:

2016-07-11 21:56:26,737 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:1150 - Skipping dir: X:\Filmy\Bitva o Britanii - Battle of Britain (1969)\.actors

The same for every folder.

EDIT2:
cache is populated by images from TV series. It obviously looks for fodlers, but is skipping all of them for some reasons...

[jwaltrip]

I am using same setup.
2012r2 server
Win10 PC

My movies are all in shares:

\\servername\share, mapped to a drive letter
O: = \\servername\MoviesMoviesShare

Under O:, I have top level folders for each movie type, animated, Comedy, Drama, etc

I define them in TMM as O:\Animated, O:\Drama, etc

I have not had any issues with TMM missing movies.

[nocturneop15]

I did not have any troubles for many months. Now, it acts like I described, without any change in folder structure or so. Even when I restored TMM from backups, nothing changed.

[jwaltrip]

very strange

what do your shares look like? do a net share.

Also... have you made sure that the permissions are set consistently on the folders?

- always make your shares everyone with full control
- set permissions at the folder level. I can send you a batch files that will do it.

[nocturneop15]

I'm long time IT admin, my home environment is more like mid-size company infrastructure than usual small home network :-)

Shares are mapped by GPO, not scripts. Some shares are through DFS namespace (but not those with media), some (including the one containing movies and tv shows) are mapped directly from file server(s).

Permissions are maintained very strictly, but permission structure is very simple - every folder in root has apropriate AD groups named "folder-RW", "folder-R". This simple method cannot be messed. BTW, it is regulary checked by reporting powershell scripts for tracking every changes). Also CRC checks above files shows total consistency.

I installed Java on fileserver and tried to run TMM localy under high-privileged account to exclude any network influence. Situation stays the same, so this brings me back to original idea - maybe some malformed name may cause troubles with TMM. I must try which one could that be...

[nocturneop15]

No success. Tried movies with absolutely clear names (no special chars etc.) - and they are not loaded. Tried to add new, empty folder, new, never seen ( = no nfo's, pictures or any other meta, just a movie itself) files into it - and it is still the same :-(

From logs, it is obvious that it recursively goes through folders, also it inceases count in following sections with every pass of updating datasource - values of predir, postdir, visfile are incrementing by +1 with every pass

2016-07-12 00:22:39,962 INFO [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:215 - Done updating datasource :) - took 00:00:00.002
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:217 - FilesFound 0 #stays 0
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:218 - moviesFound 0
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:219 - PreDir 6
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:220 - PostDir 4
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:221 - VisFile 22
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:222 - PreDir2 0
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:223 - PostDir2 0
2016-07-12 00:22:39,962 DEBUG [tmmpool-main-task-thread-4] o.t.c.m.tasks.MovieUpdateDatasourceTask2:224 - VisFile2 0

[jwaltrip]

Other than the security sounds like pretty much what I am doing. I use a script to set my security (standard for all folders on my server), and I use DFS to set up shares... I map a drive to the DFS root, and my movies are classified in folders under that root.

I think that the folks here will want a log of the activity for further analysis

[myron]

any chances of a complete log?

[nocturneop15]

Sure. This is complete log of newly created movie folder, containing one subfolder with one movie inside. Never scraped, no metadata inside. Two iterations of update:

Code:

2016-07-12 07:50:12,222 DEBUG [main] org.tinymediamanager.core.Settings:242 - Loading settings from data
2016-07-12 07:50:12,602 INFO  [main] org.tinymediamanager.TinyMediaManager:149 - =====================================================
2016-07-12 07:50:12,602 INFO  [main] org.tinymediamanager.TinyMediaManager:150 - === tinyMediaManager (c) 2012-2016 Manuel Laggner ===
2016-07-12 07:50:12,602 INFO  [main] org.tinymediamanager.TinyMediaManager:151 - =====================================================
2016-07-12 07:50:12,604 INFO  [main] org.tinymediamanager.TinyMediaManager:152 - tmm.version      : 2.8.2-SNAPSHOT - PRE-RELEASE
2016-07-12 07:50:12,604 INFO  [main] org.tinymediamanager.TinyMediaManager:158 - os.name          : Windows 10
2016-07-12 07:50:12,604 INFO  [main] org.tinymediamanager.TinyMediaManager:159 - os.version       : 10.0
2016-07-12 07:50:12,604 INFO  [main] org.tinymediamanager.TinyMediaManager:160 - os.arch          : x86
2016-07-12 07:50:12,639 INFO  [main] org.tinymediamanager.TinyMediaManager:162 - java.version     : 1.8.0_91
2016-07-12 07:50:12,639 INFO  [main] org.tinymediamanager.TinyMediaManager:522 - default encoding : UTF-8 | UTF8 | UTF-8
2016-07-12 07:50:12,639 INFO  [main] org.tinymediamanager.TinyMediaManager:522 - set encoding to  : UTF-8 | UTF8 | UTF-8
2016-07-12 07:50:12,639 INFO  [main] org.tinymediamanager.TinyMediaManager:187 - System language  : cs_CZ
2016-07-12 07:50:12,640 INFO  [main] org.tinymediamanager.TinyMediaManager:188 - GUI language     : cs_CZ
2016-07-12 07:50:12,641 INFO  [main] org.tinymediamanager.TinyMediaManager:189 - Scraper language : Český
2016-07-12 07:50:12,641 INFO  [main] org.tinymediamanager.TinyMediaManager:190 - TV Scraper lang  : Český
2016-07-12 07:50:12,763 INFO  [main] org.tinymediamanager.TinyMediaManager:238 - =====================================================
2016-07-12 07:50:12,783 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (0%) starting tinyMediaManager
2016-07-12 07:50:12,784 INFO  [main] org.tinymediamanager.TinyMediaManager:243 - starting tinyMediaManager
2016-07-12 07:50:12,786 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (10%) upgrading to new version
2016-07-12 07:50:13,104 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (20%) loading MediaInfo libs
2016-07-12 07:50:13,106 DEBUG [main] o.t.thirdparty.MediaInfoUtils:65 - Loading native mediainfo lib from: native/windows-x86
2016-07-12 07:50:13,165 INFO  [main] o.t.thirdparty.MediaInfoUtils:74 - Using MediaInfoLib - v0.7.85
2016-07-12 07:50:13,166 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (30%) loading movie module
2016-07-12 07:50:13,509 INFO  [main] o.tinymediamanager.core.movie.MovieList:326 - found 0 movies in database
2016-07-12 07:50:13,510 INFO  [main] o.tinymediamanager.core.movie.MovieList:346 - found 0 movieSets in database
2016-07-12 07:50:13,511 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (40%) loading TV show module
2016-07-12 07:50:13,575 INFO  [main] o.t.core.tvshow.TvShowList:275 - found 0 TV shows in database
2016-07-12 07:50:13,576 INFO  [main] o.t.core.tvshow.TvShowList:305 - found 0 episodes in database
2016-07-12 07:50:13,577 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (50%) loading plugins
2016-07-12 07:50:13,613 DEBUG [main] o.t.scraper.util.PluginManager:61 - loading external plugins...
2016-07-12 07:50:13,670 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_fanarttv.conf' - using defaults
2016-07-12 07:50:13,678 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_imdb.conf' - using defaults
2016-07-12 07:50:13,683 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:284 - searching for Kodi commons
2016-07-12 07:50:13,684 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:318 - Meh - could not find any common folders...
2016-07-12 07:50:13,685 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:373 - Meh - could not find any common function...
2016-07-12 07:50:13,685 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:214 - searching for Kodi scrapers
2016-07-12 07:50:13,686 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:244 - Meh - could not find any scrapers...
2016-07-12 07:50:13,701 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_opensubtitles.conf' - using defaults
2016-07-12 07:50:13,736 DEBUG [main] o.t.scraper.util.PluginManager:72 - Done loading external plugins - took 00:00:00.112
2016-07-12 07:50:13,737 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (70%) upgrading database to new version
2016-07-12 07:50:13,739 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (80%) loading ui
2016-07-12 07:50:13,874 DEBUG [main] o.tinymediamanager.ui.movies.MoviePanel:185 - loading MovieList
2016-07-12 07:50:14,522 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (100%) finished starting :)
2016-07-12 07:50:14,528 DEBUG [trackEventThread] org.tinymediamanager.scraper.http.Url:232 - getting https://ssl.google-analytics.com/collect?v=1&tid=UA-35564534-5&cid=d101c694-18e2-4d8c-8adc-03a22c180a0e&an=tinyMediaManager&av=PRE-RELEASE&t=event&ec=startup&ea=startup&aip=1&je=1&sc=start&ul=cs-CZ&vp=1100x727&cd1=Windows+10&cd2=x86&cd3=1.8&cd4=2.8.2-SNAPSHOT&cd5=0&z=1468302614524&sr=1920x1080
2016-07-12 07:50:19,525 INFO  [updateThread] org.tinymediamanager.core.UpdaterTask:67 - Checking for updates...
2016-07-12 07:50:19,529 DEBUG [updateThread] org.tinymediamanager.scraper.http.Url:232 - getting http://prerelease.tinymediamanager.org/build/digest.txt?z=1468302619528
2016-07-12 07:50:19,766 INFO  [updateThread] org.tinymediamanager.core.UpdaterTask:150 - Already up2date :)
2016-07-12 07:50:19,801 DEBUG [main] org.tinymediamanager.ui.MainWindow:303 - update result was: false
2016-07-12 07:50:36,497 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:844 - removing orphaned movies/files...
2016-07-12 07:50:36,497 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:907 - getting Mediainfo...
2016-07-12 07:50:36,497 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:215 - Done updating datasource :) - took 00:00:00.009
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:217 - FilesFound 0
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:218 - moviesFound 0
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:219 - PreDir 1
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:220 - PostDir 1
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:221 - VisFile 1
2016-07-12 07:50:36,498 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:222 - PreDir2 0
2016-07-12 07:50:36,499 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:223 - PostDir2 0
2016-07-12 07:50:36,499 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:224 - VisFile2 0
2016-07-12 07:51:25,178 INFO  [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:844 - removing orphaned movies/files...
2016-07-12 07:51:25,178 INFO  [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:907 - getting Mediainfo...
2016-07-12 07:51:25,178 INFO  [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:215 - Done updating datasource :) - took 00:00:00.002
2016-07-12 07:51:25,178 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:217 - FilesFound 0
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:218 - moviesFound 0
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:219 - PreDir 2
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:220 - PostDir 2
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:221 - VisFile 2
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:222 - PreDir2 0
2016-07-12 07:51:25,179 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:223 - PostDir2 0
2016-07-12 07:51:25,180 DEBUG [tmmpool-main-task-thread-2] o.t.c.m.tasks.MovieUpdateDatasourceTask2:224 - VisFile2 0

[myron]

hmm.. cannot see ANY parsing / directory walking in logfile.
Log looks like, as if there is NONE file in your specified datasource.
What is the path/name of that folder/filename?
Could you check the settings once again, and remove/readd the datasource?

Or, even delete/rename the /data/ folder, to start complete clean...

[nocturneop15]

There was one movie in one subfolder during last log.

I checked all the settings, all the tests are being made under high privileged account. I also reseted movie folder security, at this moment, "domain users" group has full access permissions. Deleting data folder has been done multiple times, also whole TMM folder was deleted and downloaded fresh archive. Any hint how to perform better diagnostics to clarify this issue will be appreciated. I can bet that we will find something stupid at the end :-)

As next step, I will touch TMM process with lowlevel tools from sysinternals to see if I can found some read or write issues.

Here is the latest log. At this moment, conditions are:
4 movies in 4 subfolders, one is "bare" without metainfo, three of them are scraped by TMM from the past. All recognized well by KODI. In total, 41 files and 6 folders are present in "x:\filmy" path

Code:

2016-07-12 21:44:31,222 DEBUG [main] org.tinymediamanager.core.Settings:242 - Loading settings from data
2016-07-12 21:44:31,549 INFO  [main] org.tinymediamanager.TinyMediaManager:149 - =====================================================
2016-07-12 21:44:31,550 INFO  [main] org.tinymediamanager.TinyMediaManager:150 - === tinyMediaManager (c) 2012-2016 Manuel Laggner ===
2016-07-12 21:44:31,550 INFO  [main] org.tinymediamanager.TinyMediaManager:151 - =====================================================
2016-07-12 21:44:31,551 INFO  [main] org.tinymediamanager.TinyMediaManager:152 - tmm.version      : 2.8.2-SNAPSHOT - PRE-RELEASE
2016-07-12 21:44:31,551 INFO  [main] org.tinymediamanager.TinyMediaManager:158 - os.name          : Windows 10
2016-07-12 21:44:31,551 INFO  [main] org.tinymediamanager.TinyMediaManager:159 - os.version       : 10.0
2016-07-12 21:44:31,552 INFO  [main] org.tinymediamanager.TinyMediaManager:160 - os.arch          : x86
2016-07-12 21:44:31,595 INFO  [main] org.tinymediamanager.TinyMediaManager:162 - java.version     : 1.8.0_91
2016-07-12 21:44:31,595 INFO  [main] org.tinymediamanager.TinyMediaManager:522 - default encoding : UTF-8 | UTF8 | UTF-8
2016-07-12 21:44:31,596 INFO  [main] org.tinymediamanager.TinyMediaManager:522 - set encoding to  : UTF-8 | UTF8 | UTF-8
2016-07-12 21:44:31,596 INFO  [main] org.tinymediamanager.TinyMediaManager:187 - System language  : cs_CZ
2016-07-12 21:44:31,596 INFO  [main] org.tinymediamanager.TinyMediaManager:188 - GUI language     : cs_CZ
2016-07-12 21:44:31,598 INFO  [main] org.tinymediamanager.TinyMediaManager:189 - Scraper language : Český
2016-07-12 21:44:31,598 INFO  [main] org.tinymediamanager.TinyMediaManager:190 - TV Scraper lang  : Český
2016-07-12 21:44:31,717 INFO  [main] org.tinymediamanager.TinyMediaManager:238 - =====================================================
2016-07-12 21:44:31,735 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (0%) starting tinyMediaManager
2016-07-12 21:44:31,736 INFO  [main] org.tinymediamanager.TinyMediaManager:243 - starting tinyMediaManager
2016-07-12 21:44:31,738 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (10%) upgrading to new version
2016-07-12 21:44:32,107 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (20%) loading MediaInfo libs
2016-07-12 21:44:32,108 DEBUG [main] o.t.thirdparty.MediaInfoUtils:65 - Loading native mediainfo lib from: native/windows-x86
2016-07-12 21:44:32,171 INFO  [main] o.t.thirdparty.MediaInfoUtils:74 - Using MediaInfoLib - v0.7.85
2016-07-12 21:44:32,172 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (30%) loading movie module
2016-07-12 21:44:32,467 INFO  [main] o.tinymediamanager.core.movie.MovieList:326 - found 0 movies in database
2016-07-12 21:44:32,468 INFO  [main] o.tinymediamanager.core.movie.MovieList:346 - found 0 movieSets in database
2016-07-12 21:44:32,469 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (40%) loading TV show module
2016-07-12 21:44:32,520 INFO  [main] o.t.core.tvshow.TvShowList:275 - found 0 TV shows in database
2016-07-12 21:44:32,520 INFO  [main] o.t.core.tvshow.TvShowList:305 - found 0 episodes in database
2016-07-12 21:44:32,521 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (50%) loading plugins
2016-07-12 21:44:32,551 DEBUG [main] o.t.scraper.util.PluginManager:61 - loading external plugins...
2016-07-12 21:44:32,601 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_fanarttv.conf' - using defaults
2016-07-12 21:44:32,609 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_imdb.conf' - using defaults
2016-07-12 21:44:32,613 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:284 - searching for Kodi commons
2016-07-12 21:44:32,615 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:318 - Meh - could not find any common folders...
2016-07-12 21:44:32,615 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:373 - Meh - could not find any common function...
2016-07-12 21:44:32,615 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:214 - searching for Kodi scrapers
2016-07-12 21:44:32,616 DEBUG [main] o.tinymediamanager.scraper.kodi.KodiUtil:244 - Meh - could not find any scrapers...
2016-07-12 21:44:32,628 WARN  [main] o.t.scraper.config.MediaProviderConfig:83 - Cannot load settings 'data\scraper_opensubtitles.conf' - using defaults
2016-07-12 21:44:32,661 DEBUG [main] o.t.scraper.util.PluginManager:72 - Done loading external plugins - took 00:00:00.099
2016-07-12 21:44:32,662 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (70%) upgrading database to new version
2016-07-12 21:44:32,664 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (80%) loading ui
2016-07-12 21:44:32,801 DEBUG [main] o.tinymediamanager.ui.movies.MoviePanel:185 - loading MovieList
2016-07-12 21:44:33,440 DEBUG [main] org.tinymediamanager.TinyMediaManager:414 - Startup (100%) finished starting :)
2016-07-12 21:44:33,445 DEBUG [trackEventThread] org.tinymediamanager.scraper.http.Url:232 - getting https://ssl.google-analytics.com/collect?v=1&tid=UA-35564534-5&cid=d101c694-18e2-4d8c-8adc-03a22c180a0e&an=tinyMediaManager&av=PRE-RELEASE&t=event&ec=startup&ea=startup&aip=1&je=1&sc=start&ul=cs-CZ&vp=1100x727&cd1=Windows+10&cd2=x86&cd3=1.8&cd4=2.8.2-SNAPSHOT&cd5=0&z=1468352673443&sr=1920x1080
2016-07-12 21:44:38,443 INFO  [updateThread] org.tinymediamanager.core.UpdaterTask:67 - Checking for updates...
2016-07-12 21:44:38,446 DEBUG [updateThread] org.tinymediamanager.scraper.http.Url:232 - getting http://prerelease.tinymediamanager.org/build/digest.txt?z=1468352678446
2016-07-12 21:44:39,772 INFO  [updateThread] org.tinymediamanager.core.UpdaterTask:150 - Already up2date :)
2016-07-12 21:44:39,807 DEBUG [main] org.tinymediamanager.ui.MainWindow:303 - update result was: false
2016-07-12 21:44:46,428 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:1150 - Skipping dir: X:\Filmy\Adelheid - Adelheid (1970)\.actors
2016-07-12 21:44:46,441 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:1150 - Skipping dir: X:\Filmy\Agent, ktery mne miloval - The Spy Who Loved Me (1977)\.actors
2016-07-12 21:44:46,446 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:844 - removing orphaned movies/files...
2016-07-12 21:44:46,446 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:907 - getting Mediainfo...
2016-07-12 21:44:46,447 INFO  [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:215 - Done updating datasource :) - took 00:00:00.104
2016-07-12 21:44:46,448 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:217 - FilesFound 0
2016-07-12 21:44:46,449 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:218 - moviesFound 0
2016-07-12 21:44:46,449 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:219 - PreDir 6
2016-07-12 21:44:46,450 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:220 - PostDir 4
2016-07-12 21:44:46,450 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:221 - VisFile 22
2016-07-12 21:44:46,451 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:222 - PreDir2 0
2016-07-12 21:44:46,452 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:223 - PostDir2 0
2016-07-12 21:44:46,452 DEBUG [tmmpool-main-task-thread-1] o.t.c.m.tasks.MovieUpdateDatasourceTask2:224 - VisFile2 0

Just to proof, here is directory listing, done under the same account as TMM was run:

Code:

Volume in drive X is VOL_DATA
Volume Serial Number is 7A4D-7B2D

Directory of X:\Filmy

12.07.2016  21:54    <DIR>          .
12.07.2016  21:54    <DIR>          ..
06.02.2016  23:41    <DIR>          Adelheid - Adelheid (1970)
07.02.2016  14:57    <DIR>          Afgansky zlom - Afganskiy Izlom (1991)
06.02.2016  23:43    <DIR>          Agent, ktery mne miloval - The Spy Who Loved Me (1977)
12.07.2016  21:54                68 list
10.07.2016  19:24    <DIR>          _zahradnik z argenteuil
               1 File(s)             68 bytes

Directory of X:\Filmy\Adelheid - Adelheid (1970)

06.02.2016  23:41    <DIR>          .
06.02.2016  23:41    <DIR>          ..
06.02.2016  23:41    <DIR>          .actors
02.09.2012  19:17       734˙005˙248 Adelheid - Adelheid (1970) - 640x480.avi
02.02.2016  22:28             3˙535 Adelheid - Adelheid (1970) - 640x480.nfo
10.01.2016  01:48           109˙555 fanart.jpg
10.01.2016  23:36             6˙025 movie.xml
10.01.2016  01:48            61˙397 poster.jpg
27.02.2013  21:25                 0 Thumbs.db_encryptable
               6 File(s)    734˙185˙760 bytes

Directory of X:\Filmy\Adelheid - Adelheid (1970)\.actors

06.02.2016  23:41    <DIR>          .
06.02.2016  23:41    <DIR>          ..
10.01.2016  01:48            20˙747 Jan_Vostrźil.jpg
10.01.2016  01:48            53˙503 Petr_¬epek.jpg
               2 File(s)         74˙250 bytes

Directory of X:\Filmy\Afgansky zlom - Afganskiy Izlom (1991)

07.02.2016  14:57    <DIR>          .
07.02.2016  14:57    <DIR>          ..
19.09.2015  16:53     1˙913˙362˙593 Afgansky zlom - Afganskiy Izlom (1991) - 740x586.mkv
07.02.2016  14:57             5˙587 Afgansky zlom - Afganskiy Izlom (1991) - 740x586.nfo
07.02.2016  14:57            88˙346 fanart.jpg
07.02.2016  14:57            76˙029 poster.jpg
               4 File(s)  1˙913˙532˙555 bytes

Directory of X:\Filmy\Agent, ktery mne miloval - The Spy Who Loved Me (1977)

06.02.2016  23:43    <DIR>          .
06.02.2016  23:43    <DIR>          ..
06.02.2016  23:43    <DIR>          .actors
24.04.2013  00:42     5˙706˙418˙171 Agent, ktery mne miloval - The Spy Who Loved Me (1977) - 1920x816.mkv
02.02.2016  22:28             7˙027 Agent, ktery mne miloval - The Spy Who Loved Me (1977) - 1920x816.nfo
23.01.2016  14:19           288˙030 banner.jpg
23.01.2016  14:19           397˙111 clearart.png
23.01.2016  14:19         1˙432˙253 disc.png
23.01.2016  14:19           264˙503 fanart.jpg
23.01.2016  14:19           203˙964 logo.png
02.02.2016  00:42            93˙069 movieset-fanart.jpg
02.02.2016  00:42            15˙004 movieset-poster.jpg
23.01.2016  14:19           422˙865 poster.jpg
              10 File(s)  5˙709˙541˙997 bytes

Directory of X:\Filmy\Agent, ktery mne miloval - The Spy Who Loved Me (1977)\.actors

06.02.2016  23:43    <DIR>          .
06.02.2016  23:43    <DIR>          ..
23.01.2016  14:19            30˙244 Barbara_Bach.jpg
23.01.2016  14:19            22˙045 Bernard_Lee.jpg
23.01.2016  14:19           126˙132 Caroline_Munro.jpg
23.01.2016  14:19            29˙443 Curd_Jrgens.jpg
23.01.2016  14:19           118˙933 Desmond_Llewelyn.jpg
23.01.2016  14:19            49˙613 Edward_de_Souza.jpg
23.01.2016  14:19            23˙606 Geoffrey_Keen.jpg
23.01.2016  14:19            23˙443 George_Baker.jpg
23.01.2016  14:19            22˙221 Lois_Maxwell.jpg
23.01.2016  14:19            28˙887 Michael_Billington.jpg
23.01.2016  14:19           115˙007 Nadim_Sawalha.jpg
23.01.2016  14:19            18˙196 Olga_Bisera.jpg
23.01.2016  14:19           102˙549 Richard_Kiel.jpg
23.01.2016  14:19            29˙177 Roger_Moore.jpg
23.01.2016  14:19            24˙463 Sydney_Tafler.jpg
23.01.2016  14:19            16˙758 Vernon_Dobtcheff.jpg
23.01.2016  14:19            91˙861 Walter_Gotell.jpg
              17 File(s)        872˙578 bytes

Directory of X:\Filmy\_zahradnik z argenteuil

10.07.2016  19:24    <DIR>          .
10.07.2016  19:24    <DIR>          ..
24.07.2011  19:36       677˙144˙378 zahradnik-z-argenteuil-jean-gabin-1966-cz-dub.avi
               1 File(s)    677˙144˙378 bytes

     Total Files Listed:
              41 File(s)  9˙035˙351˙586 bytes
              20 Dir(s)  3˙245˙219˙180˙544 bytes free

[nocturneop15]

So, I put sysinternals process explorer into game. I monitored .exe files of TMM as first, but then switched to monitor javaw.exe process, because this it the process responsible for querying folders. What I found? Querying folder returns its content, see this line detail for example:

Code:

High Resolution Date & Time:    12.07.2016 22:07:00,1620112
Event Class:    File System
Operation:    QueryDirectory
Result:    SUCCESS
Path:    \\kermorvan.whitelines.local\data\Filmy\Agent, ktery mne miloval - The Spy Who Loved Me (1977)
TID:    1624
Duration:    0.0000299
0:    ..
1:    .actors
2:    Agent, ktery mne miloval - The Spy Who Loved Me (1977) - 1920x816.mkv
3:    Agent, ktery mne miloval - The Spy Who Loved Me (1977) - 1920x816.nfo
4:    banner.jpg
5:    clearart.png
6:    disc.png
7:    fanart.jpg
8:    logo.png
9:    movieset-fanart.jpg
10:    movieset-poster.jpg
11:    poster.jpg

Searching folder ends with significant message:

Code:

High Resolution Date & Time:    12.07.2016 22:07:00,2152891
Event Class:    File System
Operation:    QueryDirectory
Result:    NO MORE FILES
Path:    \\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil
TID:    1624
Duration:    0.0000228

What surprised me was fact that javaw.exe process did not touch any file directly - just queried folders on server, checked access rights and created some files in network cache c:\windows\csc. Offline files are disabled (and was all the time computer is in use).

I can provide export of this tracing in native process explorer format if that may help you.

[nocturneop15]

Here is stripped process activity tracing for one of movie folders, something happening there that I cannot explain. Looks like trying to create .tmmignore files? (posting directly from CSV):

Code:

Time of Day,"Process Name","PID","Operation","Path","Result","Detail"
22:33:04,1659270,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
22:33:04,1662157,"javaw.exe","8304","QueryNetworkOpenInformationFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","CreationTime: 10.07.2016 19:24:52, LastAccessTime: 10.07.2016 19:24:57, LastWriteTime: 10.07.2016 19:24:57, ChangeTime: 12.07.2016 0:32:54, AllocationSize: 01.01.1601 2:00:00, EndOfFile: 01.01.1601 2:00:00, FileAttributes: D"
22:33:04,1662439,"javaw.exe","8304","CloseFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS",""
22:33:04,3016974,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
22:33:04,3019839,"javaw.exe","8304","QueryNetworkOpenInformationFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","CreationTime: 10.07.2016 19:24:52, LastAccessTime: 10.07.2016 19:24:57, LastWriteTime: 10.07.2016 19:24:57, ChangeTime: 12.07.2016 0:32:54, AllocationSize: 01.01.1601 2:00:00, EndOfFile: 01.01.1601 2:00:00, FileAttributes: D"
22:33:04,3020178,"javaw.exe","8304","CloseFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS",""
22:33:04,3053089,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
22:33:04,3056154,"javaw.exe","8304","QueryDirectory","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\*","SUCCESS","Filter: *, 1: ."
22:33:04,3093411,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\.tmmignore","NAME NOT FOUND","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3129928,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\.tmmignore","NAME NOT FOUND","Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3166944,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\tmmignore","NAME NOT FOUND","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3207985,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\tmmignore","NAME NOT FOUND","Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3246983,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\.nomedia","NAME NOT FOUND","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3289992,"javaw.exe","8304","CreateFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil\.nomedia","NAME NOT FOUND","Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
22:33:04,3295008,"javaw.exe","8304","QueryDirectory","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS","0: .., 1: zahradnik-z-argenteuil-jean-gabin-1966-cz-dub.avi"
22:33:04,3295843,"javaw.exe","8304","QueryDirectory","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","NO MORE FILES",""
22:33:04,3296204,"javaw.exe","8304","CloseFile","\\kermorvan.whitelines.local\data\Filmy\_zahradnik z argenteuil","SUCCESS",""

[myron]

phew!
never looked that deep, what Java really does - but quite interesting
We use the Files.walkFileTree() method, to get all file objects (the metadata) recursively, and filter all video files.
(We check there for some .tmmignore files first, if we should parse this directory or not - dunno why we see ca createFile operation here)

But:
In the logs, i can now see some skipping of .actor dirs - so it IS basically walking the directory
Unfortunately, still no movies found.
Can you check the settings? is there a data/config.xml and the videoFileTypes filled with all the known video extensions, like mkv, avi?

NO MORE FILES means, that this directory has no more files in there (there is some postDirectoryEvent fired in java)
But the video has been seen there...

[nocturneop15]

I checked settings - visually in TMM and also directly in XML - it's in default, containing all possible media types I can imagine.

Folder traversing definitely works, like in above tracing, I can trace that it touches all the folders - also updating source takes adequate time to complete depending on number of folders.

Are there any other locations containint TMM data except its home folder itself?

Aditional tries with no success:

- I tried to delete java cache
- I tried to remove 1.8 java and use old 1.7
- creating new media folder with unique name

BUT:

When I put single movie into folder ( x:\film\movie.avi), it IS recognized and processed by mediainfo. Then, I can use rename function to put it automatically in dedicated folder (x:\film\movie\movie.avi) Movie can be scraped, all seems to be OK.
But when I ty to rename movie again (after scraping correct name), it does not work anymore. folder and movie files stays in their initial name and are not renamed, even if TMM has correctly scraped info about movie. If I initialize database, this movie in subfolder is not visible and accessible in TMM anymore, but is immediately processed by KODI with correct infos.

Only that is clear fact is, that TMM in my environment has serious troubles with subfolders, even if it created them - no idea why.