2007-08-11, 07:39 PM
Hi, all.
I'm currently running a client/server setup. Server is a fairly beefy machine with two PVR250s. Client is a low-end machine (approx P3-933Mhz, 256 megs). No wireless - both machines are plugged into the same router. Both running 1.0.8 (client has the recording service stopped and is using the old GUI). Client uses streaming mode and the MPV decoder. I've set LiveTV to be a fairly low bitrate.
The client normally runs fine (video is smooth, menus are fast), but after a few hours of watching LiveTV it freezes.
Logs on the server are set to DEBUG level.
I believe the lockup occurred at around 15:09 or 15:10 (I wasn't paying close attention).
At 15:11, I tried to change the channel on the frozen client. It was on channel 2 (the lowest) and I hit channel-down, so it would wrap around to channel 78 (the highest). I saw no change on the client (still frozen), but saw the following on the server in the GBPVRRecordingService.exe-native.log:
[...]
2007-08-11 15:02:07.546 VERBOSE ConexantRecorder::StartRecording() done
2007-08-11 15:02:40.515 VERBOSE ConexantRecorder::StartNewFile(C:\Media\LiveTV\Golf_2_20070811_14001900.mpg, 2)
2007-08-11 15:02:40.515 VERBOSE getSetting(LiveTVAnalogQuickFileSwitch)
2007-08-11 15:02:40.625 VERBOSE put_Channel(2, AMTUNER_SUBCHAN_DEFAULT, AMTUNER_SUBCHAN_DEFAULT)
2007-08-11 15:02:40.781 VERBOSE Hardware Revision: 0x0207
2007-08-11 15:02:40.781 VERBOSE Product ROM: 0x0207
2007-08-11 15:02:40.781 VERBOSE Unknown MSP Product ROM Code
2007-08-11 15:02:40.796 VERBOSE Attempting to auto detect MSP Standard
2007-08-11 15:02:41.000 VERBOSE Standard Result = 0x0020
2007-08-11 15:02:41.000 VERBOSE Status = 0x0110
2007-08-11 15:02:41.156 VERBOSE ConexantRecorder::StartNewFile() finished
2007-08-11 15:11:27.968 VERBOSE ConexantRecorder::StartNewFile(C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg, 78)
2007-08-11 15:11:27.968 VERBOSE getSetting(LiveTVAnalogQuickFileSwitch)
2007-08-11 15:11:28.078 VERBOSE put_Channel(78, AMTUNER_SUBCHAN_DEFAULT, AMTUNER_SUBCHAN_DEFAULT)
2007-08-11 15:11:28.234 VERBOSE Hardware Revision: 0x0207
2007-08-11 15:11:28.234 VERBOSE Product ROM: 0x0207
2007-08-11 15:11:28.234 VERBOSE Unknown MSP Product ROM Code
2007-08-11 15:11:28.250 VERBOSE Attempting to auto detect MSP Standard
2007-08-11 15:11:28.453 VERBOSE Standard Result = 0x0020
2007-08-11 15:11:28.453 VERBOSE Status = 0x0110
2007-08-11 15:11:28.609 VERBOSE ConexantRecorder::StartNewFile() finished
Fascinatingly, it looks like the client isn't so frozen that it wasn't able to see my attempt to change the channel and send it to the server. The server received the channel change request and actually did it. The client remained frozen (can't even return to the menu).
And I see the following occurs in the GBPVRRecordingService.exe.log around the time of the client-side lockup:
[...]
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155580416
2007-08-11 15:09:35.343 VERBOSE [17] READ: complete
2007-08-11 15:09:35.343 VERBOSE [17] File length currently: 155664320
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155531264
2007-08-11 15:09:35.343 VERBOSE [17] READ: complete
2007-08-11 15:09:35.343 VERBOSE [17] File length currently: 155670464
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155580416
2007-08-11 15:09:36.343 VERBOSE [18] STATUS: DEADBEEF000000F5
2007-08-11 15:09:36.343 VERBOSE [18] returning length: 155865024
2007-08-11 15:09:36.703 VERBOSE [17] READ: complete
2007-08-11 15:09:37.484 VERBOSE [18] STATUS: DEADBEEF000000F5
2007-08-11 15:09:37.484 VERBOSE [18] returning length: 156209088
2007-08-11 15:09:41.921 VERBOSE [13] RenewLease 2
2007-08-11 15:09:41.921 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:09:41.921 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:09:41.921 VERBOSE [13] Getting current programme from cache
2007-08-11 15:09:41.921 VERBOSE [13] RenewLease finished
2007-08-11 15:10:11.953 VERBOSE [13] RenewLease 2
2007-08-11 15:10:11.953 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:10:11.953 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:10:11.953 VERBOSE [13] Getting current programme from cache
2007-08-11 15:10:11.953 VERBOSE [13] RenewLease finished
2007-08-11 15:10:42.000 VERBOSE [13] RenewLease 2
2007-08-11 15:10:42.000 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:10:42.000 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:10:42.000 VERBOSE [13] Getting current programme from cache
2007-08-11 15:10:42.000 VERBOSE [13] RenewLease finished
2007-08-11 15:11:12.046 VERBOSE [13] RenewLease 2
2007-08-11 15:11:12.046 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:11:12.046 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:11:12.046 VERBOSE [13] Getting current programme from cache
2007-08-11 15:11:12.046 VERBOSE [13] RenewLease finished
2007-08-11 15:11:27.953 VERBOSE [13] Opportunity to reuse capture graph. Attempting quick channel change
2007-08-11 15:11:27.953 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:11:27.968 VERBOSE [13] Temporary live TV filename: C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg
2007-08-11 15:12:13.781 ERROR [5] Found expired lease. Stopping recording.
2007-08-11 15:12:13.781 VERBOSE [5] Received request to stop livetv: 2
So it looks like the server, although it received and acted on the change-channel command from the frozen client, it eventually realized that nobody was watching the recording, so it stopped it.
What does "STATUS: DEADBEEF000000F5" mean? I see it very sporadically in the logs, and not always associated with a lockup.
On the client side, the GBPVR.exe-native.log has this around this time:
[...]
2007-08-11 15:02:49.260 INFO DirectShowPlayerBase::playVideoFile(~C:\Media\LiveTV\Golf_2_20070811_14001900.mpg)
2007-08-11 15:02:49.661 VERBOSE This is a remote video file
2007-08-11 15:02:49.661 VERBOSE about to file switch
2007-08-11 15:02:50.252 VERBOSE About to switch files
2007-08-11 15:02:50.762 VERBOSE After file switch
2007-08-11 15:02:50.762 VERBOSE DirectShowPlayerOverlay:
etSourceAspectRatio(2) doing auto aspect ratio..
2007-08-11 15:02:50.762 VERBOSE Window size is 800x600
2007-08-11 15:02:50.762 VERBOSE Video size is 640x480
2007-08-11 15:02:50.762 VERBOSE Handling 4:3 source
2007-08-11 15:02:50.762 INFO DirectShowPlayerBase::playFile() done
2007-08-11 15:02:50.762 VERBOSE DirectShowPlayerOverlay:etSourceAspectRatio(2) doing auto aspect ratio..
2007-08-11 15:02:50.762 VERBOSE Window size is 800x600
2007-08-11 15:02:50.762 VERBOSE Video size is 640x480
2007-08-11 15:02:50.762 VERBOSE Handling 4:3 source
2007-08-11 15:02:50.893 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos
2007-08-11 15:02:50.893 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos@2
2007-08-11 15:03:02.289 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos
2007-08-11 15:03:02.299 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos@2
2007-08-11 15:03:02.589 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos
2007-08-11 15:03:02.589 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos@2
2007-08-11 15:03:03.731 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos
2007-08-11 15:03:03.751 VERBOSE DirectShowPlayerOverlay:etVideoWindowPos@2
2007-08-11 15:11:36.709 INFO DirectShowPlayerBase::playVideoFile(~C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg)
2007-08-11 15:11:37.109 VERBOSE This is a remote video file
2007-08-11 15:11:37.109 VERBOSE about to file switch
So there's no obvious error message on the client side when the freeze occurred. And you can see log lines that seem to be responding to the channel change attempt, although nothing occurs after that.
The server did not need to be restarted. I did have to CTRL-ALT-DEL on the client, though, and kill the GBPVR process. I restarted it, and we're back to normal.
I can put together log and config files if needed, although I wanted to know if it was possible to determine what the issue might be given the data here...?
Thanks!
I'm currently running a client/server setup. Server is a fairly beefy machine with two PVR250s. Client is a low-end machine (approx P3-933Mhz, 256 megs). No wireless - both machines are plugged into the same router. Both running 1.0.8 (client has the recording service stopped and is using the old GUI). Client uses streaming mode and the MPV decoder. I've set LiveTV to be a fairly low bitrate.
The client normally runs fine (video is smooth, menus are fast), but after a few hours of watching LiveTV it freezes.
Logs on the server are set to DEBUG level.
I believe the lockup occurred at around 15:09 or 15:10 (I wasn't paying close attention).
At 15:11, I tried to change the channel on the frozen client. It was on channel 2 (the lowest) and I hit channel-down, so it would wrap around to channel 78 (the highest). I saw no change on the client (still frozen), but saw the following on the server in the GBPVRRecordingService.exe-native.log:
[...]
2007-08-11 15:02:07.546 VERBOSE ConexantRecorder::StartRecording() done
2007-08-11 15:02:40.515 VERBOSE ConexantRecorder::StartNewFile(C:\Media\LiveTV\Golf_2_20070811_14001900.mpg, 2)
2007-08-11 15:02:40.515 VERBOSE getSetting(LiveTVAnalogQuickFileSwitch)
2007-08-11 15:02:40.625 VERBOSE put_Channel(2, AMTUNER_SUBCHAN_DEFAULT, AMTUNER_SUBCHAN_DEFAULT)
2007-08-11 15:02:40.781 VERBOSE Hardware Revision: 0x0207
2007-08-11 15:02:40.781 VERBOSE Product ROM: 0x0207
2007-08-11 15:02:40.781 VERBOSE Unknown MSP Product ROM Code
2007-08-11 15:02:40.796 VERBOSE Attempting to auto detect MSP Standard
2007-08-11 15:02:41.000 VERBOSE Standard Result = 0x0020
2007-08-11 15:02:41.000 VERBOSE Status = 0x0110
2007-08-11 15:02:41.156 VERBOSE ConexantRecorder::StartNewFile() finished
2007-08-11 15:11:27.968 VERBOSE ConexantRecorder::StartNewFile(C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg, 78)
2007-08-11 15:11:27.968 VERBOSE getSetting(LiveTVAnalogQuickFileSwitch)
2007-08-11 15:11:28.078 VERBOSE put_Channel(78, AMTUNER_SUBCHAN_DEFAULT, AMTUNER_SUBCHAN_DEFAULT)
2007-08-11 15:11:28.234 VERBOSE Hardware Revision: 0x0207
2007-08-11 15:11:28.234 VERBOSE Product ROM: 0x0207
2007-08-11 15:11:28.234 VERBOSE Unknown MSP Product ROM Code
2007-08-11 15:11:28.250 VERBOSE Attempting to auto detect MSP Standard
2007-08-11 15:11:28.453 VERBOSE Standard Result = 0x0020
2007-08-11 15:11:28.453 VERBOSE Status = 0x0110
2007-08-11 15:11:28.609 VERBOSE ConexantRecorder::StartNewFile() finished
Fascinatingly, it looks like the client isn't so frozen that it wasn't able to see my attempt to change the channel and send it to the server. The server received the channel change request and actually did it. The client remained frozen (can't even return to the menu).
And I see the following occurs in the GBPVRRecordingService.exe.log around the time of the client-side lockup:
[...]
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155580416
2007-08-11 15:09:35.343 VERBOSE [17] READ: complete
2007-08-11 15:09:35.343 VERBOSE [17] File length currently: 155664320
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155531264
2007-08-11 15:09:35.343 VERBOSE [17] READ: complete
2007-08-11 15:09:35.343 VERBOSE [17] File length currently: 155670464
2007-08-11 15:09:35.343 VERBOSE [17] READ: 49152 bytes from offset 155580416
2007-08-11 15:09:36.343 VERBOSE [18] STATUS: DEADBEEF000000F5
2007-08-11 15:09:36.343 VERBOSE [18] returning length: 155865024
2007-08-11 15:09:36.703 VERBOSE [17] READ: complete
2007-08-11 15:09:37.484 VERBOSE [18] STATUS: DEADBEEF000000F5
2007-08-11 15:09:37.484 VERBOSE [18] returning length: 156209088
2007-08-11 15:09:41.921 VERBOSE [13] RenewLease 2
2007-08-11 15:09:41.921 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:09:41.921 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:09:41.921 VERBOSE [13] Getting current programme from cache
2007-08-11 15:09:41.921 VERBOSE [13] RenewLease finished
2007-08-11 15:10:11.953 VERBOSE [13] RenewLease 2
2007-08-11 15:10:11.953 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:10:11.953 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:10:11.953 VERBOSE [13] Getting current programme from cache
2007-08-11 15:10:11.953 VERBOSE [13] RenewLease finished
2007-08-11 15:10:42.000 VERBOSE [13] RenewLease 2
2007-08-11 15:10:42.000 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:10:42.000 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:10:42.000 VERBOSE [13] Getting current programme from cache
2007-08-11 15:10:42.000 VERBOSE [13] RenewLease finished
2007-08-11 15:11:12.046 VERBOSE [13] RenewLease 2
2007-08-11 15:11:12.046 VERBOSE [13] forcing refresh of next 2 hour events for all capture sources
2007-08-11 15:11:12.046 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:11:12.046 VERBOSE [13] Getting current programme from cache
2007-08-11 15:11:12.046 VERBOSE [13] RenewLease finished
2007-08-11 15:11:27.953 VERBOSE [13] Opportunity to reuse capture graph. Attempting quick channel change
2007-08-11 15:11:27.953 VERBOSE [13] getValue cached value: /settings/LiveTVDirectory : C:\Media\LiveTV
2007-08-11 15:11:27.968 VERBOSE [13] Temporary live TV filename: C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg
2007-08-11 15:12:13.781 ERROR [5] Found expired lease. Stopping recording.
2007-08-11 15:12:13.781 VERBOSE [5] Received request to stop livetv: 2
So it looks like the server, although it received and acted on the change-channel command from the frozen client, it eventually realized that nobody was watching the recording, so it stopped it.
What does "STATUS: DEADBEEF000000F5" mean? I see it very sporadically in the logs, and not always associated with a lockup.
On the client side, the GBPVR.exe-native.log has this around this time:
[...]
2007-08-11 15:02:49.260 INFO DirectShowPlayerBase::playVideoFile(~C:\Media\LiveTV\Golf_2_20070811_14001900.mpg)
2007-08-11 15:02:49.661 VERBOSE This is a remote video file
2007-08-11 15:02:49.661 VERBOSE about to file switch
2007-08-11 15:02:50.252 VERBOSE About to switch files
2007-08-11 15:02:50.762 VERBOSE After file switch
2007-08-11 15:02:50.762 VERBOSE DirectShowPlayerOverlay:
etSourceAspectRatio(2) doing auto aspect ratio..2007-08-11 15:02:50.762 VERBOSE Window size is 800x600
2007-08-11 15:02:50.762 VERBOSE Video size is 640x480
2007-08-11 15:02:50.762 VERBOSE Handling 4:3 source
2007-08-11 15:02:50.762 INFO DirectShowPlayerBase::playFile() done
2007-08-11 15:02:50.762 VERBOSE DirectShowPlayerOverlay:
etSourceAspectRatio(2) doing auto aspect ratio..2007-08-11 15:02:50.762 VERBOSE Window size is 800x600
2007-08-11 15:02:50.762 VERBOSE Video size is 640x480
2007-08-11 15:02:50.762 VERBOSE Handling 4:3 source
2007-08-11 15:02:50.893 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos2007-08-11 15:02:50.893 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos@22007-08-11 15:03:02.289 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos2007-08-11 15:03:02.299 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos@22007-08-11 15:03:02.589 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos2007-08-11 15:03:02.589 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos@22007-08-11 15:03:03.731 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos2007-08-11 15:03:03.751 VERBOSE DirectShowPlayerOverlay:
etVideoWindowPos@22007-08-11 15:11:36.709 INFO DirectShowPlayerBase::playVideoFile(~C:\Media\LiveTV\Community Programming_2_20070811_14001800.mpg)
2007-08-11 15:11:37.109 VERBOSE This is a remote video file
2007-08-11 15:11:37.109 VERBOSE about to file switch
So there's no obvious error message on the client side when the freeze occurred. And you can see log lines that seem to be responding to the channel change attempt, although nothing occurs after that.
The server did not need to be restarted. I did have to CTRL-ALT-DEL on the client, though, and kill the GBPVR process. I restarted it, and we're back to normal.
I can put together log and config files if needed, although I wanted to know if it was possible to determine what the issue might be given the data here...?
Thanks!