Dec 19, 2018 19:13:30.471 [0x7f8136656700] INFO - Plex Media Scanner v1.14.1.5488-cc260c476 - ubuntu PC x86_64 - build: linux-ubuntu-x86_64 - GMT 00:00
Dec 19, 2018 19:13:30.472 [0x7f8136656700] INFO - Linux version: 3.10.105 (#23824 SMP Fri Oct 12 18:29:40 CST 2018), language: en-US
Dec 19, 2018 19:13:30.472 [0x7f8136656700] INFO - Processor       Intel(R) Pentium(R) CPU  N3710  @ 1.60GHz
Dec 19, 2018 19:13:30.472 [0x7f8136656700] INFO - /volume1/@appstore/Plex Media Server/Plex Media Scanner --analyze --log-file-suffix  Analysis --item 1887987,1887988,1887989
Dec 19, 2018 19:13:30.397 [0x7f8142a64800] VERBOSE - [FFMPEG] - Rescanning for external libs: '/volume1/Plex/Library/Application\ Support/Plex\ Media\ Server/Codecs/531e313-1328-linux-ubuntu-x86_64/'
Dec 19, 2018 19:13:30.398 [0x7f8142a64800] VERBOSE - [FFMPEG] - Loading external lib /volume1/Plex/Library/Application Support/Plex Media Server/Codecs/531e313-1328-linux-ubuntu-x86_64/libmpeg4_decoder.so
Dec 19, 2018 19:13:30.399 [0x7f8142a64800] VERBOSE - [FFMPEG] - Loading external lib /volume1/Plex/Library/Application Support/Plex Media Server/Codecs/531e313-1328-linux-ubuntu-x86_64/libaac_encoder.so
Dec 19, 2018 19:13:30.401 [0x7f8142a64800] VERBOSE - [FFMPEG] - Loading external lib /volume1/Plex/Library/Application Support/Plex Media Server/Codecs/531e313-1328-linux-ubuntu-x86_64/libh264_decoder.so
Dec 19, 2018 19:13:30.404 [0x7f8142a64800] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.13.0, threadsafe=1
Dec 19, 2018 19:13:30.834 [0x7f8142a64800] DEBUG - Analyzing media parts for item 1887987 (P1020158): 1495446
Dec 19, 2018 19:13:30.835 [0x7f8142a64800] DEBUG - [ID 1496123] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158.jpg
Dec 19, 2018 19:13:31.904 [0x7f8142a64800] WARN - Waited one whole second for a busy database.
Dec 19, 2018 19:13:32.107 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158' (type: 200) since nothing changed.
Dec 19, 2018 19:13:32.108 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158' (type: 201) since nothing changed.
Dec 19, 2018 19:13:32.110 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158' (type: 205) since nothing changed.
Dec 19, 2018 19:13:32.111 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158' (type: 202) since nothing changed.
Dec 19, 2018 19:13:32.111 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158' (type: 203) since nothing changed.
Dec 19, 2018 19:13:32.112 [0x7f8142a64800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:32.114 [0x7f8142a64800] DEBUG - Updating media item 1495446, size=33324, metadata_item_id=1887987
Dec 19, 2018 19:13:32.115 [0x7f8142a64800] DEBUG - Updating part with ID=1496123 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158.jpg]
Dec 19, 2018 19:13:32.323 [0x7f8142a64800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.323 [0x7f8142a64800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.329 [0x7f8142a64800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.330 [0x7f8142a64800] DEBUG - Updating metadata item (save) (P1020158) with ID 1887987
Dec 19, 2018 19:13:32.354 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.357 [0x7f8142a64800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887987?force=0
Dec 19, 2018 19:13:32.359 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.361 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.361 [0x7f8142a64800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887987?force=0
Dec 19, 2018 19:13:32.364 [0x7f8142a64800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/imagga/process/1887987
Dec 19, 2018 19:13:32.366 [0x7f8142a64800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/imagga/process/1887987
Dec 19, 2018 19:13:32.366 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.367 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.372 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887987&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.374 [0x7f8142a64800] DEBUG - Analyzing media parts for item 1887988 (P1020158_1024): 1495447
Dec 19, 2018 19:13:32.375 [0x7f8142a64800] DEBUG - [ID 1496124] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158_1024.jpg
Dec 19, 2018 19:13:32.411 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_1024' (type: 200) since nothing changed.
Dec 19, 2018 19:13:32.411 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_1024' (type: 201) since nothing changed.
Dec 19, 2018 19:13:32.412 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_1024' (type: 205) since nothing changed.
Dec 19, 2018 19:13:32.413 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_1024' (type: 202) since nothing changed.
Dec 19, 2018 19:13:32.413 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_1024' (type: 203) since nothing changed.
Dec 19, 2018 19:13:32.414 [0x7f8142a64800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:32.415 [0x7f8142a64800] DEBUG - Updating media item 1495447, size=191118, metadata_item_id=1887988
Dec 19, 2018 19:13:32.415 [0x7f8142a64800] DEBUG - Updating part with ID=1496124 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158_1024.jpg]
Dec 19, 2018 19:13:32.461 [0x7f8142a64800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.461 [0x7f8142a64800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.466 [0x7f8142a64800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.466 [0x7f8142a64800] DEBUG - Updating metadata item (save) (P1020158_1024) with ID 1887988
Dec 19, 2018 19:13:32.471 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.475 [0x7f8142a64800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887988?force=0
Dec 19, 2018 19:13:32.474 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.480 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.481 [0x7f8142a64800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887988?force=0
Dec 19, 2018 19:13:32.483 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.484 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.489 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887988&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.494 [0x7f8142a64800] DEBUG - Analyzing media parts for item 1887989 (P1020158_face0): 1495448
Dec 19, 2018 19:13:32.494 [0x7f8142a64800] DEBUG - [ID 1496125] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158_face0.jpg
Dec 19, 2018 19:13:32.620 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_face0' (type: 200) since nothing changed.
Dec 19, 2018 19:13:32.621 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_face0' (type: 201) since nothing changed.
Dec 19, 2018 19:13:32.622 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_face0' (type: 205) since nothing changed.
Dec 19, 2018 19:13:32.623 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_face0' (type: 202) since nothing changed.
Dec 19, 2018 19:13:32.624 [0x7f8142a64800] VERBOSE - Skipping expensive tags write for 'P1020158_face0' (type: 203) since nothing changed.
Dec 19, 2018 19:13:32.624 [0x7f8142a64800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:32.625 [0x7f8142a64800] DEBUG - Updating media item 1495448, size=21495, metadata_item_id=1887989
Dec 19, 2018 19:13:32.626 [0x7f8142a64800] DEBUG - Updating part with ID=1496125 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/mNAvGhNFQReP+28QzGEobQ/P1020158_face0.jpg]
Dec 19, 2018 19:13:32.633 [0x7f8142a64800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.634 [0x7f8142a64800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.638 [0x7f8142a64800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:32.639 [0x7f8142a64800] DEBUG - Updating metadata item (save) (P1020158_face0) with ID 1887989
Dec 19, 2018 19:13:32.643 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.647 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:32.648 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.646 [0x7f8142a64800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887989?force=0
Dec 19, 2018 19:13:32.652 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:32.653 [0x7f8134bff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.654 [0x7f8142a64800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887989?force=0
Dec 19, 2018 19:13:32.657 [0x7f8134bff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887989&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:32.658 [0x7f8142a64800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/imagga/process/1887989
Dec 19, 2018 19:13:32.664 [0x7f8142a64800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/imagga/process/1887989
