Catalog Metadata Updates - Never Finishes & Organizer Browse Fail

[JeffG]

I tried adding about 30,000 photos to the catalog on Windows 10, PM+ 3029.  I have a good I7 system, lots of RAM, and fast SSD drive.  It has been a couple of days now and all of the components finished except the "Catalog Metadata Updates".  It go down to 1081 batches remaining and hung.  I closed PM+ and restarted.  Task manager shows that it was using most of a CPU to do something, and after an hour or two it dropped to 981 batches remaining.  8+ hours later, it is still at the same spot, but now PM+ is not using any CPU so it has stopped.  I can try restarting PM+ again but is there any way to see what is going on and if it will ever finish?  It doesn't seem unreasonable to add 30k photos to a catalog.

Also, when I go into the organizer and use the "Browse" tab, I can see there are 15 photos in the catalog with "Red" colour class.  If I right click on that and select "Open in Contact Sheet", nothing happens.

See photo below for details.

[Hayo Baan]

Wait till the remaining task is finished. Then you should be able to browse/search the catalog.

[William R Wood]

This is the same issue I had. Tried to import 50k images to the catalog on Win10 Pro, PM+ 3029, fast Xeon CPU, lots of RAM, fast video card, fast SSD. All efforts to catalog a large number of images (>5k) hung on "Catalog Metadata Updates" with various numbers of batches remaining depending on how many images I attempted to scan. After the program hung, nothing appeared to happen even if I waited a couple of hours. That is definitely not right.
There is no way I could figure out how to tell whether the program was doing anything when the program hung and nothing changed for hours. I was not about to sit there and wait all night or all day for something to happen so I quit the program and finally succeeded in importing small batches of 3-5k images.

Like Jeff I found that PM+ was frozen and nothing could be done after the import process hung. Only recourse was to force close PM+ and delete the failed catalog and try again.

[Hayo Baan]

The current version of the catalog scanning is known to hang on some images with metadata issues (errors in the metadata structure). If the catalog creation stalled, it could be due to this. But it is also true that while the catalog is building, you won't be able to browse/filter it (hence my previous answer). It's not always directly clear the catalog is busy though.

Note: if your catalog is local (which it likely will be), generating previews is not really necessary, turning this off in Catalog|Manage Catalogs (see screenshot) can speed up things.

[William R Wood]

Yes, I can corroborate Hayo's advise. I had to disable "Generate Proxy Images" in order to get any images in my catalog. My first few attempts to catalog produced completion time estimates of many many hours for any significant number of images so I unchecked proxy generation and the process did speed up a lot, but it was still way too slow. By the way the completion time estimates produced by PM+ are way low on my system, all the estimates were off until I switched to very small imports (<5k), many imports took 2 or 3 times as long as the estimate. I also feel that new versions of PM+ should have Generate Proxy Images turned off by default since they are not necessary if your catalog images are local or you don't need offline access which is probably most common.

I also found that one of my folders contained an image that PM+ would not import. I still have no idea why, since that image imports fine into other DAM software (Lightroom, Media Pro, ACDSee) and it works fine in all photo software I ever used including PM5 and PM6 - but not PM6 Plus? So I find it hard to believe that my image has any errors in the metadata structure since PM5 and PM6 can read the metadata without issue. More importantly PM+ should not hang on corrupt images, it should skip them and give users a notice of what images were skipped if any. As it is now if PM+ hangs we don't know why or if it is actually hung or just incredibly slow.

(admin: corrected "Mayo" to "Hayo")

[Hayo Baan]

I also found that one of my folders contained an image that PM+ would not import. I still have no idea why, since that image imports fine into other DAM software (Lightroom, Media Pro, ACDSee) and it works fine in all photo software I ever used including PM5 and PM6 - but not PM6 Plus? So I find it hard to believe that my image has any errors in the metadata structure since PM5 and PM6 can read the metadata without issue. More importantly PM+ should not hang on corrupt images, it should skip them and give users a notice of what images were skipped if any. As it is now if PM+ hangs we don't know why or if it is actually hung or just incredibly slow.

The files that caused the import to fail that I've analysed so far, all shared the same metadata structure corruption: the maker notes offsets got screwed.
The reason other software and even PM itself can work with these files just fine is because those applications don't try to retrieve (almost) all available metadata. For building the catalog database this is what PM needs to do though (e.g. it needs to go into the maker notes to get lens details, camera serial numbers, etc.). Sure, PM should cope with this kind of error, but that's why it's still in beta

If you can share one of your problematic images, I'll analyse it to see if the same type of corruption applies to your image as well.

[William R Wood]

Hayo, sorry for the typo on your name, just woke up, must have been half asleep! 

And by the way, I am not complaining about PM+.........just reporting issues.

Even though it's beta, PM+ is way better than all the other catalog programs I have tried. I can finally (1) import images into my computer, (2) browse them, (3) apply keywords and (4) most importantly, find them using the same software. The hassles I have gone thru over the years attempting to do those 4 things with separate programs have almost driven me nuts. Dealing with the limitations and incompatibilities between programs is not fun and it is already apparent that PM+ will eliminate that problem!

[JeffG]

I ended up deleting the catalog.  I created a very small one to ensure it worked, and it did, very nice to be able to use the organizer to find photos using various filters or browse categories and throw them into a contact sheet.  I tried re-creating the catalog again, this time without the preview/thumbnail feature. 

It may be stuck again.  Any way to find out which file it might be getting stuck on so that I can submit it so that an updated version won't get stuck but can maybe skip/ignore that file so the process can complete?

[JeffG]

I found the PM.log and dyn.log.  Nothing too interesting in the PM.log

Code: [Select]

Photo Mechanic Plus version 6.0.0.0 build 3029 (9dd0f3c)
[Sat May-04-2019 19:22:13.844][000051d4][0134396] [0000000003794ac0] Initializing DNS resolver
[Sat May-04-2019 19:22:14.263][000049c0][0140456] PM4.cpp:1686 Current locale is C
[Sat May-04-2019 19:22:14.490][000049c0][0170380] PMCache.cpp:3028 cache: main thread startup
[Sat May-04-2019 19:22:14.490][000049c0][0170416] PMCache.cpp:1302 cache: spawning 8 worker threads (8 cpus) ...
[Sat May-04-2019 19:22:14.526][00003018][0180756] PMCache.cpp:2968 cache: found 1956 disk cache entries, 1956 usable

This is what the dyn.log shows after I restart and it looks like it is trying to process the catalog metadata that hasn't finished.

Code: [Select]

[2019-05-04 19:22:18.621 Sat] [21476:104768740] [WARN] DYN: CBits::AM::DB::CatalogStateDB.retrieve_change_journal_batch_for_cat: exceeded batch size target (8416223, 8388601), deferring any remainder till next batch
[2019-05-04 19:23:18.681 Sat] [21476:104769160] [WARN] DYN: <79834860>[127.0.0.1:51448] binding.reply_timeout: 27 => #<Proc:0x00000009a223b8@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>
[2019-05-04 19:23:18.693 Sat] [21476:104768740] [ERR!] DYN: CBits::AM::CatalogMetadataUpdateTask.try_spawn_metadata_update: apply_change_journal_batch failed: [:rpc_timeout]
[21476:104768740] CILA::FiberPool - fiber outer exception: apply_change_journal_batch failed: [:rpc_timeout] - ["C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:640:in `call'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:656:in `method_missing'", "./archive/app/am.rb:1403:in `block in try_spawn_metadata_update'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'"]
[2019-05-04 19:23:19.704 Sat] [21476:104769160] [WARN] AMSV: <96187300>[127.0.0.1:51444] binding.reply_timeout: 31 => #<Proc:0x00000009c87590@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>
[2019-05-04 19:23:19.710 Sat] [21476:104768680] [ERR!] AMSV: <79833860>[127.0.0.1:51450] CILA::PROTO::RPCServerConn - rpc_dispatch: exception: CILA::PROTO::RPCException/apply_change_journal_batch failed: [:rpc_timeout] to=20 msg="apply_change_journal_batch" location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:640:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:656:in `method_missing', ./archive/common/catalog.rb:270:in `do_apply_change_journal_batch', ./archive/common/catalog.rb:187:in `block in apply_change_journal_batch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/syncwaiter.rb:85:in `synchronize', ./archive/common/catalog.rb:186:in `apply_change_journal_batch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc_object.rb:72:in `block in initialize', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `block in do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `catch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1044:in `block in rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'
[2019-05-04 19:23:19.715 Sat] [21476:104769160] [WARN] AMSV: <96187300>[127.0.0.1:51444] binding.reply_timeout: 35 => #<Proc:0x0000000caa0800@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:774>
[2019-05-04 19:23:19.719 Sat] [21476:104768860] [ERR!] AMSV: <96118860>[127.0.0.1:51449] CILA::PROTO::RPCServerConn - rpc_dispatch: exception: CILA::PROTO::RPCException/catalog_open_db failed: [:rpc_timeout] to=0 msg="open_catalog" location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:781:in `openport', ./archive/server/am_server.rb:254:in `open_or_create_catalog', ./archive/server/am_server.rb:776:in `open_local_catalog', ./archive/server/am_server.rb:608:in `open_catalog', ./archive/server/am_server.rb:438:in `open_catalog', ./archive/server/am_server.rb:1012:in `open_catalog', ./archive/server/am_server.rb:930:in `call', ./archive/server/am_server.rb:930:in `handle_root_msg', ./archive/server/am_server.rb:910:in `block in init_message_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `block in do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `catch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1044:in `block in rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'
[2019-05-04 19:23:19.724 Sat] [21476:104769160] [WARN] DYN: <96120000>[127.0.0.1:51448] binding.reply_timeout: 34 => #<Proc:0x0000000caa1bb0@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:774>
[2019-05-04 19:23:19.730 Sat] [21476:104768800] [WARN] DYN: CBits::AM::AMServerClient - open_catalog: channel 0 open failed for catalog "E:/Jeff_Pictures/Photo Mechanic Catalogs/Test Catalog" server am://127.0.0.1:51448 - open_catalog failed: [:rpc_timeout]
[2019-05-04 19:23:19.736 Sat] [21476:104768800] [WARN] DYN: CBits::AM::CatalogManager - CILA::PROTO::RPCException: open_catalog failed: [:rpc_timeout] location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:781:in `openport', ./archive/common/catalog_manager.rb:358:in `block in open_catalog', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/syncwaiter.rb:85:in `synchronize', ./archive/common/catalog_manager.rb:350:in `open_catalog', ./archive/common/catalog_manager.rb:971:in `block (2 levels) in open_catalog'
[2019-05-04 19:23:19.752 Sat] [21476:104768740] [WARN] DYN: <96120000>[127.0.0.1:51448] CILA::PROTO::RPCClientConn - do_rpc_dispatch: no_handler: to=34 portmap={0=>#<CILA::PROTO::RPCReplyHandlerBinding:0x0000000b7554a8 @handler=#<Proc:0x0000000b755610 (lambda)>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012138.111726>, 61=>#<CILA::PROTO::RPCReplyHandlerBinding:0x0000000a25cbc8 @handler=#<Proc:0x0000000a25cc40@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:680>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012199.751461>, 62=>#<CILA::PROTO::RPCReplyHandlerBinding:0x0000000a022e20 @handler=#<Proc:0x0000000a022e98@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:774>, @timeout_sec=60.0, @want_fiber=true, @lastmsg_time=1557012199.751461>} msg=nil
[2019-05-04 19:23:19.759 Sat] [21476:104769100] [WARN] DYN: <79834860>[127.0.0.1:51448] CILA::PROTO::RPCClientConn - do_rpc_dispatch: no_handler: to=27 portmap={0=>#<CILA::PROTO::RPCReplyHandlerBinding:0x00000009845950 @handler=#<Proc:0x00000009845ab8 (lambda)>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012138.2034812>} msg=nil
[2019-05-04 19:23:19.810 Sat] [21476:104768800] [WARN] DYN: CBits::AM::DB::CatalogStateDB.retrieve_change_journal_batch_for_cat: exceeded batch size target (8416223, 8388601), deferring any remainder till next batch
[2019-05-04 19:24:20.109 Sat] [21476:104769160] [WARN] AMSV: <96187300>[127.0.0.1:51444] binding.reply_timeout: 63 => #<Proc:0x0000000ca42480@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>
[2019-05-04 19:24:20.118 Sat] [21476:104768740] [ERR!] AMSV: <96118860>[127.0.0.1:51449] CILA::PROTO::RPCServerConn - rpc_dispatch: exception: CILA::PROTO::RPCException/construct_filter_stage failed: [:rpc_timeout] to=18 msg="construct_filter_stage" location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:640:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:656:in `method_missing', ./archive/common/catalog.rb:382:in `do_construct_filter_stage', ./archive/common/catalog.rb:248:in `construct_filter_stage', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc_object.rb:69:in `block in initialize', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `block in do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `catch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1044:in `block in rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'
[2019-05-04 19:24:20.124 Sat] [21476:104769160] [WARN] AMSV: <96187300>[127.0.0.1:51444] binding.reply_timeout: 64 => #<Proc:0x0000000ca436f0@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:774>
[2019-05-04 19:24:20.130 Sat] [21476:94488740] [ERR!] AMSV: <96118860>[127.0.0.1:51449] CILA::PROTO::RPCServerConn - rpc_dispatch: exception: CILA::PROTO::RPCException/catalog_open_db failed: [:rpc_timeout] to=0 msg="open_catalog" location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:781:in `openport', ./archive/server/am_server.rb:254:in `open_or_create_catalog', ./archive/server/am_server.rb:776:in `open_local_catalog', ./archive/server/am_server.rb:608:in `open_catalog', ./archive/server/am_server.rb:438:in `open_catalog', ./archive/server/am_server.rb:1012:in `open_catalog', ./archive/server/am_server.rb:930:in `call', ./archive/server/am_server.rb:930:in `handle_root_msg', ./archive/server/am_server.rb:910:in `block in init_message_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `block in do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `catch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1044:in `block in rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'
[2019-05-04 19:24:20.135 Sat] [21476:104769160] [WARN] AMSV: <96187300>[127.0.0.1:51444] binding.reply_timeout: 67 => #<Proc:0x000000096c55a8@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>
[2019-05-04 19:24:20.141 Sat] [21476:104769100] [ERR!] AMSV: <79833860>[127.0.0.1:51450] CILA::PROTO::RPCServerConn - rpc_dispatch: exception: CILA::PROTO::RPCException/apply_change_journal_batch failed: [:rpc_timeout] to=20 msg="apply_change_journal_batch" location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:640:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:656:in `method_missing', ./archive/common/catalog.rb:270:in `do_apply_change_journal_batch', ./archive/common/catalog.rb:187:in `block in apply_change_journal_batch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/syncwaiter.rb:85:in `synchronize', ./archive/common/catalog.rb:186:in `apply_change_journal_batch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc_object.rb:72:in `block in initialize', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1096:in `block in do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `catch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1095:in `do_rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:1044:in `block in rpc_dispatch', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'
[2019-05-04 19:24:20.147 Sat] [21476:104769160] [WARN] DYN: <96120000>[127.0.0.1:51448] binding.reply_timeout: 62 => #<Proc:0x0000000a022e98@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:774>
[2019-05-04 19:24:20.153 Sat] [21476:104768680] [WARN] DYN: CBits::AM::AMServerClient - open_catalog: channel 0 open failed for catalog "E:/Jeff_Pictures/Photo Mechanic Catalogs/Test Catalog" server am://127.0.0.1:51448 - open_catalog failed: [:rpc_timeout]
[2019-05-04 19:24:20.159 Sat] [21476:104768680] [WARN] DYN: CBits::AM::CatalogManager - CILA::PROTO::RPCException: open_catalog failed: [:rpc_timeout] location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:781:in `openport', ./archive/common/catalog_manager.rb:358:in `block in open_catalog', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/syncwaiter.rb:85:in `synchronize', ./archive/common/catalog_manager.rb:350:in `open_catalog', ./archive/common/catalog_manager.rb:971:in `block (2 levels) in open_catalog'
[2019-05-04 19:24:20.166 Sat] [21476:104769160] [WARN] DYN: <79834860>[127.0.0.1:51448] binding.reply_timeout: 65 => #<Proc:0x0000000ca89470@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>
[2019-05-04 19:24:20.172 Sat] [21476:104768800] [ERR!] DYN: CBits::AM::CatalogMetadataUpdateTask.try_spawn_metadata_update: apply_change_journal_batch failed: [:rpc_timeout]
[21476:104768800] CILA::FiberPool - fiber outer exception: apply_change_journal_batch failed: [:rpc_timeout] - ["C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:640:in `call'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:656:in `method_missing'", "./archive/app/am.rb:1403:in `block in try_spawn_metadata_update'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `call'", "C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/fiberpool.rb:54:in `block in add_fiber'"]
[2019-05-04 19:24:20.222 Sat] [21476:104768800] [WARN] DYN: CBits::AM::DB::CatalogStateDB.retrieve_change_journal_batch_for_cat: exceeded batch size target (8416223, 8388601), deferring any remainder till next batch
[2019-05-04 19:24:20.249 Sat] [21476:104769100] [WARN] DYN: <96120000>[127.0.0.1:51448] CILA::PROTO::RPCClientConn - do_rpc_dispatch: no_handler: to=62 portmap={0=>#<CILA::PROTO::RPCReplyHandlerBinding:0x0000000b7554a8 @handler=#<Proc:0x0000000b755610 (lambda)>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012138.111726>} msg=nil
[2019-05-04 19:24:20.257 Sat] [21476:104769100] [WARN] DYN: <79834860>[127.0.0.1:51448] CILA::PROTO::RPCClientConn - do_rpc_dispatch: no_handler: to=65 portmap={0=>#<CILA::PROTO::RPCReplyHandlerBinding:0x00000009845950 @handler=#<Proc:0x00000009845ab8 (lambda)>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012138.2034812>, 92=>#<CILA::PROTO::RPCReplyHandlerBinding:0x00000010f70ed0 @handler=#<Proc:0x00000010f70f48@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:680>, @timeout_sec=nil, @want_fiber=true, @lastmsg_time=1557012260.1653178>, 93=>#<CILA::PROTO::RPCReplyHandlerBinding:0x0000001120d378 @handler=#<Proc:0x0000001120d3f0@C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:626>, @timeout_sec=60.0, @want_fiber=true, @lastmsg_time=1557012260.2271528>} msg=nil
[2019-05-04 19:24:20.348 Sat] [21476:104768860] [WARN] DYN: CBits::AM::CatalogManager - CILA::PROTO::RPCException: construct_filter_stage failed: ["construct_filter_stage: CILA::PROTO::RPCException/construct_filter_stage failed: [:rpc_timeout]"] location=C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/proto/rpc.rb:718:in `block in msgstream', ./archive/common/catalog_manager.rb:1774:in `call', ./archive/common/catalog_manager.rb:1774:in `block (4 levels) in multi_search', C:/Program Files/Camera Bits/Photo Mechanic Plus/pmruby/lib/ruby/site_ruby/2.2.0/cila/noraise.rb:24:in `noraise', ./archive/common/catalog_manager.rb:1774:in `block (3 levels) in multi_search'

It has been blocked at 983 batches remaining.

[William R Wood]

I ended up deleting the catalog.  I created a very small one to ensure it worked, and it did, very nice to be able to use the organizer to find photos using various filters or browse categories and throw them into a contact sheet.  I tried re-creating the catalog again, this time without the preview/thumbnail feature. 

It may be stuck again. Any way to find out which file it might be getting stuck on so that I can submit it so that an updated version won't get stuck but can maybe skip/ignore that file so the process can complete?

There is no direct way to find corrupt files that I know of. Meanwhile I did find the file that was causing PM+ to hang during the import process by dividing my images in half and then scanning in small batches of < 5k images at a time until I found the folder that would not import. I then divided those images in half (created temporary folders) and scanned in smaller batches until I got down to a single file that would not import. That whole process of elimination took a couple of hours but I finally got all 52k of my images imported into a working catalog. Hopefully this issue will be fixed soon and we won't have to worry about corrupt files in the future as PM+ will skip them. By the way I did look at my corrupt file in Exiftool and it did have the Maker Notes messed up as stated by Hayo in his post.

[krubin]

Similar issue here.  I have been loading up my archive into Catalogs, with one Catalog per year of my shooting.  Modest volume shooter, with about 35-50k images per year.  Something hung and I have a perpetual "Catalog Metadata Update" message and no way to determine what is being updated.  Have trying the catalog management and cancelling all active tasks to no avail.

Upon entry into PM+, the Browser screen hangs for several minutes.  Eventually it returns, but is effectively inactive, not allowing me to click and pull up thumbnails. 

Will explore the "Generate Preview" guidance on this thread, but allowing better visibility into activities underway would be helpful, and enhancing "kill" options would be a benefit.  Perhaps even pushing them into a queue for later for unprocessed stuff, and agree with the recommendations above to skip and log images that are problemmatic for some reason.

[ralf]

Similar issue here.  I have been loading up my archive into Catalogs, with one Catalog per year of my shooting.  Modest volume shooter, with about 35-50k images per year.  Something hung and I have a perpetual "Catalog Metadata Update" message and no way to determine what is being updated.  Have trying the catalog management and cancelling all active tasks to no avail.

Upon entry into PM+, the Browser screen hangs for several minutes.  Eventually it returns, but is effectively inactive, not allowing me to click and pull up thumbnails. 

Will explore the "Generate Preview" guidance on this thread, but allowing better visibility into activities underway would be helpful, and enhancing "kill" options would be a benefit.  Perhaps even pushing them into a queue for later for unprocessed stuff, and agree with the recommendations above to skip and log images that are problemmatic for some reason.

Hello,

the same with me. Tried to import about 350 000 files (about 250 000 RAW and 100 000 images). It took about 2 days and „Catalog Metadata Updates“ is still „working“, actually nothing is happening. Although, after restarting PM the number of batches shrinks after a few minutes about 50-100 batches and then doesn´t do anything.
The number of image files is shown in the "Rating" box, is by far not matching the number of files  I have on my Raid.

Ralf

I am using MacOS 10.14.4

[Hayo Baan]

Yes, this is behaviour I see myself too; every time you startup PM, the number of batches goes down a bit but then stalls again.
The problem is that while it is busy (or stalled), you basically can't access any of the catalogs, not even the ones that are done; the whole catalog system is unresponsive.

[JeffG]

I upgraded to beta 3, and the new version seems to progress further and dropped from 981 batches, to 499 batches.  I left it overnight and seems to be stuck there.  I wasn't sure if letting it try to continue between versions would have actually worked, so I deleted the catalog, and started over from scratch with the new beta.  Ran it again, and after about 15+ hours now it got stuck at 499 batches again.

So maybe a different file that it is getting stuck at?  @Kirk Baker, was any additional logging added to try and find out where PM+ is hanging?  Is there something I can check to try and find out what the new issue might be?

[William R Wood]

It's a lot of work but you can find the file(s) that are sticking by process of elimination. I have 52k images, starting with a new database I divided my images in half, picked one half and divided that up into folders containing about 5k images and imported those small batches one by one until I found one folder that would not import. That process eliminated about 45k images that are now known good since only one folder would not import. Then I divided the remaining 5k images in half and imported batches of about 1k until I found the batch that would not import, and so on until I found the single file that would not import. Deleted that one file and all the rest of my images imported without problems. Took a couple of hours to find that corrupt file but it was worth it.