Dec 19, 2018 19:13:23.562 [0x7f9f52bdf700] 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:23.562 [0x7f9f52bdf700] INFO - Linux version: 3.10.105 (#23824 SMP Fri Oct 12 18:29:40 CST 2018), language: en-US
Dec 19, 2018 19:13:23.562 [0x7f9f52bdf700] INFO - Processor       Intel(R) Pentium(R) CPU  N3710  @ 1.60GHz
Dec 19, 2018 19:13:23.562 [0x7f9f52bdf700] INFO - /volume1/@appstore/Plex Media Server/Plex Media Scanner --analyze --log-file-suffix  Analysis --item 1887982,1887983,1887984,1887985
Dec 19, 2018 19:13:23.561 [0x7f9f5d8a5800] 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:23.562 [0x7f9f5d8a5800] 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:23.563 [0x7f9f5d8a5800] 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:23.565 [0x7f9f5d8a5800] 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:23.568 [0x7f9f5d8a5800] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.13.0, threadsafe=1
Dec 19, 2018 19:13:23.930 [0x7f9f5d8a5800] DEBUG - Analyzing media parts for item 1887982 (P1020117): 1495442
Dec 19, 2018 19:13:23.930 [0x7f9f5d8a5800] DEBUG - [ID 1496119] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117.jpg
Dec 19, 2018 19:13:24.956 [0x7f9f5d8a5800] WARN - Waited one whole second for a busy database.
Dec 19, 2018 19:13:25.100 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117' (type: 200) since nothing changed.
Dec 19, 2018 19:13:25.100 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117' (type: 201) since nothing changed.
Dec 19, 2018 19:13:25.103 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117' (type: 205) since nothing changed.
Dec 19, 2018 19:13:25.103 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117' (type: 202) since nothing changed.
Dec 19, 2018 19:13:25.104 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117' (type: 203) since nothing changed.
Dec 19, 2018 19:13:25.105 [0x7f9f5d8a5800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:25.107 [0x7f9f5d8a5800] DEBUG - Updating media item 1495442, size=37441, metadata_item_id=1887982
Dec 19, 2018 19:13:25.107 [0x7f9f5d8a5800] DEBUG - Updating part with ID=1496119 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117.jpg]
Dec 19, 2018 19:13:25.179 [0x7f9f5d8a5800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.179 [0x7f9f5d8a5800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.185 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.186 [0x7f9f5d8a5800] DEBUG - Updating metadata item (save) (P1020117) with ID 1887982
Dec 19, 2018 19:13:25.209 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:25.214 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:25.214 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887982?force=0
Dec 19, 2018 19:13:25.215 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:25.217 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887982?force=0
Dec 19, 2018 19:13:25.218 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/imagga/process/1887982
Dec 19, 2018 19:13:25.223 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/imagga/process/1887982
Dec 19, 2018 19:13:25.228 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:25.229 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:25.232 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887982&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:25.234 [0x7f9f5d8a5800] DEBUG - Analyzing media parts for item 1887983 (P1020117_1024): 1495443
Dec 19, 2018 19:13:25.235 [0x7f9f5d8a5800] DEBUG - [ID 1496120] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_1024.jpg
Dec 19, 2018 19:13:25.279 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_1024' (type: 200) since nothing changed.
Dec 19, 2018 19:13:25.280 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_1024' (type: 201) since nothing changed.
Dec 19, 2018 19:13:25.282 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_1024' (type: 205) since nothing changed.
Dec 19, 2018 19:13:25.283 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_1024' (type: 202) since nothing changed.
Dec 19, 2018 19:13:25.284 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_1024' (type: 203) since nothing changed.
Dec 19, 2018 19:13:25.285 [0x7f9f5d8a5800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:25.286 [0x7f9f5d8a5800] DEBUG - Updating media item 1495443, size=199126, metadata_item_id=1887983
Dec 19, 2018 19:13:25.287 [0x7f9f5d8a5800] DEBUG - Updating part with ID=1496120 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_1024.jpg]
Dec 19, 2018 19:13:25.294 [0x7f9f5d8a5800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.295 [0x7f9f5d8a5800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.300 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:25.301 [0x7f9f5d8a5800] DEBUG - Updating metadata item (save) (P1020117_1024) with ID 1887983
Dec 19, 2018 19:13:25.306 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:25.309 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:25.309 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:25.312 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887983?force=0
Dec 19, 2018 19:13:25.313 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:25.314 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:25.317 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887983?force=0
Dec 19, 2018 19:13:25.318 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887983&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:25.325 [0x7f9f5d8a5800] DEBUG - Analyzing media parts for item 1887984 (P1020117_face0): 1495444
Dec 19, 2018 19:13:25.325 [0x7f9f5d8a5800] DEBUG - [ID 1496121] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_face0.jpg
Dec 19, 2018 19:13:26.347 [0x7f9f5d8a5800] WARN - Waited one whole second for a busy database.
Dec 19, 2018 19:13:27.233 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face0' (type: 200) since nothing changed.
Dec 19, 2018 19:13:27.234 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face0' (type: 201) since nothing changed.
Dec 19, 2018 19:13:27.235 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face0' (type: 205) since nothing changed.
Dec 19, 2018 19:13:27.236 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face0' (type: 202) since nothing changed.
Dec 19, 2018 19:13:27.237 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face0' (type: 203) since nothing changed.
Dec 19, 2018 19:13:27.237 [0x7f9f5d8a5800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:27.239 [0x7f9f5d8a5800] DEBUG - Updating media item 1495444, size=34700, metadata_item_id=1887984
Dec 19, 2018 19:13:27.239 [0x7f9f5d8a5800] DEBUG - Updating part with ID=1496121 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_face0.jpg]
Dec 19, 2018 19:13:27.294 [0x7f9f5d8a5800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.294 [0x7f9f5d8a5800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.298 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.299 [0x7f9f5d8a5800] DEBUG - Updating metadata item (save) (P1020117_face0) with ID 1887984
Dec 19, 2018 19:13:27.543 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:27.546 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:27.546 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:27.550 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:27.550 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:27.552 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887984?force=0
Dec 19, 2018 19:13:27.555 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887984&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:27.555 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887984?force=0
Dec 19, 2018 19:13:27.557 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/imagga/process/1887984
Dec 19, 2018 19:13:27.560 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/imagga/process/1887984
Dec 19, 2018 19:13:27.568 [0x7f9f5d8a5800] DEBUG - Analyzing media parts for item 1887985 (P1020117_face1): 1495445
Dec 19, 2018 19:13:27.568 [0x7f9f5d8a5800] DEBUG - [ID 1496122] Media part analysis: /volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_face1.jpg
Dec 19, 2018 19:13:27.581 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face1' (type: 200) since nothing changed.
Dec 19, 2018 19:13:27.583 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face1' (type: 201) since nothing changed.
Dec 19, 2018 19:13:27.584 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face1' (type: 205) since nothing changed.
Dec 19, 2018 19:13:27.584 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face1' (type: 202) since nothing changed.
Dec 19, 2018 19:13:27.585 [0x7f9f5d8a5800] VERBOSE - Skipping expensive tags write for 'P1020117_face1' (type: 203) since nothing changed.
Dec 19, 2018 19:13:27.586 [0x7f9f5d8a5800] DEBUG - Streams didn't change in analysis, not saving.
Dec 19, 2018 19:13:27.587 [0x7f9f5d8a5800] DEBUG - Updating media item 1495445, size=37566, metadata_item_id=1887985
Dec 19, 2018 19:13:27.587 [0x7f9f5d8a5800] DEBUG - Updating part with ID=1496122 [/volume1/photo/photo backup/iPhoto Library/Data/2015/01/26/20150126-224045/BAhZIvbiRiK8KhJJ4HolLg/P1020117_face1.jpg]
Dec 19, 2018 19:13:27.778 [0x7f9f5d8a5800] DEBUG - Downloading document http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.778 [0x7f9f5d8a5800] DEBUG - HTTP requesting GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.782 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/library/changestamp
Dec 19, 2018 19:13:27.783 [0x7f9f5d8a5800] DEBUG - Updating metadata item (save) (P1020117_face1) with ID 1887985
Dec 19, 2018 19:13:27.787 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:27.791 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=analyzing
Dec 19, 2018 19:13:27.792 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:27.795 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/clustering/process/4/1887985?force=0
Dec 19, 2018 19:13:27.796 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=thumbnailing
Dec 19, 2018 19:13:27.797 [0x7f9f4f7ff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:27.801 [0x7f9f4f7ff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=4&metadataItemID=1887985&metadataType=13&state=-1&mediaState=idle
Dec 19, 2018 19:13:27.805 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/clustering/process/4/1887985?force=0
Dec 19, 2018 19:13:27.807 [0x7f9f5d8a5800] DEBUG - HTTP requesting PUT http://127.0.0.1:32400/services/imagga/process/1887985
Dec 19, 2018 19:13:27.811 [0x7f9f5d8a5800] DEBUG - HTTP 200 response from PUT http://127.0.0.1:32400/services/imagga/process/1887985
