matt91 |
05-28-2016 11:33 AM |
I woke up this morning to a bunch of missed recordings. In looking into it a little bit, it looks like my HDHR Prime wasn't getting an IP address and therefore Sage couldn't connect to it.
I really have no idea why that would have happened, but i don't really think it's related to OpenDCT. However, I figure i'd just post my log and see if there is anything that points one way or another.
I'm also posting my DHCP log. Every 60 seconds starting last night there was a DHCPDISCOVER/ DHCPOFFER pair, but the Prime doesn't look like it actually get an address until 7:12AM.
At 7:12, the OpenDCT log also shows that the Prime got sync'd and finally started recording.
As I said, i have no idea what happened, and this may really be a HDHR issue (or other network issue), but i thought i'd start here and see if anything looks suspicious.
thanks
Matt
the relevant portions of the logs are pasted below
Code:
May 28 07:10:16
dhcpd
DHCPDISCOVER from 00:18:dd:31:c2:2d via em0
May 28 07:10:16
dhcpd
DHCPOFFER on 192.168.1.2 to 00:18:dd:31:c2:2d via em0
May 28 07:11:16
dhcpd
DHCPDISCOVER from 00:18:dd:31:c2:2d via em0
May 28 07:11:16
dhcpd
DHCPOFFER on 192.168.1.2 to 00:18:dd:31:c2:2d via em0
May 28 07:12:16
dhcpd
DHCPDISCOVER from 00:18:dd:31:c2:2d via em0
May 28 07:12:16
dhcpd
DHCPOFFER on 192.168.1.2 to 00:18:dd:31:c2:2d via em0
May 28 07:12:16
dhcpd
DHCPREQUEST for 192.168.1.2 (192.168.1.1) from 00:18:dd:31:c2:2d via em0
May 28 07:12:16
dhcpd
DHCPACK on 192.168.1.2 to 00:18:dd:31:c2:2d via em0
May 28 08:52:16
dhcpd
DHCPREQUEST for 192.168.1.2 (192.168.1.1) from 00:18:dd:31:c2:2d via em0
May 28 08:52:16
dhcpd
DHCPACK on 192.168.1.2 to 00:18:dd:31:c2:2d via em0
07:00:00.784 [SageTVRequestHandler-12715:Unknown] DEBUG SageTVRequestHandler - SageTV sent: 'START DCT-HDHomeRun Prime Tuner 131C22D1-0 Digital TV Tuner|1335016272|804|2928866401568|/var/media/tv/Today-29290530-0.ts|Great'
07:00:00.784 [SageTVRequestHandler-12715:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Capture device is now locked.
07:00:00.784 [SageTVRequestHandler-12715:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG SageTVRequestHandler - Starting network encoder to file name '/var/media/tv/Today-29290530-0.ts'.
07:00:00.784 [SageTVRequestHandler-12715:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Starting the encoding for the channel '804' from the device 'DCT-HDHomeRun Prime Tuner 131C22D1-0' to the file '/var/media/tv/Today-29290530-0.ts'...
07:00:03.782 [SageTVRequestHandler-12715:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR HDHRNativeCaptureDevice - Unable to lock HDHomeRun because it cannot be reached => java.net.NoRouteToHostException: No route to host
at sun.nio.ch.Net.connect0(Native Method)
at sun.nio.ch.Net.connect(Net.java:454)
at sun.nio.ch.Net.connect(Net.java:446)
at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:648)
at java.nio.channels.SocketChannel.open(SocketChannel.java:189)
at opendct.tuning.hdhomerun.HDHomeRunControl.connectSocket(HDHomeRunControl.java:249)
at opendct.tuning.hdhomerun.HDHomeRunControl.setVariable(HDHomeRunControl.java:112)
at opendct.tuning.hdhomerun.HDHomeRunControl.getVariable(HDHomeRunControl.java:66)
at opendct.tuning.hdhomerun.HDHomeRunTuner.get(HDHomeRunTuner.java:120)
at opendct.tuning.hdhomerun.HDHomeRunTuner.getLockkey(HDHomeRunTuner.java:268)
at opendct.tuning.hdhomerun.HDHomeRunTuner.isLockedByThisComputer(HDHomeRunTuner.java:287)
at opendct.tuning.hdhomerun.HDHomeRunTuner.setLockkey(HDHomeRunTuner.java:396)
at opendct.capture.HDHRNativeCaptureDevice.setExternalLock(HDHRNativeCaptureDevice.java:328)
at opendct.capture.HDHRNativeCaptureDevice.startEncodingSync(HDHRNativeCaptureDevice.java:551)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:512)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:463)
at opendct.sagetv.SageTVRequestHandler.run(SageTVRequestHandler.java:228)
at java.lang.Thread.run(Thread.java:745)
07:00:03.782 [SageTVRequestHandler-12715:DCT-HDHomeRun Prime Tuner 131C22D1-0] WARN HDHRNativeCaptureDevice - Unable to lock HDHomeRun device.
[......]
07:11:36.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR HDHRNativeCaptureDevice - Unable to lock HDHomeRun because it cannot be reached => java.net.NoRouteToHostException: No route to host
at sun.nio.ch.Net.connect0(Native Method)
at sun.nio.ch.Net.connect(Net.java:454)
at sun.nio.ch.Net.connect(Net.java:446)
at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:648)
at java.nio.channels.SocketChannel.open(SocketChannel.java:189)
at opendct.tuning.hdhomerun.HDHomeRunControl.connectSocket(HDHomeRunControl.java:249)
at opendct.tuning.hdhomerun.HDHomeRunControl.setVariable(HDHomeRunControl.java:112)
at opendct.tuning.hdhomerun.HDHomeRunControl.getVariable(HDHomeRunControl.java:66)
at opendct.tuning.hdhomerun.HDHomeRunTuner.get(HDHomeRunTuner.java:120)
at opendct.tuning.hdhomerun.HDHomeRunTuner.getLockkey(HDHomeRunTuner.java:268)
at opendct.tuning.hdhomerun.HDHomeRunTuner.isLockedByThisComputer(HDHomeRunTuner.java:287)
at opendct.tuning.hdhomerun.HDHomeRunTuner.setLockkey(HDHomeRunTuner.java:396)
at opendct.capture.HDHRNativeCaptureDevice.setExternalLock(HDHRNativeCaptureDevice.java:328)
at opendct.capture.HDHRNativeCaptureDevice.startEncodingSync(HDHRNativeCaptureDevice.java:551)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:512)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:463)
at opendct.sagetv.SageTVRequestHandler.run(SageTVRequestHandler.java:228)
at java.lang.Thread.run(Thread.java:745)
07:11:36.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] WARN HDHRNativeCaptureDevice - Unable to lock HDHomeRun device.
07:11:39.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR HDHRNativeCaptureDevice - Unable to lock HDHomeRun because it cannot be reached => java.net.NoRouteToHostException: No route to host
at sun.nio.ch.Net.connect0(Native Method)
at sun.nio.ch.Net.connect(Net.java:454)
at sun.nio.ch.Net.connect(Net.java:446)
at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:648)
at java.nio.channels.SocketChannel.open(SocketChannel.java:189)
at opendct.tuning.hdhomerun.HDHomeRunControl.connectSocket(HDHomeRunControl.java:249)
at opendct.tuning.hdhomerun.HDHomeRunControl.setVariable(HDHomeRunControl.java:112)
at opendct.tuning.hdhomerun.HDHomeRunControl.getVariable(HDHomeRunControl.java:66)
at opendct.tuning.hdhomerun.HDHomeRunTuner.get(HDHomeRunTuner.java:120)
at opendct.tuning.hdhomerun.HDHomeRunTuner.getLockkey(HDHomeRunTuner.java:268)
at opendct.tuning.hdhomerun.HDHomeRunTuner.isLockedByThisComputer(HDHomeRunTuner.java:287)
at opendct.tuning.hdhomerun.HDHomeRunTuner.setLockkey(HDHomeRunTuner.java:396)
at opendct.capture.HDHRNativeCaptureDevice.setExternalLock(HDHRNativeCaptureDevice.java:328)
at opendct.capture.HDHRNativeCaptureDevice.startEncodingSync(HDHRNativeCaptureDevice.java:551)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:512)
at opendct.capture.HDHRNativeCaptureDevice.startEncoding(HDHRNativeCaptureDevice.java:463)
at opendct.sagetv.SageTVRequestHandler.run(SageTVRequestHandler.java:228)
at java.lang.Thread.run(Thread.java:745)
07:11:39.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR HDHRNativeCaptureDevice - Locking HDHomeRun device failed after 5 attempts.
07:11:39.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR SageTVRequestHandler - SageTV sent: 'START DCT-HDHomeRun Prime Tuner 131C22D1-0 Digital TV Tuner|1849668220|804|2928867696446|/var/media/tv/Today-29290530-6.ts|Great', Replied: 'ERROR Device Start Failed'
07:11:39.222 [SageTVRequestHandler-12754:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR SageTVRequestHandler - Encoder device is unable to start.
07:12:18.370 [SageTVRequestHandler-12758:Unknown] DEBUG SageTVRequestHandler - SageTV sent: 'STOP DCT-HDHomeRun Prime Tuner 131C22D1-0 Digital TV Tuner'
07:12:18.370 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHRNativeCaptureDevice - Stopping encoding...
07:12:18.370 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG BasicCaptureDevice - Consumer is was not in progress.
07:12:18.370 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'force' lockKey: '-1' sendLength: 40
07:12:18.372 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'null' lockKey: '0' sendLength: 26
07:12:18.373 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/channel' value: 'none' lockKey: '0' sendLength: 33
07:12:18.373 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/target' value: 'none' lockKey: '0' sendLength: 32
07:12:18.374 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'null' lockKey: '0' sendLength: 26
07:12:18.374 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - HDHomeRun is now unlocked.
07:12:18.374 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Capture device is now unlocked.
07:12:18.374 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG SageTVRequestHandler - Replied: 'OK'
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG SageTVRequestHandler - SageTV sent: 'START DCT-HDHomeRun Prime Tuner 131C22D1-0 Digital TV Tuner|1919195773|804|2928867876748|/var/media/tv/Today-29290530-7.ts|Great'
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Capture device is now locked.
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG SageTVRequestHandler - Starting network encoder to file name '/var/media/tv/Today-29290530-7.ts'.
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Starting the encoding for the channel '804' from the device 'DCT-HDHomeRun Prime Tuner 131C22D1-0' to the file '/var/media/tv/Today-29290530-7.ts'...
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'null' lockKey: '0' sendLength: 26
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: '1062731511' lockKey: '1062731511' sendLength: 45
07:12:18.375 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - HDHomeRun is now locked.
07:12:18.376 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG RTPCaptureDeviceServices - Producer was not running.
07:12:18.376 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG BasicCaptureDevice - Consumer is was not in progress.
07:12:18.376 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG DynamicConsumerImpl - Using default consumer 'opendct.consumer.FFmpegTransSageTVConsumerImpl' for channel '804'
07:12:18.376 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'null' lockKey: '0' sendLength: 26
07:12:18.376 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'none' lockKey: '1062731511' sendLength: 39
07:12:18.378 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/lockkey' value: 'null' lockKey: '0' sendLength: 26
07:12:18.378 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO NIOHTTPProducerImpl - Connecting to source using the URL 'http://192.168.1.2:5004/tuner0/v804'
07:12:18.938 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HTTPProducerImpl - HTTP Response: 'HTTP/1.1 200 OK', 'Server: HDHomeRun/1.0', 'Connection: close', 'Content-Type: video/mpeg', 'Cache-Control: no-cache', 'Pragma: no-cache', 'transferMode.dlna.org: Streaming', '',
07:12:18.939 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG HDHomeRunControl - key: '/tuner0/program' value: 'null' lockKey: '0' sendLength: 26
07:12:18.939 [NIOHTTPProducerImpl-12771:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO NIOHTTPProducerImpl - Producer thread is running.
07:12:18.939 [NIOHTTPProducerImpl-12771:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG NIOHTTPProducerImpl - Thread priority is 9.
07:12:18.940 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO HDHRNativeCaptureDevice - Configuring and starting the new SageTV consumer...
07:12:18.942 [SageTVRequestHandler-12758:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG BasicCaptureDevice - Consumer is was not in progress.
07:12:18.942 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO FFmpegTransSageTVConsumerImpl - FFmpeg Transcoder consumer thread is now running.
07:12:18.942 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegTransSageTVConsumerImpl - Thread priority is 8.
07:12:18.943 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegStreamDetection - Calling avformat_open_input
07:12:19.319 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO FFmpegStreamDetection - Before avformat_find_stream_info() pos=119756 bytes_read=119756 seek_count=0. probesize: 165440 analyzeduration: 165440.
07:12:19.346 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR mpeg2video - Repeated 1 time: [0x7fb13c0245e0] PES packet size mismatch.
07:12:19.346 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] ERROR mpeg2video - [0x7fb14c022620] Invalid frame dimensions -179868416x0.
07:12:19.422 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO mpegts - Repeated 2 times: [0x7fb14c022620] Invalid frame dimensions -179868416x0..
07:12:19.422 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO mpegts - [0x7fb14c01d960] decoding for stream -179868416 failed
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 331632
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 331632, returnValue = 336897
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 331632
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 331632, returnValue = 336897
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 86897, readIndex = 331632
07:12:19.424 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 86897, readIndex = 86897, returnValue = 86897
07:12:19.500 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 0, readIndex = 468496
07:12:19.500 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 0, readIndex = 0, returnValue = 0
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 469812
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 469812, returnValue = 471129
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 0, readIndex = 469812
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 0, offset = 0, readIndex = 0, returnValue = 0
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 0
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegCircularBufferNIO - Seek: wence = 65536, offset = 0, readIndex = 0, returnValue = 471129
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO FFmpegStreamDetection - After avformat_find_stream_info() pos=0 bytes_read=1183043 seek_count=3. probesize: 165440 analyzeduration: 165440.
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] INFO FFmpegStreamDetection - avformat_find_stream_info() failed with error code 1. Trying again with more data.
07:12:19.501 [FFmpegTransSageTVConsumerImpl-12774:DCT-HDHomeRun Prime Tuner 131C22D1-0] DEBUG FFmpegStreamDetection - Calling avformat_open_input
|