Server Version#: 1.40.1.8227
Player Version#: tvOS 8.33 (8039) & Web Player & iOS 8.33
Tuner Make/Model: vbox xti 3442 firmware 2.66
Guide/Lineup name: Freeview
Using XMLTV?: Plex Supplied & Vbox supplied don’t make any difference
Channel number/Name: 001 / BBC One
Troubleshooting steps:
Completely purged live TV/dvr config from Plex Media Server. Factory Reset vbox after reapplying latest firmware update and rebuilding. Tried BBC One SD and BBC One HD channels (channel 001 and channel 101 according to Freeview).
I captured logs from vbox and from Plex. It appears that for some channels, Plex is sending a malformed request or something unexpected to vbox, as when I attempt to tune BBC One and several other channels, Plex will report that it is unable to tune the channel, but vbox will show the upnp service crashing. The symptoms are always identical, if you watch the TV channel via any other source such as VLC via web player or their official app, the channel plays absolutely fine. If you attempt to access it via Plex, it causes the upnp service to fail repeatedly.
Vbox Logs:
When I try a channel that works such as BBC Two, Vbox gives me the following:
Apr 7 23:26:05 VboxUpnpMediaServer: (505) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8
Apr 7 23:26:05 VboxUpnpMediaServer: (506) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesInfo Entered
Apr 7 23:26:05 VboxUpnpMediaServer: (655) [UPNP_SRV] [A] VboxMediaServer::GetProgramsFromDelegate - Entered
Apr 7 23:26:06 VboxUpnpMediaServer: (697) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8/media/BBC%20TWO
Apr 7 23:26:06 VboxUpnpMediaServer: (698) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesMedia Entered
Apr 7 23:26:06 VboxUpnpMediaServer: (698) [UPNP_SRV] [A] VboxMediaServer::ProcessPlexMediaRequest - Entered
Apr 7 23:26:06 VboxUpnpMediaServer: (698) [UPNP_SRV] [A] VboxMediaServerDelegate::ProcessPlexMedia - request: devices/vbox-3FB8/media/BBC TWO
Apr 7 23:26:06 VboxUpnpMediaServer: (698) [UPNP_SRV] [A] VboxMediaServerDelegate::ProcessPlexMedia - BBC TWO
Apr 7 23:26:06 XLVStreamer.exe: (985) [STREAMER] [A] TunerConfiguration::ConfigureProgram (BBC TWO) - starting shared mem
Apr 7 23:26:06 XLVStreamer.exe: (990) [STREAMER] [A] MuxedPidsProgramInputs::StartPmtDetection - nPmtPid = 0xc8
Apr 7 22:26:06 vboxDaemon: (992) [PLATFORM] [A] START CapturePidsList Tuner 0, Slot 0
Apr 7 22:26:06 vboxDaemon: (993) [PLATFORM] [A] SetPidsMuxList: Tuner[0], Slot=0, PID[ 00c8]
Apr 7 22:26:07 vboxDaemon: (029) [PLATFORM] [A] ## Got first packet in Tuner 0, PID 0x00c8 [C:0xa] ##
Apr 7 22:26:07 vboxDaemon: (037) [PLATFORM] [A] STOP CapturePidsList Tuner 0, Slot 0
Apr 7 22:26:08 vboxDaemon: (012) [PLATFORM] [A] START CapturePidsList Tuner 0, Slot 0
Apr 7 22:26:08 vboxDaemon: (013) [PLATFORM] [A] SetPidsMuxList: Tuner[0], Slot=0, PID[ 00c9 00ca 00cd]
Apr 7 22:26:08 vboxDaemon: (055) [PLATFORM] [A] ## Got first packet in Tuner 0, PID 0x00c9 [C:0x5] ##
Apr 7 22:26:08 vboxDaemon: (055) [PLATFORM] [A] ## Got first packet in Tuner 0, PID 0x00ca [C:0x1] ##
Apr 7 22:26:08 vboxDaemon: (097) [PLATFORM] [A] ## Got first packet in Tuner 0, PID 0x00cd [C:0x2] ##
Apr 7 23:26:08 VboxUpnpMediaServer: (392) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8/media/BBC%20TWO
Apr 7 23:26:08 VboxUpnpMediaServer: (393) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesMedia Entered
Apr 7 23:26:08 VboxUpnpMediaServer: (393) [UPNP_SRV] [A] VboxMediaServer::ProcessPlexMediaRequest - Entered
Apr 7 23:26:08 VboxUpnpMediaServer: (393) [UPNP_SRV] [A] VboxMediaServerDelegate::ProcessPlexMedia - request: devices/vbox-3FB8/media/BBC TWO
Apr 7 23:26:08 VboxUpnpMediaServer: (393) [UPNP_SRV] [A] VboxMediaServerDelegate::ProcessPlexMedia - BBC TWO
Apr 7 23:26:09 VboxUpnpMediaServer: (238) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8
Apr 7 23:26:09 VboxUpnpMediaServer: (239) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesInfo Entered
Apr 7 23:26:09 VboxUpnpMediaServer: (392) [UPNP_SRV] [A] VboxMediaServer::GetProgramsFromDelegate - Entered
Apr 7 23:26:11 thttpd[8729]: spawned CGI process 14068 for file ‘cgi-bin/ManageApp/ManageApp’
Apr 7 23:26:11 ManageApp: (430) [MANG_APP] [A] Manage page 24 entered
Apr 7 23:26:11 ManageApp: (455) [MANG_APP] [A] Manage page 24 exited
When attempting to watch a channel that doesn’t work such as BBC One I get the following:
vbox-BBCOne
Apr 7 23:30:17 VboxUpnpMediaServer: (273) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8
Apr 7 23:30:17 VboxUpnpMediaServer: (274) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesInfo Entered
Apr 7 23:30:17 VboxUpnpMediaServer: (419) [UPNP_SRV] [A] VboxMediaServer::GetProgramsFromDelegate - Entered
Apr 7 22:30:17 vboxDaemon: (540) [PLATFORM] [A] TER TUNER 0: 658000, GUARD_1_32, MOD_64QAM, FEC_2_3, CHAN_BW_8M, DVB-T, PLPid=255, Strength=100.00%, SNR=30.30, RFLevel=-64(dB), LOCKED, BER=0, FER=0
Apr 7 23:30:18 VboxUpnpMediaServer: (520) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8
Apr 7 23:30:18 VboxUpnpMediaServer: (520) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesInfo Entered
Apr 7 23:30:18 XLVStreamer.exe: (653) [STREAMER] [A] TunerConfiguration::ConfigureProgram (BBC TWO) - removing shared mem client (10.x.x.xxx_55555_10.x.x.xxx_BBC TWO_Lavf/LIBAVFORMAT_VERSION_0)
Apr 7 23:30:18 VboxUpnpMediaServer: (681) [UPNP_SRV] [A] VboxMediaServer::GetProgramsFromDelegate - Entered
Apr 7 22:30:18 vboxDaemon: (705) [PLATFORM] [A] STOP CapturePidsList Tuner 0, Slot 0
Apr 7 23:30:19 VboxUpnpMediaServer: (168) [UPNP_SRV] [A] PlexMediaGrabber::VboxProcessHttpGetRequest - request GET for /devices/vbox-3FB8
Apr 7 23:30:19 VboxUpnpMediaServer: (169) [UPNP_SRV] [A] PlexMediaGrabber::PlexGetDevicesInfo Entered
Apr 7 23:30:19 VboxUpnpMediaServer: (316) [UPNP_SRV] [A] VboxMediaServer::GetProgramsFromDelegate - Entered
Apr 7 23:30:19 VboxUpnpMediaServer: (451) [UPNP_SRV] [A] Recieved signal 11 (Segmentation fault)
Apr 7 23:30:19 VboxUpnpMediaServer: (452) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 11, counter 0, printing backtrace
Apr 7 23:30:19 VboxUpnpMediaServer: (454) [UPNP_SRV] [A] backtrace() returned 1 addresses
Apr 7 23:30:19 VboxUpnpMediaServer: (455) [UPNP_SRV] [A] BackTrace: #0: 0x29b0d0f0 /lib/libvboxLoggerLib.so(VboxLogBacktrace+0x24) [0x29b0d0f0]
Apr 7 23:30:19 VboxUpnpMediaServer: (455) [UPNP_SRV] [E] Crashed
Apr 7 23:30:19 VboxUpnpMediaServer: (455) [UPNP_SRV] [A] Recieved signal 11 (Segmentation fault)
Apr 7 23:30:19 VboxUpnpMediaServer: (456) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 11, counter 1, printing backtrace
Apr 7 23:30:19 VboxUpnpMediaServer: (456) [UPNP_SRV] [A] backtrace() returned 1 addresses
Apr 7 23:30:19 VboxUpnpMediaServer: (456) [UPNP_SRV] [A] BackTrace: #0: 0x29b0d0f0 /lib/libvboxLoggerLib.so(VboxLogBacktrace+0x24) [0x29b0d0f0]
Apr 7 23:30:19 VboxUpnpMediaServer: (456) [UPNP_SRV] [E] Crashed
Apr 7 23:30:19 VboxUpnpMediaServer: (456) [UPNP_SRV] [A] Recieved signal 11 (Segmentation fault)
Apr 7 23:30:19 VboxUpnpMediaServer: (457) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 11, counter 2, printing backtrace
Apr 7 23:30:19 VboxUpnpMediaServer: (457) [UPNP_SRV] [A] backtrace() returned 1 addresses
Apr 7 23:30:19 VboxUpnpMediaServer: (459) [UPNP_SRV] [A] BackTrace: #0: 0x29b0d0f0 /lib/libvboxLoggerLib.so(VboxLogBacktrace+0x24) [0x29b0d0f0]
Apr 7 23:30:19 VboxUpnpMediaServer: (459) [UPNP_SRV] [E] Crashed
Apr 7 23:30:19 VboxUpnpMediaServer: (460) [UPNP_SRV] [A] Recieved signal 11 (Segmentation fault)
Apr 7 23:30:19 VboxUpnpMediaServer: (460) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 11, counter 3, printing backtrace
Apr 7 23:30:19 VboxUpnpMediaServer: (460) [UPNP_SRV] [A] backtrace() returned 1 addresses
Apr 7 23:30:19 VboxUpnpMediaServer: (460) [UPNP_SRV] [A] BackTrace: #0: 0x29b0d0f0 /lib/libvboxLoggerLib.so(VboxLogBacktrace+0x24) [0x29b0d0f0]
Apr 7 23:30:19 VboxUpnpMediaServer: (460) [UPNP_SRV] [E] Crashed
Apr 7 23:30:19 VboxUpnpMediaServer: (457) [UPNP_SRV] [A] Closing UPnP
Apr 7 22:30:19 kernel: Fixing up unaligned userspace access in “VboxUpnpMediaSe” pid=9048 pc=0x29742a66 ins=0x6e12
Apr 7 22:30:19 kernel: Fixing up unaligned userspace access in “VboxUpnpMediaSe” pid=9048 pc=0x29742a66 ins=0x6e12
Apr 7 22:30:19 kernel: Sending SIGBUS to “VboxUpnpMediaSe” due to unaligned access (PC 29742a66 PR 29742a16)
Apr 7 23:30:19 VboxUpnpMediaServer: (617) [UPNP_SRV] [A] Recieved signal 7 (Bus error)
Apr 7 23:30:19 VboxUpnpMediaServer: (617) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 7, counter 4, printing backtrace
Apr 7 23:30:19 VboxUpnpMediaServer: (617) [UPNP_SRV] [A] backtrace() returned 1 addresses
Apr 7 23:30:19 VboxUpnpMediaServer: (618) [UPNP_SRV] [A] BackTrace: #0: 0x29b0d0f0 /lib/libvboxLoggerLib.so(VboxLogBacktrace+0x24) [0x29b0d0f0]
Apr 7 23:30:19 VboxUpnpMediaServer: (618) [UPNP_SRV] [E] Crashed
Apr 7 22:30:19 kernel: Fixing up unaligned userspace access in “VboxUpnpMediaSe” pid=9048 pc=0x29742a66 ins=0x6e12
Apr 7 22:30:19 kernel: Fixing up unaligned userspace access in “VboxUpnpMediaSe” pid=9048 pc=0x29742a66 ins=0x6e12
Apr 7 22:30:19 kernel: Sending SIGBUS to “VboxUpnpMediaSe” due to unaligned access (PC 29742a66 PR 29742a16)
Apr 7 23:30:19 VboxUpnpMediaServer: (643) [UPNP_SRV] [A] Recieved signal 7 (Bus error)
Apr 7 23:30:19 VboxUpnpMediaServer: (643) [UPNP_SRV] [A] VboxUpnpMediaServer Crashed on Fatal signal 7, counter 5, printing backtrace
(Message repeats for hundreds of entries, the same thing with the counter incrementing to over 200)
Apr 7 22:30:21 kernel: Sending SIGBUS to “VboxUpnpMediaSe” due to unaligned access (PC 29742a66 PR 29742a16)
Apr 7 23:30:21 HttpControlApp: (882) [HTTP_CTL] [A] HTTP Control QueryBoardInfo entered by , Rand=[none]
Apr 7 23:30:22 VboxUpnpMediaServer: (534) [UPNP_SRV] [C] ThreadInstance::Stop (XLVStreamerUPnPClient) - timeout waiting for acknowledge
Apr 7 23:30:22 HttpControlApp: (737) [HTTP_CTL] [A] HTTP Control QueryBoardInfo exited by , Rand=[none]
Apr 7 23:30:23 vboxWatchdog: (496) [WATCHDOG] [A] Saved logfiles in /home/httpd/pub/VboxLogBacktrace_07-04-2024_23-30-21.tar.gz
Apr 7 23:30:23 VboxUpnpMediaServer: (561) [UPNP_SRV] [C] ThreadInstance::Close (Not assigned) - timeout waiting for thread to close: performing Kill
Apr 7 23:30:23 VboxUpnpMediaServer: (568) [��|] [D] TunerAdaptorManager::Close() - Enter
Apr 7 23:30:23 VboxUpnpMediaServer: (569) [��^D��^D��^D��^D��^D��^D] [D] EpgBuildScheduler::StopDetection
Apr 7 23:30:23 VboxUpnpMediaServer: (569) [��^D��^D��^D��^D��^D��^D] [D] TunerAdaptorManager::Close() - Manual program list is destroyed
Apr 7 23:30:23 VboxUpnpMediaServer: (570) [��^D��^D��^D��^D��^D��^D] [D] TunerAdaptorManager::Close() - Leave
Apr 7 23:30:24 thttpd[8729]: spawned CGI process 15016 for file ‘cgi-bin/ManageApp/ManageApp’
Apr 7 23:30:24 ManageApp: (218) [MANG_APP] [A] Manage page 24 entered
Apr 7 23:30:24 ManageApp: (242) [MANG_APP] [A] Manage page 24 exited
Apr 7 22:30:26 kernel: MAC Address Added[105e7ffffa]
Apr 7 23:30:35 thttpd[8729]: spawned CGI process 15061 for file ‘cgi-bin/ManageApp/ManageApp’
Apr 7 23:30:35 ManageApp: (805) [MANG_APP] [A] Manage page 24 entered
Apr 7 23:30:35 ManageApp: (816) [MANG_APP] [A] Manage page 24 exited
From the Plex side of things I get an error when trying to connect to BBC One that says
[HttpClient/HCl#6d60] HTTP error requesting GET http://10.x.x.xxx:55555/devices/vbox-3FB8 (7, Couldn’t connect to server) (Failed to connect to 10.x.x.xxx port 55555 after 2351 ms: Couldn’t connect to server)
I’ve of course masked my internal IP settings here but it displays the IP addresses as you’d expect.
All in all what I can make of this is that Plex is malforming a request and making the vbox crash, but I can’t see what that request is. I used info, warning, and error as my logging status for troubleshooting this, I can make it more verbose if preferred but wanted to avoid adding too much extra junk.
Has anyone seen this?
