Here also have the same problem from about a year, but the error returned for middleware exception is the 37, not 38. Error message is the same "there was a problem creating the pbi".
Plexmediaserver download (phase 1/2) work until phase 2/2, then exit at 50%.
Another istance of Plexmediaserver, fresh install, do the same result.
May 25 08:09:31 nas manage.py: [middleware.exceptions:37] [MiddlewareError: Failed to update plugin]
May 25 08:13:52 nas manage.py: [common.pipesubr:61] Popen()ing: /sbin/umount -f '/mnt/RAID/jails/plexmediaserver_1/structure'
May 25 08:14:46 nas manage.py: [middleware.exceptions:37] [MiddlewareError: There was a problem creating the PBI]
May 25 08:16:21 nas manage.py: [middleware.exceptions:37] [MiddlewareError: Failed to update plugin]
May 25 08:20:46 nas manage.py: [common.pipesubr:61] Popen()ing: /sbin/umount -f '/mnt/RAID/jails/plexmediaserver_2/structure'
May 25 08:21:34 nas manage.py: [middleware.exceptions:37] [MiddlewareError: There was a problem creating the PBI]
May 25 08:29:16 nas manage.py: [middleware.exceptions:37] [MiddlewareError: Failed to update plugin]
[...]
As reported by bdaniel7, the .plugins directory has 644 permissions for root and www, then contains all the overtime failed plugins
[stefano@nas ~/jails/plexmediaserver_1/.plugins]$ ls -lha
total 355416
drwxr-xr-x 2 root wheel 7B May 25 08:14 .
drwxr-xr-x 20 root wheel 25B Mar 11 11:25 ..
-rw-r--r-- 1 root wheel 0B Aug 7 2015 PLUGIN
-rw-r--r-- 1 root www 87M Mar 16 17:04 plexmediaserver-0.9.15.6.1714-amd64.pbi
-rw-r--r-- 1 root www 87M Apr 3 10:42 plexmediaserver-0.9.16.3.1840-amd64.pbi
-rw-r--r-- 1 root www 87M May 7 10:03 plexmediaserver-0.9.16.4.1911-amd64.pbi
-rw-r--r-- 1 root www 87M May 25 08:14 plexmediaserver-0.9.16.6.1993-amd64.pbi
This prove that there is not problem to create PBI ;-)
The error message was unuseful
Changing the 644 privileges to 755, then do again the update, result in
May 25 09:02:26 nas manage.py: [common.pipesubr:61] Popen()ing: /sbin/umount -f '/mnt/RAID/jails/plexmediaserver_1/structure'
May 25 09:02:26 nas manage.py: [middleware.exceptions:37] [MiddlewareError: umount: /mnt/RAID/jails/plexmediaserver_1/structure: not a file system root directory
The error is again 37, but the message is not the same, completely other about the mount point '
structure' of the jail
Now I'm accessing via SSH to the Freenas and do the command manually obtaining this result
[root@freenas] /mnt/RAID/jails/plexmediaserver_1/.plugins# /sbin/umount -f '/mnt/RAID/jails/plexmediaserver_1/structure'
umount: /mnt/RAID/jails/plexmediaserver_1/structure: not a file system root directory
OK, try via SSH to the jail ( don't try this at home, my personalization for this test )
root@plexmediaserver_1:/ # /sbin/umount -f 'structure'
umount: structure: not a file system root directory
right! the mount point is already unmounted as visible in the jail's mount points section, but why you must unmount this folder to achieve the update process?
now I mount the structure directory and do again the update.... 6 minute, then
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /sbin/umount -f '/mnt/RAID/jails/plexmediaserver_1/structure'
May 25 09:28:31 nas manage.py: [middleware.exceptions:37] [MiddlewareError: There was a problem creating the PBI]
is frustrating!
The mount point remain unmounted, the log was not helpful
Try to read the freenas's /var/log/debug.log
[root@nas] /# cat var/log/debug.log
[...] some other interesting things
May 25 09:28:31 nas manage.py: [common.pbi:387] pbi_add.__init__: enter
May 25 09:28:31 nas manage.py: [common.pbi:311] pbi_base.__init__: enter
May 25 09:28:31 nas manage.py: [common.pbi:312] pbi_base.__init__: path = /usr/local/sbin/pbi_add
May 25 09:28:31 nas manage.py: [common.pbi:313] pbi_base.__init__: flags = 0x00000008
May 25 09:28:31 nas manage.py: [common.pbi:335] pbi_base.__init__: args = -i
May 25 09:28:31 nas manage.py: [common.pbi:341] pbi_base.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:396] pbi_add.__init__: pbi = /var/tmp/firmware/pbifile.pbi
May 25 09:28:31 nas manage.py: [common.pbi:397] pbi_add.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:362] pbi_base.run: enter
May 25 09:28:31 nas manage.py: [common.pbi:371] pbi_base.cmd = /usr/local/sbin/pbi_add -i /var/tmp/firmware/pbifile.pbi
May 25 09:28:31 nas manage.py: [common.cmd:189] cmd_pipe.__init__: enter
May 25 09:28:31 nas manage.py: [common.cmd:190] cmd_pipe.__init__: cmd = /usr/local/sbin/pbi_add -i /var/tmp/firmware/pbifile.pbi
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /usr/local/sbin/pbi_add -i /var/tmp/firmware/pbifile.pbi
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = PBI Information for: plexmediaserver-0.9.16.6.1993-amd64
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = -----------------------------------------------------
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Name: plexmediaserver
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = RootInstall: NO
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Version: 0.9.16.6.1993
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Built: 20160514 160048
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Prefix: /usr/pbi/plexmediaserver-amd64
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Author: PLEX
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Website: http://www.plexapp.com/
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Arch: amd64
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = FbsdVer: 9.3-RELEASE
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = CreatorVer: 1.0
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = ArchiveCount: 17171
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = ArchiveSum: f9b2734d0d55f9e287cf73371fef3d58c6f73b9e164c965062b5ca2660a0305a
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = Signature: Not Signed
May 25 09:28:31 nas manage.py: [common.cmd:209] cmd_pipe.__init__: out = AutoUpdate: NO
May 25 09:28:31 nas manage.py: [common.cmd:220] cmd_pipe.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:375] pbi_base.run: leave
May 25 09:28:31 nas manage.py: [middleware.notifier:3007] XXX: var = PBI Information for, val = plexmediaserver-0.9.16.6.1993-amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3007] XXX: var = Name, val = plexmediaserver
May 25 09:28:31 nas manage.py: [middleware.notifier:3007] XXX: var = Version, val = 0.9.16.6.1993
May 25 09:28:31 nas manage.py: [middleware.notifier:3007] XXX: var = Prefix, val = /usr/pbi/plexmediaserver-amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3007] XXX: var = Arch, val = amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3097] XXX: newpbi = plexmediaserver-0.9.16.6.1993-amd64.pbi
May 25 09:28:31 nas manage.py: [middleware.notifier:3098] XXX: newpbiname = plexmediaserver-0.9.16.6.1993-amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3099] XXX: newprefix = /usr/pbi/plexmediaserver-amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3100] XXX: newname = plexmediaserver
May 25 09:28:31 nas manage.py: [middleware.notifier:3101] XXX: newversion = 0.9.16.6.1993
May 25 09:28:31 nas manage.py: [middleware.notifier:3102] XXX: newarch = amd64
May 25 09:28:31 nas manage.py: [middleware.notifier:3111] XXX: oldpbifile = /mnt/RAID/jails/plexmediaserver_1/.plugins/plexmediaserver-0.9.12.19.1537-amd64.pbi
May 25 09:28:31 nas manage.py: [middleware.notifier:3112] XXX: newpbifile = /mnt/RAID/jails/plexmediaserver_1/.plugins/plexmediaserver-0.9.16.6.1993-amd64.pbi
May 25 09:28:31 nas manage.py: [middleware.notifier:178] Executing: /bin/mv /var/tmp/firmware/pbifile.pbi /mnt/RAID/jails/plexmediaserver_1/.plugins/plexmediaserver-0.9.16.6.1993-amd64.pbi
May 25 09:28:31 nas manage.py: [middleware.notifier:192] Executed: /bin/mv /var/tmp/firmware/pbifile.pbi /mnt/RAID/jails/plexmediaserver_1/.plugins/plexmediaserver-0.9.16.6.1993-amd64.pbi -> 0
May 25 09:28:31 nas manage.py: [common.jail:125] Jexec.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:78] Jail_bait.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:79] Jail_bait.__init__: path = /usr/sbin/jexec
May 25 09:28:31 nas manage.py: [common.jail:80] Jail_bait.__init__: flags = 0x00000000
May 25 09:28:31 nas manage.py: [common.jail:100] Jail_bait.__init__: args =
May 25 09:28:31 nas manage.py: [common.jail:106] Jail_bait.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:137] Jexec.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:109] Jail_bait.run: enter
May 25 09:28:31 nas manage.py: [common.jail:115] Jail_bait.cmd = /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/old
May 25 09:28:31 nas manage.py: [common.cmd:189] cmd_pipe.__init__: enter
May 25 09:28:31 nas manage.py: [common.cmd:190] cmd_pipe.__init__: cmd = /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/old
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/old
May 25 09:28:31 nas manage.py: [common.cmd:220] cmd_pipe.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:119] Jail_bait.run: leave
May 25 09:28:31 nas manage.py: [common.jail:125] Jexec.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:78] Jail_bait.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:79] Jail_bait.__init__: path = /usr/sbin/jexec
May 25 09:28:31 nas manage.py: [common.jail:80] Jail_bait.__init__: flags = 0x00000000
May 25 09:28:31 nas manage.py: [common.jail:100] Jail_bait.__init__: args =
May 25 09:28:31 nas manage.py: [common.jail:106] Jail_bait.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:137] Jexec.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:109] Jail_bait.run: enter
May 25 09:28:31 nas manage.py: [common.jail:115] Jail_bait.cmd = /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/new
May 25 09:28:31 nas manage.py: [common.cmd:189] cmd_pipe.__init__: enter
May 25 09:28:31 nas manage.py: [common.cmd:190] cmd_pipe.__init__: cmd = /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/new
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /usr/sbin/jexec 1 /bin/mkdir -p /var/tmp/pbi/new
May 25 09:28:31 nas manage.py: [common.cmd:220] cmd_pipe.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:119] Jail_bait.run: leave
May 25 09:28:31 nas manage.py: [common.jail:125] Jexec.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:78] Jail_bait.__init__: enter
May 25 09:28:31 nas manage.py: [common.jail:79] Jail_bait.__init__: path = /usr/sbin/jexec
May 25 09:28:31 nas manage.py: [common.jail:80] Jail_bait.__init__: flags = 0x00000000
May 25 09:28:31 nas manage.py: [common.jail:100] Jail_bait.__init__: args =
May 25 09:28:31 nas manage.py: [common.jail:106] Jail_bait.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:137] Jexec.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:109] Jail_bait.run: enter
May 25 09:28:31 nas manage.py: [common.jail:115] Jail_bait.cmd = /usr/sbin/jexec 1 /bin/rm -f /var/tmp/pbi/*
May 25 09:28:31 nas manage.py: [common.cmd:189] cmd_pipe.__init__: enter
May 25 09:28:31 nas manage.py: [common.cmd:190] cmd_pipe.__init__: cmd = /usr/sbin/jexec 1 /bin/rm -f /var/tmp/pbi/*
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /usr/sbin/jexec 1 /bin/rm -f /var/tmp/pbi/*
May 25 09:28:31 nas manage.py: [common.cmd:220] cmd_pipe.__init__: leave
May 25 09:28:31 nas manage.py: [common.jail:119] Jail_bait.run: leave
May 25 09:28:31 nas manage.py: [middleware.notifier:3130] XXX: oldpbiname = plexmediaserver-0.9.12.19.1537-amd64.pbi
May 25 09:28:31 nas manage.py: [middleware.notifier:3131] XXX: newpbiname = plexmediaserver-0.9.16.6.1993-amd64.pbi
May 25 09:28:31 nas manage.py: [common.pbi:495] pbi_create.__init__: enter
May 25 09:28:31 nas manage.py: [common.pbi:311] pbi_base.__init__: enter
May 25 09:28:31 nas manage.py: [common.pbi:312] pbi_base.__init__: path = /usr/local/sbin/pbi_create
May 25 09:28:31 nas manage.py: [common.pbi:313] pbi_base.__init__: flags = 0x00000042
May 25 09:28:31 nas manage.py: [common.pbi:335] pbi_base.__init__: args = -b -o /var/tmp/pbi/old
May 25 09:28:31 nas manage.py: [common.pbi:341] pbi_base.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:504] pbi_create.__init__: pbidir = plexmediaserver-0.9.12.19.1537-amd64
May 25 09:28:31 nas manage.py: [common.pbi:505] pbi_create.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:362] pbi_base.run: enter
May 25 09:28:31 nas manage.py: [common.pbi:371] pbi_base.cmd = /usr/sbin/jexec 1 /usr/local/sbin/pbi_create -b -o /var/tmp/pbi/old plexmediaserver-0.9.12.19.1537-amd64
May 25 09:28:31 nas manage.py: [common.cmd:189] cmd_pipe.__init__: enter
May 25 09:28:31 nas manage.py: [common.cmd:190] cmd_pipe.__init__: cmd = /usr/sbin/jexec 1 /usr/local/sbin/pbi_create -b -o /var/tmp/pbi/old plexmediaserver-0.9.12.19.1537-amd64
May 25 09:28:31 nas manage.py: [common.pipesubr:61] Popen()ing: /usr/sbin/jexec 1 /usr/local/sbin/pbi_create -b -o /var/tmp/pbi/old plexmediaserver-0.9.12.19.1537-amd64
May 25 09:28:31 nas manage.py: [common.cmd:211] cmd_pipe.__init__: err = ERROR: can't find installed pbi (plexmediaserver-0.9.12.19.1537-amd64)
May 25 09:28:31 nas manage.py: [common.cmd:220] cmd_pipe.__init__: leave
May 25 09:28:31 nas manage.py: [common.pbi:375] pbi_base.run: leave
Thats all!
the real error is:
can't find installed pbi when do the command
/usr/sbin/jexec 1 /usr/local/sbin/pbi_create -b -o /var/tmp/pbi/old plexmediaserver-0.9.12.19.1537-amd64
I suspect this is a timeout error in the pyton script. A plexmediaserver install data is about some gigabyte on the disk raid
[root@nas] /var/tmp# du -sh /mnt/RAID/jails/plexmediaserver_2
8.3G /mnt/RAID/jails/plexmediaserver_2
[root@nas] /var/tmp# du -sh /mnt/RAID/jails/plexmediaserver_1
8.6G /mnt/RAID/jails/plexmediaserver_1
this produce an error in the update processing
I think modify the
manage.py file can help to resolve the question... (or reproduce another error ;.)